[#SPR-4664] AbstractFallbackTransactionAttributeSource's Map synchronization causes lock contention

Spring Framework

AbstractFallbackTransactionAttributeSource's Map synchronization causes lock contention

Created: 06/Apr/08 09:36 PM Updated: 18/Apr/08 08:53 PM

Component/s:

SpringCORE

Affects Version/s:

2.5 final

Fix Version/s:

2.5.4

Time Tracking:

Original Estimate:

Remaining Estimate:

Time Spent:

Not Specified

File Attachments:	1. threaddump-by-david.turing.rar (10 kB)
Environment:	Intel IA Platform, 8 Core, JRockit 1.5 (R27.5)

Virtual Machine:	BEA JRockit JVM - 5.0
Platform:	BEA WebLogic - 9.2

Description

« Hide

We are encountering the serious perfomance problem when we using Spring 2.X. CPU hit 100% when a lot of threads are doing the work below:
*************
            "[ACTIVE] ExecuteThread: '36' for queue: 'weblogic.kernel.Default (self-tuning)'" id=648 idx=0x2c0 tid=7380 prio=5 alive, daemon

                at java/util/HashMap.get(HashMap.java:1582)[optimized]

                at org/springframework/transaction/interceptor/AbstractFallbackTransactionAttributeSource.getTransactionAttribute(AbstractFallbackTransactionAttributeSource.java:89)[optimized]

                at org/springframework/transaction/interceptor/TransactionAttributeSourceAdvisor$TransactionAttributeSourcePointcut.matches(TransactionAttributeSourceAdvisor.java:102)[optimized]

                at org/springframework/aop/support/AopUtils.canApply(AopUtils.java:192)[inlined]

                at org/springframework/aop/support/AopUtils.canApply(AopUtils.java:231)[inlined]

                at org/springframework/aop/support/AopUtils.findAdvisorsThatCanApply(AopUtils.java:256)[inlined]

                at org/springframework/aop/framework/autoproxy/AbstractAdvisorAutoProxyCreator.findEligibleAdvisors(AbstractAdvisorAutoProxyCreator.java:68)[inlined]

                at org/springframework/aop/framework/autoproxy/AbstractAdvisorAutoProxyCreator.getAdvicesAndAdvisorsForBean(AbstractAdvisorAutoProxyCreator.java:54)[optimized]

                at org/springframework/aop/framework/autoproxy/AbstractAutoProxyCreator.postProcessAfterInitialization(AbstractAutoProxyCreator.java:247)

                at org/springframework/beans/factory/support/AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsAfterInitialization(AbstractAutowireCapableBeanFactory.java:311)

                at org/springframework/beans/factory/support/AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1038)

                at org/springframework/beans/factory/support/AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:420)

                at org/springframework/beans/factory/support/AbstractBeanFactory.getBean(AbstractBeanFactory.java:264)

                at org/springframework/beans/factory/support/AbstractBeanFactory.getBean(AbstractBeanFactory.java:156)

                at org/springframework/context/support/AbstractApplicationContext.getBean(AbstractApplicationContext.java:642)

                at com/opensymphony/xwork2/spring/SpringObjectFactory.buildBean(SpringObjectFactory.java:125)

                at com/opensymphony/xwork2/ObjectFactory.buildBean(ObjectFactory.java:143)

                at com/opensymphony/xwork2/ObjectFactory.buildAction(ObjectFactory.java:113)

                at com/opensymphony/xwork2/DefaultActionInvocation.createAction(DefaultActionInvocation.java:275)

                at com/opensymphony/xwork2/DefaultActionInvocation.init(DefaultActionInvocation.java:365)

                at com/opensymphony/xwork2/DefaultActionInvocation.access$000(DefaultActionInvocation.java:38)

                at com/opensymphony/xwork2/DefaultActionInvocation$1.doProfiling(DefaultActionInvocation.java:83)

                at com/opensymphony/xwork2/util/profiling/UtilTimerStack.profile(UtilTimerStack.java:455)

                at com/opensymphony/xwork2/DefaultActionInvocation.<init>(DefaultActionInvocation.java:74)

                at com/opensymphony/xwork2/DefaultActionProxy.prepare(DefaultActionProxy.java:189)

                at org/apache/struts2/impl/StrutsActionProxyFactory.createActionProxy(StrutsActionProxyFactory.java:41)

                at org/apache/struts2/dispatcher/Dispatcher.serviceAction(Dispatcher.java:497)

                at org/apache/struts2/dispatcher/FilterDispatcher.doFilter(FilterDispatcher.java:421)

                at weblogic/servlet/internal/FilterChainImpl.doFilter(FilterChainImpl.java:42)

                at org/springframework/orm/hibernate3/support/OpenSessionInViewFilter.doFilterInternal(OpenSessionInViewFilter.java:174)

                at org/springframework/web/filter/OncePerRequestFilter.doFilter(OncePerRequestFilter.java:77)

                at weblogic/servlet/internal/FilterChainImpl.doFilter(FilterChainImpl.java:42)

                at cn/com/picc/claim/common/web/SessionFilter.doFilter(SessionFilter.java:35)

                at weblogic/servlet/internal/FilterChainImpl.doFilter(FilterChainImpl.java:42)

                at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:264)

                at org/acegisecurity/intercept/web/FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:107)

                at org/acegisecurity/intercept/web/FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:72)

                at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)

                at org/acegisecurity/ui/ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:110)

                at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)

                at org/acegisecurity/providers/anonymous/AnonymousProcessingFilter.doFilter(AnonymousProcessingFilter.java:125)

                at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)

                at org/acegisecurity/wrapper/SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:81)

                at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)

                at org/acegisecurity/ui/AbstractProcessingFilter.doFilter(AbstractProcessingFilter.java:217)

                at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)

                at org/acegisecurity/ui/logout/LogoutFilter.doFilter(LogoutFilter.java:106)

                at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)

                at org/acegisecurity/context/HttpSessionContextIntegrationFilter.doFilter(HttpSessionContextIntegrationFilter.java:229)

                at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)

                at org/acegisecurity/util/FilterChainProxy.doFilter(FilterChainProxy.java:148)

                at org/acegisecurity/util/FilterToBeanProxy.doFilter(FilterToBeanProxy.java:98)

                at weblogic/servlet/internal/FilterChainImpl.doFilter(FilterChainImpl.java:42)

                at org/springframework/web/filter/CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:78)

                at org/springframework/web/filter/OncePerRequestFilter.doFilter(OncePerRequestFilter.java:77)

                at weblogic/servlet/internal/FilterChainImpl.doFilter(FilterChainImpl.java:42)

                at weblogic/servlet/internal/WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3229)

                at weblogic/security/acl/internal/AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)

                at weblogic/security/service/SecurityManager.runAs(SecurityManager.java:121)

                at weblogic/servlet/internal/WebAppServletContext.securedExecute(WebAppServletContext.java:2002)

                at weblogic/servlet/internal/WebAppServletContext.execute(WebAppServletContext.java:1908)

                at weblogic/servlet/internal/ServletRequestImpl.run(ServletRequestImpl.java:1362)

                at weblogic/work/ExecuteThread.execute(ExecuteThread.java:209)[inlined]

                at weblogic/work/ExecuteThread.run(ExecuteThread.java:181)[optimized]

                at jrockit/vm/RNI.c2java(IIIII)V(Native Method)

                -- end of trace

