[ Previous | Next | Table of Contents | Index | Library Home | Legal | Search ]

Performance Management Guide


Adding New Trace Events

The operating system is shipped instrumented with key events. The user need only activate trace to capture the flow of events from the operating system. Application developers may want to instrument their application code during development for tuning purposes. This provides them with insight into how their applications are interacting with the system.

To add a trace event, you must design the trace records generated by your program in accordance with trace interface conventions. You then add trace-hook macros to the program at the appropriate locations. Traces can then be taken through any of the standard ways of invoking and controlling trace (commands, subcommands, or subroutine calls). To use the trcrpt program to format your traces, add stanzas describing each new trace record and its formatting requirements to the trace format file.

Possible Forms of a Trace Event Record

A trace event can take several forms. An event consists of a hook word, optional data words, and an optional time stamp, as shown in the following figure. A four-bit type is defined for each form that the event record can take. The type field is imposed by the recording routine so that the report facility can always skip from event to event when processing the data, even if the formatting rules in the trace format file are incorrect or missing for that event.

Figure 12-2. Format of a Trace Event Record. This illustration is a table containing 7 rows. Cells in the first row are labeled 12-bit hook ID, 4-bit Type and 16-bit Data Field. The next 6 rows are simply labeled Data Word 1 through Data Word 5, and the last row is labeled 32-bit Time Stamp. A row heading for row 1 is Hook Word (required). The next 5 rows are labeled D1 (optional), D2 (optional), D3 (optional), D4 (optional), and (optional). The last row is labeled T (optional).


Artwork for h11i4

An event record should be as short as possible. Many system events use only the hook word and time stamp. The data words should seldom be used because using them is less efficient and is intrusive. A long format allows the user to record a variable length of data. In this long form, the 16-bit data field of the hook word is converted to a length field that describes the length of the event record.

Trace Channels

The trace facility can accommodate up to eight simultaneous channels of trace-hook activity, which are numbered 0-7. Channel 0 is always used for system events, but application events can also use it. The other seven channels, called generic channels, can be used for tracing application-program activity.

When trace is started, channel 0 is used by default. A trace -n channel_number command starts trace to a generic channel. Use of the generic channels has some limitations:

Macros for Recording Trace Events

Macros to record each possible type of event record are defined in the /usr/include/sys/trcmacros.h file. The event IDs are defined in the /usr/include/sys/trchkid.h file. Include these two files in any program that is recording trace events.

The macros to record events on channel 0 with a time stamp are a follows:

TRCHKL0T(hw)
TRCHKL1T(hw,D1)
TRCHKL2T(hw,D1,D2)
TRCHKL3T(hw,D1,D2,D3)
TRCHKL4T(hw,D1,D2,D3,D4)
TRCHKL5T(hw,D1,D2,D3,D4,D5)

Similarly, to record events on channel 0 without a time stamp, use:

TRCHKL0(hw)
TRCHKL1(hw,D1)
TRCHKL2(hw,D1,D2)
TRCHKL3(hw,D1,D2,D3)
TRCHKL4(hw,D1,D2,D3,D4)
TRCHKL5(hw,D1,D2,D3,D4,D5)

The type field of the trace event record is set to the value that corresponds to the macro used, regardless of the value of those 4 bits in the hw parameter.

Only two macros record events to one of the generic channels (1-7). These are as follows:

TRCGEN(ch,hw,D1,len,buf)
TRCGENT(ch,hw,D1,len,buf)

These macros record in the event stream specified by the channel parameter (ch) a hook word (hw), a data word (D1) and len bytes from the user's data segment beginning at the location specified by buf.

Use of Event IDs

The event ID in a trace record identifies that record as belonging to a particular class of records. The event ID is the basis on which the trace mechanism records or ignores trace hooks, as well as the basis on which the trcrpt command includes or excludes trace records in the formatted report.

