1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
|
'\" te
.\" Copyright (c) 2001, Sun Microsystems, Inc.
.\" The contents of this file are subject to the terms of the Common Development and Distribution License (the "License"). You may not use this file except in compliance with the License.
.\" You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE or http://www.opensolaris.org/os/licensing. See the License for the specific language governing permissions and limitations under the License.
.\" When distributing Covered Code, include this CDDL HEADER in each file and include the License file at usr/src/OPENSOLARIS.LICENSE. If applicable, add the following below this CDDL HEADER, with the fields enclosed by brackets "[]" replaced with your own identifying information: Portions Copyright [yyyy] [name of copyright owner]
.TH TNFDUMP 1 "December 28, 2020"
.SH NAME
tnfdump \- convert binary TNF file to ASCII
.SH SYNOPSIS
.nf
\fBtnfdump\fR [\fB-r\fR] [\fB-x\fR] \fItnf_file\fR...
.fi
.SH DESCRIPTION
The \fBtnfdump\fR utility converts the specified binary \fBTNF\fR trace files
to \fBASCII\fR. The \fBASCII\fR output can be used to do performance analysis.
The default mode (without the \fB-r\fR option) prints all the event records
(that were generated by \fBTNF_PROBE\fR(3TNF)) and the event descriptor records
only. It also orders the events by time.
.SH OPTIONS
The following option is supported:
.sp
.ne 2
.na
\fB\fB-r\fR\fR
.ad
.RS 6n
Does a raw conversion of \fBTNF\fR to \fBASCII\fR. The output is a literal
translation of the binary \fBTNF\fR file and includes all the records in the
file. This output is useful only if you have a good understanding of
\fBTNF\fR. A sample output is listed in EXAMPLES below.
.RE
.sp
.ne 2
.na
\fB\fB-x\fR\fR
.ad
.RS 6n
Prints all \fBTNF\fR unsigned type argument values in hexadecimal format
instead of decimal format.
.RE
.SH RETURN VALUES
\fBtnfdump\fR returns \fB0\fR on successful exit.
.SH EXAMPLES
\fBExample 1 \fRConverting a file into ASCII
.sp
.LP
To convert the file \fB/tmp/trace-2130\fR into \fBASCII\fR, use the
\fBtnfdump\fR command and the name of the binary trace file. Be aware that the
\fBtnfdump\fR output goes to \fBstdout\fR by default.
.sp
.in +2
.nf
example% \fBtnfdump /tmp/trace-2130\fR
.fi
.in -2
.sp
.sp
.in +2
.nf
probe tnf_name: "inloop" tnf_string: "keys cookie main loop;\e
file cookie2.c;line 50;sunw%debug in the loop"
probe tnf_name: "end" tnf_string: "keys cookie main end;\e
file cookie2.c;line 41;sunw%debug exiting program"
------------- ----------- ---- ------ --- ---------- ----------------
Elapsed (ms) Delta (ms) PID LWPID TID CPU Probe Data/
Name Description ...
------------- ----------- ---- ------ --- ---------- ----------------
0.000000 0.000000 8792 1 0 - inloop loop_count: 0
total_iterations: 0
0.339000 0.339000 8792 1 0 - inloop loop_count: 1
total_iterations: 1
0.350500 0.011500 8792 1 0 - inloop loop_count: 2
total_iterations: 2
0.359500 0.009000 8792 1 0 - inloop loop_count: 3
total_iterations: 3
0.369500 0.010000 8792 1 0 - inloop loop_count: 4
total_iterations: 4
7775.969500 7775.600000 8792 1 0 - inloop loop_count: 0
total_iterations: 5
7776.016000 0.046500 8792 1 0 - inloop loop_count: 1
total_iterations: 6
7776.025000 0.009000 8792 1 0 - inloop loop_count: 2
total_iterations: 7
7776.034000 0.009000 8792 1 0 - inloop loop_count: 3
total_iterations: 8
7776.043000 0.009000 8792 1 0 - inloop loop_count: 4
total_iterations: 9
7776.052000 0.009000 8792 1 0 - inloop loop_count: 5
total_iterations: 10
7776.061000 0.009000 8792 1 0 - inloop loop_count: 6
total_iterations: 11
9475.979500 1699.918500 8792 1 0 - end node_struct:
{ type: node_tnf
cur_sum: 9 max_cnt: 12 }
.fi
.in -2
.sp
.sp
.LP
All probes that are encountered during execution have a description of it
printed out. The description is one per line prefixed by the
keyword '\fBprobe\fR'. The name of the probe is in double quotes after the
keyword '\fBtnf_name\fR'. The description of this probe is in double quotes after the
keyword '\fBtnf_string\fR'.
.sp
.LP
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 \fBarg_name_n\fR \fB(see\fR
\fBTNF_PROBE\fR(3TNF)) followed by a colon and the value of that argument. The
format of the value depends on its type. \fBtnf_opaque\fR arguments are printed
in hexadecimal. All other integers are printed in decimal. Strings are printed
in double quotes and user-defined records are enclosed in braces `{ }'. The
first field of a user defined record indicates its \fBTNF\fR type (see
\fBTNF_DECLARE_RECORD\fR(3TNF)). The rest of the fields are the members of the
record.
.sp
.LP
A `-' in any column indicates that there is no data for that particular column.
.LP
\fBExample 2 \fRTo do a raw conversion of a file into ASCII
.sp
.LP
To do a raw conversion of the file \fB/tmp/trace-4000\fR into \fBASCII\fR, use:
.sp
.in +2
.nf
example% \fBtnfdump -r /tmp/trace-4000\fR
.fi
.in -2
.sp
.sp
.LP
The output will look like the following:
.sp
.in +2
.nf
0x10e00 : {
tnf_tag 0x109c0 tnf_block_header
generation 1
bytes_valid 320
A_lock 0
B_lock 0
next_block 0x0
}
0x10e10 : {
tnf_tag 0x10010 probe1
tnf_tag_arg 0x10e24 <tnf_sched_rec>
time_delta 128
test_ulong 4294967295
test_long -1
}
0x10e24 : {
tnf_tag 0x10cf4 tnf_sched_rec
tid 0
lwpid 1
pid 13568
time_base 277077875828500
}
0x10e3c : {
tnf_tag 0x11010 probe2
tnf_tag_arg 0x10e24 <tnf_sched_rec>
time_delta 735500
test_str 0x10e48 "string1"
}
0x10e48 : {
tnf_tag 0x1072c tnf_string
tnf_self_size 16
chars "string1"
}
0x10e58 : {
tnf_tag 0x110ec probe3
tnf_tag_arg 0x10e24 <tnf_sched_rec>
time_delta 868000
test_ulonglong 18446744073709551615
test_longlong -1
test_float 3.142857
}
\|.\|.\|.
\|.\|.\|.
\|.\|.\|.
0x110ec : {
tnf_tag 0x10030 tnf_probe_type
tnf_tag_code 42
tnf_name 0x1110c "probe3"
tnf_properties 0x1111c <tnf_properties>
tnf_slot_types 0x11130 <tnf_slot_types>
tnf_type_size 32
tnf_slot_names 0x111c4 <tnf_slot_names>
tnf_string 0x11268 "keys targdebug main;\e
file targdebug.c;line 61;"
}
0x1110c : {
tnf_tag 0x10068 tnf_name
tnf_self_size 16
chars "probe3"
}
0x1111c : {
tnf_tag 0x100b4 tnf_properties
tnf_self_size 20
0 0x101a0 tnf_tagged
1 0x101c4 tnf_struct
2 0x10b84 tnf_tag_arg
}
0x11130 : {
tnf_tag 0x10210 tnf_slot_types
tnf_self_size 28
0 0x10bd0 tnf_probe_event
1 0x10c20 tnf_time_delta
2 0x1114c tnf_uint64
3 0x10d54 tnf_int64
4 0x11188 tnf_float32
}
.fi
.in -2
.sp
.sp
.LP
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
\fBtnf_opaque\fR are printed in hex), or the offset of the record if it is a
reference to another record.
.sp
.LP
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 \fBtnf_name\fR 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 \fBtnf_tag\fR field). The content of strings are printed
out in double quotes at the reference site.
.sp
.LP
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.
.sp
.LP
Records that are events (generated by \fBTNF_PROBE\fR(3TNF)) will have a slot
name of \fBtnf_tag_arg\fR 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 \fBtime_base\fR. The \fBtime_delta\fR
of an event can be added to the \fBtime_base\fR 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 \fBgethrtime\fR(3C)).
.LP
\fBExample 3 \fRPrinting TNF unsigned arguments in hexadecimal
.sp
.LP
To print \fBTNF\fR unsigned arguments in hexadecimal for the file
\fB/tmp/trace-2192\fR, use:
.sp
.in +2
.nf
example% \fBtnfdump -x /tmp/trace-2192\fR
.fi
.in -2
.sp
.sp
.LP
The output will look like the following:
.sp
.in +2
.nf
probe tnf_name: "start" tnf_string: "keys cookie main;
file test17.c;line 20;sunw%debug starting main"
probe tnf_name: "inloop" tnf_string: "keys cookie main
loop;file test17.c;line 41;sunw%debug in the loop"
probe tnf_name: "final" tnf_string: "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 loop_count: 0x0
total_iterations: 0x0
2455.215768 0.004457 6280 1 1 - inloop loop_count: 0x1
total_iterations: 0x1
2455.217041 0.001273 6280 1 1 - inloop loop_count: 0x2
total_iterations: 0x2
2455.218285 0.001244 6280 1 1 - inloop loop_count: 0x3
total_iterations: 0x3
2455.219600 0.001315 6280 1 1 - inloop loop_count: 0x4
total_iterations: 0x4
4058.815125 1603.595525 6280 1 1 - inloop loop_count: 0x0
total_iterations: 0x5
4058.818699 0.003574 6280 1 1 - inloop loop_count: 0x1
total_iterations: 0x6
4058.819931 0.001232 6280 1 1 - inloop loop_count: 0x2
total_iterations: 0x7
4058.821264 0.001333 6280 1 1 - inloop loop_count: 0x3
total_iterations: 0x8
4058.822520 0.001256 6280 1 1 - inloop loop_count: 0x4
total_iterations: 0x9
4058.823781 0.001261 6280 1 1 - inloop loop_count: 0x5
total_iterations: 0xa
4058.825037 0.001256 6280 1 1 - inloop loop_count: 0x6
total_iterations: 0xb
13896.655450 9837.830413 6280 1 1 - final loop_count16: 0x258
total_iterations8: 0xb0
::
::
::
.fi
.in -2
.sp
.sp
.LP
Notice that the \fBloop_count\fR and the \fBtotal_iterations\fR are \fBTNF\fR
unsigned arguments. Their values are printed in hexadecimal when requested by
option \fB-x\fR.
.SH SEE ALSO
\fBprex\fR(1), \fBgethrtime\fR(3C), \fBTNF_DECLARE_RECORD\fR(3TNF),
\fBTNF_PROBE\fR(3TNF), \fBtnf_process_disable\fR(3TNF), \fBattributes\fR(5)
|