Programming Utilities Guide

Advanced Topics

Inserting Probe Points

Insert probe points in your code to:

Trace the values of variables in your program.

Provide internal state information that is not available through the exported interface. This is useful for debugging or for performance analysis.

For example, use probe points to show performance relevant information hidden in C⁺⁺ private classes, or to show operational data such as the collision rate in a hash table. By placing a probe point in the hash table code, the probe point can write to the trace file each time a collision is detected.

The interface for inserting probes is defined by the TNF_PROBE macros TNF_PROBE_0 through TNF_PROBE_5. The numbers 0 through 5 are the number of variables being traced by the macro.

With these macros, you can insert probe points anywhere in your code to get the values of variables and to trace program execution. The libtnfprobe library defines the standard scalar types (ints, longs, floats, and so on), but you can define more complex structures with the TNF_DECLARE_RECORD and TNF_DEFINE_RECORD macros. See "Defining User Types for Probe Points".

Using the `TNF_PROBE` Macros

In the simplest case, TNF_PROBE_0, you give no argument types:

TNF_PROBE_0 (name, keys, detail);

The variables are:

name -- The name of the probe, following all the syntax guidelines for identifiers in ANSI C. The use of name declares it, so no separate declaration is necessary. This is a block scope declaration, so it does not affect the name space of the program.