********************************

And we check source of AbstractFallbackTransactionAttributeSource.java, we found Spring are using HashMap with Synchronized for thread safe purpose.
This won't be a problem if there are less threads, but when there are lots of threads doing getTransactionAttribute(), CPU will hit 100%.

Why not use JDK 1.5 's CurrentHashMap?

Accoring to Doug Lea, this won't be a bug of JDK, and could be fixed with our way of using HashMap.
http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6423457

Description

We are encountering the serious perfomance problem when we using Spring 2.X. CPU hit 100% when a lot of threads are doing the work below: ************* "[ACTIVE] ExecuteThread: '36' for queue: 'weblogic.kernel.Default (self-tuning)'" id=648 idx=0x2c0 tid=7380 prio=5 alive, daemon at java/util/HashMap.get(HashMap.java:1582)[optimized] at org/springframework/transaction/interceptor/AbstractFallbackTransactionAttributeSource.getTransactionAttribute(AbstractFallbackTransactionAttributeSource.java:89)[optimized] at org/springframework/transaction/interceptor/TransactionAttributeSourceAdvisor$TransactionAttributeSourcePointcut.matches(TransactionAttributeSourceAdvisor.java:102)[optimized] at org/springframework/aop/support/AopUtils.canApply(AopUtils.java:192)[inlined] at org/springframework/aop/support/AopUtils.canApply(AopUtils.java:231)[inlined] at org/springframework/aop/support/AopUtils.findAdvisorsThatCanApply(AopUtils.java:256)[inlined] at org/springframework/aop/framework/autoproxy/AbstractAdvisorAutoProxyCreator.findEligibleAdvisors(AbstractAdvisorAutoProxyCreator.java:68)[inlined] at org/springframework/aop/framework/autoproxy/AbstractAdvisorAutoProxyCreator.getAdvicesAndAdvisorsForBean(AbstractAdvisorAutoProxyCreator.java:54)[optimized] at org/springframework/aop/framework/autoproxy/AbstractAutoProxyCreator.postProcessAfterInitialization(AbstractAutoProxyCreator.java:247) at org/springframework/beans/factory/support/AbstractAutowireCapableBeanFactory.applyBeanPostProcessorsAfterInitialization(AbstractAutowireCapableBeanFactory.java:311) at org/springframework/beans/factory/support/AbstractAutowireCapableBeanFactory.initializeBean(AbstractAutowireCapableBeanFactory.java:1038) at org/springframework/beans/factory/support/AbstractAutowireCapableBeanFactory.createBean(AbstractAutowireCapableBeanFactory.java:420) at org/springframework/beans/factory/support/AbstractBeanFactory.getBean(AbstractBeanFactory.java:264) at org/springframework/beans/factory/support/AbstractBeanFactory.getBean(AbstractBeanFactory.java:156) at org/springframework/context/support/AbstractApplicationContext.getBean(AbstractApplicationContext.java:642) at com/opensymphony/xwork2/spring/SpringObjectFactory.buildBean(SpringObjectFactory.java:125) at com/opensymphony/xwork2/ObjectFactory.buildBean(ObjectFactory.java:143) at com/opensymphony/xwork2/ObjectFactory.buildAction(ObjectFactory.java:113) at com/opensymphony/xwork2/DefaultActionInvocation.createAction(DefaultActionInvocation.java:275) at com/opensymphony/xwork2/DefaultActionInvocation.init(DefaultActionInvocation.java:365) at com/opensymphony/xwork2/DefaultActionInvocation.access$000(DefaultActionInvocation.java:38) at com/opensymphony/xwork2/DefaultActionInvocation$1.doProfiling(DefaultActionInvocation.java:83) at com/opensymphony/xwork2/util/profiling/UtilTimerStack.profile(UtilTimerStack.java:455) at com/opensymphony/xwork2/DefaultActionInvocation.<init>(DefaultActionInvocation.java:74) at com/opensymphony/xwork2/DefaultActionProxy.prepare(DefaultActionProxy.java:189) at org/apache/struts2/impl/StrutsActionProxyFactory.createActionProxy(StrutsActionProxyFactory.java:41) at org/apache/struts2/dispatcher/Dispatcher.serviceAction(Dispatcher.java:497) at org/apache/struts2/dispatcher/FilterDispatcher.doFilter(FilterDispatcher.java:421) at weblogic/servlet/internal/FilterChainImpl.doFilter(FilterChainImpl.java:42) at org/springframework/orm/hibernate3/support/OpenSessionInViewFilter.doFilterInternal(OpenSessionInViewFilter.java:174) at org/springframework/web/filter/OncePerRequestFilter.doFilter(OncePerRequestFilter.java:77) at weblogic/servlet/internal/FilterChainImpl.doFilter(FilterChainImpl.java:42) at cn/com/picc/claim/common/web/SessionFilter.doFilter(SessionFilter.java:35) at weblogic/servlet/internal/FilterChainImpl.doFilter(FilterChainImpl.java:42) at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:264) at org/acegisecurity/intercept/web/FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:107) at org/acegisecurity/intercept/web/FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:72) at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274) at org/acegisecurity/ui/ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:110) at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274) at org/acegisecurity/providers/anonymous/AnonymousProcessingFilter.doFilter(AnonymousProcessingFilter.java:125) at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274) at org/acegisecurity/wrapper/SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:81) at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274) at org/acegisecurity/ui/AbstractProcessingFilter.doFilter(AbstractProcessingFilter.java:217) at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274) at org/acegisecurity/ui/logout/LogoutFilter.doFilter(LogoutFilter.java:106) at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274) at org/acegisecurity/context/HttpSessionContextIntegrationFilter.doFilter(HttpSessionContextIntegrationFilter.java:229) at org/acegisecurity/util/FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274) at org/acegisecurity/util/FilterChainProxy.doFilter(FilterChainProxy.java:148) at org/acegisecurity/util/FilterToBeanProxy.doFilter(FilterToBeanProxy.java:98) at weblogic/servlet/internal/FilterChainImpl.doFilter(FilterChainImpl.java:42) at org/springframework/web/filter/CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:78) at org/springframework/web/filter/OncePerRequestFilter.doFilter(OncePerRequestFilter.java:77) at weblogic/servlet/internal/FilterChainImpl.doFilter(FilterChainImpl.java:42) at weblogic/servlet/internal/WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3229) at weblogic/security/acl/internal/AuthenticatedSubject.doAs(AuthenticatedSubject.java:321) at weblogic/security/service/SecurityManager.runAs(SecurityManager.java:121) at weblogic/servlet/internal/WebAppServletContext.securedExecute(WebAppServletContext.java:2002) at weblogic/servlet/internal/WebAppServletContext.execute(WebAppServletContext.java:1908) at weblogic/servlet/internal/ServletRequestImpl.run(ServletRequestImpl.java:1362) at weblogic/work/ExecuteThread.execute(ExecuteThread.java:209)[inlined] at weblogic/work/ExecuteThread.run(ExecuteThread.java:181)[optimized] at jrockit/vm/RNI.c2java(IIIII)V(Native Method) -- end of trace ******************************** And we check source of AbstractFallbackTransactionAttributeSource.java, we found Spring are using HashMap with Synchronized for thread safe purpose. This won't be a problem if there are less threads, but when there are lots of threads doing getTransactionAttribute(), CPU will hit 100%. Why not use JDK 1.5 's CurrentHashMap? Accoring to Doug Lea, this won't be a bug of JDK, and could be fixed with our way of using HashMap. http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6423457

