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 > <joan.balagu...@ventusproxy.com> wrote: > > Hi Ralph, > > Do you think this is a bug or a misconfiguration on my side? > > Thanks, > > Joan. > > -----Original Message----- > From: Joan ventusproxy <joan.balagu...@ventusproxy.com> > Sent: Thursday, February 6, 2020 6:21 PM > To: 'Log4J Users List' <log4j-user@logging.apache.org> > 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-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 Formatting file name. > useCurrentTime=false. currentFileTime=1580857201000, > prevFileTime=1580943601000 > 2020-02-06 00:00:01,044 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 root root 487529 Feb 6 00:00 vproxy_access > -rw-r-----. 1 root root 2437185 Feb 6 00:00 > vproxy_access.2020-02-05 > -rw-r-----. 1 root root 0 Feb 6 00:00 vproxy_cluster > -rw-r-----. 1 root root 0 Feb 6 00:00 vproxy_datametrycs > -rw-r-----. 1 root root 771 Feb 6 00:00 > vproxy_datametrycs.2020-02-06 > -rw-r-----. 1 root root 12490 Feb 6 00:00 vproxy_error > -rw-r-----. 1 root root 20756 Feb 6 00:00 > vproxy_error.2020-02-06 > -rw-r-----. 1 root root 0 Feb 6 00:00 vproxy_monitor > -rw-r-----. 1 root root 0 Feb 6 00:00 vproxy_system > -rw-r-----. 1 root root 14484 Feb 5 23:59 > vproxy_system.2020-02-05 > > Thanks, > > Joan. > > > -----Original Message----- > From: Ralph Goers <ralph.go...@dslextreme.com> > Sent: Wednesday, February 5, 2020 8:06 PM > To: Log4J Users List <log4j-user@logging.apache.org> > 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 >> <joan.balagu...@ventusproxy.com> 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: >> >> <RollingRandomAccessFile name="ACCESS_LOG" >> fileName="${sys:log.dir}vproxy_access" >> filePattern="${sys:log.dir}vproxy_access.%d{yyyy-MM-dd}" append="true" >> immediateFlush="false"> >> <PatternLayout><Pattern>%m%d{HH:mm:ss.SSS}%n</Pattern></PatternLayout> >> <Policies><CronTriggeringPolicy schedule="1 0 0 * * ?" >> evaluateOnStartup="true" /></Policies> </RollingRandomAccessFile> >> >> <Logger name="LOGGER_ACCESS" level="info" includeLocation="false" >> additivity="false"> >> <AppenderRef ref="ACCESS_LOG"/> >> </Logger> >> >> 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 root root 1649483171 Feb 5 16:22 vproxy_access >> -rw-r-----. 1 root root 225670559 Feb 5 00:00 >> vproxy_access.2020-02-04 >> -rw-r-----. 1 root root 42650335 Feb 5 16:29 vproxy_cluster >> -rw-r-----. 1 root root 8052 Feb 4 17:58 >> vproxy_cluster.2020-02-04 >> -rw-r-----. 1 root root 1222846577 Feb 5 17:26 >> vproxy_datametrycs >> -rw-r-----. 1 root root 167707641 Feb 5 00:00 >> vproxy_datametrycs.2020-02-05 >> -rw-r-----. 1 root root 1448754527 Feb 5 16:22 vproxy_error >> -rw-r-----. 1 root root 199048217 Feb 5 00:00 >> vproxy_error.2020-02-04 >> -rw-r-----. 1 root root 3683378 Feb 5 17:41 vproxy_system >> -rw-r-----. 1 root root 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 >> >> > > > > --------------------------------------------------------------------- > 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