From 997dd3ee65b0e30b396fa06db75eb6a80b3809bc Mon Sep 17 00:00:00 2001 From: Sam Brannen Date: Tue, 25 Oct 2022 13:57:47 +0200 Subject: [PATCH] Revise logging in the TestContext framework For a Spring Boot test, Logback logs at DEBUG level by default until Spring Boot's logging infrastructure has a chance to take control, and this can result in a considerable amount of INFO and DEBUG output. It's not the number of lines that causes an issue. Rather, it's the amount of information in each line that can become overwhelming, especially when the MergedContextConfiguration is complex. The main reason for lengthy DEBUG logging in a Spring Boot test is that Spring Boot's ImportsContextCustomizer implements toString() which results in logging of the fully qualified class names of all imported configuration classes. In an example using @WebMvcTest, this resulted in logging of 27 imported classes twice. However, the lists of registered TestExecutionListener, ContextCustomizerFactory, and ContextCustomizer implementations are also logged separately, and that adds quite a bit of noise at DEBUG level. This commit addresses these issues and simultaneously completely revises logging within the Spring TestContext Framework (TCF). - Numerous log statements are now logged at TRACE level instead of DEBUG. - Numerous log statements now have two modes. When logging at TRACE level, fully qualified class names (or the results of invoking toString() on related components) are included. When logging at DEBUG level, simple names of classes are logged and the results of invoking toString() on related components are omitted. - toString() implementations in TCF components are now based on the newly introduced SimpleValueStyler for ToStringCreator. The combination of the above changes greatly reduces the amount of DEBUG logging output in the TCF, but users can still access complete details by switching to TRACE level logging. Closes gh-29229 --- .../test/context/BootstrapUtils.java | 6 +- .../ContextConfigurationAttributes.java | 16 +++-- .../context/MergedContextConfiguration.java | 18 ++--- .../context/TestContextAnnotationUtils.java | 8 ++- ...tTestContextInitializersCodeGenerator.java | 4 +- .../cache/AotMergedContextConfiguration.java | 8 ++- ...efaultCacheAwareContextLoaderDelegate.java | 19 ++++-- .../test/context/jdbc/MergedSqlConfig.java | 6 +- .../jdbc/SqlScriptsTestExecutionListener.java | 18 +++-- .../junit4/SpringJUnit4ClassRunner.java | 7 +- .../junit4/statements/SpringRepeat.java | 6 +- .../support/AbstractContextLoader.java | 12 ++-- .../AbstractDelegatingSmartContextLoader.java | 29 ++++---- ...ctDirtiesContextTestExecutionListener.java | 40 ++++++++--- .../support/AbstractGenericContextLoader.java | 18 +++-- .../AbstractTestContextBootstrapper.java | 67 ++++++++++++------- .../context/support/ActiveProfilesUtils.java | 15 ++--- .../AnnotationConfigContextLoader.java | 7 +- .../DefaultActiveProfilesResolver.java | 6 +- .../support/DefaultBootstrapContext.java | 12 ++-- .../context/support/DefaultTestContext.java | 4 +- ...endencyInjectionTestExecutionListener.java | 14 ++-- .../support/MergedTestPropertySources.java | 10 +-- .../support/TestPropertySourceAttributes.java | 10 +-- .../support/TestPropertySourceUtils.java | 14 ++-- .../TestContextTransactionUtils.java | 8 +-- .../transaction/TransactionContext.java | 27 +++++--- .../TransactionalTestExecutionListener.java | 64 ++++++++++++------ .../web/AbstractGenericWebContextLoader.java | 18 ++++- .../web/ServletTestExecutionListener.java | 18 +++-- .../web/WebMergedContextConfiguration.java | 19 +++--- .../src/test/resources/log4j2-test.xml | 2 +- 32 files changed, 335 insertions(+), 195 deletions(-) diff --git a/spring-test/src/main/java/org/springframework/test/context/BootstrapUtils.java b/spring-test/src/main/java/org/springframework/test/context/BootstrapUtils.java index c958b228e59f..f5c731215408 100644 --- a/spring-test/src/main/java/org/springframework/test/context/BootstrapUtils.java +++ b/spring-test/src/main/java/org/springframework/test/context/BootstrapUtils.java @@ -82,7 +82,7 @@ static BootstrapContext createBootstrapContext(Class testClass) { ClassUtils.forName(className, BootstrapUtils.class.getClassLoader()); Constructor constructor = clazz.getConstructor(Class.class, CacheAwareContextLoaderDelegate.class); - logger.debug(LogMessage.format("Instantiating BootstrapContext using constructor [%s]", constructor)); + logger.trace(LogMessage.format("Instantiating BootstrapContext using constructor [%s]", constructor)); return BeanUtils.instantiateClass(constructor, testClass, cacheAwareContextLoaderDelegate); } catch (Throwable ex) { @@ -97,7 +97,7 @@ private static CacheAwareContextLoaderDelegate createCacheAwareContextLoaderDele try { clazz = (Class) ClassUtils.forName(className, BootstrapUtils.class.getClassLoader()); - logger.debug(LogMessage.format("Instantiating CacheAwareContextLoaderDelegate from class [%s]", className)); + logger.trace(LogMessage.format("Instantiating CacheAwareContextLoaderDelegate from class [%s]", className)); return BeanUtils.instantiateClass(clazz, CacheAwareContextLoaderDelegate.class); } catch (Throwable ex) { @@ -151,7 +151,7 @@ static TestContextBootstrapper resolveTestContextBootstrapper(BootstrapContext b if (clazz == null) { clazz = resolveDefaultTestContextBootstrapper(testClass); } - logger.debug(LogMessage.format("Instantiating TestContextBootstrapper for test class [%s] from class [%s]", + logger.trace(LogMessage.format("Instantiating TestContextBootstrapper for test class [%s] from class [%s]", testClass.getName(), clazz.getName())); TestContextBootstrapper testContextBootstrapper = BeanUtils.instantiateClass(clazz, TestContextBootstrapper.class); diff --git a/spring-test/src/main/java/org/springframework/test/context/ContextConfigurationAttributes.java b/spring-test/src/main/java/org/springframework/test/context/ContextConfigurationAttributes.java index 7b2e275c2b3d..e7e598bfdfd6 100644 --- a/spring-test/src/main/java/org/springframework/test/context/ContextConfigurationAttributes.java +++ b/spring-test/src/main/java/org/springframework/test/context/ContextConfigurationAttributes.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2021 the original author or authors. + * Copyright 2002-2022 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -23,6 +23,8 @@ import org.springframework.context.ApplicationContextInitializer; import org.springframework.core.annotation.AnnotationAttributes; +import org.springframework.core.style.DefaultToStringStyler; +import org.springframework.core.style.SimpleValueStyler; import org.springframework.core.style.ToStringCreator; import org.springframework.lang.Nullable; import org.springframework.util.Assert; @@ -368,15 +370,15 @@ public int hashCode() { */ @Override public String toString() { - return new ToStringCreator(this) - .append("declaringClass", this.declaringClass.getName()) - .append("classes", ObjectUtils.nullSafeToString(this.classes)) - .append("locations", ObjectUtils.nullSafeToString(this.locations)) + return new ToStringCreator(this, new DefaultToStringStyler(new SimpleValueStyler())) + .append("declaringClass", this.declaringClass) + .append("classes", this.classes) + .append("locations", this.locations) .append("inheritLocations", this.inheritLocations) - .append("initializers", ObjectUtils.nullSafeToString(this.initializers)) + .append("initializers", this.initializers) .append("inheritInitializers", this.inheritInitializers) .append("name", this.name) - .append("contextLoaderClass", this.contextLoaderClass.getName()) + .append("contextLoaderClass", this.contextLoaderClass) .toString(); } diff --git a/spring-test/src/main/java/org/springframework/test/context/MergedContextConfiguration.java b/spring-test/src/main/java/org/springframework/test/context/MergedContextConfiguration.java index cee892eec852..05427a80dacb 100644 --- a/spring-test/src/main/java/org/springframework/test/context/MergedContextConfiguration.java +++ b/spring-test/src/main/java/org/springframework/test/context/MergedContextConfiguration.java @@ -24,6 +24,8 @@ import org.springframework.context.ApplicationContext; import org.springframework.context.ApplicationContextInitializer; +import org.springframework.core.style.DefaultToStringStyler; +import org.springframework.core.style.SimpleValueStyler; import org.springframework.core.style.ToStringCreator; import org.springframework.lang.Nullable; import org.springframework.util.Assert; @@ -495,16 +497,16 @@ public int hashCode() { */ @Override public String toString() { - return new ToStringCreator(this) + return new ToStringCreator(this, new DefaultToStringStyler(new SimpleValueStyler())) .append("testClass", this.testClass) - .append("locations", ObjectUtils.nullSafeToString(this.locations)) - .append("classes", ObjectUtils.nullSafeToString(this.classes)) - .append("contextInitializerClasses", ObjectUtils.nullSafeToString(this.contextInitializerClasses)) - .append("activeProfiles", ObjectUtils.nullSafeToString(this.activeProfiles)) - .append("propertySourceLocations", ObjectUtils.nullSafeToString(this.propertySourceLocations)) - .append("propertySourceProperties", ObjectUtils.nullSafeToString(this.propertySourceProperties)) + .append("locations", this.locations) + .append("classes", this.classes) + .append("contextInitializerClasses", this.contextInitializerClasses) + .append("activeProfiles", this.activeProfiles) + .append("propertySourceLocations", this.propertySourceLocations) + .append("propertySourceProperties", this.propertySourceProperties) .append("contextCustomizers", this.contextCustomizers) - .append("contextLoader", nullSafeClassName(this.contextLoader)) + .append("contextLoader", (this.contextLoader != null ? this.contextLoader.getClass() : null)) .append("parent", this.parent) .toString(); } diff --git a/spring-test/src/main/java/org/springframework/test/context/TestContextAnnotationUtils.java b/spring-test/src/main/java/org/springframework/test/context/TestContextAnnotationUtils.java index 7b6aaaee129d..3ac913d5f7ee 100644 --- a/spring-test/src/main/java/org/springframework/test/context/TestContextAnnotationUtils.java +++ b/spring-test/src/main/java/org/springframework/test/context/TestContextAnnotationUtils.java @@ -31,6 +31,8 @@ import org.springframework.core.annotation.MergedAnnotations; import org.springframework.core.annotation.MergedAnnotations.SearchStrategy; import org.springframework.core.annotation.RepeatableContainers; +import org.springframework.core.style.DefaultToStringStyler; +import org.springframework.core.style.SimpleValueStyler; import org.springframework.core.style.ToStringCreator; import org.springframework.lang.Nullable; import org.springframework.test.context.NestedTestConfiguration.EnclosingConfiguration; @@ -585,9 +587,9 @@ public Set findAllLocalMergedAnnotations() { */ @Override public String toString() { - return new ToStringCreator(this) - .append("rootDeclaringClass", this.rootDeclaringClass.getName()) - .append("declaringClass", this.declaringClass.getName()) + return new ToStringCreator(this, new DefaultToStringStyler(new SimpleValueStyler())) + .append("rootDeclaringClass", this.rootDeclaringClass) + .append("declaringClass", this.declaringClass) .append("annotation", this.annotation) .toString(); } diff --git a/spring-test/src/main/java/org/springframework/test/context/aot/AotTestContextInitializersCodeGenerator.java b/spring-test/src/main/java/org/springframework/test/context/aot/AotTestContextInitializersCodeGenerator.java index 6dfff838291a..7e04d00863d5 100644 --- a/spring-test/src/main/java/org/springframework/test/context/aot/AotTestContextInitializersCodeGenerator.java +++ b/spring-test/src/main/java/org/springframework/test/context/aot/AotTestContextInitializersCodeGenerator.java @@ -123,7 +123,7 @@ private CodeBlock generateContextInitializersMappingCode() { code.addStatement("$T map = new $T<>()", CONTEXT_INITIALIZER_SUPPLIER_MAP, HashMap.class); this.initializerClassMappings.forEach((className, testClasses) -> { List testClassNames = testClasses.stream().map(Class::getName).toList(); - logger.debug(LogMessage.format( + logger.trace(LogMessage.format( "Generating mapping from AOT context initializer supplier [%s] to test classes %s", className.reflectionName(), testClassNames)); testClassNames.forEach(testClassName -> @@ -146,7 +146,7 @@ private CodeBlock generateContextInitializerClassesMappingCode() { code.addStatement("$T map = new $T<>()", CONTEXT_INITIALIZER_CLASS_MAP, HashMap.class); this.initializerClassMappings.forEach((className, testClasses) -> { List testClassNames = testClasses.stream().map(Class::getName).toList(); - logger.debug(LogMessage.format( + logger.trace(LogMessage.format( "Generating mapping from AOT context initializer class [%s] to test classes %s", className.reflectionName(), testClassNames)); testClassNames.forEach(testClassName -> diff --git a/spring-test/src/main/java/org/springframework/test/context/cache/AotMergedContextConfiguration.java b/spring-test/src/main/java/org/springframework/test/context/cache/AotMergedContextConfiguration.java index 101d7c347777..8ee994362320 100644 --- a/spring-test/src/main/java/org/springframework/test/context/cache/AotMergedContextConfiguration.java +++ b/spring-test/src/main/java/org/springframework/test/context/cache/AotMergedContextConfiguration.java @@ -19,6 +19,8 @@ import java.util.Collections; import org.springframework.context.ApplicationContextInitializer; +import org.springframework.core.style.DefaultToStringStyler; +import org.springframework.core.style.SimpleValueStyler; import org.springframework.core.style.ToStringCreator; import org.springframework.lang.Nullable; import org.springframework.test.context.CacheAwareContextLoaderDelegate; @@ -82,9 +84,9 @@ public int hashCode() { @Override public String toString() { - return new ToStringCreator(this) - .append("testClass", getTestClass().getName()) - .append("contextInitializerClass", this.contextInitializerClass.getName()) + return new ToStringCreator(this, new DefaultToStringStyler(new SimpleValueStyler())) + .append("testClass", getTestClass()) + .append("contextInitializerClass", this.contextInitializerClass) .append("original", this.original) .toString(); } diff --git a/spring-test/src/main/java/org/springframework/test/context/cache/DefaultCacheAwareContextLoaderDelegate.java b/spring-test/src/main/java/org/springframework/test/context/cache/DefaultCacheAwareContextLoaderDelegate.java index 3a357dc62cbb..fea89f746279 100644 --- a/spring-test/src/main/java/org/springframework/test/context/cache/DefaultCacheAwareContextLoaderDelegate.java +++ b/spring-test/src/main/java/org/springframework/test/context/cache/DefaultCacheAwareContextLoaderDelegate.java @@ -23,7 +23,6 @@ import org.springframework.context.ApplicationContextInitializer; import org.springframework.context.ConfigurableApplicationContext; import org.springframework.context.support.GenericApplicationContext; -import org.springframework.core.log.LogMessage; import org.springframework.lang.Nullable; import org.springframework.test.annotation.DirtiesContext.HierarchyMode; import org.springframework.test.context.ApplicationContextFailureProcessor; @@ -108,8 +107,8 @@ public ApplicationContext loadContext(MergedContextConfiguration mergedContextCo else { context = loadContextInternal(mergedContextConfiguration); } - if (logger.isDebugEnabled()) { - logger.debug("Storing ApplicationContext [%s] in cache under key %s".formatted( + if (logger.isTraceEnabled()) { + logger.trace("Storing ApplicationContext [%s] in cache under key %s".formatted( System.identityHashCode(context), mergedContextConfiguration)); } this.contextCache.put(mergedContextConfiguration, context); @@ -135,8 +134,8 @@ public ApplicationContext loadContext(MergedContextConfiguration mergedContextCo } } else { - if (logger.isDebugEnabled()) { - logger.debug("Retrieved ApplicationContext [%s] from cache with key %s".formatted( + if (logger.isTraceEnabled()) { + logger.trace("Retrieved ApplicationContext [%s] from cache with key %s".formatted( System.identityHashCode(context), mergedContextConfiguration)); } } @@ -198,7 +197,15 @@ protected ApplicationContext loadContextInAotMode(AotMergedContextConfiguration () -> "Failed to load AOT ApplicationContextInitializer for test class [%s]" .formatted(testClass.getName())); ContextLoader contextLoader = getContextLoader(aotMergedConfig); - logger.info(LogMessage.format("Loading ApplicationContext in AOT mode for %s", aotMergedConfig.getOriginal())); + + if (logger.isTraceEnabled()) { + logger.trace("Loading ApplicationContext for AOT runtime for " + aotMergedConfig.getOriginal()); + } + else if (logger.isDebugEnabled()) { + logger.debug("Loading ApplicationContext for AOT runtime for test class " + + aotMergedConfig.getTestClass().getName()); + } + if (!((contextLoader instanceof AotContextLoader aotContextLoader) && (aotContextLoader.loadContextForAotRuntime(aotMergedConfig.getOriginal(), contextInitializer) instanceof GenericApplicationContext gac))) { diff --git a/spring-test/src/main/java/org/springframework/test/context/jdbc/MergedSqlConfig.java b/spring-test/src/main/java/org/springframework/test/context/jdbc/MergedSqlConfig.java index 8130ddd3b8bb..7fdeb98ef2e9 100644 --- a/spring-test/src/main/java/org/springframework/test/context/jdbc/MergedSqlConfig.java +++ b/spring-test/src/main/java/org/springframework/test/context/jdbc/MergedSqlConfig.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2021 the original author or authors. + * Copyright 2002-2022 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -21,6 +21,8 @@ import org.springframework.core.annotation.AnnotationAttributes; import org.springframework.core.annotation.AnnotationUtils; +import org.springframework.core.style.DefaultToStringStyler; +import org.springframework.core.style.SimpleValueStyler; import org.springframework.core.style.ToStringCreator; import org.springframework.jdbc.datasource.init.ScriptUtils; import org.springframework.lang.Nullable; @@ -210,7 +212,7 @@ ErrorMode getErrorMode() { */ @Override public String toString() { - return new ToStringCreator(this) + return new ToStringCreator(this, new DefaultToStringStyler(new SimpleValueStyler())) .append("dataSource", this.dataSource) .append("transactionManager", this.transactionManager) .append("transactionMode", this.transactionMode) diff --git a/spring-test/src/main/java/org/springframework/test/context/jdbc/SqlScriptsTestExecutionListener.java b/spring-test/src/main/java/org/springframework/test/context/jdbc/SqlScriptsTestExecutionListener.java index 081ee897e55e..92bbb02e6986 100644 --- a/spring-test/src/main/java/org/springframework/test/context/jdbc/SqlScriptsTestExecutionListener.java +++ b/spring-test/src/main/java/org/springframework/test/context/jdbc/SqlScriptsTestExecutionListener.java @@ -247,9 +247,13 @@ private void executeSqlScripts( } MergedSqlConfig mergedSqlConfig = new MergedSqlConfig(sql.config(), testContext.getTestClass()); - if (logger.isDebugEnabled()) { - logger.debug(String.format("Processing %s for execution phase [%s] and test context %s.", - mergedSqlConfig, executionPhase, testContext)); + if (logger.isTraceEnabled()) { + logger.trace("Processing %s for execution phase [%s] and test context %s" + .formatted(mergedSqlConfig, executionPhase, testContext)); + } + else if (logger.isDebugEnabled()) { + logger.debug("Processing merged @SqlConfig attributes for execution phase [%s] and test class [%s]" + .formatted(executionPhase, testContext.getTestClass().getName())); } String[] scripts = getScripts(sql, testContext.getTestClass(), testContext.getTestMethod(), classLevel); @@ -265,7 +269,7 @@ private void executeSqlScripts( ResourceDatabasePopulator populator = createDatabasePopulator(mergedSqlConfig); populator.setScripts(scriptResources.toArray(new Resource[0])); if (logger.isDebugEnabled()) { - logger.debug("Executing SQL scripts: " + ObjectUtils.nullSafeToString(scriptResources)); + logger.debug("Executing SQL scripts: " + scriptResources); } String dsName = mergedSqlConfig.getDataSource(); @@ -372,9 +376,9 @@ private String detectDefaultScript(Class testClass, Method testMethod, boolea ClassPathResource classPathResource = new ClassPathResource(resourcePath); if (classPathResource.exists()) { - if (logger.isInfoEnabled()) { - logger.info(String.format("Detected default SQL script \"%s\" for test %s [%s]", - prefixedResourcePath, elementType, elementName)); + if (logger.isDebugEnabled()) { + logger.debug("Detected default SQL script \"%s\" for test %s [%s]" + .formatted(prefixedResourcePath, elementType, elementName)); } return prefixedResourcePath; } diff --git a/spring-test/src/main/java/org/springframework/test/context/junit4/SpringJUnit4ClassRunner.java b/spring-test/src/main/java/org/springframework/test/context/junit4/SpringJUnit4ClassRunner.java index f5bf4690f529..66e9c3a16ba4 100644 --- a/spring-test/src/main/java/org/springframework/test/context/junit4/SpringJUnit4ClassRunner.java +++ b/spring-test/src/main/java/org/springframework/test/context/junit4/SpringJUnit4ClassRunner.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2019 the original author or authors. + * Copyright 2002-2022 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -135,8 +135,9 @@ private static void ensureSpringRulesAreNotPresent(Class testClass) { */ public SpringJUnit4ClassRunner(Class clazz) throws InitializationError { super(clazz); - if (logger.isDebugEnabled()) { - logger.debug("SpringJUnit4ClassRunner constructor called with [" + clazz + "]"); + if (logger.isTraceEnabled()) { + logger.trace("SpringJUnit4ClassRunner constructor called with [%s]" + .formatted((clazz != null ? clazz.getName() : null))); } ensureSpringRulesAreNotPresent(clazz); this.testContextManager = createTestContextManager(clazz); diff --git a/spring-test/src/main/java/org/springframework/test/context/junit4/statements/SpringRepeat.java b/spring-test/src/main/java/org/springframework/test/context/junit4/statements/SpringRepeat.java index 4f4f45592b28..b7277f364dec 100644 --- a/spring-test/src/main/java/org/springframework/test/context/junit4/statements/SpringRepeat.java +++ b/spring-test/src/main/java/org/springframework/test/context/junit4/statements/SpringRepeat.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2015 the original author or authors. + * Copyright 2002-2022 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -77,8 +77,8 @@ public SpringRepeat(Statement next, Method testMethod, int repeat) { @Override public void evaluate() throws Throwable { for (int i = 0; i < this.repeat; i++) { - if (this.repeat > 1 && logger.isInfoEnabled()) { - logger.info(String.format("Repetition %d of test %s#%s()", (i + 1), + if (this.repeat > 1 && logger.isTraceEnabled()) { + logger.trace(String.format("Repetition %d of test %s#%s()", (i + 1), this.testMethod.getDeclaringClass().getSimpleName(), this.testMethod.getName())); } this.next.evaluate(); diff --git a/spring-test/src/main/java/org/springframework/test/context/support/AbstractContextLoader.java b/spring-test/src/main/java/org/springframework/test/context/support/AbstractContextLoader.java index 25a29fec55a4..67a249a28c38 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/AbstractContextLoader.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/AbstractContextLoader.java @@ -255,20 +255,20 @@ protected String[] generateDefaultLocations(Class clazz) { ClassPathResource classPathResource = new ClassPathResource(resourcePath); if (classPathResource.exists()) { String prefixedResourcePath = ResourceUtils.CLASSPATH_URL_PREFIX + SLASH + resourcePath; - if (logger.isInfoEnabled()) { - logger.info(String.format("Detected default resource location \"%s\" for test class [%s]", + if (logger.isDebugEnabled()) { + logger.debug(String.format("Detected default resource location \"%s\" for test class [%s]", prefixedResourcePath, clazz.getName())); } return new String[] {prefixedResourcePath}; } - else if (logger.isDebugEnabled()) { - logger.debug(String.format("Did not detect default resource location for test class [%s]: " + + else if (logger.isTraceEnabled()) { + logger.trace(String.format("Did not detect default resource location for test class [%s]: " + "%s does not exist", clazz.getName(), classPathResource)); } } - if (logger.isInfoEnabled()) { - logger.info(String.format("Could not detect default resource locations for test class [%s]: " + + if (logger.isDebugEnabled()) { + logger.debug(String.format("Could not detect default resource locations for test class [%s]: " + "no resource found for suffixes %s.", clazz.getName(), ObjectUtils.nullSafeToString(suffixes))); } diff --git a/spring-test/src/main/java/org/springframework/test/context/support/AbstractDelegatingSmartContextLoader.java b/spring-test/src/main/java/org/springframework/test/context/support/AbstractDelegatingSmartContextLoader.java index a9a99045786a..c4e215c06d08 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/AbstractDelegatingSmartContextLoader.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/AbstractDelegatingSmartContextLoader.java @@ -148,28 +148,28 @@ else if (configAttributes.hasClasses()) { boolean xmlLoaderDetectedDefaults = configAttributes.hasLocations(); if (xmlLoaderDetectedDefaults) { - if (logger.isInfoEnabled()) { - logger.info(String.format("%s detected default locations for context configuration %s.", + if (logger.isTraceEnabled()) { + logger.trace(String.format("%s detected default locations for context configuration %s", name(getXmlLoader()), configAttributes)); } } Assert.state(!configAttributes.hasClasses(), () -> String.format( - "%s should NOT have detected default configuration classes for context configuration %s.", + "%s should NOT have detected default configuration classes for context configuration %s", name(getXmlLoader()), configAttributes)); // Now let the annotation config loader process the configuration. delegateProcessing(getAnnotationConfigLoader(), configAttributes); if (configAttributes.hasClasses()) { - if (logger.isInfoEnabled()) { - logger.info(String.format("%s detected default configuration classes for context configuration %s.", + if (logger.isTraceEnabled()) { + logger.trace(String.format("%s detected default configuration classes for context configuration %s", name(getAnnotationConfigLoader()), configAttributes)); } } Assert.state(xmlLoaderDetectedDefaults || !configAttributes.hasLocations(), () -> String.format( - "%s should NOT have detected default locations for context configuration %s.", + "%s should NOT have detected default locations for context configuration %s", name(getAnnotationConfigLoader()), configAttributes)); if (configAttributes.hasLocations() && configAttributes.hasClasses()) { @@ -206,8 +206,8 @@ else if (configAttributes.hasClasses()) { @Override public final ApplicationContext loadContext(MergedContextConfiguration mergedConfig) throws Exception { SmartContextLoader loader = getContextLoader(mergedConfig); - if (logger.isDebugEnabled()) { - logger.debug("Delegating to %s to load context for %s".formatted(name(loader), mergedConfig)); + if (logger.isTraceEnabled()) { + logger.trace("Delegating to %s to load context for %s".formatted(name(loader), mergedConfig)); } return loader.loadContext(mergedConfig); } @@ -229,8 +229,8 @@ public final ApplicationContext loadContext(MergedContextConfiguration mergedCon @Override public final ApplicationContext loadContextForAotProcessing(MergedContextConfiguration mergedConfig) throws Exception { AotContextLoader loader = getAotContextLoader(mergedConfig); - if (logger.isDebugEnabled()) { - logger.debug("Delegating to %s to load context for AOT processing for %s" + if (logger.isTraceEnabled()) { + logger.trace("Delegating to %s to load context for AOT processing for %s" .formatted(name(loader), mergedConfig)); } return loader.loadContextForAotProcessing(mergedConfig); @@ -256,8 +256,8 @@ public final ApplicationContext loadContextForAotRuntime(MergedContextConfigurat ApplicationContextInitializer initializer) throws Exception { AotContextLoader loader = getAotContextLoader(mergedConfig); - if (logger.isDebugEnabled()) { - logger.debug("Delegating to %s to load context for AOT execution for %s" + if (logger.isTraceEnabled()) { + logger.trace("Delegating to %s to load context for AOT execution for %s" .formatted(name(loader), mergedConfig)); } return loader.loadContextForAotRuntime(mergedConfig, initializer); @@ -310,8 +310,9 @@ private boolean supports(SmartContextLoader loader, MergedContextConfiguration m private static void delegateProcessing(SmartContextLoader loader, ContextConfigurationAttributes configAttributes) { - if (logger.isDebugEnabled()) { - logger.debug("Delegating to %s to process context configuration %s.".formatted(name(loader), configAttributes)); + if (logger.isTraceEnabled()) { + logger.trace("Delegating to %s to process context configuration %s" + .formatted(name(loader), configAttributes)); } loader.processContextConfiguration(configAttributes); } diff --git a/spring-test/src/main/java/org/springframework/test/context/support/AbstractDirtiesContextTestExecutionListener.java b/spring-test/src/main/java/org/springframework/test/context/support/AbstractDirtiesContextTestExecutionListener.java index 055029b39729..17586a70294a 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/AbstractDirtiesContextTestExecutionListener.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/AbstractDirtiesContextTestExecutionListener.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2020 the original author or authors. + * Copyright 2002-2022 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -103,11 +103,19 @@ protected void beforeOrAfterTestMethod(TestContext testContext, MethodMode requi MethodMode methodMode = (methodAnnotated ? methodAnn.methodMode() : null); ClassMode classMode = (classAnnotated ? classAnn.classMode() : null); - if (logger.isDebugEnabled()) { - String phase = (requiredClassMode.name().startsWith("BEFORE") ? "Before" : "After"); - logger.debug(String.format("%s test method: context %s, class annotated with @DirtiesContext [%s] " - + "with mode [%s], method annotated with @DirtiesContext [%s] with mode [%s].", phase, testContext, - classAnnotated, classMode, methodAnnotated, methodMode)); + if (logger.isTraceEnabled()) { + logger.trace(""" + %s test method: context %s, class annotated with @DirtiesContext [%s] \ + with mode [%s], method annotated with @DirtiesContext [%s] with mode [%s]""" + .formatted(getPhase(requiredMethodMode), testContext, classAnnotated, classMode, + methodAnnotated, methodMode)); + } + else if (logger.isDebugEnabled()) { + logger.debug(""" + %s test method: class [%s], method [%s], class annotated with @DirtiesContext [%s] \ + with mode [%s], method annotated with @DirtiesContext [%s] with mode [%s]""" + .formatted(getPhase(requiredMethodMode), testClass.getSimpleName(), + testMethod.getName(), classAnnotated, classMode, methodAnnotated, methodMode)); } if ((methodMode == requiredMethodMode) || (classMode == requiredClassMode)) { @@ -138,11 +146,13 @@ protected void beforeOrAfterTestClass(TestContext testContext, ClassMode require boolean classAnnotated = (dirtiesContext != null); ClassMode classMode = (classAnnotated ? dirtiesContext.classMode() : null); - if (logger.isDebugEnabled()) { - String phase = (requiredClassMode.name().startsWith("BEFORE") ? "Before" : "After"); - logger.debug(String.format( - "%s test class: context %s, class annotated with @DirtiesContext [%s] with mode [%s].", phase, - testContext, classAnnotated, classMode)); + if (logger.isTraceEnabled()) { + logger.trace("%s test class: context %s, class annotated with @DirtiesContext [%s] with mode [%s]" + .formatted(getPhase(requiredClassMode), testContext, classAnnotated, classMode)); + } + else if (logger.isDebugEnabled()) { + logger.debug("%s test class: class [%s], class annotated with @DirtiesContext [%s] with mode [%s]" + .formatted(getPhase(requiredClassMode), testClass.getSimpleName(), classAnnotated, classMode)); } if (classMode == requiredClassMode) { @@ -150,4 +160,12 @@ protected void beforeOrAfterTestClass(TestContext testContext, ClassMode require } } + private static String getPhase(ClassMode classMode) { + return (classMode.name().startsWith("BEFORE") ? "Before" : "After"); + } + + private static String getPhase(MethodMode methodMode) { + return (methodMode.name().startsWith("BEFORE") ? "Before" : "After"); + } + } diff --git a/spring-test/src/main/java/org/springframework/test/context/support/AbstractGenericContextLoader.java b/spring-test/src/main/java/org/springframework/test/context/support/AbstractGenericContextLoader.java index 950d7a6c0fd5..5aa4d67dc648 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/AbstractGenericContextLoader.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/AbstractGenericContextLoader.java @@ -153,8 +153,12 @@ public final GenericApplicationContext loadContextForAotRuntime(MergedContextCon Assert.notNull(mergedConfig, "MergedContextConfiguration must not be null"); Assert.notNull(initializer, "ApplicationContextInitializer must not be null"); - if (logger.isDebugEnabled()) { - logger.debug("Loading ApplicationContext for AOT runtime for merged context configuration " + mergedConfig); + if (logger.isTraceEnabled()) { + logger.trace("Loading ApplicationContext for AOT runtime for " + mergedConfig); + } + else if (logger.isDebugEnabled()) { + logger.debug("Loading ApplicationContext for AOT runtime for test class " + + mergedConfig.getTestClass().getName()); } validateMergedContextConfiguration(mergedConfig); @@ -187,9 +191,13 @@ public final GenericApplicationContext loadContextForAotRuntime(MergedContextCon private final GenericApplicationContext loadContext( MergedContextConfiguration mergedConfig, boolean forAotProcessing) throws Exception { - if (logger.isDebugEnabled()) { - logger.debug("Loading ApplicationContext %sfor merged context configuration %s" - .formatted((forAotProcessing ? "for AOT processing " : ""), mergedConfig)); + if (logger.isTraceEnabled()) { + logger.trace("Loading ApplicationContext %sfor %s".formatted( + (forAotProcessing ? "for AOT processing " : ""), mergedConfig)); + } + else if (logger.isDebugEnabled()) { + logger.debug("Loading ApplicationContext %sfor test class %s".formatted( + (forAotProcessing ? "for AOT processing " : ""), mergedConfig.getTestClass().getName())); } validateMergedContextConfiguration(mergedConfig); diff --git a/spring-test/src/main/java/org/springframework/test/context/support/AbstractTestContextBootstrapper.java b/spring-test/src/main/java/org/springframework/test/context/support/AbstractTestContextBootstrapper.java index 6aedc74a0a10..1519df9cd820 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/AbstractTestContextBootstrapper.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/AbstractTestContextBootstrapper.java @@ -123,8 +123,8 @@ public final List getTestExecutionListeners() { // Use defaults? if (descriptor == null) { - if (logger.isDebugEnabled()) { - logger.debug(String.format("@TestExecutionListeners is not present for class [%s]: using defaults.", + if (logger.isTraceEnabled()) { + logger.trace(String.format("@TestExecutionListeners is not present for class [%s]: using defaults.", clazz.getName())); } usingDefaults = true; @@ -147,8 +147,8 @@ public final List getTestExecutionListeners() { // locally declared listeners with the defaults. if ((!inheritListeners || parentDescriptor == null) && testExecutionListeners.mergeMode() == MergeMode.MERGE_WITH_DEFAULTS) { - if (logger.isDebugEnabled()) { - logger.debug(String.format("Merging default listeners with listeners configured via " + + if (logger.isTraceEnabled()) { + logger.trace(String.format("Merging default listeners with listeners configured via " + "@TestExecutionListeners for class [%s].", descriptor.getRootDeclaringClass().getName())); } usingDefaults = true; @@ -176,8 +176,13 @@ public final List getTestExecutionListeners() { AnnotationAwareOrderComparator.sort(listeners); } - if (logger.isInfoEnabled()) { - logger.info("Using TestExecutionListeners: " + listeners); + if (logger.isTraceEnabled()) { + logger.trace("Using TestExecutionListeners for test class [%s]: %s" + .formatted(clazz.getName(), listeners)); + } + else if (logger.isDebugEnabled()) { + logger.debug("Using TestExecutionListeners for test class [%s]: %s" + .formatted(clazz.getSimpleName(), classSimpleNames(listeners))); } return listeners; } @@ -204,8 +209,8 @@ protected List getDefaultTestExecutionListeners() { SpringFactoriesLoader loader = SpringFactoriesLoader.forDefaultResourceLocation(getClass().getClassLoader()); List listeners = loader.load(TestExecutionListener.class, this::handleInstantiationFailure); - if (logger.isDebugEnabled()) { - logger.debug("Loaded default TestExecutionListener implementations from location [%s]: %s" + if (logger.isTraceEnabled()) { + logger.trace("Loaded default TestExecutionListener implementations from location [%s]: %s" .formatted(SpringFactoriesLoader.FACTORIES_RESOURCE_LOCATION, classNames(listeners))); } return Collections.unmodifiableList(listeners); @@ -284,10 +289,15 @@ private MergedContextConfiguration buildDefaultMergedContextConfiguration(Class< Collections.singletonList(new ContextConfigurationAttributes(testClass)); ContextLoader contextLoader = resolveContextLoader(testClass, defaultConfigAttributesList); - if (logger.isInfoEnabled()) { - logger.info(String.format( - "Neither @ContextConfiguration nor @ContextHierarchy found for test class [%s], using %s", - testClass.getName(), contextLoader.getClass().getSimpleName())); + if (logger.isTraceEnabled()) { + logger.trace(String.format( + "Neither @ContextConfiguration nor @ContextHierarchy found for test class [%s]: using %s", + testClass.getName(), contextLoader.getClass().getName())); + } + else if (logger.isDebugEnabled()) { + logger.debug(String.format( + "Neither @ContextConfiguration nor @ContextHierarchy found for test class [%s]: using %s", + testClass.getSimpleName(), contextLoader.getClass().getSimpleName())); } return buildMergedContextConfiguration(testClass, defaultConfigAttributesList, null, cacheAwareContextLoaderDelegate, false); @@ -387,8 +397,13 @@ private Set getContextCustomizers(Class testClass, customizers.add(customizer); } } - if (logger.isInfoEnabled()) { - logger.info("Using ContextCustomizers: " + customizers); + if (logger.isTraceEnabled()) { + logger.trace("Using ContextCustomizers for test class [%s]: %s" + .formatted(testClass.getName(), customizers)); + } + else if (logger.isDebugEnabled()) { + logger.debug("Using ContextCustomizers for test class [%s]: %s" + .formatted(testClass.getSimpleName(), classSimpleNames(customizers))); } return customizers; } @@ -405,8 +420,8 @@ protected List getContextCustomizerFactories() { SpringFactoriesLoader loader = SpringFactoriesLoader.forDefaultResourceLocation(getClass().getClassLoader()); List factories = loader.load(ContextCustomizerFactory.class, this::handleInstantiationFailure); - if (logger.isDebugEnabled()) { - logger.debug("Loaded ContextCustomizerFactory implementations from location [%s]: %s" + if (logger.isTraceEnabled()) { + logger.trace("Loaded ContextCustomizerFactory implementations from location [%s]: %s" .formatted(SpringFactoriesLoader.FACTORIES_RESOURCE_LOCATION, classNames(factories))); } return factories; @@ -476,15 +491,17 @@ protected Class resolveExplicitContextLoaderClass( for (ContextConfigurationAttributes configAttributes : configAttributesList) { if (logger.isTraceEnabled()) { - logger.trace(String.format("Resolving ContextLoader for context configuration attributes %s", - configAttributes)); + logger.trace("Resolving ContextLoader for context configuration attributes " + configAttributes); } Class contextLoaderClass = configAttributes.getContextLoaderClass(); if (ContextLoader.class != contextLoaderClass) { - if (logger.isDebugEnabled()) { - logger.debug(String.format( - "Found explicit ContextLoader class [%s] for context configuration attributes %s", - contextLoaderClass.getName(), configAttributes)); + if (logger.isTraceEnabled()) { + logger.trace("Found explicit ContextLoader class [%s] for context configuration attributes %s" + .formatted(contextLoaderClass.getName(), configAttributes)); + } + else if (logger.isDebugEnabled()) { + logger.debug("Found explicit ContextLoader class [%s] for test class [%s]" + .formatted(contextLoaderClass.getSimpleName(), configAttributes.getDeclaringClass().getSimpleName())); } return contextLoaderClass; } @@ -597,7 +614,11 @@ private void logSkippedComponent(Class factoryType, String factoryImplementat } - private static List classNames(List components) { + private static List classSimpleNames(Collection components) { + return components.stream().map(Object::getClass).map(Class::getSimpleName).toList(); + } + + private static List classNames(Collection components) { return components.stream().map(Object::getClass).map(Class::getName).toList(); } diff --git a/spring-test/src/main/java/org/springframework/test/context/support/ActiveProfilesUtils.java b/spring-test/src/main/java/org/springframework/test/context/support/ActiveProfilesUtils.java index b994e7778427..719591efd11d 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/ActiveProfilesUtils.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/ActiveProfilesUtils.java @@ -76,10 +76,9 @@ static String[] resolveActiveProfiles(Class testClass) { AnnotationDescriptor descriptor = findAnnotationDescriptor(testClass, ActiveProfiles.class); List profileArrays = new ArrayList<>(); - if (descriptor == null && logger.isDebugEnabled()) { - logger.debug(String.format( - "Could not find an 'annotation declaring class' for annotation type [%s] and class [%s]", - ActiveProfiles.class.getName(), testClass.getName())); + if (descriptor == null && logger.isTraceEnabled()) { + logger.trace("Could not find an 'annotation declaring class' for annotation type [%s] and class [%s]" + .formatted(ActiveProfiles.class.getName(), testClass.getName())); } while (descriptor != null) { @@ -87,8 +86,8 @@ static String[] resolveActiveProfiles(Class testClass) { ActiveProfiles annotation = descriptor.getAnnotation(); if (logger.isTraceEnabled()) { - logger.trace(String.format("Retrieved @ActiveProfiles [%s] for declaring class [%s]", - annotation, descriptor.getDeclaringClass().getName())); + logger.trace("Retrieved @ActiveProfiles [%s] for declaring class [%s]" + .formatted(annotation, descriptor.getDeclaringClass().getName())); } ActiveProfilesResolver resolver; @@ -101,8 +100,8 @@ static String[] resolveActiveProfiles(Class testClass) { resolver = BeanUtils.instantiateClass(resolverClass, ActiveProfilesResolver.class); } catch (Exception ex) { - String msg = String.format("Could not instantiate ActiveProfilesResolver of type [%s] " + - "for test class [%s]", resolverClass.getName(), rootDeclaringClass.getName()); + String msg = "Could not instantiate ActiveProfilesResolver of type [%s] for test class [%s]" + .formatted(resolverClass.getName(), rootDeclaringClass.getName()); logger.error(msg); throw new IllegalStateException(msg, ex); } diff --git a/spring-test/src/main/java/org/springframework/test/context/support/AnnotationConfigContextLoader.java b/spring-test/src/main/java/org/springframework/test/context/support/AnnotationConfigContextLoader.java index cc2b7286eb1b..8e195d5f2740 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/AnnotationConfigContextLoader.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/AnnotationConfigContextLoader.java @@ -17,6 +17,7 @@ package org.springframework.test.context.support; import java.util.Arrays; +import java.util.List; import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; @@ -183,11 +184,15 @@ protected void validateMergedContextConfiguration(MergedContextConfiguration mer protected void loadBeanDefinitions(GenericApplicationContext context, MergedContextConfiguration mergedConfig) { Class[] componentClasses = mergedConfig.getClasses(); if (logger.isDebugEnabled()) { - logger.debug("Registering component classes: " + Arrays.toString(componentClasses)); + logger.debug("Registering component classes: " + classNames(componentClasses)); } new AnnotatedBeanDefinitionReader(context).register(componentClasses); } + private static List classNames(Class... classes) { + return Arrays.stream(classes).map(Class::getName).toList(); + } + /** * {@code AnnotationConfigContextLoader} should be used as a * {@link org.springframework.test.context.SmartContextLoader SmartContextLoader}, diff --git a/spring-test/src/main/java/org/springframework/test/context/support/DefaultActiveProfilesResolver.java b/spring-test/src/main/java/org/springframework/test/context/support/DefaultActiveProfilesResolver.java index a15606d1b728..5f68a4d8b71d 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/DefaultActiveProfilesResolver.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/DefaultActiveProfilesResolver.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2020 the original author or authors. + * Copyright 2002-2022 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -59,8 +59,8 @@ public String[] resolve(Class testClass) { AnnotationDescriptor descriptor = findAnnotationDescriptor(testClass, ActiveProfiles.class); if (descriptor == null) { - if (logger.isDebugEnabled()) { - logger.debug(String.format( + if (logger.isTraceEnabled()) { + logger.trace(String.format( "Could not find an 'annotation declaring class' for annotation type [%s] and class [%s]", ActiveProfiles.class.getName(), testClass.getName())); } diff --git a/spring-test/src/main/java/org/springframework/test/context/support/DefaultBootstrapContext.java b/spring-test/src/main/java/org/springframework/test/context/support/DefaultBootstrapContext.java index 68fd09879269..23a8ba1c4b16 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/DefaultBootstrapContext.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/DefaultBootstrapContext.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2018 the original author or authors. + * Copyright 2002-2022 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -16,6 +16,8 @@ package org.springframework.test.context.support; +import org.springframework.core.style.DefaultToStringStyler; +import org.springframework.core.style.SimpleValueStyler; import org.springframework.core.style.ToStringCreator; import org.springframework.test.context.BootstrapContext; import org.springframework.test.context.CacheAwareContextLoaderDelegate; @@ -67,10 +69,10 @@ public CacheAwareContextLoaderDelegate getCacheAwareContextLoaderDelegate() { */ @Override public String toString() { - return new ToStringCreator(this)// - .append("testClass", this.testClass.getName())// - .append("cacheAwareContextLoaderDelegate", this.cacheAwareContextLoaderDelegate.getClass().getName())// - .toString(); + return new ToStringCreator(this, new DefaultToStringStyler(new SimpleValueStyler())) + .append("testClass", this.testClass) + .append("cacheAwareContextLoaderDelegate", this.cacheAwareContextLoaderDelegate.getClass()) + .toString(); } } diff --git a/spring-test/src/main/java/org/springframework/test/context/support/DefaultTestContext.java b/spring-test/src/main/java/org/springframework/test/context/support/DefaultTestContext.java index c13727517644..9a6941346359 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/DefaultTestContext.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/DefaultTestContext.java @@ -23,6 +23,8 @@ import org.springframework.context.ApplicationContext; import org.springframework.context.ConfigurableApplicationContext; +import org.springframework.core.style.DefaultToStringStyler; +import org.springframework.core.style.SimpleValueStyler; import org.springframework.core.style.ToStringCreator; import org.springframework.lang.Nullable; import org.springframework.test.annotation.DirtiesContext.HierarchyMode; @@ -238,7 +240,7 @@ public String[] attributeNames() { */ @Override public String toString() { - return new ToStringCreator(this) + return new ToStringCreator(this, new DefaultToStringStyler(new SimpleValueStyler())) .append("testClass", this.testClass) .append("testInstance", this.testInstance) .append("testMethod", this.testMethod) diff --git a/spring-test/src/main/java/org/springframework/test/context/support/DependencyInjectionTestExecutionListener.java b/spring-test/src/main/java/org/springframework/test/context/support/DependencyInjectionTestExecutionListener.java index bba77ea45767..ca6648346edf 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/DependencyInjectionTestExecutionListener.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/DependencyInjectionTestExecutionListener.java @@ -84,8 +84,11 @@ public final int getOrder() { */ @Override public void prepareTestInstance(TestContext testContext) throws Exception { - if (logger.isDebugEnabled()) { - logger.debug("Performing dependency injection for test context " + testContext); + if (logger.isTraceEnabled()) { + logger.trace("Performing dependency injection for test context " + testContext); + } + else if (logger.isDebugEnabled()) { + logger.debug("Performing dependency injection for test class " + testContext.getTestClass().getName()); } if (runningInAotMode(testContext.getTestClass())) { injectDependenciesInAotMode(testContext); @@ -105,8 +108,11 @@ public void prepareTestInstance(TestContext testContext) throws Exception { @Override public void beforeTestMethod(TestContext testContext) throws Exception { if (Boolean.TRUE.equals(testContext.getAttribute(REINJECT_DEPENDENCIES_ATTRIBUTE))) { - if (logger.isDebugEnabled()) { - logger.debug("Reinjecting dependencies for test context [" + testContext + "]."); + if (logger.isTraceEnabled()) { + logger.trace("Reinjecting dependencies for test context " + testContext); + } + else if (logger.isDebugEnabled()) { + logger.debug("Reinjecting dependencies for test class " + testContext.getTestClass().getName()); } if (runningInAotMode(testContext.getTestClass())) { injectDependenciesInAotMode(testContext); diff --git a/spring-test/src/main/java/org/springframework/test/context/support/MergedTestPropertySources.java b/spring-test/src/main/java/org/springframework/test/context/support/MergedTestPropertySources.java index 0ffa7689ef5b..89e985808fdc 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/MergedTestPropertySources.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/MergedTestPropertySources.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2020 the original author or authors. + * Copyright 2002-2022 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -18,6 +18,8 @@ import java.util.Arrays; +import org.springframework.core.style.DefaultToStringStyler; +import org.springframework.core.style.SimpleValueStyler; import org.springframework.core.style.ToStringCreator; import org.springframework.lang.Nullable; import org.springframework.test.context.TestPropertySource; @@ -125,9 +127,9 @@ public int hashCode() { */ @Override public String toString() { - return new ToStringCreator(this) - .append("locations", Arrays.toString(this.locations)) - .append("properties", Arrays.toString(this.properties)) + return new ToStringCreator(this, new DefaultToStringStyler(new SimpleValueStyler())) + .append("locations", this.locations) + .append("properties", this.properties) .toString(); } diff --git a/spring-test/src/main/java/org/springframework/test/context/support/TestPropertySourceAttributes.java b/spring-test/src/main/java/org/springframework/test/context/support/TestPropertySourceAttributes.java index a91b103be701..25f5ad158d53 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/TestPropertySourceAttributes.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/TestPropertySourceAttributes.java @@ -26,6 +26,8 @@ import org.springframework.core.annotation.MergedAnnotation; import org.springframework.core.io.ClassPathResource; import org.springframework.core.log.LogMessage; +import org.springframework.core.style.DefaultToStringStyler; +import org.springframework.core.style.SimpleValueStyler; import org.springframework.core.style.ToStringCreator; import org.springframework.lang.Nullable; import org.springframework.test.context.TestPropertySource; @@ -159,8 +161,8 @@ private String detectDefaultPropertiesFile(Class testClass) { throw new IllegalStateException(msg); } String prefixedResourcePath = ResourceUtils.CLASSPATH_URL_PREFIX + SLASH + resourcePath; - if (logger.isInfoEnabled()) { - logger.info(String.format("Detected default properties file \"%s\" for test class [%s]", + if (logger.isDebugEnabled()) { + logger.debug(String.format("Detected default properties file \"%s\" for test class [%s]", prefixedResourcePath, testClass.getName())); } return prefixedResourcePath; @@ -262,8 +264,8 @@ public int hashCode() { */ @Override public String toString() { - return new ToStringCreator(this) - .append("declaringClass", this.declaringClass.getName()) + return new ToStringCreator(this, new DefaultToStringStyler(new SimpleValueStyler())) + .append("declaringClass", this.declaringClass) .append("locations", this.locations) .append("inheritLocations", this.inheritLocations) .append("properties", this.properties) diff --git a/spring-test/src/main/java/org/springframework/test/context/support/TestPropertySourceUtils.java b/spring-test/src/main/java/org/springframework/test/context/support/TestPropertySourceUtils.java index 69c3f9a3f6e2..64bfb11589e9 100644 --- a/spring-test/src/main/java/org/springframework/test/context/support/TestPropertySourceUtils.java +++ b/spring-test/src/main/java/org/springframework/test/context/support/TestPropertySourceUtils.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2020 the original author or authors. + * Copyright 2002-2022 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -130,8 +130,8 @@ private static boolean duplicationDetected(TestPropertySourceAttributes currentA boolean duplicationDetected = (currentAttributes.equals(previousAttributes) && !currentAttributes.isEmpty()); - if (duplicationDetected && logger.isDebugEnabled()) { - logger.debug(String.format("Ignoring duplicate %s declaration on %s since it is also declared on %s", + if (duplicationDetected && logger.isTraceEnabled()) { + logger.trace(String.format("Ignoring duplicate %s declaration on %s since it is also declared on %s", currentAttributes, currentAttributes.getDeclaringClass().getName(), previousAttributes.getDeclaringClass().getName())); } @@ -143,7 +143,7 @@ private static String[] mergeLocations(List attrib List locations = new ArrayList<>(); for (TestPropertySourceAttributes attrs : attributesList) { if (logger.isTraceEnabled()) { - logger.trace(String.format("Processing locations for TestPropertySource attributes %s", attrs)); + logger.trace("Processing locations for " + attrs); } String[] locationsArray = TestContextResourceUtils.convertToClasspathResourcePaths( attrs.getDeclaringClass(), true, attrs.getLocations()); @@ -159,7 +159,7 @@ private static String[] mergeProperties(List attri List properties = new ArrayList<>(); for (TestPropertySourceAttributes attrs : attributesList) { if (logger.isTraceEnabled()) { - logger.trace(String.format("Processing inlined properties for TestPropertySource attributes %s", attrs)); + logger.trace("Processing inlined properties for " + attrs); } String[] attrProps = attrs.getProperties(); properties.addAll(0, Arrays.asList(attrProps)); @@ -268,8 +268,8 @@ public static void addInlinedPropertiesToEnvironment(ConfigurableEnvironment env Assert.notNull(environment, "'environment' must not be null"); Assert.notNull(inlinedProperties, "'inlinedProperties' must not be null"); if (!ObjectUtils.isEmpty(inlinedProperties)) { - if (logger.isDebugEnabled()) { - logger.debug("Adding inlined properties to environment: " + + if (logger.isTraceEnabled()) { + logger.trace("Adding inlined properties to environment: " + ObjectUtils.nullSafeToString(inlinedProperties)); } MapPropertySource ps = (MapPropertySource) diff --git a/spring-test/src/main/java/org/springframework/test/context/transaction/TestContextTransactionUtils.java b/spring-test/src/main/java/org/springframework/test/context/transaction/TestContextTransactionUtils.java index a91f4a1f44c7..38301afc42e7 100644 --- a/spring-test/src/main/java/org/springframework/test/context/transaction/TestContextTransactionUtils.java +++ b/spring-test/src/main/java/org/springframework/test/context/transaction/TestContextTransactionUtils.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2021 the original author or authors. + * Copyright 2002-2022 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -218,9 +218,9 @@ public static PlatformTransactionManager retrieveTransactionManager(TestContext } private static void logBeansException(TestContext testContext, BeansException ex, Class beanType) { - if (logger.isDebugEnabled()) { - logger.debug(String.format("Caught exception while retrieving %s for test context %s", - beanType.getSimpleName(), testContext), ex); + if (logger.isTraceEnabled()) { + logger.trace("Caught exception while retrieving %s for test context %s" + .formatted(beanType.getSimpleName(), testContext), ex); } } diff --git a/spring-test/src/main/java/org/springframework/test/context/transaction/TransactionContext.java b/spring-test/src/main/java/org/springframework/test/context/transaction/TransactionContext.java index 0ab622e95f84..73886f24129f 100644 --- a/spring-test/src/main/java/org/springframework/test/context/transaction/TransactionContext.java +++ b/spring-test/src/main/java/org/springframework/test/context/transaction/TransactionContext.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2020 the original author or authors. + * Copyright 2002-2022 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -103,10 +103,14 @@ void startTransaction() { this.transactionStatus = this.transactionManager.getTransaction(this.transactionDefinition); int transactionsStarted = this.transactionsStarted.incrementAndGet(); - if (logger.isInfoEnabled()) { - logger.info(String.format( - "Began transaction (%s) for test context %s; transaction manager [%s]; rollback [%s]", - transactionsStarted, this.testContext, this.transactionManager, this.flaggedForRollback)); + if (logger.isTraceEnabled()) { + logger.trace("Began transaction (%d) for test context %s; transaction manager [%s]; rollback [%s]" + .formatted(transactionsStarted, this.testContext, this.transactionManager, this.flaggedForRollback)); + } + else if (logger.isDebugEnabled()) { + logger.debug("Began transaction (%d) for test class [%s]; test method [%s]; transaction manager [%s]; rollback [%s]" + .formatted(transactionsStarted, this.testContext.getTestClass().getName(), + this.testContext.getTestMethod().getName(), this.transactionManager, this.flaggedForRollback)); } } @@ -135,9 +139,16 @@ void endTransaction() { this.transactionStatus = null; } - if (logger.isInfoEnabled()) { - logger.info((this.flaggedForRollback ? "Rolled back" : "Committed") + - " transaction for test: " + this.testContext); + int transactionsStarted = this.transactionsStarted.get(); + if (logger.isTraceEnabled()) { + logger.trace("%s transaction (%d) for test context: %s" + .formatted((this.flaggedForRollback ? "Rolled back" : "Committed"), + transactionsStarted, this.testContext)); + } + else if (logger.isDebugEnabled()) { + logger.debug("%s transaction (%d) for test class [%s]; test method [%s]" + .formatted((this.flaggedForRollback ? "Rolled back" : "Committed"), transactionsStarted, + this.testContext.getTestClass().getName(), this.testContext.getTestMethod().getName())); } } diff --git a/spring-test/src/main/java/org/springframework/test/context/transaction/TransactionalTestExecutionListener.java b/spring-test/src/main/java/org/springframework/test/context/transaction/TransactionalTestExecutionListener.java index 382897756d4c..0da5fc1eb8bf 100644 --- a/spring-test/src/main/java/org/springframework/test/context/transaction/TransactionalTestExecutionListener.java +++ b/spring-test/src/main/java/org/springframework/test/context/transaction/TransactionalTestExecutionListener.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2020 the original author or authors. + * Copyright 2002-2022 the original author or authors. * * Licensed under the Apache License, Version 2.0 (the "License"); * you may not use this file except in compliance with the License. @@ -210,9 +210,13 @@ public void beforeTestMethod(final TestContext testContext) throws Exception { transactionAttribute = TestContextTransactionUtils.createDelegatingTransactionAttribute(testContext, transactionAttribute); - if (logger.isDebugEnabled()) { - logger.debug("Explicit transaction definition [" + transactionAttribute + - "] found for test context " + testContext); + if (logger.isTraceEnabled()) { + logger.trace("Explicit transaction definition [%s] found for test context %s" + .formatted(transactionAttribute, testContext)); + } + else if (logger.isDebugEnabled()) { + logger.debug("Explicit transaction definition [%s] found for test class [%s] and test method [%s]" + .formatted(transactionAttribute, testClass.getName(), testMethod.getName())); } if (transactionAttribute.getPropagationBehavior() == TransactionDefinition.PROPAGATION_NOT_SUPPORTED || @@ -271,11 +275,17 @@ public void afterTestMethod(TestContext testContext) throws Exception { */ protected void runBeforeTransactionMethods(TestContext testContext) throws Exception { try { - List methods = getAnnotatedMethods(testContext.getTestClass(), BeforeTransaction.class); + Class testClass = testContext.getTestClass(); + List methods = getAnnotatedMethods(testClass, BeforeTransaction.class); Collections.reverse(methods); for (Method method : methods) { - if (logger.isDebugEnabled()) { - logger.debug("Executing @BeforeTransaction method [" + method + "] for test context " + testContext); + if (logger.isTraceEnabled()) { + logger.trace("Executing @BeforeTransaction method [%s] for test context %s" + .formatted(method, testContext)); + } + else if (logger.isDebugEnabled()) { + logger.debug("Executing @BeforeTransaction method [%s] for test class [%s]" + .formatted(method, testClass.getName())); } ReflectionUtils.makeAccessible(method); method.invoke(testContext.getTestInstance()); @@ -284,7 +294,7 @@ protected void runBeforeTransactionMethods(TestContext testContext) throws Excep catch (InvocationTargetException ex) { if (logger.isErrorEnabled()) { logger.error("Exception encountered while executing @BeforeTransaction methods for test context " + - testContext + ".", ex.getTargetException()); + testContext, ex.getTargetException()); } ReflectionUtils.rethrowException(ex.getTargetException()); } @@ -301,11 +311,17 @@ protected void runBeforeTransactionMethods(TestContext testContext) throws Excep protected void runAfterTransactionMethods(TestContext testContext) throws Exception { Throwable afterTransactionException = null; - List methods = getAnnotatedMethods(testContext.getTestClass(), AfterTransaction.class); + Class testClass = testContext.getTestClass(); + List methods = getAnnotatedMethods(testClass, AfterTransaction.class); for (Method method : methods) { try { - if (logger.isDebugEnabled()) { - logger.debug("Executing @AfterTransaction method [" + method + "] for test context " + testContext); + if (logger.isTraceEnabled()) { + logger.trace("Executing @AfterTransaction method [%s] for test context %s" + .formatted(method, testContext)); + } + else if (logger.isDebugEnabled()) { + logger.debug("Executing @AfterTransaction method [%s] for test class [%s]" + .formatted(method, testClass.getName())); } ReflectionUtils.makeAccessible(method); method.invoke(testContext.getTestInstance()); @@ -430,22 +446,28 @@ protected final boolean isDefaultRollback(TestContext testContext) throws Except */ protected final boolean isRollback(TestContext testContext) throws Exception { boolean rollback = isDefaultRollback(testContext); - Rollback rollbackAnnotation = - AnnotatedElementUtils.findMergedAnnotation(testContext.getTestMethod(), Rollback.class); + Method testMethod = testContext.getTestMethod(); + Rollback rollbackAnnotation = AnnotatedElementUtils.findMergedAnnotation(testMethod, Rollback.class); if (rollbackAnnotation != null) { boolean rollbackOverride = rollbackAnnotation.value(); - if (logger.isDebugEnabled()) { - logger.debug(String.format( - "Method-level @Rollback(%s) overrides default rollback [%s] for test context %s.", - rollbackOverride, rollback, testContext)); + if (logger.isTraceEnabled()) { + logger.trace("Method-level @Rollback(%s) overrides default rollback [%s] for test context %s" + .formatted(rollbackOverride, rollback, testContext)); + } + else if (logger.isDebugEnabled()) { + logger.debug("Method-level @Rollback(%s) overrides default rollback [%s] for test method [%s]" + .formatted(rollbackOverride, rollback, testMethod)); } rollback = rollbackOverride; } else { - if (logger.isDebugEnabled()) { - logger.debug(String.format( - "No method-level @Rollback override: using default rollback [%s] for test context %s.", - rollback, testContext)); + if (logger.isTraceEnabled()) { + logger.trace("No method-level @Rollback override: using default rollback [%s] for test context %s" + .formatted(rollback, testContext)); + } + else if (logger.isDebugEnabled()) { + logger.debug("No method-level @Rollback override: using default rollback [%s] for test method [%s]" + .formatted(rollback, testMethod)); } } return rollback; diff --git a/spring-test/src/main/java/org/springframework/test/context/web/AbstractGenericWebContextLoader.java b/spring-test/src/main/java/org/springframework/test/context/web/AbstractGenericWebContextLoader.java index 98662fe07abd..8874d5f15a37 100644 --- a/spring-test/src/main/java/org/springframework/test/context/web/AbstractGenericWebContextLoader.java +++ b/spring-test/src/main/java/org/springframework/test/context/web/AbstractGenericWebContextLoader.java @@ -154,6 +154,14 @@ public final GenericWebApplicationContext loadContextForAotRuntime(MergedContext .formatted(mergedConfig)); } + if (logger.isTraceEnabled()) { + logger.trace("Loading WebApplicationContext for AOT runtime for " + mergedConfig); + } + else if (logger.isDebugEnabled()) { + logger.debug("Loading WebApplicationContext for AOT runtime for test class " + + mergedConfig.getTestClass().getName()); + } + validateMergedContextConfiguration(webMergedConfig); GenericWebApplicationContext context = createContext(); @@ -192,9 +200,13 @@ private final GenericWebApplicationContext loadContext( .formatted(mergedConfig)); } - if (logger.isDebugEnabled()) { - logger.debug("Loading WebApplicationContext %sfor merged context configuration %s" - .formatted((forAotProcessing ? "for AOT processing " : ""), mergedConfig)); + if (logger.isTraceEnabled()) { + logger.trace("Loading WebApplicationContext %sfor %s".formatted( + (forAotProcessing ? "for AOT processing " : ""), mergedConfig)); + } + else if (logger.isDebugEnabled()) { + logger.debug("Loading WebApplicationContext %sfor test class %s".formatted( + (forAotProcessing ? "for AOT processing " : ""), mergedConfig.getTestClass().getName())); } validateMergedContextConfiguration(webMergedConfig); diff --git a/spring-test/src/main/java/org/springframework/test/context/web/ServletTestExecutionListener.java b/spring-test/src/main/java/org/springframework/test/context/web/ServletTestExecutionListener.java index ebdb4ec0f180..8975ef8f5808 100644 --- a/spring-test/src/main/java/org/springframework/test/context/web/ServletTestExecutionListener.java +++ b/spring-test/src/main/java/org/springframework/test/context/web/ServletTestExecutionListener.java @@ -161,8 +161,11 @@ public void beforeTestMethod(TestContext testContext) throws Exception { @Override public void afterTestMethod(TestContext testContext) throws Exception { if (Boolean.TRUE.equals(testContext.getAttribute(RESET_REQUEST_CONTEXT_HOLDER_ATTRIBUTE))) { - if (logger.isDebugEnabled()) { - logger.debug(String.format("Resetting RequestContextHolder for test context %s.", testContext)); + if (logger.isTraceEnabled()) { + logger.trace("Resetting RequestContextHolder for test context " + testContext); + } + else if (logger.isDebugEnabled()) { + logger.debug("Resetting RequestContextHolder for test class " + testContext.getTestClass().getName()); } RequestContextHolder.resetRequestAttributes(); testContext.setAttribute(DependencyInjectionTestExecutionListener.REINJECT_DEPENDENCIES_ATTRIBUTE, @@ -194,10 +197,13 @@ private void setUpRequestContextIfNecessary(TestContext testContext) { "The WebApplicationContext for test context %s must be configured with a MockServletContext.", testContext)); - if (logger.isDebugEnabled()) { - logger.debug(String.format( - "Setting up MockHttpServletRequest, MockHttpServletResponse, ServletWebRequest, and RequestContextHolder for test context %s.", - testContext)); + if (logger.isTraceEnabled()) { + logger.trace("Setting up MockHttpServletRequest, MockHttpServletResponse, ServletWebRequest, " + + "and RequestContextHolder for test context " + testContext); + } + else if (logger.isDebugEnabled()) { + logger.debug("Setting up MockHttpServletRequest, MockHttpServletResponse, ServletWebRequest, " + + "and RequestContextHolder for test class " + testContext.getTestClass().getName()); } MockServletContext mockServletContext = (MockServletContext) servletContext; diff --git a/spring-test/src/main/java/org/springframework/test/context/web/WebMergedContextConfiguration.java b/spring-test/src/main/java/org/springframework/test/context/web/WebMergedContextConfiguration.java index be21a0747f30..556779d0a7aa 100644 --- a/spring-test/src/main/java/org/springframework/test/context/web/WebMergedContextConfiguration.java +++ b/spring-test/src/main/java/org/springframework/test/context/web/WebMergedContextConfiguration.java @@ -19,13 +19,14 @@ import java.util.Set; import org.springframework.context.ApplicationContextInitializer; +import org.springframework.core.style.DefaultToStringStyler; +import org.springframework.core.style.SimpleValueStyler; import org.springframework.core.style.ToStringCreator; import org.springframework.lang.Nullable; import org.springframework.test.context.CacheAwareContextLoaderDelegate; import org.springframework.test.context.ContextCustomizer; import org.springframework.test.context.ContextLoader; import org.springframework.test.context.MergedContextConfiguration; -import org.springframework.util.ObjectUtils; import org.springframework.util.StringUtils; /** @@ -197,17 +198,17 @@ public int hashCode() { */ @Override public String toString() { - return new ToStringCreator(this) + return new ToStringCreator(this, new DefaultToStringStyler(new SimpleValueStyler())) .append("testClass", getTestClass()) - .append("locations", ObjectUtils.nullSafeToString(getLocations())) - .append("classes", ObjectUtils.nullSafeToString(getClasses())) - .append("contextInitializerClasses", ObjectUtils.nullSafeToString(getContextInitializerClasses())) - .append("activeProfiles", ObjectUtils.nullSafeToString(getActiveProfiles())) - .append("propertySourceLocations", ObjectUtils.nullSafeToString(getPropertySourceLocations())) - .append("propertySourceProperties", ObjectUtils.nullSafeToString(getPropertySourceProperties())) + .append("locations", getLocations()) + .append("classes", getClasses()) + .append("contextInitializerClasses", getContextInitializerClasses()) + .append("activeProfiles", getActiveProfiles()) + .append("propertySourceLocations", getPropertySourceLocations()) + .append("propertySourceProperties", getPropertySourceProperties()) .append("contextCustomizers", getContextCustomizers()) .append("resourceBasePath", getResourceBasePath()) - .append("contextLoader", nullSafeClassName(getContextLoader())) + .append("contextLoader", (getContextLoader() != null ? getContextLoader().getClass() : null)) .append("parent", getParent()) .toString(); } diff --git a/spring-test/src/test/resources/log4j2-test.xml b/spring-test/src/test/resources/log4j2-test.xml index 5a5ceae46949..88cf6a3b9aa3 100644 --- a/spring-test/src/test/resources/log4j2-test.xml +++ b/spring-test/src/test/resources/log4j2-test.xml @@ -14,7 +14,7 @@ - +