[Previous] [Contents] [Index] [Next]

Caution: This version of this document is no longer maintained. For the latest documentation, see http://www.qnx.com/developers/docs.

Analyzing Your System with Kernel Tracing

You can select a topic from this diagram:

Utilities Used by the IDE Getting System Information Using Code Coverage Common Wizards Reference Preparing Your Target Developing Photon Applications Developing C/C++ Programs Where Files Are Stored Building OS and Flash Images Migrating to the 6.3 Release Tutorials IDE Concepts About This Guide Analyzing Your System With Kernel Tracing Profiling an Application Finding Memory Errors Debugging Programs Managing Source Code Launch Configurations Reference

Workflow diagram with system-analysis chapter highlighted


Use the System Profiler to analyze your system via instrumentation.


In this chapter...

Introducing the QNX System Profiler

The System Profiler is a tool that works in concert with the Neutrino instrumented kernel (procnto-instr) to provide insight into the operating system's events and activities. Think of the System Profiler as a system-level software logic analyzer. Like the Application Profiler, the System Profiler can help pinpoint areas that need improvement, but at a system-wide level.

The instrumented kernel can gather a variety of events, including:

You might use the System Profiler to solve such problems as:


Note: Details on kernel instrumentation (such as types and classes of events) are more fully covered in the System Analysis Toolkit (SAT) User's Guide.

The QNX System Profiler perspective includes several components that are relevant to system profiling:

Navigator view
Events are stored in log files (with the extension .kev) within projects in your workspace. These log files are associated with the System Profiler editor.
Target Navigator view
When you right-click a target machine in the Target Navigator, you can select Kernel Events Tracing..., which initiates the Trace Logging wizard. You use this wizard to specify which events to capture, the duration of the capture period, as well as specific details about where the generated event log file (.kev file) will be stored.
System Profiler editor
This editor provides the graphical representation of the instrumentation events in the captured log file. Like all other Eclipse editors, the System Profiler editor shows up in the editor area and can be brought into any perspective. This editor is automatically associated with .kev files, but if you have other file types that contain instrumentation data, you could associate the editor with those files as well.
Trace Event Log view
This view lists instrumentation events, as well as their details (time, owner, etc.), surrounding the selected position in the currently active System Profiler editor.
General Statistics view
A tabular statistical representation of events.
Note: Statistics can be gathered for the entire log file or for a selected range.

Condition Statistics view
A tabular or graphical statistical representation of the conditions used in the search panel.
Event Owner Statistics view
A tabular statistical representation of events broken down per owner.
Bookmarks view
Just as you can bookmark lines in a text file, here you can bookmark particular locations and event ranges displayed in the System Profiler editor, then see your bookmarked events in the Bookmarks view.

Note: The QNX System Profiler perspective may produce incorrect results when more than one IDE is communicating with the same target system. To use this perspective, make sure only one IDE is connected to the target system.

Before you begin

As mentioned earlier, in order to capture instrumentation data for analysis, the instrumented kernel (procnto-instr) must be running. This kernel is a drop-in replacement for the standard kernel (though the instrumented kernel is slightly larger). When you're not gathering instrumentation data, the instrumented kernel is almost exactly as fast as the regular kernel.


Note: To know if the instrumented kernel is running, enter this command:
ls /proc/boot

If procnto-instr appears in the output, then the OS image is running the instrumented kernel.


To substitute the procnto-instr module in the OS image on your board, you can either manually edit your buildfile, then run mkifs to generate a new image, or use the System Builder perspective to configure the image's properties.

Replacing the kernel using the System Builder

  1. In the System Builder Projects view, double-click the project.bld file for the image you want to change.
  2. In the Images pane of the System Builder editor, select the image.
  3. In the Properties view, click the Procnto field (under System). A dropdown-menu button appears in the field:

    Instrumented kernel selection

  4. Select procnto-instr, press Enter, then save your change.
  5. Rebuild your project, then transfer your new OS image to your board.

