HP

HPjmeter 4.1 User's Guide

English
  HPjmeter 4.1 User's Guide > Chapter 8 Using Visualizer Functions   

Using Profile Displays

Profiling metric displays are available from the Metrics and Estimate menus in the profiling viewer. These visualizers display data collected with -Xeprof and hprof options. Note that the hprof data does not provide both CPU and clock times.

The following figure shows a profile viewer as it appears when first opened.

Example profile viewer as it appears when initially opened

On the Summary tab, as with any field whose value is too long for its column width, if the JVM Arguments value shown at the bottom of the upper panel is extensive and runs beyond its column, you can mouse over the value to display a yellow pop-up box that shows all the JVM arguments. When you mouse away from it, the yellow box disappears. However, if you double click the JVM arguments value, a pop-up box displays and remains until you close it:

Example
profile viewer showing Summary tab with JVM Arguments pop-up box

The profile displays are categorized as follows under the Metrics menu:

These heuristic displays appear under the Estimate menu:

See also:

Menu Choices

The menu bar can contain one or more of these choices, depending on the data type and visualizer you are viewing:

  • File — Contains selections for printing, saving, and comparing data, closing the window, or opening another window that is viewing the same data file. Opening another window is useful when you want to view more than one metric at the same time.

  • Edit— When viewing eprof or hprof data, this menu provides the find functionality also present on the tool bar for quickly navigating through tabular data. This menu also provides two selections, Scale and Scale Special, that help to compensate for differences in time, for example, when one or more files are being compared. See also Mark an Item for Search and Scaling Comparison Data

    When viewing vgc data, this menu contains options for manipulating or resetting the default time interval seen in the graphical data presentation.

    When monitoring an application, this menu contains options for selecting a portion or all of the data set displayed in the Current Live Heap Objects visualizer.

  • View — Provides mechanisms for hiding or revealing aspects of the window controls and visualizer information, and when in the garbage collection viewer, provides many of the same controls available from the button toolbar for manipulating the data display.

  • Metrics — Contains these submenus and their associated profiling metrics:

  • Estimate — Provides heuristic profiling metrics that are estimated based on collected data.

  • Sort — Provides a selector for choosing different ways to sort and display thread data. You can sort threads chronologically, by combined weight (the default), by selected method usage, by CPU usage, by lock contention, and by number of created objects.

  • Scope — Provides selector for changing thread scope. You can look at scope by process, thread, or thread group. See Adjusting Scope for details.

  • Tree— For call graph metrics, this menu provides controls for more quickly navigating the call graph tree. See also Using Call Graph Trees.

  • Help — Provides links to contextual help entries.

NOTE: Some profiling metrics may appear grayed out. These metrics may have been disabled by specifying a JVM agent option. To obtain data with these metrics enabled requires running the application with the appropriate JVM option.

Profile Code and/or CPU Activity

This section contains metrics that are derived from other metrics. The derived metrics are marked by an asterisk (*). They are usually less frequently used, as they not always are immediately useful in detecting performance bottlenecks. For each metric that presents the average values per call, only methods called at least twice are taken into account.

Method Call Count

Use this metric visualizer to see the methods called, the callers of each method, and the cumulative number of calls from each caller.

The methods are sorted by decreasing number of calls. Listed to the left of each method is the number of times it was called. By default, the list of methods includes the package in which each one is located. The gray horizontal bars provide a graphical representation of the number of times a method was called.

Double-click the method name to see a list of its callers with the cumulative number of calls from each caller.

Exclusive Method Times (CPU)

Use this visualizer to see CPU time spent by methods found in the captured data. CPU time spent is given in milliseconds, and for each method, as a percentage of all CPU time used during the capture period. Times are exclusive times.

A remark "(virtual times)" may be displayed after the metric title, if the collected times are virtual CPU times.

The methods are sorted by decreasing time spent in CPU. The gray horizontal bars provide a graphical representation of the time a method spent (in milliseconds) for the period of the collected sample.

Other data shown include packages and arguments associated with each method.

Exclusive Method Clock Times

The standard Java methods java.lang.Thread.sleep and java.lang.Object.wait are not included in this metric. This is because usually the time spent in these methods is a few orders of magnitude larger than in any other method. At the same time, the total time spent in sleep or wait has hardly any relationship to any possible performance bottlenecks, and including these two methods would only distract the user.

Call Graph Tree with Call Count

