[jira] Commented: (IBATIS-249) Race conditions in Throttle lead to thread blockage popping items from ThrottledPools under stress

["Nicolas KP (JIRA)" <ib...@incubator.apache.org>]

    [ https://issues.apache.org/jira/browse/IBATIS-249?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12557974#action_12557974 ] 

Nicolas KP commented on IBATIS-249:
-----------------------------------

It doesn't seem resolved to  me.
We have the same problem, using 2.2. It behaves the same way with 2.3 too.
Every hour (approximately), suddenly, without a gradual increase in thread count etc, a deadlock(?) suddenly rises the charge and within seconds, the application is dead.
Par example:

Name: TP-Processor431
State: WAITING on java.lang.Object@253e7f
Total blocked: 4 388  Total waited: 248

Stack trace: 
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:474)
com.ibatis.common.util.Throttle.increment(Throttle.java:70)
com.ibatis.common.util.ThrottledPool.pop(ThrottledPool.java:57)
com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.popSession(SqlMapExecutorDelegate.java:930)
com.ibatis.sqlmap.engine.impl.SqlMapSessionImpl.<init>(SqlMapSessionImpl.java:51)
com.ibatis.sqlmap.engine.impl.SqlMapClientImpl.getLocalSqlMapSession(SqlMapClientImpl.java:258)

from this point on it is different every time:
com.ibatis.sqlmap.engine.impl.SqlMapClientImpl.queryForObject(SqlMapClientImpl.java:84)
com.ibatis.sqlmap.engine.mapping.result.loader.ResultLoader.getResult(ResultLoader.java:77)
com.ibatis.sqlmap.engine.mapping.result.loader.LazyResultLoader.loadResult(LazyResultLoader.java:72)
com.ibatis.sqlmap.engine.mapping.result.loader.ResultLoader.loadResult(ResultLoader.java:56)
com.ibatis.sqlmap.engine.mapping.result.BasicResultMap.getNestedSelectMappingValue(BasicResultMap.java:504)
com.ibatis.sqlmap.engine.mapping.result.BasicResultMap.getResults(BasicResultMap.java:340)
com.ibatis.sqlmap.engine.execution.SqlExecutor.handleResults(SqlExecutor.java:375)
com.ibatis.sqlmap.engine.execution.SqlExecutor.handleMultipleResults(SqlExecutor.java:295)
com.ibatis.sqlmap.engine.execution.SqlExecutor.executeQuery(SqlExecutor.java:186)
com.ibatis.sqlmap.engine.mapping.statement.GeneralStatement.sqlExecuteQuery(GeneralStatement.java:205)
com.ibatis.sqlmap.engine.mapping.statement.GeneralStatement.executeQueryWithCallback(GeneralStatement.java:173)
com.ibatis.sqlmap.engine.mapping.statement.GeneralStatement.executeQueryForObject(GeneralStatement.java:104)
com.ibatis.sqlmap.engine.mapping.statement.CachingStatement.executeQueryForObject(CachingStatement.java:79)
com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.queryForObject(SqlMapExecutorDelegate.java:565)
com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.queryForObject(SqlMapExecutorDelegate.java:540)
com.ibatis.sqlmap.engine.impl.SqlMapSessionImpl.queryForObject(SqlMapSessionImpl.java:106)
org.springframework.orm.ibatis.SqlMapClientTemplate$1.doInSqlMapClient(SqlMapClientTemplate.java:210)
org.springframework.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:168)
org.springframework.orm.ibatis.SqlMapClientTemplate.queryForObject(SqlMapClientTemplate.java:208)
com.omegames.kilometres.dao.composants.ibatis.SqlMapActionnableCmpDao.getForGameObject(SqlMapActionnableCmpDao.java:33)
com.omegames.kilometres.dao.impl.GameObjectComponentsDaoImpl.setComponentsForGameObject(GameObjectComponentsDaoImpl.java:196)
com.omegames.kilometres.dao.impl.GameObjectComponentsDaoImpl.setComponentsForGameObjects(GameObjectComponentsDaoImpl.java:214)
com.omegames.kilometres.dao.ibatis.SqlMapDepotDao.getObjetsDeposes(SqlMapDepotDao.java:37)
com.omegames.kilometres.service.impl.DepotManagerImpl.getObjetsDeposes(DepotManagerImpl.java:73)
com.omegames.kilometres.service.impl.DepotManagerImpl.objetDepose(DepotManagerImpl.java:68)
com.omegames.kilometres.service.impl.DepotManagerImpl.aDejaDeposeIci(DepotManagerImpl.java:59)
sun.reflect.GeneratedMethodAccessor1077.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
java.lang.reflect.Method.invoke(Method.java:585)
org.codehaus.groovy.reflection.CachedMethod.invokeByReflection(CachedMethod.java:107)
org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:127)
org.codehaus.groovy.runtime.metaclass.StdMetaMethod.invoke(StdMetaMethod.java:18)
org.codehaus.groovy.runtime.MetaClassHelper.doMethodInvoke(MetaClassHelper.java:538)
groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:749)
groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:589)
org.codehaus.groovy.runtime.Invoker.invokePojoMethod(Invoker.java:87)
org.codehaus.groovy.runtime.Invoker.invokeMethod(Invoker.java:75)
org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:74)
org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodN(ScriptBytecodeAdapter.java:158)
script1200048329685.run(script1200048329685.groovy:3)
sun.reflect.GeneratedMethodAccessor1228.invoke(Unknown Source)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
java.lang.reflect.Method.invoke(Method.java:585)
org.codehaus.groovy.reflection.CachedMethod.invokeByReflection(CachedMethod.java:107)
org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:127)
org.codehaus.groovy.runtime.metaclass.StdMetaMethod.invoke(StdMetaMethod.java:18)
org.codehaus.groovy.runtime.MetaClassHelper.doMethodInvoke(MetaClassHelper.java:538)
groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:749)
groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:589)
groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:521)
groovy.lang.GroovyObjectSupport.invokeMethod(GroovyObjectSupport.java:44)
groovy.lang.Script.invokeMethod(Script.java:78)
com.omegames.kilometres.service.impl.ScriptManagerImpl.run(ScriptManagerImpl.java:89)
com.omegames.kilometres.service.impl.ScriptManagerImpl.run(ScriptManagerImpl.java:75)
com.omegames.kilometres.service.impl.ActionManagerImpl.isVisible(ActionManagerImpl.java:177)
com.omegames.kilometres.service.impl.ActionManagerImpl.getActionDisponibles(ActionManagerImpl.java:71)
com.omegames.kilometres.web.jeu.JeuController.handleRequest(JeuController.java:71)
org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:44)
org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:723)
org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:663)
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:394)
org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:348)
javax.servlet.http.HttpServlet.service(HttpServlet.java:690)
javax.servlet.http.HttpServlet.service(HttpServlet.java:803)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:269)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:264)
org.acegisecurity.intercept.web.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:107)
org.acegisecurity.intercept.web.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:72)
org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
org.acegisecurity.ui.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:110)
org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
org.acegisecurity.providers.anonymous.AnonymousProcessingFilter.doFilter(AnonymousProcessingFilter.java:125)
org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
org.acegisecurity.ui.rememberme.RememberMeProcessingFilter.doFilter(RememberMeProcessingFilter.java:142)
org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
org.acegisecurity.wrapper.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:81)
org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
org.acegisecurity.ui.AbstractProcessingFilter.doFilter(AbstractProcessingFilter.java:217)
org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
org.acegisecurity.ui.logout.LogoutFilter.doFilter(LogoutFilter.java:106)
org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
org.acegisecurity.context.HttpSessionContextIntegrationFilter.doFilter(HttpSessionContextIntegrationFilter.java:229)
org.acegisecurity.util.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:274)
org.acegisecurity.util.FilterChainProxy.doFilter(FilterChainProxy.java:148)
org.acegisecurity.util.FilterToBeanProxy.doFilter(FilterToBeanProxy.java:98)
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:215)
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:188)
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:210)
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:174)
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:117)
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:108)
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:151)
org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:200)
org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:283)
org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:773)
org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:703)
org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:895)
org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:685)
java.lang.Thread.run(Thread.java:595)


