Потоки блокировки Weblogic привели к тому, что приложение перестало отвечать

#multithreading #oracle #weblogic #blocked

#многопоточность #Oracle #weblogic #заблокировано

Вопрос:

Мы столкнулись с проблемой в нашей производственной среде с несколькими блокирующими потоками, и при проверке дампов потоков обнаружили приведенную ниже трассировку стека, где в 14 блокирующих потоках присутствовали одинаковые описания. Мы высоко ценим любую помощь в приведенном ниже вопросе.

Мы используем weblogic версии 10.3.6.0 и JDK 1.7.0_80.

ExecuteThread: ‘387’ заблокирован, поскольку ExecuteThread: ‘159’ уже удерживает блокировку и выполняется длительное время.

======================

 "[ACTIVE] ExecuteThread: '387' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00002ac72d4f4000 nid=0x530d waiting for monitor entry [0x00002ac767c38000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.springframework.beans.factory.support.AbstractBeanFactory.getMergedBeanDefinition(AbstractBeanFactory.java:1030)
- waiting to lock <0x000000051ea30728> (a java.util.concurrent.ConcurrentHashMap)
at org.springframework.beans.factory.support.AbstractBeanFactory.getMergedBeanDefinition(AbstractBeanFactory.java:1013)
at org.springframework.beans.factory.support.AbstractBeanFactory.getMergedLocalBeanDefinition(AbstractBeanFactory.java:999)
at org.springframework.beans.factory.support.AbstractBeanFactory.isTypeMatch(AbstractBeanFactory.java:433)
  

..

 "[ACTIVE] ExecuteThread: '159' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=0x00002ac7491f5800 nid=0x4781 runnable [0x00002ac7540fd000]
java.lang.Thread.State: RUNNABLE
at org.springframework.beans.factory.support.AbstractBeanFactory.getMergedBeanDefinition(AbstractBeanFactory.java:1030)
- locked <0x000000051ea30728> (a java.util.concurrent.ConcurrentHashMap)
at org.springframework.beans.factory.support.AbstractBeanFactory.getMergedBeanDefinition(AbstractBeanFactory.java:1013)
at org.springframework.beans.factory.support.AbstractBeanFactory.getMergedLocalBeanDefinition(AbstractBeanFactory.java:999)
..
at com.opensymphony.xwork2.spring.SpringObjectFactory.buildBean(SpringObjectFactory.java:151)
  

 [ACTIVE] ExecuteThread: '359' for queue: 'weblogic.kernel.Default (self-tuning)'
