Matt, The problem is: target\status.log failed with java.nio.file.FileSystemException: target\status.log: The process cannot access the file because it is being used by another process.
I'm not familiar with how log4j should be releasing the log file to know where to look. I did notice the afterAll(context) method is never called on the LoggerContextResolver. Would that explain why the file stays locked? Tim On Wed, Feb 17, 2021 at 1:49 PM Tim Perry <tim.v...@gmail.com> wrote: > Yes, I am on windows 10. I'm using Zulu OpenJdk for both Java 8 and 11, > maven 3.6.3, and a fairly new Eclipse. I'd be happy to help you sort out > the problem. It will be fun: I haven't played around with those junit > features. > > On Wed, Feb 17, 2021 at 1:45 PM Matt Sicker <boa...@gmail.com> wrote: > >> Is that on Windows? If so, there seems to be a bug I've introduced in >> the JUnit 5 code that I tried to port from the JUnit 4 code correctly, >> but I don't have a Windows machine to test that out on iteratively. >> See >> https://github.com/apache/logging-log4j2/blob/master/log4j-core/src/test/java/org/apache/logging/log4j/junit/LoggerContextResolver.java >> for relevant code and the JUnit 4 version here in >> >> https://github.com/apache/logging-log4j2/blob/master/log4j-core/src/test/java/org/apache/logging/log4j/junit/LoggerContextRule.java >> which does reconfiguration a bit more heavily (but also in such a way >> that it works more consistently on Windows apparently?) >> >> On Wed, 17 Feb 2021 at 15:36, Tim Perry <tim.v...@gmail.com> wrote: >> > >> > I mean is that: >> > >> > * when I run "mvn install" on the command line then usually 1, but >> > sometimes 2 tests fail. >> > * when I right-click the src/tests/java folder in eclipse and do "run as >> > JUnit" I get ~100 failures. >> > >> > I'm fairly sure the tests are *not* running in parallel. >> > >> > On Wed, Feb 17, 2021 at 1:11 PM Matt Sicker <boa...@gmail.com> wrote: >> > >> > > I think he's referring to the need to run mvn install once before the >> > > IDE will pick up snapshot jars for things like annotation processing >> > > or other fancy things. Simple way to reproduce: try running "mvn >> > > package" without the "install" target. >> > > >> > > On Wed, 17 Feb 2021 at 13:58, Ralph Goers <ralph.go...@dslextreme.com >> > >> > > wrote: >> > > > >> > > > Yeah, there is a very good chance if you are trying to run tests in >> core >> > > in parallel on multiple threads that they will fail. Most of them >> expect >> > > their own LoggerContext. >> > > > >> > > > Ralph >> > > > >> > > > > On Feb 17, 2021, at 12:51 PM, Tim Perry <tim.v...@gmail.com> >> wrote: >> > > > > >> > > > > On master, I noticed that when I build in my IDE that lots of >> tests in >> > > > > log4j-core fail but when I build with maven they pass. In the >> past, >> > > when >> > > > > I've seen this on other projects it was caused by race >> conditions. I >> > > > > wonder: are there race conditions in the tests or the code that >> need >> > > to be >> > > > > addressed? >> > > > > >> > > > > On Sun, Feb 7, 2021 at 1:46 PM Ralph Goers < >> ralph.go...@dslextreme.com >> > > > >> > > > > wrote: >> > > > > >> > > > >> Yes, that is why I am wondering why master is so flaky. >> > > > >> >> > > > >> Ralph >> > > > >> >> > > > >>> On Feb 7, 2021, at 2:34 PM, Gary Gregory < >> garydgreg...@gmail.com> >> > > wrote: >> > > > >>> >> > > > >>> FWIW but not master, I've been building release-2.x lately over >> and >> > > over >> > > > >>> without issues aside from the rare random failure. >> > > > >>> >> > > > >>> G >> > > > >>> >> > > > >>> On Sun, Feb 7, 2021 at 2:37 PM Matt Sicker <boa...@gmail.com> >> wrote: >> > > > >>> >> > > > >>>> I'm not getting errors in log4j-api, though it's possible some >> test >> > > is >> > > > >>>> missing a JUnit annotation which is causing that ThreadContext >> data >> > > > >>>> corruption. >> > > > >>>> >> > > > >>>> I am, however, getting the same log4j-kafka test error. I'll >> try >> > > > >>>> running the log4j-api tests a few more times to see if I can >> > > reproduce >> > > > >>>> any test errors there. >> > > > >>>> >> > > > >>>> On Sun, 7 Feb 2021 at 12:20, Ralph Goers < >> > > ralph.go...@dslextreme.com> >> > > > >>>> wrote: >> > > > >>>>> >> > > > >>>>> I am trying to apply patches to the release-2.x branch and >> make the >> > > > >>>> corresponding changes in master. When I run a build in master I >> > > cannot >> > > > >> get >> > > > >>>> it to succeed. It randomly fails in different ways. I >> typically run >> > > a >> > > > >> full >> > > > >>>> build when I make significant changes and don’t commit unless >> it >> > > > >> passes. So >> > > > >>>> far I have spent well over an hour running the build at least 6 >> > > times >> > > > >>>> trying to get a successful build with no luck. >> > > > >>>>> >> > > > >>>>> Run 1 fails in log4j-api >> > > > >>>>> [ERROR] Failures: >> > > > >>>>> [ERROR] >> AbstractLoggerTest.testMessageThrowsAndNullFormat:912 >> > > > >>>>> Expected: a string containing >> > > > >>>> "org.apache.logging.log4j.spi.AbstractLogger caught >> > > > >>>> java.lang.IllegalStateException logging TestMessage: " >> > > > >>>>> but: was "2021-02-07 10:00:31,277 ForkJoinPool-1-worker-30 >> WARN >> > > > >>>> Ignoring java.io.NotSerializableException: java.lang.Object >> for >> > > key[2] >> > > > >>>> ('unserializable')" >> > > > >>>>> [ERROR] >> > > CloseableThreadContextTest.canReuseCloseableThreadContext:169 >> > > > >>>> expected: <value> but was: <null> >> > > > >>>>> [ERROR] CloseableThreadContextTest.closeIsIdempotent:203 >> > > expected: >> > > > >>>> <map to keep> but was: <null> >> > > > >>>>> [ERROR] >> > > > >>>> >> > > > >> >> > > >> CloseableThreadContextTest.ifTheSameKeyIsAddedTwiceTheOriginalShouldBeUsed:103 >> > > > >>>> expected: <innerValue> but was: <null> >> > > > >>>>> [ERROR] >> CloseableThreadContextTest.pushAllWillPushAllValues:237 >> > > > >>>> expected: <key> but was: <> >> > > > >>>>> [ERROR] >> CloseableThreadContextTest.putAllWillPutAllValues:222 >> > > > >>>> expected: <value> but was: <null> >> > > > >>>>> [ERROR] >> CloseableThreadContextTest.shouldAddAnEntryToTheMap:53 >> > > > >>>> expected: <value> but was: <null> >> > > > >>>>> [ERROR] >> > > > >>>> >> CloseableThreadContextTest.shouldAddEntriesToBothStackAndMap:156 >> > > > >> expected: >> > > > >>>> <value> but was: <null> >> > > > >>>>> [ERROR] >> CloseableThreadContextTest.shouldAddTwoEntriesToTheMap:63 >> > > > >>>> expected: <value> but was: <null> >> > > > >>>>> [ERROR] CloseableThreadContextTest.shouldNestEntries:75 >> expected: >> > > > >>>> <value> but was: <null> >> > > > >>>>> [ERROR] >> > > > >>>> >> > > > >> >> > > >> CloseableThreadContextTest.shouldPreserveOldEntriesFromTheMapWhenAutoClosed:91 >> > > > >>>> expected: <value> but was: <null> >> > > > >>>>> [ERROR] >> > > > >>>> >> > > > >> >> > > >> CloseableThreadContextTest.shouldPushAndPopAParameterizedEntryToTheStack:137 >> > > > >>>> expected: <message param> but was: <> >> > > > >>>>> [ERROR] >> > > > >>>> >> CloseableThreadContextTest.shouldPushAndPopAnEntryToTheStack:113 >> > > > >> expected: >> > > > >>>> <message> but was: <> >> > > > >>>>> [ERROR] >> > > > >>>> >> CloseableThreadContextTest.shouldPushAndPopTwoEntriesToTheStack:124 >> > > > >>>> expected: <message2> but was: <> >> > > > >>>>> [ERROR] >> > > > >>>> >> > > > >> >> > > >> CloseableThreadContextTest.shouldRemoveAnEntryFromTheMapWhenAutoClosed:146 >> > > > >>>> expected: <value> but was: <null> >> > > > >>>>> [INFO] >> > > > >>>>> >> > > > >>>>> >> > > > >>>>> Run 2 fails in log4j-api >> > > > >>>>> [ERROR] Failures: >> > > > >>>>> [ERROR] LoggerTest.mdc:556 Test Year is null ==> expected: >> not >> > > <null> >> > > > >>>>> >> > > > >>>>> Run 3 log4j-api passes but log4j-core fails >> > > > >>>>> [INFO] >> > > > >>>>> [ERROR] Failures: >> > > > >>>>> [ERROR] >> RollingDirectTimeNewDirectoryTest.streamClosedError:95 >> > > check >> > > > >>>> failure >> > > > >>>>> >> > > > >>>>> Run 4 - log4j-api and log4j-core pass but fails in log4j-kafka >> > > > >>>>> [ERROR] Failures: >> > > > >>>>> [ERROR] ConfigurationBuilderTest.testXmlConstructing:116 >> > > > >>>> expected:<<?xml version="1.0" [?> >> > > > >>>>> ]<Configuration name=...> but was:<<?xml version="1.0" >> > > > >>>> [encoding="UTF-8"?>]<Configuration name=…> >> > > > >>>>> >> > > > >>>>> Run 5 - failure in log4j-core (I’m probably the last one to >> touch >> > > this >> > > > >>>> so I’m the one who will most likely need to figure this one >> out) >> > > > >>>>> >> > > > >>>>> [ERROR] Failures: >> > > > >>>>> [ERROR] RollingAppenderDirectWrite1906Test.testAppender:95 >> > > 2021-02-07 >> > > > >>>> 10:50:17,478 main INFO Log4j appears to be running in a Servlet >> > > > >>>> environment, but there's no log4j-web module available. If you >> want >> > > > >> better >> > > > >>>> web container support, please add the log4j-web JAR to your web >> > > archive >> > > > >> or >> > > > >>>> server lib directory. >> > > > >>>>> 2021-02-07 10:50:17,488 main INFO Log4j appears to be running >> in a >> > > > >>>> Servlet environment, but there's no log4j-web module >> available. If >> > > you >> > > > >> want >> > > > >>>> better web container support, please add the log4j-web JAR to >> your >> > > web >> > > > >>>> archive or server lib directory. >> > > > >>>>> 2021-02-07 10:50:17,499 main DEBUG Took 0.003727 seconds to >> load 3 >> > > > >>>> plugins from sun.misc.Launcher$AppClassLoader@4aa298b7 >> > > > >>>>> 2021-02-07 10:50:17,505 main DEBUG Took 0.005450 seconds to >> load >> > > 220 >> > > > >>>> plugins from sun.misc.Launcher$AppClassLoader@4aa298b7 >> > > > >>>>> 2021-02-07 10:50:17,506 main DEBUG Took 0.000032 seconds to >> load 0 >> > > > >>>> plugins from sun.misc.Launcher$ExtClassLoader@44f75083 >> > > > >>>>> 2021-02-07 10:50:17,506 main DEBUG PluginManager 'Converter' >> found >> > > 46 >> > > > >>>> plugins >> > > > >>>>> 2021-02-07 10:50:17,540 main DEBUG Starting >> OutputStreamManager >> > > > >>>> SYSTEM_OUT.false.false-1 >> > > > >>>>> 2021-02-07 10:50:17,541 main DEBUG Initializing Thread >> Context Data >> > > > >>>> Service Providers >> > > > >>>>> 2021-02-07 10:50:17,541 main DEBUG Thread Context Data Service >> > > Provider >> > > > >>>> initialization complete >> > > > >>>>> 2021-02-07 10:50:17,544 main INFO Log4j appears to be running >> in a >> > > > >>>> Servlet environment, but there's no log4j-web module >> available. If >> > > you >> > > > >> want >> > > > >>>> better web container support, please add the log4j-web JAR to >> your >> > > web >> > > > >>>> archive or server lib directory. >> > > > >>>>> 2021-02-07 10:50:17,545 main DEBUG PluginManager >> > > 'ConfigurationFactory' >> > > > >>>> found 4 plugins >> > > > >>>>> 2021-02-07 10:50:17,548 main INFO Log4j appears to be running >> in a >> > > > >>>> Servlet environment, but there's no log4j-web module >> available. If >> > > you >> > > > >> want >> > > > >>>> better web container support, please add the log4j-web JAR to >> your >> > > web >> > > > >>>> archive or server lib directory. >> > > > >>>>> 2021-02-07 10:50:17,549 main INFO Log4j appears to be running >> in a >> > > > >>>> Servlet environment, but there's no log4j-web module >> available. If >> > > you >> > > > >> want >> > > > >>>> better web container support, please add the log4j-web JAR to >> your >> > > web >> > > > >>>> archive or server lib directory. >> > > > >>>>> 2021-02-07 10:50:17,557 main INFO Log4j appears to be running >> in a >> > > > >>>> Servlet environment, but there's no log4j-web module >> available. If >> > > you >> > > > >> want >> > > > >>>> better web container support, please add the log4j-web JAR to >> your >> > > web >> > > > >>>> archive or server lib directory. >> > > > >>>>> 2021-02-07 10:50:17,558 main INFO Log4j appears to be running >> in a >> > > > >>>> Servlet environment, but there's no log4j-web module >> available. If >> > > you >> > > > >> want >> > > > >>>> better web container support, please add the log4j-web JAR to >> your >> > > web >> > > > >>>> archive or server lib directory. >> > > > >>>>> 2021-02-07 10:50:17,561 main DEBUG Using configurationFactory >> > > > >>>> >> > > > >> >> > > >> org.apache.logging.log4j.core.config.ConfigurationFactory$Factory@4387b79e >> > > > >>>>> 2021-02-07 10:50:17,562 main TRACE Trying to find >> > > > >>>> [log4j-rolling-direct-1906.xml] using context class loader >> > > > >>>> sun.misc.Launcher$AppClassLoader@4aa298b7. >> > > > >>>>> 2021-02-07 10:50:17,566 main INFO Log4j appears to be running >> in a >> > > > >>>> Servlet environment, but there's no log4j-web module >> available. If >> > > you >> > > > >> want >> > > > >>>> better web container support, please add the log4j-web JAR to >> your >> > > web >> > > > >>>> archive or server lib directory. >> > > > >>>>> 2021-02-07 10:50:17,567 main DEBUG Closing BufferedInputStream >> > > > >>>> java.io.BufferedInputStream@2cbb3d47 >> > > > >>>>> 2021-02-07 10:50:17,594 main DEBUG Watching configuration >> > > > >>>> >> > > > >> >> > > >> '/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml' >> > > > >>>> for lastModified Sun Feb 07 10:46:58 MST 2021 (1612720018000) >> > > > >>>>> 2021-02-07 10:50:17,595 main DEBUG Starting >> > > > >>>> >> > > > >> >> > > >> LoggerContext[name=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test)] >> > > > >>>> from configuration at log4j-rolling-direct-1906.xml >> > > > >>>>> 2021-02-07 10:50:17,595 main DEBUG Starting >> > > > >>>> >> > > > >> >> > > >> LoggerContext[name=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test), >> > > > >>>> org.apache.logging.log4j.core.LoggerContext@add0edd] with >> > > configuration >> > > > >>>> >> > > > >> >> > > >> XmlConfiguration[location=/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml]... >> > > > >>>>> 2021-02-07 10:50:17,595 main DEBUG Shutdown hook enabled. >> > > Registering a >> > > > >>>> new one. >> > > > >>>>> 2021-02-07 10:50:17,601 main DEBUG null null initializing >> > > configuration >> > > > >>>> >> > > > >> >> > > >> XmlConfiguration[location=/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml] >> > > > >>>>> 2021-02-07 10:50:17,605 main DEBUG Installed 3 script engines >> > > > >>>>> 2021-02-07 10:50:17,772 main DEBUG Oracle Nashorn version: >> > > 1.8.0_144, >> > > > >>>> language: ECMAScript, threading: Not Thread Safe, compile: >> true, >> > > names: >> > > > >>>> [nashorn, Nashorn, js, JS, JavaScript, javascript, ECMAScript, >> > > > >> ecmascript], >> > > > >>>> factory class: >> jdk.nashorn.api.scripting.NashornScriptEngineFactory >> > > > >>>>> 2021-02-07 10:50:17,807 main DEBUG BeanShell Engine version: >> 1.0, >> > > > >>>> language: BeanShell, threading: MULTITHREADED, compile: true, >> names: >> > > > >>>> [beanshell, bsh, java], factory class: >> > > bsh.engine.BshScriptEngineFactory >> > > > >>>>> 2021-02-07 10:50:17,839 main DEBUG Groovy Scripting Engine >> version: >> > > > >> 2.0, >> > > > >>>> language: Groovy, threading: MULTITHREADED, compile: true, >> names: >> > > > >> [groovy, >> > > > >>>> Groovy], factory class: >> > > > >> org.codehaus.groovy.jsr223.GroovyScriptEngineFactory >> > > > >>>>> 2021-02-07 10:50:17,839 main DEBUG PluginManager 'Core' found >> 117 >> > > > >> plugins >> > > > >>>>> 2021-02-07 10:50:17,839 main DEBUG PluginManager 'Level' >> found 1 >> > > > >> plugins >> > > > >>>>> 2021-02-07 10:50:17,845 main DEBUG Building >> Plugin[name=property, >> > > > >>>> class=org.apache.logging.log4j.core.config.Property]. >> > > > >>>>> 2021-02-07 10:50:17,865 main TRACE TypeConverterRegistry >> > > initializing. >> > > > >>>>> 2021-02-07 10:50:17,865 main DEBUG PluginManager >> 'TypeConverter' >> > > found >> > > > >>>> 26 plugins >> > > > >>>>> 2021-02-07 10:50:17,873 main DEBUG createProperty(, >> > > > >>>> value="target/rolling-direct-1906") >> > > > >>>>> 2021-02-07 10:50:17,873 main DEBUG Building >> Plugin[name=properties, >> > > > >>>> class=org.apache.logging.log4j.core.config.PropertiesPlugin]. >> > > > >>>>> 2021-02-07 10:50:17,877 main DEBUG >> > > > >>>> configureSubstitutor(={baseDir=target/rolling-direct-1906}, >> > > > >>>> >> > > > >> >> > > >> Configuration(/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml)) >> > > > >>>>> 2021-02-07 10:50:17,877 main DEBUG PluginManager 'Lookup' >> found 16 >> > > > >>>> plugins >> > > > >>>>> 2021-02-07 10:50:17,878 main DEBUG Building >> Plugin[name=layout, >> > > > >>>> class=org.apache.logging.log4j.core.layout.PatternLayout]. >> > > > >>>>> 2021-02-07 10:50:17,881 main TRACE Using value >> > > %d{yyyy-MM-dd-HH-mm-ss} >> > > > >>>> [%level] [%c] %msg%n for option pattern >> > > > >>>>> 2021-02-07 10:50:17,882 main TRACE Using default value null >> for >> > > option >> > > > >>>> PatternSelector >> > > > >>>>> 2021-02-07 10:50:17,882 main TRACE Using value >> > > > >>>> >> > > > >> >> > > >> XmlConfiguration[location=/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml] >> > > > >>>> for option configuration >> > > > >>>>> 2021-02-07 10:50:17,882 main TRACE Using default value null >> for >> > > option >> > > > >>>> Replace >> > > > >>>>> 2021-02-07 10:50:17,882 main TRACE Using default value UTF-8 >> for >> > > option >> > > > >>>> charset >> > > > >>>>> 2021-02-07 10:50:17,883 main TRACE Using default value true >> for >> > > option >> > > > >>>> alwaysWriteExceptions >> > > > >>>>> 2021-02-07 10:50:17,883 main TRACE Using default value false >> for >> > > option >> > > > >>>> disableAnsi >> > > > >>>>> 2021-02-07 10:50:17,883 main TRACE Using default value false >> for >> > > option >> > > > >>>> noConsoleNoAnsi >> > > > >>>>> 2021-02-07 10:50:17,883 main TRACE Using default value null >> for >> > > option >> > > > >>>> header >> > > > >>>>> 2021-02-07 10:50:17,884 main TRACE Using default value null >> for >> > > option >> > > > >>>> footer >> > > > >>>>> 2021-02-07 10:50:17,884 main DEBUG >> > > > >>>> PatternLayout$Builder(pattern="%d{yyyy-MM-dd-HH-mm-ss} >> [%level] [%c] >> > > > >>>> %msg%n", PatternSelector=null, >> > > > >>>> >> > > > >> >> > > >> Configuration(/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml), >> > > > >>>> Replace=null, charset=null, alwaysWriteExceptions=null, >> > > > >> disableAnsi=null, >> > > > >>>> noConsoleNoAnsi=null, header=null, footer=null) >> > > > >>>>> 2021-02-07 10:50:17,884 main DEBUG PluginManager 'Converter' >> found >> > > 46 >> > > > >>>> plugins >> > > > >>>>> 2021-02-07 10:50:17,893 main DEBUG Building >> > > > >>>> Plugin[name=TimeBasedTriggeringPolicy, >> > > > >>>> >> > > > >> >> > > >> class=org.apache.logging.log4j.core.appender.rolling.TimeBasedTriggeringPolicy]. >> > > > >>>>> 2021-02-07 10:50:17,895 main TRACE Using default value 1 for >> option >> > > > >>>> interval >> > > > >>>>> 2021-02-07 10:50:17,895 main TRACE Using default value false >> for >> > > option >> > > > >>>> modulate >> > > > >>>>> 2021-02-07 10:50:17,895 main TRACE Using default value 0 for >> option >> > > > >>>> maxRandomDelay >> > > > >>>>> 2021-02-07 10:50:17,895 main DEBUG >> > > > >>>> TimeBasedTriggeringPolicy$Builder(interval=null, modulate=null, >> > > > >>>> maxRandomDelay=null) >> > > > >>>>> 2021-02-07 10:50:17,895 main DEBUG Building >> Plugin[name=Policies, >> > > > >>>> >> > > > >> >> > > >> class=org.apache.logging.log4j.core.appender.rolling.CompositeTriggeringPolicy]. >> > > > >>>>> 2021-02-07 10:50:17,896 main DEBUG >> > > > >>>> createPolicy(={TimeBasedTriggeringPolicy(nextRolloverMillis=0, >> > > > >> interval=1, >> > > > >>>> modulate=false)}) >> > > > >>>>> 2021-02-07 10:50:17,896 main DEBUG Building >> > > > >>>> Plugin[name=DirectWriteRolloverStrategy, >> > > > >>>> >> > > > >> >> > > >> class=org.apache.logging.log4j.core.appender.rolling.DirectWriteRolloverStrategy]. >> > > > >>>>> 2021-02-07 10:50:17,897 main TRACE Using default value null >> for >> > > option >> > > > >>>> maxFiles >> > > > >>>>> 2021-02-07 10:50:17,898 main TRACE Using default value null >> for >> > > option >> > > > >>>> compressionLevel >> > > > >>>>> 2021-02-07 10:50:17,898 main TRACE Using value [] for option >> > > Actions >> > > > >>>>> 2021-02-07 10:50:17,898 main TRACE Using default value true >> for >> > > option >> > > > >>>> stopCustomActionsOnError >> > > > >>>>> 2021-02-07 10:50:17,898 main TRACE Using default value null >> for >> > > option >> > > > >>>> tempCompressedFilePattern >> > > > >>>>> 2021-02-07 10:50:17,898 main TRACE Using value >> > > > >>>> >> > > > >> >> > > >> XmlConfiguration[location=/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml] >> > > > >>>> for option config >> > > > >>>>> 2021-02-07 10:50:17,898 main DEBUG >> > > > >>>> DirectWriteRolloverStrategy$Builder(maxFiles=null, >> > > > >> compressionLevel=null, >> > > > >>>> ={}, stopCustomActionsOnError=null, >> tempCompressedFilePattern=null, >> > > > >>>> >> > > > >> >> > > >> Configuration(/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml)) >> > > > >>>>> 2021-02-07 10:50:17,899 main DEBUG Building >> Plugin[name=appender, >> > > > >>>> >> class=org.apache.logging.log4j.core.appender.RollingFileAppender]. >> > > > >>>>> 2021-02-07 10:50:17,900 main TRACE Using default value null >> for >> > > option >> > > > >>>> fileName >> > > > >>>>> 2021-02-07 10:50:17,901 main TRACE Using value >> > > > >>>> >> target/rolling-direct-1906/rollingfile.%d{yyyy-MM-dd-HH-mm-ss}.log >> > > for >> > > > >>>> option filePattern >> > > > >>>>> 2021-02-07 10:50:17,901 main TRACE Using default value true >> for >> > > option >> > > > >>>> append >> > > > >>>>> 2021-02-07 10:50:17,901 main TRACE Using default value false >> for >> > > option >> > > > >>>> locking >> > > > >>>>> 2021-02-07 10:50:17,902 main TRACE Using value >> > > > >>>> >> > > > >> >> > > >> CompositeTriggeringPolicy(policies=[TimeBasedTriggeringPolicy(nextRolloverMillis=0, >> > > > >>>> interval=1, modulate=false)]) for option Policy >> > > > >>>>> 2021-02-07 10:50:17,902 main TRACE Using value >> > > > >>>> DirectWriteRolloverStrategy(maxFiles=2147483647) for option >> Strategy >> > > > >>>>> 2021-02-07 10:50:17,902 main TRACE Using default value false >> for >> > > option >> > > > >>>> advertise >> > > > >>>>> 2021-02-07 10:50:17,902 main TRACE Using default value null >> for >> > > option >> > > > >>>> advertiseUri >> > > > >>>>> 2021-02-07 10:50:17,902 main TRACE Using default value false >> for >> > > option >> > > > >>>> createOnDemand >> > > > >>>>> 2021-02-07 10:50:17,902 main TRACE Using default value null >> for >> > > option >> > > > >>>> filePermissions >> > > > >>>>> 2021-02-07 10:50:17,903 main TRACE Using default value null >> for >> > > option >> > > > >>>> fileOwner >> > > > >>>>> 2021-02-07 10:50:17,903 main TRACE Using default value null >> for >> > > option >> > > > >>>> fileGroup >> > > > >>>>> 2021-02-07 10:50:17,903 main TRACE Using default value true >> for >> > > option >> > > > >>>> bufferedIo >> > > > >>>>> 2021-02-07 10:50:17,903 main TRACE Using default value 8192 >> for >> > > option >> > > > >>>> bufferSize >> > > > >>>>> 2021-02-07 10:50:17,903 main TRACE Using default value true >> for >> > > option >> > > > >>>> immediateFlush >> > > > >>>>> 2021-02-07 10:50:17,904 main TRACE Using default value true >> for >> > > option >> > > > >>>> ignoreExceptions >> > > > >>>>> 2021-02-07 10:50:17,904 main TRACE Using value >> > > %d{yyyy-MM-dd-HH-mm-ss} >> > > > >>>> [%level] [%c] %msg%n for option Layout >> > > > >>>>> 2021-02-07 10:50:17,904 main TRACE Using value RollingFile for >> > > option >> > > > >>>> name >> > > > >>>>> 2021-02-07 10:50:17,905 main TRACE Using value >> > > > >>>> >> > > > >> >> > > >> XmlConfiguration[location=/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml] >> > > > >>>> for option configuration >> > > > >>>>> 2021-02-07 10:50:17,905 main TRACE Using default value null >> for >> > > option >> > > > >>>> Filter >> > > > >>>>> 2021-02-07 10:50:17,905 main TRACE Using value [] for option >> > > Properties >> > > > >>>>> 2021-02-07 10:50:17,905 main DEBUG >> > > > >>>> RollingFileAppender$Builder(fileName=null, >> > > > >>>> >> > > > >> >> > > >> filePattern="target/rolling-direct-1906/rollingfile.%d{yyyy-MM-dd-HH-mm-ss}.log", >> > > > >>>> append=null, locking=null, >> > > > >>>> >> > > > >> >> > > >> Policies(CompositeTriggeringPolicy(policies=[TimeBasedTriggeringPolicy(nextRolloverMillis=0, >> > > > >>>> interval=1, modulate=false)])), >> > > > >>>> >> > > > >> >> > > >> DirectWriteRolloverStrategy(DirectWriteRolloverStrategy(maxFiles=2147483647)), >> > > > >>>> advertise=null, advertiseUri=null, createOnDemand=null, >> > > > >>>> filePermissions=null, fileOwner=null, fileGroup=null, >> > > bufferedIo=null, >> > > > >>>> bufferSize=null, immediateFlush=null, ignoreExceptions=null, >> > > > >>>> PatternLayout(%d{yyyy-MM-dd-HH-mm-ss} [%level] [%c] %msg%n), >> > > > >>>> name="RollingFile", >> > > > >>>> >> > > > >> >> > > >> Configuration(/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml), >> > > > >>>> Filter=null, ={}) >> > > > >>>>> 2021-02-07 10:50:17,908 main DEBUG Starting RollingFileManager >> > > > >>>> >> target/rolling-direct-1906/rollingfile.%d{yyyy-MM-dd-HH-mm-ss}.log >> > > > >>>>> 2021-02-07 10:50:17,909 main DEBUG PluginManager >> 'FileConverter' >> > > found >> > > > >> 2 >> > > > >>>> plugins >> > > > >>>>> 2021-02-07 10:50:17,914 main DEBUG Setting prev file time to >> > > > >>>> 1969-12-31T17:00:00.000-0700 >> > > > >>>>> 2021-02-07 10:50:17,914 main DEBUG Initializing triggering >> policy >> > > > >>>> >> > > > >> >> > > >> CompositeTriggeringPolicy(policies=[TimeBasedTriggeringPolicy(nextRolloverMillis=0, >> > > > >>>> interval=1, modulate=false)]) >> > > > >>>>> 2021-02-07 10:50:17,914 main DEBUG Initializing triggering >> policy >> > > > >>>> TimeBasedTriggeringPolicy(nextRolloverMillis=0, interval=1, >> > > > >> modulate=false) >> > > > >>>>> 2021-02-07 10:50:17,916 main TRACE >> PatternProcessor.getNextTime >> > > > >>>> returning 2021/02/07-10:50:18.000, >> > > nextFileTime=2021/02/07-10:50:17.000, >> > > > >>>> prevFileTime=1969/12/31-17:00:00.000, >> > > current=2021/02/07-10:50:17.915, >> > > > >>>> freq=EVERY_SECOND >> > > > >>>>> 2021-02-07 10:50:17,917 main TRACE >> PatternProcessor.getNextTime >> > > > >>>> returning 2021/02/07-10:50:18.000, >> > > nextFileTime=2021/02/07-10:50:17.000, >> > > > >>>> prevFileTime=2021/02/07-10:50:17.000, >> > > current=2021/02/07-10:50:17.916, >> > > > >>>> freq=EVERY_SECOND >> > > > >>>>> 2021-02-07 10:50:17,917 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=0, >> prevFileTime=1612720217000, >> > > > >>>> nextFileTime=1612720217000 >> > > > >>>>> 2021-02-07 10:50:17,919 main TRACE Using default SystemClock >> for >> > > > >>>> timestamps. >> > > > >>>>> 2021-02-07 10:50:17,920 main DEBUG >> > > > >>>> org.apache.logging.log4j.core.time.internal.SystemClock does >> not >> > > support >> > > > >>>> precise timestamps. >> > > > >>>>> 2021-02-07 10:50:17,921 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=true, currentFileTime=0, >> prevFileTime=1612720217000, >> > > > >>>> nextFileTime=1612720217000 >> > > > >>>>> 2021-02-07 10:50:17,922 main DEBUG Building >> Plugin[name=appenders, >> > > > >>>> class=org.apache.logging.log4j.core.config.AppendersPlugin]. >> > > > >>>>> 2021-02-07 10:50:17,922 main DEBUG >> createAppenders(={RollingFile}) >> > > > >>>>> 2021-02-07 10:50:17,923 main DEBUG Building >> > > Plugin[name=AppenderRef, >> > > > >>>> class=org.apache.logging.log4j.core.config.AppenderRef]. >> > > > >>>>> 2021-02-07 10:50:17,924 main DEBUG >> createAppenderRef(filter=null, >> > > , ) >> > > > >>>>> 2021-02-07 10:50:17,924 main DEBUG Building Plugin[name=root, >> > > > >>>> >> class=org.apache.logging.log4j.core.config.LoggerConfig$RootLogger]. >> > > > >>>>> 2021-02-07 10:50:17,927 main DEBUG createLogger(, , , >> > > ={RollingFile}, >> > > > >>>> ={}, >> > > > >>>> >> > > > >> >> > > >> Configuration(/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml), >> > > > >>>> filter=null) >> > > > >>>>> 2021-02-07 10:50:17,928 main DEBUG Building >> Plugin[name=loggers, >> > > > >>>> class=org.apache.logging.log4j.core.config.LoggersPlugin]. >> > > > >>>>> 2021-02-07 10:50:17,929 main DEBUG createLoggers(={root}) >> > > > >>>>> 2021-02-07 10:50:17,931 main DEBUG Configuration >> > > > >>>> >> > > > >> >> > > >> XmlConfiguration[location=/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml] >> > > > >>>> initialized >> > > > >>>>> 2021-02-07 10:50:17,931 main DEBUG Starting configuration >> > > > >>>> >> > > > >> >> > > >> XmlConfiguration[location=/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml] >> > > > >>>>> 2021-02-07 10:50:17,932 main DEBUG Log4j2 >> ConfigurationScheduler >> > > > >>>> starting 1 threads >> > > > >>>>> 2021-02-07 10:50:17,932 main DEBUG Started configuration >> > > > >>>> >> > > > >> >> > > >> XmlConfiguration[location=/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml] >> > > > >>>> OK. >> > > > >>>>> 2021-02-07 10:50:17,933 main TRACE Stopping >> > > > >>>> >> org.apache.logging.log4j.core.config.DefaultConfiguration@400cff1a. >> > > .. >> > > > >>>>> 2021-02-07 10:50:17,933 main TRACE DefaultConfiguration >> notified 1 >> > > > >>>> ReliabilityStrategies that config will be stopped. >> > > > >>>>> 2021-02-07 10:50:17,933 main TRACE DefaultConfiguration >> stopping >> > > root >> > > > >>>> LoggerConfig. >> > > > >>>>> 2021-02-07 10:50:17,933 main TRACE DefaultConfiguration >> notifying >> > > > >>>> ReliabilityStrategies that appenders will be stopped. >> > > > >>>>> 2021-02-07 10:50:17,934 main TRACE DefaultConfiguration >> stopping >> > > > >>>> remaining Appenders. >> > > > >>>>> 2021-02-07 10:50:17,934 main DEBUG Shutting down >> > > OutputStreamManager >> > > > >>>> SYSTEM_OUT.false.false-1 >> > > > >>>>> 2021-02-07 10:50:17,934 main DEBUG OutputStream closed >> > > > >>>>> 2021-02-07 10:50:17,934 main DEBUG Shut down >> OutputStreamManager >> > > > >>>> SYSTEM_OUT.false.false-1, all resources released: true >> > > > >>>>> 2021-02-07 10:50:17,934 main DEBUG Appender DefaultConsole-1 >> > > stopped >> > > > >>>> with status true >> > > > >>>>> 2021-02-07 10:50:17,934 main TRACE DefaultConfiguration >> stopped 1 >> > > > >>>> remaining Appenders. >> > > > >>>>> 2021-02-07 10:50:17,934 main TRACE DefaultConfiguration >> cleaning >> > > > >>>> Appenders from 1 LoggerConfigs. >> > > > >>>>> 2021-02-07 10:50:17,934 main DEBUG Stopped >> > > > >>>> >> org.apache.logging.log4j.core.config.DefaultConfiguration@400cff1a >> > > OK >> > > > >>>>> 2021-02-07 10:50:17,989 main TRACE Reregistering MBeans after >> > > > >>>> reconfigure. >> > > > >>>> >> > > > >> >> > > >> Selector=org.apache.logging.log4j.core.selector.ClassLoaderContextSelector@65987993 >> > > > >>>>> 2021-02-07 10:50:17,990 main TRACE Reregistering context >> (1/1): >> > > > >>>> >> > > > >> >> > > >> 'testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test)' >> > > > >>>> org.apache.logging.log4j.core.LoggerContext@add0edd >> > > > >>>>> 2021-02-07 10:50:17,990 main TRACE Unregistering but no MBeans >> > > found >> > > > >>>> matching >> > > > >>>> >> > > > >> >> > > >> 'org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test)' >> > > > >>>>> 2021-02-07 10:50:17,990 main TRACE Unregistering but no MBeans >> > > found >> > > > >>>> matching >> > > > >>>> >> > > > >> >> > > >> 'org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test),component=StatusLogger' >> > > > >>>>> 2021-02-07 10:50:17,990 main TRACE Unregistering but no MBeans >> > > found >> > > > >>>> matching >> > > > >>>> >> > > > >> >> > > >> 'org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test),component=ContextSelector' >> > > > >>>>> 2021-02-07 10:50:17,990 main TRACE Unregistering but no MBeans >> > > found >> > > > >>>> matching >> > > > >>>> >> > > > >> >> > > >> 'org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test),component=Loggers,name=*' >> > > > >>>>> 2021-02-07 10:50:17,991 main TRACE Unregistering but no MBeans >> > > found >> > > > >>>> matching >> > > > >>>> >> > > > >> >> > > >> 'org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test),component=Appenders,name=*' >> > > > >>>>> 2021-02-07 10:50:17,991 main TRACE Unregistering but no MBeans >> > > found >> > > > >>>> matching >> > > > >>>> >> > > > >> >> > > >> 'org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test),component=AsyncAppenders,name=*' >> > > > >>>>> 2021-02-07 10:50:17,991 main TRACE Unregistering but no MBeans >> > > found >> > > > >>>> matching >> > > > >>>> >> > > > >> >> > > >> 'org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test),component=AsyncLoggerRingBuffer' >> > > > >>>>> 2021-02-07 10:50:17,991 main TRACE Unregistering but no MBeans >> > > found >> > > > >>>> matching >> > > > >>>> >> > > > >> >> > > >> 'org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test),component=Loggers,name=*,subtype=RingBuffer' >> > > > >>>>> 2021-02-07 10:50:17,992 main DEBUG Registering MBean >> > > > >>>> >> > > > >> >> > > >> org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test) >> > > > >>>>> 2021-02-07 10:50:17,993 main DEBUG Registering MBean >> > > > >>>> >> > > > >> >> > > >> org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test),component=StatusLogger >> > > > >>>>> 2021-02-07 10:50:17,994 main DEBUG Registering MBean >> > > > >>>> >> > > > >> >> > > >> org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test),component=ContextSelector >> > > > >>>>> 2021-02-07 10:50:17,995 main DEBUG Registering MBean >> > > > >>>> >> > > > >> >> > > >> org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test),component=Loggers,name= >> > > > >>>>> 2021-02-07 10:50:17,996 main DEBUG Registering MBean >> > > > >>>> >> > > > >> >> > > >> org.apache.logging.log4j2:type=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test),component=Appenders,name=RollingFile >> > > > >>>>> 2021-02-07 10:50:17,996 main TRACE Using DummyNanoClock for >> > > nanosecond >> > > > >>>> timestamps. >> > > > >>>>> 2021-02-07 10:50:17,996 main DEBUG >> > > > >>>> >> > > > >> >> > > >> LoggerContext[name=testAppender(org.apache.logging.log4j.core.appender.rolling.RollingAppenderDirectWrite1906Test), >> > > > >>>> org.apache.logging.log4j.core.LoggerContext@add0edd] started >> OK >> > > with >> > > > >>>> configuration >> > > > >>>> >> > > > >> >> > > >> XmlConfiguration[location=/Users/rgoers/projects/apache/logging/log4j/logging-log4j2/log4j-core/target/test-classes/log4j-rolling-direct-1906.xml]. >> > > > >>>>> 2021-02-07 10:50:18,000 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=0, >> prevFileTime=1612720217000, >> > > > >>>> nextFileTime=1612720217000 >> > > > >>>>> 2021-02-07 10:50:18,000 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=true, currentFileTime=0, >> prevFileTime=1612720217000, >> > > > >>>> nextFileTime=1612720217000 >> > > > >>>>> 2021-02-07 10:50:18,001 main DEBUG Now writing to >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-18.log >> at >> > > > >>>> 2021-02-07T10:50:18.001-0700 >> > > > >>>>> 2021-02-07 10:50:18,003 main DEBUG >> > > > >>>> AsyncLogger.ThreadNameStrategy=UNCACHED (user specified null, >> > > default is >> > > > >>>> UNCACHED) >> > > > >>>>> 2021-02-07 10:50:18,003 main TRACE Using default SystemClock >> for >> > > > >>>> timestamps. >> > > > >>>>> 2021-02-07 10:50:18,003 main DEBUG >> > > > >>>> org.apache.logging.log4j.core.time.internal.SystemClock does >> not >> > > support >> > > > >>>> precise timestamps. >> > > > >>>>> 2021-02-07 10:50:18,056 main TRACE >> PatternProcessor.getNextTime >> > > > >>>> returning 2021/02/07-10:50:19.000, >> > > nextFileTime=2021/02/07-10:50:18.000, >> > > > >>>> prevFileTime=2021/02/07-10:50:17.000, >> > > current=2021/02/07-10:50:18.056, >> > > > >>>> freq=EVERY_SECOND >> > > > >>>>> 2021-02-07 10:50:18,056 main DEBUG Rolling >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-18.log >> > > > >>>>> 2021-02-07 10:50:18,056 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=1612720218056, >> > > > >>>> prevFileTime=1612720217000, nextFileTime=1612720218000 >> > > > >>>>> 2021-02-07 10:50:18,057 main DEBUG Found 0 eligible files, >> max is >> > > > >>>> 2147483647 >> > > > >>>>> 2021-02-07 10:50:18,057 main TRACE >> > > DirectWriteRolloverStrategy.purge() >> > > > >>>> took 0.0 milliseconds >> > > > >>>>> 2021-02-07 10:50:18,058 main DEBUG OutputStream closed >> > > > >>>>> 2021-02-07 10:50:18,058 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=1612720218056, >> > > > >>>> prevFileTime=1612720217000, nextFileTime=1612720218000 >> > > > >>>>> 2021-02-07 10:50:18,058 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=true, currentFileTime=1612720218056, >> > > > >>>> prevFileTime=1612720217000, nextFileTime=1612720218000 >> > > > >>>>> 2021-02-07 10:50:18,058 main DEBUG Now writing to >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-18.log >> at >> > > > >>>> 2021-02-07T10:50:18.058-0700 >> > > > >>>>> 2021-02-07 10:50:19,009 main TRACE >> PatternProcessor.getNextTime >> > > > >>>> returning 2021/02/07-10:50:20.000, >> > > nextFileTime=2021/02/07-10:50:19.000, >> > > > >>>> prevFileTime=2021/02/07-10:50:18.000, >> > > current=2021/02/07-10:50:19.009, >> > > > >>>> freq=EVERY_SECOND >> > > > >>>>> 2021-02-07 10:50:19,009 main DEBUG Rolling >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-18.log >> > > > >>>>> 2021-02-07 10:50:19,010 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=1612720219009, >> > > > >>>> prevFileTime=1612720218000, nextFileTime=1612720219000 >> > > > >>>>> 2021-02-07 10:50:19,010 main DEBUG Found 0 eligible files, >> max is >> > > > >>>> 2147483647 >> > > > >>>>> 2021-02-07 10:50:19,010 main TRACE >> > > DirectWriteRolloverStrategy.purge() >> > > > >>>> took 0.0 milliseconds >> > > > >>>>> 2021-02-07 10:50:19,010 main DEBUG OutputStream closed >> > > > >>>>> 2021-02-07 10:50:19,011 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=1612720219009, >> > > > >>>> prevFileTime=1612720218000, nextFileTime=1612720219000 >> > > > >>>>> 2021-02-07 10:50:19,011 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=true, currentFileTime=1612720219009, >> > > > >>>> prevFileTime=1612720218000, nextFileTime=1612720219000 >> > > > >>>>> 2021-02-07 10:50:19,011 main DEBUG Now writing to >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-19.log >> at >> > > > >>>> 2021-02-07T10:50:19.011-0700 >> > > > >>>>> 2021-02-07 10:50:20,011 main TRACE >> PatternProcessor.getNextTime >> > > > >>>> returning 2021/02/07-10:50:21.000, >> > > nextFileTime=2021/02/07-10:50:20.000, >> > > > >>>> prevFileTime=2021/02/07-10:50:19.000, >> > > current=2021/02/07-10:50:20.011, >> > > > >>>> freq=EVERY_SECOND >> > > > >>>>> 2021-02-07 10:50:20,011 main DEBUG Rolling >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-19.log >> > > > >>>>> 2021-02-07 10:50:20,011 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=1612720220011, >> > > > >>>> prevFileTime=1612720219000, nextFileTime=1612720220000 >> > > > >>>>> 2021-02-07 10:50:20,012 main DEBUG Found 0 eligible files, >> max is >> > > > >>>> 2147483647 >> > > > >>>>> 2021-02-07 10:50:20,012 main TRACE >> > > DirectWriteRolloverStrategy.purge() >> > > > >>>> took 0.0 milliseconds >> > > > >>>>> 2021-02-07 10:50:20,012 main DEBUG OutputStream closed >> > > > >>>>> 2021-02-07 10:50:20,012 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=1612720220011, >> > > > >>>> prevFileTime=1612720219000, nextFileTime=1612720220000 >> > > > >>>>> 2021-02-07 10:50:20,013 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=true, currentFileTime=1612720220011, >> > > > >>>> prevFileTime=1612720219000, nextFileTime=1612720220000 >> > > > >>>>> 2021-02-07 10:50:20,013 main DEBUG Now writing to >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-20.log >> at >> > > > >>>> 2021-02-07T10:50:20.013-0700 >> > > > >>>>> 2021-02-07 10:50:21,021 main TRACE >> PatternProcessor.getNextTime >> > > > >>>> returning 2021/02/07-10:50:22.000, >> > > nextFileTime=2021/02/07-10:50:21.000, >> > > > >>>> prevFileTime=2021/02/07-10:50:20.000, >> > > current=2021/02/07-10:50:21.021, >> > > > >>>> freq=EVERY_SECOND >> > > > >>>>> 2021-02-07 10:50:21,021 main DEBUG Rolling >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-20.log >> > > > >>>>> 2021-02-07 10:50:21,021 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=1612720221021, >> > > > >>>> prevFileTime=1612720220000, nextFileTime=1612720221000 >> > > > >>>>> 2021-02-07 10:50:21,022 main DEBUG Found 0 eligible files, >> max is >> > > > >>>> 2147483647 >> > > > >>>>> 2021-02-07 10:50:21,022 main TRACE >> > > DirectWriteRolloverStrategy.purge() >> > > > >>>> took 0.0 milliseconds >> > > > >>>>> 2021-02-07 10:50:21,022 main DEBUG OutputStream closed >> > > > >>>>> 2021-02-07 10:50:21,022 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=1612720221021, >> > > > >>>> prevFileTime=1612720220000, nextFileTime=1612720221000 >> > > > >>>>> 2021-02-07 10:50:21,022 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=true, currentFileTime=1612720221021, >> > > > >>>> prevFileTime=1612720220000, nextFileTime=1612720221000 >> > > > >>>>> 2021-02-07 10:50:21,022 main DEBUG Now writing to >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-21.log >> at >> > > > >>>> 2021-02-07T10:50:21.022-0700 >> > > > >>>>> 2021-02-07 10:50:22,022 main TRACE >> PatternProcessor.getNextTime >> > > > >>>> returning 2021/02/07-10:50:23.000, >> > > nextFileTime=2021/02/07-10:50:22.000, >> > > > >>>> prevFileTime=2021/02/07-10:50:21.000, >> > > current=2021/02/07-10:50:22.022, >> > > > >>>> freq=EVERY_SECOND >> > > > >>>>> 2021-02-07 10:50:22,022 main DEBUG Rolling >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-21.log >> > > > >>>>> 2021-02-07 10:50:22,022 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=1612720222022, >> > > > >>>> prevFileTime=1612720221000, nextFileTime=1612720222000 >> > > > >>>>> 2021-02-07 10:50:22,022 main DEBUG Found 0 eligible files, >> max is >> > > > >>>> 2147483647 >> > > > >>>>> 2021-02-07 10:50:22,022 main TRACE >> > > DirectWriteRolloverStrategy.purge() >> > > > >>>> took 0.0 milliseconds >> > > > >>>>> 2021-02-07 10:50:22,023 main DEBUG OutputStream closed >> > > > >>>>> 2021-02-07 10:50:22,023 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=1612720222022, >> > > > >>>> prevFileTime=1612720221000, nextFileTime=1612720222000 >> > > > >>>>> 2021-02-07 10:50:22,023 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=true, currentFileTime=1612720222022, >> > > > >>>> prevFileTime=1612720221000, nextFileTime=1612720222000 >> > > > >>>>> 2021-02-07 10:50:22,023 main DEBUG Now writing to >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-22.log >> at >> > > > >>>> 2021-02-07T10:50:22.023-0700 >> > > > >>>>> 2021-02-07 10:50:23,033 main TRACE >> PatternProcessor.getNextTime >> > > > >>>> returning 2021/02/07-10:50:24.000, >> > > nextFileTime=2021/02/07-10:50:23.000, >> > > > >>>> prevFileTime=2021/02/07-10:50:22.000, >> > > current=2021/02/07-10:50:23.033, >> > > > >>>> freq=EVERY_SECOND >> > > > >>>>> 2021-02-07 10:50:23,033 main DEBUG Rolling >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-22.log >> > > > >>>>> 2021-02-07 10:50:23,033 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=1612720223033, >> > > > >>>> prevFileTime=1612720222000, nextFileTime=1612720223000 >> > > > >>>>> 2021-02-07 10:50:23,034 main DEBUG Found 0 eligible files, >> max is >> > > > >>>> 2147483647 >> > > > >>>>> 2021-02-07 10:50:23,034 main TRACE >> > > DirectWriteRolloverStrategy.purge() >> > > > >>>> took 0.0 milliseconds >> > > > >>>>> 2021-02-07 10:50:23,034 main DEBUG OutputStream closed >> > > > >>>>> 2021-02-07 10:50:23,034 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=false, currentFileTime=1612720223033, >> > > > >>>> prevFileTime=1612720222000, nextFileTime=1612720223000 >> > > > >>>>> 2021-02-07 10:50:23,034 main DEBUG Formatting file name. >> > > > >>>> useCurrentTime=true, currentFileTime=1612720223033, >> > > > >>>> prevFileTime=1612720222000, nextFileTime=1612720223000 >> > > > >>>>> 2021-02-07 10:50:23,035 main DEBUG Now writing to >> > > > >>>> target/rolling-direct-1906/rollingfile.2021-02-07-10-50-23.log >> at >> > > > >>>> 2021-02-07T10:50:23.034-0700 >> > > > >>>>> Incorrect file name. Expected: >> rollingfile.2021-02-07-10-50-17.log >> > > > >>>> Actual: rollingfile.2021-02-07-10-50-18.log >> > > > >>>> expected:<...e.2021-02-07-10-50-1[7].log> but >> > > > >>>> was:<...e.2021-02-07-10-50-1[8].log> >> > > > >>>>> >> > > > >>>>> Run 6 - failed in Kafka again >> > > > >>>>> [ERROR] Failures: >> > > > >>>>> [ERROR] ConfigurationBuilderTest.testXmlConstructing:116 >> > > > >>>> expected:<<?xml version="1.0" [?> >> > > > >>>>> ]<Configuration name=...> but was:<<?xml version="1.0" >> > > > >>>> [encoding="UTF-8"?>]<Configuration name=…> >> > > > >>>>> >> > > > >>>>> Ralph >> > > > >>>>> >> > > > >>>>> >> > > > >>>>> >> > > > >>>> >> > > > >> >> > > > >> >> > > > >> >> > > > >> > > > >> > > > >> > > >> > > >> >>
