![[Previous]](../prev.gif) |
![[Contents]](../contents.gif) |
![[Next]](../next.gif) |
|
|
|
Print trace events (QNX)
traceinfo [options] [logfile...]
The date format is [[[[[[CCYY]MM]DD]hh]mm][.SS]. The utility assumes the current date and time for any omitted fields.
If you precede the major code with a ! symbol, events with that code aren't printed.
Values may be decimal or hexadecimal (hex numbers must start with 0x). Using multiple -M options, you can specify up to 10 matches and 10 exclusions.
If logfile isn't specified, traceinfo reads directly from Proc's trace buffer.
The traceinfo utility prints trace events in human-readable format. If you don't specify a logfile, traceinfo reads events directly from the trace buffer maintained by the Process Manager (Proc). If you specify one or more logfiles, traceinfo reads them instead of Proc's trace buffer.
Events are printed one-per-line according to the format specified in the trace format file. The default format file is /etc/config/traceinfo. You can have traceinfo read additional format files by specifying the -e option. For more information, see the section on "Trace format files."
Trace events are binary data consisting of a trace code and its associated event data. Every trace code is made up of a 20-bit major code and a 12-bit minor code. The content of the data portion of a trace event is determined by the process that generated the event. The traceinfo utility simply formats and prints the event data according to print format descriptions. For example, Proc uses the trace code 0x00001001 for a "Bad Status" event:
| Trace code | Event data |
|---|---|
| 0x00001001 | 03 2E 00 01 00 00 20 20 34 FF |
The trace code 0x00001001 can be further broken down into a major code and a minor code as follows:
| Major code | Minor code |
|---|---|
| 0x00001 | 0x001 |
Event data is a stream of bytes; in most cases the data is a series of integers. When a trace event is generated, Proc records whether the event was created by a 16- or 32-bit program. Proc does this because the number of bytes that constitute an integer affects how traceinfo processes the event data, and consequently, may affect your format specifications (integers are 2-byte items for 16-bit programs and 4-byte items for 32-bit programs).
When traceinfo formats the event data, it maintains a running pointer that always points to the next integer to be processed. This pointer is incremented by either 2 or 4, depending on whether the trace event was made by a 16- or 32-bit program. For example:
| 16-bit program | 0 | 1 | 2 | 3 | 4 | 5 |
| Event data | 032E | 0001 | 0000 | 2020 | 34FF | 22AE |
| 32-bit program | 0 | 1 | 2 |
If the above event data were made by a 16-bit program, you could print the data with the following format specification:
If the above event data were made by a 32-bit program, you could print the data with the following format specification:
In a format string you must sometimes explicitly refer to a specific integer without using traceinfo's running data pointer. To do this, you specify an index in the format string. An index is an integer-based offset from the beginning of the event data. Because this offset is integer-based, it will increment in the same manner as traceinfo's pointer index (by either 2 or 4 bytes, depending on the program that created the event). The index starts at 0, so an index of 0 refers to the first item. For more information, see the section on "Format Specifications."
Trace format files describe how to print trace events by means of a printf()-style format specification. The structure of these files is based on special characters and command keywords.
| Lines that begin with: | Indicate: |
|---|---|
| # | a command keyword entry |
| tab | a minor-code format string |
| any other characters | the line is to be ignored |
You can specify the following command keywords:
#trace date "%b %d %y" /* use Month Day Year */For more info, see the section on "Trace print variables."
#major 0x00001 /* Process Manager */All subsequent minor trace format strings refer to this major code. For more info, see "Major-code header" and "Minor-code format strings."
#table 0x00045 /* Strings for major event 0x00045 */For more information, see "Tables."
#include /etc/config/screentraceThe specified file is opened and read as though its contents were part of the original trace format file. You can use up to five levels of nesting. For more info, see "Include files."
The traceinfo utility has print variables that represent information Proc records internally with each event. (In the case of the event date, both a full date and a millisecond time stamp are recorded.) By modifying the format specification, you can control the format traceinfo uses when printing this information.
Note that two of the print variables aren't based on Proc's internal event information:
To specify print variables, use this syntax:
#trace print_variable format_spec
You can specify the following print variables:
| String | Description | Example |
|---|---|---|
| %a | abbreviated weekday name | Wed |
| %A | full weekday name | Wednesday |
| %b | abbreviated month name | Dec |
| %B | full month name | December |
| %d | day of month (01-31) | 02 |
| %D | format mm/dd/yy | 12/31/97 |
| %H | hour as 24-hour clock | 19 |
| %j | day of year (001-366) | 234 |
| %m | month (01-12) | 04 |
| %T | 24-hour clock HH:MM:SS | 23:45:12 |
| %r | 12-hour HH:MM:SS {am|pm} | 09:45:12 PM |
| %y | year (00-99) | 97 |
| %Y | year with century | 1997 |
Each print variable is referenced in parentheses. For example:
"(date) (tracestr)"
"Major code=(major), Severity=(severity)"This would produce output similar to:
Major code=00003, Severity=2
The command keyword #major defines a major-code specification that all subsequent minor-code format strings are related to.
The #major keyword has this syntax:
#major major_code
The major_code may be decimal or hexadecimal. If you specify it in hexadecimal, precede the number with a 0x (e.g. 0x00001). Anything else on the line is discarded as a comment.
The following example would start a new major-code specification for major-code 16:
#major 16 /* start of new major code section */
These format strings follow a major-code header. They describe how to format the data for each of the minor-code events that have the preceding major code.
To specify minor-code format strings, use this syntax:
<tab>minor_code format_spec...
Each line must begin with a tab, followed by a minor code and then a format specification. Numbers may be decimal or hexadecimal. The format_spec argument is a printf()-style string (with some extensions). For more information, see "Format specifications."
In the following example, a major-code header indicates that the subsequent minor-code format strings are for the Process Manager. The example contains two minor-code format strings (for the minor codes 10 and 12):
#major 0x00001 /* Process Manager */
<tab>10 Session Leader died (%s)
<tab>12 Dead loader 1 (%s)
Tables let you use the currently pointed-to event data as an index into a table of fixed strings. You can use this mechanism as an alternative to using minor trace codes to differentiate the various events that have the same major code. Also, if you use tables, programs don't need to put strings in their trace events, thus reducing the amount of data that must be stored in the trace buffer.
Note that table strings aren't interpreted as format strings; they're printed literally.
Each table begins with the command keyword #table, followed by whitespace and then a major code (which may be decimal or hexadecimal):
#table major_code
Here's an example:
#table 0x00023 /* table header for major code 0x23 */
Following the above keyword line, one or more table entries specify literal strings for events that can occur for the specified major_code. To specify these entries, use this syntax:
<tab> index literal_string
Each table entry uses this syntax, which consists of a tab character followed by an index number, whitespace, and then a constant string.
Here's a sample table entry:
#table 0x00023 /*table entries for major code 35 (0x23) */
0 Data buffer OK.
1 Data input buffer has overflowed!
2 Data output buffer has overflowed!
3 Error! Loss of carrier!
100 Unable to continue!
#major 0x00023
1 Error message: %(table)
As this example shows, you need only one minor-code format string to use the table facility.
You can include another trace format file to be read. The specified file is opened and read as if its contents were part of the original trace format file. You can have up to 5 levels of nesting.
To specify an include file, use this syntax:
#include filename
For example:
#include /etc/config/screentrace
Each format specification begins with the % character; the basic layout is as follows:
%[@index,][-][0|<space>][min][.max][S|L][format_character|format_keyword]
where:
The default size is determined by whether the trace event was created by a 16- or 32-bit program:
The following format characters are supported:
| Character | Description |
|---|---|
| d | decimal |
| u | unsigned |
| x | hexadecimal |
| b | binary |
| o | octal |
| c | char (1 byte) |
| s | string
If used, this character must be the last field specifier in the format string. It causes any unprocessed event data to be output in ASCII without recognizing a NUL character as a string terminator. |
| e | Skip (eat) the data being pointed to. Don't print. You can use this option to move the running data pointer without printing anything. |
Format keywords specify common ways to interpret the event data currently being pointed to. Each format keyword must be enclosed in parentheses.
If the PID no longer exists, or the start time of the process is later than the trace-event time, then (pidname) is expanded to pid=number or vid=number.
If the process name is too large to fit in the specified length, the process name starts with a * and is right justified so that the characters furthest to the right in the process name are printed.
With this keyword, traceinfo looks for a table entry that matches the major code of the current event. If a valid table entry exists, traceinfo uses the value pointed to by the current data pointer as an index into that table and prints the associated literal string.
For more information, see the section on "Tables."
If the second two words of the network ID are zeros, traceinfo assumes the ID is an Arcnet address and prints only the first word. Otherwise the network ID is printed as a six-byte hex number.
The manifests used in the following examples are defined in /usr/include/sys/trace.h and /usr/include/sys/tracecod.h.
For the trace C code:
Trace2(_TRACE_TEMPORARY | 1, _TRACE_EXPECTED, 0x123, 7523);
the corresponding format line could be:
#major 0xFFFFF /* temporary */
1 Trace type 1 numbers are 0x%x, %d
and would produce:
Jan 19 11:34:02 Trace type 1 numbers are 0x123, 7523
Let's now look at several format lines for the following trace C code:
#define _TRACE_DEMO _TRACE_TEMPORARY
/*
* This is _TRACE_TEMPORARY until QNX Software Systems assigns
* a trace code to your company
*/
func(pid_t sender, msg_t type) {
msg_t status;
if(Send(sender, &type, sizeof(type), &status, sizeof(status)) == -1)
{
Trace(_TRACE_DEMO | 2, _TRACE_EXPECTED, type, sender, errno);
} else if(status != EOK) {
Trace(_TRACE_DEMO | 3, _TRACE_EXPECTED, type, sender, status);
}
}
Here's a simple trace-format event line for this example:
#major 0xFFFFF /* temporary */
2 Send of msg %d to pid %d failed errno=%d
3 Reply of msg %d from pid %d failed status=%d
Sample output:
Jan 19 11:34:02 Reply of msg 291 from pid 5678 failed status=22
You can also use printf()-like formats:
2 Send of msg %04.4x to pid %d failed errno=%d
3 Reply of msg %04.4x from pid %d failed status=%d
Sample output:
Jan 19 11:34:02 Reply of msg 0123 from pid 5678 failed status=22
You can use format keywords to expand numbers to common formats:
2 Send of msg %04.4x to %(pidname) failed with %(errno) 3 Reply of msg %04.4x from %(pidname) failed status=%(errno)
Sample output:
Jan 19 11:34:02 Reply of msg 0123 from /home/peterv/test
failed with status EINVAL
Using an index override, you can print data that the current data pointer no longer references:
2 MSG=%04.4x Send failed with %@2,(errno)(%@2,d) from
%@1,(pidname)
3 MSG=%04.4x replied with %@2,(errno)(%@2,d) from
%@1,(pidname)
Sample output:
Jan 19 11:34:02 MSG=0123 replied with EINVAL(22) from /bin/test
If you also want the errno string printed, you could do the following:
2 MSG=%04.4x to %-15.15(pidname) Send %-20.20(strerror)
(%@2,(errno))
3 MSG=%04.4x to %-15.15(pidname) Reply %-20.20(strerror)
(%@2,(errno))
Sample output:
Jan 19 11:34:02 MSG=0123 to /bin/test Reply Invalid argument
(EINVAL)
For the trace C code:
long a = 0x12345678;
Trace2(_TRACE_TEMPORARY | 4, _TRACE_EXPECTED, a >> 16,
a & 0xFFFF);
the corresponding line could be:
4 Trace type 4 long number is %Ld
Sample output:
Jan 19 11:34:02 Trace type 4 long number is 305419896
The Trace*() functions always pass a native int. If you wish to create trace events with the same information for both 16- and 32-bit programs, you may have to use overrides when printing the data. Note that you can avoid this by using different minor codes for the 16-bit and 32-bit data.
Let's now look at passing a long integer from a 16- or 32-bit program and interpreting this event data as a long integer.
For the trace C code:
long a = 0x12345678;
#ifdef __386__
Trace2(_TRACE_TEMPORARY | 5, _TRACE_EXPECTED, a);
#else
Trace2(_TRACE_TEMPORARY | 5, _TRACE_EXPECTED, a >> 16, a &
0xFFFF);
#endif
the corresponding line could be:
5 Trace type 5 long number is %Ld
Sample output:
Jan 19 11:34:02 Trace type 5 long number is 305419896
Let's now look at passing a short integer from a 16- or 32-bit program and interpreting this event data as a short integer.
For the trace C code:
short a = 1234, b = 6789; #ifdef __386__ Trace2(_TRACE_TEMPORARY | 6, _TRACE_EXPECTED, a | b << 16); #else Trace2(_TRACE_TEMPORARY | 6, _TRACE_EXPECTED, a, b); #endif
the corresponding line could be:
6 Trace type 6 short numbers are %@0,Sd and %@1,Sd
Sample output:
Jan 19 11:34:02 Trace type 6 short numbers are 1234 and 6789
The following 16-bit example generates a trace event that describes when the current machine was booted:
#include <stdio.h>
#include <sys/osinfo.h>
#include <sys/psinfo.h>
#include <sys/kernel.h>
#include <sys/trace.h>
char buffer[7];
struct _osinfo osdata;
#define MY_TRACE_MAJOR 0x00044 /* major trace code assigned
by QNX Software Systems Ltd. */
main()
{
pid_t id;
struct _psinfo data;
short int tmp;
if(qnx_osinfo(getnid(), &osdata) == -1) {
exit(-1);
}
id = qnx_psinfo(0, 1, &data, 0, 0); /* get psinfo for Proc */
sprintf(buffer,"%s",
osdata.bootsrc == 'H' ? " Hard" :
osdata.bootsrc == 'h' ? "*Hard" :
osdata.bootsrc == 'F' ? " Flop" :
osdata.bootsrc == 'f' ? "*Flop" :
osdata.bootsrc == 'N' ? " Net" : " ????" );
tmp = (short int)osdata.nodename;
Trace3b( (MY_TRACE_MAJOR << 12) | 1,_TRACE_CRITICAL,
(data.un.proc.start_time & 0x0000FFFF), /* store
low word first */
(data.un.proc.start_time >> 16),
tmp,
strlen(buffer),
buffer);
}
This example produces a trace event similar to the following (use traceinfo -r to see the raw, unformatted trace output):
2 Aug 19 22:49:38 00043001 F792 2A92 0001 4820 7261 64
If you used a format string such as the following to interpret the data:
#major 0x00043 /* my trace code events */
1 (%(minor)) Node %@2,d Booted on %@0,(date) : %@3,4.4s Boot
then the output from traceinfo would look something like this:
Aug 19 22:49:38 (1) Node 1 Booted on Wed Aug 19 21:38:26 1997 : Hard Boot
Print trace events that have occurred since 1:00 pm today:
traceinfo -d 1300
Print trace events that have occurred between August 12 00:00 and August 13 00:00 of the current year:
traceinfo -d 08120000:08130000
Print trace events, using the given date format string:
traceinfo -F "%Y,%m,%d,%T"
Print trace events, using the given header format string:
traceinfo -H "(severity) (date) (tracestr)"
Print all events except for those with major code 4:
traceinfo -M !4
Print events with major code 2 and minor code 3, as well as those with major code 6:
traceinfo -M 2:0x03 -M 6
Similar to above, except that events with major code 6 and minor code 2 aren't printed:
traceinfo -M 2:0x03 -M 6 -M !6:2
Print events with severity 0 to 4:
traceinfo -s 4
Print events with severity 3:
traceinfo -s 3:3
Print events with severity 2 to 4:
traceinfo -s 2:4
ctime(), qnx_trace_close(), qnx_trace_info(), qnx_trace_open(), qnx_trace_read(), qnx_trace_severity(), qnx_trace_trigger(), strftime(), and Trace*() functions in the Watcom C Library Reference.
|
|
|