[ACTIVE] ExecuteThread: '359' for queue: 'weblogic.kernel.Default (self-tuning)' 
Stack Trace is: 
java.lang.Thread.State: RUNNABLE
at oracle.jdbc.driver.OracleResultSetImpl.getString(OracleResultSetImpl.java:2818)
- locked <0x0000000566efc058> (a oracle.jdbc.driver.T4CConnection)
at oracle.jdbc.driver.OracleResultSet.getString(OracleResultSet.java:1215)
at weblogic.jdbc.wrapper.ResultSet_oracle_jdbc_driver_OracleResultSetImpl.getString(Unknown Source)
at com.ibatis.sqlmap.engine.type.StringTypeHandler.getResult(StringTypeHandler.java:35)
at com.ibatis.sqlmap.engine.mapping.result.ResultMap.getPrimitiveResultMappingValue(ResultMap.java:619)
at com.ibatis.sqlmap.engine.mapping.result.ResultMap.getResults(ResultMap.java:345)
at com.ibatis.sqlmap.engine.mapping.result.AutoResultMap.getResults(AutoResultMap.java:47)
- locked <0x00000005205e0968> (a com.ibatis.sqlmap.engine.mapping.result.AutoResultMap)
at com.ibatis.sqlmap.engine.execution.SqlExecutor.handleResults(SqlExecutor.java:384)
at com.ibatis.sqlmap.engine.execution.SqlExecutor.handleMultipleResults(SqlExecutor.java:300)
at com.ibatis.sqlmap.engine.execution.SqlExecutor.executeQuery(SqlExecutor.java:189)
at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.sqlExecuteQuery(MappedStatement.java:221)
at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.executeQueryWithCallback(MappedStatement.java:189)
at com.ibatis.sqlmap.engine.mapping.statement.MappedStatement.executeQueryForList(MappedStatement.java:139)
at com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.queryForList(SqlMapExecutorDelegate.java:567)
at com.ibatis.sqlmap.engine.impl.SqlMapExecutorDelegate.queryForList(SqlMapExecutorDelegate.java:541)
at com.ibatis.sqlmap.engine.impl.SqlMapSessionImpl.queryForList(SqlMapSessionImpl.java:118)
at org.springframework.orm.ibatis.SqlMapClientTemplate$3.doInSqlMapClient(SqlMapClientTemplate.java:298)
at org.springframework.orm.ibatis.SqlMapClientTemplate.execute(SqlMapClientTemplate.java:209)
at org.springframework.orm.ibatis.SqlMapClientTemplate.executeWithListResult(SqlMapClientTemplate.java:249)
at org.springframework.orm.ibatis.SqlMapClientTemplate.queryForList(SqlMapClientTemplate.java:296)
at org.springframework.orm.ibatis.SqlMapClientTemplate.queryForList(SqlMapClientTemplate.java:290)
at com.dms.common.masters.daos.HomeDaoImpl.populateDropDowns(Unknown Source)
at com.dms.common.masters.daos.HomeDaoImpl$$FastClassByCGLIB$$dda6d555.invoke(<generated>)
at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:191)
at org.springframework.aop.framework.Cglib2AopProxy$CglibMethodInvocation.invokeJoinpoint(Cglib2AopProxy.java:696)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:149)
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:106)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:89)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:171)
at org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:631)
at com.dms.common.masters.daos.HomeDaoImpl$$EnhancerByCGLIB$$7cce49ec.populateDropDowns(<generated>)
at com.dms.common.masters.business.HomeBusinessImpl.populateDropDowns(Unknown Source)
at com.dms.common.masters.service.HomeServiceImpl.populateDropDowns(Unknown Source)
at com.dms.common.masters.action.HomeAction.menu(Unknown Source)
at sun.reflect.GeneratedMethodAccessor54415.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.opensymphony.xwork2.DefaultActionInvocation.invokeAction(DefaultActionInvocation.java:450)
at com.opensymphony.xwork2.DefaultActionInvocation.invokeActionOnly(DefaultActionInvocation.java:289)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:252)
at org.apache.struts2.interceptor.MultiselectInterceptor.intercept(MultiselectInterceptor.java:73)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at com.opensymphony.xwork2.interceptor.ConversionErrorInterceptor.intercept(ConversionErrorInterceptor.java:138)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at com.opensymphony.xwork2.interceptor.ParametersInterceptor.doIntercept(ParametersInterceptor.java:254)
at com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:98)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at com.opensymphony.xwork2.interceptor.StaticParametersInterceptor.intercept(StaticParametersInterceptor.java:191)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at org.apache.struts2.interceptor.CheckboxInterceptor.intercept(CheckboxInterceptor.java:91)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at org.apache.struts2.interceptor.FileUploadInterceptor.intercept(FileUploadInterceptor.java:252)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at com.opensymphony.xwork2.interceptor.ModelDrivenInterceptor.intercept(ModelDrivenInterceptor.java:100)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at com.opensymphony.xwork2.interceptor.ScopedModelDrivenInterceptor.intercept(ScopedModelDrivenInterceptor.java:141)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at com.opensymphony.xwork2.interceptor.ChainingInterceptor.intercept(ChainingInterceptor.java:145)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at com.opensymphony.xwork2.interceptor.I18nInterceptor.intercept(I18nInterceptor.java:139)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at com.opensymphony.xwork2.interceptor.PrepareInterceptor.doIntercept(PrepareInterceptor.java:171)
at com.opensymphony.xwork2.interceptor.MethodFilterInterceptor.intercept(MethodFilterInterceptor.java:98)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at org.apache.struts2.interceptor.ServletConfigInterceptor.intercept(ServletConfigInterceptor.java:164)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at com.opensymphony.xwork2.interceptor.AliasInterceptor.intercept(AliasInterceptor.java:193)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at com.opensymphony.xwork2.interceptor.ExceptionMappingInterceptor.intercept(ExceptionMappingInterceptor.java:189)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at com.utils.LoginInterceptor.intercept(Unknown Source)
at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:246)
at org.apache.struts2.impl.StrutsActionProxy.execute(StrutsActionProxy.java:54)
at org.apache.struts2.dispatcher.Dispatcher.serviceAction(Dispatcher.java:562)
at org.apache.struts2.dispatcher.ng.ExecuteOperations.executeAction(ExecuteOperations.java:77)
at org.apache.struts2.dispatcher.ng.filter.StrutsPrepareAndExecuteFilter.doFilter(StrutsPrepareAndExecuteFilter.java:99)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:60)
at com.opensymphony.module.sitemesh.filter.PageFilter.parsePage(PageFilter.java:118)
at com.opensymphony.module.sitemesh.filter.PageFilter.doFilter(PageFilter.java:52)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:60)
at com.utils.SetResponseBufferFilter.doFilter(Unknown Source)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:60)
at oracle.security.jps.ee.http.JpsAbsFilter$1.run(JpsAbsFilter.java:119)
at java.security.AccessController.doPrivileged(Native Method)
at oracle.security.jps.util.JpsSubject.doAsPrivileged(JpsSubject.java:324)
at oracle.security.jps.ee.util.JpsPlatformUtil.runJaasMode(JpsPlatformUtil.java:460)
at oracle.security.jps.ee.http.JpsAbsFilter.runJaasMode(JpsAbsFilter.java:103)
at oracle.security.jps.ee.http.JpsAbsFilter.doFilter(JpsAbsFilter.java:171)
at oracle.security.jps.ee.http.JpsFilter.doFilter(JpsFilter.java:71)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:60)
at oracle.dms.servlet.DMSServletFilter.doFilter(DMSServletFilter.java:163)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:60)
at weblogic.servlet.internal.RequestEventsFilter.doFilter(RequestEventsFilter.java:27)
at weblogic.servlet.internal.FilterChainImpl.doFilter(FilterChainImpl.java:60)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.wrapRun(WebAppServletContext.java:3748)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:3714)
at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:120)
at weblogic.servlet.internal.WebAppServletContext.securedExecute(WebAppServletContext.java:2283)
at weblogic.servlet.internal.WebAppServletContext.execute(WebAppServletContext.java:2182)
at weblogic.servlet.internal.ServletRequestImpl.run(ServletRequestImpl.java:1499)
at weblogic.work.ExecuteThread.execute(ExecuteThread.java:263)
at weblogic.work.ExecuteThread.run(ExecuteThread.java:221)
Locked ownable synchronizers:
- None
  