Show »

All

Comments

Work Log

Change History

FishEye

Related Builds

Sort Order:

[ Permlink | « Hide ]

David.Turing added a comment - 06/Apr/08 09:42 PM

Here are the source code of AbstractFallbackTransactionAttributeSource(spring 2.5.1).
the attributeCache are the cause of our 100% CPU, Restart WebLogic Instance could solved this case, and we are not sure we could reproduce the case , it was sometimes meet in product enviroment..

/**
* Cache of TransactionAttributes, keyed by DefaultCacheKey (Method + target Class).
* <p>As this base class is not marked Serializable, the cache will be recreated
* after serialization - provided that the concrete subclass is Serializable.
*/
final Map attributeCache = new HashMap();

/**
* Determine the transaction attribute for this method invocation.
* <p>Defaults to the class's transaction attribute if no method attribute is found.
* @param method the method for the current invocation (never <code>null</code>)
* @param targetClass the target class for this invocation (may be <code>null</code>)
* @return TransactionAttribute for this method, or <code>null</code> if the method
* is not transactional
*/
public TransactionAttribute getTransactionAttribute(Method method, Class targetClass) {
// First, see if we have a cached value.
Object cacheKey = getCacheKey(method, targetClass);
synchronized (this.attributeCache) {
Object cached = this.attributeCache.get(cacheKey);
if (cached != null) {
// Value will either be canonical value indicating there is no transaction attribute,
// or an actual transaction attribute.
if (cached == NULL_TRANSACTION_ATTRIBUTE) {
return null;
}
else {
return (TransactionAttribute) cached;
}
}
else {
// We need to work it out.
TransactionAttribute txAtt = computeTransactionAttribute(method, targetClass);
// Put it in the cache.
if (txAtt == null) {
this.attributeCache.put(cacheKey, NULL_TRANSACTION_ATTRIBUTE);
}
else {
if (logger.isDebugEnabled()) {
logger.debug("Adding transactional method [" + method.getName() + "] with attribute [" + txAtt + "]");
}
this.attributeCache.put(cacheKey, txAtt);
}
return txAtt;
}
}
}

