Profiler Inspectors

<< Click to Display Table of Contents >>

Navigation:  Analyzer > Profiler Analysis >

Profiler Inspectors

Profiler Inspectors allow the creation of new areas in the profiler timeline. Any existing data in the profiler timeline can be used to derive Inspector areas. The idea of profiler Inspectors is to create new objects whose state changes depending on states, state transitions, values, and timing characteristics of other objects. They are then treated like any other profiler areas, which can be used to derive statistics, export...

 

Before the configuration of Inspectors is explained, a simple example is given to provide some intuition about how Inspectors can be used. On the screenshot below, a simple OS task trace is shown in the profiler timeline. There are five task objects each running at different points in time as indicated by the red block in the respective area of each task. Profiler statistics use this information to calculate timing properties for each object in the profiler timeline.

ProfilerInspectors-ExampleTasks1

However, once the relation between multiple objects in the timeline is of interest statistics are not longer sufficient. For example, the information about how much time passes between the termination of OsHighPrioEthTask till the start of OsLowPrioMemTask is not available by default. For a single occurrence this can measured with winIDEA profiler markers. As soon as a user is interested in the delta time for every occurrence of the OsHighPrioEthTask a new approach is required and this is an example where profiler Inspectors can be utilized.

On the following screenshot the exact same trace is visualized. This time with another object called HighToLowPrio, which is an Inspector object as indicated by theProfilerInspectors-FilterIconsymbol. The Inspector has two states default and delta. Initially, the Inspector is in the default state. Once OsHighPrioEthTask becomes inactive the Inspector switches into the delta state. Then, when the OsLowPrioMemTask starts the Inspector switches back into the default state. With this approach it is possible to measure the delta between the tasks for each occurrence in the timeline.

ProfilerInspectors-ExampleTasks1InspectorArea

The Inspector area now shows the delay between the events of interest and can be used to derive further statistics. Please refer to the Inspector Examples chapter for more in-depth examples.

 

Inspector Configuration

To start working with Inspectors use the Inspectors button ProfilerInspectors-InspectorsButton in the winIDEA profiler timeline toolbar. This opens the Inspectors dialog which provides the following options:

ProfilerInspectors-ListOfInspectors

  • Add - Create a new Inspector from scratch.
  • Edit - Edit the selected Inspector.
  • Remove - Remove the selected Inspector.
  • Create copy - Copy the selected Inspector; can be used to create a similar Inspector area quickly.
  • Import - Import Inspectors saved in the Inspector JSON format.
  • Export - Save selected Inspectors in the Inspector JSON format.

 

 

Creating a new Inspector area

Describe the Inspector you would like to create. Give it a name, which will be used to show it in the profiler analysis.

If you would like to show the Inspector as a standalone item in the profiler, enable the Visible checkbox. Alternatively, the Inspector will be shown in the parent elements only.

 

ProfilerInspectors-InspectorConfiguration

 

Parents

ProfilerInspectors-ParentConfiguration

Inspectors introduce new areas into the profiler timeline. With parents it is possible to specify where the Inspector areas are shown. By default, if parents is left empty, Inspectors are shown under the Data window. Alternatively, a parent area can be provided to define where the Inspector is shown. It is possible to specify multiple parents and a wildcard “[]” can be used to show an Inspector under all areas of a certain area. For example, a parent “Data/Tasks[]” would mean that the Inspector is shown under all task areas.


Events

ProfilerInspectors-EventConfiguration

Inspectors work like a state machine. This means there are state like objects states and variables; and there are events which trigger state transitions which are called events and time constraints. Events are triggered based on existing areas in the profiler timeline.

Warning40x40

Existing Inspectors qualify as an existing area and can therefore be referenced as well.

  • Name specifies the event name which can be referenced in formulas for states, time constraints and variables.
  • Area is the profiler area which will be observed.
  • Type and Trigger specify on which attribute of an existing area the event should depend.
    • Data is used to trigger on a value change of an area. The only trigger is Write.
    • Event is used to trigger on a state transition of a block area. The Trigger types are Entry, Exit, Suspend, and Resume.
    • State is used to trigger on the current state of a block area. Possible states are Active, Inactive, and Suspend.
  • Formula (only for Data Type): Event output will be true when formula will be true, if formula is empty event will be set to true for every data write. Formula supports the following operators: &&, ||, <=, >=, !=, ==, >, <, +, -, *, /
    • Formula example: ($(VALUE) > 4.9) && ($(VALUE) < 5.1)

Time constraints

ProfilerInspectors-TimeConstraintConfiguration

Time constraints are similar to events in the sense that they also trigger on certain conditions. The difference is that that it introduces a time component into the evaluation formula. This means a time constraint can, for example, be triggered a certain amount of time after another event has been triggered.

  • Name specifies the time constraint name which can be referenced in formulas for states and variables.
  • Formula defines whether the time constraint is active (if the formula evaluates to true) or not.

