This sample is located in \Samples\Profiler\Jviewprf.
Note To use this sample, it is recommended that you have Microsoft® Visual C++® version 5.0 or higher installed.
Description
Using the Sample
Key Project Files
Technologies Demonstrated
This sample demonstrates how the profiling option (/prof) for jview and wjview was implemented. The sample builds a .dll which enables profiling for special versions of jview and wjview built with PROFILER_HOOK defined. These special versions, called pjview and pwjview, can be built with the makefile in \Samples\Native\JView using the commands nmake cfg="JView - Win32 Release PJView" and nmake cfg="JView - Win32 Release PWJView".
To compile the sample
Use Nmake.exe to compile the makefile in the \Samples\Profiler\Jviewprf directory. The resulting profiler program file (jviewprf.dll) can be found in the debug directory.
Use the following command to build a release version of the same file:
nmake cfg=release
This puts the profiler program into the release subdirectory.
To install the sample
Add Jviewprf.dll to your path, or set the JVIEW_PROFILER environment variable to the full name of Jviewprf.dll. Pjview and pwjview will be profiling-enabled, which makes the profiling command-line option (/prof) available in addition to the normal jview and wjview options.
To uninstall the sample
Delete jviewprf.dll from your path.
Pjview and pwjview support all the jview and wjview options plus the new /prof option. The syntax of the /prof option is as follows:
/prof[:<parameter>, <parameter>, …]
The following parameters can be used.
Parameter | Description |
call[time]s[=<methods>] | Shows time execution in the specified methods. |
calltrace[=<methods>] | Prints entry and exit messages. |
callparams[=<methods>] | Prints parameters and return values. |
permethodalloc | Counts per-method allocations. |
perclassalloc | Counts per-class allocations. |
gc | Prints per-garbage-collection heap information. |
heapdump | Dumps a list of live objects at each garbage collection. |
file=<filename> | Appends profiling output to the specified file. |
sample[=<frequency>] | Samples method locations with the given frequency. |
verbose | Prints class loads and thread creations. |
table | Prints tabular output in simple space-delimited form. |
You can specify several parameters on the command line, separating them with commas. To display this list of parameters on the command line, type:
pjview /prof:?
Example
pjview /prof:calls=MyClass.*+Pkg/mySample.bar()V,gc,file=prof.out.
This command does the following:
The following examples show how to use the /prof option with its parameters.
/prof:calls
Use this parameter to stop the application precisely at single method calls.
Code example:
public class Hello { public static void main (String[] args) { try { throw new Error(); } catch (Throwable e) {} System.out.println("Hello"); } }
Profiler command and results:
C:\>pjview /prof:calls Hello VM state: Interpreter loop, Fast interpreter loop, JIT compiler Start time: 02/15/1999 15:28:45 Hello End time: 02/15/1999 15:28:46 Method Type Calls Throws Time java/lang/System.<clinit>()V f 1 0 81250.81 java/io/OutputStreamWriter.write([CII)V j 1 0 34115.50 sun/io/CharToByteConverter.getDefault()Lsun/io/CharToByteConverter; j 2 0 26027.04 java/io/PrintStream.write(Ljava/lang/String;)V j 1 0 17455.01 java/io/PrintStream.print(Ljava/lang/String;)V j 1 0 13404.49 java/io/BufferedWriter.flushBuffer()V j 1 0 12155.73 java/io/BufferedWriter.write(Ljava/lang/String;II)V j 1 0 11854.02 java/io/PrintStream.newLine()V j 1 0 11729.14 java/io/Writer.write(Ljava/lang/String;)V j 1 0 11005.86 java/io/DataOutputStream.writeChars(Ljava/lang/String;)V j 1 0 10472.00 java/io/OutputStreamWriter.<init>(Ljava/io/OutputStream;)V j 2 0 10381.48 (...) --- End of profiler output. ---
For each method, the results show the following:
/prof:calltrace and /prof:callparams
Use these parameters to see how a particular component in the code is used or which APIs are called. The callparams parameter is similar to calltrace, but also prints the parameters and the return value. To restrict the set of methods and reduce profiling overhead (which makes the application run faster), use wildcards with the parameter.
Profiler command and results for system class calls is as follows:
C:\>pjview /prof:callparams=java/lang/System.* Hello VM state: Interpreter loop, Fast interpreter loop, JIT compiler Start time: 02/15/1999 15:31:46 3c java/lang/System.<clinit>()V [fast interpreted] 3c java/lang/System.nullInputStream()Ljava/io/InputStream; [JIT-compiled] 3c java/lang/System.currentTimeMillis()J [native] 3c return value: 919121506357 3c return value: null 3c java/lang/System.nullPrintStream()Ljava/io/PrintStream; [JIT-compiled] 3c java/lang/System.currentTimeMillis()J [native] 3c return value: 919121506377 3c return value: null 3c java/lang/System.nullPrintStream()Ljava/io/PrintStream; [JIT-compiled] 3c java/lang/System.currentTimeMillis()J [native] 3c return value: 919121506387 3c return value: null 3c (...) java/lang/System.getProperty(Ljava/lang/String;Ljava/lang/String;) Ljava/lang/String; [JIT-compiled] 3c parameters: "file.encoding", "8859_1" 3c return value: "Cp1252" 3c java/lang/System.getProperty(Ljava/lang/String;)Ljava/lang/String; [JIT-compiled] 3c parameters: "line.separator" 3c return value: " " 3c java/lang/System.getProperty(Ljava/lang/String;Ljava/lang/String;) Ljava/lang/String; [JIT-compiled] 3c parameters: "file.encoding", "8859_1" 3c return value: "Cp1252" 3c java/lang/System.getProperty(Ljava/lang/String;)Ljava/lang/String; [JIT-compiled] 3c parameters: "line.separator" 3c return value: " " 3c (...) End time: 02/15/1999 15:31:46 --- End of profiler output. ---
/prof:sample
Use this parameter to periodically stop the application or to specify when you want it to stop (for example, every 10 milliseconds).
Example code:
public class Loop { static double d1 = 1.23; static double d2 = 4.56; static double compute () { return Math.sin(d1) * Math.tan(d1) * Math.pow(d1, d2); } public static void main (String[] args) { long start = System.currentTimeMillis(); long stop = start + 1000; double sum = 0; double prod = 1; while (System.currentTimeMillis() < stop) { double result = compute(); sum += result; prod *= result; } } }
Profiler command and results are as follows:
C:\>pjview /prof:sample Loop VM state: Interpreter loop, Fast interpreter loop, JIT compiler Start time: 02/15/1999 15:45:55 End time: 02/15/1999 15:45:56 Total sampling overhead: 63 ms Sampling frequency: 10 ms 333 total samples Average accuracy of all samples: 24.2% Average accuracy of method samples: 100.0% Method Type Samples Accuracy Loop.compute()D j 34 100.00 java/lang/System.currentTimeMillis()J n 22 100.00 Loop.main([Ljava/lang/String;)V j 8 100.00 sun/io/CharToByteConverter.getConverter(Ljava/lang/String;)Lsun/io/CharToByteConverter; (...) j 2 100.00 java/lang/System.makeProps()V j 1 100.00 java/util/Hashtable.rehash()V j 1 100.00 java/lang/StringBuffer.<init>()V j 1 100.00 sun/io/CharToByteConverter.<init>()V j 1 100.00 java/util/Hashtable.put(Ljava/lang/Object;Ljava/lang/Object;)Ljava/lang/Object; j 1 100.00 java/lang/System.initProperties2(Ljava/util/Properties;)Ljava/util/Properties; n 1 100.00 --- End of profiler output ---
The Accuracy column is usually 100. In rare cases, the profiler APIs cannot accurately associate the current processor state with a Java method. The API then "guesses" and indicates that the sample has low accuracy.
/prof:permethodalloc
Use this parameter to determine where the objects are allocated.
Profiler command and results are as follows:
C:\>pjview /prof:permethodalloc Hello VM state: Interpreter loop, Fast interpreter loop, JIT compiler Start time: 02/15/1999 15:30:12 Hello End time: 02/15/1999 15:30:12 Allocations: 937 objects 82870 bytes Total Per GC Overall Method Type Num Bytes Num Bytes #/Bytes java/lang/System.<clinit>()V java.io.FileOutputStream 2 32 0 10 0% 0% java/io/PrintStream.<init>(Ljava/io/OutputStream;Z)V java.io.OutputStreamWriter 2 64 0 21 0% 0% java/lang/System.makeProps()V com.ms.lang.SystemProperties 1 40 0 13 0% 0% java/lang/Class.getPrimitiveClass(Ljava/lang/String;)Ljava/lang/Class; java.lang.Class 2 64 0 21 0% 0% . . . --- End of profiler output. ---
The previous code shows the types of objects and the methods where they were created. The Total and PerGC columns show the length of the average allocation activity between garbage collections.
/prof:perclassalloc
This parameter is similar to permethodalloc, but it omits the method granularity (that is, to get the output of perclassalloc, add all the per-method numbers).
/prof:gc
This parameter is similar to perclassalloc, but it provides per-garbage-collection information exclusively.
Profiler command and results are as follows:
C:\>pjview /prof:gc Hello VM state: Interpreter loop, Fast interpreter loop, JIT compiler Start time: 02/15/1999 15:52:51 Hello GC 1 duration: 1 ms Heap dump duration: 2 ms Total objects: 911 Gen Type Total New Live Bytes Avg.age 1 java.io.FileOutputStream 2 2 2 40 1.00 1 java.io.OutputStreamWriter 2 2 2 72 1.00 1 com.ms.lang.SystemProperties 1 1 1 44 1.00 1 java.lang.Class 3 3 3 108 1.00 1 [I 5 5 2 112 1.00 1 java.io.PrintStream 2 2 2 72 1.00 1 java.io.FileDescriptor 3 3 3 48 1.00 1 java.lang.OutOfMemoryError 1 1 1 20 1.00 1 [Ljava.lang.String; 1 1 1 20 1.00 1 java.io.DataOutputStream 2 2 2 48 1.00 1 java.lang.StackOverflowError 1 1 1 20 1.00 1 [B 10 10 8 20586 1.00 1 java.util.HashtableEntry 380 380 380 10640 1.00 (...)
In this example:
/prof:heapdump
Use this parameter to dump the entire heap contents at each garbage collection. To minimize the output, use the JVIEWProfiler class to enable and disable heap dumping from within the application. Heap dumping is enabled by default, which is shown in the following example.
void myMethod () { JVIEWProfiler.EnableHeapDumping(false); // Do lots of stuff that causes uninteresting garbage collections. ... // Now I want to see what's in the heap. JVIEWProfiler.EnableHeapDumping(true); System.gc(); JVIEWProfiler.EnableHeapDumping(false); ... }
/prof:table
Use this parameter to omit spacing, line wrapping, and alignment in the output. The result will be easier to import into another format (such as Microsoft® Excel).
These files implement the permethodalloc parameter.
These files implement the calls parameter.
These files implement the calltrace and callparam parameters.
These files implement the gc and heapdump parameters.
These files implement the sample parameter.
Defines GUIDS used by the sample.
Contains the EventMonitor class, which implements IJavaEventMonitor2 for event dispatching. These files also implement profiler registration and output formatting.
Contains three forms of timers: a clock tick timer, a performance counter timer, and a CPU cycle timer.
Defines Java methods that a profiled Java application uses to control the profiler.
Header file (precompiled).
Defines exports of the DLL.
Defines string resources presented to the user.
Profiler