The call graph with the method call count.

Call Graph Tree with CPU

The inclusive CPU time shown on the call graph.

Call Graph Tree with Clock Time

The inclusive clock time shown on the call graph.

Inclusive Method CPU Times

A remark “(virtual times)” may be displayed after the metric title, if the collected times are virtual CPU times. To see all callers of a given method with the accumulated inclusive CPU time spent in all calls to this method, double click on the method name.

Inclusive Method Clock Times

To see all callers of a given method with the accumulated inclusive clock time spent in all calls to this method, double click on the method name.

Average Exclusive Method CPU Times*

Exclusive CPU Method Time divided by the number of calls to the method. This is the average CPU cost for the body of the method.

Average Exclusive Method Clock Times*

Exclusive Clock Method Time divided by the number of calls to the method. This is the average time spent within the method.

Average Inclusive Method CPU Times*

Inclusive CPU Method Time divided by the number of calls to the method. This gives the average CPU cost for a high-level operation.

Average Inclusive Method Clock Times*

Inclusive Clock Method Time divided by the number of calls to the method. This gives the average turn-around (response) time for a high-level operation.

Starvation by Method*

Shows the starvation for each method. For our purposes, starvation is defined as time unaccounted for. During this time, the thread was not suspended by java.lang.Thread.sleep or java.lang.Object.wait, and it was not delayed at the monitor lock entry. The thread was runnable (in the Java sense), yet it was not running; that is, the context had switched out.

These are possible reasons for reported starvation:

  • the real starvation caused by the operating system scheduler - this should be distributed over all methods in proportion to the exclusive CPU time consumed by each method

  • waiting for the class loader to load a class

  • waiting on an internal VM lock (mutex)

  • time consuming system calls

  • explicit or implicit Garbage Collection invocation (frequent or massive memory allocation by the method)

  • excessive virtual memory paging

  • suspending the thread by external means (i.e. by a debugger)

Starvation Ratio*

Shows the starvation (see above) divided by the Exclusive Method Clock Time for each method. Values close to one indicate that the method did not consume CPU, but nevertheless delayed execution of the program. Such methods are worthwhile to investigate to understand the reason of their behavior.

Methods with Loops*

This metric tries to locate the most intensive loops in the application. The value is the average number of times a loop within a given method was executed over all invocations of the method. The actual loops are not instrumented (measured), and the calculations are based on the call counts collected for the call graph, so the metric always provides only an estimate.

Exclusive Class CPU Times*

The total of the Exclusive Method Times (CPU), summed over all methods of the class. To see the list of all contributing methods, double click on the class name.

Exclusive Class Clock Times*

The total of the Exclusive Method Times (Clock), summed over all methods of the class. To see the list of all contributing methods, double click on the class name. The standard methods java.lang.Thread.sleep and java.lang.Object.wait do not contribute to this metric, however, they will be shown on the list of all contributing methods for the respective classes.

Profile Memory and/or Heap Activity

Most of the heap metrics are available only when analyzing a heap dump file. When using the hprof tool to generate a heap dump, use the profiling option -agentlib:hprof=heap=all. See the metrics table to check how to collect the profile data in order to obtain a specific metric.

The types of objects allocated on heap are classes and arrays. If the profile data file does not contain the specific information related to objects, HPjmeter estimates Objects Created by Method and Created Objects (Count) based on the number of class constructors called. In such cases, you will see "(data estimated)" next to the metric label.

The estimation entirely misses the arrays, and may report inaccurate numbers. Some of the calls to constructors may remain unprofiled, or be not recognized as such by HPjmeter. It is also possible to err on the plus side, when HPjmeter does not properly recognize the class hierarchy.

These metrics – Reference Graph Tree, Reference Sub-tree by Size, Residual Objects (Count), and Residual Objects (Bytes) – show the residual objects. These are objects remaining on the heap at the time the profile data file is written.

Objects Created by Method

Number of objects of all types created by each method. Double click on the method name to see the distribution of the number over object types.

Created Objects (Count)

Number of objects of a given type, created by all methods, presented by object types. Double click on the object type to see which methods created the objects.

Created Objects (Bytes)

Number of bytes occupied by objects of a given type, created by all methods, presented by object types. Double clicking on the type name provides a list of allocation sites (methods) with the number of bytes allocated by each listed method.

Live Objects (Count)

The number of live objects presented by object types. Live objects are those that could be accessed through a chain of references from the set of program variables when the heap dump took place.

