System Analyzer Tutorial 3A

System Analyzer Tutorial 3A: Real-time visibility for SysBios

Configuring ti.uia.sysbios.LoggingSetup, running the Stairstep program on the simulator

SysBios ships with built-in software instrumentation that provides real-time visibility into the operation of your application. In Tutorial3A, we'll focus primarily on how to configure SysBios to log events associated with task switching and semaphores and how to view the events that are logged.

• How to build Tutorial 3A

The ti.uia.sysbios.LoggingSetup module

In the .cfg files for tutorials 1 and 2, we explicitly created loggers and configured Diags masks in order to put in place the infrastructure needed to log events. If you are using SysBios, the ti.uia.sysbios.LoggingSetup module can handle the low-level details associated with creating loggers and configuring SysBios instrumentation options for you. This module is different than the ones we've looked at so far, in that there is no .c code associated with it - it is a 'metaonly' module that executes the LoggingSetup.xs javascript code at configuration time, taking care of much of the 'boilerplate' work involved in enabling real-time instrumentation events to be logged and uploaded.

Let's take a look at the .cfg file that was added to your Tutorial3 project:

The above configuration code does the following:

• Specifies how the events are to be uploaded. In this case, the eventUploadMode is set to UploadMode_SIMULATOR. Other options include UploadMode_JTAGSTOPMODE, UploadMode_JTAGRUNMODE, and UploadMode_NONJTAGTRANSPORT. The NONJTAGTRANSPORT mode is used to specify transports such as Ethernet, and is covered in more detail in Tutorial 3B. Since UploadMode_SIMULATOR is used here, the LoggingSetup module will use instances of LoggerProbePoint to capture events.
• Specifies the size of 3 different loggers: one for logging CPU load information, one for logging events from non-XDC code (represented by the Main module), and one for logging SysBios events such as task switching events. The reason there are separate loggers by default for each of these types of events is so that important events from user application code, or significant events from sysbios are not dropped because the circular buffers used to store the events are full of CPU load events. Separating them out allows you to 'tune' your configuration to maximize the number of events you can capture while minimizing the amount of memory you need to reserve for these circular buffers.

In addition to what is shown in this .cfg file, you can also configure the types of SYS/BIOS events that are logged and sent to System Analyzer:

• Load events (i.e. logging the processor utilization over time) are enabled by default for CPU, Task, Swi, and Hwi threads. As a result, information about loads for those items is available in the CPU Load and Task Load features.

• e.g. LoggingSetup.loadLogging = true; //(default = true)
• You can control the frequency that load events are logged with the following configuration code:

• var Load = xdc.useModule('ti.sysbios.utils.Load');
• Load.windowInMs = 100; // configure to log every 100ms instead of the default period of 500ms.
• CAUTION: logging load events at a high frequency can cause a large number of events per second to be logged, leading to dropped events and slowdowns in the handling and processing of the event data.

• Sysbios events (used to display the Execution Graph) are enabled by default only for Task threads.

• You can configure whether load events for Task, Swi and Hwi threads are logged using the configuration code shown below:
• e.g. LoggingSetup.sysbiosTaskLogging = true; //(default = true)
• e.g. LoggingSetup.sysbiosSwiLogging = true; //(default = false)
• e.g. LoggingSetup.sysbiosHwiLogging = true; //(default = false)

• Main module events (used to log events from non-XDC modules and from the Main module) is enabled by default

• e.g. LoggingSetup.mainLogging = true;

Another thing that isn't shown is that a LoggerStopMode logger (named the "overflowLogger") that is used to 'catch' any events that would otherwise be dropped due to the original logger's buffer being full. The overflow logger ensures that you will always capture the events that were logged leading up to a breakpoint being hit. If you are not logging via JTAG, you can set LoggingSetup.overflowLoggerSize = 0 to save memory.

Other LoggingSetup configuration options allow you to specify whether or not the various types of logging can be controlled at runtime, use logger instances that you have configured yourself instead of having LoggingSetup create them for you, etc.

For more information on how to use UIA and SysBios together, the LoggingSetup module and the various upload modes, please see section 5 of the System Analyzer User's Guide (spruh43b)or search for LoggingSetup in CCS Help. The various configuration parameters that can be applied to the LoggingSetup module are also provided in the UIA CDoc documentation (open <UIA install folder>/docs/cdoc/index.html and browse to ti/uia/sysbios/LoggingSetup.)

