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

Enabling access logging might cause JIRA to stall

    XMLWordPrintable

Details

    Description

      Summary

      Enabling Access logging (at [ Administration > System > Logging & Profiling ] ) might cause JIRA to stall. Incoming thread will be fighting for org.apache.log4j.Logger lock in AccessLogFilter
      Those logs will be written into atlassian-jira-http-access.log file in <JIRA_HOME>/logs/ folder.

      Steps to Reproduce

      1. Enable Access logging
      2. Generate high load
      3. Start active logging something in different thread.

      Expected Results

      JIRA works fine

      Actual Results

      JIRA stalls.

      • Almost all incoming http threads are blocked waiting to obtain the logger lock to log Access log data from AccessLogFilter - LockID_1
      • Thread http1 hold the lock LockID_1, but it waits for another lock LockID_2
      • Thread http2 holds the lock LockID_2 and does slow execution of some other task during that.
      Thread dump details

      Example of one the threads waiting for LockID_1:

      http-nio-8080-exec-299" #41569 daemon prio=5 tid=0x00007f41c4090000 nid=0x36b9 waiting for monitor entry [0x00007f40c7adc000]
         java.lang.Thread.State: BLOCKED (on object monitor)
      	at org.apache.log4j.Category.callAppenders(Category.java:204)
      	- waiting to lock <0x000000040135e018> (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.info(Log4jLoggerAdapter.java:304)
      	at com.atlassian.jira.web.filters.accesslog.AccessLogFilter.preFilterCallStep(AccessLogFilter.java:194)
      ...
      

      Thread http1

      "http-nio-8080-exec-189" #25297 daemon prio=5 tid=0x00007f41c4056800 nid=0x28f8 waiting for monitor entry [0x00007f40c9045000]
         java.lang.Thread.State: BLOCKED (on object monitor)
      	at org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:231)
      	- waiting to lock <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 <0x000000040135e018> (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.info(Log4jLoggerAdapter.java:304)
      ...
      

      Thread http2:

      "http-nio-8080-exec-243 uri:/secure/admin/views/issuefields/screens/viewfieldscreens.jsp " #25366 daemon prio=5 tid=0x00007f41b8055800 nid=0x293d runnable [0x00007f3ec4d7c000]
         java.lang.Thread.State: RUNNABLE
      	at java.lang.Throwable.fillInStackTrace(Native Method)
      	at java.lang.Throwable.fillInStackTrace(Throwable.java:783)
      	- locked <0x000000077805e9f8> (a java.lang.ClassNotFoundException)
      	at java.lang.Throwable. (Throwable.java:287)
      	at java.lang.Exception. (Exception.java:84)
      	at java.lang.ReflectiveOperationException. (ReflectiveOperationException.java:75)
      	at java.lang.ClassNotFoundException. (ClassNotFoundException.java:82)
      	at java.net.URLClassLoader.findClass(URLClassLoader.java:381)
      	at org.apache.catalina.loader.WebappClassLoaderBase.findClass(WebappClassLoaderBase.java:843)
      	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:264)
      	at org.apache.logging.log4j.util.LoaderUtil.loadClass(LoaderUtil.java:109)
      	at org.apache.logging.log4j.core.util.Loader.loadClass(Loader.java:52)
      	at org.apache.logging.log4j.core.impl.ThrowableProxy.loadClass(ThrowableProxy.java:495)
      	at org.apache.logging.log4j.core.impl.ThrowableProxy.toExtendedStackTrace(ThrowableProxy.java:629)
      	at org.apache.logging.log4j.core.impl.ThrowableProxy. (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. (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)
      ...
      

      Notes

      Workaround

      Disable access logging.

      Attachments

        Issue Links

          Activity

            People

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

              Dates

                Created:
                Updated: