logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Chris McGee (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (LOG4J2-1640) RollingFileAppender with CronTriggeringPolicy broken?
Date Tue, 03 Jan 2017 20:53:58 GMT

    [ https://issues.apache.org/jira/browse/LOG4J2-1640?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15796148#comment-15796148 ] 

Chris McGee commented on LOG4J2-1640:
-------------------------------------

Sounds great and I'll be more than happy to do so. However, being a newbie and still relatively unfamiliar with git/GitHub, I'm not entirely sure how to do so without access to .jar files. So far, I've found the repository on GitHub, and I *think* I've cloned it properly to my Eclipse workspace. I just can't figure out how to make .jar files out of the -core and -api folders, though. May I please have a little push in the right direction so I can test it out with my project?

> 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
>
> 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-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Mime
View raw message