A Brief Summary of some of the SysBios Events
(See the SysBios CDocs for the most up-to-date info)

Module Name	Event Name	Usage	Diags Masks	LoggingSetup config
ti.sysbios.knl.Task	LM_switch	Logged on every task switch	Diags.USER1 or Diags.USER2	LoggingSetup.sysbiosTaskLogging = true
ti.sysbios.knl.Task	LM_sleep	Logged on calls to Task_sleep	Diags.USER1 or Diags.USER2	LoggingSetup.sysbiosTaskLogging = true
ti.sysbios.knl.Task	LD_ready	Logged when a task is made ready to run (ie Semaphore_post())	Diags.USER2	LoggingSetup.sysbiosTaskLogging = true
ti.sysbios.knl.Task	LD_block	Logged when a task is blocked (ie Semaphore_pend())	Diags.USER2	LoggingSetup.sysbiosTaskLogging = true
ti.sysbios.knl.Task	LM_yield	Logged on calls to Task_yield	Diags.USER1 or Diags.USER2	LoggingSetup.sysbiosTaskLogging = true
ti.sysbios.knl.Task	LM_setPri	Logged on calls to Task_setPri	Diags.USER1 or Diags.USER2	LoggingSetup.sysbiosTaskLogging = true
ti.sysbios.knl.Task	LD_exit	Logged when Task functions fall thru the bottom or when Task_exit() is explicitly called.	Diags.USER2	LoggingSetup.sysbiosTaskLogging = true
ti.sysbios.knl.Semaphore	LM_post	Logged on calls to Semaphore_post()	Diags.USER1 or Diags.USER2	LoggingSetup.sysbiosTaskLogging = true
ti.sysbios.knl.Semaphore	LM_pend	Logged on calls to Semaphore_pend()	Diags.USER1 or Diags.USER2	LoggingSetup.sysbiosTaskLogging = true
ti.sysbios.knl.Swi	LM_begin	The event logged just prior to invoking a Swi's function	Diags.USER1 or Diags.USER2	LoggingSetup.sysbiosSwiLogging = true
ti.sysbios.knl.Swi	LD_end	The event logged just after returning from a Swi's function	Diags.USER2	LoggingSetup.sysbiosSwiLogging = true
ti.sysbios.knl.Swi	LM_post	The event logged when Swi_post() is called	Diags.USER1 or Diags.USER2	LoggingSetup.sysbiosSwiLogging = true
ti.sysbios.family.< >.Hwi	LM_begin	Issued just prior to Hwi function invocation (with interrupts disabled)	Diags.USER1 or Diags.USER2	LoggingSetup.sysbiosHwiLogging = true
ti.sysbios.family.< >.Hwi	LD_end	The event logged just after returning from a Swi's function	Diags.USER2	LoggingSetup.sysbiosHwiLogging = true
ti.sysbios.utils.Load	LS_cpuLoad	This event logs the global CPU load as a percentage when the load is measured	Diags.USER4	LoggingSetup.loadLogging = true
ti.sysbios.utils.Load	LS_hwiLoad	This event logs the Hwi load with the form: <load time>,<measurement time>; Percentage load = <load time> / <measurement time> x 100%	Diags.USER4	LoggingSetup.loadLogging = true
ti.sysbios.utils.Load	LS_swiLoad	This event logs the Swi load with the form: <load time>,<measurement time>; Percentage load = <load time> / <measurement time> x 100%	Diags.USER4	LoggingSetup.loadLogging = true
ti.sysbios.utils.Load	LS_taskLoad	This event logs Task thread loads with the form: <Task handle>,<load time>,<measurement time>,<Task function pointer>; Percentage load = <load time> / <measurement time> x 100%	Diags.USER4	LoggingSetup.loadLogging = true
ti.sysbios.knl.Clock	LW_delayed	Logged if Clock Swi delayed by >= 1 tick	Diags.USER3	e.g. Clocks.common$.diags_USER3 = Diags.RUNTIME_ON;
ti.sysbios.knl.Clock	LM_tick	Logged in every Clock tick interrupt	Diags.USER1 or Diags.USER2	e.g. Clocks.common$.diags_USER1 = Diags.RUNTIME_ON;
ti.sysbios.knl.Clock	LM_begin	Logged just prior to calling each Clock function	Diags.USER1 or Diags.USER2	e.g. Clocks.common$.diags_USER1 = Diags.RUNTIME_ON;

CAUTION: logging hwi and swi events can cause a large number of events per second to be logged, leading to dropped events and slowdowns in the handling and processing of the event data. Use only when necessary, and consider dynamically enabling and disabling logging of the events using the Diags_setMask API (see Tutorial 1C for more info).

IMPORTANT: When adding UIA to an existing project (e.g. a project originally created from a SysBios example project template), you must ensure that the .cfg configuration script for your project does NOT contain any lines that call "xdc.useModule('xdc.runtime.LoggerBuf');". The LoggerBuf module is a legacy module that is not supported by UIA or System Analyzer. Using this module will pull in the ti.sysbios.rta.Agent module, which will create LoggerBuf instances and overwrite the configuration of the loggers for the SysBios modules so that these LoggerBuf instances are used instead of the UIA logger instances.

Running Tutorial 3A

• How to run Tutorial 3A

What you should see

The Log view should open up and periodically (e.g. every 20 seconds or so) a new set of events should be added to the log view. Click on the "Auto-fit columns" button to adjust the width of the columns to display all of the message text. (Note that it typically takes hours for the simulator to generate enough event data to show anything of interest on the Task Load graph. We'll look at the execution graph and task load graph in Tutorial3C).

Filtering out SysBios events in the System Analyzer Logs view

Due to the high number of events that can be logged by the SysBios instrumentation, it can be difficult to spot the events logged by the application code in the System Analyzer Logs view. This can be addressed by filtering the events so that events logged by SysBios are not displayed in this view. (They are still available for use by other System Analyzer views and graphs, however). To filter out SysBios events from the Logs view, click on the button in the Logs view toolbar menu, and configure the filter's Use Field tab as shown below:

Click on the "Filter" button and then close the Filter Dialog. The filter button in the toolbar will now appear as if it is 'pressed in' to indicate that the filter is active: .
A red dashed line will be displayed in the Logs view at points in the list of events where events have been filtered out.

Going Further: How to have Analysis tables and graphs display the names of tasks created at run time

If your application dynamically creates tasks while it is running, System Analyzer will, by default, use the hex value of the task handle to identify the task in Analysis views such as the Execution graph and Task Load graph. The SysBios Task "createFxn" hook function can be used to call the UIA LogSnapshot_writeNameOfReference API whenever a task is created so that the name of the task can be logged. This will allow System Analyzer to show the task name in the Analysis views instead of the hex task handle ID. Here's how:

1) Assigning a name to a dynamically created task:

#include <ti/sysbios/knl/Task.h>

#include <xdc/runtime/Error.h>

...

Task_Params taskParams;

Error_Block eb;

// Create a task with priority 15 named “myInstance”

Error_init(&eb);

Task_Params_init(&taskParams);

taskParams.stackSize = 512;

taskParams.priority = 15;

taskParams.instance->name = "myInstance";

Task_create((Task_FuncPtr)myDynamicTask, &taskParams, &eb);

2) To log task names as they are created, add the following C code function to your project...:

#include <ti/uia/runtime/LogSnapshot.h>

#include <xdc/runtime/Error.h>

#include <ti/sysbios/knl/Task.h>

#include <string.h> // for strlen

Void tskCreateHook(Task_Handle hTask, Error_Block *eb);

...

// Log the task name.

// Notes: Task name is not required when creating a BIOS task. Please make sure

//a name is provided in order for the host side analysis tool to work properly.

Void tskCreateHook(Task_Handle hTask, Error_Block *eb) {

String name;

name = Task_Handle_name(hTask);

LogSnapshot_writeNameOfReference(hTask,"Task_create: handle=%x",name,strlen(name)+1);

}

and add the following to your project's .cfg file:

var Task = xdc.useModule('ti.sysbios.knl.Task'); // add if not already in the .cfg file

var LogSnapshot = xdc.useModule('ti.uia.runtime.LogSnapshot');

/* Add hooks for UIA to monitor task creation and task switches */

Task.addHookSet ({ createFxn: '&tskCreateHook', });

Next: Tutorial 3B: Configuring the NDK to enable UIA to use Ethernet as a Transport

Links:

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