> Race conditions in Throttle lead to thread blockage popping items from ThrottledPools under stress
> --------------------------------------------------------------------------------------------------
>
>                 Key: IBATIS-249
>                 URL: https://issues.apache.org/jira/browse/IBATIS-249
>             Project: iBatis for Java
>          Issue Type: Bug
>          Components: SQL Maps
>    Affects Versions: 2.1.7
>            Reporter: Jonathan Burstein
>            Assignee: Sven Boden
>             Fix For: 2.2.0
>
>         Attachments: IBATIS-249.diff
>
>
> com.ibatis.common.util.Throttle.increment contains a synchronization error. Currently, when a waiting thread returns from LOCK.wait it will increment count and return without checking that count is below limit. There are a number of situations where LOCK.wait can complete but the count will not be less than the limit:
> 1) The wait was interrupted
> 2) There was a spurious thread wakeup
> 3) Another thread obtained the lock between the time LOCK.notify was called (by a thread calling decrement) and the wait returned.
> The fix here is to re-check the value of count after exiting the wait (using a while loop). A small amount of extra logic is necessary to satisfy maxWait properly.
> ThrottledPool.pop attempts to work around these race conditions by catching swallowing all exceptions from throttle.increment and pool.remove(0) and looping until an item is obtained. Since the increment call is within the loop this logic can lead to multiple increments with no corresponding decrements. Note that an IndexOutOfBound exception from pool.remove(0) is an artifact of the bug in Throttle.increment -- this could never occur if Throttle behaved correctly.
> This routine should simple call throttle.increment and pool.remove(0). It should most certainly not swallow exceptions.
> Finally, ThrottledPool.push incorrectly calls throttle.decrement if the parameter is invalid (null or of an incorrect type).

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.