Event IDs are 12 bits (three hexadecimal digits) for a possible 4096 IDs. Event IDs that are reserved and shipped with code are permanently assigned to avoid duplication. To allow users to define events in their environments or during development, the range of event IDs from hex 010 through hex 0FF has been reserved for temporary use. Users can freely use IDs in this range in their own environment (that is, any set of systems within which the users are prepared to ensure that the same event ID is not used ambiguously).

Note: It is important that users who make use of this event range do not let the code leave their environment. If you ship code instrumented with temporary hook IDs to an environment in which you do not control the use of IDs, you risk collision with other programs that already use the same IDs in that environment.

Event IDs should be conserved because there are so few of them, but they can be extended by using the 16-bit Data Field. This yields a possible 65536 distinguishable events for every formal hook ID. The only reason to have a unique ID is that an ID is the level at which collection and report filtering are available in the trace facility.

A user-added event can be formatted by the trcrpt command if there is a stanza for the event in the specified trace format file. The trace format file is an editable ASCII file (see Syntax for Stanzas in the Trace Format File).

Examples of Coding and Formatting Events

The following example shows the use of trace events to time the execution of a program loop:

#include <sys/trcctl.h>
#include <sys/trcmacros.h>
#include <sys/trchkid.h>
char *ctl_file = "/dev/systrctl";
int ctlfd;
int i;
main()
{
  printf("configuring trace collection \n");
  if (trcstart("-ad")){
    perror("trcstart");
    exit(1);
  }
 
  printf("opening the trace device  \n");
  if((ctlfd = open(ctl_file,0))<0){
    perror(ctl_file);
    exit(1);
  }
 
  printf("turning  trace on \n");
  if(ioctl(ctlfd,TRCON,0)){
    perror("TRCON");
    exit(1);
  }
 
  for(i=1;i<11;i++){
    TRCHKL1T(HKWD_USER1,i);
 
    /* The code being measured goes here. The interval */
    /* between occurrences of HKWD_USER1 in the trace  */
    /* file is the total time for one iteration.       */
  }
 
  printf("turning trace off\n");
  if(ioctl(ctlfd,TRCSTOP,0)){
    perror("TRCOFF");
    exit(1);
  }
 
  printf("stopping the trace daemon \n");
  if (trcstop(0)){
    perror("trcstop");
    exit(1);
  }
 
  exit(0);
}

When you compile the sample program, you must link to the librts.a library as follows:

# xlc -O3 sample.c -o sample -l rts

HKWD_USER1 is event ID 010 hexadecimal (you can verify this by examining the /usr/include/sys/trchkid.h file). The report facility does not format the HKWD_USER1 event, unless rules are provided in the trace format file. The following example of a stanza for HKWD_USER1 could be used:

# User event HKWD_USER1 Formatting Rules Stanza
# An example that will format the event usage of the sample program
010 1.0 L=APPL "USER EVENT - HKWD_USER1" O2.0      \n \
               "The # of loop iterations =" U4     \n \
               "The elapsed time of the last loop = " \
                endtimer(0x010,0x010) starttimer(0x010,0x010)

When you enter the example stanza, do not modify the master format file /etc/trcfmt, but instead make a copy and keep it in your own directory (assume you name it mytrcfmt). When you run the sample program, the raw event data is captured in the default log file because no other log file was specified to the trcstart() subroutine. You can filter the output report to get only your events. To do this, run the trcrpt command as follows:

# trcrpt -d 010 -t mytrcfmt -O "exec=on" > sample.rpt

You can browse the sample.rpt file to see the result.

Syntax for Stanzas in the Trace Format File

The trace format file provides rules for presentation and display of the expected data for each event ID. This allows new events to be formatted without changing the report facility. Rules for new events are simply added to the format file. The syntax of the rules provides flexibility in the presentation of the data.

A trace format stanza can be as long as required to describe the rules for any particular event. The stanza can be continued to the next line by terminating the present line with a '\' character. The fields are described in the AIX 5L Version 5.1 Files Reference.

Comments in the /etc/trcfmt file describe other format and macro possibilities and describe how a user can define additional macros.


[ Previous | Next | Table of Contents | Index | Library Home | Legal | Search ]