wildfly：由于日志记录线程，线程被阻塞

问题描述 投票：0回答：1

我们正在使用 Wildfly-9.01 作为 Java Web 应用程序。 对于日志记录，我们使用 log4j-1.2.17.jar 在负载条件下，应用程序使用更多 CPU 并且变得无响应。

检查 threaddump 后，我们发现有许多线程处于 BLOCKED 状态。

下面的日志线程阻塞了其他线程（大约 100 个线程）

 "EJB default - 863" #2445 prio=5 os_prio=0 tid=0x00007feee00ec800 nid=0xc10c5 waiting for monitor entry [0x00007fed29cc8000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.jboss.logmanager.handlers.WriterHandler.doPublish(WriterHandler.java:56)
    - locked <0x00007ff027670520> (a java.lang.Object)
    at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:76)
    at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:314)
    at org.jboss.logmanager.Logger.logRaw(Logger.java:850)
    at org.apache.log4j.Category.callAppenders(Category.java:69)
    at org.apache.log4j.Category.forcedLog(Category.java:121)
    at org.apache.log4j.Category.debug(Category.java:82)
    at com.mypp.dms.locking.dao.LockDAO.getObjectActivityLockByLockedObjectIds(LockDAO.java:259)
    at com.mypp.collab.locking.bizlogic.AdoddleLockEJB.getObjectActivityLockByLockedObjectIds(AdoddleLockEJB.java:173)
    at sun.reflect.GeneratedMethodAccessor335.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:437)
    at org.jboss.as.weld.ejb.DelegatingInterceptorInvocationContext.proceed(DelegatingInterceptorInvocationContext.java:87)
    at org.jboss.weld.interceptor.proxy.WeldInvocationContext.interceptorChainCompleted(WeldInvocationContext.java:98)
    at org.jboss.weld.interceptor.proxy.WeldInvocationContext.proceed(WeldInvocationContext.java:117)
    at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorBase.invokeInCallerTx(TransactionalInterceptorBase.java:104)
    at com.arjuna.ats.jta.cdi.transactional.TransactionalInterceptorRequired.intercept(TransactionalInterceptorRequired.java:54)
    at sun.reflect.GeneratedMethodAccessor334.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:74)
    at org.jboss.weld.interceptor.proxy.WeldInvocationContext.invokeNext(WeldInvocationContext.java:83)
    at org.jboss.weld.interceptor.proxy.WeldInvocationContext.proceed(WeldInvocationContext.java:115)
    at org.jboss.weld.bean.InterceptorImpl.intercept(InterceptorImpl.java:106)
    at org.jboss.as.weld.ejb.DelegatingInterceptorInvocationContext.proceed(DelegatingInterceptorInvocationContext.java:77)
    at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.delegateInterception(Jsr299BindingsInterceptor.java:68)
    at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:80)
    at org.jboss.as.weld.ejb.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:93)
    at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.jpa.interceptor.SBInvocationInterceptor.processInvocation(SBInvocationInterceptor.java:47)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:437)
    at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73)
    at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:83)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
    at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:51)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:275)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:327)
    at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:79)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:53)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:66)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
    at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:634)
    at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:356)
    at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)
    at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:340)
    at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)
    at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:195)
    at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.invokeMethod(MethodInvocationMessageHandler.java:331)
    at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler.access$100(MethodInvocationMessageHandler.java:69)
    at org.jboss.as.ejb3.remote.protocol.versionone.MethodInvocationMessageHandler$1.run(MethodInvocationMessageHandler.java:202)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)
    at org.jboss.threads.JBossThread.run(JBossThread.java:320)

   Locked ownable synchronizers:
    - <0x00007ff03c0f32c0> (a java.util.concurrent.ThreadPoolExecutor$Worker)

由于上述线程而阻塞的其他线程的堆栈跟踪

"EJB default - 1974" #3695 prio=5 os_prio=0 tid=0x00007fef8408d000 nid=0xc2451 waiting for monitor entry [0x00007fece2758000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.jboss.logmanager.handlers.WriterHandler.doPublish(WriterHandler.java:56)
    - waiting to lock <0x00007ff027670520> (a java.lang.Object)
    at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:76)
    at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:314)
    at org.jboss.logmanager.Logger.logRaw(Logger.java:850)
    at org.apache.log4j.Category.callAppenders(Category.java:69)
    at org.apache.log4j.Category.forcedLog(Category.java:121)
    at org.apache.log4j.Category.debug(Category.java:82)
    at com.mypp.dms.forms.create.persistence.dao.FormCreateDAO.insertFormMessage(FormCreateDAO.java:246)



"EJB default - 1926" #3644 prio=5 os_prio=0 tid=0x00007fedc01d5000 nid=0xc241b waiting for monitor entry [0x00007fece5486000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.jboss.logmanager.handlers.WriterHandler.doPublish(WriterHandler.java:56)
    - waiting to lock <0x00007ff027670520> (a java.lang.Object)
    at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:76)
    at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:314)
    at org.jboss.logmanager.Logger.logRaw(Logger.java:850)
    at org.apache.log4j.Category.callAppenders(Category.java:69)
    at org.apache.log4j.Category.forcedLog(Category.java:121)
    at org.apache.log4j.Category.debug(Category.java:82)
    at com.mypp.dms.distribute.bizlogic.DistributionFacadeEJB.getDistributionGroupsForProjects(DistributionFacadeEJB.java:2855)


"EJB default - 1874" #3579 prio=5 os_prio=0 tid=0x00007ffa34ba1800 nid=0xc23d3 waiting for monitor entry [0x00007fece8dbf000]
   java.lang.Thread.State: BLOCKED (on object monitor)
    at org.jboss.logmanager.handlers.WriterHandler.doPublish(WriterHandler.java:56)
    - waiting to lock <0x00007ff027670520> (a java.lang.Object)
    at org.jboss.logmanager.ExtHandler.publish(ExtHandler.java:76)
    at org.jboss.logmanager.LoggerNode.publish(LoggerNode.java:314)
    at org.jboss.logmanager.Logger.logRaw(Logger.java:850)
    at org.apache.log4j.Category.callAppenders(Category.java:69)
    at org.apache.log4j.Category.forcedLog(Category.java:121)
    at org.apache.log4j.Category.debug(Category.java:82)
    at com.mypp.dms.forms.create.bizlogic.CreateMsgSessionEJB.getFormTypeFixedFields(CreateMsgSessionEJB.java:378)

我参考了一些建议升级log4的帖子。除此之外，是否需要检查任何配置/更改以避免此问题？

感谢您看到这里:-)

java multithreading log4j wildfly-9
1个回答
0
投票

您写道在负载条件下应用程序[...]变得无响应。

您的堆栈跟踪都显示您进行了调试级别日志记录：

...
at org.apache.log4j.Category.debug(Category.java:82)
...

恕我直言，负载条件下的日志记录应配置为仅接受信息及以上级别，甚至可能仅接受警告及以上级别 - 除非您当前正在尝试解决某些问题。

这并不意味着您需要删除那些 

log.debug()
语句。您可以提高记录器的级别(
log4j.rootLogger = WARN, someappender
)。

最新问题
© www.soinside.com 2019 - 2024. All rights reserved.