Live Objects (Bytes)

The number of bytes occupied by live objects of a given type, presented by object types.

Live Array Sizes

The list of all live arrays remaining in the heap, sorted by their size.

Unfinalized Objects

The number of objects with pending finalization, arranged by their type and sorted by the number of objects of each type. These are all objects with the finalize() method available, but not yet invoked.

Reference Graph Tree

Shows all residual live objects and references between them.

Expanding the nodes shows which references a given object holds.

HPjmeter uses heuristics to detect soft or weak references and uses special symbols ~-> for them, while the hard (regular) references are marked by ->. Double-click on an object to view additional information: all references to the object, and the number of bytes held in the heap by this object. This number is the total amount of bytes that could be reclaimed by garbage collection if all references to this object were nullified. This piece of information is sticky — once this value is calculated for an object, it will be displayed in the Reference Graph.

Displaying large reference graphs puts a lot of stress on the underlying Swing components, so please be patient when dealing with huge heap dumps.

Reference Sub-Trees by Size

This visualizer shows the cluster of objects that are directly or indirectly referenced from the root of the tree, along with the cumulative size of all the references.

This metric is similar to Reference Graph Tree with this difference:

  • You can see the amount of memory allocated to a sub-tree (a node and its contents) as well as to the node itself. The memory held by the node appears in parentheses ( ), and the memory held by the sub-tree appears in brackets [ ] as shown in the following figure:

Figure 8-19 Reference Sub-Trees by Size Visualizer

Reference Sub-Trees by Size Visualizer

NOTE: The symbol // indicates a reference for which memory occupied has already been counted elsewhere in the tree, and therefore, it is not included in the memory held by the parent node of this particular reference.

Class Loaders

This visualizer displays the name and count of class loaders found operating in the application.

Figure 8-20 Class Loaders Visualizer

Class Loaders Visualizer

You can double click one of the listed class loaders to get a pop-up window displaying the class types that have been loaded by that class loader. You can then mark a type and look for it in the other visualizers:

Figure 8-21 Class Types Pop-up Window

Class Types Pop-up Window
Guidelines

  • Class types reside in the Permanent Generation space, which is usually more limited in size than other areas of memory. Continuing incorporation of additional instances of a class loader can begin to fill this area, creating an out-of-memory error in the Perm Gen region of memory. Check the Class Loaders metric — are the number of instances of each class loader what you expect?

  • Use Mark and Find functions in the visualizers to locate references to the class loader and its loaded classes in other related visualizers. Do you find any classes that you think should have been garbage collected, but are not? Note how much space is held by the class loader. Garbage collection cannot be thorough when application code has created a reference that is keeping the class loader and its classes active beyond the time they are needed in the program.

TIP: If you have instrumented the application with Java Management Extensions, you can also open a monitoring session in HPjmeter and use the JMX Memory Tab to quickly observe a rough gauge of activity in various regions of the allocated memory, including the Perm Gen and the Survivor space. See Using the JMX Viewer for additional information.

Residual Objects (Count)

The number of residual objects presented by object types. Residual objects are those remaining on the heap while the heap dump occurred. Not all residual objects are live.

Residual Objects (Bytes)

The number of bytes occupied by residual objects of a given type, presented by object types.

Profile by Threads

Threads Histogram

This visualizer shows all threads created by the application. The horizontal bars represent the lifetime of the threads with respect to the lifetime of the whole application. An explanation follows the image.

Figure 8-22 Threads Histogram with Pie Chart

Threads Histogram with Pie Chart

Thread state indicator  The colored areas of each line or line segment show relative proportions of time that a thread has spent in a particular state. Double-click anywhere on the line to open the pie chart and see actual percentages for the states of the selected thread.

Color change   In this image, the default color for starvation has been changed from white to purple using the color chooser.

Use the selections in the Sort menu to change the criteria by which the threads are ordered and presented. See Menu Choices

Thread Groups Histogram

This visualizer presents all thread groups created by the application. The horizontal bars represent the lifetime of the thread groups, with respect to the lifetime of the whole application. The lifetime of the thread group is defined as the time span between the creation of the first thread belonging to the group and the death of the last thread belonging to the group.

Figure 8-23 Threads Groups Histogram

Threads Groups Histogram

Slider  In this metric visualizer, the slider lets you extend the view to encompass either the thread or thread group view or a portion of both views.

