logging-log4j-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Joan Balagueró - ventusproxy <joan.balagu...@ventusproxy.com>
Subject RE: Problem with daily rotation on log4j2 RollingFile
Date Fri, 24 Aug 2018 18:32:56 GMT
Ok Ralph, understood. With log4j worked, but I suppose that now the implementation is completely
different.
Just one more thing, I see you say performance in RollingRandomFile is 20-200% better than
RollingRandom. So, in what cases is it better to use RollingFile instead of RollingRandomFile?
I understand that with such a high concurrency I have it's better to use RollingRandomFile.

Thanks,
Joan.

-----Mensaje original-----
De: Ralph Goers [mailto:ralph.goers@dslextreme.com] 
Enviado el: viernes, 24 de agosto de 2018 19:18
Para: Log4J Users List
Asunto: Re: Problem with daily rotation on log4j2 RollingFile

The TimeBasedTriggeringPolicy does not check for rollover on every log event to reduce the
overhead on busy systems. When you are only logging a few events you will see it log a few
records to the prior file before it checks for a rollover. In your case you would be better
off using the CronTriggeringPolicy as it has a background thread that checks for the time
to rollover.

Ralph

> On Aug 24, 2018, at 9:30 AM, Joan Balagueró - ventusproxy <joan.balaguero@ventusproxy.com>
wrote:
> 
> Hello,
> 
> 
> 
> I知 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,25
> 37,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,4
> 071,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,12
> 12,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,1
> 802,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,3
> 903,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,5
> 681,30
> ,ok,2018-08-24 12:25:42.471
> 
> 
> 
> Today I致e 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,30
> 20,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,1
> 358,46
> 7,ok,2018-08-24 23:59:59.795
> 
> 
> 
> At 00:00 rotation is performed, this is the new log file (it痴 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,11
> 86,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,2
> 597,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,o
> k,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知 not sure if this is a bug or I simply has 
> something misconfigured in my log4j.xml
> 
> 
> 
> Thanks,
> 
> 
> 
> 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


Mime
View raw message