From a09bc9b1c154048873fcf7ca88306679593c1032 Mon Sep 17 00:00:00 2001 From: Sam Brannen Date: Mon, 3 Nov 2014 15:26:44 +0100 Subject: [PATCH] Log context cache statistics in the TCF Prior to this commit, finding out how many application contexts had been loaded within a test suite required the use of reflection and a bit of hacking. This commit addresses this issue by logging ContextCache statistics whenever an application context is loaded by the Spring TestContext Framework (TCF). The log output can be enabled by setting the "org.springframework.test.context.cache" logging category to DEBUG. Issue: SPR-12409 (cherry picked from commit da04362) --- .../CacheAwareContextLoaderDelegate.java | 35 ++- .../test/context/ContextCache.java | 227 +++++++----------- .../test/context/DefaultTestContext.java | 60 ++--- .../src/test/resources/log4j.properties | 1 + src/asciidoc/index.adoc | 7 + 5 files changed, 143 insertions(+), 187 deletions(-) diff --git a/spring-test/src/main/java/org/springframework/test/context/CacheAwareContextLoaderDelegate.java b/spring-test/src/main/java/org/springframework/test/context/CacheAwareContextLoaderDelegate.java index f7375def035..507d2555741 100644 --- a/spring-test/src/main/java/org/springframework/test/context/CacheAwareContextLoaderDelegate.java +++ b/spring-test/src/main/java/org/springframework/test/context/CacheAwareContextLoaderDelegate.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2013 the original author or authors. + * Copyright 2002-2014 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,7 @@ package org.springframework.test.context; import org.apache.commons.logging.Log; import org.apache.commons.logging.LogFactory; + import org.springframework.context.ApplicationContext; import org.springframework.util.Assert; @@ -37,6 +38,8 @@ public class CacheAwareContextLoaderDelegate { private static final Log logger = LogFactory.getLog(CacheAwareContextLoaderDelegate.class); + private static final Log statsLogger = LogFactory.getLog("org.springframework.test.context.cache"); + private final ContextCache contextCache; @@ -45,6 +48,7 @@ public class CacheAwareContextLoaderDelegate { this.contextCache = contextCache; } + /** * Load the {@code ApplicationContext} for the supplied merged context * configuration. Supports both the {@link SmartContextLoader} and @@ -53,9 +57,10 @@ public class CacheAwareContextLoaderDelegate { */ private ApplicationContext loadContextInternal(MergedContextConfiguration mergedContextConfiguration) throws Exception { + ContextLoader contextLoader = mergedContextConfiguration.getContextLoader(); - Assert.notNull(contextLoader, "Cannot load an ApplicationContext with a NULL 'contextLoader'. " - + "Consider annotating your test class with @ContextConfiguration or @ContextHierarchy."); + Assert.notNull(contextLoader, "Cannot load an ApplicationContext with a NULL 'contextLoader'. " + + "Consider annotating your test class with @ContextConfiguration or @ContextHierarchy."); ApplicationContext applicationContext; @@ -65,8 +70,8 @@ public class CacheAwareContextLoaderDelegate { } else { String[] locations = mergedContextConfiguration.getLocations(); - Assert.notNull(locations, "Cannot load an ApplicationContext with a NULL 'locations' array. " - + "Consider annotating your test class with @ContextConfiguration or @ContextHierarchy."); + Assert.notNull(locations, "Cannot load an ApplicationContext with a NULL 'locations' array. " + + "Consider annotating your test class with @ContextConfiguration or @ContextHierarchy."); applicationContext = contextLoader.loadContext(locations); } @@ -76,7 +81,6 @@ public class CacheAwareContextLoaderDelegate { /** * Load the {@link ApplicationContext application context} for the supplied * merged context configuration. - * *

If the context is present in the cache it will simply be returned; * otherwise, it will be loaded, stored in the cache, and returned. * @return the application context @@ -84,16 +88,16 @@ public class CacheAwareContextLoaderDelegate { * loading the application context */ public ApplicationContext loadContext(MergedContextConfiguration mergedContextConfiguration) { - synchronized (contextCache) { - ApplicationContext context = contextCache.get(mergedContextConfiguration); + synchronized (this.contextCache) { + ApplicationContext context = this.contextCache.get(mergedContextConfiguration); if (context == null) { try { context = loadContextInternal(mergedContextConfiguration); if (logger.isDebugEnabled()) { - logger.debug(String.format("Storing ApplicationContext in cache under key [%s].", - mergedContextConfiguration)); + logger.debug(String.format("Storing ApplicationContext in cache under key [%s]", + mergedContextConfiguration)); } - contextCache.put(mergedContextConfiguration, context); + this.contextCache.put(mergedContextConfiguration, context); } catch (Exception ex) { throw new IllegalStateException("Failed to load ApplicationContext", ex); @@ -101,10 +105,15 @@ public class CacheAwareContextLoaderDelegate { } else { if (logger.isDebugEnabled()) { - logger.debug(String.format("Retrieved ApplicationContext from cache with key [%s].", - mergedContextConfiguration)); + logger.debug(String.format("Retrieved ApplicationContext from cache with key [%s]", + mergedContextConfiguration)); } } + + if (statsLogger.isDebugEnabled()) { + statsLogger.debug("Spring test ApplicationContext cache statistics: " + this.contextCache); + } + return context; } } diff --git a/spring-test/src/main/java/org/springframework/test/context/ContextCache.java b/spring-test/src/main/java/org/springframework/test/context/ContextCache.java index 3a5a5b1adbd..576021bdaa5 100644 --- a/spring-test/src/main/java/org/springframework/test/context/ContextCache.java +++ b/spring-test/src/main/java/org/springframework/test/context/ContextCache.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2013 the original author or authors. + * Copyright 2002-2014 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. @@ -22,6 +22,7 @@ import java.util.List; import java.util.Map; import java.util.Set; import java.util.concurrent.ConcurrentHashMap; +import java.util.concurrent.atomic.AtomicInteger; import org.springframework.context.ApplicationContext; import org.springframework.context.ConfigurableApplicationContext; @@ -47,13 +48,11 @@ import org.springframework.util.Assert; */ class ContextCache { - private final Object monitor = new Object(); - /** * Map of context keys to Spring {@code ApplicationContext} instances. */ - private final Map contextMap = new ConcurrentHashMap( - 64); + private final Map contextMap = + new ConcurrentHashMap(64); /** * Map of parent keys to sets of children keys, representing a top-down tree @@ -61,128 +60,99 @@ class ContextCache { * need to be recursively removed and closed when removing a context that is a parent * of other contexts. */ - private final Map> hierarchyMap = new ConcurrentHashMap>( - 64); + private final Map> hierarchyMap = + new ConcurrentHashMap>(64); - private int hitCount; + private final AtomicInteger hitCount = new AtomicInteger(); - private int missCount; + private final AtomicInteger missCount = new AtomicInteger(); /** - * Clears all contexts from the cache and clears context hierarchy information as - * well. + * Clear all contexts from the cache and clears context hierarchy information as well. */ - void clear() { - synchronized (monitor) { - this.contextMap.clear(); - this.hierarchyMap.clear(); - } + public void clear() { + this.contextMap.clear(); + this.hierarchyMap.clear(); } /** - * Clears hit and miss count statistics for the cache (i.e., resets counters to zero). + * Clear hit and miss count statistics for the cache (i.e., resets counters to zero). */ - void clearStatistics() { - this.hitCount = 0; - this.missCount = 0; + public void clearStatistics() { + this.hitCount.set(0); + this.missCount.set(0); } /** * Return whether there is a cached context for the given key. - * * @param key the context key (never {@code null}) */ - boolean contains(MergedContextConfiguration key) { + public boolean contains(MergedContextConfiguration key) { Assert.notNull(key, "Key must not be null"); - synchronized (monitor) { - return this.contextMap.containsKey(key); - } + return this.contextMap.containsKey(key); } /** * Obtain a cached {@code ApplicationContext} for the given key. - * - *

The {@link #getHitCount() hit} and {@link #getMissCount() miss} counts will be - * updated accordingly. - * + *

The {@link #getHitCount() hit} and {@link #getMissCount() miss} counts will + * be updated accordingly. * @param key the context key (never {@code null}) - * @return the corresponding {@code ApplicationContext} instance, or {@code null} if - * not found in the cache. + * @return the corresponding {@code ApplicationContext} instance, or {@code null} + * if not found in the cache * @see #remove */ - ApplicationContext get(MergedContextConfiguration key) { + public ApplicationContext get(MergedContextConfiguration key) { Assert.notNull(key, "Key must not be null"); - synchronized (monitor) { - ApplicationContext context = this.contextMap.get(key); - if (context == null) { - incrementMissCount(); - } - else { - incrementHitCount(); - } - return context; + ApplicationContext context = this.contextMap.get(key); + if (context == null) { + this.missCount.incrementAndGet(); } + else { + this.hitCount.incrementAndGet(); + } + return context; } /** - * Increment the hit count by one. A hit is an access to the cache, which - * returned a non-null context for a queried key. - */ - private void incrementHitCount() { - this.hitCount++; - } - - /** - * Increment the miss count by one. A miss is an access to the cache, which - * returned a {@code null} context for a queried key. - */ - private void incrementMissCount() { - this.missCount++; - } - - /** - * Get the overall hit count for this cache. A hit is an access to the cache, - * which returned a non-null context for a queried key. + * Get the overall hit count for this cache. + *

A hit is an access to the cache, which returned a non-null context + * for a queried key. */ - int getHitCount() { - return this.hitCount; + public int getHitCount() { + return this.hitCount.get(); } /** - * Get the overall miss count for this cache. A miss is an access to the - * cache, which returned a {@code null} context for a queried key. + * Get the overall miss count for this cache. + *

A miss is an access to the cache, which returned a {@code null} context + * for a queried key. */ - int getMissCount() { - return this.missCount; + public int getMissCount() { + return this.missCount.get(); } /** - * Explicitly add an {@code ApplicationContext} instance to the cache under the given - * key. - * + * Explicitly add an {@code ApplicationContext} instance to the cache under the given key. * @param key the context key (never {@code null}) * @param context the {@code ApplicationContext} instance (never {@code null}) */ - void put(MergedContextConfiguration key, ApplicationContext context) { + public void put(MergedContextConfiguration key, ApplicationContext context) { Assert.notNull(key, "Key must not be null"); Assert.notNull(context, "ApplicationContext must not be null"); - synchronized (monitor) { - this.contextMap.put(key, context); - - MergedContextConfiguration child = key; - MergedContextConfiguration parent = child.getParent(); - while (parent != null) { - Set list = hierarchyMap.get(parent); - if (list == null) { - list = new HashSet(); - hierarchyMap.put(parent, list); - } - list.add(child); - child = parent; - parent = child.getParent(); + this.contextMap.put(key, context); + MergedContextConfiguration child = key; + MergedContextConfiguration parent = child.getParent(); + while (parent != null) { + Set list = this.hierarchyMap.get(parent); + if (list == null) { + list = new HashSet(); + this.hierarchyMap.put(parent, list); } + list.add(child); + child = parent; + parent = child.getParent(); } } @@ -190,19 +160,16 @@ class ContextCache { * Remove the context with the given key from the cache and explicitly * {@linkplain ConfigurableApplicationContext#close() close} it if it is an * instance of {@link ConfigurableApplicationContext}. - * *

Generally speaking, you would only call this method if you change the * state of a singleton bean, potentially affecting future interaction with * the context. - * *

In addition, the semantics of the supplied {@code HierarchyMode} will * be honored. See the Javadoc for {@link HierarchyMode} for details. - * * @param key the context key; never {@code null} * @param hierarchyMode the hierarchy mode; may be {@code null} if the context * is not part of a hierarchy */ - void remove(MergedContextConfiguration key, HierarchyMode hierarchyMode) { + public void remove(MergedContextConfiguration key, HierarchyMode hierarchyMode) { Assert.notNull(key, "Key must not be null"); // startKey is the level at which to begin clearing the cache, depending @@ -214,24 +181,21 @@ class ContextCache { } } - synchronized (monitor) { - final List removedContexts = new ArrayList(); - - remove(removedContexts, startKey); + List removedContexts = new ArrayList(); + remove(removedContexts, startKey); - // Remove all remaining references to any removed contexts from the - // hierarchy map. - for (MergedContextConfiguration currentKey : removedContexts) { - for (Set children : hierarchyMap.values()) { - children.remove(currentKey); - } + // Remove all remaining references to any removed contexts from the + // hierarchy map. + for (MergedContextConfiguration currentKey : removedContexts) { + for (Set children : this.hierarchyMap.values()) { + children.remove(currentKey); } + } - // Remove empty entries from the hierarchy map. - for (MergedContextConfiguration currentKey : hierarchyMap.keySet()) { - if (hierarchyMap.get(currentKey).isEmpty()) { - hierarchyMap.remove(currentKey); - } + // Remove empty entries from the hierarchy map. + for (MergedContextConfiguration currentKey : this.hierarchyMap.keySet()) { + if (this.hierarchyMap.get(currentKey).isEmpty()) { + this.hierarchyMap.remove(currentKey); } } } @@ -239,26 +203,23 @@ class ContextCache { private void remove(List removedContexts, MergedContextConfiguration key) { Assert.notNull(key, "Key must not be null"); - synchronized (monitor) { - Set children = hierarchyMap.get(key); - if (children != null) { - for (MergedContextConfiguration child : children) { - // Recurse through lower levels - remove(removedContexts, child); - } - // Remove the set of children for the current context from the - // hierarchy map. - hierarchyMap.remove(key); + Set children = this.hierarchyMap.get(key); + if (children != null) { + for (MergedContextConfiguration child : children) { + // Recurse through lower levels + remove(removedContexts, child); } + // Remove the set of children for the current context from the hierarchy map. + this.hierarchyMap.remove(key); + } - // Physically remove and close leaf nodes first (i.e., on the way back up the - // stack as opposed to prior to the recursive call). - ApplicationContext context = contextMap.remove(key); - if (context instanceof ConfigurableApplicationContext) { - ((ConfigurableApplicationContext) context).close(); - } - removedContexts.add(key); + // Physically remove and close leaf nodes first (i.e., on the way back up the + // stack as opposed to prior to the recursive call). + ApplicationContext context = this.contextMap.remove(key); + if (context instanceof ConfigurableApplicationContext) { + ((ConfigurableApplicationContext) context).close(); } + removedContexts.add(key); } /** @@ -266,34 +227,30 @@ class ContextCache { * contains more than Integer.MAX_VALUE elements, returns * Integer.MAX_VALUE. */ - int size() { - synchronized (monitor) { - return this.contextMap.size(); - } + public int size() { + return this.contextMap.size(); } /** * Determine the number of parent contexts currently tracked within the cache. */ - int getParentContextCount() { - synchronized (monitor) { - return this.hierarchyMap.size(); - } + public int getParentContextCount() { + return this.hierarchyMap.size(); } /** * Generates a text string, which contains the {@linkplain #size() size} as well - * as the {@linkplain #getHitCount() hit}, {@linkplain #getMissCount() miss}, and - * {@linkplain #getParentContextCount() parent context} counts. + * as the {@linkplain #getHitCount() hit}, {@linkplain #getMissCount() miss}, + * and {@linkplain #getParentContextCount() parent context} counts. */ @Override public String toString() { - return new ToStringCreator(this)// - .append("size", size())// - .append("hitCount", getHitCount())// - .append("missCount", getMissCount())// - .append("parentContextCount", getParentContextCount())// - .toString(); + return new ToStringCreator(this) + .append("size", size()) + .append("hitCount", getHitCount()) + .append("missCount", getMissCount()) + .append("parentContextCount", getParentContextCount()) + .toString(); } } diff --git a/spring-test/src/main/java/org/springframework/test/context/DefaultTestContext.java b/spring-test/src/main/java/org/springframework/test/context/DefaultTestContext.java index 22d6580a3df..0c14c772293 100644 --- a/spring-test/src/main/java/org/springframework/test/context/DefaultTestContext.java +++ b/spring-test/src/main/java/org/springframework/test/context/DefaultTestContext.java @@ -1,5 +1,5 @@ /* - * Copyright 2002-2013 the original author or authors. + * Copyright 2002-2014 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. @@ -78,8 +78,7 @@ class DefaultTestContext extends AttributeAccessorSupport implements TestContext * @param testClass the test class for which the test context should be * constructed (must not be {@code null}) * @param contextCache the context cache from which the constructed test - * context should retrieve application contexts (must not be - * {@code null}) + * context should retrieve application contexts (must not be {@code null}) * @param defaultContextLoaderClassName the name of the default * {@code ContextLoader} class to use (may be {@code null}) */ @@ -90,73 +89,56 @@ class DefaultTestContext extends AttributeAccessorSupport implements TestContext this.testClass = testClass; this.contextCache = contextCache; this.cacheAwareContextLoaderDelegate = new CacheAwareContextLoaderDelegate(contextCache); - this.mergedContextConfiguration = ContextLoaderUtils.buildMergedContextConfiguration(testClass, - defaultContextLoaderClassName, cacheAwareContextLoaderDelegate); + this.mergedContextConfiguration = ContextLoaderUtils.buildMergedContextConfiguration( + testClass, defaultContextLoaderClassName, this.cacheAwareContextLoaderDelegate); } - /** - * {@inheritDoc} - */ + public ApplicationContext getApplicationContext() { - return cacheAwareContextLoaderDelegate.loadContext(mergedContextConfiguration); + return this.cacheAwareContextLoaderDelegate.loadContext(this.mergedContextConfiguration); } - /** - * {@inheritDoc} - */ public final Class getTestClass() { - return testClass; + return this.testClass; } - /** - * {@inheritDoc} - */ public final Object getTestInstance() { - return testInstance; + return this.testInstance; } - /** - * {@inheritDoc} - */ public final Method getTestMethod() { - return testMethod; + return this.testMethod; } - /** - * {@inheritDoc} - */ public final Throwable getTestException() { - return testException; + return this.testException; } - /** - * {@inheritDoc} - */ public void markApplicationContextDirty(HierarchyMode hierarchyMode) { - contextCache.remove(mergedContextConfiguration, hierarchyMode); + synchronized (this.contextCache) { + this.contextCache.remove(this.mergedContextConfiguration, hierarchyMode); + } } - /** - * {@inheritDoc} - */ public void updateState(Object testInstance, Method testMethod, Throwable testException) { this.testInstance = testInstance; this.testMethod = testMethod; this.testException = testException; } + /** * Provide a String representation of this test context's state. */ @Override public String toString() { - return new ToStringCreator(this)// - .append("testClass", testClass)// - .append("testInstance", testInstance)// - .append("testMethod", testMethod)// - .append("testException", testException)// - .append("mergedContextConfiguration", mergedContextConfiguration)// - .toString(); + return new ToStringCreator(this) + .append("testClass", this.testClass) + .append("testInstance", this.testInstance) + .append("testMethod", this.testMethod) + .append("testException", this.testException) + .append("mergedContextConfiguration", this.mergedContextConfiguration) + .toString(); } } diff --git a/spring-test/src/test/resources/log4j.properties b/spring-test/src/test/resources/log4j.properties index 5947420f135..41d968442b8 100644 --- a/spring-test/src/test/resources/log4j.properties +++ b/spring-test/src/test/resources/log4j.properties @@ -15,6 +15,7 @@ log4j.logger.org.springframework.test.context.ContextLoaderUtils=WARN log4j.logger.org.springframework.test.context.transaction.TransactionalTestExecutionListener=WARN log4j.logger.org.springframework.test.context.web=WARN log4j.logger.org.springframework.test.context=WARN +log4j.logger.org.springframework.test.context.cache=WARN #log4j.logger.org.springframework.test.context.support.DelegatingSmartContextLoader=INFO #log4j.logger.org.springframework.test.context.support.AbstractGenericContextLoader=INFO diff --git a/src/asciidoc/index.adoc b/src/asciidoc/index.adoc index cb795d28b5e..c23941ec762 100644 --- a/src/asciidoc/index.adoc +++ b/src/asciidoc/index.adoc @@ -19503,6 +19503,12 @@ framework will not be able to cache application contexts between test classes an build process will run significantly slower as a result. ==== +Since having a large number of application contexts loaded within a given test suite can +cause the suite to take an unnecessarily long time to execute, it is often beneficial to +know exactly how many contexts have been loaded and cached. To view the statistics for +the underlying context cache, simply set the log level for the +`org.springframework.test.context.cache` logging category to `DEBUG`. + In the unlikely case that a test corrupts the application context and requires reloading -- for example, by modifying a bean definition or the state of an application object -- you can annotate your test class or test method with `@DirtiesContext` (see the @@ -19512,6 +19518,7 @@ context before executing the next test. Note that support for the `@DirtiesConte annotation is provided by the `DirtiesContextTestExecutionListener` which is enabled by default. + [[testcontext-ctx-management-ctx-hierarchies]] ====== Context hierarchies