HHH-19611 demote many DEBUG-level log messages to TRACE

documentation/src/main/asciidoc/integrationguide/chapters/services/extras/register-event-listeners-example.java

@@ -6,7 +6,7 @@ public void integrate(
             SessionFactoryServiceRegistry serviceRegistry) {
         // As you might expect, an EventListenerRegistry is the thing with which event listeners are registered  It is a
         // service so we look it up using the service registry
-        final EventListenerRegistry eventListenerRegistry = serviceRegistry.getService( EventListenerRegistry.class );
+        final EventListenerRegistry eventListenerRegistry = sessionFactory.getEventListenerRegistry();
 
         // If you wish to have custom determination and handling of "duplicate" listeners, you would have to add an
         // implementation of the org.hibernate.event.service.spi.DuplicationStrategy contract like this

hibernate-core/src/main/java/org/hibernate/LazyInitializationException.java

@@ -4,12 +4,6 @@
  */
 package org.hibernate;
 
-import org.hibernate.internal.CoreMessageLogger;
-
-import org.jboss.logging.Logger;
-
-import java.lang.invoke.MethodHandles;
-
 /**
  * Indicates an attempt to access unfetched data outside the context
  * of an open stateful {@link Session}.
@@ -25,20 +19,13 @@
  */
 public class LazyInitializationException extends HibernateException {
 
-	private static final CoreMessageLogger LOG = Logger.getMessageLogger(
-			MethodHandles.lookup(),
-			CoreMessageLogger.class,
-			LazyInitializationException.class.getName()
-	);
-
 	/**
 	 * Constructs a {@code LazyInitializationException} using the given message.
 	 *
 	 * @param message A message explaining the exception condition
 	 */
 	public LazyInitializationException(String message) {
 		super( message );
-		LOG.trace( message, this );
 	}
 
 }

hibernate-core/src/main/java/org/hibernate/boot/archive/internal/ArchiveHelper.java

@@ -26,8 +26,8 @@ public class ArchiveHelper {
 	private static final Logger log = Logger.getLogger( ArchiveHelper.class );
 
 	/**
-	 * Get the JAR URL of the JAR containing the given entry
-	 * Method used in a non managed environment
+	 * Get the JAR URL of the JAR containing the given entry.
+	 * Method used in a non-managed environment.
 	 *
 	 * @param url URL pointing to the known file in the JAR
 	 * @param entry file known to be in the JAR

hibernate-core/src/main/java/org/hibernate/boot/beanvalidation/TypeSafeActivator.java

@@ -158,7 +158,7 @@ private static void setupListener(ValidatorFactory validatorFactory, SessionFact
 		final ConfigurationService cfgService = serviceRegistry.requireService( ConfigurationService.class );
 		final BeanValidationEventListener listener =
 				new BeanValidationEventListener( validatorFactory, cfgService.getSettings(), classLoaderService );
-		final EventListenerRegistry listenerRegistry = serviceRegistry.requireService( EventListenerRegistry.class );
+		final EventListenerRegistry listenerRegistry = sessionFactory.getEventListenerRegistry();
 		listenerRegistry.addDuplicationStrategy( DuplicationStrategyImpl.INSTANCE );
 		listenerRegistry.appendListeners( EventType.PRE_INSERT, listener );
 		listenerRegistry.appendListeners( EventType.PRE_UPDATE, listener );

hibernate-core/src/main/java/org/hibernate/boot/cfgxml/internal/ConfigLoader.java

@@ -130,10 +130,7 @@ public Properties loadProperties(String resourceName) {
 				stream.close();
 			}
 			catch (IOException e) {
-				log.debug(
-						String.format( "Unable to close properties file [%s] stream", resourceName ),
-						e
-				);
+				log.debug( "Unable to close properties file stream [" + resourceName + "]", e );
 			}
 		}
 	}
@@ -157,10 +154,7 @@ public Properties loadProperties(File file) {
 					stream.close();
 				}
 				catch (IOException e) {
-					log.debug(
-							String.format( "Unable to close properties file [%s] stream", file.getAbsolutePath() ),
-							e
-					);
+					log.debug( "Unable to close properties file stream [" + file.getAbsolutePath() + "]", e );
 				}
 			}
 		}

hibernate-core/src/main/java/org/hibernate/boot/internal/BootstrapContextImpl.java

@@ -307,28 +307,43 @@ public void addAttributeConverterDescriptor(ConverterDescriptor<?,?> descriptor)
 		}
 	}
 
-	void injectJpaTempClassLoader(ClassLoader jpaTempClassLoader) {
-		log.debugf( "Injecting JPA temp ClassLoader [%s] into BootstrapContext; was [%s]", jpaTempClassLoader, this.getJpaTempClassLoader() );
-		this.classLoaderAccess.injectTempClassLoader( jpaTempClassLoader );
+	void injectJpaTempClassLoader(ClassLoader classLoader) {
+		if ( log.isTraceEnabled() && classLoader != getJpaTempClassLoader() ) {
+			log.tracef( "Injecting JPA temp ClassLoader [%s] into BootstrapContext; was [%s]",
+					classLoader, getJpaTempClassLoader() );
+		}
+		this.classLoaderAccess.injectTempClassLoader( classLoader );
 	}
 
 	void injectScanOptions(ScanOptions scanOptions) {
-		log.debugf( "Injecting ScanOptions [%s] into BootstrapContext; was [%s]", scanOptions, this.scanOptions );
+		if ( log.isTraceEnabled() && scanOptions != this.scanOptions ) {
+			log.tracef( "Injecting ScanOptions [%s] into BootstrapContext; was [%s]",
+					scanOptions, this.scanOptions );
+		}
 		this.scanOptions = scanOptions;
 	}
 
 	void injectScanEnvironment(ScanEnvironment scanEnvironment) {
-		log.debugf( "Injecting ScanEnvironment [%s] into BootstrapContext; was [%s]", scanEnvironment, this.scanEnvironment );
+		if ( log.isTraceEnabled() && scanEnvironment != this.scanEnvironment ) {
+			log.tracef( "Injecting ScanEnvironment [%s] into BootstrapContext; was [%s]",
+					scanEnvironment, this.scanEnvironment );
+		}
 		this.scanEnvironment = scanEnvironment;
 	}
 
 	void injectScanner(Scanner scanner) {
-		log.debugf( "Injecting Scanner [%s] into BootstrapContext; was [%s]", scanner, this.scannerSetting );
+		if ( log.isTraceEnabled() && scanner != this.scannerSetting ) {
+			log.tracef( "Injecting Scanner [%s] into BootstrapContext; was [%s]",
+					scanner, scannerSetting );
+		}
 		this.scannerSetting = scanner;
 	}
 
 	void injectArchiveDescriptorFactory(ArchiveDescriptorFactory factory) {
-		log.debugf( "Injecting ArchiveDescriptorFactory [%s] into BootstrapContext; was [%s]", factory, this.archiveDescriptorFactory );
+		if ( log.isTraceEnabled() && factory != archiveDescriptorFactory ) {
+			log.tracef( "Injecting ArchiveDescriptorFactory [%s] into BootstrapContext; was [%s]",
+					factory, archiveDescriptorFactory );
+		}
 		this.archiveDescriptorFactory = factory;
 	}
 

hibernate-core/src/main/java/org/hibernate/boot/internal/ClassLoaderAccessImpl.java

@@ -40,7 +40,6 @@ public ClassLoaderAccessImpl(ClassLoaderService classLoaderService) {
 	}
 
 	public void injectTempClassLoader(ClassLoader jpaTempClassLoader) {
-		log.debugf( "ClassLoaderAccessImpl#injectTempClassLoader(%s) [was %s]", jpaTempClassLoader, this.jpaTempClassLoader );
 		this.jpaTempClassLoader = jpaTempClassLoader;
 	}
 
@@ -55,20 +54,19 @@ public Class<?> classForName(String name) {
 			return classLoaderService.classForName( name );
 		}
 		else {
-			log.debugf( "Not known whether passed class name [%s] is safe", name );
+			// Could not determine that the given class is safe to load with live ClassLoader
 			if ( jpaTempClassLoader == null ) {
-				log.debugf(
-						"No temp ClassLoader provided; using live ClassLoader " +
-								"for loading potentially unsafe class : %s",
+				log.tracef(
+						"No temp ClassLoader provided; using live ClassLoader to load potentially unsafe class: %s",
 						name
 				);
 				return classLoaderService.classForName( name );
 			}
 			else {
-				log.debugf(
-						"Temp ClassLoader was provided, so we will use that : %s",
-						name
-				);
+//				log.tracef(
+//						"Temp ClassLoader was provided, so we will use that: %s",
+//						name
+//				);
 				try {
 					return jpaTempClassLoader.loadClass( name );
 				}

hibernate-core/src/main/java/org/hibernate/boot/internal/InFlightMetadataCollectorImpl.java

@@ -903,9 +903,9 @@ public void addImport(String importName, String className) {
 			throw new IllegalArgumentException( "Import name or entity name is null" );
 		}
 		log.tracev( "Import: {0} -> {1}", importName, className);
-		String old = imports.put( importName, className);
+		final String old = imports.put( importName, className);
 		if ( old != null ) {
-			log.debugf( "import name [%s] overrode previous [{%s}]", importName, old );
+			log.debugf( "Import name [%s] overrode previous [{%s}]", importName, old );
 		}
 	}
 
@@ -1953,7 +1953,7 @@ protected void secondPassCompileForeignKeys(Table table, Set<ForeignKey> done, M
 
 	private void processPropertyReferences() {
 		if ( delayedPropertyReferenceHandlers != null ) {
-			log.debug( "Processing association property references" );
+			log.trace( "Processing association property references" );
 
 			for ( DelayedPropertyReferenceHandler delayedPropertyReferenceHandler : delayedPropertyReferenceHandlers ) {
 				delayedPropertyReferenceHandler.process( this );
@@ -2107,7 +2107,7 @@ private void handleIdentifierValueBinding(
 			// by tools. We want to hold off requiring classes being present until we
 			// try to build the SF. Here, just building the Metadata, it is "ok" for an
 			// exception to occur, the same exception will happen later as we build the SF.
-			log.debugf( "Ignoring exception thrown when trying to build IdentifierGenerator as part of Metadata building", e );
+			log.debug( "Ignoring exception thrown when trying to build IdentifierGenerator as part of Metadata building", e );
 		}
 	}
 

hibernate-core/src/main/java/org/hibernate/boot/internal/MetadataImpl.java

@@ -493,12 +493,9 @@ public void initSessionFactory(SessionFactoryImplementor sessionFactory) {
 		// must not use BootstrapContext services here
 		final ServiceRegistryImplementor registry = sessionFactory.getServiceRegistry();
 		assert registry != null;
-		final ConfigurationService configurationService =
-				registry.requireService( ConfigurationService.class );
-		final ClassLoaderService classLoaderService =
-				registry.requireService( ClassLoaderService.class );
-		final EventListenerRegistry eventListenerRegistry =
-				registry.requireService( EventListenerRegistry.class );
+		final ConfigurationService configurationService = registry.requireService( ConfigurationService.class );
+		final ClassLoaderService classLoaderService = registry.requireService( ClassLoaderService.class );
+		final EventListenerRegistry eventListenerRegistry = sessionFactory.getEventListenerRegistry();
 		configurationService.getSettings().forEach( (propertyName, value) -> {
 			if ( propertyName.startsWith( EVENT_LISTENER_PREFIX ) ) {
 				final String eventTypeName = propertyName.substring( EVENT_LISTENER_PREFIX.length() + 1 );

hibernate-core/src/main/java/org/hibernate/boot/jaxb/internal/AbstractBinder.java

@@ -99,7 +99,6 @@ private <X extends T> Binding<X> doBind(XMLEventReader eventReader, Origin origi
 			}
 			catch (Exception e) {
 				log.debug( "Unable to close StAX reader", e );
-
 			}
 		}
 	}

hibernate-core/src/main/java/org/hibernate/boot/jaxb/internal/CacheableFileXmlSource.java

@@ -118,8 +118,8 @@ private static void writeSerFile(Serializable binding, File xmlFile, File serFil
 			binding = (Serializable) bindingWrapper.getRoot();
 		}
 		try ( FileOutputStream fos = new FileOutputStream( serFile ) ) {
-			if ( log.isDebugEnabled() ) {
-				log.debugf( "Writing cache file for: %s to: %s", xmlFile.getAbsolutePath(), serFile.getAbsolutePath() );
+			if ( log.isTraceEnabled() ) {
+				log.tracef( "Writing cache file for: %s to: %s", xmlFile.getAbsolutePath(), serFile.getAbsolutePath() );
 			}
 			SerializationHelper.serialize( binding, fos );
 			boolean success = serFile.setLastModified( System.currentTimeMillis() );

hibernate-core/src/main/java/org/hibernate/boot/jaxb/internal/MappingBinder.java

@@ -163,8 +163,8 @@
 			Origin origin) {
 		final String rootElementLocalName = rootElementStartEvent.getName().getLocalPart();
 		if ( "hibernate-mapping".equals( rootElementLocalName ) ) {
-			if ( log.isDebugEnabled() ) {
-				log.debugf( "Performing JAXB binding of hbm.xml document : %s", origin.toString() );
+			if ( log.isTraceEnabled() ) {
+				log.tracef( "Performing JAXB binding of hbm.xml document: %s", origin.toString() );
 			}
 
 			final XMLEventReader hbmReader = new HbmEventReader( staxEventReader, xmlEventFactory );
@@ -181,7 +181,7 @@
 		else {
 			assert "entity-mappings".equals( rootElementLocalName );
 			try {
-				log.debugf( "Performing JAXB binding of orm.xml document : %s", origin.toString() );
+				log.tracef( "Performing JAXB binding of orm.xml document: %s", origin.toString() );
 
 				final XMLEventReader reader = new MappingEventReader( staxEventReader, xmlEventFactory );
 				final JaxbEntityMappingsImpl bindingRoot = jaxb(

hibernate-core/src/main/java/org/hibernate/boot/jaxb/internal/XmlSources.java

@@ -16,14 +16,15 @@
 
 import org.hibernate.boot.MappingNotFoundException;
 import org.hibernate.boot.archive.spi.InputStreamAccess;
-import org.hibernate.boot.jaxb.JaxbLogger;
 import org.hibernate.boot.jaxb.Origin;
 import org.hibernate.boot.jaxb.SourceType;
 import org.hibernate.boot.jaxb.spi.XmlSource;
 import org.hibernate.boot.registry.classloading.spi.ClassLoaderService;
 
 import org.w3c.dom.Document;
 
+import static org.hibernate.boot.jaxb.JaxbLogger.JAXB_LOGGER;
+
 /**
  * Helper for building and handling {@link XmlSource} references.
  * <p>
@@ -38,7 +39,7 @@
 	 * Create an {@link XmlSource} from a named resource
 	 */
 	public static XmlSource fromResource(String resourceName, ClassLoaderService classLoaderService) {
-		JaxbLogger.JAXB_LOGGER.tracef( "reading mappings from resource : %s", resourceName );
+		JAXB_LOGGER.tracef( "Reading mappings from resource: %s", resourceName );
 
 		final Origin origin = new Origin( SourceType.RESOURCE, resourceName );
 		final URL url = classLoaderService.locateResource( resourceName );
@@ -54,15 +55,15 @@
 	 */
 	public static XmlSource fromUrl(URL url) {
 		final String urlExternalForm = url.toExternalForm();
-		JaxbLogger.JAXB_LOGGER.tracef( "Reading mapping document from URL : %s", urlExternalForm );
+		JAXB_LOGGER.tracef( "Reading mapping document from URL: %s", urlExternalForm );
 
 		final Origin origin = new Origin( SourceType.URL, urlExternalForm );
 		return new UrlXmlSource( origin, url );
 	}
 
 	public static XmlSource fromFile(File file) {
 		final String filePath = file.getPath();
-		JaxbLogger.JAXB_LOGGER.tracef( "reading mappings from file : %s", filePath );
+		JAXB_LOGGER.tracef( "Reading mappings from file: %s", filePath );
 
 		final Origin origin = new Origin( SourceType.FILE, filePath );
 
@@ -87,29 +88,29 @@
 
 	public static XmlSource fromCacheableFile(File file, File cacheableDir, boolean strict) {
 		final String filePath = file.getPath();
-		JaxbLogger.JAXB_LOGGER.tracef( "reading mappings from cacheable-file : %s", filePath );
+		JAXB_LOGGER.tracef( "Reading mappings from cacheable file: %s", filePath );
 
 		final Origin origin = new Origin( SourceType.FILE, filePath );
 		return new CacheableFileXmlSource( origin, file, cacheableDir, strict );
 	}
 
 	public static XmlSource fromStream(InputStreamAccess inputStreamAccess) {
 		final String streamName = inputStreamAccess.getStreamName();
-		JaxbLogger.JAXB_LOGGER.tracef( "reading mappings from InputStreamAccess : %s", streamName );
+		JAXB_LOGGER.tracef( "Reading mappings from InputStreamAccess: %s", streamName );
 
 		final Origin origin = new Origin( SourceType.INPUT_STREAM, streamName );
 		return new InputStreamAccessXmlSource( origin, inputStreamAccess );
 	}
 
 	public static XmlSource fromStream(InputStream inputStream) {
-		JaxbLogger.JAXB_LOGGER.trace( "reading mappings from InputStream" );
+		JAXB_LOGGER.trace( "reading mappings from InputStream" );
 
 		final Origin origin = new Origin( SourceType.INPUT_STREAM, null );
 		return new InputStreamXmlSource( origin, inputStream, false );
 	}
 
 	public static XmlSource fromDocument(Document document) {
-		JaxbLogger.JAXB_LOGGER.trace( "reading mappings from DOM" );
+		JAXB_LOGGER.trace( "reading mappings from DOM" );
 		final Origin origin = new Origin( SourceType.DOM, Origin.UNKNOWN_FILE_PATH );
 		return new JaxpSourceXmlSource( origin, new DOMSource( document ) );
 	}
@@ -125,7 +126,7 @@
 	 * @param consumer a consumer of the resulting {@linkplain XmlSource XML sources}
 	 */
 	public static void fromJar(File jar, Consumer<XmlSource> consumer) {
-		JaxbLogger.JAXB_LOGGER.tracef( "Seeking mapping documents in jar file : %s", jar.getName() );
+		JAXB_LOGGER.tracef( "Seeking mapping documents in jar file: %s", jar.getName() );
 
 		final Origin origin = new Origin( SourceType.JAR, jar.getAbsolutePath() );
 
@@ -134,7 +135,7 @@
 			while ( entries.hasMoreElements() ) {
 				final JarEntry jarEntry = entries.nextElement();
 				if ( jarEntry.getName().endsWith(".hbm.xml") ) {
-					JaxbLogger.JAXB_LOGGER.tracef( "Found hbm.xml mapping in jar : %s", jarEntry.getName() );
+					JAXB_LOGGER.tracef( "Found 'hbm.xml' mapping in jar: %s", jarEntry.getName() );
 					consumer.accept( new JarFileEntryXmlSource( origin, jarFile, jarEntry ) );
 				}
 			}

hibernate-core/src/main/java/org/hibernate/boot/jaxb/internal/stax/LocalXmlResourceResolver.java

@@ -37,7 +37,7 @@ public Object resolveEntity(String publicID, String systemID, String baseURI, St
 		log.tracef( "In resolveEntity(%s, %s, %s, %s)", publicID, systemID, baseURI, namespace );
 
 		if ( namespace != null ) {
-			log.debugf( "Interpreting namespace : %s", namespace );
+			log.tracef( "Interpreting namespace: %s", namespace );
 			if ( MappingXsdSupport.latestDescriptor().getNamespaceUri().matches( namespace ) ) {
 				return openUrlStream( MappingXsdSupport.latestDescriptor() );
 			}
@@ -84,7 +84,7 @@ else if ( ConfigXsdSupport.cfgXsd().getNamespaceUri().matches( namespace ) ) {
 		}
 
 		if ( publicID != null || systemID != null ) {
-			log.debugf( "Checking public/system identifiers `%s`/`%s` as DTD references", publicID, systemID );
+			log.tracef( "Checking public/system identifiers `%s`/`%s` as DTD references", publicID, systemID );
 
 			if ( MAPPING_DTD.matches( publicID, systemID ) ) {
 				return openUrlStream( MAPPING_DTD.localSchemaUrl );
@@ -116,15 +116,15 @@ else if ( ConfigXsdSupport.cfgXsd().getNamespaceUri().matches( namespace ) ) {
 		if ( systemID != null ) {
 			// technically, "classpath://..." identifiers should only be declared as SYSTEM identifiers
 			if ( systemID.startsWith( CLASSPATH_EXTENSION_URL_BASE ) ) {
-				log.debugf( "Recognized `classpath:` identifier; attempting to resolve on classpath [%s]", systemID );
+				log.tracef( "Recognized 'classpath:' identifier; attempting to resolve on classpath [%s]", systemID );
 				final String path = systemID.substring( CLASSPATH_EXTENSION_URL_BASE.length() );
 				// todo : for this to truly work consistently, we need access to ClassLoaderService
 				final InputStream stream = resolveInLocalNamespace( path );
 				if ( stream == null ) {
-					log.debugf( "Unable to resolve [%s] on classpath", systemID );
+					log.tracef( "Unable to resolve [%s] on classpath", systemID );
 				}
 				else {
-					log.debugf( "Resolved [%s] on classpath", systemID );
+					log.tracef( "Resolved [%s] on classpath", systemID );
 				}
 				return stream;
 			}