Chapter 4. Inspecting and Analyzing Data

This chapter includes the following sections:

IRIXview Events

In IRIXview, an event is any action by a thread, process, or hardware component that could affect the state of the software system. Examples of events are process creations and deletions, system clock ticks, and interrupts. IRIX has been instrumented to log this event information.

In the IRIXview Context View graph windows, time is represented on the horizontal axis, while the current system's contexts are represented on the vertical axis:

  • At the top of the list, system interrupts are listed, followed by interrupt threads.

  • Below interrupts, all processes are listed in order of priority.

  • The last contexts shown are idle threads for each processor, with the highest-level processor listed first.

Figure 4-1. IntEnt Event Icon


When an event occurs, an event icon appears in the Context View graph. It is placed on the vertical axis according to the context in which it occurred, and on the horizontal axis according to the time (or sequence number) when it occurred.

You can drag an event icon into an Event Inspector window to see information associated with the event icon. For example, when a hardware interrupt occurred for which there is an associated ISR, an IntEnt event icon (see Figure 4-1) is displayed. By dragging the icon into the Event Inspector, you see information on that event: its timestamp, its context, the event name.

Figure 4-2 shows a timestamp for the real-time clock (RTC) counter appearing in the Event Inspector window. For help using the Event Inspector, see Chapter 3, “Displaying Event Data.” For details about individual events, see Chapter 5, “Event Dictionary.”

Figure 4-2. Event Inspector


The following sections describe features of event logging. These descriptions include information on how the GUI looks by default. You may customize many GUI attributes to meet your own needs; see Chapter 6, “User Interface Reference.” In addition, you can choose which events and states to display; see “Examining Event Data”.


Note: In this manual, a kernel mode switch, such as the switch the processor makes from idle mode to resume execution of a user process, is referred to as a context switch.


Context Switch Events

The term current context usually refers to the current process and the information needed to restore the process' condition, such as the state of the processor registers, operating system control information, and the stack. For IRIXview, the meaning of current context has been extended to include any thread of execution: a process, an ISR, or the kernel's idle thread. A context switch or mode switch refers to a change in the current context, which can occur when one process preempts another, when a process delays itself or waits on a resource, or when a process is interrupted by an ISR.

Figure 4-3. Current Content Line


When Context Switch events are logged, IRIXview shows the current context and where it is switched. The current context is shown as a solid, horizontal line (see Figure 4-3), with a different color used for each processor (on multiprocessor systems). When a context or mode switch occurs, and the Transition Lines button has been toggled on in the Display Event/States window, a dotted vertical line connects the previous context's line to the current context's line.

Process State Transition Events

The term process state transition refers to a process exiting from one state and entering into another; for example, from the pending state to the executing state. A process state transition may or may not result in a context switch, depending on the states of other processes in the system when the process in question makes a transition between states.

When Process State Transition events are logged, IRIXview shows the process state transitions and possibly the events that cause them. A process state is shown by the type of horizontal line (known as state stipples) used to display it. See Table 4-1 for a listing of the state stipples. State stipples are further differentiated by color. In addition, the event that caused the process state transition is shown as an icon.

As an optimization, events in Process State Transition are not separately timestamped. However, such events receive the timestamp of the next exit from the IRIX kernel. This exit is typically only a few microseconds after the event that originally caused the process state transition, and marks the moment at which the process state transition truly takes effect.

Table 4-1. Process State Representation Lines

Type of Line

Process State

Description


Executing

The process, interrupt service routine (ISR), or idle thread has control of the processor.


Suspended

The process attempted to gain access to a resource or event and the resource or event was not available (also referred to as a “blocked” process). On multiprocessor systems, if not all processors are being traced, a process can show as Suspended even after it has run, because process migration might occur.


Ready

The process is not waiting for any resource other than the processor. That is, it is ready to execute, but has not yet been executed by the scheduler. On multiprocessor systems, if not all processors are traced, a process may display as Ready even after it has run, because process migration can occur.



Note: In earlier releases there was a diagonally striped stipple to indicate nondegrading
real-time priority. You can still obtain priority levels from a Context View graph window by check marking the Priority button in the Context Graph Options window.


User-Generated Events

Figure 4-4. User Event Icon


When event logging has been started, IRIXview shows application-specific events. By default, these events are displayed by the User Event icon (see Figure 4-4) on the Context View and CPU View graphs. Event numbers are taken from a parameter provided with the rtmon_log_user_tstamp() function call; see rtmon_log_user_tstamp(3) for details. User-generated events are described in detail in the section “DefaultUser—Display User-specified Event”.

Analyzing Data

This section contains several examples of Context View windows showing how to analyze a progression of events as they are displayed in real time.

The first example shows events as IRIXview traces a single processor. The second example shows events as IRIXview traces a multiprocessor system. The third and fourth examples show IRIXview tracing a processor running the REACT/Pro Frame Scheduler. Callout numbers outside the figures point out important events that are described in nearby text (step 1 in the text describes what happens in the figure at callout 1).


Note: If scheduling actions are performed on an untraced processor, they do not display in the View graph. To completely follow the progress of the process, you must trace every processor on which the process can run.


