JIRA
  1. JIRA
  2. JRA-20537

Plugins 1 - Shaded log4j - JIRA fails bootstrap with plugins that contain copies of log4j

    Details

    • Type: Bug Bug
    • Status: Open (View Workflow)
    • Priority: Major Major
    • Resolution: Unresolved
    • Affects Version/s: 4.1
    • Fix Version/s: None
    • Component/s: Plugins
    • Labels:
      None
    • Environment:

      Description

      INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: /usr/java/jdk1.6.0_12/jre/lib/i386/client:/usr/java/jdk1.6.0_12/jre/lib/i386:/usr/java/jdk1.6.0_12/jre/../lib/i386:/usr/java/packages/lib/i386:/lib:/usr/lib
      Feb 26, 2010 11:40:17 AM org.apache.coyote.http11.Http11Protocol init
      INFO: Initializing Coyote HTTP/1.1 on http-8080
      Feb 26, 2010 11:40:17 AM org.apache.catalina.startup.Catalina load
      INFO: Initialization processed in 395 ms
      Feb 26, 2010 11:40:17 AM org.apache.catalina.realm.JAASRealm setContainer
      INFO: Set JAAS app name Catalina
      Feb 26, 2010 11:40:17 AM org.apache.catalina.core.StandardService start
      INFO: Starting service Catalina
      Feb 26, 2010 11:40:17 AM org.apache.catalina.core.StandardEngine start
      INFO: Starting Servlet Engine: Apache Tomcat/6.0.20
      0.661: [GC [PSYoungGen: 15168K->1512K(17664K)] 15168K->1512K(259648K), 0.0050020 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] 
      0.906: [GC [PSYoungGen: 16680K->2384K(17664K)] 16680K->2384K(259648K), 0.0047560 secs] [Times: user=0.00 sys=0.00, real=0.01 secs] 
      Feb 26, 2010 11:40:18 AM org.apache.catalina.core.StandardContext start
      SEVERE: Error listenerStart
      Feb 26, 2010 11:40:18 AM org.apache.catalina.core.StandardContext start
      SEVERE: Context [] startup failed due to previous errors
      1.164: [GC [PSYoungGen: 17552K->2484K(17664K)] 17552K->2854K(259648K), 0.0044280 secs] [Times: user=0.01 sys=0.01, real=0.01 secs] 
      log4j:ERROR A "org.apache.log4j.ConsoleAppender" object is not assignable to a "org.apache.log4j.Appender" variable.
      log4j:ERROR The class "org.apache.log4j.Appender" was loaded by 
      log4j:ERROR [org.apache.catalina.loader.StandardClassLoader@1fcf0ce] whereas object of type 
      log4j:ERROR "org.apache.log4j.ConsoleAppender" was loaded by [WebappClassLoader
        delegate: false
        repositories:
          /WEB-INF/classes/
      ----------> Parent Classloader:
      org.apache.catalina.loader.StandardClassLoader@1fcf0ce
      ].
      log4j:ERROR Could not instantiate appender named "console".
      log4j:ERROR A "com.atlassian.jira.logging.JiraHomeAppender" object is not assignable to a "org.apache.log4j.Appender" variable.
      log4j:ERROR The class "org.apache.log4j.Appender" was loaded by 
      log4j:ERROR [org.apache.catalina.loader.StandardClassLoader@1fcf0ce] whereas object of type 
      log4j:ERROR "com.atlassian.jira.logging.JiraHomeAppender" was loaded by [WebappClassLoader
        delegate: false
        repositories:
          /WEB-INF/classes/
      

        Issue Links

          Activity

          Hide
          Pete de Zwart [Atlassian] added a comment -

          This issue was exposed during QA of JRA-20419.

          Show
          Pete de Zwart [Atlassian] added a comment - This issue was exposed during QA of JRA-20419 .
          Hide
          Brenden Bain [Atlassian] added a comment - - edited

          This is basically caused by the hercules plugin including its own version of log4j so that it can include its own version of ant. Talked Sherali so we can fix this for the 4.1 release and SAC.

          In looking at this I believe we should change the way we set up logging for Tomcat 6.x. At the moment we include

          {log4j, sl4j-log4j, jcl-to-slf4j, jul-to-slf4j}

          .jar in $catalina.home/lib. This is problematic because:

          1. Anyone using JCL in Tomcat (e.g. JOTM) would fail to work because log4j would not be configured (we go from JCL -> slf4j -> log4j).
          2. The jul-to-slf4j is not configured correctly anyway. You need to call SLF4JBridgeHandler.install() or configure your JUL environment correctly.

          I suggest we do this:

          1. Include commons-logging-api-1.1.1.jar in $catalina.home/lib. This will make commons logging goto catalina.out (at it currently does).
          2. Move all {log4j, sl4j-log4j, jcl-to-slf4j, jul-to-slf4j}.jar into WEB-INF/lib. This will follow the recomendations of include log4j in your WEB-INF/lib as indicated on http://tomcat.apache.org/tomcat-6.0-doc/logging.html.
          3. Call SLF4JBridgeHandler.install() during startup

          I have tested this configuration with:

          The only downside to this configuration is that a warning message can be displayed on shutdown of JIRA. See https://extranet.atlassian.com/pages/viewinfo.action?pageId=1819574718 for details. I am not sure we can get around this. May need to create a KB.

          We could also consider customizing the $catalina/conf/logging.properties file for standalone. We can remove the handlers that we don't use.

          Finally, we may wish to consider including our own logging.properties in WEB-INF/classes so that we can control logging under Tomcat or maybe just standalone. For example, we could configure the SLF4JBridgeHandler here.

          Show
          Brenden Bain [Atlassian] added a comment - - edited This is basically caused by the hercules plugin including its own version of log4j so that it can include its own version of ant. Talked Sherali so we can fix this for the 4.1 release and SAC. In looking at this I believe we should change the way we set up logging for Tomcat 6.x. At the moment we include {log4j, sl4j-log4j, jcl-to-slf4j, jul-to-slf4j} .jar in $catalina.home/lib. This is problematic because: Anyone using JCL in Tomcat (e.g. JOTM) would fail to work because log4j would not be configured (we go from JCL -> slf4j -> log4j). The jul-to-slf4j is not configured correctly anyway. You need to call SLF4JBridgeHandler.install() or configure your JUL environment correctly. I suggest we do this: Include commons-logging-api-1.1.1.jar in $catalina.home/lib. This will make commons logging goto catalina.out (at it currently does). Move all {log4j, sl4j-log4j, jcl-to-slf4j, jul-to-slf4j}.jar into WEB-INF/lib. This will follow the recomendations of include log4j in your WEB-INF/lib as indicated on http://tomcat.apache.org/tomcat-6.0-doc/logging.html . Call SLF4JBridgeHandler.install() during startup I have tested this configuration with: Plugins v1: JCL, JUL and log4j work as expected. Plugins v2: JCL and log4j work as expected. JUL may work. See https://extranet.atlassian.com/pages/viewpage.action?pageId=1819575088 for details. Bad Database: All logs goto atlassian-jira.log and catalina.out. Bad Server XML: All logs goto catalina.out. The only downside to this configuration is that a warning message can be displayed on shutdown of JIRA. See https://extranet.atlassian.com/pages/viewinfo.action?pageId=1819574718 for details. I am not sure we can get around this. May need to create a KB. We could also consider customizing the $catalina/conf/logging.properties file for standalone. We can remove the handlers that we don't use. Finally, we may wish to consider including our own logging.properties in WEB-INF/classes so that we can control logging under Tomcat or maybe just standalone. For example, we could configure the SLF4JBridgeHandler here.
          Hide
          Brenden Bain [Atlassian] added a comment -

          This will only happen to JIRA v1 plugins that have an embedded version of log4j. People have been running Tomcat 6 with this configuration for a long time and the only complaint has come from Hercules.

          Show
          Brenden Bain [Atlassian] added a comment - This will only happen to JIRA v1 plugins that have an embedded version of log4j. People have been running Tomcat 6 with this configuration for a long time and the only complaint has come from Hercules.
          Hide
          Brenden Bain [Atlassian] added a comment -

          Need to check this out before we go with this deployment: http://bugzilla.slf4j.org/show_bug.cgi?id=22

          Show
          Brenden Bain [Atlassian] added a comment - Need to check this out before we go with this deployment: http://bugzilla.slf4j.org/show_bug.cgi?id=22
          Hide
          Pramod Korathota [Atlassian] added a comment -

          We see this error on EACJ and QA-JAC as well, which does not have hercules:

          2010-08-09 23:47:08.062446500 log4j:ERROR A "org.apache.log4j.ConsoleAppender" object is not assignable to a "org.apache.log4j.Appender" variable.
          2010-08-09 23:47:08.062472500 log4j:ERROR The class "org.apache.log4j.Appender" was loaded by 
          2010-08-09 23:47:08.062536500 log4j:ERROR [org.apache.catalina.loader.StandardClassLoader@1630ab9] whereas object of type 
          2010-08-09 23:47:08.062751500 log4j:ERROR "org.apache.log4j.ConsoleAppender" was loaded by [WebappClassLoader
          2010-08-09 23:47:08.062752500   delegate: false
          2010-08-09 23:47:08.062752500   repositories:
          2010-08-09 23:47:08.062753500     /WEB-INF/classes/
          2010-08-09 23:47:08.062753500 ----------> Parent Classloader:
          2010-08-09 23:47:08.062754500 org.apache.catalina.loader.StandardClassLoader@1630ab9
          2010-08-09 23:47:08.062754500 ].
          2010-08-09 23:47:08.062755500 log4j:ERROR Could not instantiate appender named "console".
          2010-08-09 23:47:08.062755500 log4j:ERROR A "org.apache.log4j.DailyRollingFileAppender" object is not assignable to a "org.apache.log4j.Appender" variable.
          2010-08-09 23:47:08.062763500 log4j:ERROR The class "org.apache.log4j.Appender" was loaded by 
          2010-08-09 23:47:08.062770500 log4j:ERROR [org.apache.catalina.loader.StandardClassLoader@1630ab9] whereas object of type 
          2010-08-09 23:47:08.062803500 log4j:ERROR "org.apache.log4j.DailyRollingFileAppender" was loaded by [WebappClassLoader
          2010-08-09 23:47:08.062804500   delegate: false
          2010-08-09 23:47:08.062805500   repositories:
          2010-08-09 23:47:08.062805500     /WEB-INF/classes/
          2010-08-09 23:47:08.062806500 ----------> Parent Classloader:
          2010-08-09 23:47:08.062806500 org.apache.catalina.loader.StandardClassLoader@1630ab9
          2010-08-09 23:47:08.062807500 ].
          2010-08-09 23:47:08.062828500 log4j:ERROR Could not instantiate appender named "filelog".
          2010-08-09 23:47:08.063895500 log4j:ERROR A "org.apache.log4j.ConsoleAppender" object is not assignable to a "org.apache.log4j.Appender" variable.
          2010-08-09 23:47:08.063922500 log4j:ERROR The class "org.apache.log4j.Appender" was loaded by 
          2010-08-09 23:47:08.063964500 log4j:ERROR [org.apache.catalina.loader.StandardClassLoader@1630ab9] whereas object of type 
          2010-08-09 23:47:08.063996500 log4j:ERROR "org.apache.log4j.ConsoleAppender" was loaded by [WebappClassLoader
          2010-08-09 23:47:08.063997500   delegate: false
          2010-08-09 23:47:08.063998500   repositories:
          2010-08-09 23:47:08.063998500     /WEB-INF/classes/
          2010-08-09 23:47:08.063999500 ----------> Parent Classloader:
          2010-08-09 23:47:08.063999500 org.apache.catalina.loader.StandardClassLoader@1630ab9
          2010-08-09 23:47:08.064000500 ].
          2010-08-09 23:47:08.064029500 log4j:ERROR Could not instantiate appender named "console".
          2010-08-09 23:47:08.064140500 log4j:ERROR A "org.apache.log4j.DailyRollingFileAppender" object is not assignable to a "org.apache.log4j.Appender" variable.
          2010-08-09 23:47:08.064155500 log4j:ERROR The class "org.apache.log4j.Appender" was loaded by 
          2010-08-09 23:47:08.064176500 log4j:ERROR [org.apache.catalina.loader.StandardClassLoader@1630ab9] whereas object of type 
          2010-08-09 23:47:08.064212500 log4j:ERROR "org.apache.log4j.DailyRollingFileAppender" was loaded by [WebappClassLoader
          2010-08-09 23:47:08.064213500   delegate: false
          2010-08-09 23:47:08.064213500   repositories:
          2010-08-09 23:47:08.064214500     /WEB-INF/classes/
          2010-08-09 23:47:08.064214500 ----------> Parent Classloader:
          2010-08-09 23:47:08.064215500 org.apache.catalina.loader.StandardClassLoader@1630ab9
          
          Show
          Pramod Korathota [Atlassian] added a comment - We see this error on EACJ and QA-JAC as well, which does not have hercules: 2010-08-09 23:47:08.062446500 log4j:ERROR A "org.apache.log4j.ConsoleAppender" object is not assignable to a "org.apache.log4j.Appender" variable. 2010-08-09 23:47:08.062472500 log4j:ERROR The class "org.apache.log4j.Appender" was loaded by 2010-08-09 23:47:08.062536500 log4j:ERROR [org.apache.catalina.loader.StandardClassLoader@1630ab9] whereas object of type 2010-08-09 23:47:08.062751500 log4j:ERROR "org.apache.log4j.ConsoleAppender" was loaded by [WebappClassLoader 2010-08-09 23:47:08.062752500 delegate: false 2010-08-09 23:47:08.062752500 repositories: 2010-08-09 23:47:08.062753500 /WEB-INF/classes/ 2010-08-09 23:47:08.062753500 ----------> Parent Classloader: 2010-08-09 23:47:08.062754500 org.apache.catalina.loader.StandardClassLoader@1630ab9 2010-08-09 23:47:08.062754500 ]. 2010-08-09 23:47:08.062755500 log4j:ERROR Could not instantiate appender named "console". 2010-08-09 23:47:08.062755500 log4j:ERROR A "org.apache.log4j.DailyRollingFileAppender" object is not assignable to a "org.apache.log4j.Appender" variable. 2010-08-09 23:47:08.062763500 log4j:ERROR The class "org.apache.log4j.Appender" was loaded by 2010-08-09 23:47:08.062770500 log4j:ERROR [org.apache.catalina.loader.StandardClassLoader@1630ab9] whereas object of type 2010-08-09 23:47:08.062803500 log4j:ERROR "org.apache.log4j.DailyRollingFileAppender" was loaded by [WebappClassLoader 2010-08-09 23:47:08.062804500 delegate: false 2010-08-09 23:47:08.062805500 repositories: 2010-08-09 23:47:08.062805500 /WEB-INF/classes/ 2010-08-09 23:47:08.062806500 ----------> Parent Classloader: 2010-08-09 23:47:08.062806500 org.apache.catalina.loader.StandardClassLoader@1630ab9 2010-08-09 23:47:08.062807500 ]. 2010-08-09 23:47:08.062828500 log4j:ERROR Could not instantiate appender named "filelog". 2010-08-09 23:47:08.063895500 log4j:ERROR A "org.apache.log4j.ConsoleAppender" object is not assignable to a "org.apache.log4j.Appender" variable. 2010-08-09 23:47:08.063922500 log4j:ERROR The class "org.apache.log4j.Appender" was loaded by 2010-08-09 23:47:08.063964500 log4j:ERROR [org.apache.catalina.loader.StandardClassLoader@1630ab9] whereas object of type 2010-08-09 23:47:08.063996500 log4j:ERROR "org.apache.log4j.ConsoleAppender" was loaded by [WebappClassLoader 2010-08-09 23:47:08.063997500 delegate: false 2010-08-09 23:47:08.063998500 repositories: 2010-08-09 23:47:08.063998500 /WEB-INF/classes/ 2010-08-09 23:47:08.063999500 ----------> Parent Classloader: 2010-08-09 23:47:08.063999500 org.apache.catalina.loader.StandardClassLoader@1630ab9 2010-08-09 23:47:08.064000500 ]. 2010-08-09 23:47:08.064029500 log4j:ERROR Could not instantiate appender named "console". 2010-08-09 23:47:08.064140500 log4j:ERROR A "org.apache.log4j.DailyRollingFileAppender" object is not assignable to a "org.apache.log4j.Appender" variable. 2010-08-09 23:47:08.064155500 log4j:ERROR The class "org.apache.log4j.Appender" was loaded by 2010-08-09 23:47:08.064176500 log4j:ERROR [org.apache.catalina.loader.StandardClassLoader@1630ab9] whereas object of type 2010-08-09 23:47:08.064212500 log4j:ERROR "org.apache.log4j.DailyRollingFileAppender" was loaded by [WebappClassLoader 2010-08-09 23:47:08.064213500 delegate: false 2010-08-09 23:47:08.064213500 repositories: 2010-08-09 23:47:08.064214500 /WEB-INF/classes/ 2010-08-09 23:47:08.064214500 ----------> Parent Classloader: 2010-08-09 23:47:08.064215500 org.apache.catalina.loader.StandardClassLoader@1630ab9
          Hide
          Sorin Sbarnea (CITRIX) added a comment -

          How can this be debugged and fixed? I get the same behaviour on Jira while I'm trying to load a plugin I'm developing.

          Yes, the plugin is supposed to use logging.

          ERROR A "org.apache.log4j.ConsoleAppender" object is not assignable to a "org.apache.log4j.Appender" variable.
          [INFO] [talledLocalContainer] log4j:ERROR The class "org.apache.log4j.Appender" was loaded by 
          [INFO] [talledLocalContainer] log4j:ERROR [109.0] whereas object of type 
          [INFO] [talledLocalContainer] log4j:ERROR "org.apache.log4j.ConsoleAppender" was loaded by [WebappClassLoader
          [INFO] [talledLocalContainer]   delegate: false
          [INFO] [talledLocalContainer]   repositories:
          [INFO] [talledLocalContainer]     /WEB-INF/classes/
          [INFO] [talledLocalContainer] ----------> Parent Classloader:
          [INFO] [talledLocalContainer] org.apache.catalina.loader.StandardClassLoader@30fffd2c
          [INFO] [talledLocalContainer] ].
          
          Show
          Sorin Sbarnea (CITRIX) added a comment - How can this be debugged and fixed? I get the same behaviour on Jira while I'm trying to load a plugin I'm developing. Yes, the plugin is supposed to use logging. ERROR A "org.apache.log4j.ConsoleAppender" object is not assignable to a "org.apache.log4j.Appender" variable. [INFO] [talledLocalContainer] log4j:ERROR The class "org.apache.log4j.Appender" was loaded by [INFO] [talledLocalContainer] log4j:ERROR [109.0] whereas object of type [INFO] [talledLocalContainer] log4j:ERROR "org.apache.log4j.ConsoleAppender" was loaded by [WebappClassLoader [INFO] [talledLocalContainer] delegate: false [INFO] [talledLocalContainer] repositories: [INFO] [talledLocalContainer] /WEB-INF/classes/ [INFO] [talledLocalContainer] ----------> Parent Classloader: [INFO] [talledLocalContainer] org.apache.catalina.loader.StandardClassLoader@30fffd2c [INFO] [talledLocalContainer] ].
          Hide
          Eric Dalgliesh [Atlassian] added a comment - - edited

          Hi Sorin Sbarnea (CITRIX),

          We provide support for developers on https://answers.atlassian.com. If you create a question there you can talk to other plugin developers and the people that Atlassian has dedicated to help support our developer community.

          Regards,
          Eric

          Show
          Eric Dalgliesh [Atlassian] added a comment - - edited Hi Sorin Sbarnea (CITRIX) , We provide support for developers on https://answers.atlassian.com . If you create a question there you can talk to other plugin developers and the people that Atlassian has dedicated to help support our developer community. Regards, Eric

            People

            • Assignee:
              Unassigned
              Reporter:
              Pete de Zwart [Atlassian]
            • Votes:
              1 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:

                Time Tracking

                Estimated:
                Original Estimate - Not Specified
                Not Specified
                Remaining:
                Remaining Estimate - 0h
                0h
                Logged:
                Time Spent - 12h
                12h