You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by "Leon Finker (JIRA)" <ji...@apache.org> on 2016/06/09 18:12:20 UTC

[jira] [Updated] (LOG4J2-1420) 2.6.1 - NPE due to OnStartupTriggeringPolicy changes

     [ https://issues.apache.org/jira/browse/LOG4J2-1420?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Leon Finker updated LOG4J2-1420:
--------------------------------
    Description: 
Hi,

Noticed an NPE with one of our configurations with 2.6.1 (doesn't happen on previous versions). Looks like it's due to changes for LOG4J2-1405. Looks like the file size in RollingFileManager constructor is set before the randomAccessFile in RollingRandomAccessFileManager ctor. And the actual policy triggering happens in RollingFileManager  before the randomAccessFile is assigned:triggeringPolicy.initialize(this); I guess that's why there was somewhat an elaborate logic in previous version of OnStartupTriggeringPolicy and the actual rollover was decided in isTriggeringEvent.

The NPE always happens with OnStartupTriggeringPolicy and if previous file is not empty.

{noformat}
2016-06-09 13:38:57,060 main ERROR Unable to invoke factory method in class class org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender for element RollingRandomAccessFile. java.lang.reflect.InvocationTargetException
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:132)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:918)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:858)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:850)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:479)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:219)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:231)
	at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:491)
	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:561)
	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:577)
	at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:212)
	at org.apache.logging.log4j.core.async.AsyncLoggerContext.start(AsyncLoggerContext.java:75)
	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:152)
	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:45)
	at org.apache.logging.log4j.LogManager.getContext(LogManager.java:194)
	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:103)
	at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:43)
	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:42)
	at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:29)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:358)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:383)
	at com.tradingscreen.gemfire.server.CacheServer.<clinit>(CacheServer.java:46)
Caused by: java.lang.NullPointerException
	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager.close(RollingRandomAccessFileManager.java:128)
	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.rollover(RollingFileManager.java:211)
	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.rollover(RollingFileManager.java:142)
	at org.apache.logging.log4j.core.appender.rolling.OnStartupTriggeringPolicy.initialize(OnStartupTriggeringPolicy.java:43)
	at org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy.initialize(CompositeTriggeringPolicy.java:49)
	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.<init>(RollingFileManager.java:77)
	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager.<init>(RollingRandomAccessFileManager.java:50)
	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager$RollingRandomAccessFileManagerFactory.createManager(RollingRandomAccessFileManager.java:183)
	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager$RollingRandomAccessFileManagerFactory.createManager(RollingRandomAccessFileManager.java:147)
	at org.apache.logging.log4j.core.appender.AbstractManager.getManager(AbstractManager.java:73)
	at org.apache.logging.log4j.core.appender.OutputStreamManager.getManager(OutputStreamManager.java:81)
	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager.getRollingRandomAccessFileManager(RollingRandomAccessFileManager.java:80)
	at org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender.createAppender(RollingRandomAccessFileAppender.java:207)
	... 26 more

2016-06-09 13:38:57,064 main ERROR Null object returned for RollingRandomAccessFile in Appenders.
{noformat}



  was:
Hi,

Noticed an NPE with one of our configurations with 2.6.1 (doesn't happen on previous versions). Looks like it's due to changes for LOG4J2-1405. Looks like the file size in RollingFileManager constructor is now set before the randomAccessFile in RollingRandomAccessFileManager ctor. And the actual policy triggering happens in RollingFileManager  before the randomAccessFile is assigned:
triggeringPolicy.initialize(this);

The NPE always happens with OnStartupTriggeringPolicy and if previous file is not empty.

{noformat}
2016-06-09 13:38:57,060 main ERROR Unable to invoke factory method in class class org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender for element RollingRandomAccessFile. java.lang.reflect.InvocationTargetException
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:132)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:918)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:858)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:850)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:479)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:219)
	at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:231)
	at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:491)
	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:561)
	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:577)
	at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:212)
	at org.apache.logging.log4j.core.async.AsyncLoggerContext.start(AsyncLoggerContext.java:75)
	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:152)
	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:45)
	at org.apache.logging.log4j.LogManager.getContext(LogManager.java:194)
	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:103)
	at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:43)
	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:42)
	at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:29)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:358)
	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:383)
	at com.tradingscreen.gemfire.server.CacheServer.<clinit>(CacheServer.java:46)