Example 1—How A Process Starts Executing

Figure 4-5 shows a trace where a process starts executing on a single processor.

Figure 4-5. Single Processor Trace


Callouts are as follows:

  1. At the beginning of this trace (at approximately 3475 microseconds into the trace) the CPU is running the idle thread (CPU 3 Idle), processes sched and rtmond are blocked, and process amtickerd has yet to begin execution on this CPU. The top three execution states on the graph, Int RTC Ctr(7), Int CPU Ctr(6), and Int 1st Level(0), are for identifying interrupts when they occur.

    Notice that Int CPU Ctr(6), which is the processor scheduling clock interrupt, is occurring every 10 milliseconds, and that Int RTC Ctr(7), the real-time clock (RTC) interrupt, occurs just once in this image.

  2. At approximately 3520 microseconds into the trace an event occurs that causes the amtickerd process to begin execution on CPU 3.

At this point, we want to examine in more detail the events that occurred which caused the amtickerd process to run. We zoom in on the graph around the 3520 microsecond time to see what is occurring in more detail, as shown in Figure 4-6.

Figure 4-6. Single Processor—Sub-Time Interval


Callouts are as follows:

  1. At approximately 3521.8 microseconds into the trace an interrupt occurs. The Context View graph shows the interrupt first being received and qualified through the Int 1st Level context—all interrupts pass through this context and are further qualified at this level.


    Note: The processor is interrupted only once; the other interrupts that follow in this figure are simply further qualifications of this same processor interrupt.


  2. The interrupt is qualified as a RTC interrupt, indicating that an event timeout has occurred and interrupt processing continues.

  3. During processing of the RTC interrupt, the Interrupt Service Routine (ISR) initiates an event that permits the amtickerd process to become ready to run (the wavy line).

  4. Upon exit from the RTC ISR, the IRIX scheduler determines which runnable process has the highest priority, and performs a context switch to that process. Since amtickerd is the highest priority runnable process, it transitions from ready-to-run into executing on CPU 3.

  5. Less than a millisecond later the CPU processes a scheduling clock interrupt that apparently leads to no rescheduling, so the amtickerd process continues to execute.

  6. Almost a millisecond later, the amtickerd process blocks and CPU 3 returns to the idle state.

Example 2—Executing on a Multiprocessor System

Figure 4-7 shows a multiprocessor system trace, showing how processes migrate between two processors as they execute.

Figure 4-7. Multiprocessor Trace


Callouts are as follows:

  1. At the start of the trace, both processors are executing the idle thread.

  2. A few milliseconds later, the aioc process begins executing on CPU 0. As time progresses, the graph shows how this process migrates to and from CPU 1 as this processor becomes available. It then migrates back to CPU 0 later in the timeline.

  3. A second invocation of aioc (a pthread application) initiates and begins execution on CPU 0. The arrow-in-circle icon indicates the startup of a new process.

  4. CPU 0 is idle when there are no other processes to run. Due to processor affinity and other scheduling considerations, it is possible for there to be runnable processes and idle CPUs at the same time.

  5. Other processes are spawned and execute on the two available processors.

Example 3—Beginning of an FRS Frame

Figure 4-8 shows the start of a Frame Scheduler (FRS) minor frame.

Figure 4-8. Beginning of an FRS Minor Frame


Callouts are as follows:

  1. CPU 1 receives an interrupt and transitions from an idle state to the first level interrupt, Int 1st Level(0).

  2. The interrupt is further qualified as an RTC interrupt, Int RTC Ctr.


    Note: The processor is interrupted only once; the other interrupts that follow in this figure are simply further qualifications of this same processor interrupt.


  3. The interrupt is further qualified as a Frame Scheduler (FRS) interrupt Int Level 1, signifying that the FRS has interrupted the CPU.

  4. The small clock icon indicates that this FRS interrupt designates the start of a minor frame.

  5. The interrupt exits the interrupt handler.

  6. The idle thread immediately schedules the first frame-scheduled activity thread (executive) for that minor frame, and context switches to it.

  7. The first FRS scheduled process (executive) begins execution.

  8. The executive process completes execution for this minor frame and issues an frs_yield (shown in the yield-exclamation point icon).

  9. The sparkplug icon indicates that another process is dispatched to run upon completion of the executive process.

  10. A context switch occurs to the next process enqueued in this minor frame, engines.

Example 4—FRS Overrun Detected

This is an example of Frame Scheduler (FRS) overrun detection. Figure 4-9 show a minor frame overrun being detected.

Figure 4-9. FRS Overrun Detected


Callouts are as follows:

  1. A start-of-minor-frame interrupt occurs as was shown in the previous example.

  2. In this case two additional frame scheduler events are shown indicating an anomaly has occurred (further information about these events could be obtained by using the Event Inspector window).

  3. The skull and crossbones icon appears, indicating that the FRS has detected an unrecoverable frame overrun condition. In this case, the overrun is occurring because process simple did not complete its execution (reach its FRS yield) before the start of the next minor frame. Note that process simple (pid 2358) is blocked and has therefore not been able to continue processing during this frame.