Sunday, 24 October 2010

TimeAndSizeRollingAppender release 20101024-1105

Several fixes and new features in the release 20101024-1105 available from www.simonsite.org.uk.

Briefly these include:
  • Still compatible with Java 1.4; now only compatible with Log4J 1.2.15+.
  • Both ZIP and GZ compression now use NIO to offer dramatic performance improvements. NB This is compatible with Java 1.4.
  • File rollover fix for a scenario where scavenging was turned off, compression was turned on. In the error scenario, slow compression combined with rapidly-filling log files could see backup files deleted erroneously. Backups are now identified by file name pattern matching instead of file modification time, thereby eliminating the cause of the scenario.
  • RollOnStartup now rolls the current log file upon Appender activation (or re-activation). Previously the Appender would only do the start-up roll upon receiving the first logging event from the application. Therefore the first log roll may not have actually taken place until some considerable time after start-up.
  • Thread-safety improvements including finer-grained synchronization and local copying.
  • Daemon threads already running (i.e. scavenger, compressor, roll enforcer) are stopped when the Appender is re-activated (via activateOptions()). This will prevent memory leaks and unpredictable behaviour if the Appender's properties are changed after initial activation. This is only really of concern if the Appender's properties are managed programmatically.
Kudos are due to Oleksiy Pastukhov, Adrian Carcu, Scott Skinner, and Craig Chapel for their contributions and suggestions.

22 comments:

Simon said...

There's a bug in this release that can cause newer backup files to be scavenged. By design, only the oldest backup files should be scavenged.

The underlying cause of the bug is a dodgy re-write of the LogFileList sort code. I have a fix in development and expect to release it this coming weekend.

In the meantime, I have removed the afflicted JAR from my site. If you have already started to use it, then I strongly recommend that you roll back to the July 2010 release for the time being (version 20100717-1237).

Simon said...

The bug fix release is version 20101024-1105, available on my site as before at www.simonsite.org.uk.

Anonymous said...

Really enjoy all of the cool feature your appender has. Wondering, would it be possible to have the date at the beginning of the file name rather than at the end of the file name?

Simon said...

Sorry Anonymous, that's not a feature that's supported by the Appender at present. It should be possible with a bit of a refactor of the code. The filename pattern matching is a bit simplistic at the moment. I'll have a think about it.

Anonymous said...

Simon, thanks for the quick responds. Let me know what you find. I'm digging thru the code and trying to figure it out myself. But my take some time :)

Anonymous said...

I figure it would probably be easier if I asked you. Which class adds the time stamp to the end of the log file name?

Simon said...

The AbstractRoller.BackupFile class.

Anonymous said...

Even when i set the DateRollEnforced to false, the file still rolls before the max file size is set. Here is my property file. is the prop file setup wrong?

log4j.rootLogger=debug, stdout, R

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%5p [%d] [%t] %c (%F:%L) - %m%n


log4j.appender.R=org.apache.log4j.appender.TimeAndSizeRollingAppender
log4j.appender.R.DatePattern=yyyyMMdd_HHmmssss
log4j.appender.R.File=c://Testlogging//ApplicationName.
log4j.appender.R.MaxFileSize=50KB
log4j.appender.R.MaxRollFileCount=10
log4j.appender.R.DateRollEnforced= false
log4j.appender.R.RollOnStartup=true
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=[%d] %5p [%t] %c - %m%n

Simon said...

Hi Anonymous(!),

You can confirm whether this is genuinely an issue by checking (a) the timestamp of the first entry in each new log file, and (b) whether the first entry in each new log file is at the log level "ALL" with the message "Log4J file roll".

You have configured the appender to roll every minute. Try changing the DatePattern parameter to e.g. yyyyMMdd_HH and see whether you see the same issue.

NB The appender only resolves down to the minute, i.e. the seconds part of your posted DatePattern is ignored.

Anonymous said...

so even with DateRollEnforced set to false, the files will still roll every min based on my configuration?

I would like to keep the timestamp added on to the file name. What changes would i need to make inorder to keep the timestamp to the milliseconds without rolling every minute?

Simon said...