Caused by: java.lang.NullPointerException
	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager.close(RollingRandomAccessFileManager.java:128)
	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.rollover(RollingFileManager.java:211)
	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.rollover(RollingFileManager.java:142)
	at org.apache.logging.log4j.core.appender.rolling.OnStartupTriggeringPolicy.initialize(OnStartupTriggeringPolicy.java:43)
	at org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy.initialize(CompositeTriggeringPolicy.java:49)
	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.<init>(RollingFileManager.java:77)
	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager.<init>(RollingRandomAccessFileManager.java:50)
	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager$RollingRandomAccessFileManagerFactory.createManager(RollingRandomAccessFileManager.java:183)
	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager$RollingRandomAccessFileManagerFactory.createManager(RollingRandomAccessFileManager.java:147)
	at org.apache.logging.log4j.core.appender.AbstractManager.getManager(AbstractManager.java:73)
	at org.apache.logging.log4j.core.appender.OutputStreamManager.getManager(OutputStreamManager.java:81)
	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager.getRollingRandomAccessFileManager(RollingRandomAccessFileManager.java:80)
	at org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender.createAppender(RollingRandomAccessFileAppender.java:207)
	... 26 more

2016-06-09 13:38:57,064 main ERROR Null object returned for RollingRandomAccessFile in Appenders.
{noformat}




> 2.6.1 - NPE due to OnStartupTriggeringPolicy changes
> ----------------------------------------------------
>
>                 Key: LOG4J2-1420
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-1420
>             Project: Log4j 2
>          Issue Type: Bug
>    Affects Versions: 2.6.1
>            Reporter: Leon Finker
>
> Hi,
> Noticed an NPE with one of our configurations with 2.6.1 (doesn't happen on previous versions). Looks like it's due to changes for LOG4J2-1405. Looks like the file size in RollingFileManager constructor is set before the randomAccessFile in RollingRandomAccessFileManager ctor. And the actual policy triggering happens in RollingFileManager  before the randomAccessFile is assigned:triggeringPolicy.initialize(this); I guess that's why there was somewhat an elaborate logic in previous version of OnStartupTriggeringPolicy and the actual rollover was decided in isTriggeringEvent.
> The NPE always happens with OnStartupTriggeringPolicy and if previous file is not empty.
> {noformat}
> 2016-06-09 13:38:57,060 main ERROR Unable to invoke factory method in class class org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender for element RollingRandomAccessFile. java.lang.reflect.InvocationTargetException
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:497)
> 	at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:132)
> 	at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:918)
> 	at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:858)
> 	at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:850)
> 	at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:479)
> 	at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:219)
> 	at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:231)
> 	at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:491)
> 	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:561)
> 	at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:577)
> 	at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:212)
> 	at org.apache.logging.log4j.core.async.AsyncLoggerContext.start(AsyncLoggerContext.java:75)
> 	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:152)
> 	at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:45)
> 	at org.apache.logging.log4j.LogManager.getContext(LogManager.java:194)
> 	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getContext(AbstractLoggerAdapter.java:103)
> 	at org.apache.logging.slf4j.Log4jLoggerFactory.getContext(Log4jLoggerFactory.java:43)
> 	at org.apache.logging.log4j.spi.AbstractLoggerAdapter.getLogger(AbstractLoggerAdapter.java:42)
> 	at org.apache.logging.slf4j.Log4jLoggerFactory.getLogger(Log4jLoggerFactory.java:29)
> 	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:358)
> 	at org.slf4j.LoggerFactory.getLogger(LoggerFactory.java:383)
> 	at com.tradingscreen.gemfire.server.CacheServer.<clinit>(CacheServer.java:46)
> Caused by: java.lang.NullPointerException
> 	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager.close(RollingRandomAccessFileManager.java:128)
> 	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.rollover(RollingFileManager.java:211)
> 	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.rollover(RollingFileManager.java:142)
> 	at org.apache.logging.log4j.core.appender.rolling.OnStartupTriggeringPolicy.initialize(OnStartupTriggeringPolicy.java:43)
> 	at org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy.initialize(CompositeTriggeringPolicy.java:49)
> 	at org.apache.logging.log4j.core.appender.rolling.RollingFileManager.<init>(RollingFileManager.java:77)
> 	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager.<init>(RollingRandomAccessFileManager.java:50)
> 	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager$RollingRandomAccessFileManagerFactory.createManager(RollingRandomAccessFileManager.java:183)
> 	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager$RollingRandomAccessFileManagerFactory.createManager(RollingRandomAccessFileManager.java:147)
> 	at org.apache.logging.log4j.core.appender.AbstractManager.getManager(AbstractManager.java:73)
> 	at org.apache.logging.log4j.core.appender.OutputStreamManager.getManager(OutputStreamManager.java:81)
> 	at org.apache.logging.log4j.core.appender.rolling.RollingRandomAccessFileManager.getRollingRandomAccessFileManager(RollingRandomAccessFileManager.java:80)
> 	at org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender.createAppender(RollingRandomAccessFileAppender.java:207)
> 	... 26 more
> 2016-06-09 13:38:57,064 main ERROR Null object returned for RollingRandomAccessFile in Appenders.
> {noformat}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org