This performance Insight article is a follow-up to a previous article that discussed the difference between trace instrumentation and application performance management. The article describes small changes made to an open source byte code instrumentation tool,
Java Interactive Profiler, in order to redirect profiling responsibilities to JXInsight's
Tracer and enhance aspects of the JIP tool with enterprise application performance and test management capabilities.
Introduction
The Java Interactive Profiler (JIP) is an open source instrumentation and to some degree code profiling tool. It works only with Java 5 VM's and uses the –javaagent VM option to install a class byte code transformer. This standard Java 5 option allows tools to “hook” into the class loading of the runtime with the ability to modify byte code prior to class linkage. JIP simply injects static method invocations calls at each method entry and exit point. For more information please read this
article published on the IBM Java
developerWorks web site.
Note: The current implementation of the JIP tool has a few limitations which render it inappropriate for Java enterprise production environments. The authors of the tool, Mentor LLC, who have a copyright on the source code, have clearly documented such limitations within the source as well as on the JIP forum. The limitations center around J2EE class loading hierarchies, class initializations, incomplete call stacks (this is also an inherent problem in solutions from Quest and CA WilyTech), and handling of exceptions thrown directly or indirectly in instrumented methods.
Clock Application
The Clock example used in the previous article has been changed to exclude explicit instrumentation calls because the JIP tool uses the dynamic byte code transformation feature of Java 5 to weave instrumentation code into methods during class loading.
Running the Clock application with the original JIP Java 5 profiling agent produces the following text output. During the execution of the application there is very limited interaction capabilities exposed by the JIP client tool apart from stop and start.
Clock Example - JXInsight Enhanced JIP Code
The following code snippets show the required changes to two of the JIP classes redirecting profiling responsibilities to JXInsight. Instead of injecting instrumentation code to call out to
com.mentorgen.tools.profile.runtime.Profile the instrumentation code has been changed to call out to JXInsight's
Tracer.
Code Snippet:
com.mentorgen.tools.profile.instrument.PerfMethodAdapter
Code Snippet:
com.mentorgen.tools.profile.instrument.Transformer
JXInsight Enhanced Performance Analysis
Running the Clock example with both the JXInsight JVMPI agent and the JIP JVMTI Agent loaded, produces the following visualizations within the JXInsight application analysis and management console. What is important to note are the new resource timing measurements
(CPU,
Service,
Thread Waiting,
Thread Blocking, Clock Adjusted, and
GC) that has been collected for each instrumentated trace. The
Service Totals indicate a small overlap in the execution windows of the main thread and the spawned thread. This is also shown later in the timeline analysis. The
Wait Totals indicate that the processing was stalled via direct or indirect calls to a
Object.wait(). The CPU totals also reflect this pause in execution. The
GC Totals indicate the occurrence of GC cycles during the test execution. 4 seconds of GC time was recorded during the execution of
Clock.run.
The standard console trace analysis view provides the following additional interaction features
- Column Ordering and Sorting
- Statistical distributions of measurements
- Annotation of snapshots via cell notes
- Filtering and collapsing of trace tree
- Call stack graphic visualization allowing filtering via a percentage slider
- Export to CSV or System Clipboard
- Merging of multiple traces across a cluster of servers
- Color encoding of cells to increase understanding of numerical data
- Column bar charts embedded in left side of table view
- Integrated and complete (instrumented and non-instrumented) Java call stacks
Running the JXInsight agent with object allocation JVMPI event monitoring enabled (-Xrunjdbinsight:a=t) results in instrumented traces containing additional statistical data related to object allocation sizes. Unlike JIP, JXInsight records object allocation sizes, and not counts, as well as including all classes (instrumented or not) and arrays of primitives. The ability to report on memory consumption alongside other timings is a unique profiling capability of JXInsight.
The JXInsight timeline analysis of the Clock application provides a history of instrumented method invocations along with complete call stacks. The top section of the timeline shows the execution of traces by multiple threads. Here the overlap between the main application thread and the spawned thread is visible.
William
Louth, JXInsight's Product Architect