RE: Issue after moving to log4j 2.19
Hi Ralph, It's a tomcat related issue. If I execute my application with the latest version of 8.5 series (8.5.83), it does not work. Exactly the same using tomcat 8.5.39 works perfectly. Thanks, Joan. -Original Message- From: Ralph Goers Sent: Monday, October 17, 2022 5:28 PM To: Log4J Users List Subject: Re: Issue after moving to log4j 2.19 This indicates that for some reason Log4j 2 is now initializing earlier - before your system property is being set. Your solution gets the currently configured LoggerContext (presumably using the default configuration) and causes it to reconfigure using the new location. Ralph > On Oct 17, 2022, at 6:03 AM, Joan ventusproxy > wrote: > > Hello, > > Solved ... I don't exactly understand why ... but solved. > > I had to change my code in this way. Instead of: > System.setProperty("log4j.configurationFile", > "/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml"); > this.systemLog = LogManager.getLogger("LOGGER_SYSTEM"); > > Now is: > LoggerContext context = (LoggerContext) LogManager.getContext(false); > context.setConfigLocation("/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log > 4j.xml"); > > this.systemLog = context.getLogger("LOGGER_SYSTEM"); > > > Thanks, > > Joan. > > -Original Message- > From: Joan ventusproxy > Sent: Monday, October 17, 2022 1:47 PM > To: 'Log4J Users List' > Subject: RE: Issue after moving to log4j 2.19 > > Hello, > > Investigating a little more ... > > If I set the variable > -Dlog4j.configurationFile=/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml > on the tomcat startup script, it works. > > But setting this on my application, as we always did, it does not work any > more: > System.setProperty("log4j.configurationFile", > "/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml"); > > The point is this is a simplified example, building this path is much more > complicated and it must be done at application level, not tomcat level. > > By the way, our web.xml contains this: > > >isLog4jContextSelectorNamed >true > > > >log4jContextName >ventusproxy > > > Thanks, > > Joan. > > > -Original Message- > From: Joan ventusproxy > Sent: Sunday, October 16, 2022 9:03 PM > To: 'Log4J Users List' > Subject: RE: Issue after moving to log4j 2.19 > > Is not this? (second gist): > > DEBUG StatusLogger Watching configuration > '/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml' for lastModified > Sat Oct 15 21:55:38 UTC 2022 (1665870938000) DEBUG StatusLogger Apache > Log4j Core 2.19.0 initializing configuration > XmlConfiguration[location=/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4 > j.xml] > > Joan. > > -Original Message- > From: Ralph Goers > Sent: Sunday, October 16, 2022 2:44 AM > To: Log4J Users List > Subject: Re: Issue after moving to log4j 2.19 > > In both of those log files Log4j is not seeing any value as being set of > log4j.configurationFile. It is ending up using the default configuration. > > Ralph > >> On Oct 15, 2022, at 3:45 PM, Joan ventusproxy >> wrote: >> >> Hi Piotr, >> >> Thanks for your quick response. >> >> Below two gists with the traces for both cases: >> >> 1. Using "this.systemLog = LogManager.getLogger("LOGGER_SYSTEM");": >> https://gist.githubusercontent.com/joanbalaguero/a59fb664774c44535c10 >> 8 >> 17900a80ed5/raw/8bb6b6a963a607f0d99105248ce32a28ad39590a/gistfile1.tx >> t >> >> In this case logs are not created. >> >> >> 2. Using "this.systemLog = >> LogManager.getContext().getLogger("LOGGER_SYSTEM");": >> https://gist.githubusercontent.com/joanbalaguero/acd0a4edaf856ad34c44 >> a >> 196caef7bdc/raw/474febc0397b97a9b941dbd86b830149ac94ad07/gistfile1.tx >> t >> >> In this case logs are created and content is logged into them correctly, but >> the hazelcast log (from "com.hazelcast") is not sent to the SYSTEM_LOG. >> >> >> The " log4j.configurationFile " variable is set in this way: >> System.setProperty("log4j.configurationFile", >> "/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml"); >> >> And tomcat starts with: >> -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLogge >> r >> ContextSelector >> >> >> The point is that for years we have been running this without issues using >> point 1, without getting the context from the L
RE: Issue after moving to log4j 2.19
Hello, Solved ... I don't exactly understand why ... but solved. I had to change my code in this way. Instead of: System.setProperty("log4j.configurationFile", "/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml"); this.systemLog = LogManager.getLogger("LOGGER_SYSTEM"); Now is: LoggerContext context = (LoggerContext) LogManager.getContext(false); context.setConfigLocation("/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml"); this.systemLog = context.getLogger("LOGGER_SYSTEM"); Thanks, Joan. -Original Message- From: Joan ventusproxy Sent: Monday, October 17, 2022 1:47 PM To: 'Log4J Users List' Subject: RE: Issue after moving to log4j 2.19 Hello, Investigating a little more ... If I set the variable -Dlog4j.configurationFile=/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml on the tomcat startup script, it works. But setting this on my application, as we always did, it does not work any more: System.setProperty("log4j.configurationFile", "/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml"); The point is this is a simplified example, building this path is much more complicated and it must be done at application level, not tomcat level. By the way, our web.xml contains this: isLog4jContextSelectorNamed true log4jContextName ventusproxy Thanks, Joan. -Original Message- From: Joan ventusproxy Sent: Sunday, October 16, 2022 9:03 PM To: 'Log4J Users List' Subject: RE: Issue after moving to log4j 2.19 Is not this? (second gist): DEBUG StatusLogger Watching configuration '/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml' for lastModified Sat Oct 15 21:55:38 UTC 2022 (1665870938000) DEBUG StatusLogger Apache Log4j Core 2.19.0 initializing configuration XmlConfiguration[location=/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml] Joan. -Original Message- From: Ralph Goers Sent: Sunday, October 16, 2022 2:44 AM To: Log4J Users List Subject: Re: Issue after moving to log4j 2.19 In both of those log files Log4j is not seeing any value as being set of log4j.configurationFile. It is ending up using the default configuration. Ralph > On Oct 15, 2022, at 3:45 PM, Joan ventusproxy > wrote: > > Hi Piotr, > > Thanks for your quick response. > > Below two gists with the traces for both cases: > > 1. Using "this.systemLog = LogManager.getLogger("LOGGER_SYSTEM");": > https://gist.githubusercontent.com/joanbalaguero/a59fb664774c44535c108 > 17900a80ed5/raw/8bb6b6a963a607f0d99105248ce32a28ad39590a/gistfile1.txt > > In this case logs are not created. > > > 2. Using "this.systemLog = > LogManager.getContext().getLogger("LOGGER_SYSTEM");": > https://gist.githubusercontent.com/joanbalaguero/acd0a4edaf856ad34c44a > 196caef7bdc/raw/474febc0397b97a9b941dbd86b830149ac94ad07/gistfile1.txt > > In this case logs are created and content is logged into them correctly, but > the hazelcast log (from "com.hazelcast") is not sent to the SYSTEM_LOG. > > > The " log4j.configurationFile " variable is set in this way: > System.setProperty("log4j.configurationFile", > "/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml"); > > And tomcat starts with: > -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLogger > ContextSelector > > > The point is that for years we have been running this without issues using > point 1, without getting the context from the LogManager. > > One more clue. As I said, this is not working fine on our new installation > with Centos9 Stream, Apache Tomcat 8.5.83 and Zing JVM 11. Exactly the same > code running locally on a windows 10 with Apache Tomcat 8.5.39 and Oracle jdk > 11 works perfectly, logs are created and the hazelcast logging is sent to the > SYSTEM_LOG. > > > Thanks, > > Joan. > > -Original Message- > From: Piotr P. Karwasz > Sent: Friday, October 14, 2022 5:23 PM > To: Log4J Users List > Subject: Re: Issue after moving to log4j 2.19 > > Hi Joan, > >> After making a lot of tests trying to get this working again, we had to >> change the line below: >> >> this.systemLog = LogManager.getLogger("LOGGER_SYSTEM"); >> >> >> >> By this: >> >> this.systemLog = LogManager.getContext().getLogger("LOGGER_SYSTEM"); > > This looks like a `LoggerContextSelector` problem: > https://logging.apache.org/log4j/2.x/manual/extending.html#ContextSele > ctor > > `LogManager.getContext()` should not be used, because it gives you the wrong > logger context most of the time. > The automatic configuration uses `LogManager.getContext(false)` to retrieve > the right logger
RE: Issue after moving to log4j 2.19
Hello, Investigating a little more ... If I set the variable -Dlog4j.configurationFile=/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml on the tomcat startup script, it works. But setting this on my application, as we always did, it does not work any more: System.setProperty("log4j.configurationFile", "/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml"); The point is this is a simplified example, building this path is much more complicated and it must be done at application level, not tomcat level. By the way, our web.xml contains this: isLog4jContextSelectorNamed true log4jContextName ventusproxy Thanks, Joan. -Original Message- From: Joan ventusproxy Sent: Sunday, October 16, 2022 9:03 PM To: 'Log4J Users List' Subject: RE: Issue after moving to log4j 2.19 Is not this? (second gist): DEBUG StatusLogger Watching configuration '/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml' for lastModified Sat Oct 15 21:55:38 UTC 2022 (1665870938000) DEBUG StatusLogger Apache Log4j Core 2.19.0 initializing configuration XmlConfiguration[location=/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml] Joan. -Original Message- From: Ralph Goers Sent: Sunday, October 16, 2022 2:44 AM To: Log4J Users List Subject: Re: Issue after moving to log4j 2.19 In both of those log files Log4j is not seeing any value as being set of log4j.configurationFile. It is ending up using the default configuration. Ralph > On Oct 15, 2022, at 3:45 PM, Joan ventusproxy > wrote: > > Hi Piotr, > > Thanks for your quick response. > > Below two gists with the traces for both cases: > > 1. Using "this.systemLog = LogManager.getLogger("LOGGER_SYSTEM");": > https://gist.githubusercontent.com/joanbalaguero/a59fb664774c44535c108 > 17900a80ed5/raw/8bb6b6a963a607f0d99105248ce32a28ad39590a/gistfile1.txt > > In this case logs are not created. > > > 2. Using "this.systemLog = > LogManager.getContext().getLogger("LOGGER_SYSTEM");": > https://gist.githubusercontent.com/joanbalaguero/acd0a4edaf856ad34c44a > 196caef7bdc/raw/474febc0397b97a9b941dbd86b830149ac94ad07/gistfile1.txt > > In this case logs are created and content is logged into them correctly, but > the hazelcast log (from "com.hazelcast") is not sent to the SYSTEM_LOG. > > > The " log4j.configurationFile " variable is set in this way: > System.setProperty("log4j.configurationFile", > "/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml"); > > And tomcat starts with: > -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLogger > ContextSelector > > > The point is that for years we have been running this without issues using > point 1, without getting the context from the LogManager. > > One more clue. As I said, this is not working fine on our new installation > with Centos9 Stream, Apache Tomcat 8.5.83 and Zing JVM 11. Exactly the same > code running locally on a windows 10 with Apache Tomcat 8.5.39 and Oracle jdk > 11 works perfectly, logs are created and the hazelcast logging is sent to the > SYSTEM_LOG. > > > Thanks, > > Joan. > > -Original Message- > From: Piotr P. Karwasz > Sent: Friday, October 14, 2022 5:23 PM > To: Log4J Users List > Subject: Re: Issue after moving to log4j 2.19 > > Hi Joan, > >> After making a lot of tests trying to get this working again, we had to >> change the line below: >> >> this.systemLog = LogManager.getLogger("LOGGER_SYSTEM"); >> >> >> >> By this: >> >> this.systemLog = LogManager.getContext().getLogger("LOGGER_SYSTEM"); > > This looks like a `LoggerContextSelector` problem: > https://logging.apache.org/log4j/2.x/manual/extending.html#ContextSele > ctor > > `LogManager.getContext()` should not be used, because it gives you the wrong > logger context most of the time. > The automatic configuration uses `LogManager.getContext(false)` to retrieve > the right logger context. > > Can you run your application with `-Dlog4j2.debug=true` and share the output? > > Piotr > > - > To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org > For additional commands, e-mail: log4j-user-h...@logging.apache.org > > > > > - > To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org > For additional commands, e-mail: log4j-user-h...@logging.apache.org > - To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org For additional commands, e-mail: log4j-user-h...@logging.apache.org - To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org For additional commands, e-mail: log4j-user-h...@logging.apache.org
RE: Issue after moving to log4j 2.19
Is not this? (second gist): DEBUG StatusLogger Watching configuration '/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml' for lastModified Sat Oct 15 21:55:38 UTC 2022 (1665870938000) DEBUG StatusLogger Apache Log4j Core 2.19.0 initializing configuration XmlConfiguration[location=/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml] Joan. -Original Message- From: Ralph Goers Sent: Sunday, October 16, 2022 2:44 AM To: Log4J Users List Subject: Re: Issue after moving to log4j 2.19 In both of those log files Log4j is not seeing any value as being set of log4j.configurationFile. It is ending up using the default configuration. Ralph > On Oct 15, 2022, at 3:45 PM, Joan ventusproxy > wrote: > > Hi Piotr, > > Thanks for your quick response. > > Below two gists with the traces for both cases: > > 1. Using "this.systemLog = LogManager.getLogger("LOGGER_SYSTEM");": > https://gist.githubusercontent.com/joanbalaguero/a59fb664774c44535c10817900a80ed5/raw/8bb6b6a963a607f0d99105248ce32a28ad39590a/gistfile1.txt > > In this case logs are not created. > > > 2. Using "this.systemLog = > LogManager.getContext().getLogger("LOGGER_SYSTEM");": > https://gist.githubusercontent.com/joanbalaguero/acd0a4edaf856ad34c44a196caef7bdc/raw/474febc0397b97a9b941dbd86b830149ac94ad07/gistfile1.txt > > In this case logs are created and content is logged into them correctly, but > the hazelcast log (from "com.hazelcast") is not sent to the SYSTEM_LOG. > > > The " log4j.configurationFile " variable is set in this way: > System.setProperty("log4j.configurationFile", > "/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml"); > > And tomcat starts with: > -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector > > > The point is that for years we have been running this without issues using > point 1, without getting the context from the LogManager. > > One more clue. As I said, this is not working fine on our new installation > with Centos9 Stream, Apache Tomcat 8.5.83 and Zing JVM 11. Exactly the same > code running locally on a windows 10 with Apache Tomcat 8.5.39 and Oracle jdk > 11 works perfectly, logs are created and the hazelcast logging is sent to the > SYSTEM_LOG. > > > Thanks, > > Joan. > > -Original Message- > From: Piotr P. Karwasz > Sent: Friday, October 14, 2022 5:23 PM > To: Log4J Users List > Subject: Re: Issue after moving to log4j 2.19 > > Hi Joan, > >> After making a lot of tests trying to get this working again, we had to >> change the line below: >> >> this.systemLog = LogManager.getLogger("LOGGER_SYSTEM"); >> >> >> >> By this: >> >> this.systemLog = LogManager.getContext().getLogger("LOGGER_SYSTEM"); > > This looks like a `LoggerContextSelector` problem: > https://logging.apache.org/log4j/2.x/manual/extending.html#ContextSelector > > `LogManager.getContext()` should not be used, because it gives you the wrong > logger context most of the time. > The automatic configuration uses `LogManager.getContext(false)` to retrieve > the right logger context. > > Can you run your application with `-Dlog4j2.debug=true` and share the output? > > Piotr > > - > To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org > For additional commands, e-mail: log4j-user-h...@logging.apache.org > > > > > - > To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org > For additional commands, e-mail: log4j-user-h...@logging.apache.org > - To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org For additional commands, e-mail: log4j-user-h...@logging.apache.org - To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org For additional commands, e-mail: log4j-user-h...@logging.apache.org
RE: Issue after moving to log4j 2.19
Hi Piotr, Thanks for your quick response. Below two gists with the traces for both cases: 1. Using "this.systemLog = LogManager.getLogger("LOGGER_SYSTEM");": https://gist.githubusercontent.com/joanbalaguero/a59fb664774c44535c10817900a80ed5/raw/8bb6b6a963a607f0d99105248ce32a28ad39590a/gistfile1.txt In this case logs are not created. 2. Using "this.systemLog = LogManager.getContext().getLogger("LOGGER_SYSTEM");": https://gist.githubusercontent.com/joanbalaguero/acd0a4edaf856ad34c44a196caef7bdc/raw/474febc0397b97a9b941dbd86b830149ac94ad07/gistfile1.txt In this case logs are created and content is logged into them correctly, but the hazelcast log (from "com.hazelcast") is not sent to the SYSTEM_LOG. The " log4j.configurationFile " variable is set in this way: System.setProperty("log4j.configurationFile", "/opt/ventusproxy/app/proxy/ROOT/WEB-INF/log4j.xml"); And tomcat starts with: -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector The point is that for years we have been running this without issues using point 1, without getting the context from the LogManager. One more clue. As I said, this is not working fine on our new installation with Centos9 Stream, Apache Tomcat 8.5.83 and Zing JVM 11. Exactly the same code running locally on a windows 10 with Apache Tomcat 8.5.39 and Oracle jdk 11 works perfectly, logs are created and the hazelcast logging is sent to the SYSTEM_LOG. Thanks, Joan. -Original Message- From: Piotr P. Karwasz Sent: Friday, October 14, 2022 5:23 PM To: Log4J Users List Subject: Re: Issue after moving to log4j 2.19 Hi Joan, > After making a lot of tests trying to get this working again, we had to > change the line below: > > this.systemLog = LogManager.getLogger("LOGGER_SYSTEM"); > > > > By this: > > this.systemLog = LogManager.getContext().getLogger("LOGGER_SYSTEM"); This looks like a `LoggerContextSelector` problem: https://logging.apache.org/log4j/2.x/manual/extending.html#ContextSelector `LogManager.getContext()` should not be used, because it gives you the wrong logger context most of the time. The automatic configuration uses `LogManager.getContext(false)` to retrieve the right logger context. Can you run your application with `-Dlog4j2.debug=true` and share the output? Piotr - To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org For additional commands, e-mail: log4j-user-h...@logging.apache.org - To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org For additional commands, e-mail: log4j-user-h...@logging.apache.org
Issue after moving to log4j 2.19
Hello, � We have moved to log4j 2.19.0 from log4j 2.17.2. Our environment is Centos9 stream with tomcat 8.5.83 and jdk11. After doing that, logging has stopped working (the code related to log4j2 has not been changed for years) � All our loggers are asynchronous by adding: -DLog4jContextSelector=org.apache.logging.log4j.core.async.AsyncLoggerContextSelector � The piece of log4j.xml: � %d{-MM-dd HH:mm:ss}\t%m%n � � � Adding this before log creation: System.setProperty("log4j2.debug", "true"); � We only got this when we printed the variable that should contain the system logger: LOGGER_SYSTEM:ERROR in AsyncContext@587d32cc � After making a lot of tests trying to get this working again, we had to change the line below: this.systemLog = LogManager.getLogger("LOGGER_SYSTEM"); � By this: this.systemLog = LogManager.getContext().getLogger("LOGGER_SYSTEM"); � And now it is almost working again, because the hazelcast log is not sent to the system logger yet. So our questions are: � 1. Why must we get the logger from the context now? What has changed? 2. What should we do to get the hazelcast logging working again, so send it to the system logger correctly. � � Thanks, � Joan.
Get timestamp from logged line
Hello, � I’m using the following pattern to log lines: %m%d{-MM-dd HH:mm:ss.SSS}%n � And writing the line with: this.accessLog.info(variable) � I was wondering if there is any chance to get the timestamp printed in the line (%d{-MM-dd HH:mm:ss.SSS}) after writing it to the file with the ‘info’ method. � Thanks, � Joan.
RE: Wrong extensions when rotating files using RollingRandomAccessFile with CronTriggeringPolicy
Hi Ralph, Is this a bug definitely? Do you want I open an issue? Thanks, Joan. -Original Message- From: Joan ventusproxy Sent: Tuesday, February 11, 2020 7:36 PM To: 'Log4J Users List' Subject: RE: Wrong extensions when rotating files using RollingRandomAccessFile with CronTriggeringPolicy Hi Ralph, Similar with 2.13.0 I'd say: 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-11 DEBUG Setting prev file time to 2020-02-05T00:00:01.000+0100 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-8 DEBUG Setting prev file time to 2020-02-05T00:00:01.000+0100 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-12 DEBUG Setting prev file time to 2020-02-05T00:00:01.000+0100 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-10 DEBUG Setting prev file time to 2020-02-05T00:00:01.000+0100 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-9 DEBUG Setting prev file time to 2020-02-05T00:00:01.000+0100 2020-02-06 00:00:01,006 Log4j2-TF-13-Scheduled-12 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,006 Log4j2-TF-13-Scheduled-9 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,006 Log4j2-TF-13-Scheduled-11 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,006 Log4j2-TF-13-Scheduled-10 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,006 Log4j2-TF-13-Scheduled-8 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,009 Log4j2-TF-13-Scheduled-8 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,009 Log4j2-TF-13-Scheduled-12 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,009 Log4j2-TF-13-Scheduled-9 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,009 Log4j2-TF-13-Scheduled-11 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,009 Log4j2-TF-13-Scheduled-10 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,011 Log4j2-TF-13-Scheduled-11 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/vproxy_datametrycs to /home/ventusproxy/logs/vproxy_datametrycs.2020-02-05, renameEmptyFiles=false] 2020-02-06 00:00:01,011 Log4j2-TF-13-Scheduled-12 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/http.log to /home/ventusproxy/logs/http.2020-02-05, renameEmptyFiles=false] 2020-02-06 00:00:01,011 Log4j2-TF-13-Scheduled-9 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/vproxy_system to /home/ventusproxy/logs/vproxy_system.2020-02-05, renameEmptyFiles=false] 2020-02-06 00:00:01,011 Log4j2-TF-13-Scheduled-8 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/vproxy_cluster to /home/ventusproxy/logs/vproxy_cluster.2020-02-05, renameEmptyFiles=false] 2020-02-06 00:00:01,011 Log4j2-TF-13-Scheduled-10 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/vproxy_monitor to /home/ventusproxy/logs/vproxy_monitor.2020-02-05, renameEmptyFiles=false] 2020-02-06 00:00:01,011 Log4j2-TF-13-Scheduled-8 DEBUG Now writing to /home/ventusproxy/logs/vproxy_cluster at 2020-02-06T00:00:01.011+0100 2020-02-06 00:00:01,011 Log4j2-TF-13-Scheduled-10 DEBUG Now writing to /home/ventusproxy/logs/vproxy_monitor at 2020-02-06T00:00:01.011+0100 2020-02-06 00:00:01,011 Log4j2-TF-13-Scheduled-12 DEBUG Now writing to /home/ventusproxy/logs/http.log at 2020-02-06T00:00:01.011+0100 2020-02-06 00:00:01,012 Log4j2-TF-13-Scheduled-12 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 2020-02-06 00:00:01,012 Log4j2-TF-13-Scheduled-8 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 2020-02-06 00:00:01,012 Log4j2-TF-13-Scheduled-10 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 2020-02-06 00:00:01,012 Log4j2-TF-13-Scheduled-12 DEBUG Setting prev file time to 2020-02-06T00:00:01.000+0100 2020-02-06 00:00:01,012 Log4j2-TF-13-Scheduled-8 DEBUG Setting prev file time to 2020-02-06T00:00:01.000+0100 2020-02-06 00:00:01,012 Log4j2-TF-13-Scheduled-12 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580943601000 2020-02-06 00:00:01,012 Log4j2-TF-13
RE: Wrong extensions when rotating files using RollingRandomAccessFile with CronTriggeringPolicy
-Scheduled-8 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580943601000 2020-02-06 00:00:01,013 Log4j2-TF-13-Scheduled-12 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/vproxy_error to /home/ventusproxy/logs/vproxy_error.2020-02-06, renameEmptyFiles=false] 2020-02-06 00:00:01,013 Log4j2-TF-13-Scheduled-8 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/vproxy_access to /home/ventusproxy/logs/vproxy_access.2020-02-06, renameEmptyFiles=false] 2020-02-06 00:00:01,013 Log4j2-TF-13-Scheduled-9 DEBUG Now writing to /home/ventusproxy/logs/vproxy_system at 2020-02-06T00:00:01.013+0100 2020-02-06 00:00:01,013 Log4j2-TF-13-Scheduled-11 DEBUG Now writing to /home/ventusproxy/logs/vproxy_datametrycs at 2020-02-06T00:00:01.013+0100 2020-02-06 00:00:01,013 Log4j2-TF-13-Scheduled-12 DEBUG Now writing to /home/ventusproxy/logs/vproxy_error at 2020-02-06T00:00:01.013+0100 2020-02-06 00:00:01,013 Log4j2-TF-13-Scheduled-8 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 2020-02-06 00:00:01,013 Log4j2-TF-13-Scheduled-9 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 2020-02-06 00:00:01,013 Log4j2-TF-13-Scheduled-11 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 2020-02-06 00:00:01,013 Log4j2-TF-13-Scheduled-12 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 And logs: -rw-r-. 1 rootroot3725082 Feb 6 00:01 vproxy_access -rw-r-. 1 rootroot 795226 Feb 6 00:00 vproxy_access.2020-02-06 -rw-r-. 1 rootroot 0 Feb 6 00:00 vproxy_cluster -rw-r-. 1 rootroot 0 Feb 6 00:00 vproxy_datametrycs -rw-r-. 1 rootroot771 Feb 6 00:00 vproxy_datametrycs.2020-02-05 -rw-r-. 1 rootroot 40514 Feb 6 00:01 vproxy_error -rw-r-. 1 rootroot 12463 Feb 5 23:59 vproxy_error.2020-02-06 -rw-r-. 1 rootroot 0 Feb 6 00:00 vproxy_monitor -rw-r-. 1 rootroot 2640 Feb 6 00:00 vproxy_system -rw-r-. 1 rootroot 15865 Feb 5 23:59 vproxy_system.2020-02-05 Regards, Joan. -Original Message- From: Ralph Goers Sent: Tuesday, February 11, 2020 7:18 PM To: Log4J Users List Subject: Re: Wrong extensions when rotating files using RollingRandomAccessFile with CronTriggeringPolicy Joan, I apologize but I have only had time to glance at the log. It doesn’t look correct. Is it possible you could test with 2.13.0 just to rule out that it might have already been fixed? Ralph > On Feb 11, 2020, at 9:30 AM, Joan ventusproxy > wrote: > > Hi Ralph, > > Do you think this is a bug or a misconfiguration on my side? > > Thanks, > > Joan. > > -----Original Message- > From: Joan ventusproxy > Sent: Thursday, February 6, 2020 6:21 PM > To: 'Log4J Users List' > Subject: RE: Wrong extensions when rotating files using > RollingRandomAccessFile with CronTriggeringPolicy > > Hi Ralph, > > Log4j version is 2.11.2. Below the output requested: > > 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-12 DEBUG Setting prev file > time to 2020-02-05T00:00:01.000+0100 > 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-10 DEBUG Setting prev file > time to 2020-02-05T00:00:01.000+0100 > 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-9 DEBUG Setting prev file time > to 2020-02-05T00:00:01.000+0100 > 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-8 DEBUG Setting prev file time > to 2020-02-05T00:00:01.000+0100 > 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-11 DEBUG Setting prev file > time to 2020-02-05T00:00:01.000+0100 > 2020-02-06 00:00:01,037 Log4j2-TF-13-Scheduled-8 DEBUG Formatting file name. > useCurrentTime=false. currentFileTime=1580857201000, > prevFileTime=1580857201000 > 2020-02-06 00:00:01,037 Log4j2-TF-13-Scheduled-12 DEBUG Formatting file name. > useCurrentTime=false. currentFileTime=1580857201000, > prevFileTime=1580857201000 > 2020-02-06 00:00:01,037 Log4j2-TF-13-Scheduled-10 DEBUG Formatting file name. > useCurrentTime=false. currentFileTime=1580857201000, > prevFileTime=1580857201000 > 2020-02-06 00:00:01,037 Log4j2-TF-13-Scheduled-9 DEBUG Formatting file name. > useCurrentTime=false. currentFileTime=1580857201000, > prevFileTime=1580857201000 > 2020-02-06 00:00:01,037 Log4j2-TF-13-Scheduled-11 DEBUG Formatting file name. > useCurrentTime=false. currentFileTime=1580857201000, > prevFileTime=1580857201000 > 2020-02-06 00:00:01,040 Log4j2-TF-13-Schedul
RE: Wrong extensions when rotating files using RollingRandomAccessFile with CronTriggeringPolicy
Hi Ralph, Do you think this is a bug or a misconfiguration on my side? Thanks, Joan. -Original Message- From: Joan ventusproxy Sent: Thursday, February 6, 2020 6:21 PM To: 'Log4J Users List' Subject: RE: Wrong extensions when rotating files using RollingRandomAccessFile with CronTriggeringPolicy Hi Ralph, Log4j version is 2.11.2. Below the output requested: 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-12 DEBUG Setting prev file time to 2020-02-05T00:00:01.000+0100 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-10 DEBUG Setting prev file time to 2020-02-05T00:00:01.000+0100 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-9 DEBUG Setting prev file time to 2020-02-05T00:00:01.000+0100 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-8 DEBUG Setting prev file time to 2020-02-05T00:00:01.000+0100 2020-02-06 00:00:01,001 Log4j2-TF-13-Scheduled-11 DEBUG Setting prev file time to 2020-02-05T00:00:01.000+0100 2020-02-06 00:00:01,037 Log4j2-TF-13-Scheduled-8 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,037 Log4j2-TF-13-Scheduled-12 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,037 Log4j2-TF-13-Scheduled-10 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,037 Log4j2-TF-13-Scheduled-9 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,037 Log4j2-TF-13-Scheduled-11 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,040 Log4j2-TF-13-Scheduled-8 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,040 Log4j2-TF-13-Scheduled-11 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,040 Log4j2-TF-13-Scheduled-10 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,040 Log4j2-TF-13-Scheduled-12 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,040 Log4j2-TF-13-Scheduled-9 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580857201000 2020-02-06 00:00:01,043 Log4j2-TF-13-Scheduled-10 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/vproxy_access to /home/ventusproxy/logs/vproxy_access.2020-02-05, renameEmptyFiles=false] 2020-02-06 00:00:01,043 Log4j2-TF-13-Scheduled-8 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/http.log to /home/ventusproxy/logs/http.2020-02-05, renameEmptyFiles=false] 2020-02-06 00:00:01,043 Log4j2-TF-13-Scheduled-11 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/vproxy_system to /home/ventusproxy/logs/vproxy_system.2020-02-05, renameEmptyFiles=false] 2020-02-06 00:00:01,043 Log4j2-TF-13-Scheduled-12 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/vproxy_cluster to /home/ventusproxy/logs/vproxy_cluster.2020-02-05, renameEmptyFiles=false] 2020-02-06 00:00:01,043 Log4j2-TF-13-Scheduled-9 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/vproxy_monitor to /home/ventusproxy/logs/vproxy_monitor.2020-02-05, renameEmptyFiles=false] 2020-02-06 00:00:01,043 Log4j2-TF-13-Scheduled-12 DEBUG Now writing to /home/ventusproxy/logs/vproxy_cluster at 2020-02-06T00:00:01.043+0100 2020-02-06 00:00:01,043 Log4j2-TF-13-Scheduled-8 DEBUG Now writing to /home/ventusproxy/logs/http.log at 2020-02-06T00:00:01.043+0100 2020-02-06 00:00:01,043 Log4j2-TF-13-Scheduled-9 DEBUG Now writing to /home/ventusproxy/logs/vproxy_monitor at 2020-02-06T00:00:01.043+0100 2020-02-06 00:00:01,044 Log4j2-TF-13-Scheduled-8 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 2020-02-06 00:00:01,044 Log4j2-TF-13-Scheduled-9 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 2020-02-06 00:00:01,044 Log4j2-TF-13-Scheduled-12 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 2020-02-06 00:00:01,044 Log4j2-TF-13-Scheduled-8 DEBUG Setting prev file time to 2020-02-06T00:00:01.000+0100 2020-02-06 00:00:01,044 Log4j2-TF-13-Scheduled-9 DEBUG Setting prev file time to 2020-02-06T00:00:01.000+0100 2020-02-06 00:00:01,044 Log4j2-TF-13-Scheduled-8 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580943601000 2020-02-06 00:00:01,044 Log4j2
RE: Wrong extensions when rotating files using RollingRandomAccessFile with CronTriggeringPolicy
Log4j2-TF-13-Scheduled-9 DEBUG Formatting file name. useCurrentTime=false. currentFileTime=1580857201000, prevFileTime=1580943601000 2020-02-06 00:00:01,044 Log4j2-TF-13-Scheduled-8 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/vproxy_error to /home/ventusproxy/logs/vproxy_error.2020-02-06, renameEmptyFiles=false] 2020-02-06 00:00:01,044 Log4j2-TF-13-Scheduled-9 DEBUG RollingFileManager executing synchronous FileRenameAction[/home/ventusproxy/logs/vproxy_datametrycs to /home/ventusproxy/logs/vproxy_datametrycs.2020-02-06, renameEmptyFiles=false] 2020-02-06 00:00:01,045 Log4j2-TF-13-Scheduled-8 DEBUG Now writing to /home/ventusproxy/logs/vproxy_error at 2020-02-06T00:00:01.045+0100 2020-02-06 00:00:01,045 Log4j2-TF-13-Scheduled-9 DEBUG Now writing to /home/ventusproxy/logs/vproxy_datametrycs at 2020-02-06T00:00:01.045+0100 2020-02-06 00:00:01,045 Log4j2-TF-13-Scheduled-11 DEBUG Now writing to /home/ventusproxy/logs/vproxy_system at 2020-02-06T00:00:01.045+0100 2020-02-06 00:00:01,045 Log4j2-TF-13-Scheduled-10 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 2020-02-06 00:00:01,045 Log4j2-TF-13-Scheduled-8 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 2020-02-06 00:00:01,045 Log4j2-TF-13-Scheduled-9 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 2020-02-06 00:00:01,045 Log4j2-TF-13-Scheduled-11 DEBUG Log4j2 ConfigurationScheduler Cron expression 1 0 0 * * ? scheduled to fire again at 2020-02-07T00:00:01.000+0100 Files after rotation: -rw-r-. 1 rootroot 487529 Feb 6 00:00 vproxy_access -rw-r-. 1 rootroot2437185 Feb 6 00:00 vproxy_access.2020-02-05 -rw-r-. 1 rootroot 0 Feb 6 00:00 vproxy_cluster -rw-r-. 1 rootroot 0 Feb 6 00:00 vproxy_datametrycs -rw-r-. 1 rootroot771 Feb 6 00:00 vproxy_datametrycs.2020-02-06 -rw-r-. 1 rootroot 12490 Feb 6 00:00 vproxy_error -rw-r-. 1 rootroot 20756 Feb 6 00:00 vproxy_error.2020-02-06 -rw-r-. 1 rootroot 0 Feb 6 00:00 vproxy_monitor -rw-r-. 1 rootroot 0 Feb 6 00:00 vproxy_system -rw-r-. 1 rootroot 14484 Feb 5 23:59 vproxy_system.2020-02-05 Thanks, Joan. -Original Message- From: Ralph Goers Sent: Wednesday, February 5, 2020 8:06 PM To: Log4J Users List Subject: Re: Wrong extensions when rotating files using RollingRandomAccessFile with CronTriggeringPolicy What version of Log4j are you using? If you add status=DEBUG to the configuration element you will see logs appear in stdout that identify some things that are useful for debugging issues during rollover. Could you provide that please? Ralph > On Feb 5, 2020, at 9:50 AM, Joan ventusproxy > wrote: > > Hello, > > We have 5 async logs in our log4j2 configuration that rotates every day at > 00:01. This is the config for one of them: > > fileName="${sys:log.dir}vproxy_access" > filePattern="${sys:log.dir}vproxy_access.%d{-MM-dd}" append="true" > immediateFlush="false"> > %m%d{HH:mm:ss.SSS}%n >evaluateOnStartup="true" /> > > additivity="false"> > > > > So at 5 Feb 00:01 we expected to have 5 logs with the '2020-02-04' extension, > but we see files with '2020-02-05' extension. This sometimes happens to some > files, sometimes to other files ... it's not always happening to the same > files. Some days rotation is ok, some days rotation fails just in 1 file, > sometimes in 2 files, ... > > -rw-r-. 1 rootroot1649483171 Feb 5 16:22 vproxy_access > -rw-r-. 1 rootroot 225670559 Feb 5 00:00 > vproxy_access.2020-02-04 > -rw-r-. 1 rootroot 42650335 Feb 5 16:29 vproxy_cluster > -rw-r-. 1 rootroot 8052 Feb 4 17:58 > vproxy_cluster.2020-02-04 > -rw-r-. 1 rootroot1222846577 Feb 5 17:26 > vproxy_datametrycs > -rw-r-. 1 rootroot 167707641 Feb 5 00:00 > vproxy_datametrycs.2020-02-05 > -rw-r-. 1 rootroot1448754527 Feb 5 16:22 vproxy_error > -rw-r-. 1 rootroot 199048217 Feb 5 00:00 > vproxy_error.2020-02-04 > -rw-r-. 1 rootroot 3683378 Feb 5 17:41 vproxy_system > -rw-r-. 1 rootroot 2238045 Feb 4 23:59 > vproxy_system.2020-02-05 > > Is this a bug or some misconfiguration in our log4j.xml file? > > Thanks for any help you can provide, > > Joan. > &g
Wrong extensions when rotating files using RollingRandomAccessFile with CronTriggeringPolicy
Hello, We have 5 async logs in our log4j2 configuration that rotates every day at 00:01. This is the config for one of them: %m%d{HH:mm:ss.SSS}%n So at 5 Feb 00:01 we expected to have 5 logs with the '2020-02-04' extension, but we see files with '2020-02-05' extension. This sometimes happens to some files, sometimes to other files ... it's not always happening to the same files. Some days rotation is ok, some days rotation fails just in 1 file, sometimes in 2 files, ... -rw-r-. 1 rootroot1649483171 Feb 5 16:22 vproxy_access -rw-r-. 1 rootroot 225670559 Feb 5 00:00 vproxy_access.2020-02-04 -rw-r-. 1 rootroot 42650335 Feb 5 16:29 vproxy_cluster -rw-r-. 1 rootroot 8052 Feb 4 17:58 vproxy_cluster.2020-02-04 -rw-r-. 1 rootroot1222846577 Feb 5 17:26 vproxy_datametrycs -rw-r-. 1 rootroot 167707641 Feb 5 00:00 vproxy_datametrycs.2020-02-05 -rw-r-. 1 rootroot1448754527 Feb 5 16:22 vproxy_error -rw-r-. 1 rootroot 199048217 Feb 5 00:00 vproxy_error.2020-02-04 -rw-r-. 1 rootroot 3683378 Feb 5 17:41 vproxy_system -rw-r-. 1 rootroot 2238045 Feb 4 23:59 vproxy_system.2020-02-05 Is this a bug or some misconfiguration in our log4j.xml file? Thanks for any help you can provide, Joan. - To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org For additional commands, e-mail: log4j-user-h...@logging.apache.org