Java Technology Community

with Tags: stack

Dump the Stack Trace information of a method using Xtrace

adevegow Tags: stack xtrace trace method 2 Comments 3,183 Visits

One of the most common technique used while debugging a problem in Java is to add debug statements (System.out.println) into the suspected code or dump the stack trace using the Thread.currentThread().dumpStack() API. This helps to print the parameter values, know the code path that lead to the suspected method. However, this has the drawback that the code needs to be re-compiled, updated to the relevant JAR file and tested.

A more efficient approach to do the same is to use to tracing facility that comes with IBM JDKs. IBM JDK provides the –Xtrace option to trace the Java or native methods and it also allows the user to dump the stacktrace of any Java method.

The “jstacktrace” option allows the user to walk the Java stack of the current thread. This option is available since IBM Java 6 SR5. In this blog, I would like to give syntax details and a couple of examples on how the “jstacktrace” option can be used to dump the stacktrace of any Java method or a JNI method.

Use the below option to print the Java stack trace to the console when java/nio/ByteBuffer.allocateDirect() method is called:

-Xtrace:print=mt,trigger=method{java/nio/ByteBuffer.allocateDirect,jstacktrace}

Sample Output:

11:30:14.560 0x2a5c00 j9trc_aux.0 - jstacktrace:

11:30:14.560 0x2a5c00 j9trc_aux.1 - [1] sun.misc.Unsafe.allocateMemory (Native Method)

11:30:14.561 0x2a5c00 j9trc_aux.1 - [2] java.nio.DirectByteBuffer.<init> (DirectByteBuffer.java:102)

11:30:14.561 0x2a5c00 j9trc_aux.1 - [3] java.nio.ByteBuffer.allocateDirect (ByteBuffer.java:288)

11:30:14.561 0x2a5c00 j9trc_aux.1 - [4] sun.io.CharToByteSingleByte.createCopy (CharToByteSingleByte.java:557)

11:30:14.561 0x2a5c00 j9trc_aux.1 - [5] sun.io.CharToByteCp1252.<clinit> (CharToByteCp1252.java:221)

11:30:14.561 0x2a5c00 j9trc_aux.1 - [6] java.lang.J9VMInternals.initializeImpl (Native Method)

11:30:14.561 0x2a5c00 j9trc_aux.1 - [7] java.lang.J9VMInternals.initialize (J9VMInternals.java:200)

11:30:14.561 0x2a5c00 j9trc_aux.1 - [8] java.lang.Class.forNameImpl (Native Method)

11:30:14.562 0x2a5c00 j9trc_aux.1 - [9] java.lang.Class.forName (Class.java:141)

11:30:14.562 0x2a5c00 j9trc_aux.1 - [10] sun.io.Converters.getConverterClass (Converters.java:298)

11:30:14.562 0x2a5c00 j9trc_aux.1 - [11] sun.io.Converters.newConverter (Converters.java:334)

11:30:14.562 0x2a5c00 j9trc_aux.1 - [12] sun.io.CharToByteConverter.getConverter (CharToByteConverter.java:86)

11:30:14.562 0x2a5c00 j9trc_aux.1 - [13] java.lang.StringCoding.makeEncoder (StringCoding.java:179)

11:30:14.562 0x2a5c00 j9trc_aux.1 - [14] java.lang.StringCoding$EncoderCache$1.run (StringCoding.java:244)

11:30:14.562 0x2a5c00 j9trc_aux.1 - [15] java.security.AccessController.doPrivileged (AccessController.java:277)

11:30:14.563 0x2a5c00 j9trc_aux.1 - [16] java.lang.StringCoding$EncoderCache.getEncoder (StringCoding.java:241)

11:30:14.563 0x2a5c00 j9trc_aux.1 - [17] java.lang.StringCoding.getEncoder (StringCoding.java:434)

