User Commands tnfdump(1)
NAME
tnfdump - convert binary TNF file to ASCI
SYNOPSIS
tnfdump [-r] [-x] tnffile...
DESCRIPTION
The tnfdump utility converts the specified binary TNF trace
files to ASCI. The ASCI output can be used to do perfor-
mance analysis. The default mode (without the -r option)
prints all the event records (that were generated by
TNFPROBE(3TNF)) and the event descriptor records only. It
also orders the events by time.
OPTIONS
The following option is supported:
-r Does a raw conversion of TNF to ASCI. The output is a
literal transalation of the binary TNF file and
includes all the records in the file. This output is
useful only if you have a good understanding of TNF. A
sample output is listed in EXAMPLES below.
-x Prints all TNF unsigned type argument values in hexa-
decimal format instead of decimal format.
RETURN VALUES
tnfdump returns 0 on succcessful exit.
EXAMPLES
Example 1 Converting a file into ASCI
To convert the file /tmp/trace-2130 into ASCI, use the
tnfdump command and the name of the binary trace file. Be
aware that the tnfdump output goes to stdout by default.
example% tnfdump /tmp/trace-2130
probe tnfname: "inloop" tnfstring: "keys cookie main loop;\
file cookie2.c;line 50;sunw%debug in the loop"
probe tnfname: "end" tnfstring: "keys cookie main end;\
file cookie2.c;line 41;sunw%debug exiting program"
------------- ----------- ---- ------ --- ---------- ----------------
Elapsed (ms) Delta (ms) PID LWPID TID CPU Probe Data/
Name Description . . .
SunOS 5.11 Last change: 22 Jan 2001 1
User Commands tnfdump(1)
------------- ----------- ---- ------ --- ---------- ----------------
0.000000 0.000000 8792 1 0 - inloop loopcount: 0
totaliterations: 0
0.339000 0.339000 8792 1 0 - inloop loopcount: 1
totaliterations: 1
0.350500 0.011500 8792 1 0 - inloop loopcount: 2
totaliterations: 2
0.359500 0.009000 8792 1 0 - inloop loopcount: 3
totaliterations: 3
0.369500 0.010000 8792 1 0 - inloop loopcount: 4
totaliterations: 4
7775.969500 7775.600000 8792 1 0 - inloop loopcount: 0
totaliterations: 5
7776.016000 0.046500 8792 1 0 - inloop loopcount: 1
totaliterations: 6
7776.025000 0.009000 8792 1 0 - inloop loopcount: 2
totaliterations: 7
7776.034000 0.009000 8792 1 0 - inloop loopcount: 3
totaliterations: 8
7776.043000 0.009000 8792 1 0 - inloop loopcount: 4
totaliterations: 9
7776.052000 0.009000 8792 1 0 - inloop loopcount: 5
totaliterations: 10
7776.061000 0.009000 8792 1 0 - inloop loopcount: 6
totaliterations: 11
9475.979500 1699.918500 8792 1 0 - end nodestruct:
{ type: nodetnf
cursum: 9 maxcnt: 12 }
All probes that are encountered during execution have a
description of it printed out. The description is one per
line prefixed by the keyword 'probe'. The name of the probe
is in double quotes after the keyword 'tnfname'. The
description of this probe is in double quotes after the key-
word 'tnfstring'.
A heading is printed after all the description of the probes
are printed. The first column gives the elapsed time in
milli-seconds since the first event. The second column gives
the elapsed time in milli-seconds since the previous event.
The next four columns are the process id, lwp id, thread id,
and cpu number. The next column is the name of the probe
that generated this event. This can be matched to the probe
description explained above. The last column is the data
that the event contains, formatted as argnamen (see
TNFPROBE(3TNF)) followed by a colon and the value of that
argument. The format of the value depends on its type.
SunOS 5.11 Last change: 22 Jan 2001 2
User Commands tnfdump(1)
tnfopaque arguments are printed in hexadecimal. All other
integers are printed in decimal. Strings are printed in dou-
ble quotes and user-defined records are enclosed in braces
`{ }'. The first field of a user defined record indicates
its TNF type (see TNFDECLARERECORD(3TNF)). The rest of the
fields are the members of the record.
A `-' in any column indicates that there is no data for that
particular column.
Example 2 To do a raw conversion of a file into ASCI
To do a raw conversion of the file /tmp/trace-4000 into
ASCI, use:
example% tnfdump -r /tmp/trace-4000
The output will look like the following:
0x10e00 : {
tnftag 0x109c0 tnfblockheader
generation 1
bytesvalid 320
Alock 0
Block 0
nextblock 0x0
}
0x10e10 : {
tnftag 0x10010 probe1
tnftagarg 0x10e24
timedelta 128
testulong 4294967295
testlong -1
}
0x10e24 : {
tnftag 0x10cf4 tnfschedrec
tid 0
lwpid 1
pid 13568
timebase 277077875828500
}
0x10e3c : {
tnftag 0x11010 probe2
SunOS 5.11 Last change: 22 Jan 2001 3
User Commands tnfdump(1)
tnftagarg 0x10e24
timedelta 735500
teststr 0x10e48 "string1"
}
0x10e48 : {
tnftag 0x1072c tnfstring
tnfselfsize 16
chars "string1"
}
0x10e58 : {
tnftag 0x110ec probe3
tnftagarg 0x10e24
timedelta 868000
testulonglong 18446744073709551615
testlonglong -1
testfloat 3.142857
}
0x110ec : {
tnftag 0x10030 tnfprobetype
tnftagcode 42
tnfname 0x1110c "probe3"
tnfproperties 0x1111c
tnfslottypes 0x11130
tnftypesize 32
tnfslotnames 0x111c4
tnfstring 0x11268 "keys targdebug main;\
file targdebug.c;line 61;"
}
0x1110c : {
tnftag 0x10068 tnfname
tnfselfsize 16
chars "probe3"
}
0x1111c : {
tnftag 0x100b4 tnfproperties
tnfselfsize 20
0 0x101a0 tnftagged
1 0x101c4 tnfstruct
2 0x10b84 tnftagarg
}
0x11130 : {
tnftag 0x10210 tnfslottypes
tnfselfsize 28
0 0x10bd0 tnfprobeevent
1 0x10c20 tnftimedelta
2 0x1114c tnfuint64
3 0x10d54 tnfint64
4 0x11188 tnffloat32
}
SunOS 5.11 Last change: 22 Jan 2001 4
User Commands tnfdump(1)
The first number is the file offset of the record. The
record is enclosed in braces `{ }'. The first column in a
record is the slot name (for records whose fields do not
have names, it is the type name). The second column in the
record is the value of that slot if it is a scalar (only
scalars that are of type tnfopaque are printed in hex), or
the offset of the record if it is a reference to another
record.
The third column in a record is optional. It does not exist
for scalar slots of records. If it exists, the third column
is a type name with or without angle brackets, or a string
in double quotes. Unadorned names indicate a reference to
the named metatag record (that is, a reference to a record
with that name in the tnfname field). Type names in angled
brackets indicate a reference to a record that is an
instance of that type (that is, a reference to a record with
that name in the tnftag field). The content of strings are
printed out in double quotes at the reference site.
Records that are arrays have their array elements follow the
header slots, and are numbered 0, 1, 2, and so on, except
strings where the string is written as the 'chars' (pseudo-
name) slot.
Records that are events (generated by TNFPROBE(3TNF)) will
have a slot name of tnftagarg as their second field which
is a reference to the schedule record. Schedule records
describe more information about the event like the thread-
id, process-id, and the timebase. The timedelta of an
event can be added to the timebase of the schedule record
that the event references, to give an absolute time. This
time is expressed as nanoseconds since some arbitrary time
in the past (see gethrtime(3C)).
Example 3 Printing TNF unsigned arguments in hexadecimal
To print TNF unsigned arguments in hexadecimal for the file
/tmp/trace-2192, use:
example% tnfdump -x /tmp/trace-2192
SunOS 5.11 Last change: 22 Jan 2001 5
User Commands tnfdump(1)
The output will look like the following:
probe tnfname: "start" tnfstring: "keys cookie main;
file test17.c;line 20;sunw%debug starting main"
probe tnfname: "inloop" tnfstring: "keys cookie main
loop;file test17.c;line 41;sunw%debug in the loop"
probe tnfname: "final" tnfstring: "keys cookie main
final;file test17.c;line 32;sunw%debug in the final"
------------ ----------- ---- ----- --- --------- ---------------------
Elapsed Delta PID LWPID TID CPU Probe Data/Description ...
(ms) (ms) Name
------------ ----------- ---- ----- --- --------- ---------------------
0.000000 0.000000 6280 1 1 - start
2455.211311 2455.211311 6280 1 1 - inloop loopcount: 0x0
totaliterations: 0x0
2455.215768 0.004457 6280 1 1 - inloop loopcount: 0x1
totaliterations: 0x1
2455.217041 0.001273 6280 1 1 - inloop loopcount: 0x2
totaliterations: 0x2
2455.218285 0.001244 6280 1 1 - inloop loopcount: 0x3
totaliterations: 0x3
2455.219600 0.001315 6280 1 1 - inloop loopcount: 0x4
totaliterations: 0x4
4058.815125 1603.595525 6280 1 1 - inloop loopcount: 0x0
totaliterations: 0x5
4058.818699 0.003574 6280 1 1 - inloop loopcount: 0x1
totaliterations: 0x6
4058.819931 0.001232 6280 1 1 - inloop loopcount: 0x2
totaliterations: 0x7
4058.821264 0.001333 6280 1 1 - inloop loopcount: 0x3
totaliterations: 0x8
4058.822520 0.001256 6280 1 1 - inloop loopcount: 0x4
totaliterations: 0x9
4058.823781 0.001261 6280 1 1 - inloop loopcount: 0x5
totaliterations: 0xa
4058.825037 0.001256 6280 1 1 - inloop loopcount: 0x6
totaliterations: 0xb
13896.655450 9837.830413 6280 1 1 - final loopcount16: 0x258
totaliterations8: 0xb0
::
::
::
Notice that the loopcount and the totaliterations are TNF
unsigned arguments. Their values are printed in hexadecimal
when requested by option -x.
SunOS 5.11 Last change: 22 Jan 2001 6
User Commands tnfdump(1)
ATRIBUTES
See attributes(5) for descriptions of the following attri-
butes:
ATRIBUTE TYPE ATRIBUTE VALUE
Availability SUNWtnfd
SEE ALSO
prex(1), gethrtime(3C), TNFDECLARERECORD(3TNF),
TNFPROBE(3TNF), tnfprocessdisable(3TNF), attributes(5)
SunOS 5.11 Last change: 22 Jan 2001 7
|
