4 * The contents of this file are subject to the terms of the
5 * Common Development and Distribution License (the "License").
6 * You may not use this file except in compliance with the License.
8 * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE
9 * or http://www.opensolaris.org/os/licensing.
10 * See the License for the specific language governing permissions
11 * and limitations under the License.
13 * When distributing Covered Code, include this CDDL HEADER in each
14 * file and include the License file at usr/src/OPENSOLARIS.LICENSE.
15 * If applicable, add the following below this CDDL HEADER, with the
16 * fields enclosed by brackets "[]" replaced with your own identifying
17 * information: Portions Copyright [yyyy] [name of copyright owner]
22 * Copyright 2008 Sun Microsystems, Inc. All rights reserved.
23 * Use is subject to license terms.
26 #pragma ident "%Z%%M% %I% %E% SMI"
39 #include <sys/types.h>
40 #include <sys/modctl.h>
44 #include <sys/lockstat.h>
49 #define LOCKSTAT_OPTSTR "x:bths:n:d:i:l:f:e:ckwWgCHEATID:RpPo:V"
51 #define LS_MAX_STACK_DEPTH 50
52 #define LS_MAX_EVENTS 64
54 typedef struct lsrec
{
55 struct lsrec
*ls_next
; /* next in hash chain */
56 uintptr_t ls_lock
; /* lock address */
57 uintptr_t ls_caller
; /* caller address */
58 uint32_t ls_count
; /* cumulative event count */
59 uint32_t ls_event
; /* type of event */
60 uintptr_t ls_refcnt
; /* cumulative reference count */
61 uint64_t ls_time
; /* cumulative event duration */
62 uint32_t ls_hist
[64]; /* log2(duration) histogram */
63 uintptr_t ls_stack
[LS_MAX_STACK_DEPTH
];
66 typedef struct lsdata
{
67 struct lsrec
*lsd_next
; /* next available */
68 int lsd_count
; /* number of records */
72 * Definitions for the types of experiments which can be run. They are
73 * listed in increasing order of memory cost and processing time cost.
74 * The numerical value of each type is the number of bytes needed per record.
76 #define LS_BASIC offsetof(lsrec_t, ls_time)
77 #define LS_TIME offsetof(lsrec_t, ls_hist[0])
78 #define LS_HIST offsetof(lsrec_t, ls_stack[0])
79 #define LS_STACK(depth) offsetof(lsrec_t, ls_stack[depth])
81 static void report_stats(FILE *, lsrec_t
**, size_t, uint64_t, uint64_t);
82 static void report_trace(FILE *, lsrec_t
**);
84 extern int symtab_init(void);
85 extern char *addr_to_sym(uintptr_t, uintptr_t *, size_t *);
86 extern uintptr_t sym_to_addr(char *name
);
87 extern size_t sym_size(char *name
);
88 extern char *strtok_r(char *, const char *, char **);
90 #define DEFAULT_NRECS 10000
93 #define MIN_AGGSIZE (16 * 1024)
94 #define MAX_AGGSIZE (32 * 1024 * 1024)
96 static int g_stkdepth
;
97 static int g_topn
= INT_MAX
;
98 static hrtime_t g_elapsed
;
99 static int g_rates
= 0;
100 static int g_pflag
= 0;
101 static int g_Pflag
= 0;
102 static int g_wflag
= 0;
103 static int g_Wflag
= 0;
104 static int g_cflag
= 0;
105 static int g_kflag
= 0;
106 static int g_gflag
= 0;
107 static int g_Vflag
= 0;
108 static int g_tracing
= 0;
109 static size_t g_recsize
;
110 static size_t g_nrecs
;
111 static int g_nrecs_used
;
112 static uchar_t g_enabled
[LS_MAX_EVENTS
];
113 static hrtime_t g_min_duration
[LS_MAX_EVENTS
];
114 static dtrace_hdl_t
*g_dtp
;
115 static char *g_predicate
;
116 static char *g_ipredicate
;
118 static int g_proglen
;
119 static int g_dropped
;
121 typedef struct ls_event_info
{
126 char ev_name
[DTRACE_NAMELEN
];
131 static ls_event_info_t g_event_info
[LS_MAX_EVENTS
] = {
132 { 'C', "Lock", "Adaptive mutex spin", "nsec",
133 "lockstat:::adaptive-spin" },
134 { 'C', "Lock", "Adaptive mutex block", "nsec",
135 "lockstat:::adaptive-block" },
136 { 'C', "Lock", "Spin lock spin", "nsec",
137 "lockstat:::spin-spin" },
138 { 'C', "Lock", "Thread lock spin", "nsec",
139 "lockstat:::thread-spin" },
140 { 'C', "Lock", "R/W writer blocked by writer", "nsec",
141 "lockstat:::rw-block", "arg2 == 0 && arg3 == 1" },
142 { 'C', "Lock", "R/W writer blocked by readers", "nsec",
143 "lockstat:::rw-block", "arg2 == 0 && arg3 == 0 && arg4" },
144 { 'C', "Lock", "R/W reader blocked by writer", "nsec",
145 "lockstat:::rw-block", "arg2 != 0 && arg3 == 1" },
146 { 'C', "Lock", "R/W reader blocked by write wanted", "nsec",
147 "lockstat:::rw-block", "arg2 != 0 && arg3 == 0 && arg4" },
148 { 'C', "Lock", "Unknown event (type 8)", "units" },
149 { 'C', "Lock", "Unknown event (type 9)", "units" },
150 { 'C', "Lock", "Unknown event (type 10)", "units" },
151 { 'C', "Lock", "Unknown event (type 11)", "units" },
152 { 'C', "Lock", "Unknown event (type 12)", "units" },
153 { 'C', "Lock", "Unknown event (type 13)", "units" },
154 { 'C', "Lock", "Unknown event (type 14)", "units" },
155 { 'C', "Lock", "Unknown event (type 15)", "units" },
156 { 'C', "Lock", "Unknown event (type 16)", "units" },
157 { 'C', "Lock", "Unknown event (type 17)", "units" },
158 { 'C', "Lock", "Unknown event (type 18)", "units" },
159 { 'C', "Lock", "Unknown event (type 19)", "units" },
160 { 'C', "Lock", "Unknown event (type 20)", "units" },
161 { 'C', "Lock", "Unknown event (type 21)", "units" },
162 { 'C', "Lock", "Unknown event (type 22)", "units" },
163 { 'C', "Lock", "Unknown event (type 23)", "units" },
164 { 'C', "Lock", "Unknown event (type 24)", "units" },
165 { 'C', "Lock", "Unknown event (type 25)", "units" },
166 { 'C', "Lock", "Unknown event (type 26)", "units" },
167 { 'C', "Lock", "Unknown event (type 27)", "units" },
168 { 'C', "Lock", "Unknown event (type 28)", "units" },
169 { 'C', "Lock", "Unknown event (type 29)", "units" },
170 { 'C', "Lock", "Unknown event (type 30)", "units" },
171 { 'C', "Lock", "Unknown event (type 31)", "units" },
172 { 'H', "Lock", "Adaptive mutex hold", "nsec",
173 "lockstat:::adaptive-release", NULL
,
174 "lockstat:::adaptive-acquire" },
175 { 'H', "Lock", "Spin lock hold", "nsec",
176 "lockstat:::spin-release", NULL
,
177 "lockstat:::spin-acquire" },
178 { 'H', "Lock", "R/W writer hold", "nsec",
179 "lockstat:::rw-release", "arg1 == 0",
180 "lockstat:::rw-acquire" },
181 { 'H', "Lock", "R/W reader hold", "nsec",
182 "lockstat:::rw-release", "arg1 != 0",
183 "lockstat:::rw-acquire" },
184 { 'H', "Lock", "Unknown event (type 36)", "units" },
185 { 'H', "Lock", "Unknown event (type 37)", "units" },
186 { 'H', "Lock", "Unknown event (type 38)", "units" },
187 { 'H', "Lock", "Unknown event (type 39)", "units" },
188 { 'H', "Lock", "Unknown event (type 40)", "units" },
189 { 'H', "Lock", "Unknown event (type 41)", "units" },
190 { 'H', "Lock", "Unknown event (type 42)", "units" },
191 { 'H', "Lock", "Unknown event (type 43)", "units" },
192 { 'H', "Lock", "Unknown event (type 44)", "units" },
193 { 'H', "Lock", "Unknown event (type 45)", "units" },
194 { 'H', "Lock", "Unknown event (type 46)", "units" },
195 { 'H', "Lock", "Unknown event (type 47)", "units" },
196 { 'H', "Lock", "Unknown event (type 48)", "units" },
197 { 'H', "Lock", "Unknown event (type 49)", "units" },
198 { 'H', "Lock", "Unknown event (type 50)", "units" },
199 { 'H', "Lock", "Unknown event (type 51)", "units" },
200 { 'H', "Lock", "Unknown event (type 52)", "units" },
201 { 'H', "Lock", "Unknown event (type 53)", "units" },
202 { 'H', "Lock", "Unknown event (type 54)", "units" },
203 { 'H', "Lock", "Unknown event (type 55)", "units" },
204 { 'I', "CPU+PIL", "Profiling interrupt", "nsec",
205 "profile:::profile-97", NULL
},
206 { 'I', "Lock", "Unknown event (type 57)", "units" },
207 { 'I', "Lock", "Unknown event (type 58)", "units" },
208 { 'I', "Lock", "Unknown event (type 59)", "units" },
209 { 'E', "Lock", "Recursive lock entry detected", "(N/A)",
210 "lockstat:::rw-release", NULL
, "lockstat:::rw-acquire" },
211 { 'E', "Lock", "Lockstat enter failure", "(N/A)" },
212 { 'E', "Lock", "Lockstat exit failure", "nsec" },
213 { 'E', "Lock", "Lockstat record failure", "(N/A)" },
217 fail(int do_perror
, const char *message
, ...)
220 int save_errno
= errno
;
222 va_start(args
, message
);
223 (void) fprintf(stderr
, "lockstat: ");
224 (void) vfprintf(stderr
, message
, args
);
227 (void) fprintf(stderr
, ": %s", strerror(save_errno
));
228 (void) fprintf(stderr
, "\n");
233 dfail(const char *message
, ...)
237 va_start(args
, message
);
238 (void) fprintf(stderr
, "lockstat: ");
239 (void) vfprintf(stderr
, message
, args
);
241 (void) fprintf(stderr
, ": %s\n",
242 dtrace_errmsg(g_dtp
, dtrace_errno(g_dtp
)));
248 show_events(char event_type
, char *desc
)
250 int i
, first
= -1, last
;
252 for (i
= 0; i
< LS_MAX_EVENTS
; i
++) {
253 ls_event_info_t
*evp
= &g_event_info
[i
];
254 if (evp
->ev_type
!= event_type
||
255 strncmp(evp
->ev_desc
, "Unknown event", 13) == 0)
262 (void) fprintf(stderr
,
263 "\n%s events (lockstat -%c or lockstat -e %d-%d):\n\n",
264 desc
, event_type
, first
, last
);
266 for (i
= first
; i
<= last
; i
++)
267 (void) fprintf(stderr
,
268 "%4d = %s\n", i
, g_event_info
[i
].ev_desc
);
274 (void) fprintf(stderr
,
275 "Usage: lockstat [options] command [args]\n"
276 "\nEvent selection options:\n\n"
277 " -C watch contention events [on by default]\n"
278 " -E watch error events [off by default]\n"
279 " -H watch hold events [off by default]\n"
280 " -I watch interrupt events [off by default]\n"
281 " -A watch all lock events [equivalent to -CH]\n"
282 " -e event_list only watch the specified events (shown below);\n"
283 " <event_list> is a comma-separated list of\n"
284 " events or ranges of events, e.g. 1,4-7,35\n"
285 " -i rate interrupt rate for -I [default: %d Hz]\n"
286 "\nData gathering options:\n\n"
287 " -b basic statistics (lock, caller, event count)\n"
288 " -t timing for all events [default]\n"
289 " -h histograms for event times\n"
290 " -s depth stack traces <depth> deep\n"
291 " -x opt[=val] enable or modify DTrace options\n"
292 "\nData filtering options:\n\n"
293 " -n nrecords maximum number of data records [default: %d]\n"
294 " -l lock[,size] only watch <lock>, which can be specified as a\n"
295 " symbolic name or hex address; <size> defaults\n"
296 " to the ELF symbol size if available, 1 if not\n"
297 " -f func[,size] only watch events generated by <func>\n"
298 " -d duration only watch events longer than <duration>\n"
299 " -T trace (rather than sample) events\n"
300 "\nData reporting options:\n\n"
301 " -c coalesce lock data for arrays like pse_mutex[]\n"
302 " -k coalesce PCs within functions\n"
303 " -g show total events generated by function\n"
304 " -w wherever: don't distinguish events by caller\n"
305 " -W whichever: don't distinguish events by lock\n"
306 " -R display rates rather than counts\n"
307 " -p parsable output format (awk(1)-friendly)\n"
308 " -P sort lock data by (count * avg_time) product\n"
309 " -D n only display top <n> events of each type\n"
310 " -o filename send output to <filename>\n",
311 DEFAULT_HZ
, DEFAULT_NRECS
);
313 show_events('C', "Contention");
314 show_events('H', "Hold-time");
315 show_events('I', "Interrupt");
316 show_events('E', "Error");
317 (void) fprintf(stderr
, "\n");
323 lockcmp(lsrec_t
*a
, lsrec_t
*b
)
327 if (a
->ls_event
< b
->ls_event
)
329 if (a
->ls_event
> b
->ls_event
)
332 for (i
= g_stkdepth
- 1; i
>= 0; i
--) {
333 if (a
->ls_stack
[i
] < b
->ls_stack
[i
])
335 if (a
->ls_stack
[i
] > b
->ls_stack
[i
])
339 if (a
->ls_caller
< b
->ls_caller
)
341 if (a
->ls_caller
> b
->ls_caller
)
344 if (a
->ls_lock
< b
->ls_lock
)
346 if (a
->ls_lock
> b
->ls_lock
)
353 countcmp(lsrec_t
*a
, lsrec_t
*b
)
355 if (a
->ls_event
< b
->ls_event
)
357 if (a
->ls_event
> b
->ls_event
)
360 return (b
->ls_count
- a
->ls_count
);
364 timecmp(lsrec_t
*a
, lsrec_t
*b
)
366 if (a
->ls_event
< b
->ls_event
)
368 if (a
->ls_event
> b
->ls_event
)
371 if (a
->ls_time
< b
->ls_time
)
373 if (a
->ls_time
> b
->ls_time
)
380 lockcmp_anywhere(lsrec_t
*a
, lsrec_t
*b
)
382 if (a
->ls_event
< b
->ls_event
)
384 if (a
->ls_event
> b
->ls_event
)
387 if (a
->ls_lock
< b
->ls_lock
)
389 if (a
->ls_lock
> b
->ls_lock
)
396 lock_and_count_cmp_anywhere(lsrec_t
*a
, lsrec_t
*b
)
398 if (a
->ls_event
< b
->ls_event
)
400 if (a
->ls_event
> b
->ls_event
)
403 if (a
->ls_lock
< b
->ls_lock
)
405 if (a
->ls_lock
> b
->ls_lock
)
408 return (b
->ls_count
- a
->ls_count
);
412 sitecmp_anylock(lsrec_t
*a
, lsrec_t
*b
)
416 if (a
->ls_event
< b
->ls_event
)
418 if (a
->ls_event
> b
->ls_event
)
421 for (i
= g_stkdepth
- 1; i
>= 0; i
--) {
422 if (a
->ls_stack
[i
] < b
->ls_stack
[i
])
424 if (a
->ls_stack
[i
] > b
->ls_stack
[i
])
428 if (a
->ls_caller
< b
->ls_caller
)
430 if (a
->ls_caller
> b
->ls_caller
)
437 site_and_count_cmp_anylock(lsrec_t
*a
, lsrec_t
*b
)
441 if (a
->ls_event
< b
->ls_event
)
443 if (a
->ls_event
> b
->ls_event
)
446 for (i
= g_stkdepth
- 1; i
>= 0; i
--) {
447 if (a
->ls_stack
[i
] < b
->ls_stack
[i
])
449 if (a
->ls_stack
[i
] > b
->ls_stack
[i
])
453 if (a
->ls_caller
< b
->ls_caller
)
455 if (a
->ls_caller
> b
->ls_caller
)
458 return (b
->ls_count
- a
->ls_count
);
462 mergesort(int (*cmp
)(lsrec_t
*, lsrec_t
*), lsrec_t
**a
, lsrec_t
**b
, int n
)
468 mergesort(cmp
, a
, b
, m
);
470 mergesort(cmp
, a
+ m
, b
+ m
, n
- m
);
471 for (i
= m
; i
> 0; i
--)
473 for (j
= m
- 1; j
< n
- 1; j
++)
474 b
[n
+ m
- j
- 2] = a
[j
+ 1];
476 *a
++ = cmp(b
[i
], b
[j
]) < 0 ? b
[i
++] : b
[j
--];
481 coalesce(int (*cmp
)(lsrec_t
*, lsrec_t
*), lsrec_t
**lock
, int n
)
484 lsrec_t
*target
, *current
;
488 for (i
= 1; i
< n
; i
++) {
490 if (cmp(current
, target
) != 0) {
494 current
->ls_event
= LS_MAX_EVENTS
;
495 target
->ls_count
+= current
->ls_count
;
496 target
->ls_refcnt
+= current
->ls_refcnt
;
497 if (g_recsize
< LS_TIME
)
499 target
->ls_time
+= current
->ls_time
;
500 if (g_recsize
< LS_HIST
)
502 for (j
= 0; j
< 64; j
++)
503 target
->ls_hist
[j
] += current
->ls_hist
[j
];
508 coalesce_symbol(uintptr_t *addrp
)
513 if (addr_to_sym(*addrp
, &symoff
, &symsize
) != NULL
&& symoff
< symsize
)
518 predicate_add(char **pred
, char *what
, char *cmp
, uintptr_t value
)
532 newlen
= len
+ strlen(what
) + 32 + strlen("( && )");
533 new = malloc(newlen
);
535 if (*pred
[0] != '\0') {
537 (void) sprintf(new, "(%s) && (%s %s 0x%p)",
538 *pred
, what
, cmp
, (void *)value
);
540 (void) sprintf(new, "(%s) && (%s)", *pred
, what
);
544 (void) sprintf(new, "%s %s 0x%p",
545 what
, cmp
, (void *)value
);
547 (void) sprintf(new, "%s", what
);
556 predicate_destroy(char **pred
)
563 filter_add(char **filt
, char *what
, uintptr_t base
, uintptr_t size
)
565 char buf
[256], *c
= buf
, *new;
573 (void) sprintf(c
, "%s(%s >= 0x%p && %s < 0x%p)", *filt
[0] != '\0' ?
574 " || " : "", what
, (void *)base
, what
, (void *)(base
+ size
));
576 newlen
= (len
= strlen(*filt
) + 1) + strlen(c
);
577 new = malloc(newlen
);
578 bcopy(*filt
, new, len
);
579 (void) strcat(new, c
);
585 filter_destroy(char **filt
)
592 dprog_add(const char *fmt
, ...)
599 size
= vsnprintf(&c
, 1, fmt
, args
) + 1;
601 if (g_proglen
== 0) {
604 offs
= g_proglen
- 1;
607 g_proglen
= offs
+ size
;
609 if ((g_prog
= realloc(g_prog
, g_proglen
)) == NULL
)
610 fail(1, "failed to reallocate program text");
612 (void) vsnprintf(&g_prog
[offs
], size
, fmt
, args
);
616 * This function may read like an open sewer, but keep in mind that programs
617 * that generate other programs are rarely pretty. If one has the unenviable
618 * task of maintaining or -- worse -- extending this code, use the -V option
619 * to examine the D program as generated by this function.
622 dprog_addevent(int event
)
624 ls_event_info_t
*info
= &g_event_info
[event
];
627 const char *arg0
, *caller
;
633 if (info
->ev_name
[0] == '\0')
636 if (info
->ev_type
== 'I') {
638 * For interrupt events, arg0 (normally the lock pointer) is
639 * the CPU address plus the current pil, and arg1 (normally
640 * the number of nanoseconds) is the number of nanoseconds
641 * late -- and it's stored in arg2.
643 arg0
= "(uintptr_t)curthread->t_cpu + \n"
644 "\t curthread->t_cpu->cpu_profile_pil";
645 caller
= "(uintptr_t)arg0";
648 arg0
= "(uintptr_t)arg0";
652 if (g_recsize
> LS_HIST
) {
653 for (depth
= 0; g_recsize
> LS_STACK(depth
); depth
++)
657 (void) sprintf(stack
, "\tstack(%d);\n", depth
);
659 (void) sprintf(stack
, ", stack(%d)", depth
);
662 (void) sprintf(stack
, "");
665 if (info
->ev_acquire
!= NULL
) {
667 * If this is a hold event, we need to generate an additional
668 * clause for the acquire; the clause for the release will be
669 * generated with the aggregating statement, below.
671 dprog_add("%s\n", info
->ev_acquire
);
672 predicate_add(&pred
, info
->ev_predicate
, NULL
, 0);
673 predicate_add(&pred
, g_predicate
, NULL
, 0);
675 dprog_add("/%s/\n", pred
);
678 (void) sprintf(buf
, "self->ev%d[(uintptr_t)arg0]", event
);
680 if (info
->ev_type
== 'H') {
681 dprog_add("\t%s = timestamp;\n", buf
);
684 * If this isn't a hold event, it's the recursive
685 * error event. For this, we simply bump the
686 * thread-local, per-lock count.
688 dprog_add("\t%s++;\n", buf
);
692 predicate_destroy(&pred
);
695 if (info
->ev_type
== 'E') {
697 * If this is the recursive lock error event, we need
698 * to generate an additional clause to decrement the
699 * thread-local, per-lock count. This assures that we
700 * only execute the aggregating clause if we have
703 dprog_add("%s\n", info
->ev_name
);
704 dprog_add("/%s/\n{\n\t%s--;\n}\n\n", buf
, buf
);
707 predicate_add(&pred
, buf
, NULL
, 0);
709 if (info
->ev_type
== 'H') {
710 (void) sprintf(buf
, "timestamp -\n\t "
711 "self->ev%d[(uintptr_t)arg0]", event
);
716 predicate_add(&pred
, info
->ev_predicate
, NULL
, 0);
717 if (info
->ev_type
!= 'I')
718 predicate_add(&pred
, g_predicate
, NULL
, 0);
720 predicate_add(&pred
, g_ipredicate
, NULL
, 0);
723 if ((dur
= g_min_duration
[event
]) != 0)
724 predicate_add(&pred
, arg1
, ">=", dur
);
726 dprog_add("%s\n", info
->ev_name
);
729 dprog_add("/%s/\n", pred
);
730 predicate_destroy(&pred
);
735 dprog_add("\ttrace(%dULL);\n", event
);
736 dprog_add("\ttrace(%s);\n", arg0
);
737 dprog_add("\ttrace(%s);\n", caller
);
741 * The ordering here is important: when we process the
742 * aggregate, we count on the fact that @avg appears before
743 * @hist in program order to assure that @avg is assigned the
744 * first aggregation variable ID and @hist assigned the
745 * second; see the comment in process_aggregate() for details.
747 dprog_add("\t@avg[%dULL, %s, %s%s] = avg(%s);\n",
748 event
, arg0
, caller
, stack
, arg1
);
750 if (g_recsize
>= LS_HIST
) {
751 dprog_add("\t@hist[%dULL, %s, %s%s] = quantize"
752 "(%s);\n", event
, arg0
, caller
, stack
, arg1
);
756 if (info
->ev_acquire
!= NULL
)
757 dprog_add("\tself->ev%d[arg0] = 0;\n", event
);
766 dtrace_proginfo_t info
;
769 (void) fprintf(stderr
, "lockstat: vvvv D program vvvv\n");
770 (void) fputs(g_prog
, stderr
);
771 (void) fprintf(stderr
, "lockstat: ^^^^ D program ^^^^\n");
774 if ((prog
= dtrace_program_strcompile(g_dtp
, g_prog
,
775 DTRACE_PROBESPEC_NAME
, 0, 0, NULL
)) == NULL
)
776 dfail("failed to compile program");
778 if (dtrace_program_exec(g_dtp
, prog
, &info
) == -1)
779 dfail("failed to enable probes");
781 if (dtrace_go(g_dtp
) != 0)
782 dfail("couldn't start tracing");
792 dtrace_optval_t val
, status
, agg
;
793 struct sigaction act
;
794 struct itimerspec ts
;
798 if (dtrace_getopt(g_dtp
, "statusrate", &status
) == -1)
799 dfail("failed to get 'statusrate'");
801 if (dtrace_getopt(g_dtp
, "aggrate", &agg
) == -1)
802 dfail("failed to get 'statusrate'");
805 * We would want to awaken at a rate that is the GCD of the statusrate
806 * and the aggrate -- but that seems a bit absurd. Instead, we'll
807 * simply awaken at a rate that is the more frequent of the two, which
808 * assures that we're never later than the interval implied by the
809 * more frequent rate.
811 val
= status
< agg
? status
: agg
;
813 (void) sigemptyset(&act
.sa_mask
);
815 act
.sa_handler
= status_fire
;
816 (void) sigaction(SIGUSR1
, &act
, NULL
);
818 ev
.sigev_notify
= SIGEV_SIGNAL
;
819 ev
.sigev_signo
= SIGUSR1
;
821 if (timer_create(CLOCK_REALTIME
, &ev
, &tid
) == -1)
822 dfail("cannot create CLOCK_REALTIME timer");
824 ts
.it_value
.tv_sec
= val
/ NANOSEC
;
825 ts
.it_value
.tv_nsec
= val
% NANOSEC
;
826 ts
.it_interval
= ts
.it_value
;
828 if (timer_settime(tid
, TIMER_RELTIME
, &ts
, NULL
) == -1)
829 dfail("cannot set time on CLOCK_REALTIME timer");
835 if (!g_tracing
&& dtrace_aggregate_snap(g_dtp
) != 0)
836 dfail("failed to snap aggregate");
838 if (dtrace_status(g_dtp
) == -1)
839 dfail("dtrace_status()");
843 lsrec_fill(lsrec_t
*lsrec
, const dtrace_recdesc_t
*rec
, int nrecs
, caddr_t data
)
845 bzero(lsrec
, g_recsize
);
848 if ((g_recsize
> LS_HIST
&& nrecs
< 4) || (nrecs
< 3))
849 fail(0, "truncated DTrace record");
851 if (rec
->dtrd_size
!= sizeof (uint64_t))
852 fail(0, "bad event size in first record");
854 /* LINTED - alignment */
855 lsrec
->ls_event
= (uint32_t)*((uint64_t *)(data
+ rec
->dtrd_offset
));
858 if (rec
->dtrd_size
!= sizeof (uintptr_t))
859 fail(0, "bad lock address size in second record");
861 /* LINTED - alignment */
862 lsrec
->ls_lock
= *((uintptr_t *)(data
+ rec
->dtrd_offset
));
865 if (rec
->dtrd_size
!= sizeof (uintptr_t))
866 fail(0, "bad caller size in third record");
868 /* LINTED - alignment */
869 lsrec
->ls_caller
= *((uintptr_t *)(data
+ rec
->dtrd_offset
));
872 if (g_recsize
> LS_HIST
) {
876 frames
= rec
->dtrd_size
/ sizeof (pc_t
);
877 /* LINTED - alignment */
878 stack
= (pc_t
*)(data
+ rec
->dtrd_offset
);
880 for (i
= 1; i
< frames
; i
++)
881 lsrec
->ls_stack
[i
- 1] = stack
[i
];
887 count_aggregate(const dtrace_aggdata_t
*agg
, void *arg
)
889 *((size_t *)arg
) += 1;
891 return (DTRACE_AGGWALK_NEXT
);
895 process_aggregate(const dtrace_aggdata_t
*agg
, void *arg
)
897 const dtrace_aggdesc_t
*aggdesc
= agg
->dtada_desc
;
898 caddr_t data
= agg
->dtada_data
;
899 lsdata_t
*lsdata
= arg
;
900 lsrec_t
*lsrec
= lsdata
->lsd_next
;
901 const dtrace_recdesc_t
*rec
;
902 uint64_t *avg
, *quantized
;
905 assert(lsdata
->lsd_count
< g_nrecs
);
908 * Aggregation variable IDs are guaranteed to be generated in program
909 * order, and they are guaranteed to start from DTRACE_AGGVARIDNONE
910 * plus one. As "avg" appears before "hist" in program order, we know
911 * that "avg" will be allocated the first aggregation variable ID, and
912 * "hist" will be allocated the second aggregation variable ID -- and
913 * we therefore use the aggregation variable ID to differentiate the
916 if (aggdesc
->dtagd_varid
> DTRACE_AGGVARIDNONE
+ 1) {
918 * If this is the histogram entry. We'll copy the quantized
919 * data into lc_hist, and jump over the rest.
921 rec
= &aggdesc
->dtagd_rec
[aggdesc
->dtagd_nrecs
- 1];
923 if (aggdesc
->dtagd_varid
!= DTRACE_AGGVARIDNONE
+ 2)
924 fail(0, "bad variable ID in aggregation record");
926 if (rec
->dtrd_size
!=
927 DTRACE_QUANTIZE_NBUCKETS
* sizeof (uint64_t))
928 fail(0, "bad quantize size in aggregation record");
930 /* LINTED - alignment */
931 quantized
= (uint64_t *)(data
+ rec
->dtrd_offset
);
933 for (i
= DTRACE_QUANTIZE_ZEROBUCKET
, j
= 0;
934 i
< DTRACE_QUANTIZE_NBUCKETS
; i
++, j
++)
935 lsrec
->ls_hist
[j
] = quantized
[i
];
940 lsrec_fill(lsrec
, &aggdesc
->dtagd_rec
[1],
941 aggdesc
->dtagd_nrecs
- 1, data
);
943 rec
= &aggdesc
->dtagd_rec
[aggdesc
->dtagd_nrecs
- 1];
945 if (rec
->dtrd_size
!= 2 * sizeof (uint64_t))
946 fail(0, "bad avg size in aggregation record");
948 /* LINTED - alignment */
949 avg
= (uint64_t *)(data
+ rec
->dtrd_offset
);
950 lsrec
->ls_count
= (uint32_t)avg
[0];
951 lsrec
->ls_time
= (uintptr_t)avg
[1];
953 if (g_recsize
>= LS_HIST
)
954 return (DTRACE_AGGWALK_NEXT
);
957 lsdata
->lsd_next
= (lsrec_t
*)((uintptr_t)lsrec
+ g_recsize
);
960 return (DTRACE_AGGWALK_NEXT
);
964 process_trace(const dtrace_probedata_t
*pdata
, void *arg
)
966 lsdata_t
*lsdata
= arg
;
967 lsrec_t
*lsrec
= lsdata
->lsd_next
;
968 dtrace_eprobedesc_t
*edesc
= pdata
->dtpda_edesc
;
969 caddr_t data
= pdata
->dtpda_data
;
971 if (lsdata
->lsd_count
>= g_nrecs
)
972 return (DTRACE_CONSUME_NEXT
);
974 lsrec_fill(lsrec
, edesc
->dtepd_rec
, edesc
->dtepd_nrecs
, data
);
976 lsdata
->lsd_next
= (lsrec_t
*)((uintptr_t)lsrec
+ g_recsize
);
979 return (DTRACE_CONSUME_NEXT
);
983 process_data(FILE *out
, char *data
)
987 /* LINTED - alignment */
988 lsdata
.lsd_next
= (lsrec_t
*)data
;
989 lsdata
.lsd_count
= 0;
992 if (dtrace_consume(g_dtp
, out
,
993 process_trace
, NULL
, &lsdata
) != 0)
994 dfail("failed to consume buffer");
996 return (lsdata
.lsd_count
);
999 if (dtrace_aggregate_walk_keyvarsorted(g_dtp
,
1000 process_aggregate
, &lsdata
) != 0)
1001 dfail("failed to walk aggregate");
1003 return (lsdata
.lsd_count
);
1008 drophandler(const dtrace_dropdata_t
*data
, void *arg
)
1011 (void) fprintf(stderr
, "lockstat: warning: %s", data
->dtdda_msg
);
1012 return (DTRACE_HANDLE_OK
);
1016 main(int argc
, char **argv
)
1019 lsrec_t
*lsp
, **current
, **first
, **sort_buf
, **merge_buf
;
1026 char *addrp
, *offp
, *sizep
, *evp
, *lastp
, *p
;
1029 int events_specified
= 0;
1032 char *filt
= NULL
, *ifilt
= NULL
;
1033 static uint64_t ev_count
[LS_MAX_EVENTS
+ 1];
1034 static uint64_t ev_time
[LS_MAX_EVENTS
+ 1];
1035 dtrace_optval_t aggsize
;
1041 if ((g_dtp
= dtrace_open(DTRACE_VERSION
, 0, &err
)) == NULL
) {
1042 fail(0, "cannot open dtrace library: %s",
1043 dtrace_errmsg(NULL
, err
));
1046 if (dtrace_handle_drop(g_dtp
, &drophandler
, NULL
) == -1)
1047 dfail("couldn't establish drop handler");
1049 if (symtab_init() == -1)
1050 fail(1, "can't load kernel symbols");
1052 g_nrecs
= DEFAULT_NRECS
;
1054 while ((c
= getopt(argc
, argv
, LOCKSTAT_OPTSTR
)) != EOF
) {
1057 g_recsize
= LS_BASIC
;
1061 g_recsize
= LS_TIME
;
1065 g_recsize
= LS_HIST
;
1069 if (!isdigit(optarg
[0]))
1071 g_stkdepth
= atoi(optarg
);
1072 if (g_stkdepth
> LS_MAX_STACK_DEPTH
)
1073 fail(0, "max stack depth is %d",
1074 LS_MAX_STACK_DEPTH
);
1075 g_recsize
= LS_STACK(g_stkdepth
);
1079 if (!isdigit(optarg
[0]))
1081 g_nrecs
= atoi(optarg
);
1085 if (!isdigit(optarg
[0]))
1087 duration
= atoll(optarg
);
1090 * XXX -- durations really should be per event
1091 * since the units are different, but it's hard
1092 * to express this nicely in the interface.
1093 * Not clear yet what the cleanest solution is.
1095 for (i
= 0; i
< LS_MAX_EVENTS
; i
++)
1096 if (g_event_info
[i
].ev_type
!= 'E')
1097 g_min_duration
[i
] = duration
;
1102 if (!isdigit(optarg
[0]))
1108 fail(0, "max interrupt rate is %d Hz", MAX_HZ
);
1110 for (j
= 0; j
< LS_MAX_EVENTS
; j
++)
1111 if (strcmp(g_event_info
[j
].ev_desc
,
1112 "Profiling interrupt") == 0)
1115 (void) sprintf(g_event_info
[j
].ev_name
,
1116 "profile:::profile-%d", i
);
1121 addrp
= strtok(optarg
, ",");
1122 sizep
= strtok(NULL
, ",");
1123 addrp
= strtok(optarg
, ",+");
1124 offp
= strtok(NULL
, ",");
1126 size
= sizep
? strtoul(sizep
, NULL
, 0) : 1;
1127 off
= offp
? strtoul(offp
, NULL
, 0) : 0;
1129 if (addrp
[0] == '0') {
1130 addr
= strtoul(addrp
, NULL
, 16) + off
;
1132 addr
= sym_to_addr(addrp
) + off
;
1134 size
= sym_size(addrp
) - off
;
1135 if (addr
- off
== 0)
1136 fail(0, "symbol '%s' not found", addrp
);
1143 filter_add(&filt
, "arg0", addr
, size
);
1145 filter_add(&filt
, "caller", addr
, size
);
1146 filter_add(&ifilt
, "arg0", addr
, size
);
1151 evp
= strtok_r(optarg
, ",", &lastp
);
1156 (void) strtok(evp
, "-");
1157 evp2
= strtok(NULL
, "-");
1159 ev2
= evp2
? atoi(evp2
) : ev1
;
1160 if ((uint_t
)ev1
>= LS_MAX_EVENTS
||
1161 (uint_t
)ev2
>= LS_MAX_EVENTS
|| ev1
> ev2
)
1162 fail(0, "-e events out of range");
1163 for (i
= ev1
; i
<= ev2
; i
++)
1165 evp
= strtok_r(NULL
, ",", &lastp
);
1167 events_specified
= 1;
1194 for (i
= 0; i
< LS_MAX_EVENTS
; i
++)
1195 if (g_event_info
[i
].ev_type
== c
)
1197 events_specified
= 1;
1201 for (i
= 0; i
< LS_MAX_EVENTS
; i
++)
1202 if (strchr("CH", g_event_info
[i
].ev_type
))
1204 events_specified
= 1;
1212 if (!isdigit(optarg
[0]))
1214 g_topn
= atoi(optarg
);
1230 if ((out
= fopen(optarg
, "w")) == NULL
)
1231 fail(1, "error opening file");
1239 if (strchr(LOCKSTAT_OPTSTR
, c
) == NULL
)
1245 predicate_add(&g_predicate
, filt
, NULL
, 0);
1246 filter_destroy(&filt
);
1249 if (ifilt
!= NULL
) {
1250 predicate_add(&g_ipredicate
, ifilt
, NULL
, 0);
1251 filter_destroy(&ifilt
);
1254 if (g_recsize
== 0) {
1256 g_stkdepth
= LS_MAX_STACK_DEPTH
;
1257 g_recsize
= LS_STACK(g_stkdepth
);
1259 g_recsize
= LS_TIME
;
1263 if (g_gflag
&& g_recsize
<= LS_STACK(0))
1264 fail(0, "'-g' requires at least '-s 1' data gathering");
1267 * Make sure the alignment is reasonable
1269 g_recsize
= -(-g_recsize
& -sizeof (uint64_t));
1271 for (i
= 0; i
< LS_MAX_EVENTS
; i
++) {
1273 * If no events were specified, enable -C.
1275 if (!events_specified
&& g_event_info
[i
].ev_type
== 'C')
1279 for (i
= 0; i
< LS_MAX_EVENTS
; i
++) {
1283 if (g_event_info
[i
].ev_acquire
!= NULL
) {
1285 * If we've enabled a hold event, we must explicitly
1286 * allocate dynamic variable space.
1295 * Make sure there are remaining arguments to specify a child command
1301 if ((ncpus
= sysconf(_SC_NPROCESSORS_ONLN
)) == -1)
1302 dfail("couldn't determine number of online CPUs");
1305 * By default, we set our data buffer size to be the number of records
1306 * multiplied by the size of the record, doubled to account for some
1307 * DTrace slop and divided by the number of CPUs. We silently clamp
1308 * the aggregation size at both a minimum and a maximum to prevent
1309 * absurdly low or high values.
1311 if ((aggsize
= (g_nrecs
* g_recsize
* 2) / ncpus
) < MIN_AGGSIZE
)
1312 aggsize
= MIN_AGGSIZE
;
1314 if (aggsize
> MAX_AGGSIZE
)
1315 aggsize
= MAX_AGGSIZE
;
1317 (void) sprintf(aggstr
, "%lld", (long long)aggsize
);
1320 if (dtrace_setopt(g_dtp
, "bufsize", "4k") == -1)
1321 dfail("failed to set 'bufsize'");
1323 if (dtrace_setopt(g_dtp
, "aggsize", aggstr
) == -1)
1324 dfail("failed to set 'aggsize'");
1328 * If we're using dynamic variables, we set our
1329 * dynamic variable size to be one megabyte per CPU,
1330 * with a hard-limit of 32 megabytes. This may still
1331 * be too small in some cases, but it can be tuned
1332 * manually via -x if need be.
1334 (void) sprintf(aggstr
, "%ldm", ncpus
< 32 ? ncpus
: 32);
1336 if (dtrace_setopt(g_dtp
, "dynvarsize", aggstr
) == -1)
1337 dfail("failed to set 'dynvarsize'");
1340 if (dtrace_setopt(g_dtp
, "bufsize", aggstr
) == -1)
1341 dfail("failed to set 'bufsize'");
1344 if (dtrace_setopt(g_dtp
, "statusrate", "10sec") == -1)
1345 dfail("failed to set 'statusrate'");
1348 while ((c
= getopt(argc
, argv
, LOCKSTAT_OPTSTR
)) != EOF
) {
1351 if ((p
= strchr(optarg
, '=')) != NULL
)
1354 if (dtrace_setopt(g_dtp
, optarg
, p
) != 0)
1355 dfail("failed to set -x %s", optarg
);
1366 g_elapsed
= -gethrtime();
1369 * Spawn the specified command and wait for it to complete.
1373 fail(1, "cannot fork");
1375 (void) dtrace_close(g_dtp
);
1376 (void) execvp(argv
[0], &argv
[0]);
1381 while (waitpid(child
, &status
, WEXITED
) != child
)
1384 g_elapsed
+= gethrtime();
1386 if (WIFEXITED(status
)) {
1387 if (WEXITSTATUS(status
) != 0) {
1388 if (exec_errno
!= 0) {
1390 fail(1, "could not execute %s", argv
[0]);
1392 (void) fprintf(stderr
,
1393 "lockstat: warning: %s exited with code %d\n",
1394 argv
[0], WEXITSTATUS(status
));
1397 (void) fprintf(stderr
,
1398 "lockstat: warning: %s died on signal %d\n",
1399 argv
[0], WTERMSIG(status
));
1402 if (dtrace_stop(g_dtp
) == -1)
1403 dfail("failed to stop dtrace");
1406 * Before we read out the results, we need to allocate our buffer.
1407 * If we're tracing, then we'll just use the precalculated size. If
1408 * we're not, then we'll take a snapshot of the aggregate, and walk
1409 * it to count the number of records.
1412 if (dtrace_aggregate_snap(g_dtp
) != 0)
1413 dfail("failed to snap aggregate");
1417 if (dtrace_aggregate_walk(g_dtp
,
1418 count_aggregate
, &g_nrecs
) != 0)
1419 dfail("failed to walk aggregate");
1422 if ((data_buf
= memalign(sizeof (uint64_t),
1423 (g_nrecs
+ 1) * g_recsize
)) == NULL
)
1424 fail(1, "Memory allocation failed");
1427 * Read out the DTrace data.
1429 g_nrecs_used
= process_data(out
, data_buf
);
1431 if (g_nrecs_used
> g_nrecs
|| g_dropped
)
1432 (void) fprintf(stderr
, "lockstat: warning: "
1433 "ran out of data records (use -n for more)\n");
1435 /* LINTED - alignment */
1436 for (i
= 0, lsp
= (lsrec_t
*)data_buf
; i
< g_nrecs_used
; i
++,
1437 /* LINTED - alignment */
1438 lsp
= (lsrec_t
*)((char *)lsp
+ g_recsize
)) {
1439 ev_count
[lsp
->ls_event
] += lsp
->ls_count
;
1440 ev_time
[lsp
->ls_event
] += lsp
->ls_time
;
1444 * If -g was specified, convert stacks into individual records.
1447 lsrec_t
*newlsp
, *oldlsp
;
1449 newlsp
= memalign(sizeof (uint64_t),
1450 g_nrecs_used
* LS_TIME
* (g_stkdepth
+ 1));
1452 fail(1, "Cannot allocate space for -g processing");
1454 /* LINTED - alignment */
1455 for (i
= 0, oldlsp
= (lsrec_t
*)data_buf
; i
< g_nrecs_used
; i
++,
1456 /* LINTED - alignment */
1457 oldlsp
= (lsrec_t
*)((char *)oldlsp
+ g_recsize
)) {
1459 int caller_in_stack
= 0;
1461 if (oldlsp
->ls_count
== 0)
1464 for (fr
= 0; fr
< g_stkdepth
; fr
++) {
1465 if (oldlsp
->ls_stack
[fr
] == 0)
1467 if (oldlsp
->ls_stack
[fr
] == oldlsp
->ls_caller
)
1468 caller_in_stack
= 1;
1469 bcopy(oldlsp
, lsp
, LS_TIME
);
1470 lsp
->ls_caller
= oldlsp
->ls_stack
[fr
];
1471 /* LINTED - alignment */
1472 lsp
= (lsrec_t
*)((char *)lsp
+ LS_TIME
);
1474 if (!caller_in_stack
) {
1475 bcopy(oldlsp
, lsp
, LS_TIME
);
1476 /* LINTED - alignment */
1477 lsp
= (lsrec_t
*)((char *)lsp
+ LS_TIME
);
1480 g_nrecs
= g_nrecs_used
=
1481 ((uintptr_t)lsp
- (uintptr_t)newlsp
) / LS_TIME
;
1482 g_recsize
= LS_TIME
;
1485 data_buf
= (char *)newlsp
;
1488 if ((sort_buf
= calloc(2 * (g_nrecs
+ 1),
1489 sizeof (void *))) == NULL
)
1490 fail(1, "Sort buffer allocation failed");
1491 merge_buf
= sort_buf
+ (g_nrecs
+ 1);
1494 * Build the sort buffer, discarding zero-count records along the way.
1496 /* LINTED - alignment */
1497 for (i
= 0, lsp
= (lsrec_t
*)data_buf
; i
< g_nrecs_used
; i
++,
1498 /* LINTED - alignment */
1499 lsp
= (lsrec_t
*)((char *)lsp
+ g_recsize
)) {
1500 if (lsp
->ls_count
== 0)
1501 lsp
->ls_event
= LS_MAX_EVENTS
;
1505 if (g_nrecs_used
== 0)
1509 * Add a sentinel after the last record
1512 lsp
->ls_event
= LS_MAX_EVENTS
;
1515 report_trace(out
, sort_buf
);
1520 * Application of -g may have resulted in multiple records
1521 * with the same signature; coalesce them.
1524 mergesort(lockcmp
, sort_buf
, merge_buf
, g_nrecs_used
);
1525 coalesce(lockcmp
, sort_buf
, g_nrecs_used
);
1529 * Coalesce locks within the same symbol if -c option specified.
1530 * Coalesce PCs within the same function if -k option specified.
1532 if (g_cflag
|| g_kflag
) {
1533 for (i
= 0; i
< g_nrecs_used
; i
++) {
1537 coalesce_symbol(&lsp
->ls_lock
);
1539 for (fr
= 0; fr
< g_stkdepth
; fr
++)
1540 coalesce_symbol(&lsp
->ls_stack
[fr
]);
1541 coalesce_symbol(&lsp
->ls_caller
);
1544 mergesort(lockcmp
, sort_buf
, merge_buf
, g_nrecs_used
);
1545 coalesce(lockcmp
, sort_buf
, g_nrecs_used
);
1549 * Coalesce callers if -w option specified
1552 mergesort(lock_and_count_cmp_anywhere
,
1553 sort_buf
, merge_buf
, g_nrecs_used
);
1554 coalesce(lockcmp_anywhere
, sort_buf
, g_nrecs_used
);
1558 * Coalesce locks if -W option specified
1561 mergesort(site_and_count_cmp_anylock
,
1562 sort_buf
, merge_buf
, g_nrecs_used
);
1563 coalesce(sitecmp_anylock
, sort_buf
, g_nrecs_used
);
1567 * Sort data by contention count (ls_count) or total time (ls_time),
1568 * depending on g_Pflag. Override g_Pflag if time wasn't measured.
1570 if (g_recsize
< LS_TIME
)
1574 mergesort(timecmp
, sort_buf
, merge_buf
, g_nrecs_used
);
1576 mergesort(countcmp
, sort_buf
, merge_buf
, g_nrecs_used
);
1579 * Display data by event type
1581 first
= &sort_buf
[0];
1582 while ((event
= (*first
)->ls_event
) < LS_MAX_EVENTS
) {
1584 while ((lsp
= *current
)->ls_event
== event
)
1586 report_stats(out
, first
, current
- first
, ev_count
[event
],
1595 format_symbol(char *buf
, uintptr_t addr
, int show_size
)
1601 symname
= addr_to_sym(addr
, &symoff
, &symsize
);
1603 if (show_size
&& symoff
== 0)
1604 (void) sprintf(buf
, "%s[%ld]", symname
, (long)symsize
);
1605 else if (symoff
== 0)
1606 (void) sprintf(buf
, "%s", symname
);
1607 else if (symoff
< 16 && bcmp(symname
, "cpu[", 4) == 0) /* CPU+PIL */
1608 (void) sprintf(buf
, "%s+%ld", symname
, (long)symoff
);
1609 else if (symoff
<= symsize
|| (symoff
< 256 && addr
!= symoff
))
1610 (void) sprintf(buf
, "%s+0x%llx", symname
,
1611 (unsigned long long)symoff
);
1613 (void) sprintf(buf
, "0x%llx", (unsigned long long)addr
);
1618 report_stats(FILE *out
, lsrec_t
**sort_buf
, size_t nrecs
, uint64_t total_count
,
1619 uint64_t total_time
)
1621 uint32_t event
= sort_buf
[0]->ls_event
;
1623 double ptotal
= 0.0;
1627 int first_bin
, last_bin
, max_bin_count
, total_bin_count
;
1630 char lhdr
[80], chdr
[80];
1632 rectype
= g_recsize
;
1635 (void) fprintf(out
, "%20llu %s\n",
1636 g_rates
== 0 ? total_count
:
1637 ((unsigned long long)total_count
* NANOSEC
) / g_elapsed
,
1638 g_event_info
[event
].ev_desc
);
1642 (void) sprintf(lhdr
, "%s%s",
1643 g_Wflag
? "Hottest " : "", g_event_info
[event
].ev_lhdr
);
1644 (void) sprintf(chdr
, "%s%s",
1645 g_wflag
? "Hottest " : "", "Caller");
1649 "\n%s: %.0f events in %.3f seconds (%.0f events/sec)\n\n",
1650 g_event_info
[event
].ev_desc
, (double)total_count
,
1651 (double)g_elapsed
/ NANOSEC
,
1652 (double)total_count
* NANOSEC
/ g_elapsed
);
1654 if (!g_pflag
&& rectype
< LS_HIST
) {
1655 (void) sprintf(buf
, "%s", g_event_info
[event
].ev_units
);
1656 (void) fprintf(out
, "%5s %4s %4s %4s %8s %-22s %-24s\n",
1657 g_rates
? "ops/s" : "Count",
1658 g_gflag
? "genr" : "indv",
1659 "cuml", "rcnt", rectype
>= LS_TIME
? buf
: "", lhdr
, chdr
);
1660 (void) fprintf(out
, "---------------------------------"
1661 "----------------------------------------------\n");
1665 for (i
= 0; i
< nrecs
; i
++) {
1668 if (displayed
++ >= g_topn
)
1674 (void) fprintf(out
, "%u %u",
1675 lsp
->ls_event
, lsp
->ls_count
);
1676 (void) fprintf(out
, " %s",
1677 format_symbol(buf
, lsp
->ls_lock
, g_cflag
));
1678 (void) fprintf(out
, " %s",
1679 format_symbol(buf
, lsp
->ls_caller
, 0));
1680 (void) fprintf(out
, " %f",
1681 (double)lsp
->ls_refcnt
/ lsp
->ls_count
);
1682 if (rectype
>= LS_TIME
)
1683 (void) fprintf(out
, " %llu",
1684 (unsigned long long)lsp
->ls_time
);
1685 if (rectype
>= LS_HIST
) {
1686 for (j
= 0; j
< 64; j
++)
1687 (void) fprintf(out
, " %u",
1690 for (j
= 0; j
< LS_MAX_STACK_DEPTH
; j
++) {
1691 if (rectype
<= LS_STACK(j
) ||
1692 lsp
->ls_stack
[j
] == 0)
1694 (void) fprintf(out
, " %s",
1695 format_symbol(buf
, lsp
->ls_stack
[j
], 0));
1697 (void) fprintf(out
, "\n");
1701 if (rectype
>= LS_HIST
) {
1702 (void) fprintf(out
, "---------------------------------"
1703 "----------------------------------------------\n");
1704 (void) sprintf(buf
, "%s",
1705 g_event_info
[event
].ev_units
);
1706 (void) fprintf(out
, "%5s %4s %4s %4s %8s %-22s %-24s\n",
1707 g_rates
? "ops/s" : "Count",
1708 g_gflag
? "genr" : "indv",
1709 "cuml", "rcnt", buf
, lhdr
, chdr
);
1712 if (g_Pflag
&& total_time
!= 0)
1713 percent
= (lsp
->ls_time
* 100.00) / total_time
;
1715 percent
= (lsp
->ls_count
* 100.00) / total_count
;
1719 if (rectype
>= LS_TIME
)
1720 (void) sprintf(buf
, "%llu",
1721 (unsigned long long)(lsp
->ls_time
/ lsp
->ls_count
));
1725 (void) fprintf(out
, "%5llu ",
1726 g_rates
== 0 ? lsp
->ls_count
:
1727 ((uint64_t)lsp
->ls_count
* NANOSEC
) / g_elapsed
);
1729 (void) fprintf(out
, "%3.0f%% ", percent
);
1732 (void) fprintf(out
, "---- ");
1734 (void) fprintf(out
, "%3.0f%% ", ptotal
);
1736 (void) fprintf(out
, "%4.2f %8s ",
1737 (double)lsp
->ls_refcnt
/ lsp
->ls_count
, buf
);
1739 (void) fprintf(out
, "%-22s ",
1740 format_symbol(buf
, lsp
->ls_lock
, g_cflag
));
1742 (void) fprintf(out
, "%-24s\n",
1743 format_symbol(buf
, lsp
->ls_caller
, 0));
1745 if (rectype
< LS_HIST
)
1748 (void) fprintf(out
, "\n");
1749 (void) fprintf(out
, "%10s %31s %-9s %-24s\n",
1750 g_event_info
[event
].ev_units
,
1751 "------ Time Distribution ------",
1752 g_rates
? "ops/s" : "count",
1753 rectype
> LS_STACK(0) ? "Stack" : "");
1756 while (lsp
->ls_hist
[first_bin
] == 0)
1760 while (lsp
->ls_hist
[last_bin
] == 0)
1764 total_bin_count
= 0;
1765 for (j
= first_bin
; j
<= last_bin
; j
++) {
1766 total_bin_count
+= lsp
->ls_hist
[j
];
1767 if (lsp
->ls_hist
[j
] > max_bin_count
)
1768 max_bin_count
= lsp
->ls_hist
[j
];
1772 * If we went a few frames below the caller, ignore them
1774 for (fr
= 3; fr
> 0; fr
--)
1775 if (lsp
->ls_stack
[fr
] == lsp
->ls_caller
)
1778 for (j
= first_bin
; j
<= last_bin
; j
++) {
1779 uint_t depth
= (lsp
->ls_hist
[j
] * 30) / total_bin_count
;
1780 (void) fprintf(out
, "%10llu |%s%s %-9u ",
1782 "@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@" + 30 - depth
,
1784 g_rates
== 0 ? lsp
->ls_hist
[j
] :
1785 (uint_t
)(((uint64_t)lsp
->ls_hist
[j
] * NANOSEC
) /
1787 if (rectype
<= LS_STACK(fr
) || lsp
->ls_stack
[fr
] == 0) {
1788 (void) fprintf(out
, "\n");
1791 (void) fprintf(out
, "%-24s\n",
1792 format_symbol(buf
, lsp
->ls_stack
[fr
], 0));
1795 while (rectype
> LS_STACK(fr
) && lsp
->ls_stack
[fr
] != 0) {
1796 (void) fprintf(out
, "%15s %-36s %-24s\n", "", "",
1797 format_symbol(buf
, lsp
->ls_stack
[fr
], 0));
1803 (void) fprintf(out
, "---------------------------------"
1804 "----------------------------------------------\n");
1810 report_trace(FILE *out
, lsrec_t
**sort_buf
)
1815 char buf
[256], buf2
[256];
1817 rectype
= g_recsize
;
1820 (void) fprintf(out
, "%5s %7s %11s %-24s %-24s\n",
1821 "Event", "Time", "Owner", "Lock", "Caller");
1822 (void) fprintf(out
, "---------------------------------"
1823 "----------------------------------------------\n");
1826 for (i
= 0; i
< g_nrecs_used
; i
++) {
1830 if (lsp
->ls_event
>= LS_MAX_EVENTS
|| lsp
->ls_count
== 0)
1833 (void) fprintf(out
, "%2d %10llu %11p %-24s %-24s\n",
1834 lsp
->ls_event
, (unsigned long long)lsp
->ls_time
,
1835 (void *)lsp
->ls_next
,
1836 format_symbol(buf
, lsp
->ls_lock
, 0),
1837 format_symbol(buf2
, lsp
->ls_caller
, 0));
1839 if (rectype
<= LS_STACK(0))
1843 * If we went a few frames below the caller, ignore them
1845 for (fr
= 3; fr
> 0; fr
--)
1846 if (lsp
->ls_stack
[fr
] == lsp
->ls_caller
)
1849 while (rectype
> LS_STACK(fr
) && lsp
->ls_stack
[fr
] != 0) {
1850 (void) fprintf(out
, "%53s %-24s\n", "",
1851 format_symbol(buf
, lsp
->ls_stack
[fr
], 0));
1854 (void) fprintf(out
, "\n");