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 1464 ahl * Common Development and Distribution License (the "License"). 6 1464 ahl * 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 1464 ahl 22 0 stevel /* 23 1464 ahl * Copyright 2006 Sun Microsystems, Inc. All rights reserved. 24 0 stevel * Use is subject to license terms. 25 0 stevel */ 26 0 stevel 27 0 stevel #pragma ident "%Z%%M% %I% %E% SMI" 28 0 stevel 29 0 stevel #include <assert.h> 30 0 stevel #include <dtrace.h> 31 0 stevel #include <limits.h> 32 0 stevel #include <link.h> 33 0 stevel #include <priv.h> 34 0 stevel #include <signal.h> 35 0 stevel #include <stdlib.h> 36 0 stevel #include <stdarg.h> 37 0 stevel #include <stdio.h> 38 0 stevel #include <string.h> 39 0 stevel #include <strings.h> 40 0 stevel #include <errno.h> 41 0 stevel #include <sys/wait.h> 42 1464 ahl #include <libgen.h> 43 0 stevel #include <libproc.h> 44 0 stevel 45 0 stevel static char *g_pname; 46 0 stevel static dtrace_hdl_t *g_dtp; 47 0 stevel struct ps_prochandle *g_pr; 48 0 stevel 49 0 stevel #define E_SUCCESS 0 50 0 stevel #define E_ERROR 1 51 0 stevel #define E_USAGE 2 52 0 stevel 53 0 stevel /* 54 0 stevel * For hold times we use a global associative array since for mutexes, in 55 0 stevel * user-land, it's not invalid to release a sychonization primitive that 56 0 stevel * another thread acquired; rwlocks require a thread-local associative array 57 0 stevel * since multiple thread can hold the same lock for reading. Note that we 58 0 stevel * ignore recursive mutex acquisitions and releases as they don't truly 59 0 stevel * affect lock contention. 60 0 stevel */ 61 0 stevel static const char *g_hold_init = 62 0 stevel "plockstat$target:::rw-acquire\n" 63 0 stevel "{\n" 64 0 stevel " self->rwhold[arg0] = timestamp;\n" 65 0 stevel "}\n" 66 0 stevel "plockstat$target:::mutex-acquire\n" 67 0 stevel "/arg1 == 0/\n" 68 0 stevel "{\n" 69 0 stevel " mtxhold[arg0] = timestamp;\n" 70 0 stevel "}\n"; 71 0 stevel 72 0 stevel static const char *g_hold_histogram = 73 0 stevel "plockstat$target:::rw-release\n" 74 0 stevel "/self->rwhold[arg0] && arg1 == 1/\n" 75 0 stevel "{\n" 76 0 stevel " @rw_w_hold[arg0, ustack()] =\n" 77 0 stevel " quantize(timestamp - self->rwhold[arg0]);\n" 78 0 stevel " self->rwhold[arg0] = 0;\n" 79 1464 ahl " rw_w_hold_found = 1;\n" 80 0 stevel "}\n" 81 0 stevel "plockstat$target:::rw-release\n" 82 0 stevel "/self->rwhold[arg0]/\n" 83 0 stevel "{\n" 84 0 stevel " @rw_r_hold[arg0, ustack()] =\n" 85 0 stevel " quantize(timestamp - self->rwhold[arg0]);\n" 86 0 stevel " self->rwhold[arg0] = 0;\n" 87 1464 ahl " rw_r_hold_found = 1;\n" 88 0 stevel "}\n" 89 0 stevel "plockstat$target:::mutex-release\n" 90 0 stevel "/mtxhold[arg0] && arg1 == 0/\n" 91 0 stevel "{\n" 92 0 stevel " @mtx_hold[arg0, ustack()] = quantize(timestamp - mtxhold[arg0]);\n" 93 0 stevel " mtxhold[arg0] = 0;\n" 94 1464 ahl " mtx_hold_found = 1;\n" 95 1464 ahl "}\n" 96 1464 ahl "\n" 97 1464 ahl "END\n" 98 1464 ahl "/mtx_hold_found/\n" 99 1464 ahl "{\n" 100 1464 ahl " trace(\"Mutex hold\");\n" 101 1464 ahl " printa(@mtx_hold);\n" 102 1464 ahl "}\n" 103 1464 ahl "END\n" 104 1464 ahl "/rw_r_hold_found/\n" 105 1464 ahl "{\n" 106 1464 ahl " trace(\"R/W reader hold\");\n" 107 1464 ahl " printa(@rw_r_hold);\n" 108 1464 ahl "}\n" 109 1464 ahl "END\n" 110 1464 ahl "/rw_w_hold_found/\n" 111 1464 ahl "{\n" 112 1464 ahl " trace(\"R/W writer hold\");\n" 113 1464 ahl " printa(@rw_w_hold);\n" 114 0 stevel "}\n"; 115 0 stevel 116 0 stevel static const char *g_hold_times = 117 0 stevel "plockstat$target:::rw-release\n" 118 0 stevel "/self->rwhold[arg0] && arg1 == 1/\n" 119 0 stevel "{\n" 120 1464 ahl " @rw_w_hold[arg0, ustack(5)] = sum(timestamp - self->rwhold[arg0]);\n" 121 1464 ahl " @rw_w_hold_count[arg0, ustack(5)] = count();\n" 122 0 stevel " self->rwhold[arg0] = 0;\n" 123 1464 ahl " rw_w_hold_found = 1;\n" 124 0 stevel "}\n" 125 0 stevel "plockstat$target:::rw-release\n" 126 0 stevel "/self->rwhold[arg0]/\n" 127 0 stevel "{\n" 128 1464 ahl " @rw_r_hold[arg0, ustack(5)] = sum(timestamp - self->rwhold[arg0]);\n" 129 1464 ahl " @rw_r_hold_count[arg0, ustack(5)] = count();\n" 130 0 stevel " self->rwhold[arg0] = 0;\n" 131 1464 ahl " rw_r_hold_found = 1;\n" 132 0 stevel "}\n" 133 0 stevel "plockstat$target:::mutex-release\n" 134 0 stevel "/mtxhold[arg0] && arg1 == 0/\n" 135 0 stevel "{\n" 136 1464 ahl " @mtx_hold[arg0, ustack(5)] = sum(timestamp - mtxhold[arg0]);\n" 137 1464 ahl " @mtx_hold_count[arg0, ustack(5)] = count();\n" 138 0 stevel " mtxhold[arg0] = 0;\n" 139 1464 ahl " mtx_hold_found = 1;\n" 140 1464 ahl "}\n" 141 1464 ahl "\n" 142 1464 ahl "END\n" 143 1464 ahl "/mtx_hold_found/\n" 144 1464 ahl "{\n" 145 1464 ahl " trace(\"Mutex hold\");\n" 146 1464 ahl " printa(@mtx_hold, @mtx_hold_count);\n" 147 1464 ahl "}\n" 148 1464 ahl "END\n" 149 1464 ahl "/rw_r_hold_found/\n" 150 1464 ahl "{\n" 151 1464 ahl " trace(\"R/W reader hold\");\n" 152 1464 ahl " printa(@rw_r_hold, @rw_r_hold_count);\n" 153 1464 ahl "}\n" 154 1464 ahl "END\n" 155 1464 ahl "/rw_w_hold_found/\n" 156 1464 ahl "{\n" 157 1464 ahl " trace(\"R/W writer hold\");\n" 158 1464 ahl " printa(@rw_w_hold, @rw_w_hold_count);\n" 159 0 stevel "}\n"; 160 0 stevel 161 0 stevel 162 0 stevel /* 163 0 stevel * For contention, we use thread-local associative arrays since we're tracing 164 0 stevel * a single thread's activity in libc and multiple threads can be blocking or 165 0 stevel * spinning on the same sychonization primitive. 166 0 stevel */ 167 0 stevel static const char *g_ctnd_init = 168 0 stevel "plockstat$target:::rw-block\n" 169 0 stevel "{\n" 170 0 stevel " self->rwblock[arg0] = timestamp;\n" 171 0 stevel "}\n" 172 0 stevel "plockstat$target:::mutex-block\n" 173 0 stevel "{\n" 174 0 stevel " self->mtxblock[arg0] = timestamp;\n" 175 0 stevel "}\n" 176 0 stevel "plockstat$target:::mutex-spin\n" 177 0 stevel "{\n" 178 0 stevel " self->mtxspin[arg0] = timestamp;\n" 179 0 stevel "}\n"; 180 0 stevel 181 0 stevel static const char *g_ctnd_histogram = 182 0 stevel "plockstat$target:::rw-blocked\n" 183 0 stevel "/self->rwblock[arg0] && arg1 == 1 && arg2 != 0/\n" 184 0 stevel "{\n" 185 0 stevel " @rw_w_block[arg0, ustack()] =\n" 186 0 stevel " quantize(timestamp - self->rwblock[arg0]);\n" 187 0 stevel " self->rwblock[arg0] = 0;\n" 188 1464 ahl " rw_w_block_found = 1;\n" 189 0 stevel "}\n" 190 0 stevel "plockstat$target:::rw-blocked\n" 191 0 stevel "/self->rwblock[arg0] && arg2 != 0/\n" 192 0 stevel "{\n" 193 0 stevel " @rw_r_block[arg0, ustack()] =\n" 194 0 stevel " quantize(timestamp - self->rwblock[arg0]);\n" 195 0 stevel " self->rwblock[arg0] = 0;\n" 196 1464 ahl " rw_r_block_found = 1;\n" 197 0 stevel "}\n" 198 0 stevel "plockstat$target:::rw-blocked\n" 199 0 stevel "/self->rwblock[arg0]/\n" 200 0 stevel "{\n" 201 0 stevel " self->rwblock[arg0] = 0;\n" 202 0 stevel "}\n" 203 0 stevel "plockstat$target:::mutex-spun\n" 204 0 stevel "/self->mtxspin[arg0] && arg1 != 0/\n" 205 0 stevel "{\n" 206 0 stevel " @mtx_spin[arg0, ustack()] =\n" 207 0 stevel " quantize(timestamp - self->mtxspin[arg0]);\n" 208 0 stevel " self->mtxspin[arg0] = 0;\n" 209 1464 ahl " mtx_spin_found = 1;\n" 210 0 stevel "}\n" 211 0 stevel "plockstat$target:::mutex-spun\n" 212 0 stevel "/self->mtxspin[arg0]/\n" 213 0 stevel "{\n" 214 0 stevel " @mtx_vain_spin[arg0, ustack()] =\n" 215 0 stevel " quantize(timestamp - self->mtxspin[arg0]);\n" 216 0 stevel " self->mtxspin[arg0] = 0;\n" 217 1464 ahl " mtx_vain_spin_found = 1;\n" 218 0 stevel "}\n" 219 0 stevel "plockstat$target:::mutex-blocked\n" 220 0 stevel "/self->mtxblock[arg0] && arg1 != 0/\n" 221 0 stevel "{\n" 222 0 stevel " @mtx_block[arg0, ustack()] =\n" 223 0 stevel " quantize(timestamp - self->mtxblock[arg0]);\n" 224 0 stevel " self->mtxblock[arg0] = 0;\n" 225 1464 ahl " mtx_block_found = 1;\n" 226 0 stevel "}\n" 227 0 stevel "plockstat$target:::mutex-blocked\n" 228 0 stevel "/self->mtxblock[arg0]/\n" 229 0 stevel "{\n" 230 0 stevel " self->mtxblock[arg0] = 0;\n" 231 1464 ahl "}\n" 232 1464 ahl "\n" 233 1464 ahl "END\n" 234 1464 ahl "/mtx_block_found/\n" 235 1464 ahl "{\n" 236 1464 ahl " trace(\"Mutex block\");\n" 237 1464 ahl " printa(@mtx_block);\n" 238 1464 ahl "}\n" 239 1464 ahl "END\n" 240 1464 ahl "/mtx_spin_found/\n" 241 1464 ahl "{\n" 242 1464 ahl " trace(\"Mutex spin\");\n" 243 1464 ahl " printa(@mtx_spin);\n" 244 1464 ahl "}\n" 245 1464 ahl "END\n" 246 1464 ahl "/mtx_vain_spin_found/\n" 247 1464 ahl "{\n" 248 1464 ahl " trace(\"Mutex unsuccessful spin\");\n" 249 1464 ahl " printa(@mtx_vain_spin);\n" 250 1464 ahl "}\n" 251 1464 ahl "END\n" 252 1464 ahl "/rw_r_block_found/\n" 253 1464 ahl "{\n" 254 1464 ahl " trace(\"R/W reader block\");\n" 255 1464 ahl " printa(@rw_r_block);\n" 256 1464 ahl "}\n" 257 1464 ahl "END\n" 258 1464 ahl "/rw_w_block_found/\n" 259 1464 ahl "{\n" 260 1464 ahl " trace(\"R/W writer block\");\n" 261 1464 ahl " printa(@rw_w_block);\n" 262 0 stevel "}\n"; 263 0 stevel 264 0 stevel 265 0 stevel static const char *g_ctnd_times = 266 0 stevel "plockstat$target:::rw-blocked\n" 267 0 stevel "/self->rwblock[arg0] && arg1 == 1 && arg2 != 0/\n" 268 0 stevel "{\n" 269 0 stevel " @rw_w_block[arg0, ustack(5)] =\n" 270 1464 ahl " sum(timestamp - self->rwblock[arg0]);\n" 271 1464 ahl " @rw_w_block_count[arg0, ustack(5)] = count();\n" 272 0 stevel " self->rwblock[arg0] = 0;\n" 273 1464 ahl " rw_w_block_found = 1;\n" 274 0 stevel "}\n" 275 0 stevel "plockstat$target:::rw-blocked\n" 276 0 stevel "/self->rwblock[arg0] && arg2 != 0/\n" 277 0 stevel "{\n" 278 0 stevel " @rw_r_block[arg0, ustack(5)] =\n" 279 1464 ahl " sum(timestamp - self->rwblock[arg0]);\n" 280 1464 ahl " @rw_r_block_count[arg0, ustack(5)] = count();\n" 281 0 stevel " self->rwblock[arg0] = 0;\n" 282 1464 ahl " rw_r_block_found = 1;\n" 283 0 stevel "}\n" 284 0 stevel "plockstat$target:::rw-blocked\n" 285 0 stevel "/self->rwblock[arg0]/\n" 286 0 stevel "{\n" 287 0 stevel " self->rwblock[arg0] = 0;\n" 288 0 stevel "}\n" 289 0 stevel "plockstat$target:::mutex-spun\n" 290 0 stevel "/self->mtxspin[arg0] && arg1 != 0/\n" 291 0 stevel "{\n" 292 0 stevel " @mtx_spin[arg0, ustack(5)] =\n" 293 1464 ahl " sum(timestamp - self->mtxspin[arg0]);\n" 294 1464 ahl " @mtx_spin_count[arg0, ustack(5)] = count();\n" 295 0 stevel " self->mtxspin[arg0] = 0;\n" 296 1464 ahl " mtx_spin_found = 1;\n" 297 0 stevel "}\n" 298 0 stevel "plockstat$target:::mutex-spun\n" 299 0 stevel "/self->mtxspin[arg0]/\n" 300 0 stevel "{\n" 301 0 stevel " @mtx_vain_spin[arg0, ustack(5)] =\n" 302 1464 ahl " sum(timestamp - self->mtxspin[arg0]);\n" 303 1464 ahl " @mtx_vain_spin_count[arg0, ustack(5)] = count();\n" 304 0 stevel " self->mtxspin[arg0] = 0;\n" 305 1464 ahl " mtx_vain_spin_found = 1;\n" 306 0 stevel "}\n" 307 0 stevel "plockstat$target:::mutex-blocked\n" 308 0 stevel "/self->mtxblock[arg0] && arg1 != 0/\n" 309 0 stevel "{\n" 310 0 stevel " @mtx_block[arg0, ustack(5)] =\n" 311 1464 ahl " sum(timestamp - self->mtxblock[arg0]);\n" 312 1464 ahl " @mtx_block_count[arg0, ustack(5)] = count();\n" 313 0 stevel " self->mtxblock[arg0] = 0;\n" 314 1464 ahl " mtx_block_found = 1;\n" 315 0 stevel "}\n" 316 0 stevel "plockstat$target:::mutex-blocked\n" 317 0 stevel "/self->mtxblock[arg0]/\n" 318 0 stevel "{\n" 319 0 stevel " self->mtxblock[arg0] = 0;\n" 320 1464 ahl "}\n" 321 1464 ahl "\n" 322 1464 ahl "END\n" 323 1464 ahl "/mtx_block_found/\n" 324 1464 ahl "{\n" 325 1464 ahl " trace(\"Mutex block\");\n" 326 1464 ahl " printa(@mtx_block, @mtx_block_count);\n" 327 1464 ahl "}\n" 328 1464 ahl "END\n" 329 1464 ahl "/mtx_spin_found/\n" 330 1464 ahl "{\n" 331 1464 ahl " trace(\"Mutex spin\");\n" 332 1464 ahl " printa(@mtx_spin, @mtx_spin_count);\n" 333 1464 ahl "}\n" 334 1464 ahl "END\n" 335 1464 ahl "/mtx_vain_spin_found/\n" 336 1464 ahl "{\n" 337 1464 ahl " trace(\"Mutex unsuccessful spin\");\n" 338 1464 ahl " printa(@mtx_vain_spin, @mtx_vain_spin_count);\n" 339 1464 ahl "}\n" 340 1464 ahl "END\n" 341 1464 ahl "/rw_r_block_found/\n" 342 1464 ahl "{\n" 343 1464 ahl " trace(\"R/W reader block\");\n" 344 1464 ahl " printa(@rw_r_block, @rw_r_block_count);\n" 345 1464 ahl "}\n" 346 1464 ahl "END\n" 347 1464 ahl "/rw_w_block_found/\n" 348 1464 ahl "{\n" 349 1464 ahl " trace(\"R/W writer block\");\n" 350 1464 ahl " printa(@rw_w_block, @rw_w_block_count);\n" 351 0 stevel "}\n"; 352 0 stevel 353 1464 ahl static char g_prog[4096]; 354 0 stevel static size_t g_proglen; 355 0 stevel static int g_opt_V, g_opt_s; 356 0 stevel static int g_intr; 357 1464 ahl static int g_exited; 358 0 stevel static dtrace_optval_t g_nframes; 359 0 stevel static ulong_t g_nent = ULONG_MAX; 360 0 stevel 361 0 stevel #define PLOCKSTAT_OPTSTR "n:ps:e:vx:ACHV" 362 0 stevel 363 0 stevel static void 364 0 stevel usage(void) 365 0 stevel { 366 0 stevel (void) fprintf(stderr, "Usage:\n" 367 0 stevel "\t%s [-vACHV] [-n count] [-s depth] [-e secs] [-x opt[=val]]\n" 368 0 stevel "\t command [arg...]\n" 369 0 stevel "\t%s [-vACHV] [-n count] [-s depth] [-e secs] [-x opt[=val]]\n" 370 0 stevel "\t -p pid\n", g_pname, g_pname); 371 0 stevel 372 0 stevel exit(E_USAGE); 373 0 stevel } 374 0 stevel 375 0 stevel static void 376 0 stevel verror(const char *fmt, va_list ap) 377 0 stevel { 378 0 stevel int error = errno; 379 0 stevel 380 0 stevel (void) fprintf(stderr, "%s: ", g_pname); 381 0 stevel (void) vfprintf(stderr, fmt, ap); 382 0 stevel 383 0 stevel if (fmt[strlen(fmt) - 1] != '\n') 384 0 stevel (void) fprintf(stderr, ": %s\n", strerror(error)); 385 0 stevel } 386 0 stevel 387 0 stevel /*PRINTFLIKE1*/ 388 0 stevel static void 389 0 stevel fatal(const char *fmt, ...) 390 0 stevel { 391 0 stevel va_list ap; 392 0 stevel 393 0 stevel va_start(ap, fmt); 394 0 stevel verror(fmt, ap); 395 0 stevel va_end(ap); 396 0 stevel 397 0 stevel if (g_pr != NULL && g_dtp != NULL) 398 0 stevel dtrace_proc_release(g_dtp, g_pr); 399 0 stevel 400 0 stevel exit(E_ERROR); 401 0 stevel } 402 0 stevel 403 0 stevel /*PRINTFLIKE1*/ 404 0 stevel static void 405 0 stevel dfatal(const char *fmt, ...) 406 0 stevel { 407 0 stevel va_list ap; 408 0 stevel 409 0 stevel va_start(ap, fmt); 410 0 stevel 411 0 stevel (void) fprintf(stderr, "%s: ", g_pname); 412 0 stevel if (fmt != NULL) 413 0 stevel (void) vfprintf(stderr, fmt, ap); 414 0 stevel 415 0 stevel va_end(ap); 416 0 stevel 417 0 stevel if (fmt != NULL && fmt[strlen(fmt) - 1] != '\n') { 418 0 stevel (void) fprintf(stderr, ": %s\n", 419 0 stevel dtrace_errmsg(g_dtp, dtrace_errno(g_dtp))); 420 0 stevel } else if (fmt == NULL) { 421 0 stevel (void) fprintf(stderr, "%s\n", 422 0 stevel dtrace_errmsg(g_dtp, dtrace_errno(g_dtp))); 423 0 stevel } 424 0 stevel 425 0 stevel if (g_pr != NULL) { 426 0 stevel dtrace_proc_continue(g_dtp, g_pr); 427 0 stevel dtrace_proc_release(g_dtp, g_pr); 428 0 stevel } 429 0 stevel 430 0 stevel exit(E_ERROR); 431 0 stevel } 432 0 stevel 433 0 stevel /*PRINTFLIKE1*/ 434 0 stevel static void 435 0 stevel notice(const char *fmt, ...) 436 0 stevel { 437 0 stevel va_list ap; 438 0 stevel 439 0 stevel va_start(ap, fmt); 440 0 stevel verror(fmt, ap); 441 0 stevel va_end(ap); 442 0 stevel } 443 0 stevel 444 0 stevel static void 445 0 stevel dprog_add(const char *prog) 446 0 stevel { 447 0 stevel size_t len = strlen(prog); 448 0 stevel bcopy(prog, g_prog + g_proglen, len + 1); 449 0 stevel g_proglen += len; 450 1464 ahl assert(g_proglen < sizeof (g_prog)); 451 0 stevel } 452 0 stevel 453 0 stevel static void 454 0 stevel dprog_compile(void) 455 0 stevel { 456 0 stevel dtrace_prog_t *prog; 457 0 stevel dtrace_proginfo_t info; 458 0 stevel 459 0 stevel if (g_opt_V) { 460 0 stevel (void) fprintf(stderr, "%s: vvvv D program vvvv\n", g_pname); 461 0 stevel (void) fputs(g_prog, stderr); 462 0 stevel (void) fprintf(stderr, "%s: ^^^^ D program ^^^^\n", g_pname); 463 0 stevel } 464 0 stevel 465 0 stevel if ((prog = dtrace_program_strcompile(g_dtp, g_prog, 466 0 stevel DTRACE_PROBESPEC_NAME, 0, 0, NULL)) == NULL) 467 0 stevel dfatal("failed to compile program"); 468 0 stevel 469 0 stevel if (dtrace_program_exec(g_dtp, prog, &info) == -1) 470 0 stevel dfatal("failed to enable probes"); 471 0 stevel } 472 0 stevel 473 0 stevel void 474 0 stevel print_legend(void) 475 0 stevel { 476 0 stevel (void) printf("%5s %8s %-28s %s\n", "Count", "nsec", "Lock", "Caller"); 477 0 stevel } 478 0 stevel 479 0 stevel void 480 0 stevel print_bar(void) 481 0 stevel { 482 0 stevel (void) printf("---------------------------------------" 483 0 stevel "----------------------------------------\n"); 484 0 stevel } 485 0 stevel 486 0 stevel void 487 0 stevel print_histogram_header(void) 488 0 stevel { 489 0 stevel (void) printf("\n%10s ---- Time Distribution --- %5s %s\n", 490 0 stevel "nsec", "count", "Stack"); 491 0 stevel } 492 0 stevel 493 0 stevel /* 494 0 stevel * Convert an address to a symbolic string or a numeric string. If nolocks 495 0 stevel * is set, we return an error code if this symbol appears to be a mutex- or 496 0 stevel * rwlock-related symbol in libc so the caller has a chance to find a more 497 0 stevel * helpful symbol. 498 0 stevel */ 499 0 stevel static int 500 0 stevel getsym(struct ps_prochandle *P, uintptr_t addr, char *buf, size_t size, 501 0 stevel int nolocks) 502 0 stevel { 503 0 stevel char name[256]; 504 0 stevel GElf_Sym sym; 505 0 stevel prsyminfo_t info; 506 0 stevel size_t len; 507 0 stevel 508 0 stevel if (P == NULL || Pxlookup_by_addr(P, addr, name, sizeof (name), 509 0 stevel &sym, &info) != 0) { 510 0 stevel (void) snprintf(buf, size, "%#lx", addr); 511 0 stevel return (0); 512 0 stevel } 513 2915 rh87107 if (info.prs_object == NULL) 514 2915 rh87107 info.prs_object = "<unknown>"; 515 0 stevel 516 0 stevel if (info.prs_lmid != LM_ID_BASE) { 517 0 stevel len = snprintf(buf, size, "LM%lu`", info.prs_lmid); 518 0 stevel buf += len; 519 0 stevel size -= len; 520 0 stevel } 521 0 stevel 522 0 stevel len = snprintf(buf, size, "%s`%s", info.prs_object, info.prs_name); 523 0 stevel buf += len; 524 0 stevel size -= len; 525 0 stevel 526 0 stevel if (sym.st_value != addr) 527 0 stevel len = snprintf(buf, size, "+%#lx", addr - sym.st_value); 528 0 stevel 529 0 stevel if (nolocks && strcmp("libc.so.1", info.prs_object) == 0 && 530 0 stevel (strstr("mutex", info.prs_name) == 0 || 531 0 stevel strstr("rw", info.prs_name) == 0)) 532 0 stevel return (-1); 533 0 stevel 534 0 stevel return (0); 535 0 stevel } 536 0 stevel 537 0 stevel /*ARGSUSED*/ 538 0 stevel static int 539 1464 ahl process_aggregate(const dtrace_aggdata_t **aggsdata, int naggvars, void *arg) 540 0 stevel { 541 457 bmc const dtrace_recdesc_t *rec; 542 1464 ahl uintptr_t lock; 543 1464 ahl uint64_t *stack; 544 1464 ahl caddr_t data; 545 1464 ahl pid_t pid; 546 1464 ahl struct ps_prochandle *P; 547 191 ahl char buf[256]; 548 0 stevel int i, j; 549 1464 ahl uint64_t sum, count, avg; 550 0 stevel 551 1464 ahl if ((*(uint_t *)arg)++ >= g_nent) 552 1464 ahl return (DTRACE_AGGWALK_NEXT); 553 0 stevel 554 1464 ahl rec = aggsdata[0]->dtada_desc->dtagd_rec; 555 1464 ahl data = aggsdata[0]->dtada_data; 556 0 stevel 557 0 stevel /*LINTED - alignment*/ 558 0 stevel lock = (uintptr_t)*(uint64_t *)(data + rec[1].dtrd_offset); 559 0 stevel /*LINTED - alignment*/ 560 0 stevel stack = (uint64_t *)(data + rec[2].dtrd_offset); 561 0 stevel 562 0 stevel if (!g_opt_s) { 563 1464 ahl /*LINTED - alignment*/ 564 1464 ahl sum = *(uint64_t *)(aggsdata[1]->dtada_data + 565 1464 ahl aggsdata[1]->dtada_desc->dtagd_rec[3].dtrd_offset); 566 1464 ahl /*LINTED - alignment*/ 567 1464 ahl count = *(uint64_t *)(aggsdata[2]->dtada_data + 568 1464 ahl aggsdata[2]->dtada_desc->dtagd_rec[3].dtrd_offset); 569 1464 ahl } else { 570 1464 ahl uint64_t *a; 571 0 stevel 572 1464 ahl /*LINTED - alignment*/ 573 1464 ahl a = (uint64_t *)(aggsdata[1]->dtada_data + 574 1464 ahl aggsdata[1]->dtada_desc->dtagd_rec[3].dtrd_offset); 575 1464 ahl 576 0 stevel print_bar(); 577 0 stevel print_legend(); 578 0 stevel 579 1464 ahl for (count = sum = 0, i = DTRACE_QUANTIZE_ZEROBUCKET, j = 0; 580 0 stevel i < DTRACE_QUANTIZE_NBUCKETS; i++, j++) { 581 0 stevel count += a[i]; 582 1464 ahl sum += a[i] << (j - 64); 583 0 stevel } 584 0 stevel } 585 0 stevel 586 1464 ahl avg = sum / count; 587 0 stevel (void) printf("%5llu %8llu ", (u_longlong_t)count, (u_longlong_t)avg); 588 0 stevel 589 0 stevel pid = stack[0]; 590 0 stevel P = dtrace_proc_grab(g_dtp, pid, PGRAB_RDONLY); 591 0 stevel 592 0 stevel (void) getsym(P, lock, buf, sizeof (buf), 0); 593 0 stevel (void) printf("%-28s ", buf); 594 0 stevel 595 0 stevel for (i = 2; i <= 5; i++) { 596 0 stevel if (getsym(P, stack[i], buf, sizeof (buf), 1) == 0) 597 0 stevel break; 598 0 stevel } 599 0 stevel (void) printf("%s\n", buf); 600 0 stevel 601 0 stevel if (g_opt_s) { 602 0 stevel int stack_done = 0; 603 0 stevel int quant_done = 0; 604 0 stevel int first_bin, last_bin; 605 1464 ahl uint64_t bin_size, *a; 606 1464 ahl 607 1464 ahl /*LINTED - alignment*/ 608 1464 ahl a = (uint64_t *)(aggsdata[1]->dtada_data + 609 1464 ahl aggsdata[1]->dtada_desc->dtagd_rec[3].dtrd_offset); 610 0 stevel 611 0 stevel print_histogram_header(); 612 0 stevel 613 0 stevel for (first_bin = DTRACE_QUANTIZE_ZEROBUCKET; 614 0 stevel a[first_bin] == 0; first_bin++) 615 0 stevel continue; 616 0 stevel for (last_bin = DTRACE_QUANTIZE_ZEROBUCKET + 63; 617 0 stevel a[last_bin] == 0; last_bin--) 618 0 stevel continue; 619 0 stevel 620 0 stevel for (i = 0; !stack_done || !quant_done; i++) { 621 0 stevel if (!stack_done) { 622 0 stevel (void) getsym(P, stack[i + 2], buf, 623 0 stevel sizeof (buf), 0); 624 0 stevel } else { 625 0 stevel buf[0] = '\0'; 626 0 stevel } 627 0 stevel 628 0 stevel if (!quant_done) { 629 0 stevel bin_size = a[first_bin]; 630 0 stevel 631 0 stevel (void) printf("%10llu |%-24.*s| %5llu %s\n", 632 0 stevel 1ULL << 633 0 stevel (first_bin - DTRACE_QUANTIZE_ZEROBUCKET), 634 0 stevel (int)(24.0 * bin_size / count), 635 0 stevel "@@@@@@@@@@@@@@@@@@@@@@@@@@", 636 0 stevel (u_longlong_t)bin_size, buf); 637 0 stevel } else { 638 0 stevel (void) printf("%43s %s\n", "", buf); 639 0 stevel } 640 0 stevel 641 0 stevel if (i + 1 >= g_nframes || stack[i + 3] == 0) 642 0 stevel stack_done = 1; 643 0 stevel 644 0 stevel if (first_bin++ == last_bin) 645 0 stevel quant_done = 1; 646 0 stevel } 647 0 stevel } 648 0 stevel 649 0 stevel dtrace_proc_release(g_dtp, P); 650 0 stevel 651 0 stevel return (DTRACE_AGGWALK_NEXT); 652 0 stevel } 653 0 stevel 654 1464 ahl /*ARGSUSED*/ 655 1464 ahl static void 656 1464 ahl prochandler(struct ps_prochandle *P, const char *msg, void *arg) 657 0 stevel { 658 0 stevel const psinfo_t *prp = Ppsinfo(P); 659 0 stevel int pid = Pstatus(P)->pr_pid; 660 0 stevel char name[SIG2STR_MAX]; 661 1464 ahl 662 1464 ahl if (msg != NULL) { 663 1464 ahl notice("pid %d: %s\n", pid, msg); 664 1464 ahl return; 665 1464 ahl } 666 0 stevel 667 0 stevel switch (Pstate(P)) { 668 0 stevel case PS_UNDEAD: 669 0 stevel /* 670 0 stevel * Ideally we would like to always report pr_wstat here, but it 671 0 stevel * isn't possible given current /proc semantics. If we grabbed 672 0 stevel * the process, Ppsinfo() will either fail or return a zeroed 673 0 stevel * psinfo_t depending on how far the parent is in reaping it. 674 0 stevel * When /proc provides a stable pr_wstat in the status file, 675 0 stevel * this code can be improved by examining this new pr_wstat. 676 0 stevel */ 677 0 stevel if (prp != NULL && WIFSIGNALED(prp->pr_wstat)) { 678 0 stevel notice("pid %d terminated by %s\n", pid, 679 0 stevel proc_signame(WTERMSIG(prp->pr_wstat), 680 0 stevel name, sizeof (name))); 681 0 stevel } else if (prp != NULL && WEXITSTATUS(prp->pr_wstat) != 0) { 682 0 stevel notice("pid %d exited with status %d\n", 683 0 stevel pid, WEXITSTATUS(prp->pr_wstat)); 684 0 stevel } else { 685 0 stevel notice("pid %d has exited\n", pid); 686 0 stevel } 687 1464 ahl g_exited = 1; 688 1464 ahl break; 689 0 stevel 690 0 stevel case PS_LOST: 691 0 stevel notice("pid %d exec'd a set-id or unobservable program\n", pid); 692 1464 ahl g_exited = 1; 693 1464 ahl break; 694 1464 ahl } 695 1464 ahl } 696 1464 ahl 697 1464 ahl /*ARGSUSED*/ 698 1464 ahl static int 699 1464 ahl chewrec(const dtrace_probedata_t *data, const dtrace_recdesc_t *rec, void *arg) 700 1464 ahl { 701 1464 ahl dtrace_eprobedesc_t *epd = data->dtpda_edesc; 702 1464 ahl dtrace_aggvarid_t aggvars[2]; 703 1464 ahl const void *buf; 704 1464 ahl int i, nagv; 705 1464 ahl 706 1464 ahl /* 707 1464 ahl * A NULL rec indicates that we've processed the last record. 708 1464 ahl */ 709 1464 ahl if (rec == NULL) 710 1464 ahl return (DTRACE_CONSUME_NEXT); 711 1464 ahl 712 1464 ahl buf = data->dtpda_data - rec->dtrd_offset; 713 1464 ahl 714 1464 ahl switch (rec->dtrd_action) { 715 1464 ahl case DTRACEACT_DIFEXPR: 716 1464 ahl (void) printf("\n%s\n\n", (char *)buf + rec->dtrd_offset); 717 1464 ahl if (!g_opt_s) { 718 1464 ahl print_legend(); 719 1464 ahl print_bar(); 720 1464 ahl } 721 1464 ahl return (DTRACE_CONSUME_NEXT); 722 1464 ahl 723 1464 ahl case DTRACEACT_PRINTA: 724 1464 ahl for (nagv = 0, i = 0; i < epd->dtepd_nrecs - 1; i++) { 725 1464 ahl const dtrace_recdesc_t *nrec = &rec[i]; 726 1464 ahl 727 1464 ahl if (nrec->dtrd_uarg != rec->dtrd_uarg) 728 1464 ahl break; 729 1464 ahl 730 1464 ahl /*LINTED - alignment*/ 731 1464 ahl aggvars[nagv++] = *(dtrace_aggvarid_t *)((caddr_t)buf + 732 1464 ahl nrec->dtrd_offset); 733 1464 ahl } 734 1464 ahl 735 1464 ahl if (nagv == (g_opt_s ? 1 : 2)) { 736 1464 ahl uint_t nent = 0; 737 1464 ahl if (dtrace_aggregate_walk_joined(g_dtp, aggvars, nagv, 738 1464 ahl process_aggregate, &nent) != 0) 739 1464 ahl dfatal("failed to walk aggregate"); 740 1464 ahl } 741 1464 ahl 742 1464 ahl return (DTRACE_CONSUME_NEXT); 743 0 stevel } 744 0 stevel 745 1464 ahl return (DTRACE_CONSUME_THIS); 746 0 stevel } 747 0 stevel 748 0 stevel /*ARGSUSED*/ 749 0 stevel static void 750 0 stevel intr(int signo) 751 0 stevel { 752 0 stevel g_intr = 1; 753 0 stevel } 754 0 stevel 755 0 stevel int 756 0 stevel main(int argc, char **argv) 757 0 stevel { 758 0 stevel ucred_t *ucp; 759 0 stevel int err; 760 0 stevel int opt_C = 0, opt_H = 0, opt_p = 0, opt_v = 0; 761 0 stevel char c, *p, *end; 762 0 stevel struct sigaction act; 763 0 stevel int done = 0; 764 0 stevel 765 1464 ahl g_pname = basename(argv[0]); 766 1464 ahl argv[0] = g_pname; /* rewrite argv[0] for getopt errors */ 767 0 stevel 768 0 stevel /* 769 0 stevel * Make sure we have the required dtrace_proc privilege. 770 0 stevel */ 771 0 stevel if ((ucp = ucred_get(getpid())) != NULL) { 772 0 stevel const priv_set_t *psp; 773 0 stevel if ((psp = ucred_getprivset(ucp, PRIV_EFFECTIVE)) != NULL && 774 0 stevel !priv_ismember(psp, PRIV_DTRACE_PROC)) { 775 0 stevel fatal("dtrace_proc privilege required\n"); 776 0 stevel } 777 0 stevel 778 0 stevel ucred_free(ucp); 779 0 stevel } 780 0 stevel 781 0 stevel while ((c = getopt(argc, argv, PLOCKSTAT_OPTSTR)) != EOF) { 782 0 stevel switch (c) { 783 0 stevel case 'n': 784 0 stevel errno = 0; 785 0 stevel g_nent = strtoul(optarg, &end, 10); 786 0 stevel if (*end != '\0' || errno != 0) { 787 0 stevel (void) fprintf(stderr, "%s: invalid count " 788 0 stevel "'%s'\n", g_pname, optarg); 789 0 stevel usage(); 790 0 stevel } 791 0 stevel break; 792 0 stevel 793 0 stevel case 'p': 794 0 stevel opt_p = 1; 795 0 stevel break; 796 0 stevel 797 0 stevel case 'v': 798 0 stevel opt_v = 1; 799 0 stevel break; 800 0 stevel 801 0 stevel case 'A': 802 0 stevel opt_C = opt_H = 1; 803 0 stevel break; 804 0 stevel 805 0 stevel case 'C': 806 0 stevel opt_C = 1; 807 0 stevel break; 808 0 stevel 809 0 stevel case 'H': 810 0 stevel opt_H = 1; 811 0 stevel break; 812 0 stevel 813 0 stevel case 'V': 814 0 stevel g_opt_V = 1; 815 0 stevel break; 816 0 stevel 817 0 stevel default: 818 0 stevel if (strchr(PLOCKSTAT_OPTSTR, c) == NULL) 819 0 stevel usage(); 820 0 stevel } 821 0 stevel } 822 0 stevel 823 0 stevel /* 824 0 stevel * We need a command or at least one pid. 825 0 stevel */ 826 0 stevel if (argc == optind) 827 0 stevel usage(); 828 0 stevel 829 0 stevel if (opt_C == 0 && opt_H == 0) 830 0 stevel opt_C = 1; 831 0 stevel 832 0 stevel if ((g_dtp = dtrace_open(DTRACE_VERSION, 0, &err)) == NULL) 833 0 stevel fatal("failed to initialize dtrace: %s\n", 834 0 stevel dtrace_errmsg(NULL, err)); 835 0 stevel 836 1464 ahl /* 837 1464 ahl * The longest string we trace is 23 bytes long -- so 32 is plenty. 838 1464 ahl */ 839 1464 ahl if (dtrace_setopt(g_dtp, "strsize", "32") == -1) 840 1464 ahl dfatal("failed to set 'strsize'"); 841 1464 ahl 842 1464 ahl /* 843 1464 ahl * 1k should be more than enough for all trace() and printa() actions. 844 1464 ahl */ 845 1464 ahl if (dtrace_setopt(g_dtp, "bufsize", "1k") == -1) 846 1464 ahl dfatal("failed to set 'bufsize'"); 847 1464 ahl 848 1464 ahl /* 849 1464 ahl * The table we produce has the hottest locks at the top. 850 1464 ahl */ 851 1464 ahl if (dtrace_setopt(g_dtp, "aggsortrev", NULL) == -1) 852 1464 ahl dfatal("failed to set 'aggsortrev'"); 853 1464 ahl 854 1464 ahl /* 855 1464 ahl * These are two reasonable defaults which should suffice. 856 1464 ahl */ 857 0 stevel if (dtrace_setopt(g_dtp, "aggsize", "256k") == -1) 858 0 stevel dfatal("failed to set 'aggsize'"); 859 0 stevel if (dtrace_setopt(g_dtp, "aggrate", "1sec") == -1) 860 0 stevel dfatal("failed to set 'aggrate'"); 861 0 stevel 862 0 stevel /* 863 0 stevel * Take a second pass through to look for options that set options now 864 0 stevel * that we have an open dtrace handle. 865 0 stevel */ 866 0 stevel optind = 1; 867 0 stevel while ((c = getopt(argc, argv, PLOCKSTAT_OPTSTR)) != EOF) { 868 0 stevel switch (c) { 869 0 stevel case 's': 870 0 stevel g_opt_s = 1; 871 0 stevel if (dtrace_setopt(g_dtp, "ustackframes", optarg) == -1) 872 0 stevel dfatal("failed to set 'ustackframes'"); 873 0 stevel break; 874 0 stevel 875 0 stevel case 'x': 876 0 stevel if ((p = strchr(optarg, '=')) != NULL) 877 0 stevel *p++ = '\0'; 878 0 stevel 879 0 stevel if (dtrace_setopt(g_dtp, optarg, p) != 0) 880 0 stevel dfatal("failed to set -x %s", optarg); 881 0 stevel break; 882 0 stevel 883 0 stevel case 'e': 884 0 stevel errno = 0; 885 0 stevel (void) strtoul(optarg, &end, 10); 886 0 stevel if (*optarg == '-' || *end != '\0' || errno != 0) { 887 0 stevel (void) fprintf(stderr, "%s: invalid timeout " 888 0 stevel "'%s'\n", g_pname, optarg); 889 0 stevel usage(); 890 0 stevel } 891 0 stevel 892 0 stevel /* 893 0 stevel * Construct a DTrace enabling that will exit after 894 0 stevel * the specified number of seconds. 895 0 stevel */ 896 0 stevel dprog_add("BEGIN\n{\n\tend = timestamp + "); 897 0 stevel dprog_add(optarg); 898 0 stevel dprog_add(" * 1000000000;\n}\n"); 899 0 stevel dprog_add("tick-10hz\n/timestamp >= end/\n"); 900 0 stevel dprog_add("{\n\texit(0);\n}\n"); 901 0 stevel break; 902 0 stevel } 903 0 stevel } 904 0 stevel 905 0 stevel argc -= optind; 906 0 stevel argv += optind; 907 0 stevel 908 0 stevel if (opt_H) { 909 0 stevel dprog_add(g_hold_init); 910 0 stevel if (g_opt_s == NULL) 911 0 stevel dprog_add(g_hold_times); 912 0 stevel else 913 0 stevel dprog_add(g_hold_histogram); 914 0 stevel } 915 0 stevel 916 0 stevel if (opt_C) { 917 0 stevel dprog_add(g_ctnd_init); 918 0 stevel if (g_opt_s == NULL) 919 0 stevel dprog_add(g_ctnd_times); 920 0 stevel else 921 0 stevel dprog_add(g_ctnd_histogram); 922 0 stevel } 923 0 stevel 924 0 stevel if (opt_p) { 925 0 stevel ulong_t pid; 926 0 stevel 927 0 stevel if (argc > 1) { 928 0 stevel (void) fprintf(stderr, "%s: only one pid is allowed\n", 929 0 stevel g_pname); 930 0 stevel usage(); 931 0 stevel } 932 0 stevel 933 0 stevel errno = 0; 934 0 stevel pid = strtoul(argv[0], &end, 10); 935 0 stevel if (*end != '\0' || errno != 0 || (pid_t)pid != pid) { 936 0 stevel (void) fprintf(stderr, "%s: invalid pid '%s'\n", 937 0 stevel g_pname, argv[0]); 938 0 stevel usage(); 939 0 stevel } 940 0 stevel 941 0 stevel if ((g_pr = dtrace_proc_grab(g_dtp, (pid_t)pid, 0)) == NULL) 942 0 stevel dfatal(NULL); 943 0 stevel } else { 944 0 stevel if ((g_pr = dtrace_proc_create(g_dtp, argv[0], argv)) == NULL) 945 0 stevel dfatal(NULL); 946 0 stevel } 947 0 stevel 948 0 stevel dprog_compile(); 949 0 stevel 950 1464 ahl if (dtrace_handle_proc(g_dtp, &prochandler, NULL) == -1) 951 1464 ahl dfatal("failed to establish proc handler"); 952 1464 ahl 953 0 stevel (void) sigemptyset(&act.sa_mask); 954 0 stevel act.sa_flags = 0; 955 0 stevel act.sa_handler = intr; 956 0 stevel (void) sigaction(SIGINT, &act, NULL); 957 0 stevel (void) sigaction(SIGTERM, &act, NULL); 958 0 stevel 959 0 stevel if (dtrace_go(g_dtp) != 0) 960 0 stevel dfatal("dtrace_go()"); 961 0 stevel 962 0 stevel if (dtrace_getopt(g_dtp, "ustackframes", &g_nframes) != 0) 963 0 stevel dfatal("failed to get 'ustackframes'"); 964 0 stevel 965 0 stevel dtrace_proc_continue(g_dtp, g_pr); 966 0 stevel 967 0 stevel if (opt_v) 968 0 stevel (void) printf("%s: tracing enabled for pid %d\n", g_pname, 969 0 stevel (int)Pstatus(g_pr)->pr_pid); 970 0 stevel 971 1464 ahl do { 972 1464 ahl if (!g_intr && !done) 973 1464 ahl dtrace_sleep(g_dtp); 974 0 stevel 975 1464 ahl if (done || g_intr || g_exited) { 976 0 stevel done = 1; 977 1464 ahl if (dtrace_stop(g_dtp) == -1) 978 1464 ahl dfatal("couldn't stop tracing"); 979 1464 ahl } 980 0 stevel 981 1464 ahl switch (dtrace_work(g_dtp, stdout, NULL, chewrec, NULL)) { 982 1464 ahl case DTRACE_WORKSTATUS_DONE: 983 0 stevel done = 1; 984 1464 ahl break; 985 1464 ahl case DTRACE_WORKSTATUS_OKAY: 986 1464 ahl break; 987 1464 ahl default: 988 1464 ahl dfatal("processing aborted"); 989 1464 ahl } 990 0 stevel 991 1464 ahl } while (!done); 992 0 stevel 993 0 stevel dtrace_close(g_dtp); 994 0 stevel 995 0 stevel return (0); 996 0 stevel } 997