1 0 stevel /* 2 0 stevel * CDDL HEADER START 3 0 stevel * 4 0 stevel * The contents of this file are subject to the terms of the 5 6103 ck142721 * Common Development and Distribution License (the "License"). 6 6103 ck142721 * You may not use this file except in compliance with the License. 7 0 stevel * 8 0 stevel * You can obtain a copy of the license at usr/src/OPENSOLARIS.LICENSE 9 0 stevel * or http://www.opensolaris.org/os/licensing. 10 0 stevel * See the License for the specific language governing permissions 11 0 stevel * and limitations under the License. 12 0 stevel * 13 0 stevel * When distributing Covered Code, include this CDDL HEADER in each 14 0 stevel * file and include the License file at usr/src/OPENSOLARIS.LICENSE. 15 0 stevel * If applicable, add the following below this CDDL HEADER, with the 16 0 stevel * fields enclosed by brackets "[]" replaced with your own identifying 17 0 stevel * information: Portions Copyright [yyyy] [name of copyright owner] 18 0 stevel * 19 0 stevel * CDDL HEADER END 20 0 stevel */ 21 0 stevel /* 22 6103 ck142721 * Copyright 2008 Sun Microsystems, Inc. All rights reserved. 23 0 stevel * Use is subject to license terms. 24 0 stevel */ 25 0 stevel 26 0 stevel #pragma ident "%Z%%M% %I% %E% SMI" 27 0 stevel 28 0 stevel #include <stdio.h> 29 0 stevel #include <stddef.h> 30 0 stevel #include <stdlib.h> 31 0 stevel #include <stdarg.h> 32 0 stevel #include <string.h> 33 0 stevel #include <strings.h> 34 0 stevel #include <ctype.h> 35 0 stevel #include <fcntl.h> 36 0 stevel #include <unistd.h> 37 0 stevel #include <errno.h> 38 0 stevel #include <limits.h> 39 0 stevel #include <sys/types.h> 40 0 stevel #include <sys/modctl.h> 41 0 stevel #include <sys/stat.h> 42 0 stevel #include <sys/wait.h> 43 0 stevel #include <dtrace.h> 44 0 stevel #include <sys/lockstat.h> 45 0 stevel #include <alloca.h> 46 0 stevel #include <signal.h> 47 0 stevel #include <assert.h> 48 0 stevel 49 0 stevel #define LOCKSTAT_OPTSTR "x:bths:n:d:i:l:f:e:ckwWgCHEATID:RpPo:V" 50 0 stevel 51 0 stevel #define LS_MAX_STACK_DEPTH 50 52 0 stevel #define LS_MAX_EVENTS 64 53 0 stevel 54 0 stevel typedef struct lsrec { 55 0 stevel struct lsrec *ls_next; /* next in hash chain */ 56 0 stevel uintptr_t ls_lock; /* lock address */ 57 0 stevel uintptr_t ls_caller; /* caller address */ 58 0 stevel uint32_t ls_count; /* cumulative event count */ 59 0 stevel uint32_t ls_event; /* type of event */ 60 0 stevel uintptr_t ls_refcnt; /* cumulative reference count */ 61 0 stevel uint64_t ls_time; /* cumulative event duration */ 62 0 stevel uint32_t ls_hist[64]; /* log2(duration) histogram */ 63 0 stevel uintptr_t ls_stack[LS_MAX_STACK_DEPTH]; 64 0 stevel } lsrec_t; 65 0 stevel 66 0 stevel typedef struct lsdata { 67 0 stevel struct lsrec *lsd_next; /* next available */ 68 0 stevel int lsd_count; /* number of records */ 69 0 stevel } lsdata_t; 70 0 stevel 71 0 stevel /* 72 0 stevel * Definitions for the types of experiments which can be run. They are 73 0 stevel * listed in increasing order of memory cost and processing time cost. 74 0 stevel * The numerical value of each type is the number of bytes needed per record. 75 0 stevel */ 76 0 stevel #define LS_BASIC offsetof(lsrec_t, ls_time) 77 0 stevel #define LS_TIME offsetof(lsrec_t, ls_hist[0]) 78 0 stevel #define LS_HIST offsetof(lsrec_t, ls_stack[0]) 79 0 stevel #define LS_STACK(depth) offsetof(lsrec_t, ls_stack[depth]) 80 0 stevel 81 0 stevel static void report_stats(FILE *, lsrec_t **, size_t, uint64_t, uint64_t); 82 0 stevel static void report_trace(FILE *, lsrec_t **); 83 0 stevel 84 0 stevel extern int symtab_init(void); 85 0 stevel extern char *addr_to_sym(uintptr_t, uintptr_t *, size_t *); 86 0 stevel extern uintptr_t sym_to_addr(char *name); 87 0 stevel extern size_t sym_size(char *name); 88 0 stevel extern char *strtok_r(char *, const char *, char **); 89 0 stevel 90 0 stevel #define DEFAULT_NRECS 10000 91 0 stevel #define DEFAULT_HZ 97 92 0 stevel #define MAX_HZ 1000 93 0 stevel #define MIN_AGGSIZE (16 * 1024) 94 0 stevel #define MAX_AGGSIZE (32 * 1024 * 1024) 95 0 stevel 96 0 stevel static int g_stkdepth; 97 0 stevel static int g_topn = INT_MAX; 98 0 stevel static hrtime_t g_elapsed; 99 0 stevel static int g_rates = 0; 100 0 stevel static int g_pflag = 0; 101 0 stevel static int g_Pflag = 0; 102 0 stevel static int g_wflag = 0; 103 0 stevel static int g_Wflag = 0; 104 0 stevel static int g_cflag = 0; 105 0 stevel static int g_kflag = 0; 106 0 stevel static int g_gflag = 0; 107 0 stevel static int g_Vflag = 0; 108 0 stevel static int g_tracing = 0; 109 0 stevel static size_t g_recsize; 110 0 stevel static size_t g_nrecs; 111 0 stevel static int g_nrecs_used; 112 0 stevel static uchar_t g_enabled[LS_MAX_EVENTS]; 113 0 stevel static hrtime_t g_min_duration[LS_MAX_EVENTS]; 114 0 stevel static dtrace_hdl_t *g_dtp; 115 0 stevel static char *g_predicate; 116 0 stevel static char *g_ipredicate; 117 0 stevel static char *g_prog; 118 0 stevel static int g_proglen; 119 0 stevel static int g_dropped; 120 0 stevel 121 0 stevel typedef struct ls_event_info { 122 0 stevel char ev_type; 123 0 stevel char ev_lhdr[20]; 124 0 stevel char ev_desc[80]; 125 0 stevel char ev_units[10]; 126 0 stevel char ev_name[DTRACE_NAMELEN]; 127 0 stevel char *ev_predicate; 128 0 stevel char *ev_acquire; 129 0 stevel } ls_event_info_t; 130 0 stevel 131 0 stevel static ls_event_info_t g_event_info[LS_MAX_EVENTS] = { 132 6103 ck142721 { 'C', "Lock", "Adaptive mutex spin", "nsec", 133 0 stevel "lockstat:::adaptive-spin" }, 134 0 stevel { 'C', "Lock", "Adaptive mutex block", "nsec", 135 0 stevel "lockstat:::adaptive-block" }, 136 6103 ck142721 { 'C', "Lock", "Spin lock spin", "nsec", 137 0 stevel "lockstat:::spin-spin" }, 138 6103 ck142721 { 'C', "Lock", "Thread lock spin", "nsec", 139 0 stevel "lockstat:::thread-spin" }, 140 0 stevel { 'C', "Lock", "R/W writer blocked by writer", "nsec", 141 0 stevel "lockstat:::rw-block", "arg2 == 0 && arg3 == 1" }, 142 0 stevel { 'C', "Lock", "R/W writer blocked by readers", "nsec", 143 0 stevel "lockstat:::rw-block", "arg2 == 0 && arg3 == 0 && arg4" }, 144 0 stevel { 'C', "Lock", "R/W reader blocked by writer", "nsec", 145 0 stevel "lockstat:::rw-block", "arg2 != 0 && arg3 == 1" }, 146 0 stevel { 'C', "Lock", "R/W reader blocked by write wanted", "nsec", 147 0 stevel "lockstat:::rw-block", "arg2 != 0 && arg3 == 0 && arg4" }, 148 0 stevel { 'C', "Lock", "Unknown event (type 8)", "units" }, 149 0 stevel { 'C', "Lock", "Unknown event (type 9)", "units" }, 150 0 stevel { 'C', "Lock", "Unknown event (type 10)", "units" }, 151 0 stevel { 'C', "Lock", "Unknown event (type 11)", "units" }, 152 0 stevel { 'C', "Lock", "Unknown event (type 12)", "units" }, 153 0 stevel { 'C', "Lock", "Unknown event (type 13)", "units" }, 154 0 stevel { 'C', "Lock", "Unknown event (type 14)", "units" }, 155 0 stevel { 'C', "Lock", "Unknown event (type 15)", "units" }, 156 0 stevel { 'C', "Lock", "Unknown event (type 16)", "units" }, 157 0 stevel { 'C', "Lock", "Unknown event (type 17)", "units" }, 158 0 stevel { 'C', "Lock", "Unknown event (type 18)", "units" }, 159 0 stevel { 'C', "Lock", "Unknown event (type 19)", "units" }, 160 0 stevel { 'C', "Lock", "Unknown event (type 20)", "units" }, 161 0 stevel { 'C', "Lock", "Unknown event (type 21)", "units" }, 162 0 stevel { 'C', "Lock", "Unknown event (type 22)", "units" }, 163 0 stevel { 'C', "Lock", "Unknown event (type 23)", "units" }, 164 0 stevel { 'C', "Lock", "Unknown event (type 24)", "units" }, 165 0 stevel { 'C', "Lock", "Unknown event (type 25)", "units" }, 166 0 stevel { 'C', "Lock", "Unknown event (type 26)", "units" }, 167 0 stevel { 'C', "Lock", "Unknown event (type 27)", "units" }, 168 0 stevel { 'C', "Lock", "Unknown event (type 28)", "units" }, 169 0 stevel { 'C', "Lock", "Unknown event (type 29)", "units" }, 170 0 stevel { 'C', "Lock", "Unknown event (type 30)", "units" }, 171 0 stevel { 'C', "Lock", "Unknown event (type 31)", "units" }, 172 0 stevel { 'H', "Lock", "Adaptive mutex hold", "nsec", 173 0 stevel "lockstat:::adaptive-release", NULL, 174 0 stevel "lockstat:::adaptive-acquire" }, 175 0 stevel { 'H', "Lock", "Spin lock hold", "nsec", 176 0 stevel "lockstat:::spin-release", NULL, 177 0 stevel "lockstat:::spin-acquire" }, 178 0 stevel { 'H', "Lock", "R/W writer hold", "nsec", 179 0 stevel "lockstat:::rw-release", "arg1 == 0", 180 0 stevel "lockstat:::rw-acquire" }, 181 0 stevel { 'H', "Lock", "R/W reader hold", "nsec", 182 0 stevel "lockstat:::rw-release", "arg1 != 0", 183 0 stevel "lockstat:::rw-acquire" }, 184 0 stevel { 'H', "Lock", "Unknown event (type 36)", "units" }, 185 0 stevel { 'H', "Lock", "Unknown event (type 37)", "units" }, 186 0 stevel { 'H', "Lock", "Unknown event (type 38)", "units" }, 187 0 stevel { 'H', "Lock", "Unknown event (type 39)", "units" }, 188 0 stevel { 'H', "Lock", "Unknown event (type 40)", "units" }, 189 0 stevel { 'H', "Lock", "Unknown event (type 41)", "units" }, 190 0 stevel { 'H', "Lock", "Unknown event (type 42)", "units" }, 191 0 stevel { 'H', "Lock", "Unknown event (type 43)", "units" }, 192 0 stevel { 'H', "Lock", "Unknown event (type 44)", "units" }, 193 0 stevel { 'H', "Lock", "Unknown event (type 45)", "units" }, 194 0 stevel { 'H', "Lock", "Unknown event (type 46)", "units" }, 195 0 stevel { 'H', "Lock", "Unknown event (type 47)", "units" }, 196 0 stevel { 'H', "Lock", "Unknown event (type 48)", "units" }, 197 0 stevel { 'H', "Lock", "Unknown event (type 49)", "units" }, 198 0 stevel { 'H', "Lock", "Unknown event (type 50)", "units" }, 199 0 stevel { 'H', "Lock", "Unknown event (type 51)", "units" }, 200 0 stevel { 'H', "Lock", "Unknown event (type 52)", "units" }, 201 0 stevel { 'H', "Lock", "Unknown event (type 53)", "units" }, 202 0 stevel { 'H', "Lock", "Unknown event (type 54)", "units" }, 203 0 stevel { 'H', "Lock", "Unknown event (type 55)", "units" }, 204 0 stevel { 'I', "CPU+PIL", "Profiling interrupt", "nsec", 205 0 stevel "profile:::profile-97", NULL }, 206 0 stevel { 'I', "Lock", "Unknown event (type 57)", "units" }, 207 0 stevel { 'I', "Lock", "Unknown event (type 58)", "units" }, 208 0 stevel { 'I', "Lock", "Unknown event (type 59)", "units" }, 209 0 stevel { 'E', "Lock", "Recursive lock entry detected", "(N/A)", 210 0 stevel "lockstat:::rw-release", NULL, "lockstat:::rw-acquire" }, 211 0 stevel { 'E', "Lock", "Lockstat enter failure", "(N/A)" }, 212 0 stevel { 'E', "Lock", "Lockstat exit failure", "nsec" }, 213 0 stevel { 'E', "Lock", "Lockstat record failure", "(N/A)" }, 214 0 stevel }; 215 0 stevel 216 0 stevel static void 217 0 stevel fail(int do_perror, const char *message, ...) 218 0 stevel { 219 0 stevel va_list args; 220 0 stevel int save_errno = errno; 221 0 stevel 222 0 stevel va_start(args, message); 223 0 stevel (void) fprintf(stderr, "lockstat: "); 224 0 stevel (void) vfprintf(stderr, message, args); 225 0 stevel va_end(args); 226 0 stevel if (do_perror) 227 0 stevel (void) fprintf(stderr, ": %s", strerror(save_errno)); 228 0 stevel (void) fprintf(stderr, "\n"); 229 0 stevel exit(2); 230 0 stevel } 231 0 stevel 232 0 stevel static void 233 0 stevel dfail(const char *message, ...) 234 0 stevel { 235 0 stevel va_list args; 236 0 stevel 237 0 stevel va_start(args, message); 238 0 stevel (void) fprintf(stderr, "lockstat: "); 239 0 stevel (void) vfprintf(stderr, message, args); 240 0 stevel va_end(args); 241 0 stevel (void) fprintf(stderr, ": %s\n", 242 0 stevel dtrace_errmsg(g_dtp, dtrace_errno(g_dtp))); 243 0 stevel 244 0 stevel exit(2); 245 0 stevel } 246 0 stevel 247 0 stevel static void 248 0 stevel show_events(char event_type, char *desc) 249 0 stevel { 250 0 stevel int i, first = -1, last; 251 0 stevel 252 0 stevel for (i = 0; i < LS_MAX_EVENTS; i++) { 253 0 stevel ls_event_info_t *evp = &g_event_info[i]; 254 0 stevel if (evp->ev_type != event_type || 255 0 stevel strncmp(evp->ev_desc, "Unknown event", 13) == 0) 256 0 stevel continue; 257 0 stevel if (first == -1) 258 0 stevel first = i; 259 0 stevel last = i; 260 0 stevel } 261 0 stevel 262 0 stevel (void) fprintf(stderr, 263 0 stevel "\n%s events (lockstat -%c or lockstat -e %d-%d):\n\n", 264 0 stevel desc, event_type, first, last); 265 0 stevel 266 0 stevel for (i = first; i <= last; i++) 267 0 stevel (void) fprintf(stderr, 268 0 stevel "%4d = %s\n", i, g_event_info[i].ev_desc); 269 0 stevel } 270 0 stevel 271 0 stevel static void 272 0 stevel usage(void) 273 0 stevel { 274 0 stevel (void) fprintf(stderr, 275 0 stevel "Usage: lockstat [options] command [args]\n" 276 0 stevel "\nEvent selection options:\n\n" 277 0 stevel " -C watch contention events [on by default]\n" 278 0 stevel " -E watch error events [off by default]\n" 279 0 stevel " -H watch hold events [off by default]\n" 280 0 stevel " -I watch interrupt events [off by default]\n" 281 0 stevel " -A watch all lock events [equivalent to -CH]\n" 282 0 stevel " -e event_list only watch the specified events (shown below);\n" 283 0 stevel " <event_list> is a comma-separated list of\n" 284 0 stevel " events or ranges of events, e.g. 1,4-7,35\n" 285 0 stevel " -i rate interrupt rate for -I [default: %d Hz]\n" 286 0 stevel "\nData gathering options:\n\n" 287 0 stevel " -b basic statistics (lock, caller, event count)\n" 288 0 stevel " -t timing for all events [default]\n" 289 0 stevel " -h histograms for event times\n" 290 0 stevel " -s depth stack traces <depth> deep\n" 291 0 stevel " -x opt[=val] enable or modify DTrace options\n" 292 0 stevel "\nData filtering options:\n\n" 293 0 stevel " -n nrecords maximum number of data records [default: %d]\n" 294 0 stevel " -l lock[,size] only watch <lock>, which can be specified as a\n" 295 0 stevel " symbolic name or hex address; <size> defaults\n" 296 0 stevel " to the ELF symbol size if available, 1 if not\n" 297 0 stevel " -f func[,size] only watch events generated by <func>\n" 298 0 stevel " -d duration only watch events longer than <duration>\n" 299 0 stevel " -T trace (rather than sample) events\n" 300 0 stevel "\nData reporting options:\n\n" 301 0 stevel " -c coalesce lock data for arrays like pse_mutex[]\n" 302 0 stevel " -k coalesce PCs within functions\n" 303 0 stevel " -g show total events generated by function\n" 304 0 stevel " -w wherever: don't distinguish events by caller\n" 305 0 stevel " -W whichever: don't distinguish events by lock\n" 306 0 stevel " -R display rates rather than counts\n" 307 0 stevel " -p parsable output format (awk(1)-friendly)\n" 308 0 stevel " -P sort lock data by (count * avg_time) product\n" 309 0 stevel " -D n only display top <n> events of each type\n" 310 0 stevel " -o filename send output to <filename>\n", 311 0 stevel DEFAULT_HZ, DEFAULT_NRECS); 312 0 stevel 313 0 stevel show_events('C', "Contention"); 314 0 stevel show_events('H', "Hold-time"); 315 0 stevel show_events('I', "Interrupt"); 316 0 stevel show_events('E', "Error"); 317 0 stevel (void) fprintf(stderr, "\n"); 318 0 stevel 319 0 stevel exit(1); 320 0 stevel } 321 0 stevel 322 0 stevel static int 323 0 stevel lockcmp(lsrec_t *a, lsrec_t *b) 324 0 stevel { 325 0 stevel int i; 326 0 stevel 327 0 stevel if (a->ls_event < b->ls_event) 328 0 stevel return (-1); 329 0 stevel if (a->ls_event > b->ls_event) 330 0 stevel return (1); 331 0 stevel 332 0 stevel for (i = g_stkdepth - 1; i >= 0; i--) { 333 0 stevel if (a->ls_stack[i] < b->ls_stack[i]) 334 0 stevel return (-1); 335 0 stevel if (a->ls_stack[i] > b->ls_stack[i]) 336 0 stevel return (1); 337 0 stevel } 338 0 stevel 339 0 stevel if (a->ls_caller < b->ls_caller) 340 0 stevel return (-1); 341 0 stevel if (a->ls_caller > b->ls_caller) 342 0 stevel return (1); 343 0 stevel 344 0 stevel if (a->ls_lock < b->ls_lock) 345 0 stevel return (-1); 346 0 stevel if (a->ls_lock > b->ls_lock) 347 0 stevel return (1); 348 0 stevel 349 0 stevel return (0); 350 0 stevel } 351 0 stevel 352 0 stevel static int 353 0 stevel countcmp(lsrec_t *a, lsrec_t *b) 354 0 stevel { 355 0 stevel if (a->ls_event < b->ls_event) 356 0 stevel return (-1); 357 0 stevel if (a->ls_event > b->ls_event) 358 0 stevel return (1); 359 0 stevel 360 0 stevel return (b->ls_count - a->ls_count); 361 0 stevel } 362 0 stevel 363 0 stevel static int 364 0 stevel timecmp(lsrec_t *a, lsrec_t *b) 365 0 stevel { 366 0 stevel if (a->ls_event < b->ls_event) 367 0 stevel return (-1); 368 0 stevel if (a->ls_event > b->ls_event) 369 0 stevel return (1); 370 0 stevel 371 0 stevel if (a->ls_time < b->ls_time) 372 0 stevel return (1); 373 0 stevel if (a->ls_time > b->ls_time) 374 0 stevel return (-1); 375 0 stevel 376 0 stevel return (0); 377 0 stevel } 378 0 stevel 379 0 stevel static int 380 0 stevel lockcmp_anywhere(lsrec_t *a, lsrec_t *b) 381 0 stevel { 382 0 stevel if (a->ls_event < b->ls_event) 383 0 stevel return (-1); 384 0 stevel if (a->ls_event > b->ls_event) 385 0 stevel return (1); 386 0 stevel 387 0 stevel if (a->ls_lock < b->ls_lock) 388 0 stevel return (-1); 389 0 stevel if (a->ls_lock > b->ls_lock) 390 0 stevel return (1); 391 0 stevel 392 0 stevel return (0); 393 0 stevel } 394 0 stevel 395 0 stevel static int 396 0 stevel lock_and_count_cmp_anywhere(lsrec_t *a, lsrec_t *b) 397 0 stevel { 398 0 stevel if (a->ls_event < b->ls_event) 399 0 stevel return (-1); 400 0 stevel if (a->ls_event > b->ls_event) 401 0 stevel return (1); 402 0 stevel 403 0 stevel if (a->ls_lock < b->ls_lock) 404 0 stevel return (-1); 405 0 stevel if (a->ls_lock > b->ls_lock) 406 0 stevel return (1); 407 0 stevel 408 0 stevel return (b->ls_count - a->ls_count); 409 0 stevel } 410 0 stevel 411 0 stevel static int 412 0 stevel sitecmp_anylock(lsrec_t *a, lsrec_t *b) 413 0 stevel { 414 0 stevel int i; 415 0 stevel 416 0 stevel if (a->ls_event < b->ls_event) 417 0 stevel return (-1); 418 0 stevel if (a->ls_event > b->ls_event) 419 0 stevel return (1); 420 0 stevel 421 0 stevel for (i = g_stkdepth - 1; i >= 0; i--) { 422 0 stevel if (a->ls_stack[i] < b->ls_stack[i]) 423 0 stevel return (-1); 424 0 stevel if (a->ls_stack[i] > b->ls_stack[i]) 425 0 stevel return (1); 426 0 stevel } 427 0 stevel 428 0 stevel if (a->ls_caller < b->ls_caller) 429 0 stevel return (-1); 430 0 stevel if (a->ls_caller > b->ls_caller) 431 0 stevel return (1); 432 0 stevel 433 0 stevel return (0); 434 0 stevel } 435 0 stevel 436 0 stevel static int 437 0 stevel site_and_count_cmp_anylock(lsrec_t *a, lsrec_t *b) 438 0 stevel { 439 0 stevel int i; 440 0 stevel 441 0 stevel if (a->ls_event < b->ls_event) 442 0 stevel return (-1); 443 0 stevel if (a->ls_event > b->ls_event) 444 0 stevel return (1); 445 0 stevel 446 0 stevel for (i = g_stkdepth - 1; i >= 0; i--) { 447 0 stevel if (a->ls_stack[i] < b->ls_stack[i]) 448 0 stevel return (-1); 449 0 stevel if (a->ls_stack[i] > b->ls_stack[i]) 450 0 stevel return (1); 451 0 stevel } 452 0 stevel 453 0 stevel if (a->ls_caller < b->ls_caller) 454 0 stevel return (-1); 455 0 stevel if (a->ls_caller > b->ls_caller) 456 0 stevel return (1); 457 0 stevel 458 0 stevel return (b->ls_count - a->ls_count); 459 0 stevel } 460 0 stevel 461 0 stevel static void 462 0 stevel mergesort(int (*cmp)(lsrec_t *, lsrec_t *), lsrec_t **a, lsrec_t **b, int n) 463 0 stevel { 464 0 stevel int m = n / 2; 465 0 stevel int i, j; 466 0 stevel 467 0 stevel if (m > 1) 468 0 stevel mergesort(cmp, a, b, m); 469 0 stevel if (n - m > 1) 470 0 stevel mergesort(cmp, a + m, b + m, n - m); 471 0 stevel for (i = m; i > 0; i--) 472 0 stevel b[i - 1] = a[i - 1]; 473 0 stevel for (j = m - 1; j < n - 1; j++) 474 0 stevel b[n + m - j - 2] = a[j + 1]; 475 0 stevel while (i < j) 476 0 stevel *a++ = cmp(b[i], b[j]) < 0 ? b[i++] : b[j--]; 477 0 stevel *a = b[i]; 478 0 stevel } 479 0 stevel 480 0 stevel static void 481 0 stevel coalesce(int (*cmp)(lsrec_t *, lsrec_t *), lsrec_t **lock, int n) 482 0 stevel { 483 0 stevel int i, j; 484 0 stevel lsrec_t *target, *current; 485 0 stevel 486 0 stevel target = lock[0]; 487 0 stevel 488 0 stevel for (i = 1; i < n; i++) { 489 0 stevel current = lock[i]; 490 0 stevel if (cmp(current, target) != 0) { 491 0 stevel target = current; 492 0 stevel continue; 493 0 stevel } 494 0 stevel current->ls_event = LS_MAX_EVENTS; 495 0 stevel target->ls_count += current->ls_count; 496 0 stevel target->ls_refcnt += current->ls_refcnt; 497 0 stevel if (g_recsize < LS_TIME) 498 0 stevel continue; 499 0 stevel target->ls_time += current->ls_time; 500 0 stevel if (g_recsize < LS_HIST) 501 0 stevel continue; 502 0 stevel for (j = 0; j < 64; j++) 503 0 stevel target->ls_hist[j] += current->ls_hist[j]; 504 0 stevel } 505 0 stevel } 506 0 stevel 507 0 stevel static void 508 0 stevel coalesce_symbol(uintptr_t *addrp) 509 0 stevel { 510 0 stevel uintptr_t symoff; 511 0 stevel size_t symsize; 512 0 stevel 513 0 stevel if (addr_to_sym(*addrp, &symoff, &symsize) != NULL && symoff < symsize) 514 0 stevel *addrp -= symoff; 515 0 stevel } 516 0 stevel 517 0 stevel static void 518 0 stevel predicate_add(char **pred, char *what, char *cmp, uintptr_t value) 519 0 stevel { 520 0 stevel char *new; 521 0 stevel int len, newlen; 522 0 stevel 523 0 stevel if (what == NULL) 524 0 stevel return; 525 0 stevel 526 0 stevel if (*pred == NULL) { 527 0 stevel *pred = malloc(1); 528 0 stevel *pred[0] = '\0'; 529 0 stevel } 530 0 stevel 531 0 stevel len = strlen(*pred); 532 0 stevel newlen = len + strlen(what) + 32 + strlen("( && )"); 533 0 stevel new = malloc(newlen); 534 0 stevel 535 0 stevel if (*pred[0] != '\0') { 536 0 stevel if (cmp != NULL) { 537 0 stevel (void) sprintf(new, "(%s) && (%s %s 0x%p)", 538 0 stevel *pred, what, cmp, (void *)value); 539 0 stevel } else { 540 0 stevel (void) sprintf(new, "(%s) && (%s)", *pred, what); 541 0 stevel } 542 0 stevel } else { 543 0 stevel if (cmp != NULL) { 544 0 stevel (void) sprintf(new, "%s %s 0x%p", 545 0 stevel what, cmp, (void *)value); 546 0 stevel } else { 547 0 stevel (void) sprintf(new, "%s", what); 548 0 stevel } 549 0 stevel } 550 0 stevel 551 0 stevel free(*pred); 552 0 stevel *pred = new; 553 0 stevel } 554 0 stevel 555 0 stevel static void 556 0 stevel predicate_destroy(char **pred) 557 0 stevel { 558 0 stevel free(*pred); 559 0 stevel *pred = NULL; 560 0 stevel } 561 0 stevel 562 0 stevel static void 563 0 stevel filter_add(char **filt, char *what, uintptr_t base, uintptr_t size) 564 0 stevel { 565 0 stevel char buf[256], *c = buf, *new; 566 0 stevel int len, newlen; 567 0 stevel 568 0 stevel if (*filt == NULL) { 569 0 stevel *filt = malloc(1); 570 0 stevel *filt[0] = '\0'; 571 0 stevel } 572 0 stevel 573 0 stevel (void) sprintf(c, "%s(%s >= 0x%p && %s < 0x%p)", *filt[0] != '\0' ? 574 0 stevel " || " : "", what, (void *)base, what, (void *)(base + size)); 575 0 stevel 576 0 stevel newlen = (len = strlen(*filt) + 1) + strlen(c); 577 0 stevel new = malloc(newlen); 578 0 stevel bcopy(*filt, new, len); 579 0 stevel (void) strcat(new, c); 580 0 stevel free(*filt); 581 0 stevel *filt = new; 582 0 stevel } 583 0 stevel 584 0 stevel static void 585 0 stevel filter_destroy(char **filt) 586 0 stevel { 587 0 stevel free(*filt); 588 0 stevel *filt = NULL; 589 0 stevel } 590 0 stevel 591 0 stevel static void 592 0 stevel dprog_add(const char *fmt, ...) 593 0 stevel { 594 0 stevel va_list args; 595 0 stevel int size, offs; 596 0 stevel char c; 597 0 stevel 598 0 stevel va_start(args, fmt); 599 0 stevel size = vsnprintf(&c, 1, fmt, args) + 1; 600 0 stevel 601 0 stevel if (g_proglen == 0) { 602 0 stevel offs = 0; 603 0 stevel } else { 604 0 stevel offs = g_proglen - 1; 605 0 stevel } 606 0 stevel 607 0 stevel g_proglen = offs + size; 608 0 stevel 609 0 stevel if ((g_prog = realloc(g_prog, g_proglen)) == NULL) 610 0 stevel fail(1, "failed to reallocate program text"); 611 0 stevel 612 0 stevel (void) vsnprintf(&g_prog[offs], size, fmt, args); 613 0 stevel } 614 0 stevel 615 0 stevel /* 616 0 stevel * This function may read like an open sewer, but keep in mind that programs 617 0 stevel * that generate other programs are rarely pretty. If one has the unenviable 618 0 stevel * task of maintaining or -- worse -- extending this code, use the -V option 619 0 stevel * to examine the D program as generated by this function. 620 0 stevel */ 621 0 stevel static void 622 0 stevel dprog_addevent(int event) 623 0 stevel { 624 0 stevel ls_event_info_t *info = &g_event_info[event]; 625 0 stevel char *pred = NULL; 626 0 stevel char stack[20]; 627 0 stevel const char *arg0, *caller; 628 0 stevel char *arg1 = "arg1"; 629 0 stevel char buf[80]; 630 0 stevel hrtime_t dur; 631 0 stevel int depth; 632 0 stevel 633 0 stevel if (info->ev_name[0] == '\0') 634 0 stevel return; 635 0 stevel 636 0 stevel if (info->ev_type == 'I') { 637 0 stevel /* 638 0 stevel * For interrupt events, arg0 (normally the lock pointer) is 639 0 stevel * the CPU address plus the current pil, and arg1 (normally 640 0 stevel * the number of nanoseconds) is the number of nanoseconds 641 0 stevel * late -- and it's stored in arg2. 642 0 stevel */ 643 0 stevel arg0 = "(uintptr_t)curthread->t_cpu + \n" 644 0 stevel "\t curthread->t_cpu->cpu_profile_pil"; 645 0 stevel caller = "(uintptr_t)arg0"; 646 0 stevel arg1 = "arg2"; 647 0 stevel } else { 648 0 stevel arg0 = "(uintptr_t)arg0"; 649 0 stevel caller = "caller"; 650 0 stevel } 651 0 stevel 652 0 stevel if (g_recsize > LS_HIST) { 653 0 stevel for (depth = 0; g_recsize > LS_STACK(depth); depth++) 654 0 stevel continue; 655 0 stevel 656 0 stevel if (g_tracing) { 657 0 stevel (void) sprintf(stack, "\tstack(%d);\n", depth); 658 0 stevel } else { 659 0 stevel (void) sprintf(stack, ", stack(%d)", depth); 660 0 stevel } 661 0 stevel } else { 662 0 stevel (void) sprintf(stack, ""); 663 0 stevel } 664 0 stevel 665 0 stevel if (info->ev_acquire != NULL) { 666 0 stevel /* 667 0 stevel * If this is a hold event, we need to generate an additional 668 0 stevel * clause for the acquire; the clause for the release will be 669 0 stevel * generated with the aggregating statement, below. 670 0 stevel */ 671 0 stevel dprog_add("%s\n", info->ev_acquire); 672 0 stevel predicate_add(&pred, info->ev_predicate, NULL, 0); 673 0 stevel predicate_add(&pred, g_predicate, NULL, 0); 674 0 stevel if (pred != NULL) 675 0 stevel dprog_add("/%s/\n", pred); 676 0 stevel 677 0 stevel dprog_add("{\n"); 678 0 stevel (void) sprintf(buf, "self->ev%d[(uintptr_t)arg0]", event); 679 0 stevel 680 0 stevel if (info->ev_type == 'H') { 681 0 stevel dprog_add("\t%s = timestamp;\n", buf); 682 0 stevel } else { 683 0 stevel /* 684 0 stevel * If this isn't a hold event, it's the recursive 685 0 stevel * error event. For this, we simply bump the 686 0 stevel * thread-local, per-lock count. 687 0 stevel */ 688 0 stevel dprog_add("\t%s++;\n", buf); 689 0 stevel } 690 0 stevel 691 0 stevel dprog_add("}\n\n"); 692 0 stevel predicate_destroy(&pred); 693 0 stevel pred = NULL; 694 0 stevel 695 0 stevel if (info->ev_type == 'E') { 696 0 stevel /* 697 0 stevel * If this is the recursive lock error event, we need 698 0 stevel * to generate an additional clause to decrement the 699 0 stevel * thread-local, per-lock count. This assures that we 700 0 stevel * only execute the aggregating clause if we have 701 0 stevel * recursive entry. 702 0 stevel */ 703 0 stevel dprog_add("%s\n", info->ev_name); 704 0 stevel dprog_add("/%s/\n{\n\t%s--;\n}\n\n", buf, buf); 705 0 stevel } 706 0 stevel 707 0 stevel predicate_add(&pred, buf, NULL, 0); 708 0 stevel 709 0 stevel if (info->ev_type == 'H') { 710 0 stevel (void) sprintf(buf, "timestamp -\n\t " 711 0 stevel "self->ev%d[(uintptr_t)arg0]", event); 712 0 stevel } 713 0 stevel 714 0 stevel arg1 = buf; 715 0 stevel } else { 716 0 stevel predicate_add(&pred, info->ev_predicate, NULL, 0); 717 0 stevel if (info->ev_type != 'I') 718 0 stevel predicate_add(&pred, g_predicate, NULL, 0); 719 0 stevel else 720 0 stevel predicate_add(&pred, g_ipredicate, NULL, 0); 721 0 stevel } 722 0 stevel 723 0 stevel if ((dur = g_min_duration[event]) != 0) 724 0 stevel predicate_add(&pred, arg1, ">=", dur); 725 0 stevel 726 0 stevel dprog_add("%s\n", info->ev_name); 727 0 stevel 728 0 stevel if (pred != NULL) 729 0 stevel dprog_add("/%s/\n", pred); 730 0 stevel predicate_destroy(&pred); 731 0 stevel 732 0 stevel dprog_add("{\n"); 733 0 stevel 734 0 stevel if (g_tracing) { 735 0 stevel dprog_add("\ttrace(%dULL);\n", event); 736 0 stevel dprog_add("\ttrace(%s);\n", arg0); 737 0 stevel dprog_add("\ttrace(%s);\n", caller); 738 0 stevel dprog_add(stack); 739 0 stevel } else { 740 1028 bmc /* 741 1028 bmc * The ordering here is important: when we process the 742 1028 bmc * aggregate, we count on the fact that @avg appears before 743 1028 bmc * @hist in program order to assure that @avg is assigned the 744 1028 bmc * first aggregation variable ID and @hist assigned the 745 1028 bmc * second; see the comment in process_aggregate() for details. 746 1028 bmc */ 747 0 stevel dprog_add("\t@avg[%dULL, %s, %s%s] = avg(%s);\n", 748 0 stevel event, arg0, caller, stack, arg1); 749 0 stevel 750 0 stevel if (g_recsize >= LS_HIST) { 751 0 stevel dprog_add("\t@hist[%dULL, %s, %s%s] = quantize" 752 0 stevel "(%s);\n", event, arg0, caller, stack, arg1); 753 0 stevel } 754 0 stevel } 755 0 stevel 756 0 stevel if (info->ev_acquire != NULL) 757 0 stevel dprog_add("\tself->ev%d[arg0] = 0;\n", event); 758 0 stevel 759 0 stevel dprog_add("}\n\n"); 760 0 stevel } 761 0 stevel 762 0 stevel static void 763 0 stevel dprog_compile() 764 0 stevel { 765 0 stevel dtrace_prog_t *prog; 766 0 stevel dtrace_proginfo_t info; 767 0 stevel 768 0 stevel if (g_Vflag) { 769 0 stevel (void) fprintf(stderr, "lockstat: vvvv D program vvvv\n"); 770 0 stevel (void) fputs(g_prog, stderr); 771 0 stevel (void) fprintf(stderr, "lockstat: ^^^^ D program ^^^^\n"); 772 0 stevel } 773 0 stevel 774 0 stevel if ((prog = dtrace_program_strcompile(g_dtp, g_prog, 775 0 stevel DTRACE_PROBESPEC_NAME, 0, 0, NULL)) == NULL) 776 0 stevel dfail("failed to compile program"); 777 0 stevel 778 0 stevel if (dtrace_program_exec(g_dtp, prog, &info) == -1) 779 0 stevel dfail("failed to enable probes"); 780 0 stevel 781 0 stevel if (dtrace_go(g_dtp) != 0) 782 0 stevel dfail("couldn't start tracing"); 783 0 stevel } 784 0 stevel 785 0 stevel static void 786 0 stevel status_fire(void) 787 0 stevel {} 788 0 stevel 789 0 stevel static void 790 0 stevel status_init(void) 791 0 stevel { 792 0 stevel dtrace_optval_t val, status, agg; 793 0 stevel struct sigaction act; 794 0 stevel struct itimerspec ts; 795 0 stevel struct sigevent ev; 796 0 stevel timer_t tid; 797 0 stevel 798 0 stevel if (dtrace_getopt(g_dtp, "statusrate", &status) == -1) 799 0 stevel dfail("failed to get 'statusrate'"); 800 0 stevel 801 0 stevel if (dtrace_getopt(g_dtp, "aggrate", &agg) == -1) 802 0 stevel dfail("failed to get 'statusrate'"); 803 0 stevel 804 0 stevel /* 805 0 stevel * We would want to awaken at a rate that is the GCD of the statusrate 806 0 stevel * and the aggrate -- but that seems a bit absurd. Instead, we'll 807 0 stevel * simply awaken at a rate that is the more frequent of the two, which 808 0 stevel * assures that we're never later than the interval implied by the 809 0 stevel * more frequent rate. 810 0 stevel */ 811 0 stevel val = status < agg ? status : agg; 812 0 stevel 813 0 stevel (void) sigemptyset(&act.sa_mask); 814 0 stevel act.sa_flags = 0; 815 0 stevel act.sa_handler = status_fire; 816 0 stevel (void) sigaction(SIGUSR1, &act, NULL); 817 0 stevel 818 0 stevel ev.sigev_notify = SIGEV_SIGNAL; 819 0 stevel ev.sigev_signo = SIGUSR1; 820 0 stevel 821 0 stevel if (timer_create(CLOCK_REALTIME, &ev, &tid) == -1) 822 0 stevel dfail("cannot create CLOCK_REALTIME timer"); 823 0 stevel 824 0 stevel ts.it_value.tv_sec = val / NANOSEC; 825 0 stevel ts.it_value.tv_nsec = val % NANOSEC; 826 0 stevel ts.it_interval = ts.it_value; 827 0 stevel 828 0 stevel if (timer_settime(tid, TIMER_RELTIME, &ts, NULL) == -1) 829 0 stevel dfail("cannot set time on CLOCK_REALTIME timer"); 830 0 stevel } 831 0 stevel 832 0 stevel static void 833 0 stevel status_check(void) 834 0 stevel { 835 0 stevel if (!g_tracing && dtrace_aggregate_snap(g_dtp) != 0) 836 0 stevel dfail("failed to snap aggregate"); 837 0 stevel 838 0 stevel if (dtrace_status(g_dtp) == -1) 839 0 stevel dfail("dtrace_status()"); 840 0 stevel } 841 0 stevel 842 0 stevel static void 843 457 bmc lsrec_fill(lsrec_t *lsrec, const dtrace_recdesc_t *rec, int nrecs, caddr_t data) 844 0 stevel { 845 0 stevel bzero(lsrec, g_recsize); 846 0 stevel lsrec->ls_count = 1; 847 0 stevel 848 0 stevel if ((g_recsize > LS_HIST && nrecs < 4) || (nrecs < 3)) 849 0 stevel fail(0, "truncated DTrace record"); 850 0 stevel 851 0 stevel if (rec->dtrd_size != sizeof (uint64_t)) 852 0 stevel fail(0, "bad event size in first record"); 853 0 stevel 854 0 stevel /* LINTED - alignment */ 855 0 stevel lsrec->ls_event = (uint32_t)*((uint64_t *)(data + rec->dtrd_offset)); 856 0 stevel rec++; 857 0 stevel 858 0 stevel if (rec->dtrd_size != sizeof (uintptr_t)) 859 0 stevel fail(0, "bad lock address size in second record"); 860 0 stevel 861 0 stevel /* LINTED - alignment */ 862 0 stevel lsrec->ls_lock = *((uintptr_t *)(data + rec->dtrd_offset)); 863 0 stevel rec++; 864 0 stevel 865 0 stevel if (rec->dtrd_size != sizeof (uintptr_t)) 866 0 stevel fail(0, "bad caller size in third record"); 867 0 stevel 868 0 stevel /* LINTED - alignment */ 869 0 stevel lsrec->ls_caller = *((uintptr_t *)(data + rec->dtrd_offset)); 870 0 stevel rec++; 871 0 stevel 872 0 stevel if (g_recsize > LS_HIST) { 873 0 stevel int frames, i; 874 0 stevel pc_t *stack; 875 0 stevel 876 0 stevel frames = rec->dtrd_size / sizeof (pc_t); 877 0 stevel /* LINTED - alignment */ 878 0 stevel stack = (pc_t *)(data + rec->dtrd_offset); 879 0 stevel 880 0 stevel for (i = 1; i < frames; i++) 881 0 stevel lsrec->ls_stack[i - 1] = stack[i]; 882 0 stevel } 883 0 stevel } 884 0 stevel 885 0 stevel /*ARGSUSED*/ 886 0 stevel static int 887 457 bmc count_aggregate(const dtrace_aggdata_t *agg, void *arg) 888 0 stevel { 889 0 stevel *((size_t *)arg) += 1; 890 0 stevel 891 0 stevel return (DTRACE_AGGWALK_NEXT); 892 0 stevel } 893 0 stevel 894 0 stevel static int 895 457 bmc process_aggregate(const dtrace_aggdata_t *agg, void *arg) 896 0 stevel { 897 457 bmc const dtrace_aggdesc_t *aggdesc = agg->dtada_desc; 898 0 stevel caddr_t data = agg->dtada_data; 899 0 stevel lsdata_t *lsdata = arg; 900 0 stevel lsrec_t *lsrec = lsdata->lsd_next; 901 457 bmc const dtrace_recdesc_t *rec; 902 0 stevel uint64_t *avg, *quantized; 903 0 stevel int i, j; 904 0 stevel 905 0 stevel assert(lsdata->lsd_count < g_nrecs); 906 0 stevel 907 1028 bmc /* 908 1028 bmc * Aggregation variable IDs are guaranteed to be generated in program 909 1028 bmc * order, and they are guaranteed to start from DTRACE_AGGVARIDNONE 910 1028 bmc * plus one. As "avg" appears before "hist" in program order, we know 911 1028 bmc * that "avg" will be allocated the first aggregation variable ID, and 912 1028 bmc * "hist" will be allocated the second aggregation variable ID -- and 913 1028 bmc * we therefore use the aggregation variable ID to differentiate the 914 1028 bmc * cases. 915 1028 bmc */ 916 1028 bmc if (aggdesc->dtagd_varid > DTRACE_AGGVARIDNONE + 1) { 917 0 stevel /* 918 1028 bmc * If this is the histogram entry. We'll copy the quantized 919 1028 bmc * data into lc_hist, and jump over the rest. 920 0 stevel */ 921 0 stevel rec = &aggdesc->dtagd_rec[aggdesc->dtagd_nrecs - 1]; 922 1028 bmc 923 1028 bmc if (aggdesc->dtagd_varid != DTRACE_AGGVARIDNONE + 2) 924 1028 bmc fail(0, "bad variable ID in aggregation record"); 925 0 stevel 926 0 stevel if (rec->dtrd_size != 927 0 stevel DTRACE_QUANTIZE_NBUCKETS * sizeof (uint64_t)) 928 0 stevel fail(0, "bad quantize size in aggregation record"); 929 0 stevel 930 0 stevel /* LINTED - alignment */ 931 0 stevel quantized = (uint64_t *)(data + rec->dtrd_offset); 932 0 stevel 933 0 stevel for (i = DTRACE_QUANTIZE_ZEROBUCKET, j = 0; 934 0 stevel i < DTRACE_QUANTIZE_NBUCKETS; i++, j++) 935 0 stevel lsrec->ls_hist[j] = quantized[i]; 936 0 stevel 937 0 stevel goto out; 938 0 stevel } 939 0 stevel 940 0 stevel lsrec_fill(lsrec, &aggdesc->dtagd_rec[1], 941 0 stevel aggdesc->dtagd_nrecs - 1, data); 942 0 stevel 943 0 stevel rec = &aggdesc->dtagd_rec[aggdesc->dtagd_nrecs - 1]; 944 0 stevel 945 0 stevel if (rec->dtrd_size != 2 * sizeof (uint64_t)) 946 0 stevel fail(0, "bad avg size in aggregation record"); 947 0 stevel 948 0 stevel /* LINTED - alignment */ 949 0 stevel avg = (uint64_t *)(data + rec->dtrd_offset); 950 0 stevel lsrec->ls_count = (uint32_t)avg[0]; 951 0 stevel lsrec->ls_time = (uintptr_t)avg[1]; 952 0 stevel 953 0 stevel if (g_recsize >= LS_HIST) 954 0 stevel return (DTRACE_AGGWALK_NEXT); 955 0 stevel 956 0 stevel out: 957 0 stevel lsdata->lsd_next = (lsrec_t *)((uintptr_t)lsrec + g_recsize); 958 0 stevel lsdata->lsd_count++; 959 0 stevel 960 0 stevel return (DTRACE_AGGWALK_NEXT); 961 0 stevel } 962 0 stevel 963 0 stevel static int 964 0 stevel process_trace(const dtrace_probedata_t *pdata, void *arg) 965 0 stevel { 966 0 stevel lsdata_t *lsdata = arg; 967 0 stevel lsrec_t *lsrec = lsdata->lsd_next; 968 0 stevel dtrace_eprobedesc_t *edesc = pdata->dtpda_edesc; 969 0 stevel caddr_t data = pdata->dtpda_data; 970 0 stevel 971 0 stevel if (lsdata->lsd_count >= g_nrecs) 972 0 stevel return (DTRACE_CONSUME_NEXT); 973 0 stevel 974 0 stevel lsrec_fill(lsrec, edesc->dtepd_rec, edesc->dtepd_nrecs, data); 975 0 stevel 976 0 stevel lsdata->lsd_next = (lsrec_t *)((uintptr_t)lsrec + g_recsize); 977 0 stevel lsdata->lsd_count++; 978 0 stevel 979 0 stevel return (DTRACE_CONSUME_NEXT); 980 0 stevel } 981 0 stevel 982 0 stevel static int 983 0 stevel process_data(FILE *out, char *data) 984 0 stevel { 985 0 stevel lsdata_t lsdata; 986 0 stevel 987 0 stevel /* LINTED - alignment */ 988 0 stevel lsdata.lsd_next = (lsrec_t *)data; 989 0 stevel lsdata.lsd_count = 0; 990 0 stevel 991 0 stevel if (g_tracing) { 992 0 stevel if (dtrace_consume(g_dtp, out, 993 0 stevel process_trace, NULL, &lsdata) != 0) 994 0 stevel dfail("failed to consume buffer"); 995 0 stevel 996 0 stevel return (lsdata.lsd_count); 997 0 stevel } 998 0 stevel 999 0 stevel if (dtrace_aggregate_walk_keyvarsorted(g_dtp, 1000 0 stevel process_aggregate, &lsdata) != 0) 1001 0 stevel dfail("failed to walk aggregate"); 1002 0 stevel 1003 0 stevel return (lsdata.lsd_count); 1004 0 stevel } 1005 0 stevel 1006 0 stevel /*ARGSUSED*/ 1007 0 stevel static int 1008 457 bmc drophandler(const dtrace_dropdata_t *data, void *arg) 1009 0 stevel { 1010 0 stevel g_dropped++; 1011 0 stevel (void) fprintf(stderr, "lockstat: warning: %s", data->dtdda_msg); 1012 0 stevel return (DTRACE_HANDLE_OK); 1013 0 stevel } 1014 0 stevel 1015 0 stevel int 1016 0 stevel main(int argc, char **argv) 1017 0 stevel { 1018 0 stevel char *data_buf; 1019 0 stevel lsrec_t *lsp, **current, **first, **sort_buf, **merge_buf; 1020 0 stevel FILE *out = stdout; 1021 0 stevel char c; 1022 0 stevel pid_t child; 1023 0 stevel int status; 1024 0 stevel int i, j; 1025 0 stevel hrtime_t duration; 1026 0 stevel char *addrp, *offp, *sizep, *evp, *lastp, *p; 1027 0 stevel uintptr_t addr; 1028 0 stevel size_t size, off; 1029 0 stevel int events_specified = 0; 1030 0 stevel int exec_errno = 0; 1031 0 stevel uint32_t event; 1032 0 stevel char *filt = NULL, *ifilt = NULL; 1033 0 stevel static uint64_t ev_count[LS_MAX_EVENTS + 1]; 1034 0 stevel static uint64_t ev_time[LS_MAX_EVENTS + 1]; 1035 0 stevel dtrace_optval_t aggsize; 1036 0 stevel char aggstr[10]; 1037 0 stevel long ncpus; 1038 0 stevel int dynvar = 0; 1039 0 stevel int err; 1040 0 stevel 1041 0 stevel if ((g_dtp = dtrace_open(DTRACE_VERSION, 0, &err)) == NULL) { 1042 0 stevel fail(0, "cannot open dtrace library: %s", 1043 0 stevel dtrace_errmsg(NULL, err)); 1044 0 stevel } 1045 0 stevel 1046 0 stevel if (dtrace_handle_drop(g_dtp, &drophandler, NULL) == -1) 1047 0 stevel dfail("couldn't establish drop handler"); 1048 0 stevel 1049 0 stevel if (symtab_init() == -1) 1050 0 stevel fail(1, "can't load kernel symbols"); 1051 0 stevel 1052 0 stevel g_nrecs = DEFAULT_NRECS; 1053 0 stevel 1054 0 stevel while ((c = getopt(argc, argv, LOCKSTAT_OPTSTR)) != EOF) { 1055 0 stevel switch (c) { 1056 0 stevel case 'b': 1057 0 stevel g_recsize = LS_BASIC; 1058 0 stevel break; 1059 0 stevel 1060 0 stevel case 't': 1061 0 stevel g_recsize = LS_TIME; 1062 0 stevel break; 1063 0 stevel 1064 0 stevel case 'h': 1065 0 stevel g_recsize = LS_HIST; 1066 0 stevel break; 1067 0 stevel 1068 0 stevel case 's': 1069 0 stevel if (!isdigit(optarg[0])) 1070 0 stevel usage(); 1071 0 stevel g_stkdepth = atoi(optarg); 1072 0 stevel if (g_stkdepth > LS_MAX_STACK_DEPTH) 1073 0 stevel fail(0, "max stack depth is %d", 1074 0 stevel LS_MAX_STACK_DEPTH); 1075 0 stevel g_recsize = LS_STACK(g_stkdepth); 1076 0 stevel break; 1077 0 stevel 1078 0 stevel case 'n': 1079 0 stevel if (!isdigit(optarg[0])) 1080 0 stevel usage(); 1081 0 stevel g_nrecs = atoi(optarg); 1082 0 stevel break; 1083 0 stevel 1084 0 stevel case 'd': 1085 0 stevel if (!isdigit(optarg[0])) 1086 0 stevel usage(); 1087 0 stevel duration = atoll(optarg); 1088 0 stevel 1089 0 stevel /* 1090 0 stevel * XXX -- durations really should be per event 1091 0 stevel * since the units are different, but it's hard 1092 0 stevel * to express this nicely in the interface. 1093 0 stevel * Not clear yet what the cleanest solution is. 1094 0 stevel */ 1095 0 stevel for (i = 0; i < LS_MAX_EVENTS; i++) 1096 0 stevel if (g_event_info[i].ev_type != 'E') 1097 0 stevel g_min_duration[i] = duration; 1098 0 stevel 1099 0 stevel break; 1100 0 stevel 1101 0 stevel case 'i': 1102 0 stevel if (!isdigit(optarg[0])) 1103 0 stevel usage(); 1104 0 stevel i = atoi(optarg); 1105 0 stevel if (i <= 0) 1106 0 stevel usage(); 1107 0 stevel if (i > MAX_HZ) 1108 0 stevel fail(0, "max interrupt rate is %d Hz", MAX_HZ); 1109 0 stevel 1110 0 stevel for (j = 0; j < LS_MAX_EVENTS; j++) 1111 0 stevel if (strcmp(g_event_info[j].ev_desc, 1112 0 stevel "Profiling interrupt") == 0) 1113 0 stevel break; 1114 0 stevel 1115 0 stevel (void) sprintf(g_event_info[j].ev_name, 1116 0 stevel "profile:::profile-%d", i); 1117 0 stevel break; 1118 0 stevel 1119 0 stevel case 'l': 1120 0 stevel case 'f': 1121 0 stevel addrp = strtok(optarg, ","); 1122 0 stevel sizep = strtok(NULL, ","); 1123 0 stevel addrp = strtok(optarg, ",+"); 1124 0 stevel offp = strtok(NULL, ","); 1125 0 stevel 1126 0 stevel size = sizep ? strtoul(sizep, NULL, 0) : 1; 1127 0 stevel off = offp ? strtoul(offp, NULL, 0) : 0; 1128 0 stevel 1129 0 stevel if (addrp[0] == '0') { 1130 0 stevel addr = strtoul(addrp, NULL, 16) + off; 1131 0 stevel } else { 1132 0 stevel addr = sym_to_addr(addrp) + off; 1133 0 stevel if (sizep == NULL) 1134 0 stevel size = sym_size(addrp) - off; 1135 0 stevel if (addr - off == 0) 1136 0 stevel fail(0, "symbol '%s' not found", addrp); 1137 0 stevel if (size == 0) 1138 0 stevel size = 1; 1139 0 stevel } 1140 0 stevel 1141 0 stevel 1142 0 stevel if (c == 'l') { 1143 0 stevel filter_add(&filt, "arg0", addr, size); 1144 0 stevel } else { 1145 0 stevel filter_add(&filt, "caller", addr, size); 1146 0 stevel filter_add(&ifilt, "arg0", addr, size); 1147 0 stevel } 1148 0 stevel break; 1149 0 stevel 1150 0 stevel case 'e': 1151 0 stevel evp = strtok_r(optarg, ",", &lastp); 1152 0 stevel while (evp) { 1153 0 stevel int ev1, ev2; 1154 0 stevel char *evp2; 1155 0 stevel 1156 0 stevel (void) strtok(evp, "-"); 1157 0 stevel evp2 = strtok(NULL, "-"); 1158 0 stevel ev1 = atoi(evp); 1159 0 stevel ev2 = evp2 ? atoi(evp2) : ev1; 1160 0 stevel if ((uint_t)ev1 >= LS_MAX_EVENTS || 1161 0 stevel (uint_t)ev2 >= LS_MAX_EVENTS || ev1 > ev2) 1162 0 stevel fail(0, "-e events out of range"); 1163 0 stevel for (i = ev1; i <= ev2; i++) 1164 0 stevel g_enabled[i] = 1; 1165 0 stevel evp = strtok_r(NULL, ",", &lastp); 1166 0 stevel } 1167 0 stevel events_specified = 1; 1168 0 stevel break; 1169 0 stevel 1170 0 stevel case 'c': 1171 0 stevel g_cflag = 1; 1172 0 stevel break; 1173 0 stevel 1174 0 stevel case 'k': 1175 0 stevel g_kflag = 1; 1176 0 stevel break; 1177 0 stevel 1178 0 stevel case 'w': 1179 0 stevel g_wflag = 1; 1180 0 stevel break; 1181 0 stevel 1182 0 stevel case 'W': 1183 0 stevel g_Wflag = 1; 1184 0 stevel break; 1185 0 stevel 1186 0 stevel case 'g': 1187 0 stevel g_gflag = 1; 1188 0 stevel break; 1189 0 stevel 1190 0 stevel case 'C': 1191 0 stevel case 'E': 1192 0 stevel case 'H': 1193 0 stevel case 'I': 1194 0 stevel for (i = 0; i < LS_MAX_EVENTS; i++) 1195 0 stevel if (g_event_info[i].ev_type == c) 1196 0 stevel g_enabled[i] = 1; 1197 0 stevel events_specified = 1; 1198 0 stevel break; 1199 0 stevel 1200 0 stevel case 'A': 1201 0 stevel for (i = 0; i < LS_MAX_EVENTS; i++) 1202 0 stevel if (strchr("CH", g_event_info[i].ev_type)) 1203 0 stevel g_enabled[i] = 1; 1204 0 stevel events_specified = 1; 1205 0 stevel break; 1206 0 stevel 1207 0 stevel case 'T': 1208 0 stevel g_tracing = 1; 1209 0 stevel break; 1210 0 stevel 1211 0 stevel case 'D': 1212 0 stevel if (!isdigit(optarg[0])) 1213 0 stevel usage(); 1214 0 stevel g_topn = atoi(optarg); 1215 0 stevel break; 1216 0 stevel 1217 0 stevel case 'R': 1218 0 stevel g_rates = 1; 1219 0 stevel break; 1220 0 stevel 1221 0 stevel case 'p': 1222 0 stevel g_pflag = 1; 1223 0 stevel break; 1224 0 stevel 1225 0 stevel case 'P': 1226 0 stevel g_Pflag = 1; 1227 0 stevel break; 1228 0 stevel 1229 0 stevel case 'o': 1230 0 stevel if ((out = fopen(optarg, "w")) == NULL) 1231 0 stevel fail(1, "error opening file"); 1232 0 stevel break; 1233 0 stevel 1234 0 stevel case 'V': 1235 0 stevel g_Vflag = 1; 1236 0 stevel break; 1237 0 stevel 1238 0 stevel default: 1239 0 stevel if (strchr(LOCKSTAT_OPTSTR, c) == NULL) 1240 0 stevel usage(); 1241 0 stevel } 1242 0 stevel } 1243 0 stevel 1244 0 stevel if (filt != NULL) { 1245 0 stevel predicate_add(&g_predicate, filt, NULL, 0); 1246 0 stevel filter_destroy(&filt); 1247 0 stevel } 1248 0 stevel 1249 0 stevel if (ifilt != NULL) { 1250 0 stevel predicate_add(&g_ipredicate, ifilt, NULL, 0); 1251 0 stevel filter_destroy(&ifilt); 1252 0 stevel } 1253 0 stevel 1254 0 stevel if (g_recsize == 0) { 1255 0 stevel if (g_gflag) { 1256 0 stevel g_stkdepth = LS_MAX_STACK_DEPTH; 1257 0 stevel g_recsize = LS_STACK(g_stkdepth); 1258 0 stevel } else { 1259 0 stevel g_recsize = LS_TIME; 1260 0 stevel } 1261 0 stevel } 1262 0 stevel 1263 0 stevel if (g_gflag && g_recsize <= LS_STACK(0)) 1264 0 stevel fail(0, "'-g' requires at least '-s 1' data gathering"); 1265 0 stevel 1266 0 stevel /* 1267 0 stevel * Make sure the alignment is reasonable 1268 0 stevel */ 1269 0 stevel g_recsize = -(-g_recsize & -sizeof (uint64_t)); 1270 0 stevel 1271 0 stevel for (i = 0; i < LS_MAX_EVENTS; i++) { 1272 0 stevel /* 1273 0 stevel * If no events were specified, enable -C. 1274 0 stevel */ 1275 0 stevel if (!events_specified && g_event_info[i].ev_type == 'C') 1276 0 stevel g_enabled[i] = 1; 1277 0 stevel } 1278 0 stevel 1279 0 stevel for (i = 0; i < LS_MAX_EVENTS; i++) { 1280 0 stevel if (!g_enabled[i]) 1281 0 stevel continue; 1282 0 stevel 1283 0 stevel if (g_event_info[i].ev_acquire != NULL) { 1284 0 stevel /* 1285 0 stevel * If we've enabled a hold event, we must explicitly 1286 0 stevel * allocate dynamic variable space. 1287 0 stevel */ 1288 0 stevel dynvar = 1; 1289 0 stevel } 1290 0 stevel 1291 0 stevel dprog_addevent(i); 1292 0 stevel } 1293 0 stevel 1294 0 stevel /* 1295 0 stevel * Make sure there are remaining arguments to specify a child command 1296 0 stevel * to execute. 1297 0 stevel */ 1298 0 stevel if (argc <= optind) 1299 0 stevel usage(); 1300 0 stevel 1301 0 stevel if ((ncpus = sysconf(_SC_NPROCESSORS_ONLN)) == -1) 1302 0 stevel dfail("couldn't determine number of online CPUs"); 1303 0 stevel 1304 0 stevel /* 1305 0 stevel * By default, we set our data buffer size to be the number of records 1306 0 stevel * multiplied by the size of the record, doubled to account for some 1307 0 stevel * DTrace slop and divided by the number of CPUs. We silently clamp 1308 0 stevel * the aggregation size at both a minimum and a maximum to prevent 1309 0 stevel * absurdly low or high values. 1310 0 stevel */ 1311 0 stevel if ((aggsize = (g_nrecs * g_recsize * 2) / ncpus) < MIN_AGGSIZE) 1312 0 stevel aggsize = MIN_AGGSIZE; 1313 0 stevel 1314 0 stevel if (aggsize > MAX_AGGSIZE) 1315 0 stevel aggsize = MAX_AGGSIZE; 1316 0 stevel 1317 0 stevel (void) sprintf(aggstr, "%lld", (long long)aggsize); 1318 0 stevel 1319 0 stevel if (!g_tracing) { 1320 0 stevel if (dtrace_setopt(g_dtp, "bufsize", "4k") == -1) 1321 0 stevel dfail("failed to set 'bufsize'"); 1322 0 stevel 1323 0 stevel if (dtrace_setopt(g_dtp, "aggsize", aggstr) == -1) 1324 0 stevel dfail("failed to set 'aggsize'"); 1325 0 stevel 1326 0 stevel if (dynvar) { 1327 0 stevel /* 1328 0 stevel * If we're using dynamic variables, we set our 1329 0 stevel * dynamic variable size to be one megabyte per CPU, 1330 0 stevel * with a hard-limit of 32 megabytes. This may still 1331 0 stevel * be too small in some cases, but it can be tuned 1332 0 stevel * manually via -x if need be. 1333 0 stevel */ 1334 0 stevel (void) sprintf(aggstr, "%ldm", ncpus < 32 ? ncpus : 32); 1335 0 stevel 1336 0 stevel if (dtrace_setopt(g_dtp, "dynvarsize", aggstr) == -1) 1337 0 stevel dfail("failed to set 'dynvarsize'"); 1338 0 stevel } 1339 0 stevel } else { 1340 0 stevel if (dtrace_setopt(g_dtp, "bufsize", aggstr) == -1) 1341 0 stevel dfail("failed to set 'bufsize'"); 1342 0 stevel } 1343 0 stevel 1344 0 stevel if (dtrace_setopt(g_dtp, "statusrate", "10sec") == -1) 1345 0 stevel dfail("failed to set 'statusrate'"); 1346 0 stevel 1347 0 stevel optind = 1; 1348 0 stevel while ((c = getopt(argc, argv, LOCKSTAT_OPTSTR)) != EOF) { 1349 0 stevel switch (c) { 1350 0 stevel case 'x': 1351 0 stevel if ((p = strchr(optarg, '=')) != NULL) 1352 0 stevel *p++ = '\0'; 1353 0 stevel 1354 0 stevel if (dtrace_setopt(g_dtp, optarg, p) != 0) 1355 0 stevel dfail("failed to set -x %s", optarg); 1356 0 stevel break; 1357 0 stevel } 1358 0 stevel } 1359 0 stevel 1360 0 stevel argc -= optind; 1361 0 stevel argv += optind; 1362 0 stevel 1363 0 stevel dprog_compile(); 1364 0 stevel status_init(); 1365 0 stevel 1366 0 stevel g_elapsed = -gethrtime(); 1367 0 stevel 1368 0 stevel /* 1369 0 stevel * Spawn the specified command and wait for it to complete. 1370 0 stevel */ 1371 0 stevel child = fork(); 1372 0 stevel if (child == -1) 1373 0 stevel fail(1, "cannot fork"); 1374 0 stevel if (child == 0) { 1375 0 stevel (void) dtrace_close(g_dtp); 1376 0 stevel (void) execvp(argv[0], &argv[0]); 1377 0 stevel exec_errno = errno; 1378 0 stevel exit(127); 1379 0 stevel } 1380 0 stevel 1381 0 stevel while (waitpid(child, &status, WEXITED) != child) 1382 0 stevel status_check(); 1383 0 stevel 1384 0 stevel g_elapsed += gethrtime(); 1385 0 stevel 1386 0 stevel if (WIFEXITED(status)) { 1387 0 stevel if (WEXITSTATUS(status) != 0) { 1388 0 stevel if (exec_errno != 0) { 1389 0 stevel errno = exec_errno; 1390 0 stevel fail(1, "could not execute %s", argv[0]); 1391 0 stevel } 1392 0 stevel (void) fprintf(stderr, 1393 0 stevel "lockstat: warning: %s exited with code %d\n", 1394 6103 ck142721 argv[0], WEXITSTATUS(status)); 1395 0 stevel } 1396 0 stevel } else { 1397 0 stevel (void) fprintf(stderr, 1398 0 stevel "lockstat: warning: %s died on signal %d\n", 1399 6103 ck142721 argv[0], WTERMSIG(status)); 1400 0 stevel } 1401 0 stevel 1402 0 stevel if (dtrace_stop(g_dtp) == -1) 1403 0 stevel dfail("failed to stop dtrace"); 1404 0 stevel 1405 0 stevel /* 1406 0 stevel * Before we read out the results, we need to allocate our buffer. 1407 0 stevel * If we're tracing, then we'll just use the precalculated size. If 1408 0 stevel * we're not, then we'll take a snapshot of the aggregate, and walk 1409 0 stevel * it to count the number of records. 1410 0 stevel */ 1411 0 stevel if (!g_tracing) { 1412 0 stevel if (dtrace_aggregate_snap(g_dtp) != 0) 1413 0 stevel dfail("failed to snap aggregate"); 1414 0 stevel 1415 0 stevel g_nrecs = 0; 1416 0 stevel 1417 0 stevel if (dtrace_aggregate_walk(g_dtp, 1418 0 stevel count_aggregate, &g_nrecs) != 0) 1419 0 stevel dfail("failed to walk aggregate"); 1420 0 stevel } 1421 0 stevel 1422 0 stevel if ((data_buf = memalign(sizeof (uint64_t), 1423 0 stevel (g_nrecs + 1) * g_recsize)) == NULL) 1424 0 stevel fail(1, "Memory allocation failed"); 1425 0 stevel 1426 0 stevel /* 1427 0 stevel * Read out the DTrace data. 1428 0 stevel */ 1429 0 stevel g_nrecs_used = process_data(out, data_buf); 1430 0 stevel 1431 0 stevel if (g_nrecs_used > g_nrecs || g_dropped) 1432 0 stevel (void) fprintf(stderr, "lockstat: warning: " 1433 0 stevel "ran out of data records (use -n for more)\n"); 1434 0 stevel 1435 0 stevel /* LINTED - alignment */ 1436 0 stevel for (i = 0, lsp = (lsrec_t *)data_buf; i < g_nrecs_used; i++, 1437 0 stevel /* LINTED - alignment */ 1438 0 stevel lsp = (lsrec_t *)((char *)lsp + g_recsize)) { 1439 0 stevel ev_count[lsp->ls_event] += lsp->ls_count; 1440 0 stevel ev_time[lsp->ls_event] += lsp->ls_time; 1441 0 stevel } 1442 0 stevel 1443 0 stevel /* 1444 0 stevel * If -g was specified, convert stacks into individual records. 1445 0 stevel */ 1446 0 stevel if (g_gflag) { 1447 0 stevel lsrec_t *newlsp, *oldlsp; 1448 0 stevel 1449 0 stevel newlsp = memalign(sizeof (uint64_t), 1450 0 stevel g_nrecs_used * LS_TIME * (g_stkdepth + 1)); 1451 0 stevel if (newlsp == NULL) 1452 0 stevel fail(1, "Cannot allocate space for -g processing"); 1453 0 stevel lsp = newlsp; 1454 0 stevel /* LINTED - alignment */ 1455 0 stevel for (i = 0, oldlsp = (lsrec_t *)data_buf; i < g_nrecs_used; i++, 1456 0 stevel /* LINTED - alignment */ 1457 0 stevel oldlsp = (lsrec_t *)((char *)oldlsp + g_recsize)) { 1458 0 stevel int fr; 1459 0 stevel int caller_in_stack = 0; 1460 0 stevel 1461 0 stevel if (oldlsp->ls_count == 0) 1462 0 stevel continue; 1463 0 stevel 1464 0 stevel for (fr = 0; fr < g_stkdepth; fr++) { 1465 0 stevel if (oldlsp->ls_stack[fr] == 0) 1466 0 stevel break; 1467 0 stevel if (oldlsp->ls_stack[fr] == oldlsp->ls_caller) 1468 0 stevel caller_in_stack = 1; 1469 0 stevel bcopy(oldlsp, lsp, LS_TIME); 1470 0 stevel lsp->ls_caller = oldlsp->ls_stack[fr]; 1471 0 stevel /* LINTED - alignment */ 1472 0 stevel lsp = (lsrec_t *)((char *)lsp + LS_TIME); 1473 0 stevel } 1474 0 stevel if (!caller_in_stack) { 1475 0 stevel bcopy(oldlsp, lsp, LS_TIME); 1476 0 stevel /* LINTED - alignment */ 1477 0 stevel lsp = (lsrec_t *)((char *)lsp + LS_TIME); 1478 0 stevel } 1479 0 stevel } 1480 0 stevel g_nrecs = g_nrecs_used = 1481 0 stevel ((uintptr_t)lsp - (uintptr_t)newlsp) / LS_TIME; 1482 0 stevel g_recsize = LS_TIME; 1483 0 stevel g_stkdepth = 0; 1484 0 stevel free(data_buf); 1485 0 stevel data_buf = (char *)newlsp; 1486 0 stevel } 1487 0 stevel 1488 0 stevel if ((sort_buf = calloc(2 * (g_nrecs + 1), 1489 0 stevel sizeof (void *))) == NULL) 1490 0 stevel fail(1, "Sort buffer allocation failed"); 1491 0 stevel merge_buf = sort_buf + (g_nrecs + 1); 1492 0 stevel 1493 0 stevel /* 1494 0 stevel * Build the sort buffer, discarding zero-count records along the way. 1495 0 stevel */ 1496 0 stevel /* LINTED - alignment */ 1497 0 stevel for (i = 0, lsp = (lsrec_t *)data_buf; i < g_nrecs_used; i++, 1498 0 stevel /* LINTED - alignment */ 1499 0 stevel lsp = (lsrec_t *)((char *)lsp + g_recsize)) { 1500 0 stevel if (lsp->ls_count == 0) 1501 0 stevel lsp->ls_event = LS_MAX_EVENTS; 1502 0 stevel sort_buf[i] = lsp; 1503 0 stevel } 1504 0 stevel 1505 0 stevel if (g_nrecs_used == 0) 1506 0 stevel exit(0); 1507 0 stevel 1508 0 stevel /* 1509 0 stevel * Add a sentinel after the last record 1510 0 stevel */ 1511 0 stevel sort_buf[i] = lsp; 1512 0 stevel lsp->ls_event = LS_MAX_EVENTS; 1513 0 stevel 1514 0 stevel if (g_tracing) { 1515 0 stevel report_trace(out, sort_buf); 1516 0 stevel return (0); 1517 0 stevel } 1518 0 stevel 1519 0 stevel /* 1520 0 stevel * Application of -g may have resulted in multiple records 1521 0 stevel * with the same signature; coalesce them. 1522 0 stevel */ 1523 0 stevel if (g_gflag) { 1524 0 stevel mergesort(lockcmp, sort_buf, merge_buf, g_nrecs_used); 1525 0 stevel coalesce(lockcmp, sort_buf, g_nrecs_used); 1526 0 stevel } 1527 0 stevel 1528 0 stevel /* 1529 0 stevel * Coalesce locks within the same symbol if -c option specified. 1530 0 stevel * Coalesce PCs within the same function if -k option specified. 1531 0 stevel */ 1532 0 stevel if (g_cflag || g_kflag) { 1533 0 stevel for (i = 0; i < g_nrecs_used; i++) { 1534 0 stevel int fr; 1535 0 stevel lsp = sort_buf[i]; 1536 0 stevel if (g_cflag) 1537 0 stevel coalesce_symbol(&lsp->ls_lock); 1538 0 stevel if (g_kflag) { 1539 0 stevel for (fr = 0; fr < g_stkdepth; fr++) 1540 0 stevel coalesce_symbol(&lsp->ls_stack[fr]); 1541 0 stevel coalesce_symbol(&lsp->ls_caller); 1542 0 stevel } 1543 0 stevel } 1544 0 stevel mergesort(lockcmp, sort_buf, merge_buf, g_nrecs_used); 1545 0 stevel coalesce(lockcmp, sort_buf, g_nrecs_used); 1546 0 stevel } 1547 0 stevel 1548 0 stevel /* 1549 0 stevel * Coalesce callers if -w option specified 1550 0 stevel */ 1551 0 stevel if (g_wflag) { 1552 0 stevel mergesort(lock_and_count_cmp_anywhere, 1553 0 stevel sort_buf, merge_buf, g_nrecs_used); 1554 0 stevel coalesce(lockcmp_anywhere, sort_buf, g_nrecs_used); 1555 0 stevel } 1556 0 stevel 1557 0 stevel /* 1558 0 stevel * Coalesce locks if -W option specified 1559 0 stevel */ 1560 0 stevel if (g_Wflag) { 1561 0 stevel mergesort(site_and_count_cmp_anylock, 1562 0 stevel sort_buf, merge_buf, g_nrecs_used); 1563 0 stevel coalesce(sitecmp_anylock, sort_buf, g_nrecs_used); 1564 0 stevel } 1565 0 stevel 1566 0 stevel /* 1567 0 stevel * Sort data by contention count (ls_count) or total time (ls_time), 1568 0 stevel * depending on g_Pflag. Override g_Pflag if time wasn't measured. 1569 0 stevel */ 1570 0 stevel if (g_recsize < LS_TIME) 1571 0 stevel g_Pflag = 0; 1572 0 stevel 1573 0 stevel if (g_Pflag) 1574 0 stevel mergesort(timecmp, sort_buf, merge_buf, g_nrecs_used); 1575 0 stevel else 1576 0 stevel mergesort(countcmp, sort_buf, merge_buf, g_nrecs_used); 1577 0 stevel 1578 0 stevel /* 1579 0 stevel * Display data by event type 1580 0 stevel */ 1581 0 stevel first = &sort_buf[0]; 1582 0 stevel while ((event = (*first)->ls_event) < LS_MAX_EVENTS) { 1583 0 stevel current = first; 1584 0 stevel while ((lsp = *current)->ls_event == event) 1585 0 stevel current++; 1586 0 stevel report_stats(out, first, current - first, ev_count[event], 1587 0 stevel ev_time[event]); 1588 0 stevel first = current; 1589 0 stevel } 1590 0 stevel 1591 0 stevel return (0); 1592 0 stevel } 1593 0 stevel 1594 0 stevel static char * 1595 0 stevel format_symbol(char *buf, uintptr_t addr, int show_size) 1596 0 stevel { 1597 0 stevel uintptr_t symoff; 1598 0 stevel char *symname; 1599 0 stevel size_t symsize; 1600 0 stevel 1601 0 stevel symname = addr_to_sym(addr, &symoff, &symsize); 1602 0 stevel 1603 0 stevel if (show_size && symoff == 0) 1604 0 stevel (void) sprintf(buf, "%s[%ld]", symname, (long)symsize); 1605 0 stevel else if (symoff == 0) 1606 0 stevel (void) sprintf(buf, "%s", symname); 1607 0 stevel else if (symoff < 16 && bcmp(symname, "cpu[", 4) == 0) /* CPU+PIL */ 1608 0 stevel (void) sprintf(buf, "%s+%ld", symname, (long)symoff); 1609 0 stevel else if (symoff <= symsize || (symoff < 256 && addr != symoff)) 1610 0 stevel (void) sprintf(buf, "%s+0x%llx", symname, 1611 0 stevel (unsigned long long)symoff); 1612 0 stevel else 1613 0 stevel (void) sprintf(buf, "0x%llx", (unsigned long long)addr); 1614 0 stevel return (buf); 1615 0 stevel } 1616 0 stevel 1617 0 stevel static void 1618 0 stevel report_stats(FILE *out, lsrec_t **sort_buf, size_t nrecs, uint64_t total_count, 1619 0 stevel uint64_t total_time) 1620 0 stevel { 1621 0 stevel uint32_t event = sort_buf[0]->ls_event; 1622 0 stevel lsrec_t *lsp; 1623 0 stevel double ptotal = 0.0; 1624 0 stevel double percent; 1625 0 stevel int i, j, fr; 1626 0 stevel int displayed; 1627 0 stevel int first_bin, last_bin, max_bin_count, total_bin_count; 1628 0 stevel int rectype; 1629 0 stevel char buf[256]; 1630 0 stevel char lhdr[80], chdr[80]; 1631 0 stevel 1632 0 stevel rectype = g_recsize; 1633 0 stevel 1634 0 stevel if (g_topn == 0) { 1635 0 stevel (void) fprintf(out, "%20llu %s\n", 1636 0 stevel g_rates == 0 ? total_count : 1637 0 stevel ((unsigned long long)total_count * NANOSEC) / g_elapsed, 1638 0 stevel g_event_info[event].ev_desc); 1639 0 stevel return; 1640 0 stevel } 1641 0 stevel 1642 0 stevel (void) sprintf(lhdr, "%s%s", 1643 0 stevel g_Wflag ? "Hottest " : "", g_event_info[event].ev_lhdr); 1644 0 stevel (void) sprintf(chdr, "%s%s", 1645 0 stevel g_wflag ? "Hottest " : "", "Caller"); 1646 0 stevel 1647 0 stevel if (!g_pflag) 1648 0 stevel (void) fprintf(out, 1649 0 stevel "\n%s: %.0f events in %.3f seconds (%.0f events/sec)\n\n", 1650 0 stevel g_event_info[event].ev_desc, (double)total_count, 1651 0 stevel (double)g_elapsed / NANOSEC, 1652 0 stevel (double)total_count * NANOSEC / g_elapsed); 1653 0 stevel 1654 0 stevel if (!g_pflag && rectype < LS_HIST) { 1655 0 stevel (void) sprintf(buf, "%s", g_event_info[event].ev_units); 1656 0 stevel (void) fprintf(out, "%5s %4s %4s %4s %8s %-22s %-24s\n", 1657 0 stevel g_rates ? "ops/s" : "Count", 1658 0 stevel g_gflag ? "genr" : "indv", 1659 0 stevel "cuml", "rcnt", rectype >= LS_TIME ? buf : "", lhdr, chdr); 1660 0 stevel (void) fprintf(out, "---------------------------------" 1661 0 stevel "----------------------------------------------\n"); 1662 0 stevel } 1663 0 stevel 1664 0 stevel displayed = 0; 1665 0 stevel for (i = 0; i < nrecs; i++) { 1666 0 stevel lsp = sort_buf[i]; 1667 0 stevel 1668 0 stevel if (displayed++ >= g_topn) 1669 0 stevel break; 1670 0 stevel 1671 0 stevel if (g_pflag) { 1672 0 stevel int j; 1673 0 stevel 1674 0 stevel (void) fprintf(out, "%u %u", 1675 0 stevel lsp->ls_event, lsp->ls_count); 1676 0 stevel (void) fprintf(out, " %s", 1677 0 stevel format_symbol(buf, lsp->ls_lock, g_cflag)); 1678 0 stevel (void) fprintf(out, " %s", 1679 0 stevel format_symbol(buf, lsp->ls_caller, 0)); 1680 0 stevel (void) fprintf(out, " %f", 1681 0 stevel (double)lsp->ls_refcnt / lsp->ls_count); 1682 0 stevel if (rectype >= LS_TIME) 1683 0 stevel (void) fprintf(out, " %llu", 1684 0 stevel (unsigned long long)lsp->ls_time); 1685 0 stevel if (rectype >= LS_HIST) { 1686 0 stevel for (j = 0; j < 64; j++) 1687 0 stevel (void) fprintf(out, " %u", 1688 0 stevel lsp->ls_hist[j]); 1689 0 stevel } 1690 0 stevel for (j = 0; j < LS_MAX_STACK_DEPTH; j++) { 1691 0 stevel if (rectype <= LS_STACK(j) || 1692 0 stevel lsp->ls_stack[j] == 0) 1693 0 stevel break; 1694 0 stevel (void) fprintf(out, " %s", 1695 0 stevel format_symbol(buf, lsp->ls_stack[j], 0)); 1696 0 stevel } 1697 0 stevel (void) fprintf(out, "\n"); 1698 0 stevel continue; 1699 0 stevel } 1700 0 stevel 1701 0 stevel if (rectype >= LS_HIST) { 1702 0 stevel (void) fprintf(out, "---------------------------------" 1703 0 stevel "----------------------------------------------\n"); 1704 0 stevel (void) sprintf(buf, "%s", 1705 0 stevel g_event_info[event].ev_units); 1706 0 stevel (void) fprintf(out, "%5s %4s %4s %4s %8s %-22s %-24s\n", 1707 0 stevel g_rates ? "ops/s" : "Count", 1708 0 stevel g_gflag ? "genr" : "indv", 1709 0 stevel "cuml", "rcnt", buf, lhdr, chdr); 1710 0 stevel } 1711 0 stevel 1712 0 stevel if (g_Pflag && total_time != 0) 1713 0 stevel percent = (lsp->ls_time * 100.00) / total_time; 1714 0 stevel else 1715 0 stevel percent = (lsp->ls_count * 100.00) / total_count; 1716 0 stevel 1717 0 stevel ptotal += percent; 1718 0 stevel 1719 0 stevel if (rectype >= LS_TIME) 1720 0 stevel (void) sprintf(buf, "%llu", 1721 0 stevel (unsigned long long)(lsp->ls_time / lsp->ls_count)); 1722 0 stevel else 1723 0 stevel buf[0] = '\0'; 1724 0 stevel 1725 0 stevel (void) fprintf(out, "%5llu ", 1726 0 stevel g_rates == 0 ? lsp->ls_count : 1727 0 stevel ((uint64_t)lsp->ls_count * NANOSEC) / g_elapsed); 1728 0 stevel 1729 0 stevel (void) fprintf(out, "%3.0f%% ", percent); 1730 0 stevel 1731 0 stevel if (g_gflag) 1732 0 stevel (void) fprintf(out, "---- "); 1733 0 stevel else 1734 0 stevel (void) fprintf(out, "%3.0f%% ", ptotal); 1735 0 stevel 1736 0 stevel (void) fprintf(out, "%4.2f %8s ", 1737 0 stevel (double)lsp->ls_refcnt / lsp->ls_count, buf); 1738 0 stevel 1739 0 stevel (void) fprintf(out, "%-22s ", 1740 0 stevel format_symbol(buf, lsp->ls_lock, g_cflag)); 1741 0 stevel 1742 0 stevel (void) fprintf(out, "%-24s\n", 1743 0 stevel format_symbol(buf, lsp->ls_caller, 0)); 1744 0 stevel 1745 0 stevel if (rectype < LS_HIST) 1746 0 stevel continue; 1747 0 stevel 1748 0 stevel (void) fprintf(out, "\n"); 1749 0 stevel (void) fprintf(out, "%10s %31s %-9s %-24s\n", 1750 6103 ck142721 g_event_info[event].ev_units, 1751 6103 ck142721 "------ Time Distribution ------", 1752 6103 ck142721 g_rates ? "ops/s" : "count", 1753 6103 ck142721 rectype > LS_STACK(0) ? "Stack" : ""); 1754 0 stevel 1755 0 stevel first_bin = 0; 1756 0 stevel while (lsp->ls_hist[first_bin] == 0) 1757 0 stevel first_bin++; 1758 0 stevel 1759 0 stevel last_bin = 63; 1760 0 stevel while (lsp->ls_hist[last_bin] == 0) 1761 0 stevel last_bin--; 1762 0 stevel 1763 0 stevel max_bin_count = 0; 1764 0 stevel total_bin_count = 0; 1765 0 stevel for (j = first_bin; j <= last_bin; j++) { 1766 0 stevel total_bin_count += lsp->ls_hist[j]; 1767 0 stevel if (lsp->ls_hist[j] > max_bin_count) 1768 0 stevel max_bin_count = lsp->ls_hist[j]; 1769 0 stevel } 1770 0 stevel 1771 0 stevel /* 1772 0 stevel * If we went a few frames below the caller, ignore them 1773 0 stevel */ 1774 0 stevel for (fr = 3; fr > 0; fr--) 1775 0 stevel if (lsp->ls_stack[fr] == lsp->ls_caller) 1776 0 stevel break; 1777 0 stevel 1778 0 stevel for (j = first_bin; j <= last_bin; j++) { 1779 0 stevel uint_t depth = (lsp->ls_hist[j] * 30) / total_bin_count; 1780 0 stevel (void) fprintf(out, "%10llu |%s%s %-9u ", 1781 0 stevel 1ULL << j, 1782 0 stevel "@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@" + 30 - depth, 1783 0 stevel " " + depth, 1784 0 stevel g_rates == 0 ? lsp->ls_hist[j] : 1785 0 stevel (uint_t)(((uint64_t)lsp->ls_hist[j] * NANOSEC) / 1786 0 stevel g_elapsed)); 1787 0 stevel if (rectype <= LS_STACK(fr) || lsp->ls_stack[fr] == 0) { 1788 0 stevel (void) fprintf(out, "\n"); 1789 0 stevel continue; 1790 0 stevel } 1791 0 stevel (void) fprintf(out, "%-24s\n", 1792 0 stevel format_symbol(buf, lsp->ls_stack[fr], 0)); 1793 0 stevel fr++; 1794 0 stevel } 1795 0 stevel while (rectype > LS_STACK(fr) && lsp->ls_stack[fr] != 0) { 1796 0 stevel (void) fprintf(out, "%15s %-36s %-24s\n", "", "", 1797 0 stevel format_symbol(buf, lsp->ls_stack[fr], 0)); 1798 0 stevel fr++; 1799 0 stevel } 1800 0 stevel } 1801 0 stevel 1802 0 stevel if (!g_pflag) 1803 0 stevel (void) fprintf(out, "---------------------------------" 1804 0 stevel "----------------------------------------------\n"); 1805 0 stevel 1806 0 stevel (void) fflush(out); 1807 0 stevel } 1808 0 stevel 1809 0 stevel static void 1810 0 stevel report_trace(FILE *out, lsrec_t **sort_buf) 1811 0 stevel { 1812 0 stevel lsrec_t *lsp; 1813 0 stevel int i, fr; 1814 0 stevel int rectype; 1815 0 stevel char buf[256], buf2[256]; 1816 0 stevel 1817 0 stevel rectype = g_recsize; 1818 0 stevel 1819 0 stevel if (!g_pflag) { 1820 0 stevel (void) fprintf(out, "%5s %7s %11s %-24s %-24s\n", 1821 0 stevel "Event", "Time", "Owner", "Lock", "Caller"); 1822 0 stevel (void) fprintf(out, "---------------------------------" 1823 0 stevel "----------------------------------------------\n"); 1824 0 stevel } 1825 0 stevel 1826 0 stevel for (i = 0; i < g_nrecs_used; i++) { 1827 0 stevel 1828 0 stevel lsp = sort_buf[i]; 1829 0 stevel 1830 0 stevel if (lsp->ls_event >= LS_MAX_EVENTS || lsp->ls_count == 0) 1831 0 stevel continue; 1832 0 stevel 1833 0 stevel (void) fprintf(out, "%2d %10llu %11p %-24s %-24s\n", 1834 0 stevel lsp->ls_event, (unsigned long long)lsp->ls_time, 1835 0 stevel (void *)lsp->ls_next, 1836 0 stevel format_symbol(buf, lsp->ls_lock, 0), 1837 0 stevel format_symbol(buf2, lsp->ls_caller, 0)); 1838 0 stevel 1839 0 stevel if (rectype <= LS_STACK(0)) 1840 0 stevel continue; 1841 0 stevel 1842 0 stevel /* 1843 0 stevel * If we went a few frames below the caller, ignore them 1844 0 stevel */ 1845 0 stevel for (fr = 3; fr > 0; fr--) 1846 0 stevel if (lsp->ls_stack[fr] == lsp->ls_caller) 1847 0 stevel break; 1848 0 stevel 1849 0 stevel while (rectype > LS_STACK(fr) && lsp->ls_stack[fr] != 0) { 1850 0 stevel (void) fprintf(out, "%53s %-24s\n", "", 1851 0 stevel format_symbol(buf, lsp->ls_stack[fr], 0)); 1852 0 stevel fr++; 1853 0 stevel } 1854 0 stevel (void) fprintf(out, "\n"); 1855 0 stevel } 1856 0 stevel 1857 0 stevel (void) fflush(out); 1858 0 stevel } 1859
Indexes created Fri Nov 27 08:09:20 UTC 2009
Terms of Use |
Privacy |
Trademarks |
Copyright Policy |
Site Guidelines |
Help
Your use of this web site or any of its content or software indicates your agreement to be bound by these Terms of Use.
Copyright © 1995-2008 Sun Microsystems, Inc.