Uploaded image for project: 'Jira Data Center'
  1. Jira Data Center
  2. JRASERVER-62959

StackTraceInfo Class are initialised multiple times on stack trace logging

    XMLWordPrintable

Details

    Description

      Summary

      StackTraceInfo Class are initialised multiple times on stack trace logging

      Steps to Reproduce

      1. Produce a lot of logging in the same thread

      Expected Results

      No additional overhead and class loading done only once.

      Actual Results

      Thread produces many log messages with stacktrace and each time it tries to load some class from com.atlassian.logging.log4j.FilteredPatternLayout.getThrowableStrRep. This causing slow execution and high CPU usage.
      Progress over time:

      grep -A 50 http-nio-8080-exec-243 jira_threads.20161025-133* | grep -e 'com.atlassian.logging.log4j.FilteredPatternLayout.getThrowableStrRep' -e 'org.apache.log4j.WriterAppender.subAppend' -e 'java.lang.Thread.State' -e 'org.apache.log4j.Category.callAppenders' -e 'org.apache.logging.log4j.core.util.Loader.initializeClass'
      
      jira_threads.20161025-133119.txt-   java.lang.Thread.State: RUNNABLE
      jira_threads.20161025-133119.txt-	at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:310)
      jira_threads.20161025-133119.txt-	at org.apache.log4j.Category.callAppenders(Category.java:206)
      
      jira_threads.20161025-133131.txt-   java.lang.Thread.State: RUNNABLE
      jira_threads.20161025-133131.txt-	at org.apache.logging.log4j.core.util.Loader.initializeClass(Loader.java:66)
      jira_threads.20161025-133131.txt-	at com.atlassian.logging.log4j.FilteredPatternLayout.getThrowableStrRep(FilteredPatternLayout.java:359)
      jira_threads.20161025-133131.txt-	at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:310)
      jira_threads.20161025-133131.txt-	at org.apache.log4j.Category.callAppenders(Category.java:206)
      
      jira_threads.20161025-133142.txt-   java.lang.Thread.State: RUNNABLE
      jira_threads.20161025-133142.txt-	at org.apache.logging.log4j.core.util.Loader.initializeClass(Loader.java:66)
      jira_threads.20161025-133142.txt-	at com.atlassian.logging.log4j.FilteredPatternLayout.getThrowableStrRep(FilteredPatternLayout.java:359)
      jira_threads.20161025-133142.txt-	at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:310)
      jira_threads.20161025-133142.txt-	at org.apache.log4j.Category.callAppenders(Category.java:206)
      
      jira_threads.20161025-133153.txt-   java.lang.Thread.State: BLOCKED (on object monitor)
      jira_threads.20161025-133153.txt-	at org.apache.log4j.Category.callAppenders(Category.java:204)
      
      jira_threads.20161025-133204.txt-   java.lang.Thread.State: RUNNABLE
      jira_threads.20161025-133204.txt-	at com.atlassian.logging.log4j.FilteredPatternLayout.getThrowableStrRep(FilteredPatternLayout.java:359)
      jira_threads.20161025-133204.txt-	at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:310)
      jira_threads.20161025-133204.txt-	at org.apache.log4j.Category.callAppenders(Category.java:206)
      
      jira_threads.20161025-133215.txt-   java.lang.Thread.State: BLOCKED (on object monitor)
      jira_threads.20161025-133215.txt-	at org.apache.log4j.Category.callAppenders(Category.java:204)
      

      Full stacktrace:

      "http-nio-8080-exec-243 uri:/secure/admin/views/issuefields/screens/viewfieldscreens.jsp username:" #25366 daemon prio=5 tid=0x00007f41b8055800 nid=0x293d runnable [0x00007f3ec4d7c000]
        java.lang.Thread.State: RUNNABLE
            at java.util.zip.ZipFile.getEntry(Native Method)
            at java.util.zip.ZipFile.getEntry(ZipFile.java:310)
            - locked <0x00000007b5902e30> (a java.util.jar.JarFile)
            at java.util.jar.JarFile.getEntry(JarFile.java:240)
            at java.util.jar.JarFile.getJarEntry(JarFile.java:223)
            at org.apache.catalina.webresources.JarResourceSet.getArchiveEntry(JarResourceSet.java:120)
            at org.apache.catalina.webresources.AbstractArchiveResourceSet.getResource(AbstractArchiveResourceSet.java:260)
            at org.apache.catalina.webresources.StandardRoot.getResourceInternal(StandardRoot.java:281)
            at org.apache.catalina.webresources.Cache.getResource(Cache.java:63)
            at org.apache.catalina.webresources.StandardRoot.getResource(StandardRoot.java:216)
            at org.apache.catalina.webresources.StandardRoot.getClassLoaderResource(StandardRoot.java:225)
            at org.apache.catalina.loader.WebappClassLoaderBase.findResourceInternal(WebappClassLoaderBase.java:2569)
            at org.apache.catalina.loader.WebappClassLoaderBase.findClassInternal(WebappClassLoaderBase.java:2406)
            at org.apache.catalina.loader.WebappClassLoaderBase.findClass(WebappClassLoaderBase.java:831)
            at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1274)
            - locked <0x0000000401a8d810> (a org.apache.catalina.loader.WebappClassLoader)
            at org.apache.catalina.loader.WebappClassLoaderBase.loadClass(WebappClassLoaderBase.java:1139)
            at java.lang.Class.forName0(Native Method)
            at java.lang.Class.forName(Class.java:348)
            at org.apache.logging.log4j.core.util.Loader.initializeClass(Loader.java:66)
            at org.apache.logging.log4j.core.impl.ThrowableProxy.loadClass(ThrowableProxy.java:501)
            at org.apache.logging.log4j.core.impl.ThrowableProxy.toExtendedStackTrace(ThrowableProxy.java:629)
            at org.apache.logging.log4j.core.impl.ThrowableProxy.<init>(ThrowableProxy.java:111)
            at com.atlassian.logging.log4j.StackTraceInfo.buildPackagingRepresentation(StackTraceInfo.java:145)
            at com.atlassian.logging.log4j.StackTraceInfo.buildThrowableStrRep(StackTraceInfo.java:106)
            at com.atlassian.logging.log4j.StackTraceInfo.<init>(StackTraceInfo.java:43)
            at com.atlassian.logging.log4j.FilteredPatternLayout.getThrowableStrRep(FilteredPatternLayout.java:359)
            at com.atlassian.logging.log4j.FilteredPatternLayout.formatStackTrace(FilteredPatternLayout.java:336)
            at com.atlassian.logging.log4j.FilteredPatternLayout.format(FilteredPatternLayout.java:330)
            at org.apache.log4j.WriterAppender.subAppend(WriterAppender.java:310)
            at org.apache.log4j.RollingFileAppender.subAppend(RollingFileAppender.java:276)
            at org.apache.log4j.WriterAppender.append(WriterAppender.java:162)
            at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
            - locked <0x0000000401138288> (a org.apache.log4j.RollingFileAppender)
            at com.atlassian.jira.logging.JiraHomeAppender.doAppend(JiraHomeAppender.java:206)
            at org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
            at org.apache.log4j.Category.callAppenders(Category.java:206)
            - locked <0x000000040113de30> (a org.apache.log4j.Logger)
            at org.apache.log4j.Category.forcedLog(Category.java:391)
            at org.apache.log4j.Category.log(Category.java:856)
            at org.slf4j.impl.Log4jLoggerAdapter.log(Log4jLoggerAdapter.java:601)
            at org.apache.commons.logging.impl.SLF4JLocationAwareLog.error(SLF4JLocationAwareLog.java:225)
            at webwork.util.ValueStack.findValue(ValueStack.java:532)
            at webwork.util.SimpleTest.test(SimpleTest.java:408)
            at webwork.util.ValueStack.test(ValueStack.java:157)
            at webwork.view.taglib.IfTag.doStartTag(IfTag.java:40)
            at jsp.secure.admin.views.issuefields.screens.viewfieldscreens_jsp._jspx_meth_ww_005fif_005f6(viewfieldscreens_jsp.java:2355)
            at jsp.secure.admin.views.issuefields.screens.viewfieldscreens_jsp._jspService(viewfieldscreens_jsp.java:281)
            at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
      ...
      

      Notes

      None

      Workaround

      None

      Attachments

        Issue Links

          Activity

            People

              Unassigned Unassigned
              ayakovlev@atlassian.com Andriy Yakovlev [Atlassian]
              Votes:
              0 Vote for this issue
              Watchers:
              5 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: