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