Комментарии:

1. этот стек не показывает «заблокированный» поток, как вы говорите. Оно запущено, может быть, очень медленно, но оно запущено. С другой стороны, похоже, что на вашем сервере weblogic запущено очень большое количество потоков выполнения, от 350 до 400. Вы можете подтвердить?

2. Привет, спасибо за быстрый ответ, когда я пытаюсь проанализировать дампы потоков, я обнаружил несколько блокирующих потоков. Извините за невежество, потрудитесь объяснить, как мне проверить количество потоков выполнения.

3. Можете ли вы предоставить общий доступ к трассировкам стека из «заблокированных» потоков? Выполняемый поток имеет идентификатор 359. WebLogic начинается с 1 и по умолчанию может создавать до 400 потоков.

4. @EmmanuelCollin обновил сообщение обновленным стеком потоков, также я проверил дампы потоков с помощью fastthread. ввод-вывод и показывает, что более 40% потоков были заблокированы.

Ответ №1:

Заблокированные потоки не обязательно являются проблемой, в java при обработке параллельных запросов и использовании одноэлементных классов или хэш-карт и т.д. Естественно иметь некоторую блокировку как средство достижения целостности данных… Когда принимать дампы потоков — Когда сервер weblogic сообщает о застрявших потоках или вы получаете общую медлительность в ответе (хотя этому способствуют многие другие факторы)

