[
https://issues.apache.org/jira/browse/LOG4J2-1640?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15828254#comment-15828254
]
Chris McGee commented on LOG4J2-1640:
-------------------------------------
Looks good. I'll go ahead and close this issue, then (if it isn't already
closed by now). I'm guessing this fix will make it into a 2.7.1 or 2.8 release.
Thanks so much, [~ralphgoers]!
> RollingFileAppender with CronTriggeringPolicy broken?
> -----------------------------------------------------
>
> Key: LOG4J2-1640
> URL: https://issues.apache.org/jira/browse/LOG4J2-1640
> Project: Log4j 2
> Issue Type: Bug
> Components: Core
> Affects Versions: 2.7
> Environment: Mac OS X 10.11.6 running Eclipse Neon 4.6.0 with JDK
> 1.8.0_74
> Reporter: Chris McGee
> Labels: CronTriggeringPolicy, RollingFile, RollingFileAppender,
> newbie
> Fix For: 2.8
>
>
> If this isn't actually a bug, then I apologize for reporting it, but I cannot
> figure out how it could be anything else currently. Full disclosure: I am
> still a newbie.
> I've been using the log4j 2.6.x series for a while, but noticed that the
> CronTriggeringPolicy when used with RollingFileAppender causes that infinite
> rollover bug. I noted that this bug was to be fixed in 2.7, so I downloaded
> that the day it was released and replaced the 2.6 version with it. Now,
> however, without changing anything else in my code nor in my log4j2.xml file,
> I am getting exceptions regarding them.
> Here's the interesting bit: Since I was trying to see if the rollover would
> occur at midnight, I manually changed my computer's clock to just a minute
> before, logged some info, let it roll to past midnight, and let it log some
> more info. All of that info got logged into the main file; nothing rolled
> over. Here's the stacktrace from that execution:
> {noformat}
> 2016-10-10 09:40:47,521 main DEBUG Initializing configuration
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> 2016-10-10 09:40:47,526 main DEBUG Installed script engines
> 2016-10-10 09:40:47,955 main DEBUG Oracle Nashorn Version: 1.8.0_74,
> Language: ECMAScript, Threading: Not Thread Safe, Compile: true, Names:
> {nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript}
> 2016-10-10 09:40:48,307 main DEBUG AppleScriptEngine Version: 1.1, Language:
> AppleScript, Threading: Not Thread Safe, Compile: false, Names:
> {AppleScriptEngine, AppleScript, OSA}
> 2016-10-10 09:40:48,308 main DEBUG PluginManager 'Core' found 107 plugins
> 2016-10-10 09:40:48,308 main DEBUG PluginManager 'Level' found 0 plugins
> 2016-10-10 09:40:48,312 main DEBUG 2 starting Log4j2 ConfigurationScheduler
> threads
> 2016-10-10 09:40:48,314 main DEBUG Building Plugin[name=property,
> class=org.apache.logging.log4j.core.config.Property].
> 2016-10-10 09:40:48,323 main TRACE TypeConverterRegistry initializing.
> 2016-10-10 09:40:48,324 main DEBUG PluginManager 'TypeConverter' found 23
> plugins
> 2016-10-10 09:40:48,330 main DEBUG createProperty(name="filename",
> value="logs/artdept.log")
> 2016-10-10 09:40:48,330 main DEBUG Building Plugin[name=property,
> class=org.apache.logging.log4j.core.config.Property].
> 2016-10-10 09:40:48,331 main DEBUG createProperty(name="baseDir",
> value="/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs")
> 2016-10-10 09:40:48,331 main DEBUG Building Plugin[name=properties,
> class=org.apache.logging.log4j.core.config.PropertiesPlugin].
> 2016-10-10 09:40:48,334 main DEBUG
> configureSubstitutor(={filename=logs/artdept.log,
> baseDir=/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs},
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml))
> 2016-10-10 09:40:48,335 main DEBUG PluginManager 'Lookup' found 13 plugins
> 2016-10-10 09:40:48,335 main DEBUG Building Plugin[name=layout,
> class=org.apache.logging.log4j.core.layout.PatternLayout].
> 2016-10-10 09:40:48,341 main DEBUG
> PatternLayout$Builder(pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} -
> %msg%n", PatternSelector=null,
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> Replace=null, charset="null", alwaysWriteExceptions="null",
> noConsoleNoAnsi="null", header="null", footer="null")
> 2016-10-10 09:40:48,341 main DEBUG PluginManager 'Converter' found 41 plugins
> 2016-10-10 09:40:48,342 main DEBUG Building Plugin[name=appender,
> class=org.apache.logging.log4j.core.appender.ConsoleAppender].
> 2016-10-10 09:40:48,347 main DEBUG
> ConsoleAppender$Builder(target="SYSTEM_OUT", follow="null", direct="null",
> bufferedIo="null", bufferSize="null", immediateFlush="null",
> ignoreExceptions="null", PatternLayout(%d{HH:mm:ss.SSS} [%t] %-5level
> %logger{36} - %msg%n), name="Console", Filter=null)
> 2016-10-10 09:40:48,347 main DEBUG Starting OutputStreamManager
> SYSTEM_OUT.false.false
> 2016-10-10 09:40:48,348 main DEBUG Building Plugin[name=layout,
> class=org.apache.logging.log4j.core.layout.PatternLayout].
> 2016-10-10 09:40:48,348 main DEBUG PatternLayout$Builder(pattern="%d %p
> %C{1.} [%t] %m%n", PatternSelector=null,
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> Replace=null, charset="null", alwaysWriteExceptions="null",
> noConsoleNoAnsi="null", header="null", footer="null")
> 2016-10-10 09:40:48,360 main DEBUG Building Plugin[name=appender,
> class=org.apache.logging.log4j.core.appender.FileAppender].
> 2016-10-10 09:40:48,364 main DEBUG
> FileAppender$Builder(fileName="logs/artdept.log", append="null",
> locking="null", advertise="null", advertiseUri="null", createOnDemand="null",
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> bufferedIo="null", bufferSize="null", immediateFlush="null",
> ignoreExceptions="null", PatternLayout(%d %p %C{1.} [%t] %m%n),
> name="MyFile", Filter=null)
> 2016-10-10 09:40:48,365 main DEBUG Starting FileManager logs/artdept.log
> 2016-10-10 09:40:48,366 main DEBUG Building Plugin[name=layout,
> class=org.apache.logging.log4j.core.layout.PatternLayout].
> 2016-10-10 09:40:48,366 main DEBUG PatternLayout$Builder(pattern="%d %p
> %C{1.} [%t] %m%n", PatternSelector=null,
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> Replace=null, charset="null", alwaysWriteExceptions="null",
> noConsoleNoAnsi="null", header="null", footer="null")
> 2016-10-10 09:40:48,367 main DEBUG Building Plugin[name=CronTriggeringPolicy,
> class=org.apache.logging.log4j.core.appender.rolling.CronTriggeringPolicy].
> 2016-10-10 09:40:48,368 main DEBUG
> createPolicy(Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> evaluateOnStartup="true", schedule="0 0 0 * * ?")
> 2016-10-10 09:40:48,370 main DEBUG Building
> Plugin[name=SizeBasedTriggeringPolicy,
> class=org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy].
> 2016-10-10 09:40:48,371 main DEBUG createPolicy(size="250 MB")
> 2016-10-10 09:40:48,372 main DEBUG Building Plugin[name=Policies,
> class=org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy].
> 2016-10-10 09:40:48,373 main DEBUG
> createPolicy(={CronTriggeringPolicy(schedule=0 0 0 * * ?),
> SizeBasedTriggeringPolicy(size=262144000)})
> 2016-10-10 09:40:48,373 main DEBUG Building Plugin[name=appender,
> class=org.apache.logging.log4j.core.appender.RollingFileAppender].
> 2016-10-10 09:40:48,376 main DEBUG
> RollingFileAppender$Builder(fileName="/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10
> - Oct/Launcher.log",
> filePattern="/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10
> - Oct/%d{dd} - Launcher-%i.log", append="null", locking="null",
> Policies(CompositeTriggeringPolicy(policies=[CronTriggeringPolicy(schedule=0
> 0 0 * * ?), SizeBasedTriggeringPolicy(size=262144000)])), Strategy=null,
> advertise="null", advertiseUri="null", createOnDemand="null",
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> bufferedIo="null", bufferSize="null", immediateFlush="null",
> ignoreExceptions="null", PatternLayout(%d %p %C{1.} [%t] %m%n),
> name="DailyRoll", Filter=null)
> 2016-10-10 09:40:48,512 main TRACE New file
> '/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 -
> Oct/Launcher.log' created = false
> 2016-10-10 09:40:48,515 main DEBUG Starting RollingFileManager
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 -
> Oct/Launcher.log
> 2016-10-10 09:40:48,516 main DEBUG PluginManager 'FileConverter' found 2
> plugins
> 2016-10-10 09:40:48,520 main DEBUG Building Plugin[name=appenders,
> class=org.apache.logging.log4j.core.config.AppendersPlugin].
> 2016-10-10 09:40:48,521 main DEBUG createAppenders(={Console, MyFile,
> DailyRoll})
> 2016-10-10 09:40:48,521 main DEBUG Building Plugin[name=AppenderRef,
> class=org.apache.logging.log4j.core.config.AppenderRef].
> 2016-10-10 09:40:48,521 main DEBUG createAppenderRef(ref="DailyRoll",
> level="null", Filter=null)
> 2016-10-10 09:40:48,522 main DEBUG Building Plugin[name=root,
> class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
> 2016-10-10 09:40:48,522 main DEBUG createLogger(additivity="null",
> level="TRACE", includeLocation="null", ={DailyRoll}, ={},
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> Filter=null)
> 2016-10-10 09:40:48,524 main DEBUG Building Plugin[name=loggers,
> class=org.apache.logging.log4j.core.config.LoggersPlugin].
> 2016-10-10 09:40:48,525 main DEBUG createLoggers(={root})
> 2016-10-10 09:40:48,525 main DEBUG Configuration
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> initialized
> 2016-10-10 09:40:48,525 main DEBUG Starting configuration
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> 2016-10-10 09:40:48,526 main DEBUG Started configuration
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> OK.
> 2016-10-10 09:40:48,526 main TRACE Stopping
> org.apache.logging.log4j.core.config.DefaultConfiguration@76ccd017...
> 2016-10-10 09:40:48,527 main TRACE DefaultConfiguration notified 1
> ReliabilityStrategies that config will be stopped.
> 2016-10-10 09:40:48,527 main TRACE DefaultConfiguration stopping root
> LoggerConfig.
> 2016-10-10 09:40:48,527 main TRACE DefaultConfiguration notifying
> ReliabilityStrategies that appenders will be stopped.
> 2016-10-10 09:40:48,527 main TRACE DefaultConfiguration stopping remaining
> Appenders.
> 2016-10-10 09:40:48,527 main DEBUG Shutting down OutputStreamManager
> SYSTEM_OUT.false.false-1
> 2016-10-10 09:40:48,528 main DEBUG Shut down OutputStreamManager
> SYSTEM_OUT.false.false-1, all resources released: true
> 2016-10-10 09:40:48,528 main TRACE DefaultConfiguration stopped 1 remaining
> Appenders.
> 2016-10-10 09:40:48,528 main TRACE DefaultConfiguration cleaning Appenders
> from 1 LoggerConfigs.
> 2016-10-10 09:40:48,528 main DEBUG Stopped
> org.apache.logging.log4j.core.config.DefaultConfiguration@76ccd017 OK
> 2016-10-10 09:40:48,572 main TRACE Reregistering MBeans after reconfigure.
> Selector=org.apache.logging.log4j.core.selector.ClassLoaderContextSelector@1bd4fdd
> 2016-10-10 09:40:48,572 main TRACE Reregistering context (1/1): '2a139a55'
> org.apache.logging.log4j.core.LoggerContext@55183b20
> 2016-10-10 09:40:48,574 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55'
> 2016-10-10 09:40:48,574 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=StatusLogger'
> 2016-10-10 09:40:48,574 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=ContextSelector'
> 2016-10-10 09:40:48,575 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=*'
> 2016-10-10 09:40:48,575 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=*'
> 2016-10-10 09:40:48,575 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=AsyncAppenders,name=*'
> 2016-10-10 09:40:48,576 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=AsyncLoggerRingBuffer'
> 2016-10-10 09:40:48,576 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=*,subtype=RingBuffer'
> 2016-10-10 09:40:48,578 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55
> 2016-10-10 09:40:48,580 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=StatusLogger
> 2016-10-10 09:40:48,581 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=ContextSelector
> 2016-10-10 09:40:48,582 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=
> 2016-10-10 09:40:48,583 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=Console
> 2016-10-10 09:40:48,583 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=MyFile
> 2016-10-10 09:40:48,583 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=DailyRoll
> 2016-10-10 09:40:48,585 main TRACE Using default SystemClock for timestamps.
> 2016-10-10 09:40:48,585 main TRACE Using DummyNanoClock for nanosecond
> timestamps.
> 2016-10-10 09:40:48,585 main DEBUG Reconfiguration complete for
> context[name=2a139a55] at URI
> /Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml
> (org.apache.logging.log4j.core.LoggerContext@55183b20) with optional
> ClassLoader: null
> 2016-10-10 09:40:48,585 main DEBUG Shutdown hook enabled. Registering a new
> one.
> 2016-10-10 09:40:48,586 main DEBUG LoggerContext[name=2a139a55,
> org.apache.logging.log4j.core.LoggerContext@55183b20] started OK.
> Debug Log menu item clicked; Logging is now true
> 2016-10-11 00:00:25,734 pool-1-thread-1 DEBUG Stopping
> LoggerContext[name=2a139a55,
> org.apache.logging.log4j.core.LoggerContext@55183b20]
> 2016-10-11 00:00:25,734 pool-1-thread-1 DEBUG Stopping
> LoggerContext[name=2a139a55,
> org.apache.logging.log4j.core.LoggerContext@55183b20]...
> 2016-10-11 00:00:25,735 pool-1-thread-1 TRACE Unregistering 1 MBeans:
> [org.apache.logging.log4j2:type=2a139a55]
> 2016-10-11 00:00:25,735 pool-1-thread-1 TRACE Unregistering 1 MBeans:
> [org.apache.logging.log4j2:type=2a139a55,component=StatusLogger]
> 2016-10-11 00:00:25,735 pool-1-thread-1 TRACE Unregistering 1 MBeans:
> [org.apache.logging.log4j2:type=2a139a55,component=ContextSelector]
> 2016-10-11 00:00:25,736 pool-1-thread-1 TRACE Unregistering 1 MBeans:
> [org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=]
> 2016-10-11 00:00:25,736 pool-1-thread-1 TRACE Unregistering 3 MBeans:
> [org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=MyFile,
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=Console,
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=DailyRoll]
> 2016-10-11 00:00:25,736 pool-1-thread-1 TRACE Unregistering but no MBeans
> found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=AsyncAppenders,name=*'
> 2016-10-11 00:00:25,736 pool-1-thread-1 TRACE Unregistering but no MBeans
> found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=AsyncLoggerRingBuffer'
> 2016-10-11 00:00:25,736 pool-1-thread-1 TRACE Unregistering but no MBeans
> found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=*,subtype=RingBuffer'
> 2016-10-11 00:00:25,737 pool-1-thread-1 TRACE Stopping
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]...
> 2016-10-11 00:00:25,737 pool-1-thread-1 TRACE XmlConfiguration notified 2
> ReliabilityStrategies that config will be stopped.
> 2016-10-11 00:00:25,737 pool-1-thread-1 TRACE XmlConfiguration stopping 1
> LoggerConfigs.
> 2016-10-11 00:00:25,737 pool-1-thread-1 TRACE XmlConfiguration stopping root
> LoggerConfig.
> 2016-10-11 00:00:25,737 pool-1-thread-1 TRACE XmlConfiguration notifying
> ReliabilityStrategies that appenders will be stopped.
> 2016-10-11 00:00:25,737 pool-1-thread-1 TRACE XmlConfiguration stopping
> remaining Appenders.
> 2016-10-11 00:00:25,737 pool-1-thread-1 DEBUG Shutting down
> RollingFileManager
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 -
> Oct/Launcher.log
> 2016-10-11 00:00:25,988 pool-1-thread-1 DEBUG Shut down RollingFileManager
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 -
> Oct/Launcher.log, all resources released: true
> 2016-10-11 00:00:25,988 pool-1-thread-1 DEBUG Shutting down FileManager
> logs/artdept.log
> 2016-10-11 00:00:25,988 pool-1-thread-1 DEBUG Shut down FileManager
> logs/artdept.log, all resources released: true
> 2016-10-11 00:00:25,989 pool-1-thread-1 DEBUG Shutting down
> OutputStreamManager SYSTEM_OUT.false.false
> 2016-10-11 00:00:25,989 pool-1-thread-1 DEBUG Shut down OutputStreamManager
> SYSTEM_OUT.false.false, all resources released: true
> 2016-10-11 00:00:25,989 pool-1-thread-1 TRACE XmlConfiguration stopped 3
> remaining Appenders.
> 2016-10-11 00:00:25,989 pool-1-thread-1 TRACE XmlConfiguration cleaning
> Appenders from 2 LoggerConfigs.
> 2016-10-11 00:00:25,989 pool-1-thread-1 DEBUG Log4j2 ConfigurationScheduler
> shutting down threads in
> java.util.concurrent.ScheduledThreadPoolExecutor@11d33cbe[Running, pool size
> = 2, active threads = 0, queued tasks = 2, completed tasks = 7]
> 2016-10-11 00:00:25,989 pool-1-thread-1 DEBUG Stopped
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> OK
> 2016-10-11 00:00:25,990 pool-1-thread-1 DEBUG Stopped
> LoggerContext[name=2a139a55,
> org.apache.logging.log4j.core.LoggerContext@55183b20]...
> {noformat}
> No exceptions recorded.
> However, if I re-start the application _while the computer's clock is still
> showing past Midnight on the following day_, I am given _this_ stacktrace,
> which _does_ have exceptions recorded:
> {noformat}
> 2016-10-11 00:01:02,843 main DEBUG Initializing configuration
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> 2016-10-11 00:01:02,848 main DEBUG Installed script engines
> 2016-10-11 00:01:03,071 main DEBUG Oracle Nashorn Version: 1.8.0_74,
> Language: ECMAScript, Threading: Not Thread Safe, Compile: true, Names:
> {nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript}
> 2016-10-11 00:01:03,097 main DEBUG AppleScriptEngine Version: 1.1, Language:
> AppleScript, Threading: Not Thread Safe, Compile: false, Names:
> {AppleScriptEngine, AppleScript, OSA}
> 2016-10-11 00:01:03,097 main DEBUG PluginManager 'Core' found 107 plugins
> 2016-10-11 00:01:03,097 main DEBUG PluginManager 'Level' found 0 plugins
> 2016-10-11 00:01:03,102 main DEBUG 2 starting Log4j2 ConfigurationScheduler
> threads
> 2016-10-11 00:01:03,104 main DEBUG Building Plugin[name=property,
> class=org.apache.logging.log4j.core.config.Property].
> 2016-10-11 00:01:03,113 main TRACE TypeConverterRegistry initializing.
> 2016-10-11 00:01:03,114 main DEBUG PluginManager 'TypeConverter' found 23
> plugins
> 2016-10-11 00:01:03,121 main DEBUG createProperty(name="filename",
> value="logs/artdept.log")
> 2016-10-11 00:01:03,121 main DEBUG Building Plugin[name=property,
> class=org.apache.logging.log4j.core.config.Property].
> 2016-10-11 00:01:03,122 main DEBUG createProperty(name="baseDir",
> value="/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs")
> 2016-10-11 00:01:03,122 main DEBUG Building Plugin[name=properties,
> class=org.apache.logging.log4j.core.config.PropertiesPlugin].
> 2016-10-11 00:01:03,126 main DEBUG
> configureSubstitutor(={filename=logs/artdept.log,
> baseDir=/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs},
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml))
> 2016-10-11 00:01:03,127 main DEBUG PluginManager 'Lookup' found 13 plugins
> 2016-10-11 00:01:03,128 main DEBUG Building Plugin[name=layout,
> class=org.apache.logging.log4j.core.layout.PatternLayout].
> 2016-10-11 00:01:03,132 main DEBUG
> PatternLayout$Builder(pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} -
> %msg%n", PatternSelector=null,
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> Replace=null, charset="null", alwaysWriteExceptions="null",
> noConsoleNoAnsi="null", header="null", footer="null")
> 2016-10-11 00:01:03,132 main DEBUG PluginManager 'Converter' found 41 plugins
> 2016-10-11 00:01:03,133 main DEBUG Building Plugin[name=appender,
> class=org.apache.logging.log4j.core.appender.ConsoleAppender].
> 2016-10-11 00:01:03,139 main DEBUG
> ConsoleAppender$Builder(target="SYSTEM_OUT", follow="null", direct="null",
> bufferedIo="null", bufferSize="null", immediateFlush="null",
> ignoreExceptions="null", PatternLayout(%d{HH:mm:ss.SSS} [%t] %-5level
> %logger{36} - %msg%n), name="Console", Filter=null)
> 2016-10-11 00:01:03,139 main DEBUG Starting OutputStreamManager
> SYSTEM_OUT.false.false
> 2016-10-11 00:01:03,140 main DEBUG Building Plugin[name=layout,
> class=org.apache.logging.log4j.core.layout.PatternLayout].
> 2016-10-11 00:01:03,140 main DEBUG PatternLayout$Builder(pattern="%d %p
> %C{1.} [%t] %m%n", PatternSelector=null,
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> Replace=null, charset="null", alwaysWriteExceptions="null",
> noConsoleNoAnsi="null", header="null", footer="null")
> 2016-10-11 00:01:03,150 main DEBUG Building Plugin[name=appender,
> class=org.apache.logging.log4j.core.appender.FileAppender].
> 2016-10-11 00:01:03,153 main DEBUG
> FileAppender$Builder(fileName="logs/artdept.log", append="null",
> locking="null", advertise="null", advertiseUri="null", createOnDemand="null",
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> bufferedIo="null", bufferSize="null", immediateFlush="null",
> ignoreExceptions="null", PatternLayout(%d %p %C{1.} [%t] %m%n),
> name="MyFile", Filter=null)
> 2016-10-11 00:01:03,154 main DEBUG Starting FileManager logs/artdept.log
> 2016-10-11 00:01:03,154 main DEBUG Building Plugin[name=layout,
> class=org.apache.logging.log4j.core.layout.PatternLayout].
> 2016-10-11 00:01:03,155 main DEBUG PatternLayout$Builder(pattern="%d %p
> %C{1.} [%t] %m%n", PatternSelector=null,
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> Replace=null, charset="null", alwaysWriteExceptions="null",
> noConsoleNoAnsi="null", header="null", footer="null")
> 2016-10-11 00:01:03,155 main DEBUG Building Plugin[name=CronTriggeringPolicy,
> class=org.apache.logging.log4j.core.appender.rolling.CronTriggeringPolicy].
> 2016-10-11 00:01:03,157 main DEBUG
> createPolicy(Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> evaluateOnStartup="true", schedule="0 0 0 * * ?")
> 2016-10-11 00:01:03,160 main DEBUG Building
> Plugin[name=SizeBasedTriggeringPolicy,
> class=org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy].
> 2016-10-11 00:01:03,160 main DEBUG createPolicy(size="250 MB")
> 2016-10-11 00:01:03,161 main DEBUG Building Plugin[name=Policies,
> class=org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy].
> 2016-10-11 00:01:03,162 main DEBUG
> createPolicy(={CronTriggeringPolicy(schedule=0 0 0 * * ?),
> SizeBasedTriggeringPolicy(size=262144000)})
> 2016-10-11 00:01:03,162 main DEBUG Building Plugin[name=appender,
> class=org.apache.logging.log4j.core.appender.RollingFileAppender].
> 2016-10-11 00:01:03,165 main DEBUG
> RollingFileAppender$Builder(fileName="/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10
> - Oct/Launcher.log",
> filePattern="/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10
> - Oct/%d{dd} - Launcher-%i.log", append="null", locking="null",
> Policies(CompositeTriggeringPolicy(policies=[CronTriggeringPolicy(schedule=0
> 0 0 * * ?), SizeBasedTriggeringPolicy(size=262144000)])), Strategy=null,
> advertise="null", advertiseUri="null", createOnDemand="null",
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> bufferedIo="null", bufferSize="null", immediateFlush="null",
> ignoreExceptions="null", PatternLayout(%d %p %C{1.} [%t] %m%n),
> name="DailyRoll", Filter=null)
> 2016-10-11 00:01:03,175 main TRACE New file
> '/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 -
> Oct/Launcher.log' created = false
> 2016-10-11 00:01:03,177 main DEBUG Starting RollingFileManager
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 -
> Oct/Launcher.log
> 2016-10-11 00:01:03,178 main DEBUG PluginManager 'FileConverter' found 2
> plugins
> 2016-10-11 00:01:03,182 main TRACE Using default SystemClock for timestamps.
> 2016-10-11 00:01:03,191 main TRACE DefaultRolloverStrategy.purge() took 10.0
> milliseconds
> 2016-10-11 00:01:03,193 main DEBUG RollingFileManager executing synchronous
> FileRenameAction[/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10
> - Oct/Launcher.log to
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 - Oct/11 -
> Launcher-2.log, renameEmptyFiles=false]
> 2016-10-11 00:01:03,203 main TRACE Renamed file
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 -
> Oct/Launcher.log to
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 - Oct/11 -
> Launcher-2.log with Files.move
> 2016-10-11 00:01:03,205 main ERROR Unable to inject fields into builder class
> for plugin type class
> org.apache.logging.log4j.core.appender.RollingFileAppender, element
> RollingFile. java.lang.NullPointerException
> at
> org.apache.logging.log4j.core.appender.rolling.CronTriggeringPolicy.rollover(CronTriggeringPolicy.java:133)
> at
> org.apache.logging.log4j.core.appender.rolling.CronTriggeringPolicy.initialize(CronTriggeringPolicy.java:69)
> at
> org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy.initialize(CompositeTriggeringPolicy.java:52)
> at
> org.apache.logging.log4j.core.appender.rolling.RollingFileManager.initialize(RollingFileManager.java:104)
> at
> org.apache.logging.log4j.core.appender.RollingFileAppender$Builder.build(RollingFileAppender.java:142)
> at
> org.apache.logging.log4j.core.appender.RollingFileAppender$Builder.build(RollingFileAppender.java:58)
> at
> org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:122)
> at
> org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:942)
> at
> org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:882)
> at
> org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:874)
> at
> org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:498)
> at
> org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:227)
> at
> org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:239)
> at
> org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:530)
> at
> org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:603)
> at
> org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:620)
> at
> org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:226)
> at
> org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:242)
> at
> org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:45)
> at org.apache.logging.log4j.LogManager.getContext(LogManager.java:174)
> at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:618)
> at info.chrismcgee.sky.artdept.ArtDept.<clinit>(ArtDept.java:85)
> 2016-10-11 00:01:03,206 main ERROR Unable to invoke factory method in class
> class org.apache.logging.log4j.core.appender.RollingFileAppender for element
> RollingFile. java.lang.IllegalStateException: No factory method found for
> class org.apache.logging.log4j.core.appender.RollingFileAppender
> at
> org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.findFactoryMethod(PluginBuilder.java:224)
> at
> org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:130)
> at
> org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:942)
> at
> org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:882)
> at
> org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:874)
> at
> org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:498)
> at
> org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:227)
> at
> org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:239)
> at
> org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:530)
> at
> org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:603)
> at
> org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:620)
> at
> org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:226)
> at
> org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:242)
> at
> org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:45)
> at org.apache.logging.log4j.LogManager.getContext(LogManager.java:174)
> at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:618)
> at info.chrismcgee.sky.artdept.ArtDept.<clinit>(ArtDept.java:85)
> 2016-10-11 00:01:03,207 main DEBUG Building Plugin[name=appenders,
> class=org.apache.logging.log4j.core.config.AppendersPlugin].
> 2016-10-11 00:01:03,207 main ERROR Null object returned for RollingFile in
> Appenders.
> 2016-10-11 00:01:03,207 main DEBUG createAppenders(={Console, MyFile, })
> 2016-10-11 00:01:03,207 main DEBUG Building Plugin[name=AppenderRef,
> class=org.apache.logging.log4j.core.config.AppenderRef].
> 2016-10-11 00:01:03,208 main DEBUG createAppenderRef(ref="DailyRoll",
> level="null", Filter=null)
> 2016-10-11 00:01:03,208 main DEBUG Building Plugin[name=root,
> class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
> 2016-10-11 00:01:03,209 main DEBUG createLogger(additivity="null",
> level="TRACE", includeLocation="null", ={DailyRoll}, ={},
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> Filter=null)
> 2016-10-11 00:01:03,211 main DEBUG Building Plugin[name=loggers,
> class=org.apache.logging.log4j.core.config.LoggersPlugin].
> 2016-10-11 00:01:03,211 main DEBUG createLoggers(={root})
> 2016-10-11 00:01:03,211 main ERROR Unable to locate appender "DailyRoll" for
> logger config "root"
> 2016-10-11 00:01:03,212 main DEBUG Configuration
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> initialized
> 2016-10-11 00:01:03,212 main DEBUG Starting configuration
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> 2016-10-11 00:01:03,213 main DEBUG Started configuration
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> OK.
> 2016-10-11 00:01:03,214 main TRACE Stopping
> org.apache.logging.log4j.core.config.DefaultConfiguration@76ccd017...
> 2016-10-11 00:01:03,214 main TRACE DefaultConfiguration notified 1
> ReliabilityStrategies that config will be stopped.
> 2016-10-11 00:01:03,214 main TRACE DefaultConfiguration stopping root
> LoggerConfig.
> 2016-10-11 00:01:03,214 main TRACE DefaultConfiguration notifying
> ReliabilityStrategies that appenders will be stopped.
> 2016-10-11 00:01:03,214 main TRACE DefaultConfiguration stopping remaining
> Appenders.
> 2016-10-11 00:01:03,214 main DEBUG Shutting down OutputStreamManager
> SYSTEM_OUT.false.false-1
> 2016-10-11 00:01:03,215 main DEBUG Shut down OutputStreamManager
> SYSTEM_OUT.false.false-1, all resources released: true
> 2016-10-11 00:01:03,215 main TRACE DefaultConfiguration stopped 1 remaining
> Appenders.
> 2016-10-11 00:01:03,215 main TRACE DefaultConfiguration cleaning Appenders
> from 1 LoggerConfigs.
> 2016-10-11 00:01:03,215 main DEBUG Stopped
> org.apache.logging.log4j.core.config.DefaultConfiguration@76ccd017 OK
> 2016-10-11 00:01:03,265 main TRACE Reregistering MBeans after reconfigure.
> Selector=org.apache.logging.log4j.core.selector.ClassLoaderContextSelector@689604d9
> 2016-10-11 00:01:03,266 main TRACE Reregistering context (1/1): '2a139a55'
> org.apache.logging.log4j.core.LoggerContext@18078bef
> 2016-10-11 00:01:03,267 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55'
> 2016-10-11 00:01:03,268 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=StatusLogger'
> 2016-10-11 00:01:03,268 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=ContextSelector'
> 2016-10-11 00:01:03,268 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=*'
> 2016-10-11 00:01:03,269 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=*'
> 2016-10-11 00:01:03,269 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=AsyncAppenders,name=*'
> 2016-10-11 00:01:03,269 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=AsyncLoggerRingBuffer'
> 2016-10-11 00:01:03,269 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=*,subtype=RingBuffer'
> 2016-10-11 00:01:03,270 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55
> 2016-10-11 00:01:03,272 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=StatusLogger
> 2016-10-11 00:01:03,273 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=ContextSelector
> 2016-10-11 00:01:03,274 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=
> 2016-10-11 00:01:03,276 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=Console
> 2016-10-11 00:01:03,276 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=MyFile
> 2016-10-11 00:01:03,276 main TRACE Using DummyNanoClock for nanosecond
> timestamps.
> 2016-10-11 00:01:03,277 main DEBUG Reconfiguration complete for
> context[name=2a139a55] at URI
> /Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml
> (org.apache.logging.log4j.core.LoggerContext@18078bef) with optional
> ClassLoader: null
> 2016-10-11 00:01:03,277 main DEBUG Shutdown hook enabled. Registering a new
> one.
> 2016-10-11 00:01:03,278 main DEBUG LoggerContext[name=2a139a55,
> org.apache.logging.log4j.core.LoggerContext@18078bef] started OK.
> Debug Log menu item clicked; Logging is now true
> 2016-10-11 00:02:05,448 pool-1-thread-1 DEBUG Stopping
> LoggerContext[name=2a139a55,
> org.apache.logging.log4j.core.LoggerContext@18078bef]
> 2016-10-11 00:02:05,449 pool-1-thread-1 DEBUG Stopping
> LoggerContext[name=2a139a55,
> org.apache.logging.log4j.core.LoggerContext@18078bef]...
> 2016-10-11 00:02:05,449 pool-1-thread-1 TRACE Unregistering 1 MBeans:
> [org.apache.logging.log4j2:type=2a139a55]
> 2016-10-11 00:02:05,449 pool-1-thread-1 TRACE Unregistering 1 MBeans:
> [org.apache.logging.log4j2:type=2a139a55,component=StatusLogger]
> 2016-10-11 00:02:05,449 pool-1-thread-1 TRACE Unregistering 1 MBeans:
> [org.apache.logging.log4j2:type=2a139a55,component=ContextSelector]
> 2016-10-11 00:02:05,450 pool-1-thread-1 TRACE Unregistering 1 MBeans:
> [org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=]
> 2016-10-11 00:02:05,450 pool-1-thread-1 TRACE Unregistering 2 MBeans:
> [org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=MyFile,
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=Console]
> 2016-10-11 00:02:05,450 pool-1-thread-1 TRACE Unregistering but no MBeans
> found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=AsyncAppenders,name=*'
> 2016-10-11 00:02:05,450 pool-1-thread-1 TRACE Unregistering but no MBeans
> found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=AsyncLoggerRingBuffer'
> 2016-10-11 00:02:05,451 pool-1-thread-1 TRACE Unregistering but no MBeans
> found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=*,subtype=RingBuffer'
> 2016-10-11 00:02:05,451 pool-1-thread-1 TRACE Stopping
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]...
> 2016-10-11 00:02:05,451 pool-1-thread-1 TRACE XmlConfiguration notified 2
> ReliabilityStrategies that config will be stopped.
> 2016-10-11 00:02:05,451 pool-1-thread-1 TRACE XmlConfiguration stopping 1
> LoggerConfigs.
> 2016-10-11 00:02:05,451 pool-1-thread-1 TRACE XmlConfiguration stopping root
> LoggerConfig.
> 2016-10-11 00:02:05,451 pool-1-thread-1 TRACE XmlConfiguration notifying
> ReliabilityStrategies that appenders will be stopped.
> 2016-10-11 00:02:05,452 pool-1-thread-1 TRACE XmlConfiguration stopping
> remaining Appenders.
> 2016-10-11 00:02:05,452 pool-1-thread-1 DEBUG Shutting down FileManager
> logs/artdept.log
> 2016-10-11 00:02:05,452 pool-1-thread-1 DEBUG Shut down FileManager
> logs/artdept.log, all resources released: true
> 2016-10-11 00:02:05,452 pool-1-thread-1 DEBUG Shutting down
> OutputStreamManager SYSTEM_OUT.false.false
> 2016-10-11 00:02:05,452 pool-1-thread-1 DEBUG Shut down OutputStreamManager
> SYSTEM_OUT.false.false, all resources released: true
> 2016-10-11 00:02:05,452 pool-1-thread-1 TRACE XmlConfiguration stopped 2
> remaining Appenders.
> 2016-10-11 00:02:05,453 pool-1-thread-1 TRACE XmlConfiguration cleaning
> Appenders from 2 LoggerConfigs.
> 2016-10-11 00:02:05,453 pool-1-thread-1 DEBUG Log4j2 ConfigurationScheduler
> shutting down threads in
> java.util.concurrent.ScheduledThreadPoolExecutor@4fba9a33[Running, pool size
> = 2, active threads = 0, queued tasks = 1, completed tasks = 2]
> 2016-10-11 00:02:05,453 pool-1-thread-1 DEBUG Stopped
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> OK
> 2016-10-11 00:02:05,454 pool-1-thread-1 DEBUG Stopped
> LoggerContext[name=2a139a55,
> org.apache.logging.log4j.core.LoggerContext@18078bef]...
> {noformat}
> The rollover _does_ occur, but then nothing is recorded into the current log
> file.
> One final log. This one is taken from when I left the program running
> overnight. Notice what happens, close to the end of it, where the actual
> rollover takes place at Midnight:
> {noformat}
> 2016-10-10 17:13:45,925 main DEBUG Initializing configuration
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> 2016-10-10 17:13:45,952 main DEBUG Installed script engines
> 2016-10-10 17:13:46,217 main DEBUG Oracle Nashorn Version: 1.8.0_74,
> Language: ECMAScript, Threading: Not Thread Safe, Compile: true, Names:
> {nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, ecmascript}
> 2016-10-10 17:13:46,650 main DEBUG AppleScriptEngine Version: 1.1, Language:
> AppleScript, Threading: Not Thread Safe, Compile: false, Names:
> {AppleScriptEngine, AppleScript, OSA}
> 2016-10-10 17:13:46,651 main DEBUG PluginManager 'Core' found 107 plugins
> 2016-10-10 17:13:46,651 main DEBUG PluginManager 'Level' found 0 plugins
> 2016-10-10 17:13:46,655 main DEBUG 2 starting Log4j2 ConfigurationScheduler
> threads
> 2016-10-10 17:13:46,657 main DEBUG Building Plugin[name=property,
> class=org.apache.logging.log4j.core.config.Property].
> 2016-10-10 17:13:46,687 main TRACE TypeConverterRegistry initializing.
> 2016-10-10 17:13:46,688 main DEBUG PluginManager 'TypeConverter' found 23
> plugins
> 2016-10-10 17:13:46,700 main DEBUG createProperty(name="filename",
> value="logs/artdept.log")
> 2016-10-10 17:13:46,700 main DEBUG Building Plugin[name=property,
> class=org.apache.logging.log4j.core.config.Property].
> 2016-10-10 17:13:46,700 main DEBUG createProperty(name="baseDir",
> value="/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs")
> 2016-10-10 17:13:46,701 main DEBUG Building Plugin[name=properties,
> class=org.apache.logging.log4j.core.config.PropertiesPlugin].
> 2016-10-10 17:13:46,706 main DEBUG
> configureSubstitutor(={filename=logs/artdept.log,
> baseDir=/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs},
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml))
> 2016-10-10 17:13:46,706 main DEBUG PluginManager 'Lookup' found 13 plugins
> 2016-10-10 17:13:46,707 main DEBUG Building Plugin[name=layout,
> class=org.apache.logging.log4j.core.layout.PatternLayout].
> 2016-10-10 17:13:46,713 main DEBUG
> PatternLayout$Builder(pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} -
> %msg%n", PatternSelector=null,
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> Replace=null, charset="null", alwaysWriteExceptions="null",
> noConsoleNoAnsi="null", header="null", footer="null")
> 2016-10-10 17:13:46,713 main DEBUG PluginManager 'Converter' found 41 plugins
> 2016-10-10 17:13:46,714 main DEBUG Building Plugin[name=appender,
> class=org.apache.logging.log4j.core.appender.ConsoleAppender].
> 2016-10-10 17:13:46,719 main DEBUG
> ConsoleAppender$Builder(target="SYSTEM_OUT", follow="null", direct="null",
> bufferedIo="null", bufferSize="null", immediateFlush="null",
> ignoreExceptions="null", PatternLayout(%d{HH:mm:ss.SSS} [%t] %-5level
> %logger{36} - %msg%n), name="Console", Filter=null)
> 2016-10-10 17:13:46,719 main DEBUG Starting OutputStreamManager
> SYSTEM_OUT.false.false
> 2016-10-10 17:13:46,720 main DEBUG Building Plugin[name=layout,
> class=org.apache.logging.log4j.core.layout.PatternLayout].
> 2016-10-10 17:13:46,720 main DEBUG PatternLayout$Builder(pattern="%d %p
> %C{1.} [%t] %m%n", PatternSelector=null,
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> Replace=null, charset="null", alwaysWriteExceptions="null",
> noConsoleNoAnsi="null", header="null", footer="null")
> 2016-10-10 17:13:46,732 main DEBUG Building Plugin[name=appender,
> class=org.apache.logging.log4j.core.appender.FileAppender].
> 2016-10-10 17:13:46,735 main DEBUG
> FileAppender$Builder(fileName="logs/artdept.log", append="null",
> locking="null", advertise="null", advertiseUri="null", createOnDemand="null",
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> bufferedIo="null", bufferSize="null", immediateFlush="null",
> ignoreExceptions="null", PatternLayout(%d %p %C{1.} [%t] %m%n),
> name="MyFile", Filter=null)
> 2016-10-10 17:13:46,736 main DEBUG Starting FileManager logs/artdept.log
> 2016-10-10 17:13:46,736 main DEBUG Building Plugin[name=layout,
> class=org.apache.logging.log4j.core.layout.PatternLayout].
> 2016-10-10 17:13:46,736 main DEBUG PatternLayout$Builder(pattern="%d %p
> %C{1.} [%t] %m%n", PatternSelector=null,
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> Replace=null, charset="null", alwaysWriteExceptions="null",
> noConsoleNoAnsi="null", header="null", footer="null")
> 2016-10-10 17:13:46,737 main DEBUG Building Plugin[name=CronTriggeringPolicy,
> class=org.apache.logging.log4j.core.appender.rolling.CronTriggeringPolicy].
> 2016-10-10 17:13:46,738 main DEBUG
> createPolicy(Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> evaluateOnStartup="true", schedule="0 0 0 * * ?")
> 2016-10-10 17:13:46,740 main DEBUG Building
> Plugin[name=SizeBasedTriggeringPolicy,
> class=org.apache.logging.log4j.core.appender.rolling.SizeBasedTriggeringPolicy].
> 2016-10-10 17:13:46,741 main DEBUG createPolicy(size="250 MB")
> 2016-10-10 17:13:46,742 main DEBUG Building Plugin[name=Policies,
> class=org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy].
> 2016-10-10 17:13:46,742 main DEBUG
> createPolicy(={CronTriggeringPolicy(schedule=0 0 0 * * ?),
> SizeBasedTriggeringPolicy(size=262144000)})
> 2016-10-10 17:13:46,742 main DEBUG Building Plugin[name=appender,
> class=org.apache.logging.log4j.core.appender.RollingFileAppender].
> 2016-10-10 17:13:46,745 main DEBUG
> RollingFileAppender$Builder(fileName="/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10
> - Oct/Launcher.log",
> filePattern="/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10
> - Oct/%d{dd} - Launcher-%i.log", append="null", locking="null",
> Policies(CompositeTriggeringPolicy(policies=[CronTriggeringPolicy(schedule=0
> 0 0 * * ?), SizeBasedTriggeringPolicy(size=262144000)])), Strategy=null,
> advertise="null", advertiseUri="null", createOnDemand="null",
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> bufferedIo="null", bufferSize="null", immediateFlush="null",
> ignoreExceptions="null", PatternLayout(%d %p %C{1.} [%t] %m%n),
> name="DailyRoll", Filter=null)
> 2016-10-10 17:13:46,757 main TRACE New file
> '/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 -
> Oct/Launcher.log' created = false
> 2016-10-10 17:13:46,760 main DEBUG Starting RollingFileManager
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 -
> Oct/Launcher.log
> 2016-10-10 17:13:46,760 main DEBUG PluginManager 'FileConverter' found 2
> plugins
> 2016-10-10 17:13:46,765 main DEBUG Building Plugin[name=appenders,
> class=org.apache.logging.log4j.core.config.AppendersPlugin].
> 2016-10-10 17:13:46,765 main DEBUG createAppenders(={Console, MyFile,
> DailyRoll})
> 2016-10-10 17:13:46,766 main DEBUG Building Plugin[name=AppenderRef,
> class=org.apache.logging.log4j.core.config.AppenderRef].
> 2016-10-10 17:13:46,766 main DEBUG createAppenderRef(ref="DailyRoll",
> level="null", Filter=null)
> 2016-10-10 17:13:46,766 main DEBUG Building Plugin[name=root,
> class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger].
> 2016-10-10 17:13:46,767 main DEBUG createLogger(additivity="null",
> level="TRACE", includeLocation="null", ={DailyRoll}, ={},
> Configuration(/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml),
> Filter=null)
> 2016-10-10 17:13:46,769 main DEBUG Building Plugin[name=loggers,
> class=org.apache.logging.log4j.core.config.LoggersPlugin].
> 2016-10-10 17:13:46,770 main DEBUG createLoggers(={root})
> 2016-10-10 17:13:46,770 main DEBUG Configuration
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> initialized
> 2016-10-10 17:13:46,770 main DEBUG Starting configuration
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> 2016-10-10 17:13:46,771 main DEBUG Started configuration
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> OK.
> 2016-10-10 17:13:46,771 main TRACE Stopping
> org.apache.logging.log4j.core.config.DefaultConfiguration@76ccd017...
> 2016-10-10 17:13:46,772 main TRACE DefaultConfiguration notified 1
> ReliabilityStrategies that config will be stopped.
> 2016-10-10 17:13:46,772 main TRACE DefaultConfiguration stopping root
> LoggerConfig.
> 2016-10-10 17:13:46,772 main TRACE DefaultConfiguration notifying
> ReliabilityStrategies that appenders will be stopped.
> 2016-10-10 17:13:46,772 main TRACE DefaultConfiguration stopping remaining
> Appenders.
> 2016-10-10 17:13:46,772 main DEBUG Shutting down OutputStreamManager
> SYSTEM_OUT.false.false-1
> 2016-10-10 17:13:46,773 main DEBUG Shut down OutputStreamManager
> SYSTEM_OUT.false.false-1, all resources released: true
> 2016-10-10 17:13:46,773 main TRACE DefaultConfiguration stopped 1 remaining
> Appenders.
> 2016-10-10 17:13:46,773 main TRACE DefaultConfiguration cleaning Appenders
> from 1 LoggerConfigs.
> 2016-10-10 17:13:46,773 main DEBUG Stopped
> org.apache.logging.log4j.core.config.DefaultConfiguration@76ccd017 OK
> 2016-10-10 17:13:46,816 main TRACE Reregistering MBeans after reconfigure.
> Selector=org.apache.logging.log4j.core.selector.ClassLoaderContextSelector@1bd4fdd
> 2016-10-10 17:13:46,817 main TRACE Reregistering context (1/1): '2a139a55'
> org.apache.logging.log4j.core.LoggerContext@55183b20
> 2016-10-10 17:13:46,818 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55'
> 2016-10-10 17:13:46,819 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=StatusLogger'
> 2016-10-10 17:13:46,819 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=ContextSelector'
> 2016-10-10 17:13:46,820 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=*'
> 2016-10-10 17:13:46,820 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=*'
> 2016-10-10 17:13:46,820 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=AsyncAppenders,name=*'
> 2016-10-10 17:13:46,821 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=AsyncLoggerRingBuffer'
> 2016-10-10 17:13:46,821 main TRACE Unregistering but no MBeans found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=*,subtype=RingBuffer'
> 2016-10-10 17:13:46,823 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55
> 2016-10-10 17:13:46,825 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=StatusLogger
> 2016-10-10 17:13:46,826 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=ContextSelector
> 2016-10-10 17:13:46,827 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=
> 2016-10-10 17:13:46,829 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=Console
> 2016-10-10 17:13:46,830 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=MyFile
> 2016-10-10 17:13:46,830 main DEBUG Registering MBean
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=DailyRoll
> 2016-10-10 17:13:46,832 main TRACE Using default SystemClock for timestamps.
> 2016-10-10 17:13:46,832 main TRACE Using DummyNanoClock for nanosecond
> timestamps.
> 2016-10-10 17:13:46,832 main DEBUG Reconfiguration complete for
> context[name=2a139a55] at URI
> /Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml
> (org.apache.logging.log4j.core.LoggerContext@55183b20) with optional
> ClassLoader: null
> 2016-10-10 17:13:46,832 main DEBUG Shutdown hook enabled. Registering a new
> one.
> 2016-10-10 17:13:46,833 main DEBUG LoggerContext[name=2a139a55,
> org.apache.logging.log4j.core.LoggerContext@55183b20] started OK.
> Debug Log menu item clicked; Logging is now true
> 2016-10-10 23:59:59,188 Log4j2-TF-3-Scheduled-2 TRACE
> DefaultRolloverStrategy.purge() took 53.0 milliseconds
> 2016-10-10 23:59:59,191 Log4j2-TF-3-Scheduled-2 DEBUG RollingFileManager
> executing synchronous
> FileRenameAction[/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10
> - Oct/Launcher.log to
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 - Oct/11 -
> Launcher-3.log, renameEmptyFiles=false]
> 2016-10-10 23:59:59,204 Log4j2-TF-3-Scheduled-2 TRACE Renamed file
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 -
> Oct/Launcher.log to
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 - Oct/11 -
> Launcher-3.log with Files.move
> 2016-10-11 00:00:00,015 Log4j2-TF-3-Scheduled-1 TRACE
> DefaultRolloverStrategy.purge() took 6.0 milliseconds
> 2016-10-11 00:00:00,016 Log4j2-TF-3-Scheduled-1 DEBUG RollingFileManager
> executing synchronous
> FileRenameAction[/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10
> - Oct/Launcher.log to
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 - Oct/10 -
> Launcher-1.log, renameEmptyFiles=false]
> 2016-10-11 08:38:47,589 pool-1-thread-1 DEBUG Stopping
> LoggerContext[name=2a139a55,
> org.apache.logging.log4j.core.LoggerContext@55183b20]
> 2016-10-11 08:38:47,589 pool-1-thread-1 DEBUG Stopping
> LoggerContext[name=2a139a55,
> org.apache.logging.log4j.core.LoggerContext@55183b20]...
> 2016-10-11 08:38:47,590 pool-1-thread-1 TRACE Unregistering 1 MBeans:
> [org.apache.logging.log4j2:type=2a139a55]
> 2016-10-11 08:38:47,590 pool-1-thread-1 TRACE Unregistering 1 MBeans:
> [org.apache.logging.log4j2:type=2a139a55,component=StatusLogger]
> 2016-10-11 08:38:47,590 pool-1-thread-1 TRACE Unregistering 1 MBeans:
> [org.apache.logging.log4j2:type=2a139a55,component=ContextSelector]
> 2016-10-11 08:38:47,590 pool-1-thread-1 TRACE Unregistering 1 MBeans:
> [org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=]
> 2016-10-11 08:38:47,591 pool-1-thread-1 TRACE Unregistering 3 MBeans:
> [org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=MyFile,
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=Console,
> org.apache.logging.log4j2:type=2a139a55,component=Appenders,name=DailyRoll]
> 2016-10-11 08:38:47,591 pool-1-thread-1 TRACE Unregistering but no MBeans
> found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=AsyncAppenders,name=*'
> 2016-10-11 08:38:47,591 pool-1-thread-1 TRACE Unregistering but no MBeans
> found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=AsyncLoggerRingBuffer'
> 2016-10-11 08:38:47,591 pool-1-thread-1 TRACE Unregistering but no MBeans
> found matching
> 'org.apache.logging.log4j2:type=2a139a55,component=Loggers,name=*,subtype=RingBuffer'
> 2016-10-11 08:38:47,592 pool-1-thread-1 TRACE Stopping
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]...
> 2016-10-11 08:38:47,592 pool-1-thread-1 TRACE XmlConfiguration notified 2
> ReliabilityStrategies that config will be stopped.
> 2016-10-11 08:38:47,592 pool-1-thread-1 TRACE XmlConfiguration stopping 1
> LoggerConfigs.
> 2016-10-11 08:38:47,592 pool-1-thread-1 TRACE XmlConfiguration stopping root
> LoggerConfig.
> 2016-10-11 08:38:47,592 pool-1-thread-1 TRACE XmlConfiguration notifying
> ReliabilityStrategies that appenders will be stopped.
> 2016-10-11 08:38:47,592 pool-1-thread-1 TRACE XmlConfiguration stopping
> remaining Appenders.
> 2016-10-11 08:38:47,592 pool-1-thread-1 DEBUG Shutting down
> RollingFileManager
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 -
> Oct/Launcher.log
> 2016-10-11 08:38:47,598 pool-1-thread-1 DEBUG Shut down RollingFileManager
> /Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs/apache/2016/10 -
> Oct/Launcher.log, all resources released: true
> 2016-10-11 08:38:47,598 pool-1-thread-1 DEBUG Shutting down FileManager
> logs/artdept.log
> 2016-10-11 08:38:47,598 pool-1-thread-1 DEBUG Shut down FileManager
> logs/artdept.log, all resources released: true
> 2016-10-11 08:38:47,598 pool-1-thread-1 DEBUG Shutting down
> OutputStreamManager SYSTEM_OUT.false.false
> 2016-10-11 08:38:47,598 pool-1-thread-1 DEBUG Shut down OutputStreamManager
> SYSTEM_OUT.false.false, all resources released: true
> 2016-10-11 08:38:47,598 pool-1-thread-1 TRACE XmlConfiguration stopped 3
> remaining Appenders.
> 2016-10-11 08:38:47,599 pool-1-thread-1 TRACE XmlConfiguration cleaning
> Appenders from 2 LoggerConfigs.
> 2016-10-11 08:38:47,599 pool-1-thread-1 DEBUG Log4j2 ConfigurationScheduler
> shutting down threads in
> java.util.concurrent.ScheduledThreadPoolExecutor@d1f9106[Running, pool size =
> 2, active threads = 0, queued tasks = 2, completed tasks = 1851]
> 2016-10-11 08:38:47,599 pool-1-thread-1 DEBUG Stopped
> XmlConfiguration[location=/Users/apache/Dropbox/eclipse/workspace/ArtDept/bin/log4j2.xml]
> OK
> 2016-10-11 08:38:47,600 pool-1-thread-1 DEBUG Stopped
> LoggerContext[name=2a139a55,
> org.apache.logging.log4j.core.LoggerContext@55183b20]...
> {noformat}
> It seems to want to rollover _twice_. The first rollover works, but then the
> second one does not. Moreover, the first one is assigning the new day's date
> to the rolled-over log file, which I _don't_ want. Since all of the logs
> inside it are from the 10th of October, the filename should begin with {{10 -
> Launcher}}, not {{11 - Launcher}}.
> This isn't that big of an issue, however, and is one we can live with; but it
> certainly would be nice to have it name the file appropriate to its contents.
> The more important issue is the exceptions that occur, which I mentioned
> earlier.
> For reference, the code in my ArtDept.java file on line 85 (as seen in the
> exception violation lines in the stacktrace above) is just a simple field
> declaration & initialization:
> {code:title=ArtDept.java|borderStyle=solid}
> static final Logger log = LogManager.getLogger(ArtDept.class.getName());
> {code}
> Finally, for reference, my log4j2.xml file:
> {code:xml|title=log4j2.xml|borderStyle=solid}
> <?xml version="1.0" encoding="UTF-8"?>
> <Configuration status="TRACE" monitorInterval="30">
> <Properties>
> <Property name="filename">logs/artdept.log</Property>
> <Property
> name="baseDir">/Volumes/ArtDept/ArtDept/Scripts/sky-artdept/logs</Property>
> </Properties>
> <Appenders>
> <Console name="Console" target="SYSTEM_OUT">
> <PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} -
> %msg%n"/>
> </Console>
> <File name="MyFile" fileName="${filename}">
> <PatternLayout>
> <pattern>%d %p %C{1.} [%t] %m%n</pattern>
> </PatternLayout>
> </File>
> <RollingFile name="DailyRoll"
> fileName="${baseDir}/${env:USER}/${date:yyyy}/${date:MM} -
> ${date:MMM}/Launcher.log"
> filePattern="${baseDir}/${env:USER}/${date:yyyy}/${date:MM} -
> ${date:MMM}/%d{dd} - Launcher-%i.log">
> <PatternLayout>
> <Pattern>%d %p %C{1.} [%t] %m%n</Pattern>
> </PatternLayout>
> <Policies>
> <CronTriggeringPolicy schedule="0 0 0 * * ?"
> evaluateOnStartup="true" />
> <SizeBasedTriggeringPolicy size="250 MB" />
> </Policies>
> </RollingFile>
> </Appenders>
> <Loggers>
> <Root level="trace">
> <AppenderRef ref="DailyRoll"/>
> </Root>
> </Loggers>
> </Configuration>
> {code}
> *EDIT:* Provided some more detailed info and more detailed stacktraces.
> *EDIT 2:* Provided a third stacktrace to show an unusual file renaming issue.
> (Possibly unrelated?)
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-dev-h...@logging.apache.org