Assuming you're running the instrumented kernel on your board, you're ready to use the System Profiler. A profiling session usually involves these three steps:

Configuring a target for system profiling

You can gather trace events from the instrumented kernel in two different ways. You run a command-line utility (e.g. tracelogger) on your target to generate a log file, and then transfer that log file back to your development environment for analysis. Or, you can capture events directly from the IDE using the Trace Events Configuration wizard.


Note: In order to get timing information from the kernel, you need to run tracelogger as the root user.

If you gather system profiling data through qconn in the IDE, you're already accessing the instrumented kernel as root.


Using the command-line server currently offers more flexibility as to when the data is captured, but requires that you set up and configure filters yourself using the TraceEvent() API. The Trace Events Configuration wizard lets you set a variety of different static filters and configure the duration of time that the events will be logged for.

For more information on the tracelogger utility, see its entry in the Utilities Reference. For TraceEvent(), see the Library Reference.

Launching the System Profiler Configuration wizard

=>> In the Target Navigator view, right-click a target, then select Kernel Events Tracing... from the menu.

If you don't have the Target Navigator view open, choose Window-->Show View-->Other..., then QNX Targets-->Target Navigator.


Note: If you don't already have a target project, you'll have to create one:
=>> In the Target Navigator, right-click and select Add New Target.

You can use this target project for a number of different tasks (debugging, memory analysis, profiling), so once you create it, you won't have to worry about connecting to your target again. Note also that the qconn target agent must be running on your target machine.


Selecting options in the wizard

The wizard takes you through the process of selecting:

System Profiler configuration dialog

Here are the main fields in this wizard:

Save Project as
The name you want to use for the kernel events log file (.kev) in your workspace.
Tracing method, Type (Period of time)
The duration of the capture of events as defined by a time. This is the default.
Tracing method, Period length
Floating-point value in seconds representing the length of time to capture kernel events on the target.
Tracing method, Type (Iterations)
The duration of the capture of events as defined by the number of kernel event buffers.
Tracing method, Number of Iterations
Total number of full kernel event buffers to log on the target.
Trace file, Mode (Save on target then upload)
In this mode, kernel event buffers are first saved in a file on the target, then uploaded to your workspace. This is the default.
Trace file, Filename on target
Name of the file used to save the kernel event buffers on the target.
Trace file, Mode (Stream)
In this mode, no file is saved on the target. Kernel event buffers are directly sent from qconn to the IDE.
Trace statistics File, Mode (Generate only on the target)
The information file will be generated only on the target. This is the default.
Trace statistics file, Mode (Do not generate)
No file will be generated.
Note: If your target is running QNX 6.2.1, you must use this option instead of "Generate only on the target" because the trace statistics file is not supported under QNX 6.2.1.

Trace statistics File, Mode (Save on target then upload)
The statistical information is first saved in a file on the target, then uploaded to your workspace.
Trace statistics File, Filename on target
Name of the file used to save the statistical information on the target.
Buffers, Number of kernel buffers
Size of the static ring of buffers allocated in the kernel.
Buffers, Number of qconn buffers
Maximum size of the dynamic ring of buffers allocated in the qconn target agent.

Capturing instrumentation data in event log files

Regardless of how your log file is captured, you have a number of different options for how to regulate the amount of information actually captured:

(For more information, see the SAT User's Guide.)

The IDE lets you access the first three of the above filters. You can enable tracing (currently done by activating the tracing wizard), and then select what kind of data is logged for various events in the system.

The events in the system are organized into different classes (kernel calls, communication, thread states, interrupts, etc). You can toggle each of these classes in order to indicate whether or not you want to generate such events for logging.

System Profiler event filter dialog

The data logged with events comes in the following modes:

Fast mode
A small-payload data packet that conveys only the most important aspects of the particular event. Better for performance.
Wide mode
A larger-payload data packet that contains a more complete event definition, with more context. Better for understanding the data.
Class Specific
This mode lets you select Disable (no data is collected), Fast, Wide, or Event Specific for each of the following event classes:

Choosing Event Specific lets you select Disable, Fast, or Wide for each event in that class.

Depending on the purpose of the trace, you'll want to selectively enable different tracing modes for different types of events so as to minimize the impact on the overall system. For its part in the analysis of these events, the IDE will do its best to work with whatever data is present. (But note that some functionality may not be available for post-capture analysis if it isn't present in the raw event log. ;-))