keys -- A list of groups to which the probe belongs. The list is a string containing space-separated keywords and cannot contain a semicolon, an equal sign, or a single quotation mark.( ;= ` ). When any of the groups are enabled, the probe point is enabled. keys cannot be a variable--it must be an in-line string.

detail -- Provides a way for you to define your own attributes and values. The detail string is made up of attribute-value pairs separated from each other by semicolons, although the value is optional. The first word (up to a space) is considered to be the attribute and the rest of the string (up to the semicolon) is considered to be the value. Spaces around the semicolon delimiter are allowed. Single quotation marks and the equal sign are not allowed in the detail statement.

Prefix the attribute name with a vendor stock symbol followed by the % character to avoid name collisions. In the following example, four attributes are defined: sunw%debug, comX%exception, comY%func_entry, and comY%color. Since prex tokenizes the value on spaces, multiword values can be matched on any of the words, but not on the entire string. For example:
```
sunw%debug entering function A; 
comX%exception no file;  
comY%func_entry;  
comY%color red blue
```

Table 1-8 gives the values that are matched on for the command shown above:

Table 1-8 Examples of User-Defined Attributes


Attribute	Value	Values `prex` matches on
`sunw%debug`	`entering function A`	`entering` or `function` or `A`
`comX%exception`	`no file`	`no` or `file`
`comY%func_entry`		`/.*/` (regular expression)
`comY%color`	`red blue`	`red` or `blue`

libtnfprobe reserves all attribute names that are not prefixed by a vendor symbol (it reserves all attributes that do not have the % character in them). The code for cookie.c in "A Sample C Program" contains the following use of TNF_PROBE_0:

TNF_PROBE_0(start, "cookie main", "sunw%debug starting main");

Note -

Compiling with the preprocessor option -DNPROBE (see cc(1)), or with the preprocessor control statement #define NPROBE ahead of the #include <tnf/probe.h> statement, stops probe points as well as TNF type extension code from being compiled into the program.

`TNF_PROBE_1` Through `TNF_PROBE_5`

The numbers 1 through 5 in the argument names are used here to illustrate the number of variables you give to the probe point. For example, the syntax for TNF_PROBE_1 is:

TNF_PROBE_1(name, keys, detail,
arg_type_1, arg_name_1, arg_value_1);

and the syntax for TNF_PROBE_5 is:

TNF_PROBE_5(name, keys, detail,
arg_type_1, arg_name_1, arg_value_1
arg_type_2, arg_name_2, arg_value_2
arg_type_3, arg_name_3, arg_value_3
arg_type_4, arg_name_4, arg_value_4
arg_type_5, arg_name_5, arg_value_5);

The arguments are:

arg_type_n--The type of the nth argument. n is a number from 1 through 5. The predefined types are listed in Table 1-9. See "Defining User Types for Probe Points" for information about defining your own types.

arg_name_n--The name you give the nth argument. Follow the ANSI C rules for identifiers, and do not use quotation marks around the argument name. (Note that the slots attribute mentioned on "Attributes " contains a string version of this name.)

arg_value_n--The expression that is evaluated to a value that is included in the trace file. A read access is done on any variables that are mentioned in value_n. In a multithreaded program, place locks around the TNF_PROBE_n macro if value_n contains data that should be read protected.

Table 1-9 Predefined Types


Type	Associated C Type and Semantics
`tnf_long`	int, long
`tnf_ulong`	unsigned int, unsigned long
`tnf_longlong`	long long (if implemented in compilation system)
`tnf_ulonglong`	unsigned long long (if implemented in compilation system)
`tnf_float`	float
`tnf_double`	double
`tnf_string`	char *
`tnf_opaque`	void *

For example, the cookie.c program on "A Sample C Program" uses TNF_PROBE_2 as follows:

TNF_PROBE_2(inloop, "cookie main loop","sunw%debug in the loop",
				tnf_long, loop_count, 		i,
				tnf_long, total_iterations, 	sum);

Table 1-10 explains some of the macro definitions in cookie.c.

Table 1-10 TNF Macro Definitions in cookie.c


TNF_PROBE_0 (	A probe with no argument types
start,	The name of the probe
"cookie main",	The list of groups the probe belongs to `cookie` and `main` (the values of the keys attribute)
"sunw%debug starting main");	User-defined attribute=`sunw%debug`; value=`starting main` (used by debug probe function)
TNF_PROBE_2 (	A probe with two variables
inloop,	The name of the probe
"cookie main loop",	The keys - `cookie, main`, and `loop`
"sunw%debug in the loop",	Values for the debug probe function
tnf_long,	The type of the first variable
loop_count,	The name of the first variable (value of the `slots` attribute)
i,	The first variable
tnf_long,	The type of the second variable
total_iterations,	The name of the second variable (value of the `slots` attribute)
`sum`);	The second variable
"");

Example--Timing Functions

In Example 1-4, probe points are placed at the entry and exit of a function to see how much time is spent in the function. The probe at the function entry also logs the arguments to the function.

When prex encounters a probe point at run time that is enabled for tracing, it writes a record to the trace file. Each probe point logs the time when it was encountered and also references a tag record containing information like the file name, line number, name, keys, and detail of the probe point. These tag records are written only once, and are never overwritten in the trace file.

The first probe point, work_args, also logs the value of the two arguments of the probe point (state and message).

Example 1-4 Probe Points at Entry and Exit of Function

#include <tnf/probe.h>

int
work(int state, char *message)
{
    TNF_PROBE_2(work_start, "work_module work"
               "sunw%debug in function work",
               tnf_long, int_input, state,
               tnf_string, string_input, message);
   ...
    TNF_PROBE_0(work_end, "work_module work", "");
}

Defining User Types for Probe Points

To trace a structure in your program, define a new type with the TNF_DECLARE_RECORD and TNF_DEFINE_RECORD_n macros. These are parts of a compile time interface for extending the types sent in to probe points.

TNF_DECLARE_RECORD(c_type, tnf_type);

TNF_DEFINE_RECORD_1(c_type, tnf_type, 
                    tnf_member_type_1, 
                    tnf_member_name_1)
TNF_DEFINE_RECORD_2(c_type, tnf_type,  
                    tnf_member_type_1, 
                    tnf_member_name_1, 
                    tnf_member_type_2, 
                    tnf_member_name_2)
TNF_DEFINE_RECORD_3(c_type, tnf_type, 
                    tnf_member_type_1, 
                    tnf_member_name_1,
                    tnf_member_type_2, 
                    tnf_member_name_2, 
                    tnf_member_type_3, 
                    tnf_member_name_3)
TNF_DEFINE_RECORD_4(c_type, tnf_type, 
                    tnf_member_type_1, 
                    tnf_member_name_1,
                    tnf_member_type_2, 
                    tnf_member_name_2,
                    tnf_member_type_3, 
                    tnf_member_name_3,  
                    tnf_member_type_4, 
                    tnf_member_name_4) 
TNF_DEFINE_RECORD_5(c_type, tnf_type, 
                    tnf_member_type_1, 
                    tnf_member_name_1,
                    tnf_member_type_2, 
                    tnf_member_name_2,
                    tnf_member_type_3, 
                    tnf_member_name_3,
                    tnf_member_type_4,  
                    tnf_member_name_4,
                    tnf_member_type_5,  
                    tnf_member_name_5)

Create only one TNF_DECLARE_RECORD and one TNF_DEFINE_RECORD for each new type you define. The TNF_DECLARE_RECORD should precede the TNF_DEFINE_RECORD. It can be in a header file that multiple source files share if those source files need to use the tnf_type being defined. The TNF_DEFINE_RECORD should appear in only one of the source files.

The TNF_DEFINE_RECORD macro interface defines a function as well as several data structures. Therefore, use this interface in a source file (.c file or .cc file) at file scope and not inside a function.

Note -

Do not put a semicolon after the TNF_DEFINE_RECORD statement; it will generate a compiler warning.

The variables are:

c_type -- The template from which the new tnf_type is created. Not all the elements of the C struct need to be provided in the TNF type being defined. c_type must be a C struct type.

tnf_type -- The name given to the newly created type. This interface uses the name space prefixed by the tnf_type. So, if a new type called xxx_type is defined by a library, then the library should not use xxx_type as a prefix in any other symbols it defines.

The policy on managing the type name space is the same as that for managing any other name space in a library: prefix any new TNF types by the unique prefix that the rest of the symbols in the library use. This prevents name space collisions when you link multiple libraries that define new TNF types.

For example, if a library called libpalloc.so uses the prefix pal for all symbols it defines, then it should also use the prefix pal for all new TNF types being defined.

tnf_member_type_n -- The TNF type of the nth provided member of the C structure.

tnf_member_name_n -- The name of the nth provided member of the C structure.

Examples--Defining TNF Types

Example 1-5 shows how a new TNF type is defined and used in a probe.

Example 1-5 is assumed to be part of a fictitious library called libpalloc.so that uses the prefix pal for all its symbols.

Example 1-5 Defining a new TNF type

#include <tnf/probe.h>

typedef struct pal_header {
        long    size;
        char * descriptor;
        struct pal_header *next;
} pal_header_t;

TNF_DECLARE_RECORD(pal_header_t, pal_tnf_header);
TNF_DEFINE_RECORD_2(pal_header_t, pal_tnf_header,
                        tnf_long,   size,
                        tnf_string, descriptor)

/* 
 * Note: name space prefixed by pal_tnf_header should not be  * used by this client any more.
 */

void 
pal_free(pal_header_t *header_p)
{
        int state;

        TNF_PROBE_2(pal_free_start, "palloc pal_free",
                "sunw%debug entering pal_free",
                tnf_long,       state_var, state,
                pal_tnf_header, header_var, header_p);
        . . .
}

It is possible to make a tnf_type definition recursive or mutually recursive, such as in a structure that uses the next field to point to itself (a linked list).

When such a structure is sent in to a TNF_PROBE, then the entire linked list is logged to the trace file (until the next field is NULL). But, when the list is circular, it results in an infinite loop. To break the recursion, either omit the next field from the tnf_type, or define the type of the next member as tnf_opaque.

Performance Issues

Don't place probe points in sections of code that are traversed frequently, as in a mutex lock that is used often.

Estimate about 30 words of working set memory (10 words data and 20 words text) for each probe and about 200ns for each disabled probe on a SPARCStation10. You can control the performance degradation of the application by controlling the number and placement of probes.

If you are shipping a library with probe points, it is important to run benchmarks to ensure that the performance is still at an acceptable level. Reduce the number of probes or change their positions to increase performance.

`/proc`

dbx, truss, and prex all use /proc to control the target process. /proc allows only one client to control a target process safely. Because of this, you cannot run programs like dbx and prex simultaneously on the same target program. If you try to run prex on a target while dbx or truss is running on the same target, prex displays the message "Cannot attach to target."

You can, however, interleave prex and dbx execution by following these steps:

Start prex.
Set up the state of the probe points.
Give the command quit suspend.
Start dbx.
Attach to the suspended program.

The target will not execute any code between prex and dbx.

You can also suspend the target by sending it a SIGSTOP signal, then type "quit resume" to prex. If you do this, you should also send a SIGCONT signal after invoking dbx on the stopped process (or else dbx hangs).

`dlopen()` and `dlclose()` and History

Probes in shared objects that are brought in by a dlopen(3X) are automatically set up according to the prex command history. When a shared object is removed by a dlclose(3X), prex refreshes its understanding of the probes in the target program. This implies that there is more work to do for dlopen and dlclose, so they take slightly longer.

If you are not interested in this feature and don't want dlopen and dlclose to be perturbed, detach prex from the target.

Signals

prex does not interfere with signals that are delivered directly to the target program. However, prex receives all terminal-generated signals, such as Control-c (SIGINT) and Control-z (SIGSTOP), and does not forward them to the target program.

Use the kill(1) command from a shell to signal the target program.

Failure of Event-Writing Operations

A few failure points, like system call failures, are possible when writing events to trace files. These failures result in a failure code being set in the target process. The target process continues normally (but no trace records are written).

Whenever a user types Control-c to prex to get to a prex prompt, prex checks the failure code in the target and informs the user if there was a tracing failure.

Target Executing a `fork()` or `exec()`

If your program does a fork(), any probes that the child encounters are logged to the same trace file. Events are annotated with a process ID, so it is possible to determine which process a particular event came from.

A thread in a multithreaded program doing a fork while the other threads are still running can cause a race conditon. For the trace file to stay uncorrupted, make sure that the other threads are quiescent when doing a fork, or else use fork1(2).

If the target program itself (not any children it might fork) does an exec(2), prex detaches from the target and exits. The user can reconnect prex with:

$ prex -p pid