11:30:14.563 0x2a5c00 j9trc_aux.1 - [18] java.lang.StringCoding.encode (StringCoding.java:576)

11:30:14.563 0x2a5c00 j9trc_aux.1 - [19] java.lang.StringCoding.encode (StringCoding.java:641)

11:30:14.563 0x2a5c00 j9trc_aux.1 - [20] java.lang.System.<clinit> (System.java:106)

11:30:14.563 0x2a5c00 j9trc_aux.1 - [21] java.lang.J9VMInternals.initializeImpl (Native Method)

11:30:14.563 0x2a5c00 j9trc_aux.1 - [22] java.lang.J9VMInternals.initialize (J9VMInternals.java:200)

11:30:14.564 0x2a5c00 j9trc_aux.1 - [23] java.lang.ClassLoader.initializeClassLoaders (ClassLoader.java:74)

11:30:14.564 0x2a5c00 j9trc_aux.1 - [24] java.lang.Thread.initialize (Thread.java:325)

11:30:14.564 0x2a5c00 j9trc_aux.1 - [25] java.lang.Thread.<init> (Thread.java:124)

Use the below option to write the Java stack trace to a file when java/nio/ByteBuffer.allocateDirect() method is called:

-Xtrace:maximal=mt,output=trc.out,trigger=method{java/nio/ByteBuffer.allocateDirect,jstacktrace}

Display the Java Stack Trace for JNI Methods

The jstacktrace can be used to dump the Java stack when a trace point is reached. This will be useful to dump the jstacktrace when JNI methods are called.

Use the below option to print the Java stack trace to the console when tracepoint id of Unsafe.allocateMemory is called:

-Xtrace:print="j9jcl.62",trigger="tpnid{j9jcl.62,jstacktrace}"

Note: j9jcl.62 is the tracepoint for the JNI method Unsafe.allocateMemory

Sample Output:

15:01:24.995*0x247600 j9jcl.62 > sun_misc_Unsafe_allocateMemory(8)

15:01:24.997 0x247600 j9trc_aux.0 - jstacktrace:

15:01:24.997 0x247600 j9trc_aux.1 - [1] sun.misc.Unsafe.allocateMemory (Native Method)

15:01:24.997 0x247600 j9trc_aux.1 - [2] java.nio.Bits.byteOrder (Bits.java:556)

15:01:24.997 0x247600 j9trc_aux.1 - [3] java.nio.ByteBuffer.<init> (ByteBuffer.java:1361)

15:01:24.997 0x247600 j9trc_aux.1 - [4] java.nio.ByteBuffer.<init> (ByteBuffer.java:267)

15:01:24.997 0x247600 j9trc_aux.1 - [5] java.nio.MappedByteBuffer.<init> (MappedByteBuffer.java:72)

15:01:24.998 0x247600 j9trc_aux.1 - [6] java.nio.DirectByteBuffer.<init> (DirectByteBuffer.java:97)

15:01:24.998 0x247600 j9trc_aux.1 - [7] java.nio.ByteBuffer.allocateDirect (ByteBuffer.java:288)

15:01:24.998 0x247600 j9trc_aux.1 - [8] sun.io.CharToByteSingleByte.createCopy (CharToByteSingleByte.java:557)

15:01:24.998 0x247600 j9trc_aux.1 - [9] sun.io.CharToByteCp1252.<clinit> (CharToByteCp1252.java:221)

15:01:24.998 0x247600 j9trc_aux.1 - [10] java.lang.J9VMInternals.initializeImpl (Native Method)

15:01:24.998 0x247600 j9trc_aux.1 - [11] java.lang.J9VMInternals.initialize (J9VMInternals.java:200)

15:01:24.998 0x247600 j9trc_aux.1 - [12] java.lang.Class.forNameImpl (Native Method)

15:01:24.998 0x247600 j9trc_aux.1 - [13] java.lang.Class.forName (Class.java:141)

