Uploaded image for project: 'logback'
  1. logback
  2. LOGBACK-1112

PackagingDataCalculator.populateFrames calls Throwable.fillInStackTrace and running of this method is never finished

    XMLWordPrintable

Details

    • Icon: Bug Bug
    • Resolution: Unresolved
    • Icon: Major Major
    • None
    • 1.1.3
    • logback-classic
    • None

    Description

      After 5 hours of running of my application I can see that running of this thread consumes 100% CPU and because of that my mythod is synchronized, it blocks my application forever. I thing the problem is with PackagingDataCalculator.populateFrames and preparing of stack trace.

      I use pattern

      %d{yyyy-MM-dd HH:mm:ss.SSS}|%thread| %m%n%nopex
      
      "http-nio-8686-exec-174" #231 daemon prio=5 os_prio=0 tid=0x0000000000ced800 nid=0x3132 runnable [0x00007f76c6160000]
         java.lang.Thread.State: RUNNABLE
              at java.lang.Throwable.fillInStackTrace(Native Method)
              at java.lang.Throwable.fillInStackTrace(Throwable.java:783)
              - locked <0x0000000710577e68> (a java.lang.Throwable)
              at java.lang.Throwable.<init>(Throwable.java:265)
              at ch.qos.logback.classic.spi.PackagingDataCalculator.populateFrames(PackagingDataCalculator.java:71)
              at ch.qos.logback.classic.spi.PackagingDataCalculator.calculate(PackagingDataCalculator.java:57)
              at ch.qos.logback.classic.spi.ThrowableProxy.calculatePackagingData(ThrowableProxy.java:147)
              at ch.qos.logback.classic.spi.LoggingEvent.<init>(LoggingEvent.java:124)
              at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:440)
              at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396)
              at ch.qos.logback.classic.Logger.warn(Logger.java:725)
              at org.myapp.r.impl.Manager.create(Manager.java:104)
              - locked <0x00000006c1b4e5a0> (a org.myapp.r.impl.Manager)
              at org.myapp.r.impl.Manager$$FastClassBySpringCGLIB$$8f0fc1fb.invoke(<generated>)
              at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
              at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:717)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
              at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:97)
              at org.myapp.service.ServerNotifierImpl.logAround(ServerNotifierImpl.java:95)
              at sun.reflect.GeneratedMethodAccessor29.invoke(Unknown Source)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
              at java.lang.reflect.Method.invoke(Method.java:497)
              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:68)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
              at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
              at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:653)
              at org.myapp.r.impl.Manager$$EnhancerBySpringCGLIB$$a26ad0d3.create(<generated>)
              at org.myapp.service.RestLineCreateController.create(RestLineCreateController.java:101)
              at org.myapp.service.RestLineCreateController$$FastClassBySpringCGLIB$$d8fabc30.invoke(<generated>)
              at org.springframework.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
              at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.invokeJoinpoint(CglibAopProxy.java:717)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:157)
              at org.springframework.aop.aspectj.MethodInvocationProceedingJoinPoint.proceed(MethodInvocationProceedingJoinPoint.java:97)
              at org.myapp.service.DebugInterceptor.logAround(DebugInterceptor.java:29)
              at sun.reflect.GeneratedMethodAccessor61.invoke(Unknown Source)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
              at java.lang.reflect.Method.invoke(Method.java:497)
              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:68)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
              at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:92)
              at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:179)
              at org.springframework.aop.framework.CglibAopProxy$DynamicAdvisedInterceptor.intercept(CglibAopProxy.java:653)
              at org.myapp.service.RestLineCreateController$$EnhancerBySpringCGLIB$$7ee0c168.create(<generated>)
              at sun.reflect.GeneratedMethodAccessor62.invoke(Unknown Source)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
              at java.lang.reflect.Method.invoke(Method.java:497)
              at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:221)
              at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:137)
              at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:110)
              at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandleMethod(RequestMappingHandlerAdapter.java:776)
              at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:705)
              at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:85)
              at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:959)
              at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:893)
              at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:966)
              at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:868)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:644)
              at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:842)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:291)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.springframework.boot.actuate.autoconfigure.EndpointWebMvcAutoConfiguration$ApplicationContextHeaderFilter.doFilterInternal(EndpointWebMvcAutoConfiguration.java:291)
              at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.springframework.web.filter.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:77)
              at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.springframework.boot.actuate.trace.WebRequestTraceFilter.doFilterInternal(WebRequestTraceFilter.java:102)
              at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:85)
              at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.springframework.boot.actuate.autoconfigure.MetricFilterAutoConfiguration$MetricsFilter.doFilterInternal(MetricFilterAutoConfiguration.java:90)
              at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107)
              at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:239)
              at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
              at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
              at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:106)
              at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:501)
              at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:142)
              at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
              at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
              at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:516)
              at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1086)
              at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:659)
              at org.apache.coyote.http11.Http11NioProtocol$Http11ConnectionHandler.process(Http11NioProtocol.java:223)
              at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1558)
              at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1515)
      
      		        - locked <0x00000006e40572f8> (a org.apache.tomcat.util.net.NioChannel)
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
              at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
              at java.lang.Thread.run(Thread.java:745)
      
         Locked ownable synchronizers:
              - <0x00000006e2b01140> (a java.util.concurrent.ThreadPoolExecutor$Worker)
      
      

      Attachments

        Activity

          People

            logback-dev Logback dev list
            MartinM Marcin M
            Votes:
            0 Vote for this issue
            Watchers:
            1 Start watching this issue

            Dates

              Created:
              Updated: