Issue Details (XML | Word | Printable)

Key: SPR-4664
Type: Improvement Improvement
Status: Resolved Resolved
Resolution: Fixed
Priority: Critical Critical
Assignee: Juergen Hoeller
Reporter: David.Turing
Votes: 0
Watchers: 2
Operations

If you were logged in you would be able to see more operations.
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: 1d
Original Estimate - 1d
Remaining Estimate: 1d
Remaining Estimate - 1d
Time Spent: Not Specified
Remaining Estimate - 1d

File Attachments: 1. File 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

 All   Comments   Work Log   Change History   FishEye   Builds      Sort Order: Ascending order - Click to sort in descending order
[ Permalink | « 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)
    Unknown macro: { // 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
    Unknown macro: { if (logger.isDebugEnabled()) { logger.debug("Adding transactional method [" + method.getName() + "] with attribute [" + txAtt + "]"); } this.attributeCache.put(cacheKey, txAtt); }

    return txAtt;
    }
    }
    }

[ Permalink | « 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.

[ Permalink | « 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


[ Permalink | « Hide ]
David.Turing added a comment - 18/Apr/08 08:53 PM
Thanks, Juergen Hoeller . You could close this case.


Powered by a free Atlassian JIRA open source license for Spring Framework. Try JIRA - bug tracking software for your team.
Atlassian JIRA the Professional Issue Tracker. (Enterprise Edition, Version: 3.13.4-#354) - Bug/feature request - Atlassian news - Contact Administrators