首页 > 解决方案 > 如何在异常堆栈中停止 log4j2 加载类?

问题描述

Log4j2 会在打印异常堆栈跟踪时加载类,但它会使用不正确的类加载器(org.eclipse.jetty.webapp.WebAppClassLoader,扩展 URLClassLoader,加载类同步)来加载由 aop 生成的类(例如sun.reflect. GeneratedMethodAccessor<\digit>,只能通过DelegateClassLoader)加载,永远无法加载成功。

这是我的服务中的异常堆栈跟踪:

2018-11-30 14:43:09.425 - - [ERROR] com.myservice.mobile.message.group.deal.RPCGroupDealService-2-thread-30 ThriftServerInvoker #XMDT#{__ptTest__=true __traceId__=4869019290298993826}#XMDT# mtthrift server invoker Exception:null, cause:
Error querying database.  Cause: java.sql.SQLException: com.alibaba.druid.pool.GetConnectionTimeoutException: wait millis 50, active 20, maxActive 20
at com.alibaba.druid.pool.DruidDataSource.getConnectionInternal(DruidDataSource.java:1155)
at com.alibaba.druid.pool.DruidDataSource.getConnectionDirect(DruidDataSource.java:977)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:957)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:947)
at com.alibaba.druid.pool.DruidDataSource.getConnection(DruidDataSource.java:102)
at com.mycompany.zebra.single.jdbc.SingleDataSource.getConnectionOrigin(SingleDataSource.java:212)
at com.mycompany.zebra.single.jdbc.SingleDataSource.access$000(SingleDataSource.java:31)
at com.mycompany.zebra.single.jdbc.SingleDataSource$2.getSingleConnection(SingleDataSource.java:197)
at com.mycompany.zebra.filter.wall.WallFilter.getSingleConnection(WallFilter.java:120)
at com.mycompany.zebra.single.jdbc.SingleDataSource$2.getSingleConnection(SingleDataSource.java:195)
at com.mycompany.zebra.filter.DefaultJdbcFilter.getSingleConnection(DefaultJdbcFilter.java:75)
at com.mycompany.zebra.single.jdbc.SingleDataSource$2.getSingleConnection(SingleDataSource.java:195)
at com.mycompany.zebra.filter.DefaultJdbcFilter.getSingleConnection(DefaultJdbcFilter.java:75)
at com.mycompany.zebra.single.jdbc.SingleDataSource$2.getSingleConnection(SingleDataSource.java:195)
at com.mycompany.zebra.filter.DefaultJdbcFilter.getSingleConnection(DefaultJdbcFilter.java:75)
at com.mycompany.zebra.single.jdbc.SingleDataSource$2.getSingleConnection(SingleDataSource.java:195)
at com.mycompany.zebra.monitor.filter.CatFilter.getSingleConnection(CatFilter.java:114)
at com.mycompany.zebra.single.jdbc.SingleDataSource$2.getSingleConnection(SingleDataSource.java:195)
at com.mycompany.zebra.single.jdbc.SingleDataSource.getConnection(SingleDataSource.java:201)
at com.mycompany.zebra.single.jdbc.SingleDataSource.getConnection(SingleDataSource.java:184)
at com.mycompany.zebra.group.datasources.LoadBalancedDataSource.getConnection(LoadBalancedDataSource.java:114)
at com.mycompany.zebra.group.datasources.LoadBalancedDataSource.getConnection(LoadBalancedDataSource.java:80)
at com.mycompany.zebra.group.jdbc.GroupConnection.getReadConnection(GroupConnection.java:176)
at com.mycompany.zebra.group.jdbc.GroupConnection.getRealConnection(GroupConnection.java:192)
at com.mycompany.zebra.group.jdbc.GroupPreparedStatement.executeQuery(GroupPreparedStatement.java:140)
at com.mycompany.zebra.group.jdbc.GroupPreparedStatement.execute(GroupPreparedStatement.java:97)
at org.apache.ibatis.executor.statement.PreparedStatementHandler.query(PreparedStatementHandler.java:39)
at org.apache.ibatis.executor.statement.RoutingStatementHandler.query(RoutingStatementHandler.java:55)
at org.apache.ibatis.executor.SimpleExecutor.doQuery(SimpleExecutor.java:41)
at org.apache.ibatis.executor.BaseExecutor.queryFromDatabase(BaseExecutor.java:243)
at org.apache.ibatis.executor.BaseExecutor.query(BaseExecutor.java:117)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:79)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:73)
at sun.reflect.GeneratedMethodAccessor29.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at org.mybatis.spring.SqlSessionTemplate$SqlSessionInterceptor.invoke(SqlSessionTemplate.java:350)
at com.sun.proxy.$Proxy44.selectList(Unknown Source)
at org.mybatis.spring.SqlSessionTemplate.selectList(SqlSessionTemplate.java:190)
at com.myservice.mobile.group.biz.domain.dao.DealPoiDao.selectByPoiidsAndDpStatus(DealPoiDao.java:89)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:318)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
at com.myservice.deal.aspects.aj.MonitorAspect.wrap(MonitorAspect.java:72)
at com.myservice.deal.aspects.aj.MonitorAspect.wrapMethod(MonitorAspect.java:41)
at sun.reflect.GeneratedMethodAccessor26.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
at com.myservice.mobile.group.biz.common.aspect.DaoFlowControlAspect.doFlowControl(DaoFlowControlAspect.java:25)
at sun.reflect.GeneratedMethodAccessor28.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at com.sun.proxy.$Proxy45.selectByPoiidsAndDpStatus(Unknown Source)
at com.myservice.mobile.group.biz.service.PoiDealService.getPoiDealFromDB(PoiDealService.java:118)
at com.myservice.mobile.group.biz.service.PoiDealService.getPoiDealMap(PoiDealService.java:91)
at com.myservice.mobile.group.octo.DealThriftProcessor.listDidByEqualsPoiidsAndDpStatus(DealThriftProcessor.java:283)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:318)
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:80)
at com.myservice.deal.aspects.aj.MonitorAspect.wrap(MonitorAspect.java:72)
at com.myservice.deal.aspects.aj.MonitorAspect.wrapMethod(MonitorAspect.java:41)
at sun.reflect.GeneratedMethodAccessor26.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethodWithGivenArgs(AbstractAspectJAdvice.java:621)
at org.springframework.aop.aspectj.AbstractAspectJAdvice.invokeAdviceMethod(AbstractAspectJAdvice.java:610)
at org.springframework.aop.aspectj.AspectJAroundAdvice.invoke(AspectJAroundAdvice.java:65)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:161)
at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:90)
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:202)
at com.sun.proxy.$Proxy48.listDidByEqualsPoiidsAndDpStatus(Unknown Source)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at com.myservice.mobile.mtthrift.proxy.ThriftServerInvoker.invoke(ThriftServerInvoker.java:187)
at com.sun.proxy.$Proxy48.listDidByEqualsPoiidsAndDpStatus(Unknown Source)
at com.myservice.mobile.message.group.deal.RPCGroupDealService$Processor$listDidByEqualsPoiidsAndDpStatus.getResult(RPCGroupDealService.java:726)
at com.myservice.mobile.message.group.deal.RPCGroupDealService$Processor$listDidByEqualsPoiidsAndDpStatus.getResult(RPCGroupDealService.java:715)
at org.apache.thrift.ProcessFunction.process(ProcessFunction.java:32)
at org.apache.thrift.TBaseProcessor.process(TBaseProcessor.java:34)
at com.myservice.mobile.mtthrift.proxy.ThriftServerPublisher$MtTProcessor.process(ThriftServerPublisher.java:416)
at com.myservice.mobile.mtthrift.server.netty.DefaultServerHandler.handleRequest(DefaultServerHandler.java:138)
at com.myservice.mobile.mtthrift.server.netty.DefaultServerHandler$1.run(DefaultServerHandler.java:106)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:722)

当突然发生大量异常时,工作线程会阻塞在 log4j2 类加载器加载 GeneratedMethodAccessor<\digit> 上。

这是锁定在方法 loadClass 上的工作线程堆栈:

在此处输入图像描述

标签: javalog4jclassloaderlog4j2

解决方案


此问题是由格式化“扩展堆栈跟踪”时发生的类加载引起的,如ThrowableProxy.toExtendedStackTrace您的示例所示。

您可以通过添加到您的 PatternLayout 来禁用扩展堆栈跟踪alwaysWriteExceptions="false"(然后添加您自己的异常格式化程序,例如%ex,而不是),例如:

        <PatternLayout pattern="%d{ISO8601}{GMT} %m%n%ex" alwaysWriteExceptions="false"/>

我已经验证这可以解决我的问题。

请注意,这个问题不仅会导致锁定,还可能由于 JAR 解压缩发生在 Tomcat 的类加载器中而导致性能下降。


推荐阅读