You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-user@logging.apache.org by Joan Balagueró - ventusproxy <jo...@ventusproxy.com> on 2017/06/02 10:19:02 UTC
Log4j2 rolling file rotation by hour not working
Hello,
Ive posted this in stackoverflow, with no success. So Im trying here now.
I'm seeing the following behaviour in log4j2, not sure if it's the expected.
This is part of my log4j.xml:
<RollingFile name="ACCESS_LOG"
filePattern="${sys:log.dir}vproxy_access.%d{${sys:log.rotateAccess}}"
append="true"
bufferedIO="true"
bufferSize="16384"
immediateFlush="false">
<PatternLayout>
<Pattern>%m%d{yyyy-MM-dd HH:mm:ss.SSS}%n</Pattern>
</PatternLayout>
<Policies>
<TimeBasedTriggeringPolicy/>
</Policies>
</RollingFile>
The log.rotateAccess is a system property than can have the values of
'yyyy-MM-dd' for daily rotation or 'yyyy-MM-dd.HH' for hourly rotation.
So, when I start to send requests to my app at 19:01 the
vproxy_access.2017-05-25.19 is correctly created and requests are logged.
This is the first line of this log:
1,88.0.193.186,2017-05-25
19:01:31.733,A,56,A,0,A,190,A,60,N,,,,2716,423,0,53,ok,2017-05-25
19:01:31.852
It's ok, but this is the last line:
1,167.114.89.180,2017-05-25
20:59:59.943,A,56,A,66,A,190,A,60,N,,,gzip,213161,323,5853,18,ok,2017-05-25
20:59:59.967
The file has rotated at 21:00 instead of 20:00. So the
vproxy_access.2017-05-25.20 contains all requests from 21:00:00 to 21:59:59.
And if we check the vproxy_access.2017-05-25.23, the first and last line
are:
1,167.114.89.180,2017-05-25
23:59:59.984,A,56,A,0,A,190,A,60,N,,,gzip,165921,323,4683,12,ok,2017-05-26
00:00:00.002
( . . . )
1,167.114.89.180,2017-05-26
00:59:59.984,A,56,A,0,A,190,A,60,N,,,,147025,323,0,10,ok,2017-05-26
00:59:59.999
Furthermore, today we have stopped to send requests at 01:00
(vproxy_access.2017-06-02.00). When we have started to send requests again
at 12:07, the log file vproxy_access.2017-06-02.01 has been created. This is
the first line:
1,167.114.89.180,2017-06-02
12:07:23.561,A,56,A,0,A,190,A,60,N,,167.114.89.180:80,gzip,151749,323,4335,8
,ok,2017-06-02 12:07:23.575
I need my vproxy_access.yyyy-MM-dd.HH to contain all lines from HH:00:00 to
HH:59:59
Any help would be very appreciated.
Joan.
RE: Log4j2 rolling file rotation by hour not working
Posted by Joan Balagueró - ventusproxy <jo...@ventusproxy.com>.
Hi,
CronTriggeringPolicy does not work either. We started to send requests at 17:26, the vproxy_access.2017-02-06.17 was correctly created, and it rotated at 18:00. Ok.
But the vproxy_access. 2017-02-06.18 didn't rotate at 19:00. The last line is:
1,167.114.89.180,2017-06-02 19:59:59.969,A,56,A,0,A,190,A,60,N,,167.114.89.180:80,deflate,16708,321,905,1,ok,2017-06-02 19:59:59.971
Apparently it's the same problem that occurs with the TimeBased. The log4j configuration is the same, changing TimeBased by CronTriggeringPolicy:
<Policies>
<CronTriggeringPolicy schedule="${sys:log.cronAccess}" />
</Policies>
Where log.cronAccess is "0 0 0/1 * * ?"
Joan.
-----Mensaje original-----
De: Ralph Goers [mailto:ralph.goers@dslextreme.com]
Enviado el: viernes, 2 de junio de 2017 15:55
Para: Log4J Users List
Asunto: Re: Log4j2 rolling file rotation by hour not working
This sounds like a bug that has already been reported. I would suggest you try the CronTriggeringPolicy instead o the TimeBasedTriggeringPolicy.
Ralph
> On Jun 2, 2017, at 3:19 AM, Joan Balagueró - ventusproxy <jo...@ventusproxy.com> wrote:
>
> Hello,
>
>
>
> I致e posted this in stackoverflow, with no success. So I知 trying here now.
>
>
>
> I'm seeing the following behaviour in log4j2, not sure if it's the expected.
>
>
>
> This is part of my log4j.xml:
>
> <RollingFile name="ACCESS_LOG"
>
>
> filePattern="${sys:log.dir}vproxy_access.%d{${sys:log.rotateAccess}}"
>
> append="true"
>
> bufferedIO="true"
>
> bufferSize="16384"
>
> immediateFlush="false">
>
>
>
> <PatternLayout>
>
> <Pattern>%m%d{yyyy-MM-dd HH:mm:ss.SSS}%n</Pattern>
>
> </PatternLayout>
>
>
>
> <Policies>
>
> <TimeBasedTriggeringPolicy/>
>
> </Policies>
>
>
>
> </RollingFile>
>
>
>
> The log.rotateAccess is a system property than can have the values of
> 'yyyy-MM-dd' for daily rotation or 'yyyy-MM-dd.HH' for hourly rotation.
>
> So, when I start to send requests to my app at 19:01 the
> vproxy_access.2017-05-25.19 is correctly created and requests are logged.
> This is the first line of this log:
>
> 1,88.0.193.186,2017-05-25
> 19:01:31.733,A,56,A,0,A,190,A,60,N,,,,2716,423,0,53,ok,2017-05-25
> 19:01:31.852
>
>
>
> It's ok, but this is the last line:
>
> 1,167.114.89.180,2017-05-25
> 20:59:59.943,A,56,A,66,A,190,A,60,N,,,gzip,213161,323,5853,18,ok,2017-
> 05-25
> 20:59:59.967
>
>
>
> The file has rotated at 21:00 instead of 20:00. So the
> vproxy_access.2017-05-25.20 contains all requests from 21:00:00 to 21:59:59.
>
>
>
> And if we check the vproxy_access.2017-05-25.23, the first and last
> line
> are:
>
> 1,167.114.89.180,2017-05-25
> 23:59:59.984,A,56,A,0,A,190,A,60,N,,,gzip,165921,323,4683,12,ok,2017-0
> 5-26
> 00:00:00.002
>
> ( . . . )
>
> 1,167.114.89.180,2017-05-26
> 00:59:59.984,A,56,A,0,A,190,A,60,N,,,,147025,323,0,10,ok,2017-05-26
> 00:59:59.999
>
>
>
> Furthermore, today we have stopped to send requests at 01:00
> (vproxy_access.2017-06-02.00). When we have started to send requests
> again at 12:07, the log file vproxy_access.2017-06-02.01 has been
> created. This is the first line:
>
> 1,167.114.89.180,2017-06-02
> 12:07:23.561,A,56,A,0,A,190,A,60,N,,167.114.89.180:80,gzip,151749,323,
> 4335,8
> ,ok,2017-06-02 12:07:23.575
>
>
>
> I need my vproxy_access.yyyy-MM-dd.HH to contain all lines from
> HH:00:00 to
> HH:59:59
>
> Any help would be very appreciated.
>
> Joan.
>
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org
Re: Log4j2 rolling file rotation by hour not working
Posted by Ralph Goers <ra...@dslextreme.com>.
This sounds like a bug that has already been reported. I would suggest you try the CronTriggeringPolicy instead o the TimeBasedTriggeringPolicy.
Ralph
> On Jun 2, 2017, at 3:19 AM, Joan Balagueró - ventusproxy <jo...@ventusproxy.com> wrote:
>
> Hello,
>
>
>
> I致e posted this in stackoverflow, with no success. So I知 trying here now.
>
>
>
> I'm seeing the following behaviour in log4j2, not sure if it's the expected.
>
>
>
> This is part of my log4j.xml:
>
> <RollingFile name="ACCESS_LOG"
>
>
> filePattern="${sys:log.dir}vproxy_access.%d{${sys:log.rotateAccess}}"
>
> append="true"
>
> bufferedIO="true"
>
> bufferSize="16384"
>
> immediateFlush="false">
>
>
>
> <PatternLayout>
>
> <Pattern>%m%d{yyyy-MM-dd HH:mm:ss.SSS}%n</Pattern>
>
> </PatternLayout>
>
>
>
> <Policies>
>
> <TimeBasedTriggeringPolicy/>
>
> </Policies>
>
>
>
> </RollingFile>
>
>
>
> The log.rotateAccess is a system property than can have the values of
> 'yyyy-MM-dd' for daily rotation or 'yyyy-MM-dd.HH' for hourly rotation.
>
> So, when I start to send requests to my app at 19:01 the
> vproxy_access.2017-05-25.19 is correctly created and requests are logged.
> This is the first line of this log:
>
> 1,88.0.193.186,2017-05-25
> 19:01:31.733,A,56,A,0,A,190,A,60,N,,,,2716,423,0,53,ok,2017-05-25
> 19:01:31.852
>
>
>
> It's ok, but this is the last line:
>
> 1,167.114.89.180,2017-05-25
> 20:59:59.943,A,56,A,66,A,190,A,60,N,,,gzip,213161,323,5853,18,ok,2017-05-25
> 20:59:59.967
>
>
>
> The file has rotated at 21:00 instead of 20:00. So the
> vproxy_access.2017-05-25.20 contains all requests from 21:00:00 to 21:59:59.
>
>
>
> And if we check the vproxy_access.2017-05-25.23, the first and last line
> are:
>
> 1,167.114.89.180,2017-05-25
> 23:59:59.984,A,56,A,0,A,190,A,60,N,,,gzip,165921,323,4683,12,ok,2017-05-26
> 00:00:00.002
>
> ( . . . )
>
> 1,167.114.89.180,2017-05-26
> 00:59:59.984,A,56,A,0,A,190,A,60,N,,,,147025,323,0,10,ok,2017-05-26
> 00:59:59.999
>
>
>
> Furthermore, today we have stopped to send requests at 01:00
> (vproxy_access.2017-06-02.00). When we have started to send requests again
> at 12:07, the log file vproxy_access.2017-06-02.01 has been created. This is
> the first line:
>
> 1,167.114.89.180,2017-06-02
> 12:07:23.561,A,56,A,0,A,190,A,60,N,,167.114.89.180:80,gzip,151749,323,4335,8
> ,ok,2017-06-02 12:07:23.575
>
>
>
> I need my vproxy_access.yyyy-MM-dd.HH to contain all lines from HH:00:00 to
> HH:59:59
>
> Any help would be very appreciated.
>
> Joan.
>
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-user-help@logging.apache.org