Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Garbage collector log (loggc) file rotation with logrotate does not work properly

I came across a weird issue when using JVM garbage collection log option with Linux logrotate command. When rotation is executed, it fills NUL ( ^@ ) values the first line of the file given as argument to the JVM.

Let say this is the java call (Test.class is located in /home/test/) :

java -Xloggc:/home/test/test.log -cp /home/test/ Test

The configuration of logrotate for this file is as follow :

/home/test/test.log {
   rotate 56
   missingok
   notifempty
   copytruncate
   nocreate
   nomail
}

I also have a crontab entry logging every minute for testing purposes :

*/1 * * * * /usr/sbin/logrotate -f /etc/logrotate.d/gcLog

I came to the conclusion that JVM writes in append mode and keeps some kind of offset used to write next line in the related file, even if the file is truncated by logrotate (I may be wrong).


My next idea was to try and redirect the stdout to test.log file. I used this java call and kept the same configuration for logrotate and cron:

java -verbose:gc -cp /home/test/ Test > /home/test/test.log

Once again, when test.log is truncated by logrotate, the new created file is filled with NUL (^@) values on the first line.


No need to say that I didn't find anything helpful using google. I found another question on stackoverflow kind of related, but I couldn't manage to setup Java Script Wrapper, so this doesn't work.

Did anybody come across this issue ? Any idea why is this happening ? Better, any workaround or solution ? I need to try and pipe the call to the application to a some script reading the output and maybe look at the way Tomcat logs and rotate stdout in catalina.out (here some help will be really appreciated as well)

like image 726
Hyb Avatar asked Dec 02 '11 08:12

Hyb


People also ask

How do I rotate GC logs?

Developers take advantage of the JVM argument -XX:+UseGCLogFileRotation to rotate GC log files. As shown above, the JVM will rotate the GC log file whenever its size reaches 20MB. It will generate up to five files, with extensions gc.

What is disable explicit GC?

The -Xdisableexplicitgc parameter allows the JVM to ignore these garbage collection suggestions. Typically, system administrators use this parameter in applications that show some benefit from its use. By default, calls to System. gc() trigger a garbage collection. Parent topic: Garbage Collector command-line options.

What is the option to enable the GC trace in Java parameters?

To activate the detailed GC logging, we use the argument -XX:+PrintGCDetails.


1 Answers

We had the same problem at our place running Jboss7 and Java6, we were getting NULLs in the GC file and they just kept growing.

Solution was to just log GC to stdout and then append stdout to a file:

Simple example:

java -verbose:gc >> console.log

Apparently using append (>>) gets rid of the Java "pointer" to a position in the file. With the added bonus of not having the GC logs reset per server restart so we can have some stats over time.

At least the IBM PMAT tool has no problem parsing the sysout with GC output.

The simplest solution is sometimes the best :)

Though I wish Java would support rotating of GC logs, as I see someone's been discussing before: http://mail.openjdk.java.net/pipermail/hotspot-runtime-dev/2011-April/002061.html

like image 135
Stian Lund Avatar answered Sep 20 '22 16:09

Stian Lund