Log4j 2
  1. Log4j 2
  2. LOG4J2-379

Problem using log4j2 in Google App Engine

    Details

    • Type: Improvement Improvement
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 2.0-beta8
    • Fix Version/s: 2.0-rc1
    • Component/s: Core
    • Labels:
      None
    • Environment:

      Google App Engine

      Description

      [INFO] Caused by: java.lang.NoClassDefFoundError: java.lang.management.ManagementFactory is a restricted class. Please see the Google  App Engine developer's guide for more details.
      [INFO]  at com.google.appengine.tools.development.agent.runtime.Runtime.reject(Runtime.java:51)
      [INFO]  at org.apache.logging.log4j.core.appender.rolling.OnStartupTriggeringPolicy.<clinit>(OnStartupTriggeringPolicy.java:33)
      [INFO]  at java.lang.Class.forName0(Native Method)
      [INFO]  at java.lang.Class.forName(Class.java:186)
      [INFO]  at org.apache.logging.log4j.core.config.plugins.PluginManager.decode(PluginManager.java:222
      

      This seems to be caused by the OnStartupTriggeringPolicy class initializing a static field with this code:

      private static final long JVM_START_TIME = ManagementFactory.getRuntimeMXBean().getStartTime();
      

      Is there a workaround for this?

        Activity

        Hide
        Ralph Goers added a comment -

        I believe I have a fix for this but I don't know how to test it. Can you provide a unit test? I checked in what I think is the fix in revision 1519489.

        Show
        Ralph Goers added a comment - I believe I have a fix for this but I don't know how to test it. Can you provide a unit test? I checked in what I think is the fix in revision 1519489.
        Hide
        Michael Peter Gower added a comment - - edited

        I got a similar error using 2.0-beta9. From examining the stack-log it appears that it was triggered by using Spring, log4j-slf4j-impl and log4j2.disable.jmx=true. It occurred during server start-up (both via the Maven GAE plugin and from the command line). I'm using Spring 3.2.1-RELEASE. Thanks!

        [INFO] WARNING: failed com.google.appengine.tools.development.DevAppEngineWebAppContext@73982201{/,C:\Users\Vlad\git\main\estatevault-ear\target\estatevault-ear-0.1.0-SNAPSHOT}: java.lang.NoClassDefFoundError: java.lang.management.ManagementFactory is a restricted class. Please see the Google  App Engine developer's guide for more details.
        [INFO] Sep 17, 2013 10:45:47 PM com.google.apphosting.utils.jetty.JettyLogger warn
        [INFO] WARNING: failed JettyContainerService$ApiProxyHandler@43823f04: java.lang.NoClassDefFoundError: java.lang.management.ManagementFactory is a restricted class. Please see the Google  App Engine developer's guide for more details.
        [INFO] Sep 17, 2013 10:45:47 PM com.google.apphosting.utils.jetty.JettyLogger warn
        [INFO] WARNING: Error starting handlers
        [INFO] java.lang.NoClassDefFoundError: java.lang.management.ManagementFactory is a restricted class. Please see the Google  App Engine developer's guide for more details.
        [INFO] 	at com.google.appengine.tools.development.agent.runtime.Runtime.reject(Runtime.java:51)
        [INFO] 	at org.apache.logging.log4j.core.appender.rolling.OnStartupTriggeringPolicy.<clinit>(OnStartupTriggeringPolicy.java:35)
        [INFO] 	at java.lang.Class.forName0(Native Method)
        [INFO] 	at java.lang.Class.forName(Class.java:186)
        [INFO] 	at org.apache.logging.log4j.core.config.plugins.PluginManager.decode(PluginManager.java:241)
        [INFO] 	at org.apache.logging.log4j.core.config.plugins.PluginManager.collectPlugins(PluginManager.java:152)
        [INFO] 	at org.apache.logging.log4j.core.config.plugins.PluginManager.collectPlugins(PluginManager.java:130)
        [INFO] 	at org.apache.logging.log4j.core.pattern.PatternParser.<init>(PatternParser.java:116)
        [INFO] 	at org.apache.logging.log4j.core.pattern.PatternParser.<init>(PatternParser.java:102)
        [INFO] 	at org.apache.logging.log4j.core.layout.PatternLayout.createPatternParser(PatternLayout.java:183)
        [INFO] 	at org.apache.logging.log4j.core.layout.PatternLayout.<init>(PatternLayout.java:115)
        [INFO] 	at org.apache.logging.log4j.core.layout.PatternLayout.createLayout(PatternLayout.java:219)
        [INFO] 	at org.apache.logging.log4j.core.config.DefaultConfiguration.<init>(DefaultConfiguration.java:51)
        [INFO] 	at org.apache.logging.log4j.core.LoggerContext.<init>(LoggerContext.java:63)
        [INFO] 	at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.locateContext(ClassLoaderContextSelector.java:217)
        [INFO] 	at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.getContext(ClassLoaderContextSelector.java:145)
        [INFO] 	at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.getContext(ClassLoaderContextSelector.java:81)
        [INFO] 	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:83)
        [INFO] 	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:34)
        [INFO] 	at org.apache.logging.log4j.LogManager.getContext(LogManager.java:200)
        [INFO] 	at org.slf4j.helpers.Log4JLoggerFactory$PrivateManager.getContext(Log4JLoggerFactory.java:103)
        [INFO] 	at org.slf4j.helpers.Log4JLoggerFactory.getContext(Log4JLoggerFactory.java:89)
        [INFO] 	at org.slf4j.helpers.Log4JLoggerFactory.getLogger(Log4JLoggerFactory.java:45)
        [INFO] 	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:253)
        [INFO] 	at org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:156)
        [INFO] 	at org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:132)
        [INFO] 	at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:685)
        [INFO] 	at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:270)
        [INFO] 	at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:112)
        [INFO] 	at org.mortbay.jetty.handler.ContextHandler.startContext(ContextHandler.java:548)
        [INFO] 	at org.mortbay.jetty.servlet.Context.startContext(Context.java:136)
        [INFO] 	at org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1250)
        [INFO] 	at org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:517)
        [INFO] 	at org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:467)
        [INFO] 	at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
        [INFO] 	at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:130)
        [INFO] 	at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
        [INFO] 	at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:130)
        [INFO] 	at org.mortbay.jetty.Server.doStart(Server.java:224)
        [INFO] 	at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50)
        [INFO] 	at com.google.appengine.tools.development.JettyContainerService.startContainer(JettyContainerService.java:249)
        [INFO] 	at com.google.appengine.tools.development.AbstractContainerService.startup(AbstractContainerService.java:306)
        [INFO] 	at com.google.appengine.tools.development.AutomaticInstanceHolder.startUp(AutomaticInstanceHolder.java:26)
        [INFO] 	at com.google.appengine.tools.development.AbstractModule.startup(AbstractModule.java:79)
        [INFO] 	at com.google.appengine.tools.development.Modules.startup(Modules.java:88)
        [INFO] 	at com.google.appengine.tools.development.DevAppServerImpl.start(DevAppServerImpl.java:240)
        [INFO] 	at com.google.appengine.tools.development.DevAppServerMain$StartAction.apply(DevAppServerMain.java:399)
        [INFO] 	at com.google.appengine.tools.util.Parser$ParseResult.applyArgs(Parser.java:48)
        [INFO] 	at com.google.appengine.tools.development.DevAppServerMain.<init>(DevAppServerMain.java:334)
        [INFO] 	at com.google.appengine.tools.development.DevAppServerMain.main(DevAppServerMain.java:310)
        
        Show
        Michael Peter Gower added a comment - - edited I got a similar error using 2.0-beta9. From examining the stack-log it appears that it was triggered by using Spring, log4j-slf4j-impl and log4j2.disable.jmx=true. It occurred during server start-up (both via the Maven GAE plugin and from the command line). I'm using Spring 3.2.1-RELEASE. Thanks! [INFO] WARNING: failed com.google.appengine.tools.development.DevAppEngineWebAppContext@73982201{/,C:\Users\Vlad\git\main\estatevault-ear\target\estatevault-ear-0.1.0-SNAPSHOT}: java.lang.NoClassDefFoundError: java.lang.management.ManagementFactory is a restricted class. Please see the Google App Engine developer's guide for more details. [INFO] Sep 17, 2013 10:45:47 PM com.google.apphosting.utils.jetty.JettyLogger warn [INFO] WARNING: failed JettyContainerService$ApiProxyHandler@43823f04: java.lang.NoClassDefFoundError: java.lang.management.ManagementFactory is a restricted class. Please see the Google App Engine developer's guide for more details. [INFO] Sep 17, 2013 10:45:47 PM com.google.apphosting.utils.jetty.JettyLogger warn [INFO] WARNING: Error starting handlers [INFO] java.lang.NoClassDefFoundError: java.lang.management.ManagementFactory is a restricted class. Please see the Google App Engine developer's guide for more details. [INFO] at com.google.appengine.tools.development.agent.runtime.Runtime.reject(Runtime.java:51) [INFO] at org.apache.logging.log4j.core.appender.rolling.OnStartupTriggeringPolicy.<clinit>(OnStartupTriggeringPolicy.java:35) [INFO] at java.lang.Class.forName0(Native Method) [INFO] at java.lang.Class.forName(Class.java:186) [INFO] at org.apache.logging.log4j.core.config.plugins.PluginManager.decode(PluginManager.java:241) [INFO] at org.apache.logging.log4j.core.config.plugins.PluginManager.collectPlugins(PluginManager.java:152) [INFO] at org.apache.logging.log4j.core.config.plugins.PluginManager.collectPlugins(PluginManager.java:130) [INFO] at org.apache.logging.log4j.core.pattern.PatternParser.<init>(PatternParser.java:116) [INFO] at org.apache.logging.log4j.core.pattern.PatternParser.<init>(PatternParser.java:102) [INFO] at org.apache.logging.log4j.core.layout.PatternLayout.createPatternParser(PatternLayout.java:183) [INFO] at org.apache.logging.log4j.core.layout.PatternLayout.<init>(PatternLayout.java:115) [INFO] at org.apache.logging.log4j.core.layout.PatternLayout.createLayout(PatternLayout.java:219) [INFO] at org.apache.logging.log4j.core.config.DefaultConfiguration.<init>(DefaultConfiguration.java:51) [INFO] at org.apache.logging.log4j.core.LoggerContext.<init>(LoggerContext.java:63) [INFO] at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.locateContext(ClassLoaderContextSelector.java:217) [INFO] at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.getContext(ClassLoaderContextSelector.java:145) [INFO] at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.getContext(ClassLoaderContextSelector.java:81) [INFO] at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:83) [INFO] at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:34) [INFO] at org.apache.logging.log4j.LogManager.getContext(LogManager.java:200) [INFO] at org.slf4j.helpers.Log4JLoggerFactory$PrivateManager.getContext(Log4JLoggerFactory.java:103) [INFO] at org.slf4j.helpers.Log4JLoggerFactory.getContext(Log4JLoggerFactory.java:89) [INFO] at org.slf4j.helpers.Log4JLoggerFactory.getLogger(Log4JLoggerFactory.java:45) [INFO] at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:253) [INFO] at org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:156) [INFO] at org.apache.commons.logging.impl.SLF4JLogFactory.getInstance(SLF4JLogFactory.java:132) [INFO] at org.apache.commons.logging.LogFactory.getLog(LogFactory.java:685) [INFO] at org.springframework.web.context.ContextLoader.initWebApplicationContext(ContextLoader.java:270) [INFO] at org.springframework.web.context.ContextLoaderListener.contextInitialized(ContextLoaderListener.java:112) [INFO] at org.mortbay.jetty.handler.ContextHandler.startContext(ContextHandler.java:548) [INFO] at org.mortbay.jetty.servlet.Context.startContext(Context.java:136) [INFO] at org.mortbay.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1250) [INFO] at org.mortbay.jetty.handler.ContextHandler.doStart(ContextHandler.java:517) [INFO] at org.mortbay.jetty.webapp.WebAppContext.doStart(WebAppContext.java:467) [INFO] at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50) [INFO] at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:130) [INFO] at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50) [INFO] at org.mortbay.jetty.handler.HandlerWrapper.doStart(HandlerWrapper.java:130) [INFO] at org.mortbay.jetty.Server.doStart(Server.java:224) [INFO] at org.mortbay.component.AbstractLifeCycle.start(AbstractLifeCycle.java:50) [INFO] at com.google.appengine.tools.development.JettyContainerService.startContainer(JettyContainerService.java:249) [INFO] at com.google.appengine.tools.development.AbstractContainerService.startup(AbstractContainerService.java:306) [INFO] at com.google.appengine.tools.development.AutomaticInstanceHolder.startUp(AutomaticInstanceHolder.java:26) [INFO] at com.google.appengine.tools.development.AbstractModule.startup(AbstractModule.java:79) [INFO] at com.google.appengine.tools.development.Modules.startup(Modules.java:88) [INFO] at com.google.appengine.tools.development.DevAppServerImpl.start(DevAppServerImpl.java:240) [INFO] at com.google.appengine.tools.development.DevAppServerMain$StartAction.apply(DevAppServerMain.java:399) [INFO] at com.google.appengine.tools.util.Parser$ParseResult.applyArgs(Parser.java:48) [INFO] at com.google.appengine.tools.development.DevAppServerMain.<init>(DevAppServerMain.java:334) [INFO] at com.google.appengine.tools.development.DevAppServerMain.main(DevAppServerMain.java:310)
        Hide
        Remko Popma added a comment -

        Michael, can you also post your log4j2.xml config?

        Show
        Remko Popma added a comment - Michael, can you also post your log4j2.xml config?
        Hide
        Michael Peter Gower added a comment -

        Wow, that was quick! My config is basically a copy from the getting started section:

        <?xml version="1.0" encoding="UTF-8"?>
        <Configuration>
          <Appenders>
            <Console name="STDOUT" target="SYSTEM_OUT">
              <PatternLayout pattern="%d %-5p [%t] %C{2} (%F:%L) - %m%n" />
            </Console>
          </Appenders>
          <Loggers>
            <Logger name="com.peninsulawebsolutions" level="trace" />
            <Root level="warn">
              <AppenderRef ref="STDOUT" />
            </Root>
          </Loggers>
        </Configuration>
        
        Show
        Michael Peter Gower added a comment - Wow, that was quick! My config is basically a copy from the getting started section: <?xml version="1.0" encoding="UTF-8"?> <Configuration> <Appenders> <Console name="STDOUT" target="SYSTEM_OUT"> <PatternLayout pattern="%d %-5p [%t] %C{2} (%F:%L) - %m%n" /> </Console> </Appenders> <Loggers> <Logger name="com.peninsulawebsolutions" level="trace" /> <Root level="warn"> <AppenderRef ref="STDOUT" /> </Root> </Loggers> </Configuration>
        Hide
        Remko Popma added a comment -

        On closer inspection it seems that the error occurs when the OnStartupTriggeringPolicy class is being loaded.
        Which means that we can't even import java.lang.management.ManagementFactory; without ticking off Google App Engine...

        Since this is a once-only initialization and performance impact will be negligible we can use reflection to try and call ManagementFactory.getRuntimeMXBean().getStartTime().
        If that fails, I propose we use System.currentTimeMillis instead.

        This means that on Google App Engine, using OnStartupTriggeringPolicy results in log files older than Log4j initialization time will be rolled over. (In other environments the behavior is still: log files older than the current JVM's start time are rolled over.)

        Thoughts?

        Show
        Remko Popma added a comment - On closer inspection it seems that the error occurs when the OnStartupTriggeringPolicy class is being loaded. Which means that we can't even import java.lang.management.ManagementFactory; without ticking off Google App Engine... Since this is a once-only initialization and performance impact will be negligible we can use reflection to try and call ManagementFactory.getRuntimeMXBean().getStartTime() . If that fails, I propose we use System.currentTimeMillis instead. This means that on Google App Engine, using OnStartupTriggeringPolicy results in log files older than Log4j initialization time will be rolled over. (In other environments the behavior is still: log files older than the current JVM's start time are rolled over.) Thoughts?
        Hide
        Remko Popma added a comment -

        I went ahead and made this change; it may not be perfect but it is better than what we have now (where log4j doesn't work at all in GAE). The change includes a note in the docs for OnStartup rollover trigger.

        I've only been able to verify that OnStartupTriggeringPolicy still works outside GAE. Can someone verify this solves the problem when running in GAE?

        Fixed in revision 1525494.
        Please verify and close.

        Show
        Remko Popma added a comment - I went ahead and made this change; it may not be perfect but it is better than what we have now (where log4j doesn't work at all in GAE). The change includes a note in the docs for OnStartup rollover trigger. I've only been able to verify that OnStartupTriggeringPolicy still works outside GAE. Can someone verify this solves the problem when running in GAE? Fixed in revision 1525494. Please verify and close.

          People

          • Assignee:
            Remko Popma
            Reporter:
            Remko Popma
          • Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development