Use RTOS Event Logging to do Real-Time Systems Analysis -

Use RTOS Event Logging to do Real-Time Systems Analysis


Leading-edge real-time operating systems (RTOSes) offer powerfulmultitasking features such as the ability to make rapid context changesbetween threads and support for many thread priority levels.

While this makes it possible to more easily provide real-timecontrol, these capabilities create the potential for considerablecomplexity in the way that threads share resources. As a result,real-time applications are often difficult to understand and even moredifficult to optimize.

Real-time applications, and the RTOSes they run on, can helpdevelopers discover, analyze and correct some of the most difficultsystem problems to find. They can do this by logging records of eventsthat occur during execution of the application, and inside the RTOS asservices that are provided.

Such logging provides the capability to see clearly the occurrenceof system events such as interrupts and context switches that occur outof view of standard debugging tools.

The ability to identify and study these events and pinpoint theirtiming in the context of the overall system's operation enablesdevelopers to identify bugs in less time and to optimize multitaskingbehavior.

The traditional approach to systemevent analysis
Real-time programmers have long understood the importance of systembehavior to the functionality and performance of their applications.The conventional approach to address these issues is to instrument thecode by leaving “bread crumbs” that will generate data on systembehavior when the code reaches a certain stages such as toggling an I/Opin, using printf, setting a variable or writing a value to a file.

Inserting such responses can require a considerable amount of time,especially when you consider that the instrumentation code oftendoesn't work exactly as expected the first time around and itself hasto be debugged.

Once that part of the program is verified, the instrumentation codeneeds to be removed and its removal also needs to be debugged. Sincemuch of the instrumentation process is manual, the process istime-consuming and prone to additional errors.

Besides instrumenting the code, the developer also needs to find away to interpret the data that is generated. Due to the volume ofinformation generated by the instrumentation code, gaining anunderstanding of what system events have transpired, and in whatsequence, can be challenging in itself.

A few commercial RTOSes address these concerns by offering toolsthat assist in the capture and interpretation of system events.Generally, these tools enable creation of a log of events during systemoperation and the graphical display of that log on the host, and assistin giving developers visibility into the behavior of their system.

One weakness of many of these tools, though, is that they typicallyare available only as an element of an overall integrated toolset,which is often very expensive to buy and may duplicate other hostdevelopment tools already in use.

Most system event analyzers also tend to be inflexible in the waythat they manage the buffer that stores the log of system events. Theytypically write to only one specific trace buffer and the buffer cannotbe turned off or back on by the application, thereby risking the lossof events of interest, or saturating the buffer with useless clutter.

Figure1: Express Logic's TraceX offers a graphical view of real-time systemevents. In this example, you can see the initialization process andearly execution of the application program.

Most of these programs present trace events graphically, on multiplelines, representing the various threads in the program, system routinessuch as interrupt handlers, initialization code, etc., and the user mayhave to do a considerable amount of scrolling up and down to see all ofthe captured events.

And, since developers generally get information on events byclicking on an icon representing the event and viewing a pop-up windowwith key event information, they can only view one event at a time.A new approach offers advantages
A new approach to system and application event viewing that avoidsthese weaknesses that are common in similar products can offerdevelopers better access to valuable information.

An effective approach is to provide the user with the opportunity tolog desired application events using an application programminginterface (API). Events are logged in the database under programcontrol with time-stamping and active thread identification so they canbe displayed later in the proper time sequence. These applicationevents join the system events that the RTOS already logs.

To make events available for sequential viewing, trace informationshould be stored in a circular buffer on the target system with buffersize determined by the application. A circular buffer enables the mostrecent “n” events to be stored at all times and to be available forinspection in the case of a system malfunction or other significantevent (see Figure 2 below). Multiple buffers enable distinct “clips” ofsystem behavior that can be analyzed together or separately.

Figure2: Information about the circular buffers used to capture event dataduring execution.

Event logging may be stopped and started by the application programdynamically, such as when an area of interest is encountered. Thisavoids cluttering the database and using up target memory when thesystem is performing correctly.

To enable developers to hone in on specific threads, a system eventanalyzer should make it possible to use multiple trace buffers and toswitch between them when necessary. The trace information may beuploaded to the host for analysis at any time, either when encounteringa breakdown or after the application has finished running.

Once an event log is uploaded from target memory to the host, theevents are displayed graphically. The display on the horizontal axiswhich represents time. The various application threads and systemroutines, to which events are related, are listed along the verticalaxis and the events themselves are presented in the appropriate row.

Solving the problem of too manyrows of threads
All events are presented in a summary row at the top, which providesdevelopers with a handy way to obtain a complete picture of all systemevents without the vertical scrolling that's required in many products.

In all rows, events are represented by color-coded icons, located atthe point of occurrence along the horizontal timeline, to the right ofthe relevant thread or system routine, or all combined in the summaryrow at the top. The horizontal axis may be expanded to show more detailabout events or collapsed to show more events.

When an event is selected, detailed information for that event isshown at the bottom of the display including the context, event, threadpointer, new state, stack pointer, and next thread point.

