Re: Wrong extensions when rotating files using RollingRandomAccessFile with CronTriggeringPolicy
Whether it is a bug or not I still can’t say, but please open an issue and attach all of this information. A sample project that demonstrates the problem would be extremely helpful. We have tests and, as far as I know, none of them exhibit this behavior. Ralph > On Feb 25, 2020, at 4:12 AM, Joan ventusproxy > wrote: > > 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-0
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
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-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 D
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
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.
>
>
> -
> 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
