Thank you, Volkan. I'm not quite ready to submit a PR. I was hoping some of you with more knowledge of log4j-core would weigh in on what we should do about shutting down the StatusLogger.
My thought is we choose one of two options: Option A: 1) check if any StatusLogger is writing to standard out or standard error. If not, add one. 2) stop any loggers that don't write to standard out or standard error. Option B: 1) stop any loggers that don't write to standard out or standard error. Option A could cause the log messages to be split across two destinations, but they all get sent somewhere. Option B could lose shutdown messages when writing to a file, but by that point it may not matter. If any of you have a better idea, I'm happy to implement it. If nobody weighs in on the best option, I'll probably submit Option A as a pull request on Friday or Saturday. Tim On Tue, Feb 23, 2021 at 1:00 PM Volkan Yazıcı <volkan.yaz...@gmail.com> wrote: > Great work Tim! I can't be happier finally somebody stepping up to fix > sporadic build failures on Windows due to open file related issues. Would > you mind creating a PR, please? (I haven't missed one, right?) This will > make it easier to review your changes and merge them. > > On Mon, Feb 22, 2021 at 8:19 PM Tim Perry <tim.v...@gmail.com> wrote: > > > I have a fork of log4j2 master that builds on windows here: > > https://github.com/perry2of5/logging-log4j2 > > > > For log4j-core, I close the StatusLogger using > > StatusLogger.getLogger().reset() to LoggerContext.stop(...). Now > > log4j2-core tests pass. (Usually). I doubt this is the best solution, but > > it shows that closing the logger does in fact allow the test to complete > > correctly. > > > > > https://github.com/perry2of5/logging-log4j2/commit/9f5b083956ca7e5de8e7acc3b2e7397cb770b186 > > > > For log4j-layout-template-json, I had to change the hard-coded port in > > JsonTemplateLayoutNullEventDelimiterTest in log4j-layout-template-json to > > get the tests to run. I don't know why, but changing the port to 35514 > > worked. > > > > > https://github.com/perry2of5/logging-log4j2/commit/5ca4fba8aaa1879d48619d1f23631ae81c37ec6d > > > > I had to update the expected XML in the Kafka ConfigurationBuilderTest to > > match what windows outputs. Obviously we need to make this conditional > > based on the OS it is running under... > > > > > https://github.com/perry2of5/logging-log4j2/commit/dec236a4d358b9847ad7710f668749241a1b50e5 > > > > On Fri, Feb 19, 2021 at 10:26 AM Tim Perry <tim.v...@gmail.com> wrote: > > > > > The simplest fix is to add "StatusLogger.getLogger().reset();" to the > > very > > > end of LoggerContext.stop(timeout, timeUnit). > > > > > > However, I'm not sure that is a great idea -- all status messages after > > > that point would be lost. > > > > > > Perhaps we want to have some logic that updates the LoggerContext to > have > > > one StatusConsoleListener writing to stdout or stderr and remove the > > rest. > > > If there is a StatusConsoleListener, which there always is with the > > current > > > code, check if it is writing to a file and is so mutate it's > destination > > to > > > stdout or stderr and close the file stream. Then remove any other > > > StatusListeners and it should cleanly shut down. The problem here is > that > > > now some of the status messages went to a log file and some went to > > > standard out. I'm not sure that is avoidable. > > > > > > > > > > > > > > > On Thu, Feb 18, 2021 at 7:57 PM Ralph Goers < > ralph.go...@dslextreme.com> > > > wrote: > > > > > >> This is a very good observation. When the status logger was > implemented > > >> it targeted System.out, which you obviously never want to close. > Shortly > > >> there after the ability to route it to a file instead was added. I > > guess we > > >> just never thought to add logic to close it at shutdown. > > >> > > >> Ralph > > >> > > >> > On Feb 18, 2021, at 7:01 PM, Tim Perry <tim.v...@gmail.com> wrote: > > >> > > > >> > It looks to me like LoggerContext.stop(...) closes the file > > 'test.log'. > > >> > However, I can't find anything closing 'status.log'. They are > > >> configured in > > >> > the same XML file: log4j-filetest.xml > > >> > > > >> > <Configuration status="debug" dest="target/status.log" > > >> > name="XMLConfigTest"> > > >> > <Properties> > > >> > <Property name="filename">target/test.log</Property> > > >> > </Properties> ...</Configuration> > > >> > </Configuration> > > >> > > > >> > I modified the @Test from FileOutputTest to see if it could delete > the > > >> log > > >> > files in the test. On windows, neither file gets deleted and in both > > >> delete > > >> > attempts I get an IOException with the message "The process cannot > > >> access > > >> > the file because it is being used by another process.". On Ubuntu, > no > > >> > exception is thrown even though the file is obviously open. See the > > code > > >> > below. > > >> > > > >> > From this I'm guessing that nothing closes status.log before the > > >> > FileCleaner goes to delete it and that it triggers an exception on > > >> Windows, > > >> > but not Linux. My guess is that the default file locking level is > > >> different > > >> > between JVM's or OS's. What should be releasing the file handle for > > >> > status.log? LoggerContext? > > >> > > > >> > > > >> > @Test > > >> > @LoggerContextSource("classpath:log4j-filetest.xml") > > >> > public void testConfig() throws IOException { > > >> > final Path logFile = Paths.get("target", "status.log"); > > >> > assertTrue(Files.exists(logFile), "Status output file does > not > > >> > exist"); > > >> > assertTrue(Files.size(logFile) > 0, "File is empty"); > > >> > > > >> > try { > > >> > Files.deleteIfExists(logFile); > > >> > fail("Should not have been able to delete " + logFile); > // > > >> this > > >> > is called on Ubuntu, but not Windows > > >> > } catch (IOException ioe) { > > >> > // this is called for Windows,but not Ubuntu > > >> > System.err.println("THIS SHOULD FAIL: Failed to delete " > + > > >> > logFile + ": " + ioe.getMessage()); > > >> > } > > >> > final Path testLog = Paths.get("target", "test.log"); > > >> > try { > > >> > Files.deleteIfExists(testLog); > > >> > fail("Should not have been able to delete " + testLog); > // > > >> this > > >> > presumably would be called for Ubuntu, but we failed above. > > >> > } catch (IOException ioe) { > > >> > // this is called for Windows,but not Ubuntu > > >> > System.err.println("THIS SHOULD FAIL: Failed to delete " > + > > >> > testLog + ": " + ioe.getMessage()); > > >> > } > > >> > } > > >> > > > >> > On Thu, Feb 18, 2021 at 8:48 AM Matt Sicker <boa...@gmail.com> > wrote: > > >> > > > >> >> The gist of what I recall the problem being was that sometimes, a > > file > > >> >> might still be in use asynchronously for various appenders (e.g., > > >> >> during rolling, compression, etc.), so the shutdown and removal of > > >> >> temporary files needs to signal that the configuration needs to > shut > > >> >> down. It looks like you may have found the missing link as to why > > this > > >> >> wasn't working properly. In that particular error message, that is > > >> >> some race condition where the temporary file is attempted to be > > >> >> deleted before the configuration stops. > > >> >> > > >> >> On Wed, 17 Feb 2021 at 18:19, Tim Perry <tim.v...@gmail.com> > wrote: > > >> >>> > > >> >>> 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 > > >> >>>>>>>>>>>>> > > >> >>>>>>>>>>>>> > > >> >>>>>>>>>>>>> > > >> >>>>>>>>>>>> > > >> >>>>>>>>>> > > >> >>>>>>>>>> > > >> >>>>>>>>>> > > >> >>>>>>>> > > >> >>>>>>>> > > >> >>>>>>>> > > >> >>>>>>> > > >> >>>>>>> > > >> >>>>> > > >> >>>>> > > >> >> > > >> > > >> > > >> > > >