Как удалить дампы потоков — Всегда используйте 3-4 дампы потоков с интервалом в 1-2 секунды. Просмотр 1 мгновенного дампа потока обычно не дает полной картины.. Если вы заметили, что одни и те же потоки находятся в заблокированном состоянии почти во всех 3-4 дампах, проверьте, какой поток удерживает блокировку и что он делает, выполняет ли поток, удерживающий блокировку, одну и ту же задачу во всех 4 дампах, если да, то вы получили подсказку о том, что нужно устранить..

В дампе потока, который вы предоставили..

ExecuteThread: ‘387’ ожидает блокировки <0x000000051ea30728>

и ExecuteThread: ‘159’ остается заблокированным <0x000000051ea30728>, но 159 находится в работоспособном состоянии, что означает, что он не застрял и выполняет свои обычные операции..

если вы сделали несколько дампов потоков и увидели, что 159 удерживает блокировку слишком долго, вам нужно подумать о настройке вашего приложения и, по возможности, об обходном пути вокруг этой блокировки.

Ответ №2:

Проблема, по-видимому, связана с блокировкой, com.ibatis.sqlmap.engine.mapping.result.AutoResultMap предполагающей, что часть кода синхронизирована, что означает, что ОДНОВРЕМЕННО будет выполняться ТОЛЬКО один поток.

Если вы соберете дамп потока, вы увидите, что несколько потоков ожидают блокировки, и только один выполняет что-то вроде:

 "[ACTIVE] ExecuteThread: '339' for queue: 'weblogic.kernel.Default (self-tuning)'" daemon prio=10 tid=REMOVED nid=REMOVED runnable [REMOVED]
   java.lang.Thread.State: RUNNABLE
    at weblogic.jdbc.wrapper.ResultSet_oracle_jdbc_driver_OracleResultSetImpl.wasNull(Unknown Source)
    at com.ibatis.sqlmap.engine.type.StringTypeHandler.getResult(StringTypeHandler.java:36)
    at com.ibatis.sqlmap.engine.mapping.result.ResultMap.getPrimitiveResultMappingValue(ResultMap.java:619)
    at com.ibatis.sqlmap.engine.mapping.result.ResultMap.getResults(ResultMap.java:345)
    at com.ibatis.sqlmap.engine.mapping.result.AutoResultMap.getResults(AutoResultMap.java:47)
    - locked <0x00000004544b7328> (a com.ibatis.sqlmap.engine.mapping.result.AutoResultMap)
    at com.ibatis.sqlmap.engine.execution.SqlExecutor.handleResults(SqlExecutor.java:384)
    at com.ibatis.sqlmap.engine.execution.SqlExecutor.handleMultipleResults(SqlExecutor.java:300)
  

Это подводит нас к другому вопросу: поддерживает ли iBatis многопоточность? На основании следующей ссылки ответ отрицательный:

Mybatis не работает в многопоточном программировании

При стандартном использовании модуля ядра MyBatis объект SqlSession и mapper не поддерживает потокобезопасность. Это дизайн. MyBatis предоставляют SqlSessionManager для поддержки потокобезопасности в качестве необязательного компонента.

https://github.com/mybatis/mybatis-3/issues/1529