Execution Profiler is installed via a javaagent and its GUI runs in the same JVM. You must access via your operating system's system tray. The system tray will looks like this:
When you hover your mouse over the system tray icon, you will see a tool tip similar to the following:
The tool tip text uses the following format:
<Process ID>@<Machine Name> <Date> <Time>
If multiple JVMs are being profiled simultaneously, the format should help to identify which system tray icon belongs to which JVM.
To activate the popup menu, right-click on the system tray icon:
The popup menu has three menu items:
Click the Show GUI menu item to make the GUI visible (note, the functionality of other menu items are available in the main GUI and discussed in a moment):
Let's now take a look at Execution Profiler in action. This tool has been instrumental (no pun intended) in understanding how various application servers handle converting .jsp files into class files. To understand how WebLogic accomplishes this, this line can be added to the <domain>/bin/startWebLogic.cmd (or .../startWebLogic.sh) script:
set JAVA_OPTIONS=%JAVA_OPTIONS% -javaagent:/agents/discotek.execution-profiler-agent-1.2.0.jar=classes="weblogic.*|javax.servlet.*"
Once WebLogic is in Running state, set Execution Profiler to start recording (click Record Enabled checkbox in the interface or use the system tray) and access a web page from a web application (which doesn't have pre-compiled JSPs). Next, click the Refresh button at the bottom of the window. You should see output similar to this:
Note, recording all activity in WebLogic using the classes="weblogic.*|javax.servlet.*" configuration will record a large amount of data. It is recommended that you instrument only your application classes and that you use the Clear Data button to expunge the captured data as often as possible to avoid OutOfMemoryErrors or performance problems.
If we sort the Total Ellapsed column, you get something like this:
The selected row represents the call to working method of a compiled JSP, _jspService (yeah, its not a servlet's service method. Check out the javadoc). This JSP was called home.jsp. The Method tab is important because it let's you sort by various fields in the table and visualizes what is going on in the JVM. The Trace tab is a little less tidy:
There is continual activity in a WebLogic JVM, which makes finding your execution paths you are interested in like looking for a needle in a hay stack. However, if we flip back to the Method tab and right-click the _jspService method row, we get a pop-up menu:
If you click the Expand in Trace View menu item, all instances of this method will be expanded in the Trace tab and the first instance will be visible in the scroll pane:
From here you can see the execution path to this method and the methods that it invokes.
You'll notice in the above screen shot that some method nodes are green, but a couple of them are orange. Color is used to help identify exceptions:
|Red||Indicates that the node threw an exception|
|Orange||Indicates that some descendant node (method) threw an exception|
|Green||Indicates that no descendant nodes (methods) threw an exception|
The above screen shot doesn't show any red nodes (methods), so let's use the Exceptions tab to drill down (of course we could do this manually in the Trace tab by expanding nodes one by one). Selecting the first row in the Exceptions tab will give you the following:
The table displays the time each exception was encountered, The name of the thread that encountered the exception, the exception type, the name of class in which the method was thrown, and the name of the method in which the method was thrown. Additionally, the stack trace for the selected row will be displayed in the Stack Trace Viewer panel at the bottom. The exception thrown here is mostly irrelevant and is just for illustration. However, it is worth noting this exception doesn't represent an error condition. Here, a class loader in the class loader hierarchy is throwing a ClassNotFoundException because its findClass method cannot find the requested class.
This table also has a pop-up menu when you right-click on a row:
If you click on the pop-up menu, it will expand and scroll to the method node where the exception was encountered:
Note there is a red child node of the selected node. In this case, it is because the exception did not originate from the selected node. It originated in descendant node and the selected now encountered it as it was thrown back down the stack.
Lastly, if you select a red node in the Trace tab, the stack trace will be displayed in the bottom panel, titled Stack Trace Viewer:.
Let's now look at the Http tab:
In the top half of the screen shot is a table, where each row represents where a servlet, filter, or JSP has been invoked. While recording, only a single JSP was invoked and consequently there is only one row in the table. The table has the following columns:
A tool tip is also display over the table. This tool tip contains an HTML table which provides more data in regard to the request. Lastly, when a row is selected, the bottom half of the Http tab will display a tree graph of the invoked Filter/Servlet/JSP method and all the the descendants it invoked. Note, it will only show the methods in classes that were targeted for instrumentation when you configured the agent on the command line.
You should note that a single request may generate several rows in the Http tab, depending on the web container implementation. Specifically, processing a single request may pass through multiple servlet/filter classes. You should also be aware of a system property configuration. If the discotek-ex-prof-all-servlet-methods system property is set, all servlet methods will be instrumented (i.e. doGet, doPost, etc).
Let's now look at the Jdbc tab. This tab captures all SQL processed by java.sql.Statement or java.sql.PreparedStatement objects. The JSP application I was using to explore JSP class generation doesn't perform any JDBC, so the tab is empty. The following is a screen shot from a different instrumented Java application. The application is a log file analyzer, which isn't ready to be published on discotek.ca, but does use an HSQLDB database extensively.
In the top half of the panel, we have a table with the following columns:
When a row in this table is selected, the bottom half of the panel displays the stack of methods used to call the method that executed the SQL. In the above screen shot, an HSQLDB JDBCPreparedStatement.executeQuery method was invoked. The stack shows us that it was invoked via a c3p0 connection pool library.