The formula accepts a special macro $(TIME) which represents the current point on the profiler timeline. Also it is possible to reference other events. If the referenced event is a state transition than the event is replaced with the timestamp at which the event has occurred the last time. If the referenced event maps to a certain state then the event is replaced with the duration for which the specific state has been active. All values in the formula are provided in nanoseconds.

 

Consider the use-cases in the following table and the respective example to get a better understanding of how timing constraints work. Check the Task Deadline example for more elaborate explanation.

Use-case

Example

Timing constraint triggers when the event FuncActivatedEvent  is true and the absolute timestamp is greater or equal to 1000 nanoseconds.

FuncActivatedEvent >= 1000

Timing constraint triggers when more than 1000 nanoseconds have passed since FuncEntryEvent.

($(TIME) - FuncEntryEvent) > 1000

Timing constraint triggers when more than 1000 nanoseconds pass between the occurrence of Func2ExcitEvent and Func1EntryEvent.

(Func1EntryEvent - Func2ExitEvent) > 1000


States

ProfilerInspectors-TransitionConfiguration

While events and time constraints are used to detect certain conditions in the profiler timeline, states generate the visible Inspector output. Each state is displayed as a child area of the Inspector itself (provided it is configured as visible). The following options are available for each state.

  • Name is the name of the state.
  • Visible specifies whether the state is visible in the profiler timeline.
  • Transitions lists the possible transitions from the current state.

Note that it is necessary to specify a default state in the main Inspector dialog. Only one state can be active at a certain point in time. Each state can have an arbitrary number of Transitions. Each transitions has the following fields:

  • Name of the state to which the Inspector will go when formula is true.
  • Formula that triggers a state transition. A formula can reference events, time constraints, and variables. It supports the  following operators: &&, ||, <=, >=, !=, ==, >, <, +, -, *, /
    Examples:
    • (Event1 && Event2) || Event3
    • (IRQCount + Func1Count) >= 10
  • Suspend indicates that the current state is suspended and not exited on the transition.

Variables

ProfilerInspectors-VariableConfiguration

Variables can be modified when an event occurs. They can be used to output numerical values on the profiler timeline or serve as arguments in state transition formulas. In the variable configuration dialog the following options are available.

  • Name of the variable.
  • Visible specifies if the variable is shown in the Profiler Timeline as a regular variable under the Inspector.
  • Default value specifies the initial value of the variable.
  • Evaluate is a list of events on which the variable is updated. For each event a formula is used to calculate the new value of the variable.

A variable changes its value upon defined events. For each event that is mapped to a variable a formula is provided. As soon as a certain event is triggered the respective formula is evaluated and the result is assigned to the variable. The formula can contain other variables and also other events which either evaluate to true or false. If an event is of type Data it is possible to reference its value with the syntax $(DataEvent:=VALUE). Numerical values can be entered as 123 or -123, 1.23, or 0x123. In case a decimal value is entered, it is treated as signed 64 bit, a float  value is treated as 64 bit double and hex is unsigned 64 bit. Formulas support the following operators &&, ||, <=, >=, !=, ==, >, <, +, -, *, /.

 

Example

Formula

Increment the value of myVariable by one.

myVariable + 1

Assign the sum of the current trace values which are referenced by Data2 and Data1  to the variable.

$(Data2:=VALUE) + $(Data1:=VALUE)

 

Inspector Examples

This section contains example Inspectors and works through their configuration in full detail to give a starting point for user defined Inspectors.

 

Delta Time between two Runnables

ProfilerInspectors-DeltaTimeBetweenTwoRunnablesExample1In this example we implement an Inspector which represents the delta time between the termination of the runnable R_calculate_B and the start of runnable R_Send2Com.


ProfilerInspectors-DeltaTimeBetweenTwoRunnablesExample2We start by creating a new Inspector called RunnableDelta. The first step is to define the events that change the state of our Inspector. Since we want to measure the time between the termination of R_calculate_B and the start of R_Send2Com it is reasonable to create those two events which we will simply call terminate and start. The areas which we reference are called Code/<name_of_runnable> and the type is Event which allows to reference the respective state transitions exit and entry. Our event window should now show the created events.


ProfilerInspectors-DeltaTimeBetweenTwoRunnablesExample3Next we have to define a state machine that emphasizes the delta we are interested in. So in general we have two states:

  • a default state that is not really important and then there is
  • a delta state that is active exactly during the time period we are interested in.

We start in the default state. Our state configuration should now look like this.


ProfilerInspectors-DeltaTimeBetweenTwoRunnablesExample4The last step is to add the necessary state transitions. We want to switch from default to delta on the terminate event and switch back one R_Send2Com starts as indicated by the start event. The following screenshot shows the final configuration and the configuration of the default state.


ProfilerInspectors-DeltaTimeBetweenTwoRunnablesExample5Now it is time to close the Inspector dialogs and observe the result in the profiler timeline.

As expected our Inspector starts in the default state and changes to delta exactly for the time period we expect. The same behavior can be observed for any other occurrence of R_calculate_B in the trace.

 

Task Response Time

ProfilerInspectors-TaskResponseTimeExample1In this example we measure the response time of a task using an Inspector. The response time is the time from the activation of a task (entry into the NEW state) till the termination (entry into the SUSPENDED state).

 

