1*c29d5175SchristosThe following are examples of pl_calldist.d. 2*c29d5175Schristos 3*c29d5175SchristosThis script traces the elapsed time of Perl subroutines (functions) and 4*c29d5175Schristosprints a report containing distribution plots per subroutine. Here it 5*c29d5175Schristostraces the example program, Code/Perl/func_abc.pl. 6*c29d5175Schristos 7*c29d5175Schristos # pl_calldist.d 8*c29d5175Schristos Tracing... Hit Ctrl-C to end. 9*c29d5175Schristos ^C 10*c29d5175Schristos 11*c29d5175Schristos Exclusive subroutine elapsed times (us), 12*c29d5175Schristos func_abc.pl, sub, func_a 13*c29d5175Schristos value ------------- Distribution ------------- count 14*c29d5175Schristos 262144 | 0 15*c29d5175Schristos 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 16*c29d5175Schristos 1048576 | 0 17*c29d5175Schristos 18*c29d5175Schristos func_abc.pl, sub, func_b 19*c29d5175Schristos value ------------- Distribution ------------- count 20*c29d5175Schristos 262144 | 0 21*c29d5175Schristos 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 22*c29d5175Schristos 1048576 | 0 23*c29d5175Schristos 24*c29d5175Schristos func_abc.pl, sub, func_c 25*c29d5175Schristos value ------------- Distribution ------------- count 26*c29d5175Schristos 262144 | 0 27*c29d5175Schristos 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 28*c29d5175Schristos 1048576 | 0 29*c29d5175Schristos 30*c29d5175Schristos 31*c29d5175Schristos Inclusive subroutine elapsed times (us), 32*c29d5175Schristos func_abc.pl, sub, func_c 33*c29d5175Schristos value ------------- Distribution ------------- count 34*c29d5175Schristos 262144 | 0 35*c29d5175Schristos 524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 36*c29d5175Schristos 1048576 | 0 37*c29d5175Schristos 38*c29d5175Schristos func_abc.pl, sub, func_b 39*c29d5175Schristos value ------------- Distribution ------------- count 40*c29d5175Schristos 524288 | 0 41*c29d5175Schristos 1048576 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 42*c29d5175Schristos 2097152 | 0 43*c29d5175Schristos 44*c29d5175Schristos func_abc.pl, sub, func_a 45*c29d5175Schristos value ------------- Distribution ------------- count 46*c29d5175Schristos 1048576 | 0 47*c29d5175Schristos 2097152 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 48*c29d5175Schristos 4194304 | 0 49*c29d5175Schristos 50*c29d5175SchristosIn total, 3 subroutines were called - func_a(), func_b(), and func_c(). 51*c29d5175Schristos 52*c29d5175SchristosThe exclusive subroutine elapsed times show that each subroutine spent 53*c29d5175Schristosbetween 524 and 1048 ms. This exclusive time excludes the time spent in 54*c29d5175Schristosother subroutines. 55*c29d5175Schristos 56*c29d5175SchristosThe inclusive subroutine elapsed times show that func_c() took between 0.5 and 57*c29d5175Schristos1.0 seconds, func_b() took between 1.0 and 2.1 seconds, and func_a() took 58*c29d5175Schristosbetween 2.1 and 4.2 seconds to execute. This inclusive time includes the 59*c29d5175Schristostime spent in other subroutines called, and since func_a() called func_b() 60*c29d5175Schristoswhich called func_c(), these times make sense. 61*c29d5175Schristos 62*c29d5175SchristosThese elapsed times are the absolute time from when the subroutine began to 63*c29d5175Schristoswhen it completed - which includes off-CPU time due to other system events 64*c29d5175Schristossuch as I/O, scheduling, interrupts, etc. 65*c29d5175Schristos 66*c29d5175SchristosElapsed times are useful for identifying where latencies are. 67*c29d5175SchristosSee Notes/ALLelapsed_notes.txt for more details. Also see 68*c29d5175SchristosNotes/ALLexclusive_notes.txt and Notes/ALLinclusive_notes.txt for a 69*c29d5175Schristosdetailed explanation of exclusive vs inclusive subroutine time. 70*c29d5175Schristos 71*c29d5175Schristos 72*c29d5175Schristos 73*c29d5175SchristosThe following traces a Perl network interface statistics tool, "nicstat" 74*c29d5175Schristosversion 0.99, 75*c29d5175Schristos 76*c29d5175Schristos# pl_calldist.d 77*c29d5175SchristosTracing... Hit Ctrl-C to end. 78*c29d5175Schristos^C 79*c29d5175Schristos 80*c29d5175SchristosExclusive subroutine elapsed times (us), 81*c29d5175Schristos DynaLoader.pm, sub, dl_load_flags 82*c29d5175Schristos value ------------- Distribution ------------- count 83*c29d5175Schristos 1 | 0 84*c29d5175Schristos 2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 85*c29d5175Schristos 4 | 0 86*c29d5175Schristos 87*c29d5175Schristos Config.pm, sub, TIEHASH 88*c29d5175Schristos value ------------- Distribution ------------- count 89*c29d5175Schristos 2 | 0 90*c29d5175Schristos 4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 91*c29d5175Schristos 8 | 0 92*c29d5175Schristos 93*c29d5175Schristos Config.pm, sub, DESTROY 94*c29d5175Schristos value ------------- Distribution ------------- count 95*c29d5175Schristos 4 | 0 96*c29d5175Schristos 8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 97*c29d5175Schristos 16 | 0 98*c29d5175Schristos 99*c29d5175Schristos Config.pm, sub, import 100*c29d5175Schristos value ------------- Distribution ------------- count 101*c29d5175Schristos 4 | 0 102*c29d5175Schristos 8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 103*c29d5175Schristos 16 | 0 104*c29d5175Schristos 105*c29d5175Schristos register.pm, sub, mkMask 106*c29d5175Schristos value ------------- Distribution ------------- count 107*c29d5175Schristos 2 | 0 108*c29d5175Schristos 4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 109*c29d5175Schristos 8 | 0 110*c29d5175Schristos 111*c29d5175Schristos Config.pm, sub, FETCH 112*c29d5175Schristos value ------------- Distribution ------------- count 113*c29d5175Schristos 1 | 0 114*c29d5175Schristos 2 |@@@@@@@@@@@@@@@@@@@@ 2 115*c29d5175Schristos 4 |@@@@@@@@@@@@@@@@@@@@ 2 116*c29d5175Schristos 8 | 0 117*c29d5175Schristos 118*c29d5175Schristos Config.pm, sub, BEGIN 119*c29d5175Schristos value ------------- Distribution ------------- count 120*c29d5175Schristos 4 | 0 121*c29d5175Schristos 8 |@@@@@@@@@@@@@@@@@@@@ 1 122*c29d5175Schristos 16 |@@@@@@@@@@@@@@@@@@@@ 1 123*c29d5175Schristos 32 | 0 124*c29d5175Schristos 125*c29d5175Schristos strict.pm, sub, import 126*c29d5175Schristos value ------------- Distribution ------------- count 127*c29d5175Schristos 1 | 0 128*c29d5175Schristos 2 |@@@@@@@@ 1 129*c29d5175Schristos 4 |@@@@@@@@@@@@@@@@ 2 130*c29d5175Schristos 8 |@@@@@@@@ 1 131*c29d5175Schristos 16 |@@@@@@@@ 1 132*c29d5175Schristos 32 | 0 133*c29d5175Schristos 134*c29d5175Schristos strict.pm, sub, bits 135*c29d5175Schristos value ------------- Distribution ------------- count 136*c29d5175Schristos 2 | 0 137*c29d5175Schristos 4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 4 138*c29d5175Schristos 8 |@@@@@@@ 1 139*c29d5175Schristos 16 |@@@@@@@ 1 140*c29d5175Schristos 32 | 0 141*c29d5175Schristos 142*c29d5175Schristos strict.pm, sub, unimport 143*c29d5175Schristos value ------------- Distribution ------------- count 144*c29d5175Schristos 4 | 0 145*c29d5175Schristos 8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3 146*c29d5175Schristos 16 |@@@@@@@@@@ 1 147*c29d5175Schristos 32 | 0 148*c29d5175Schristos 149*c29d5175Schristos AutoLoader.pm, sub, BEGIN 150*c29d5175Schristos value ------------- Distribution ------------- count 151*c29d5175Schristos 1 | 0 152*c29d5175Schristos 2 |@@@@@@@ 1 153*c29d5175Schristos 4 |@@@@@@@ 1 154*c29d5175Schristos 8 |@@@@@@@@@@@@@@@@@@@@ 3 155*c29d5175Schristos 16 |@@@@@@@ 1 156*c29d5175Schristos 32 | 0 157*c29d5175Schristos 158*c29d5175Schristos Std.pm, sub, getopts 159*c29d5175Schristos value ------------- Distribution ------------- count 160*c29d5175Schristos 32 | 0 161*c29d5175Schristos 64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 162*c29d5175Schristos 128 | 0 163*c29d5175Schristos 164*c29d5175Schristos register.pm, sub, import 165*c29d5175Schristos value ------------- Distribution ------------- count 166*c29d5175Schristos 32 | 0 167*c29d5175Schristos 64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 168*c29d5175Schristos 128 | 0 169*c29d5175Schristos 170*c29d5175Schristos vars.pm, sub, import 171*c29d5175Schristos value ------------- Distribution ------------- count 172*c29d5175Schristos 16 | 0 173*c29d5175Schristos 32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 174*c29d5175Schristos 64 | 0 175*c29d5175Schristos 176*c29d5175Schristos Exporter.pm, sub, import 177*c29d5175Schristos value ------------- Distribution ------------- count 178*c29d5175Schristos 16 | 0 179*c29d5175Schristos 32 |@@@@@@@@@@@@@@@@@@@@ 1 180*c29d5175Schristos 64 |@@@@@@@@@@@@@@@@@@@@ 1 181*c29d5175Schristos 128 | 0 182*c29d5175Schristos 183*c29d5175Schristos DynaLoader.pm, sub, bootstrap 184*c29d5175Schristos value ------------- Distribution ------------- count 185*c29d5175Schristos 256 | 0 186*c29d5175Schristos 512 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 187*c29d5175Schristos 1024 | 0 188*c29d5175Schristos 189*c29d5175Schristos warnings.pm, sub, BEGIN 190*c29d5175Schristos value ------------- Distribution ------------- count 191*c29d5175Schristos 256 | 0 192*c29d5175Schristos 512 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 193*c29d5175Schristos 1024 | 0 194*c29d5175Schristos 195*c29d5175Schristos DynaLoader.pm, sub, BEGIN 196*c29d5175Schristos value ------------- Distribution ------------- count 197*c29d5175Schristos 128 | 0 198*c29d5175Schristos 256 |@@@@@@@@@@@@@@@@@@@@ 1 199*c29d5175Schristos 512 | 0 200*c29d5175Schristos 1024 |@@@@@@@@@@@@@@@@@@@@ 1 201*c29d5175Schristos 2048 | 0 202*c29d5175Schristos 203*c29d5175Schristos nicstat, sub, print_neat 204*c29d5175Schristos value ------------- Distribution ------------- count 205*c29d5175Schristos 32 | 0 206*c29d5175Schristos 64 |@@@@@@@@@@@@@@@@@@@@@@ 10 207*c29d5175Schristos 128 |@@@@@@@@@@@@@@@@@@ 8 208*c29d5175Schristos 256 | 0 209*c29d5175Schristos 210*c29d5175Schristos vars.pm, sub, BEGIN 211*c29d5175Schristos value ------------- Distribution ------------- count 212*c29d5175Schristos 1 | 0 213*c29d5175Schristos 2 |@@@@@@@@@@@@@ 1 214*c29d5175Schristos 4 | 0 215*c29d5175Schristos 8 |@@@@@@@@@@@@@ 1 216*c29d5175Schristos 16 | 0 217*c29d5175Schristos 32 | 0 218*c29d5175Schristos 64 | 0 219*c29d5175Schristos 128 | 0 220*c29d5175Schristos 256 | 0 221*c29d5175Schristos 512 | 0 222*c29d5175Schristos 1024 | 0 223*c29d5175Schristos 2048 |@@@@@@@@@@@@@ 1 224*c29d5175Schristos 4096 | 0 225*c29d5175Schristos 226*c29d5175Schristos Kstat.pm, sub, BEGIN 227*c29d5175Schristos value ------------- Distribution ------------- count 228*c29d5175Schristos 4 | 0 229*c29d5175Schristos 8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 230*c29d5175Schristos 16 | 0 231*c29d5175Schristos 32 | 0 232*c29d5175Schristos 64 | 0 233*c29d5175Schristos 128 | 0 234*c29d5175Schristos 256 | 0 235*c29d5175Schristos 512 | 0 236*c29d5175Schristos 1024 | 0 237*c29d5175Schristos 2048 |@@@@@@@@@@@@@ 1 238*c29d5175Schristos 4096 | 0 239*c29d5175Schristos 240*c29d5175Schristos nicstat, sub, BEGIN 241*c29d5175Schristos value ------------- Distribution ------------- count 242*c29d5175Schristos 128 | 0 243*c29d5175Schristos 256 |@@@@@@@@@@@@@ 1 244*c29d5175Schristos 512 |@@@@@@@@@@@@@ 1 245*c29d5175Schristos 1024 | 0 246*c29d5175Schristos 2048 |@@@@@@@@@@@@@ 1 247*c29d5175Schristos 4096 | 0 248*c29d5175Schristos 249*c29d5175Schristos nicstat, sub, fetch_net_data 250*c29d5175Schristos value ------------- Distribution ------------- count 251*c29d5175Schristos 16384 | 0 252*c29d5175Schristos 32768 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 253*c29d5175Schristos 65536 | 0 254*c29d5175Schristos 255*c29d5175Schristos nicstat, sub, find_nets 256*c29d5175Schristos value ------------- Distribution ------------- count 257*c29d5175Schristos 16384 | 0 258*c29d5175Schristos 32768 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 259*c29d5175Schristos 65536 | 0 260*c29d5175Schristos 261*c29d5175Schristos 262*c29d5175SchristosInclusive subroutine elapsed times (us), 263*c29d5175Schristos DynaLoader.pm, sub, dl_load_flags 264*c29d5175Schristos value ------------- Distribution ------------- count 265*c29d5175Schristos 1 | 0 266*c29d5175Schristos 2 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 267*c29d5175Schristos 4 | 0 268*c29d5175Schristos 269*c29d5175Schristos Config.pm, sub, TIEHASH 270*c29d5175Schristos value ------------- Distribution ------------- count 271*c29d5175Schristos 2 | 0 272*c29d5175Schristos 4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 273*c29d5175Schristos 8 | 0 274*c29d5175Schristos 275*c29d5175Schristos Config.pm, sub, DESTROY 276*c29d5175Schristos value ------------- Distribution ------------- count 277*c29d5175Schristos 4 | 0 278*c29d5175Schristos 8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 279*c29d5175Schristos 16 | 0 280*c29d5175Schristos 281*c29d5175Schristos Config.pm, sub, import 282*c29d5175Schristos value ------------- Distribution ------------- count 283*c29d5175Schristos 4 | 0 284*c29d5175Schristos 8 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 285*c29d5175Schristos 16 | 0 286*c29d5175Schristos 287*c29d5175Schristos register.pm, sub, mkMask 288*c29d5175Schristos value ------------- Distribution ------------- count 289*c29d5175Schristos 2 | 0 290*c29d5175Schristos 4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 291*c29d5175Schristos 8 | 0 292*c29d5175Schristos 293*c29d5175Schristos Config.pm, sub, FETCH 294*c29d5175Schristos value ------------- Distribution ------------- count 295*c29d5175Schristos 1 | 0 296*c29d5175Schristos 2 |@@@@@@@@@@@@@@@@@@@@ 2 297*c29d5175Schristos 4 |@@@@@@@@@@@@@@@@@@@@ 2 298*c29d5175Schristos 8 | 0 299*c29d5175Schristos 300*c29d5175Schristos strict.pm, sub, bits 301*c29d5175Schristos value ------------- Distribution ------------- count 302*c29d5175Schristos 2 | 0 303*c29d5175Schristos 4 |@@@@@@@@@@@@@@@@@@@@@@@@@@@ 4 304*c29d5175Schristos 8 |@@@@@@@ 1 305*c29d5175Schristos 16 |@@@@@@@ 1 306*c29d5175Schristos 32 | 0 307*c29d5175Schristos 308*c29d5175Schristos strict.pm, sub, import 309*c29d5175Schristos value ------------- Distribution ------------- count 310*c29d5175Schristos 1 | 0 311*c29d5175Schristos 2 |@@@@@@@@ 1 312*c29d5175Schristos 4 |@@@@@@@@@@@@@@@@ 2 313*c29d5175Schristos 8 | 0 314*c29d5175Schristos 16 |@@@@@@@@@@@@@@@@ 2 315*c29d5175Schristos 32 | 0 316*c29d5175Schristos 317*c29d5175Schristos Config.pm, sub, BEGIN 318*c29d5175Schristos value ------------- Distribution ------------- count 319*c29d5175Schristos 8 | 0 320*c29d5175Schristos 16 |@@@@@@@@@@@@@@@@@@@@ 1 321*c29d5175Schristos 32 |@@@@@@@@@@@@@@@@@@@@ 1 322*c29d5175Schristos 64 | 0 323*c29d5175Schristos 324*c29d5175Schristos Std.pm, sub, getopts 325*c29d5175Schristos value ------------- Distribution ------------- count 326*c29d5175Schristos 32 | 0 327*c29d5175Schristos 64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 328*c29d5175Schristos 128 | 0 329*c29d5175Schristos 330*c29d5175Schristos register.pm, sub, import 331*c29d5175Schristos value ------------- Distribution ------------- count 332*c29d5175Schristos 32 | 0 333*c29d5175Schristos 64 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 334*c29d5175Schristos 128 | 0 335*c29d5175Schristos 336*c29d5175Schristos strict.pm, sub, unimport 337*c29d5175Schristos value ------------- Distribution ------------- count 338*c29d5175Schristos 8 | 0 339*c29d5175Schristos 16 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 4 340*c29d5175Schristos 32 | 0 341*c29d5175Schristos 342*c29d5175Schristos vars.pm, sub, import 343*c29d5175Schristos value ------------- Distribution ------------- count 344*c29d5175Schristos 16 | 0 345*c29d5175Schristos 32 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2 346*c29d5175Schristos 64 | 0 347*c29d5175Schristos 348*c29d5175Schristos AutoLoader.pm, sub, BEGIN 349*c29d5175Schristos value ------------- Distribution ------------- count 350*c29d5175Schristos 1 | 0 351*c29d5175Schristos 2 |@@@@@@@ 1 352*c29d5175Schristos 4 |@@@@@@@ 1 353*c29d5175Schristos 8 | 0 354*c29d5175Schristos 16 |@@@@@@@@@@@@@@@@@@@@ 3 355*c29d5175Schristos 32 |@@@@@@@ 1 356*c29d5175Schristos 64 | 0 357*c29d5175Schristos 358*c29d5175Schristos Exporter.pm, sub, import 359*c29d5175Schristos value ------------- Distribution ------------- count 360*c29d5175Schristos 16 | 0 361*c29d5175Schristos 32 |@@@@@@@@@@@@@@@@@@@@ 1 362*c29d5175Schristos 64 |@@@@@@@@@@@@@@@@@@@@ 1 363*c29d5175Schristos 128 | 0 364*c29d5175Schristos 365*c29d5175Schristos DynaLoader.pm, sub, bootstrap 366*c29d5175Schristos value ------------- Distribution ------------- count 367*c29d5175Schristos 256 | 0 368*c29d5175Schristos 512 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 369*c29d5175Schristos 1024 | 0 370*c29d5175Schristos 371*c29d5175Schristos warnings.pm, sub, BEGIN 372*c29d5175Schristos value ------------- Distribution ------------- count 373*c29d5175Schristos 256 | 0 374*c29d5175Schristos 512 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 375*c29d5175Schristos 1024 | 0 376*c29d5175Schristos 377*c29d5175Schristos nicstat, sub, print_neat 378*c29d5175Schristos value ------------- Distribution ------------- count 379*c29d5175Schristos 32 | 0 380*c29d5175Schristos 64 |@@@@@@@@@@@@@@@@@@@@@@ 10 381*c29d5175Schristos 128 |@@@@@@@@@@@@@@@@@@ 8 382*c29d5175Schristos 256 | 0 383*c29d5175Schristos 384*c29d5175Schristos vars.pm, sub, BEGIN 385*c29d5175Schristos value ------------- Distribution ------------- count 386*c29d5175Schristos 1 | 0 387*c29d5175Schristos 2 |@@@@@@@@@@@@@ 1 388*c29d5175Schristos 4 | 0 389*c29d5175Schristos 8 | 0 390*c29d5175Schristos 16 | 0 391*c29d5175Schristos 32 |@@@@@@@@@@@@@ 1 392*c29d5175Schristos 64 | 0 393*c29d5175Schristos 128 | 0 394*c29d5175Schristos 256 | 0 395*c29d5175Schristos 512 | 0 396*c29d5175Schristos 1024 | 0 397*c29d5175Schristos 2048 |@@@@@@@@@@@@@ 1 398*c29d5175Schristos 4096 | 0 399*c29d5175Schristos 400*c29d5175Schristos DynaLoader.pm, sub, BEGIN 401*c29d5175Schristos value ------------- Distribution ------------- count 402*c29d5175Schristos 512 | 0 403*c29d5175Schristos 1024 |@@@@@@@@@@@@@@@@@@@@ 1 404*c29d5175Schristos 2048 |@@@@@@@@@@@@@@@@@@@@ 1 405*c29d5175Schristos 4096 | 0 406*c29d5175Schristos 407*c29d5175Schristos Kstat.pm, sub, BEGIN 408*c29d5175Schristos value ------------- Distribution ------------- count 409*c29d5175Schristos 8 | 0 410*c29d5175Schristos 16 |@@@@@@@@@@@@@ 1 411*c29d5175Schristos 32 |@@@@@@@@@@@@@ 1 412*c29d5175Schristos 64 | 0 413*c29d5175Schristos 128 | 0 414*c29d5175Schristos 256 | 0 415*c29d5175Schristos 512 | 0 416*c29d5175Schristos 1024 | 0 417*c29d5175Schristos 2048 | 0 418*c29d5175Schristos 4096 | 0 419*c29d5175Schristos 8192 |@@@@@@@@@@@@@ 1 420*c29d5175Schristos 16384 | 0 421*c29d5175Schristos 422*c29d5175Schristos nicstat, sub, BEGIN 423*c29d5175Schristos value ------------- Distribution ------------- count 424*c29d5175Schristos 256 | 0 425*c29d5175Schristos 512 |@@@@@@@@@@@@@ 1 426*c29d5175Schristos 1024 | 0 427*c29d5175Schristos 2048 |@@@@@@@@@@@@@ 1 428*c29d5175Schristos 4096 | 0 429*c29d5175Schristos 8192 |@@@@@@@@@@@@@ 1 430*c29d5175Schristos 16384 | 0 431*c29d5175Schristos 432*c29d5175Schristos nicstat, sub, fetch_net_data 433*c29d5175Schristos value ------------- Distribution ------------- count 434*c29d5175Schristos 16384 | 0 435*c29d5175Schristos 32768 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 436*c29d5175Schristos 65536 | 0 437*c29d5175Schristos 438*c29d5175Schristos nicstat, sub, find_nets 439*c29d5175Schristos value ------------- Distribution ------------- count 440*c29d5175Schristos 16384 | 0 441*c29d5175Schristos 32768 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1 442*c29d5175Schristos 65536 | 0 443*c29d5175Schristos 444*c29d5175SchristosAs an example of interpreting the output: the inclusive elapsed time for 445*c29d5175Schristosthe "print_neat" subroutine in "nicstat", 446*c29d5175Schristos 447*c29d5175Schristos nicstat, sub, print_neat 448*c29d5175Schristos value ------------- Distribution ------------- count 449*c29d5175Schristos 32 | 0 450*c29d5175Schristos 64 |@@@@@@@@@@@@@@@@@@@@@@ 10 451*c29d5175Schristos 128 |@@@@@@@@@@@@@@@@@@ 8 452*c29d5175Schristos 256 | 0 453*c29d5175Schristos 454*c29d5175Schristosshows that "print_neat" was called 18 times, 10 of which took between 64 455*c29d5175Schristosand 127 microseconds, and 8 of which took between 128 and 255 microseconds. 456*c29d5175Schristos 457