Viewing and interpreting the captured data

Once an event file is generated and transferred back to the development host for analysis (whether it was done automatically by the IDE or generated by using tracelogger and manually extracted back to the IDE), you can then invoke the System Profiler editor.


Note: If you receive a "Could not find target: Read timed out." error while capturing data, it's possible that a CPU-intensive program running at a priority the same as or higher than qconn is preventing qconn from transferring data back to the host system.

If this happens, restart qconn with the qconn_prio= option to specify a higher priority. You can use hogs or pidin to see which process is keeping the target busy, and discover its priority.


The IDE includes a custom perspective for working with the System Profiler. This perspective sets up some of the more relevant views for easy access.

The System Profiler editor

In order to start examining an event file, the easiest way is to name it with a .kev (kernel event) extension. Files with this extension are automatically bound to the System Profiler editor.

The System Profiler editor is the center of all of the analysis activity. It provides different visualization options for the event data in the log files:

System Profiler editor

CPU Activity presentation
Displays the CPU activity associated with a particular thread of process. For a thread, CPU activity is defined as the amount of runtime for that thread. For a process, CPU activity is the amount of runtime for all the process's threads combined.
CPU Usage presentation
Displays the percent of CPU usage associated with all event owners. CPU usage is the amount of runtime that event owners get. CPU usage can also be displayed as a time instead of a percentage.
Element Activity presentation
Displays CPU usage for an individual selected process or thread.
Timeline presentation (the default)
Displays events associated with their particular owners (i.e. processes, threads, and interrupts) along with the state of those particular owners (where it makes sense to do so).

The Timeline presentation is the default. To choose one of the other types, right-click in the editor, then select Display-->Toggle. Then choose one of:

For displays other than the Timeline, you can display the data using your choice of graph by right-clicking the graph and choosing Graph Type. Select one of the graph types from the list:

3D versions of the graphs are also available, with the exception of the Pie Chart which has no 3D version.

Each of these visualizations is available as a "pane" in a stack of "panes." Additionally, the visualization panes can be split -- you can look at the different sections of the same log file and do comparative analysis.

All panes of the same stack share the same display information. A new pane inherits the display information of the previous pane, but becomes independent after it's created.

To split the display, right-click in the editor, then select Display-->Split. Note that you can lock two panes to each other. From the Split sub-menu, choose the graph you want to display in the new pane:


Note: You can have a maximum of four panes.

A number of different features are available from within the editor:

Event owner selection
Clicking on event owners will select them in the IDE. These selected event owners can then be used by other components of the IDE (such as Filters and Find).

If an owner has children (e.g. a parent process with threads), you'll see an plus sign beside the parent's name. To see a parent's children, click the plus sign (or press Shift-E to expand all owners, and Shift-C to collapse).

Filters
Event owners and specific events can be filtered out using the Event Owner Filters and Event Filters items in the right-click (context) menu. You can use this filtering feature to significantly cut down on the unwanted event "noise" in the display. Once filtered, the log file can be saved as a new log file (using Save As) to produce a smaller, more succinct log file for further examination.

For example, to view only processes that are sending pulses, right-click in the timeline, then select Event Owner Filters-->Show Only-->MsgSend Family.

Find
Pressing Ctrl-F (or selecting Edit-->Find/Replace) will open up a dialog that lets you quickly move from event to event. This is particularly useful when following the flow of activity for a particular event owner or when looking for particular events.
Bookmarks
You can place bookmarks in the timeline editor just as you would to annotate text files. Press the B key to add a bookmark, or right-click in the editor and choose Bookmark from the menu.

