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)
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.
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.
To activate the detailed GC logging, we use the argument -XX:+PrintGCDetails.
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
If you love us? You can donate to us via Paypal or buy me a coffee so we can maintain and grow! Thank you!
Donate Us With