My name is Golan Shem-Tov, I am a Solutions Architect in the Quest presales team.
After being asked a couple of times about single trace I have decided to write this blog entry to help make things more “visual” to people who are using Single trace.
Singe trace is a tracing mechanism that is built into Foglight java agent; it enables users to trace the call of java requests in the Java stack with the unique capability of showing almost all classes and methods and also SQL parameters sent to DB.
Collecting Single traces:
Single trace collection will typically be triggered in one of 2 ways:
- Manually – a user clicks on an arrow in the “collect” column on the right side of the Java requests page before testing a request or as a response to a notification about a problem with a request type.
In this case the user will be presented with a small dialog window asking about number of trace, tracking SQL parameters (yes/no) and the time duration in
which the java agent will try to collect those traces.
Please note that when triggering single trace manually it can be triggered for a request on all clusters and all servers or a request on all servers in a specific
cluster or on a specific server. In the picture below the first arrow from the top will collect traces for that request on all clusters and servers, the second
arrow will collect traces on all servers that belong to medRecCluster and the third and forth arrows will collect traces on MedRecServer2 and
MedRecServer1.
This is important for a couple of reasons:
- No need to add overhead (even though it is small) to a server that is running fine.
- If you collect traces on a request type level or a cluster level you may collect requests from servers that are not having a problem which will not help
in the investigation.
- The second way to collect traces is automatic, a response to an alert, typically a java request alert (response time, exceptional exits, time out). In the list of available actions you will see a JavaEEtrace action
Please note that when you choose java trace action you get the default settings similar to the ones you saw in the collect traces dialog window.
You still need to define the request name. You can define a regular expression or just select the request name from the list of variables.
Analyzing traces:
Once traces are collected you can investigate them by clicking on the number of traces in the “traces” column of the java requests page
The traces window is divided to 3 sections
Left side – Trace Selector, sort and select traces
Top right – Request trace, showing the call tree of the request
Bottom right – Trace SQL, showing all the request SQL calls.
Since a request tree can be quite big, there is a drop down list that gives you the capability to quickly locate the method that is causing the problem.
- In a case of slowness, you will typically choose “avg. Exclusive execution time”, from the fast find, to locate the method that is taking the most to execute.
In this picture you can see a save method that exclusively takes 10 seconds. A developer can then use a developer profiler like JProbe to isolate the problem to a
line or lines of code in the development environment.
- In a case of request timing out you need concentrate the research on traces that have N/A in their response time column, once you do a fast find Foglight will locate the method that is causing the time out. In this picture the time out is happening when trying to get a connection to the DB.
- In a case of request ending in exception a fast find on exceptions will focus on the method that is throwing the exception. Please note that the method that is throwing the exception is the same get connection to the DB. The difference here is the requests are not timing out, the request and the methods that are seen in the picture have a response time and the user is probably seeing an exception page rather than a time out message.
- In the case of Problems that come from DB calls we will concentrate the investigation on the Trace SQL part of the page. In this case it looks like we have an insert to a prescription table that is taking 60 seconds. Since we chose to run tracing with SQL parameters, they are listed at the end of the tool tip.
A user can then execute this SQL statement directly against the DB and see what is causing this slowness.
I hope you find this information useful.
Golan Shem-Tov