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