[ Show » ]

David.Turing added a comment - 06/Apr/08 09:42 PM Here are the source code of AbstractFallbackTransactionAttributeSource(spring 2.5.1). the attributeCache are the cause of our 100% CPU, Restart WebLogic Instance could solved this case, and we are not sure we could reproduce the case , it was sometimes meet in product enviroment.. /** * Cache of TransactionAttributes, keyed by DefaultCacheKey (Method + target Class). * <p>As this base class is not marked Serializable, the cache will be recreated * after serialization - provided that the concrete subclass is Serializable. */ final Map attributeCache = new HashMap(); /** * Determine the transaction attribute for this method invocation. * <p>Defaults to the class's transaction attribute if no method attribute is found. * @param method the method for the current invocation (never <code>null</code>) * @param targetClass the target class for this invocation (may be <code>null</code>) * @return TransactionAttribute for this method, or <code>null</code> if the method * is not transactional */ public TransactionAttribute getTransactionAttribute(Method method, Class targetClass) { // First, see if we have a cached value. Object cacheKey = getCacheKey(method, targetClass); synchronized (this.attributeCache) { Object cached = this.attributeCache.get(cacheKey); if (cached != null) { // Value will either be canonical value indicating there is no transaction attribute, // or an actual transaction attribute. if (cached == NULL_TRANSACTION_ATTRIBUTE) { return null; } else { return (TransactionAttribute) cached; } } else { // We need to work it out. TransactionAttribute txAtt = computeTransactionAttribute(method, targetClass); // Put it in the cache. if (txAtt == null) { this.attributeCache.put(cacheKey, NULL_TRANSACTION_ATTRIBUTE); } else { if (logger.isDebugEnabled()) { logger.debug("Adding transactional method [" + method.getName() + "] with attribute [" + txAtt + "]"); } this.attributeCache.put(cacheKey, txAtt); } return txAtt; } } }

[ Permlink | « Hide ]

David.Turing added a comment - 06/Apr/08 09:45 PM

This is the thread dump, there are lots of thread accesing the HashMap of attributeCache, which making the CPU 100%.
It is most like softCache problem on Sun HotSpot.

[ Permlink | « Hide ]

Juergen Hoeller added a comment - 15/Apr/08 05:29 PM

Thanks for raising this! I've revised AbstractFallbackTransactionAttributeSource accordingly, using a concurrent Map for the attribute cache in order to avoid lock contention.

This will be available in the next 2.5.4 snapshot (http://static.springframework.org/downloads/nightly/snapshot-download.php?project=SPR). Please give it a try and let me know whether it works for you...

Juergen

[ Permlink | « Hide ]

David.Turing added a comment - 18/Apr/08 08:53 PM

Thanks, Juergen Hoeller . You could close this case.