SystemAnalyzerTutorial1B

System Analyzer Tutorial 1B

How to benchmark your application code so that you can see how long it takes to execute code on a running system

This tutorial demonstrates the use of UIABenchmark events to measure the performance of application code as the code runs in a live system. Let's start by running Tutorial 1B (see the Getting Started page for how to build and run the tutorials.).

After you have run Tutorial 1B, the System Analyzer Log View should display the UIABenchmark events that were logged.

• To make it easier to read the event data, please click on the AutoFit button in the System Analyzer Log View toolbar.

The table should now look something like this:

If you can, it will be helpful to look at the tutorial1b.c file in an editor.

Measuring how long it takes to write a string using printf

The code:

The UIABenchmark_startInstanceWithStr and UIABenchmark_stopInstanceWithStr events are described in the "CDoc" documentation that ships with the UIA package. To read the documentation, open <UIA install dir>/docs/cdoc/index.html and open ti / uia / events / UIABenchmark, or search for UIABenchmark using CCS online help.

The events contain 3 parameters:

• fmt — a constant string that provides format specifiers for up to 5 additional parameters
• instanceId — a unique instance ID that is used by System Analyzer to match benchmark start and stop events
• str — a constant string reference that is used by System Analyzer to match benchmark start and stop events

In the example code, an instanceId of 1 is used along with the string "printf" to uniquely identify the start and stop events used for benchmarking the printf API. This information will be used by the Duration analysis to uniquely identify which start and stop events should be used together in order to evaluate the elapsed time. Typically, the instance Id can be something like a task handle, frame number, etc. and the constant string parameter can be used to 'tag' the start / stop event pair with a name indicating what is being measured. Note that the instanceId and str parameters for both the start and stop events MUST BE IDENTICAL in order for the analysis to work properly. Be careful to make the case of each letter in the string the same, and avoid adding leading or trailing spaces in the string.

The events in the Log View:

Interpreting the data:

The Time column of the Log View shows the event timestamp value in nano-seconds, measured from the time the target's CPU timestamp timer started running until the time the event was logged on the target. The elapsed time between two successive events can thus be determined by subtracting the timestamp time of the an event from the timestamp time of the previous event.

Note that the elapsed time between any two events will include such things as the overhead introduced by servicing interrupts, task switches, the code to log the event, etc.

Measuring how long it takes to write a string using sprintf

The code:

The events in the Log View:

Measuring how long it takes to call the Log_write3 API

The events in the Log View:

Comparing the Measurements

System Analyzer's Duration view automatically pairs up the start and stop events and displays the elapsed time between the paired up events in a table view. To open the Duration view, right click on the Log view and select Analyze -> Duration.

From this, you can see that using printf takes the most time to execute (4468 ns), sprintf takes 1445ns and the XDC Log_write3 used by UIA takes 129 ns to execute. For this target, the CPU timestamp clock speed is 1GHz, so the number of cycles it takes to execute these APIs is equal to the number of nanoseconds. If the CPU timestamp clock speed was not 1GHz, you can convert the duration from nanoseconds to cycles by multiplying by the CPU timestamp clock speed in Hz. divided by 1GHz. You can determine the CPU timestamp clock speed by opening up Tools -> System Analyzer -> Live and dividing the displayed CPU Speed (MHz) by the "Cycles per tick" value.

Improving performance: compile options

We can see from the Duration view, that, in the Debug version of the Tutorial1 application, the Log_write3 API takes 129 cycles to log an event. Let's see if we can reduce the number of cycles it takes by building the Release version of Tutorial1. To do that, go to the CCS Edit perspective, right click on the Tutorial1 project and select Build Configurations->Set Active->Release.

Then build the project (e.g. right click on the project and select Build Project. Then load in the release version of the project into the simulator.

At this point, it is important to realize that the System Analyzer (if it is still active), has loaded the symbols and metadata associated with the Debug version of the project, and, if left 'as-is' will display and interpret any subsequently received events using this out-of-date symbol and metadata information. To clean things up, we need to "Remove" System Analyzer and start it again in order to load in the symbols and metadata for the Release version of the project. To remove System Analyzer, either click on the red X in the LogView's toolbar or select Tools->System Analyzer->System Analyzer Live Session->Remove as shown below:

Let's now re-run Tutorial1B using Scripts -> McsaTutorial1 -> Tutorial1B_Benchmarking. The LogView should now show something like the following:

Now, we can run the Duration analysis to generate the following table:

You can see from this that we've reduced the overhead associated with the Log_write3 API from 129 cycles to 99 cycles by changing from Debug to Release.

Another thing that is apparent is that the overhead associated with logging the event is included in the duration analysis results, and this must be manually subtracted from the duration in order to understand how many cycles a particular piece of code takes to execute. (An option to automatically calculate this overhead and compensate for it in the duration analysis results is being considered for inclusion in a future release of System Analyzer.) In Tutorial 1C, we'll look at how to configure your application to always log events, turn off event logging completely, or to enable event logging to be dynamically controlled by software.

Next: Tutorial 1C: how to control which events in your application are enabled and disabled

Links:

• Tutorial 1A: How to instrument your application code to log errors, warnings, and informational events
• Tutorial 1C: how to control which events in your application are enabled and disabled
• Tutorial 1D: How to upload the contents of dynamically allocated strings so that references to them can be displayed as text

• Back up to the System Analyzer Tutorials page
• Back up to the System Analyzer Home