These bookmarks show up in the Bookmarks view and can represent a range of time or a single particular event instance.

Cursor tracking
The information from the System Profiler editor is also made available to other components in the IDE such as the Trace Event Log and the Trace Event Statistics views. These views can synchronize with the cursor, event owner selections, and time ranges, and can adjust their content accordingly.
IPC representation
The flow of interprocess communication (e.g. messages, pulses) is represented by a vertical arrow between the two elements.

You can toggle IPC tracing on/off by pressing I or clicking this button in the toolbar:

IPC tracing button

Display Event Labels
The Display Event Labels button in the toolbar (Display Event Labels) toggles kernel event labels. I/O events, memory events, etc. are all given labels when this is enabled:

Display Event Labels

Types of selection

Within the editor, you can select either of the following:

Elements

To select a single element, simply click the element's name. To unselect an element, press and hold the Ctrl key, then click each selected element's name.

To select multiple elements, press and hold the Ctrl key, then click each element's name.

Time

To select a point in time, click an element on the timeline.

To select a range, click the start point on the timeline, then drag and release at the end point.

Or, select the start point, then hold down the Shift key and select the end point.

Zooming

When zooming in, the display will center the selection. If a time-range selection is smaller than the current display, the display will adjust to the range selection (or by a factor of two).

When zooming out, the display will center the selection and adjust by a factor of two.

When using a preset zoom factor (100% to 0.01%), the display will center the current selection and adjust to the new factor.

There are various ways to zoom:

Scrolling

You use these keys to scroll through time:

To move: Use this key:
The selection to the left by one event. <--
The selection to the right by one event. -->
The display to the right by one page (horizontal scrollbar thumb size). Shift--->
The display to the left by one page (horizontal scrollbar thumb size). Shift-<--
The display to the beginning of the timeline. Shift-Home
The display to the end of the timeline. Shift-End

You use these keys to scroll through elements:

To move the display: Use this key:
Up by one element. /\
Down by one element. \/
Up by one page (horizontal scrollbar thumb size). Page Up
Down by one page (horizontal scrollbar thumb size). Page Down
To the top of the element list. Home
To the bottom of the element list. End

Hovering

When you pause your mouse pointer over an element or an event, you'll see relevant information (e.g. PID, timestamps, etc.).

Other views in the System Profiler

There are a number of additional components outside of the editor that you can use to examine the event data in more detail:

Trace Event Log view
This view can display additional details for the events surrounding the cursor in the editor. The additional detail includes the event number, time, class, type as well as decoding the data associated with a particular event.

System Profiler Trace Event Log

Trace Search panel
Invoked by Ctrl-H (or via Search-->Search...), this panel lets you execute more complex event queries than are possible with the Find dialog.

You can define conditions, which may include regular expressions for matching particular event data content (e.g. all MsgSend events whose calling function corresponds to mmap()). You can then evaluate these conditions and place annotations directly into the System Profiler editor. The results are shown in the Search view.

Unlike the other search panels in the IDE, the Trace Search panel can search for events only in the currently active System Profiler editor. You use this search panel to build conditions and then combine them into an expression. A search will iterate through the events from the active log file and be applied against the expression; "hits" appear in the Search Results view and are highlighted in the System Profiler editor.

By default, the Trace Search panel will return up to 1000 hits. You can change this maximum on the QNX-->System Profiler of the Preferences dialog (Window-->Preferences).

Condition Statistics, Event Owner Statistics, General Statistics views
These views provide a tabular statistical representation of particular events. The statistics can be gathered for the entire log file or for a selected range.
Note: You'll need to click the Refresh button (Refresh) to populate these views with data.

Here's an example of the General Statistics view:

System Profiler General Statistics view

Properties view
Shows information about the log file that was captured, such as the date and time as well as the machine the log file was captured on.

[Previous] [Contents] [Index] [Next]