15:01:24.998 0x247600 j9trc_aux.1 - [14] sun.io.Converters.getConverterClass (Converters.java:298)

15:01:24.999 0x247600 j9trc_aux.1 - [15] sun.io.Converters.newConverter (Converters.java:334)

15:01:24.999 0x247600 j9trc_aux.1 - [16] sun.io.CharToByteConverter.getConverter (CharToByteConverter.java:86)

15:01:24.999 0x247600 j9trc_aux.1 - [17] java.lang.StringCoding.makeEncoder (StringCoding.java:179)

15:01:24.999 0x247600 j9trc_aux.1 - [18] java.lang.StringCoding$EncoderCache$1.run (StringCoding.java:244)

15:01:25.000 0x247600 j9trc_aux.1 - [19] java.security.AccessController.doPrivileged (AccessController.java:277)

15:01:25.000 0x247600 j9trc_aux.1 - [20] java.lang.StringCoding$EncoderCache.getEncoder (StringCoding.java:241)

15:01:25.001 0x247600 j9trc_aux.1 - [21] java.lang.StringCoding.getEncoder (StringCoding.java:434)

15:01:25.001 0x247600 j9trc_aux.1 - [22] java.lang.StringCoding.encode (StringCoding.java:576)

15:01:25.001 0x247600 j9trc_aux.1 - [23] java.lang.StringCoding.encode (StringCoding.java:641)

15:01:25.001 0x247600 j9trc_aux.1 - [24] java.lang.System.<clinit> (System.java:106)

15:01:25.001 0x247600 j9trc_aux.1 - [25] java.lang.J9VMInternals.initializeImpl (Native Method)

15:01:25.001 0x247600 j9trc_aux.1 - [26] java.lang.J9VMInternals.initialize (J9VMInternals.java:200)

15:01:25.001 0x247600 j9trc_aux.1 - [27] java.lang.ClassLoader.initializeClassLoaders (ClassLoader.java:74)

15:01:25.001 0x247600 j9trc_aux.1 - [28] java.lang.Thread.initialize (Thread.java:325)

15:01:25.001 0x247600 j9trc_aux.1 - [29] java.lang.Thread.<init> (Thread.java:124)

Control the number of stack frames displayed

The “stackdepth” option can be used to limit the number of stack frames displayed along with the jstacktrace trigger option. By default, all the stack frames are displayed.

Use the below option to print only 5 frames of the Java stack trace to the console when java/nio/ByteBuffer.allocateDirect() method is called:

-Xtrace:print=mt,trigger=method{java/nio/ByteBuffer.allocateDirect,jstacktrace},stackdepth=5

Sample Output:

15:00:20.707*0x627800 mt.3 > java/nio/ByteBuffer.allocateDirect(I)Ljava/nio/ByteBuffer; Bytecode static method

15:00:20.707 0x627800 mt.19 - Static method arguments: ((int)65536)

15:00:20.711 0x627800 j9trc_aux.0 - jstacktrace:

15:00:20.711 0x627800 j9trc_aux.1 - [1] java.nio.ByteBuffer.allocateDirect (ByteBuffer.java:288)

15:00:20.711 0x627800 j9trc_aux.1 - [2] sun.io.CharToByteSingleByte.createCopy (CharToByteSingleByte.java:557)

15:00:20.711 0x627800 j9trc_aux.1 - [3] sun.io.CharToByteCp1252.<clinit> (CharToByteCp1252.java:221)

15:00:20.712 0x627800 j9trc_aux.1 - [4] java.lang.J9VMInternals.initializeImpl (Native Method)

15:00:20.712 0x627800 j9trc_aux.1 - [5] java.lang.J9VMInternals.initialize (J9VMInternals.java:200)

15:00:20.719 0x627800 mt.9 < java/nio/ByteBuffer.allocateDirect(I)Ljava/nio/ByteBuffer; Bytecode static method

Feed for Blog Entries ▼