Wednesday, April 27, 2011

Java 6u25 released

Two new operations in ThreadingMBean
 - getThreadCPUTime - over threadID array
 - getThreadAllocateBytes - allocated bytes on thread basis 

http://www.oracle.com/technetwork/java/javase/6u25releasenotes-356444.html

- Tiered compilation is in...


HotSpot diagnostic information has been expanded in several ways:
  • Tracking of cumulative Java heap bytes allocated on a per-thread basis (Threading mbean was added an operation getThreadAllocateBytes

  • On OutOfMemoryError, indication of the faulting thread in the heap dump
  • Improved handling of unexpected exceptions in application native code
  • Better indication of native heap exhaustion
  • More details in hs_err files

Wednesday, April 6, 2011

Tuesday, March 22, 2011

Thread Top

Hi,
I have finally found time to write a small tool which can help profiling Java applications.
Its name is threadTop and it connects to your application via JMX.
It can measure

  •   thread contention 
  •   thread CPU usage
I think it can be very useful when combined with jstack.
Waiting for your feedback :

Tuesday, March 15, 2011

Controlling GC logs at runtime

GC logging can be controlled using the following command line options:
  • -XX:+PrintGC (same as -verbose:gc) - Displays basic GC details 
  • -XX:+PrintGCDetails  - Displays advanced GC details 
  • -XX:+PrintGCTimeStamps - Displays the time stamp for every GC event  reported
  • -XX:+PrintGCDateStamps -  Displays the date for every GC event  reported  
  • -Xloggc:c:\gc.log     - Writes GC logging to the specified file.
It is usually recommended to run with -XX:+PrintGC -XX:+PrintGCTimeStamps -Xloggc:c:\gc.log even in production. The amount of data written to those files is not huge and it can help to analyze GC throughput ,pause time and even to expose bugs in the GC mechanism.
On the other hand these files are not managed by a "log4j style" rolling appender and will not be trimmed by default. So what would we choose ?
The good news is that logging GC can be configured at runtime. It can be enabled and disabled at will via JMX.
The JMX object com.sun.management:type=HotSpotDiagnostic has an attribute named DiagnosticOptions. This attribute contains 12 boolean sub-attributes (as for Java 1.6.0_24). All of them are very interesting but for the GC logging we need to take a look on 4 of them:
  • PrintGC
  • PrintGCDetails
  • PrintGCTimeStamps
  • PrintGCDateStamps

The bad news is that -Xloggc   cannot be configured via JMX so you will need to configure it on startup.


All these can be modified using jconsole or VisualVM using the operation setVMOption.

My recommendation is that even if you do not want to log GC by default add the following params to your command line -Xloggc:c:\gc.log -XX:-PrintGC -XX:+PrintGCTimeStamps 
(Notice that the PrintGC has a -  sign before it)
When you will need to analyze GC just turn on PrintGC and possible the PrintGCDetails.


Thursday, March 3, 2011

-XX:PrintFLSStatistics=1

When trying to understand what is going on with GC logging on G1GC. I found an undocumented JVM param that can really help when using CMS. -XX:PrintFLSStatistics=1 will report extra data for every GC:

8.790: [ParNew: 72703K->6341K(76672K), 0.0067245 secs] 72703K->6341K(816832K)After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 94724096
Max   Chunk Size: 94724096
Number of Blocks: 1
Av.  Block  Size: 94724096
Tree      Height: 1
After GC:
Statistics for BinaryTreeDictionary:
------------------------------------
Total Free Space: 0
Max   Chunk Size: 0
Number of Blocks: 0
Tree      Height: 0
, 0.0068238 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]  

This can really help when trying to understand CMS concurrent mode failure due to fragmentation

Pity it is not reporting data in a single line though :-)

Friday, February 25, 2011

JDK1.6.0_24 released

Nothing interesting though.... JDK1.6.0_23 included the latest version of VisualVM but this is old news by now.

First impressions from G1GC

I was trying to see how G1GC will cope with an application that I am investigating.
Here are my disappointing results:
1. With JDK 1.6.0_20 G1GC is not reporting memory correctly via JMX. problem is solved in later jdks but I am not able at this stage to upgrade the JVM
2. VisualVM is not reporting memory correctly with G1GC need to open a bug for this issue.
3. I cannot find thorough documentation regarding what the GC logs mean (when using G1GC with -Xloggc)
4. The application crashed every few minutes. Again this was with  160_20 and I need to recheck with 160_24