ProfilerInspectors-TaskResponseTimeExample2We start by creating a Inspector RT_T_10MS_0 with the events activate and terminate, and the states default and ResponseTime. We use the parent window to display the Inspector as a child of the task for which we want to see the response time.

 

ProfilerInspectors-TaskResponseTimeExample3The following screenshot shows the configuration of the activate event.

 

The rest of the event and state configuration is left as an exercise for the user. The resulting configuration should look similar as to what is shown on the following screenshot:

ProfilerInspectors-TaskResponseTimeExample4

 

ProfilerInspectors-TaskResponseTimeExample5In this example only the state ResponseTime which is of interest for the analysis is set to visible. The result can be seen on the following screenshot.

 

Task Deadline

In this example the ResponseTime area from the previous example is used to specify a deadline requirement. This means we specify a maximum duration for the ResponseTime. If the duration stays under this value nothing happens. If the duration exceeds the maximum value the Inspector changes into a violation state. The Inspector switches back to default from violation once the ResponseTime area exits. This means an occurrence of the violation area does not only tell us that a violation has occurred, but also how long the violation was.

ProfilerInspectors-TaskDeadlineExample1For this Inspector we need three states and three events. The states are default, responding, and violation. The events are activate, terminate, and violate. The first two events are entry/exit events and the latter is a time constraint. In this case it makes sense to define the activate and terminate events on the ResponseTime area from the previous example. This has the advantage that, if the indicators for the task activation or termination change, only one Inspector has to be adapted.

 

ProfilerInspectors-TaskDeadlineExample2The last event violate is a time constraint. In this example we assume a deadline of 2 ms (2000000 ns). With that said the respective time constraint looks as follows.

 

To understand how the constraint works imagine a pointer running up the profiler timeline. The symbol $(TIME) references the timestamp at the current position of the pointer. The symbol activate references the activate event and evaluates to the timestamp of the previous (earlier) occurrence of the activate event relative to the pointer. This means the time constraint is false within 2 ms after each activate event and true afterwards.

ProfilerInspectors-TaskDeadlineExample3Next the state machine is configured with respect to the defined events. The Inspector starts in the default state. Once the task is activated as indicated by the activate event the Inspector changes into responding. From responding there are two possible state transitions. If the violate event triggers the Inspector changes into the violation state. If no violate occurs the Inspector goes back into the default state on the terminate event. If a transition to violate occurs the change back to default is also triggered on terminate. This leaves us with the following state configuration.

 

ProfilerInspectors-TaskDeadlineExample4Finally, we only make the violate state visible and select the response time Inspector as the parent element. This yields the following result in the profiler timeline. There are two occurrences of the T_10MS_0 task. The first occurrence is preempted and consequently violates the deadline. The second occurrence fulfills the deadline and no violation is indicated.

 

CPU Utilization

An important metric in the analysis of embedded applications is the CPU idle time. The idle time is the amount of time the CPU is not busy. If the operating system has an idle task the idle time is simply the amount of time the idle task is running. If no idle task is available in the trace it can be derived via an inspector instead. This works by creating an inspector that is active whenever no task or ISR is running and inactive in the opposite case.

Keep in mind that certain OS functions like task context switches are performed outside the context of tasks or ISRs. This means strictly speaking the time derived by the inspector does not represent the idle time, but the idle time plus time spent in OS functions.

ProfilerInspectors-ExampleCPUUtilization1

To illustrate the configuration of an idle time inspector we use a task trace with three tasks called WriteCode, EatPizza, and OrderPizza. We create an inspector CpuUtilization which has two states CpuRunning and CpuIdle.


ProfilerInspectors-ExampleCPUUtilization2The aim is to go into CpuRunning state whenever any tasks becomes active and go into CpuIdle whenever any tasks becomes inactive. Currently, there is no wild card mechanism allowing the selection of all tasks. Therefore, an entry and exit event have to be created for each task individually which yields the following configuration.


ProfilerInspectors-ExampleCPUUtilization3Now the state transition from CpuRunning to CpuIdle is defined by combining all exit events with a logical or.


ProfilerInspectors-ExampleCPUUtilization4The transition from CpuIdle to CpuRunning is done  by combining all entry events with a logical or.


ProfilerInspectors-ExampleCPUUtilization5With this step the configuration of the CpuUtilization inspector is finished and the result can be viewed in the profiler timeline. As expected the inspector is in the CpuIdle state when no task is active and in CpuRunning when any task is active. The spikes during the task changes have a duration of zero and do not affect the resulting metrics.


ProfilerInspectors-ExampleCPUUtilization6The CPU Idle Time can now be retrieved by right clicking CpuIdle and selecting properties. The Net Time metric is the total idle time for the duration of the trace (orange). The total trace time can be seen on the upper right corner of the profiler timeline window (green). In this example the idle time is about 684 ms and the trace duration 2000 ms. This results in a CPU utilization of ((2000 - 684) ms / 2000 ms) which is 65.8% or an idle percentage of 34.2%.