Information is presented not only for the current event, but alsofor the two events preceding and the two events following the currentevent. This can be very useful in reducing the number of clicksrequired to see details of several successive events.Solving priority inversion problems
An example of the bugs that can be solved more quickly and easily withthis type of tool is the classic priority inversion problem.Priority inversions arise because RTOSs employ a priority-basedpreemptive scheduler that ensures the highest priority thread that isready to run actually runs.

The scheduler may preempt a lower priority task in mid-execution tomeet this objective. Problems can occur when high and low prioritytasks share resources, such as a memory buffer.

If the lower priority task is using the shared resource when thehigher priority task is ready to run, the higher priority task mustwait for the lower priority task to finish. If the higher priority taskmust meet a critical deadline, then it becomes necessary to calculatethe maximum time it might have to wait for all its shared resources indetermining its worst-case performance.

Priority inversions are difficult to identify and correct. Theirsymptom is normally poor performance, but poor performance stems frommany potential causes. Just as troublesome is the potential that thepriority inversion might not be noticeable in testing, which couldcause the application to be non-deterministic.

With a system trace analysis, it is possible to identify and correctpriority inversions. The trace buffer clearly identifies which threadis running at any point in time. So it's easy to go back in time anddetermine whether a higher level priority thread is ready to run.

The next step is typically determining the resource blockage causingthe priority inversion. The normal process is to cycle back on thehigher priority thread to identify the last point in time at which itwas blocked.

Clicking on this event will identify the mutex or semaphore on whichthe high-priority thread is blocked, and can be used to track theownership of the resource and the lower priority event that has takencontrol of the semaphore.

Figure3: This display shows a simple priority inversion, where thread 1 holdsa resource that is needed by thread 0, which is higher in priority.Thus, thread 0 is delayed by a lower priority thread.

The simple priority version shown in Figure 3 above is identified byclicking on the “MP” event (Mutex Put) in the “thread 1″ line.”Selected Event – 2” shows us a planned priority inversion. Thread 0has suspended on “mutex 0” which is owned by the lower priority “thread1”.

This could be an error if the developer did not know that thispriority inversion was possible. More likely, this is a typical case ofdifferent priority threads competing for the same resource (protectedby “mutex 0”).

Figure4. This system snapshot shows a complex priority inversion with mutexpriority inheritance. Thread 0 is still being delayed while it waitsfor a resource owned by a lower priority thread, thread 1. However,priority inheritance prevents the mid-priority thread 2 from runningduring the priority inversion situation.

Figure 4 above shows acomplex priority inversion with mutex priority inheritance revealed byclicking on the “TR” icon (Thread Resume) in the “thread 0″ time-line.”Selected Event – 2” shows the same priority inversion problem as theprevious example.

In this case, the mutex is setup for priority inheritance so thatwhen “thread 0” attempts to get the mutex, “thread 1” temporarilyinherits the priority of “thread 0”.

The effect of this is that although “thread 2” became ready duringthe priority inversion window (inside the “System Timer Thread at theTR icon), it does not run until after the priority inversion is clearedand “thread 0” finishes its processing.

Improving application performance
While most developers will begin using such a tool in order tounderstand and correct problems, a potentially broader benefit can bederived from using the tool to analyze and improve system-levelapplication performance.

As a general rule, the greater the proportion of time spent in theapplication and the less spent on system-level tasks such as contextswitches, the faster the application will run. The system eventanalyzer makes it easy to see at a glance how much time is devoted tosystem activity. The developer can easily drill down on specific eventsfor diagnostic purposes.

For example, a developer might notice that there are a large numberof interrupts caused by the receipt of data packets. The simplest andmost common approach is to simply add each incoming data packet to aqueue.

As the number of packets received increases, the amount of timerequired to interrupt the current thread and throw the packet onto thequeue becomes substantial. The event trace makes it easy to visualizethe overhead involved in putting packets onto the queue.

This information helps developers realize the need to look atalternative solutions such as setting a semaphore whenever the queue isempty. Then, instead of interrupting the thread every time a packetarrives, it is interrupted only when there are no packets in the queue.

Developers also can look at how the setting of priorities affectssystem performance. When threads are set at a relatively high number ofpriority levels, there's typically a lot of switching between threadsto keep the highest priority thread that is “ready” running.

Developers challenge performance by assigning priorities withoutthinking about the volume of context switches they are willing totolerate. Context switches are transparent to traditional debuggingtools so developers usually have no way to determine the impact ofpriorities.

Here, context switches are revealed and this makes it easier tounderstand their impact on performance. Invariably one of the firstthings developers notice when they begin using such a tool is thelarger than expected number of context switches.

They are typically surprised at the amount of time these switchesconsume and they then can modify their programs to use a smaller numberof priorities so that context switches occur less frequently. Notably,without a tool such as this, developers would be unaware of many of theinefficiencies in their system.

In conclusion, a system event trace tool can paint a graphicalpicture of the system in a way that standard debuggers cannot. Thisenables developers to get a clear picture of interrupts, contextswitches and other system events that could otherwise be detected onlythrough time-consuming instrumentation of code, and tedious examinationof the resulting data.

The result is that developers can find and fix bugs and optimizeapplication performance in substantially less time than would berequired using standard debugging tools alone. As a result, they canproduce better products in less time than ever before.

John Carbone is vice president of marketing at Express Logic.

Leave a Reply

This site uses Akismet to reduce spam. Learn how your comment data is processed.