Problem with daily rotation on log4j2 RollingFile

Fri, 24 Aug 2018 09:30:19 -0700 

Hello,

 

I’m using RollingFileAppender with full async logging. This is the config:

 

<Appenders>

<RollingFile name="ACCESS_LOG"
filePattern="${sys:log.dir}vproxy_access.%d{yyyy-MM-dd}" append="true"
immediateFlush="false">

<PatternLayout>

<Pattern>%m%d{yyyy-MM-dd HH:mm:ss.SSS}%n</Pattern>

</PatternLayout>

<Policies>

                  <TimeBasedTriggeringPolicy/>

            </Policies>

    </RollingFile>

<Appenders>

 

<Loggers>

<Root level="off" additivity="false" />

<Logger name="LOGGER_ACCESS" level="info" includeLocation="false"
additivity="false">

<AppenderRef ref="ACCESS_LOG"/>

</Logger>

</Loggers>

 

 

I started to send requests the 2018-08-22, the vproxy_access.2018-08-22 was
correctly created and requests started to be logged. These are the first 2
lines:

1,192.168.1.248,2018-08-22
18:11:30.171,A,13,A,40,A,72,A,60,N,,192.168.1.248:80,gzip,80616,329,2537,202
,ok,2018-08-22 18:11:30.735

1,192.168.1.248,2018-08-22
18:11:30.171,A,13,A,39,A,72,A,60,N,,192.168.1.248:80,gzip,140160,328,4071,45
2,ok,2018-08-22 18:11:30.744

 

Then I stopped to send requests until 2018-08-24 12:25. The point is these
requests (sent today, day 24) have been logged on the same file, 2018-08-22,
instead of in a newly created log file 2018-08-24. This is the moment (2
lines before, and the first 2 lines today):

1,192.168.1.248,2018-08-22
18:59:23.415,A,13,A,39,A,72,A,60,N,,192.168.1.248:80,gzip,28236,329,1212,121
,ok,2018-08-22 18:59:23.537

1,192.168.1.248,2018-08-22
18:59:23.537,A,13,A,40,A,72,A,60,N,,167.114.89.182:80,gzip,51516,329,1802,43
7,ok,2018-08-22 18:59:23.977

1,192.168.1.248,2018-08-24
12:25:42.439,A,13,A,39,A,72,A,60,N,,192.168.1.248:80,gzip,133122,329,3903,18
,ok,2018-08-24 12:25:42.466

1,192.168.1.248,2018-08-24
12:25:42.428,A,13,A,40,A,72,A,60,N,,192.168.1.248:80,gzip,205848,329,5681,30
,ok,2018-08-24 12:25:42.471

 

Today I’ve kept on sending requests, and these are the last 2 lines:

1,192.168.1.248,2018-08-24
23:59:58.851,A,13,A,40,A,72,A,60,N,,192.168.1.248:80,gzip,99240,329,3020,472
,ok,2018-08-24 23:59:59.326

1,192.168.1.248,2018-08-24
23:59:59.326,A,13,A,41,A,72,A,60,N,,167.114.89.182:80,gzip,34056,327,1358,46
7,ok,2018-08-24 23:59:59.795

 

At 00:00 rotation is performed, this is the new log file (it’s correct):

1,192.168.1.248,2018-08-24
23:59:59.796,A,13,A,40,A,72,A,60,N,,192.168.1.248:80,gzip,27072,329,1186,392
,ok,2018-08-25 00:00:00.189

1,192.168.1.248,2018-08-25
00:00:00.190,A,13,A,41,A,72,A,60,N,,167.114.89.182:80,gzip,82944,327,2597,48
7,ok,2018-08-25 00:00:00.680

1,192.168.1.248,2018-08-25
00:00:00.681,A,13,A,41,A,72,A,60,N,,192.168.1.248:80,,2700,326,0,256,ok,2018
-08-25 00:00:00.937

 

But the problem is this log file has been created as 2018-08-24 instead of
2018-08-25.

 

These are my 2 log files:

-rw-r-----. 1 root        root        4382871 Aug 24 23:59
vproxy_access.2018-08-22

-rw-r-----. 1 root        root          16224 Aug 25 00:00
vproxy_access.2018-08-24

 

And this is the system date now:

[root@server02 logs]# date

Sat Aug 25 00:17:37 EDT 2018

 

 

So at this point I’m not sure if this is a bug or I simply has something
misconfigured in my log4j.xml

 

Thanks,

 

Joan.

Reply via email to