Profile by Locks

The lock delay is a measure for lock contention. The delay is caused by the lock being busy, and is larger if the thread holding the lock is spending much time within the monitor, or when there are many threads attempting to enter the same monitor.

Do not confuse lock delay with the time spent in the java.lang.Object.wait() method, or with the time spent by a given thread within a Java monitor.

Lock metrics are produced only by the -Xeprof profiling option.

Note that the lock metrics do not show individual locks, but only values accumulated over all locks used by a given method. Most methods, however, contain only one synchronization statement or none at all, so identifying the contended lock should be easy if the source code is available.

Uncontested locks remain unprofiled for two reasons:

  • Many locks are in use by a Java program, not always as the programmer's conscious choice. For example, a java.util.Hashtable object used exclusively by only one thread or accessed within a monitor, may be “synchronized” upon multiple times, yet with today's advanced JVM technologies this behavior creates no penalty for the application performance. Lock claims for such objects are not helpful to present.

  • Because of the ubiquitous synchronization in many Java standard packages, profiling all locks would be detrimental to the profiler's performance.

This section contains some metrics derived from other metrics. The derived metrics are marked by an asterisk (*). They are usually less frequently used, as they not always are immediately useful in detecting performance bottlenecks. For each metric that presents the average values per call, only methods called at least twice are taken into account.

The following metrics are available.

Contested Lock Claims by Method

The number of all attempts by individual methods to acquire a Java monitor lock while the lock was being held by another thread, thus entailing a delay, even if only a very short one.

All Lock Claims by Method

The number of all Java monitor locks acquisitions by individual methods. The data is inherently incomplete, because the metric is accumulated only since the first lock conflict for each lock. You will see “partial data)” displayed after the metric label.

Lock Delay - Method Exclusive

Accumulated lock delay, wasted in the method acquiring the lock(s). The lock delay is the time between an attempt to get the lock and the actual acquisition of the lock.

Lock Delay - Call Graph Tree

The inclusive lock delay shown on the call graph. Be sure to read the page on using the trees.

Lock Delay - Method Inclusive

Accumulated lock delay, wasted in the method acquiring the lock(s) and all methods called from it and their descendants.

Lock Contention Ratio by Method*

Contested Lock Claims divided by All Lock Claims for each method. This gives the average frequency with which the method encountered a taken lock. A method must have claimed a lock at least five times to be included in this metric.

Average Exclusive Method Lock Delay*

Method Exclusive Lock Delay divided by the number of calls to the method. For synchronized methods, this is the average delay caused by calling the method.

Exclusive Method Lock Delay / Clock Time*

Method Exclusive Lock Delay divided by the Exclusive Clock Time. For each method, this gives the ratio of time wasted on synchronization to the total time spent in the method.

Average Inclusive Method Lock Delay*

Method Inclusive Lock Delay divided by the number of calls to the method. This gives the average delay caused by synchronization for a high-level operation.

Inclusive Method Lock Delay / Clock Time*

Method Inclusive Lock Delay divided by the Inclusive Clock Time. For each high-level operation, this gives the ratio of time wasted on synchronization to the total time spent in the operation.

Exclusive Class Lock Delay*

The total of the Exclusive Method Lock Delay, summed over all methods of the class. To see the list of all contributing methods, double click on the class name. If a class is used as a monitor with many synchronized methods, the individual methods may not exhibit excessive lock contention, but the problem might get visible using this metric.

Using Heuristic Metrics from the Estimate Menu

HPjmeter provides three estimated measures to aid in narrowing the field of your problem-solving or performance tuning inquiry.

Inline Candidates

Use this estimate to see a list of packages, classes, and methods that are possible candidates for inlining activity during processing. For some candidates, the table lists amount of time estimated to be wasted during the execution of the method.

Use the Mark button to capture the method name, then use Find in other tabular metric visualizers to locate the method in relation to the other data presented.

Exceptions Thrown

Use this estimation to obtain a list of methods, packages, and classes and a count of thrown exceptions associated with each method or package.

Use the Mark button to capture the method name, then use Find in other tabular metric visualizers to locate the method in relation to the other data presented.

Memory Leaks

Use this estimation to obtain a list of packages and package types where leaks are suspected to be occurring, and the amount of memory associated with each listed package.

Use the Mark button to capture the package name, then use Find in other tabular metric visualizers to locate the method in relation to the other data presented.