When the DateRollEnforced parameter (false by default) is set to true, the TASRA will roll your log files even if the application is not actively logging.

The MaxFileSize parameter is a target size beyond which the TASRA will roll your log files.

If you specify log file rolling at 1-minute resolution, e.g. via the DatePattern "yyyyMMdd_HHmm", then your log files will be rolled in each new minute whilst the application is actively logging.

With the configuration you posted, if the application doesn't actively log anything for 5 minutes, then you might legitimately see backup files less than 50KB in size, with gaps in the timestamps formatted into the backup log filenames.

See the TASRA Javadoc for more information.

GV said...

Hi Simon,

Recently we have started using timesandsizerollingappender. And what we have observed is the logs on lower environments are being written good, but on the prod, sometimes it doesn't write the logs.

Why is this happening? Could you please help!

Thank You!
Sripada

Simon said...

GV - That's a hard problem to solve in the absence of any context. I am pretty certain this is not due to an issue with the TASRA. Drop me an email and I'll see what I can do to help.

SimonC said...

I'd like to subclass the TimeAndSizeRollingAppender class to create some dynamic stats on the logging content. I notice that it is declared as final which is a problem for me. Is there an important reason why it was decided to make it final?

Simon said...

You're way off topic. Drop me an email to discuss this.

Barat said...

Simon...

I have started using TASRA... How to delete log files after few days(say after 5 days)

Unknown said...
This comment has been removed by a blog administrator.
Simon said...

annapurna patil's comment removed since it had nothing to do with either the ActiveAsynchronousAppender or the TimeAndSizeRollingAppender.

lonely ....but still standing said...

Hi Simon,

Jar Used: log4j-rolling-appender-20100717-1237-1.2.9.jar
Log 4j Version : 1.2.8

Below is the log Configuration , we are using :

log4j.rootCategory=Info, R
log4j.appender.R=uk.org.simonsite.log4j.appender.TimeAndSizeRollingAppender
log4j.appender.R.DatePattern='.'yyyy-MM-dd
log4j.appender.R.File=d://logtest//test.log
log4j.appender.R.DateRollEnforced=true
log4j.appender.R.MaxFileSize=1024MB
log4j.appender.R.MaxRollFileCount=100
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.ConversionPattern=[${jboss.server.name}] %d{dd MMM yyyy HH:mm:ss} [%p] %t%X{instance} %c - %m%n

This configuration is working perfectly in local Environment.

If we deploy the code in cluster Environment.

Logs are getting erased (i.e)

For example ,
Date aug 19 2016 : test.log had size of 900KB
Date aug 20 2016 : test.log got erased and two log files got created test.log.2016-08-18.1 and test.log.2016-08-18.2 {new logs are getting written into it}

Request assistance on this

Simon said...

Sorry, I no longer support that release, Lonely. For that matter, your Log4J version is also very old. Please try Log4J 1.2.17 with TimeAndSizeRollingAppender 20150607-2059.

Simon said...

NB Each node in your cluster should be configured to use its own unique log filename.

lonely ....but still standing said...

Hi Simon,

As per the above suggestion, we started using Log4J 1.2.17 with TimeAndSizeRollingAppender 20150607-2059.

Configuration

log4j.appender.R=uk.org.simonsite.log4j.appender.TimeAndSizeRollingAppender
log4j.appender.R.File=d:/test.log
log4j.appender.R.DatePattern=.yyyy-MM-dd
log4j.appender.R.MaxFileSize=500KB
log4j.appender.R.MaxRollFileCount =1000
log4j.appender.R.ScavengeInterval=-1
log4j.appender.R.DateRollEnforced=true
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.layout.conversionPattern=[${jboss.server.name}]%d{dd MMM yyyy HH:mm:ss} [%p] %t%X{instance} %c - %m%n .


If we deploy the above configuration in cluster environment .

Files are getting rolled before the maxFileSize is reached.

Also, the logs are not getting written sequentially , it is getting written in different logs

our requirement is to write all the logging information into a single file in a cluster environment .Kindly let us know whether it can be achieved or may I missing any configuration


Thanks