Example Trace Format File
You can define other macros and use other formatting techniques in the trace format file.
# @(#)65 1.142 src/bos/usr/bin/trcrpt/trcfmt, cmdtrace, bos43N, 9909A_43N 2/12/99 13:15:34
# COMPONENT_NAME: CMDTRACE system trace logging and reporting facility
#
# FUNCTIONS: template file for trcrpt
#
# ORIGINS: 27, 83
#
# (C) COPYRIGHT International Business Machines Corp. 1988, 1993
# All Rights Reserved
# Licensed Materials - Property of IBM
#
# US Government Users Restricted Rights - Use, duplication or
# disclosure restricted by GSA ADP Schedule Contract with IBM Corp.
#
# LEVEL 1, 5 Years Bull Confidential Information
#
# I. General Information
#
# The formats shown below apply to the data placed into the
# trcrpt format buffer. These formats in general mirror the binary
# format of the data in the trace stream. The exceptions are
# hooks from a 32-bit application on a 64-bit kernel, and hooks from a
# 64-bit application on a 32-bit kernel. These exceptions are noted
# below as appropriate.
#
# Trace formatting templates should not use the thread id or time
# stamp from the buffer. The thread id should be obtained with the
# $TID macro. The time stamp is a raw timer value used by trcrpt to
# calculate the elapsed and delta times. These values are either
# 4 or 8 bytes depending upon the system the trace was run on, not upon
# the environment from which the hook was generated.
# The system environment, 32 or 64 bit, and the hook's
# environment, 32 or 64 bit, are obtained from the $TRACEENV and $HOOKENV
# macros discussed below.
#
# To interpret the time stamp, it is necessary to get the values from
# hook 0x00a, subhook 0x25c, used to convert it to nanoseconds.
# The 3 data words of interest are all 8 bytes in length and are in
# the generic buffer, see the template for hook 00A.
# The first data word gives the multiplier, m, and the second word
# is the divisor, d. These values should be set to 1 if the
# third word doesn't contain a 2. The nanosecond time is then
# calculated with nt = t * m / d where t is the time from the trace.
#
# Also, on a 64-bit system, there will be a header on the trace stream.
# This header serves to identify the stream as coming from a
# 64-bit system. There is no such header on the data stream on a
# 32-bit system. This data stream, on both systems, is produced with
# the "-o -" option of the trace command.
# This header consists only of a 4-byte magic number, 0xEFDF1114.
#
# A. Binary format for the 32-bit trace data
# TRCHKL0 MMMTDDDDiiiiiiii
# TRCHKL0T MMMTDDDDiiiiiiiitttttttt
# TRCHKL1 MMMTDDDD11111111iiiiiiii
# TRCHKL1T MMMTDDDD11111111iiiiiiiitttttttt
# Note that trchkg covers TRCHKL2-TRCHKL5.
# trchkg MMMTDDDD1111111122222222333333334444444455555555iiiiiiii
# trchkgt MMMTDDDD1111111122222222333333334444444455555555 i... t...
# trcgent MMMTLLLL11111111vvvvvvvvvvvvvvvvvvvvvvvvvvxxxxxx i... t...
#
# legend:
# MMM = hook id
# T = hooktype
# D = hookdata
# i = thread id, 4 bytes on a 32 byte system and 8 bytes on a 64-bit
# system. The thread id starts on a 4 or 8 byte boundary.
# t = timestamp, 4 bytes on a 32-bit system or 8 on a
# 64-bit system.
# 1 = d1 (see trchkid.h for calling syntax for the tracehook routines)
# 2 = d2, etc.
# v = trcgen variable length buffer
# L = length of variable length data in bytes.
#
# The DATA_POINTER starts at the third byte in the event, ie.,
# at the 16 bit hookdata DDDD.
# The trcgen() is an exception. The DATA_POINTER starts at
# the fifth byte, ie., at the 'd1' parameter 11111111.
#
# Note that a generic trace hook with a hookid of 0x00b is
# produced for 64-bit data traced from a 64-bit app running on
# a 32-bit kernel. Since this is produced on a 32-bit system, the
# thread id and time stamp will be 4 bytes in the data stream.
#
# B. 64-bit trace hook format
#
# TRCHK64L0 ffffllllhhhhssss iiiiiiiiiiiiiiii
# TRCHK64L0T ffffllllhhhhssss iiiiiiiiiiiiiiii tttttttttttttttt
# TRCHK64L1 ffffllllhhhhssss 1111111111111111 i...
# ...
# TRCGEN ffffllllhhhhssss dddddddddddddddd "string" i...
# TRCGENt ffffllllhhhhssss dddddddddddddddd "string" i... t...
#
# Legend
# f - flags
# tgbuuuuuuuuuuuuu: t - time stamped, g - generic (trcgen),
# b - 32-bit data, u - unused.
# l - length, number of bytes traced.
# For TRCHKL0 llll = 0,
# for TRCHKL5T llll = 40, 0x28 (5 8-byte words)
# h - hook id
# s - subhook id
# 1 - data word 1, ...
# d - generic trace data word.
# i - thread id, 8 bytes on a 64-bit system, 4 on a 32-bit system.
# The thread id starts on an 8-byte boundary.
# t - time stamp, 8 bytes on a 64-bit system, 4 on a 32-bit system.
#
# For non-generic entries, the data pointer starts at the
# subhook id, offset 6. This is compatible with the 32-bit
# hook format shown above.
# For generic (trcgen) hooks, the g flag above is on. The
# length shows the number of variable bytes traced and does not include
# the data word.
# The data pointer starts at the 64-bit data word.
# Note that the data word is 64 bits here.
#
# C. Trace environments
# The trcrpt, trace report, utility must be able to tell whether
# the trace it's formatting came from a 32 or a 64 bit system.
# This is accomplished by the log file header's magic number.
# In addition, we need to know whether 32 or 64 bit data was traced.
# It is possible to run a 32-bit application on a 64-bit kernel,
# and a 64-bit application on a 32-bit kernel.
# In the case of a 32-bit app on a 64-bit kernel, the "b" flag
# shown under item B above is set on. The trcrpt program will
# then present the data as if it came from a 32-bit kernel.
# In the second case, if the reserved hook id 00b is seen, the data
# traced by the 32-bit kernel is made to look as if it came
# from a 64-bit trace. Thus the templates need not be kernel aware.
#
# For example, if a 32-bit app uses
# TRCHKL5T(0x50000005, 1, 2, 3, 4, 5)
# and is running on a 64-bit kernel, the data actually traced
# will look like:
# ffffllllhhhhssss 1111111111111111 2222222222222222 3333333333333333
# a000001450000005 0000000100000002 0000000300000004 0000000500000000 i t
# Here, the flags have the T and B bits set (a000) which says
# the hook is timestamped and from a 32-bit app.
# The length is 0x14 bytes, 5 4-byte registers 00000001 through
# 00000005.
# The hook id is 0x5000.
# The subhook id is 0x0005.
# i and t refer to the 8-byte thread id and time stamp.
#
# This would be reformatted as follows before being processed
# by the corresponding template:
# 500e0005 00000001 00000002 00000003 00000004 00000005
# Note this is how the data would look if traced on a 32-bit kernel.
# Note also that the data would be followed by an 8-byte thread id and
# time stamp.
#
# Similarly, consider the following hook traced by a 64-bit app
# on a 32-bit kernel:
# TRCHKL5T(0x50000005, 1, 2, 3, 4, 5)
# The data traced would be:
# 00b8002c 80000028 50000005 0000000000000001 ... 0000000000000005 i t
# Note that this is a generic trace entry, T = 8.
# In the generic entry, we're using the 32-bit data word for the flags
# and length.
# The trcrpt utility would reformat this before processing by
# the template as follows:
# 8000002850000005 0000000000000001 ... 0000000000000005 i8 t8
#
# The thread id and time stamp in the data stream will be 4 bytes,
# because the hook came from a 32-bit system.
#
# If a 32-bit app traces generic data on a 64-bit kernel, the b
# bit will be set on in the data stream, and the entry will be formatted
# like it came from a 32-bit environment, i.e. with a 32-bit data word.
# For the case of a 64-bit app on a 32-bit kernel, generic trace
# data is handled in the same manner, with the flags placed
# into the data word.
# For example, if the app issues
# TRCGEN(1, 0x50000005, 1, 6, "hello")
# The 32-bit kernel trace will generate
# 00b00012 40000006 50000005 0000000000000001 "hello"
# This will be reformatted by trcrpt into
# 4000000650000005 0000000000000001 "hello"
# with the data pointer starting at the data word.
#
# Note that the string "hello" could have been 4096 bytes. Therefore
# this generic entry must be able to violate the 4096 byte length
# restriction.
#
# D. Indentation levels
# The left margin is set per template using the 'L=XXXX' command.
# The default is L=KERN, the second column.
# L=APPL moves the left margin to the first column.
# L=SVC moves the left margin to the second column.
# L=KERN moves the left margin to the third column.
# L=INT moves the left margin to the fourth column.
# The command if used must go just after the version code.
#
# Example usage:
#113 1.7 L=INT "stray interrupt" ... \
#
# E. Continuation code and delimiters.
# A '\' at the end of the line must be used to continue the template
# on the next line.
# Individual strings (labels) can be separated by one or more blanks
# or tabs. However, all whitespace is squeezed down to 1 blank on
# the report. Use '\t' for skipping to the next tabstop, or use
# A0.X format (see below) for variable space.
#
#
# II. FORMAT codes
#
# A. Codes that manipulate the DATA_POINTER
# Gm.n
# "Goto" Set DATA_POINTER to byte.bit location m.n
#
# Om.n
# "Omit" Advance DATA_POINTER by m.n byte.bits
#
# Rm
# "Reverse" Decrement DATA_POINTER by m bytes. R0 byte aligns.
#
# Wm
# Position DATA_POINTER at word m. The word size is either 4 or 8
# bytes, depending upon whether or not this is a 32 or 64 bit format
# trace. This bares no relation to the %W format specifier.
#
# B. Codes that cause data to be output.
# Am.n
# Left justified ascii.
# m=length in bytes of the binary data.
# n=width of the displayed field.
# The data pointer is rounded up to the next byte boundary.
# Example
# DATA_POINTER|
# V
# xxxxxhello world\0xxxxxx
#
# i. A8.16 results in: |hello wo |
# DATA_POINTER--------|
# V
# xxxxxhello world\0xxxxxx
#
# ii. A16.16 results in: |hello world |
# DATA_POINTER----------------|
# V
# xxxxxhello world\0xxxxxx
#
# iii. A16 results in: |hello world|
# DATA_POINTER----------------|
# V
# xxxxxhello world\0xxxxxx
#
# iv. A0.16 results in: | |
# DATA_POINTER|
# V
# xxxxxhello world\0xxxxxx
#
# Sm (m = 1, 2, 4, or 8)
# Left justified ascii string.
# The length of the string is in the first m bytes of
# the data. This length of the string does not include these bytes.
# The data pointer is advanced by the length value.
# SW specifies the length to be 4 or 8 bytes, depending upon whether
# this is a 32 or 64 bit hook.
# Example
# DATA_POINTER|
# V
# xxxxxBhello worldxxxxxx (B = hex 0x0b)
#
# i. S1 results in: |hello world|
# DATA_POINTER-----------|
# V
# xxxxBhello worldxxxxxx
#
# $reg%S1
# A register with the format code of 'Sx' works "backwards" from
# a register with a different type. The format is Sx, but the length
# of the string comes from $reg instead of the next n bytes.
#
# Bm.n
# Binary format.
# m = length in bytes
# n = length in bits
# The length in bits of the data is m * 8 + n. B2.3 and B0.19 are the same.
# Unlike the other printing FORMAT codes, the DATA_POINTER
# can be bit aligned and is not rounded up to the next byte boundary.
#
# Xm
# Hex format.
# m = length in bytes. m=0 thru 16
# X0 is the same as X1, except that no trailing space is output after
# the data. Therefore X0 can be used with a LOOP to output an
# unbroken string of data.
# The DATA_POINTER is advanced by m (1 if m = 0).
# XW will format either 4 or 8 bytes of data depending upon whether
# this is a 32 or 64 bit hook. The DATA_POINTER is advanced
# by 4 or 8 bytes.
#
# Dm (m = 2, 4, or 8)
# Signed decimal format.
# The length of the data is m bytes.
# The DATA_POINTER is advanced by m.
# DW will format either 4 or 8 bytes of data depending upon whether
# this is a 32 or 64 bit hook. The DATA_POINTER is advanced
# by 4 or 8 bytes.
#
# Um (m = 2, 4, or 8)
# Unsigned decimal format.
# The length of the data is m bytes.
# The DATA_POINTER is advanced by m.
# UW will format either 4 or 8 bytes of data depending upon whether
# this is a 32 or 64 bit hook. The DATA_POINTER is advanced
# by 4 or 8 bytes.
#
# om (m = 2, 4, or 8)
# Octal format.
# The length of the data is m bytes.
# The DATA_POINTER is advanced by m.
# ow will format either 4 or 8 bytes of data depending upon whether
# this is a 32 or 64 bit hook. The DATA_POINTER is advanced
# by 4 or 8 bytes.
#
# F4
# Floating point format. (like %0.4E)
# The length of the data is 4 bytes.
# The format of the data is that of C type 'float'.
# The DATA_POINTER is advanced by 4.
#
# F8
# Floating point format. (like %0.4E)
# The length of the data is 8 bytes.
# The format of the data is that of C type 'double'.
# The DATA_POINTER is advanced by 8.
#
# HB
# Number of bytes in trcgen() variable length buffer.
# The DATA_POINTER is not changed.
#
# HT
# 32-bit hooks:
# The hooktype. (0 - E)
# trcgen = 0, trchk = 1, trchl = 2, trchkg = 6
# trcgent = 8, trchkt = 9, trchlt = A, trchkgt = E
# HT & 0x07 masks off the timestamp bit
# This is used for allowing multiple, different trchook() calls with
# the same template.
# The DATA_POINTER is not changed.
# 64-bit hooks
# This is the flags field.
# 0x8000 - hook is time stamped.
# 0x4000 - This is a generic trace.
#
# Note that if the hook was reformatted as discussed under item
# I.C above, HT is set to reflect the flags in the new format.
#
# C. Codes that interpret the data in some way before output.
# Tm (m = 4, or 8)
# Output the next m bytes as a data and time string,
# in GMT timezone format. (as in ctime(&seconds))
# The DATA_POINTER is advanced by m bytes.
# Only the low-order 32-bits of the time are actually used.
# TW will format either 4 or 8 bytes of data depending upon whether
# this is a 32 or 64 bit hook. The DATA_POINTER is advanced
# by 4 or 8 bytes.
#
# Em (m = 1, 2, 4, or 8)
# Output the next m bytes as an 'errno' value, replacing
# the numeric code with the corresponding #define name in
# /usr/include/sys/errno.h
# The DATA_POINTER is advanced by 1, 2, 4, or 8.
# EW will format either 4 or 8 bytes of data depending upon whether
# this is a 32 or 64 bit hook. The DATA_POINTER is advanced
# by 4 or 8 bytes.
#
# Pm (m = 4, or 8)
# Use the next m bytes as a process id (pid), and
# output the pathname of the executable with that process id.
# Process ids and their pathnames are acquired by the trace command
# at the start of a trace and by trcrpt via a special EXEC tracehook.
# The DATA_POINTER is advanced by 4 or 8 bytes.
# PW will format either 4 or 8 bytes of data depending upon whether
# this is a 32 or 64 bit hook.
#
# \t
# Output a tab. \t\t\t outputs 3 tabs. Tabs are expanded to spaces,
# using a fixed tabstop separation of 8. If L=0 indentation is used,
# the first tabstop is at 3.
#
# \n
# Output a newline. \n\n\n outputs 3 newlines.
# The newline is left-justified according to the INDENTATION LEVEL.
#
# $macro
# Undefined macros have the value of 0.
# The DATA_POINTER is not changed.
# An optional format can be used with macros:
# $v1%X8 will output the value $v1 in X8 format.
# $zz%B0.8 will output the value $v1 in 8 bits of binary.
# Understood formats are: X, D, U, B and W. Others default to X2.
#
# The W format is used to mask the register.
# Wm.n masks off all bits except bits m through n, then shifts the
# result right m bits. For example, if $ZZ = 0x12345678, then
# $zz%W24.27 yields 2. Note the bit numbering starts at the right,
# with 0 being the least significant bit.
#
# "string" 'string' data type
# Output the characters inside the double quotes exactly. A string
# is treated as a descriptor. Use "" as a NULL string.
#
# `string format $macro` If a string is backquoted, it is expanded
# as a quoted string, except that FORMAT codes and $registers are
# expanded as registers.
#
# III. SWITCH statement
# A format code followed by a comma is a SWITCH statement.
# Each CASE entry of the SWITCH statement consists of
# 1. a 'matchvalue' with a type (usually numeric) corresponding to
# the format code.
# 2. a simple 'string' or a new 'descriptor' bounded by braces.
# A descriptor is a sequence of format codes, strings, switches,
# and loops.
# 3. and a comma delimiter.
# The switch is terminated by a CASE entry without a comma delimiter.
# The CASE entry selected is the first entry whose matchvalue
# is equal to the expansion of the format code.
# The special matchvalue '\*' is a wildcard and matches anything.
# The DATA_POINTER is advanced by the format code.
#
#
# IV. LOOP statement
# The syntax of a 'loop' is
# LOOP format_code { descriptor }
# The descriptor is executed N times, where N is the numeric value
# of the format code.
# The DATA_POINTER is advanced by the format code plus whatever the
# descriptor does.
# Loops are used to output binary buffers of data, so descriptor is
# usually simply X1 or X0. Note that X0 is like X1 but does not
# supply a space separator ' ' between each byte.
#
#
# V. macro assignment and expressions
# 'macros' are temporary (for the duration of that event) variables
# that work like shell variables.
# They are assigned a value with the syntax:
# {{ $xxx = EXPR }}
# where EXPR is a combination of format codes, macros, and constants.
# Allowed operators are + - / *
# For example:
#{{ $dog = 7 + 6 }} {{ $cat = $dog * 2 }} $dog $cat
#
# will output:
#000D 001A
#
# Macros are useful in loops where the loop count is not always
# just before the data:
#G1.5 {{ $count = B0.5 }} G11 LOOP $count {X0}
#
# Up to 255 macros can be defined per template.
#
#
# VI. Special macros:
# $HOOKENV This is either "32" or "64" depending upon
# whether this is a 32 or 64 bit trace hook.
# This can be used to interpret the HT value.
# $TRACEENV This is either "32" or "64" depending upon
# whether this is a 32 or 64 bit trace, i.e., whether the
#
trace was generated by a 32 or 64 bit kernel.
# Since hooks will be formatted according to the environment
# they came from, $HOOKENV should normally be used.
# $RELLINENO line number for this event. The first line starts at 1.
# $D1 - $D5 dataword 1 through dataword 5. No change to datapointer.
# The data word is either 4 or 8 bytes.
# $L1 - $L5 Long dataword 1,5(64 bits). No change to datapointer.
# $HD hookdata (lower 16 bits)
# For a 32-bit generic hook, $HD is the length of the
# generic data traced.
# For 32 or 64 bit generic hooks, use $HL.
# $HL Hook data length. This is the length in bytes of the hook
# data. For generic entries it is the length of the
# variable length buffer and doesn't include the data word.
# $WORDSIZE Contains the word size, 4 or 8 bytes, of the current
# entry, (i.e.) $HOOKENV / 8.
# $GENERIC specifies whether the entry is a generic entry. The
# value is 1 for a generic entry, and 0 if not generic.
# $GENERIC is especially useful if the hook can come from
# either a 32 or 64 bit environment, since the types (HT)
# have different formats.
# $TOTALCPUS Output the number of CPUs in the system.
# $TRACEDCPUS Output the number of CPUs that were traced.
# $REPORTEDCPUS Output the number of CPUs active in this report.
# This can decrease as CPUs stop tracing when, for example,
# the single-buffer trace, -f, was used and the buffers for
# each CPU fill up.
# $LARGEDATATYPES This is set to 1 if the kernel is supporting large data
# types for 64-bit applications.
# $SVC Output the name of the current SVC
# $EXECPATH Output the pathname of the executable for current process.
# $PID Output the current process id.
# $TID Output the current thread id.
# $CPUID Output the current processor id.
# $PRI Output the current process priority
# $ERROR Output an error message to the report and exit from the
# template after the current descriptor is processed.
# The error message supplies the logfile, logfile offset of the
# start of that event, and the traceid.
# $LOGIDX Current logfile offset into this event.
# $LOGIDX0 Like $LOGIDX, but is the start of the event.
# $LOGFILE Name of the logfile being processed.
# $TRACEID Traceid of this event.
# $DEFAULT Use the DEFAULT template 008
# $STOP End the trace report right away
# $BREAK End the current trace event
# $SKIP Like break, but don't print anything out.
# $DATAPOINTER The DATA_POINTER. It can be set and manipulated
# like other user-macros.
# {{ $DATAPOINTER = 5 }} is equivalent to G5
#
# Note: For generic trace hooks, $DATAPOINTER points to the
# data word. This means it is 0x4 for 32-bit hooks, and 0x8 for
# 64-bit hooks.
# For non-generic hooks, $DATAPOINTER is set to 2 for 32-bit hooks
# and to 6 for 64 bit trace hooks. This means it always
# points to the subhook id.
#
# $BASEPOINTER Usually 0. It is the starting offset into an event. The actual
# offset is the DATA_POINTER + BASE_POINTER. It is used with
# template subroutines, where the parts on an event have the
# same structure, and can be printed by the same template, but
# might have different starting points into an event.
# $IPADDR IP address of this machine, 4 bytes.
# $BUFF Buffer allocation scheme used, 1=kernel heap, 2=separate segment.
#
# VII. Template subroutines
# If a macro name consists of 3 hex digits, it is a "template subroutine".
# The template whose traceid equals the macro name is inserted in place
# of the macro.
#
# The data pointer is where it was when the template
# substitution was encountered. Any change made to the data pointer
# by the template subroutine remains in affect when the template ends.
#
# Macros used within the template subroutine correspond to those in the
# calling template. The first definition of a macro in the called template
# is the same variable as the first in the called. The names are not
# related.
#
# NOTE: Nesting of template subroutines is supported to 10 levels.
#
# Example:
# Output the trace label ESDI STRATEGY.
# The macro '$stat' is set to bytes 2 and 3 of the trace event.
# Then call template 90F to interpret a buf header. The macro '$return'
# corresponds to the macro '$rv', because they were declared in the same
# order. A macro definition with no '=' assignment just declares the name
# like a place holder. When the template returns, the saved special
# status word is output and the returned minor device number.
#
#900 1.0 "ESDI STRATEGY" {{ $rv = 0 }} {{ $stat = X2 }} \
# $90F \n\
#special_esdi_status=$stat for minor device $rv
#
#90F 1.0 "" G4 {{ $return }} \
# block number X4 \n\
# byte count X4 \n\
# B0.1, 1 B_FLAG0 \
# B0.1, 1 B_FLAG1 \
# B0.1, 1 B_FLAG2 \
# G16 {{ $return = X2 }}
#
#
# Note: The $DEFAULT reserved macro is the same as $008
#
# VIII. BITFLAGS statement
# The syntax of a 'bitflags' is
# BITFLAGS [format_code|register],
# flag_value string {optional string if false}, or
# '&' mask field_value string,
# ...
#
# This statement simplifies expanding state flags, because it looks
# a lot like a series of #defines.
# The '&' mask is used for interpreting bit fields.
# The mask is anded to the register and the result is compared to
# the field_value. If a match, the string is printed.
# The base is 16 for flag_values and masks.
# The DATA_POINTER is advanced if a format code is used.
# Note: the default base for BITFLAGS is 16. If the mask or field value
# has a leading "o", the number is octal. 0x or 0X makes the number hexadecimal.