Solaris Dynamic Tracing Guide

Examples

exec

You can use the exec probe to easily determine which programs are being executed, and by whom, as shown in the following example:

#pragma D option quiet

proc:::exec
{
        self->parent = execname;
}

proc:::exec-success
/self->parent != NULL/
{
	@[self->parent, execname] = count();
	self->parent = NULL;
}

proc:::exec-failure
/self->parent != NULL/
{
	self->parent = NULL;
}

END
{
	printf("%-20s %-20s %s\n", "WHO", "WHAT", "COUNT");
	printa("%-20s %-20s %@d\n", @);
}

Running the example script for a short period of time on a build machine results in output similar to the following example:


# dtrace -s ./whoexec.d
^C
WHO                  WHAT                 COUNT
make.bin             yacc                 1
tcsh                 make                 1
make.bin             spec2map             1
sh                   grep                 1
lint                 lint2                1
sh                   lint                 1
sh                   ln                   1
cc                   ld                   1
make.bin             cc                   1
lint                 lint1                1
sh                   lex                  1
make.bin             mv                   2
sh                   sh                   3
sh                   make                 3
sh                   sed                  4
sh                   tr                   4
make                 make.bin             4
sh                   install.bin          5
sh                   rm                   6
cc                   ir2hf                33
cc                   ube                  33
sh                   date                 34
sh                   mcs                  34
cc                   acomp                34
sh                   cc                   34
sh                   basename             34
basename             expr                 34
make.bin             sh                   87

start and exit

If you want to know how long programs are running from creation to termination, you can enable the start and exit probes, as shown in the following example:

proc:::start
{
	self->start = timestamp;
}

proc:::exit
/self->start/
{
	@[execname] = quantize(timestamp - self->start);
	self->start = 0;
}

Running the example script on the build server for several seconds results in output similar to the following example:


# dtrace -s ./progtime.d
dtrace: script './progtime.d' matched 2 probes
^C

  ir2hf                                             
           value  ------------- Distribution ------------- count
         4194304 |                                         0        
         8388608 |@                                        1        
        16777216 |@@@@@@@@@@@@@@@@                         14       
        33554432 |@@@@@@@@@@                               9        
        67108864 |@@@                                      3        
       134217728 |@                                        1        
       268435456 |@@@@                                     4        
       536870912 |@                                        1        
      1073741824 |                                         0        

  ube                                               
           value  ------------- Distribution ------------- count
        16777216 |                                         0        
        33554432 |@@@@@@@                                  6        
        67108864 |@@@                                      3        
       134217728 |@@                                       2        
       268435456 |@@@@                                     4        
       536870912 |@@@@@@@@@@@@                             10       
      1073741824 |@@@@@@@                                  6        
      2147483648 |@@                                       2        
      4294967296 |                                         0        

  acomp                                             
           value  ------------- Distribution ------------- count
         8388608 |                                         0        
        16777216 |@@                                       2        
        33554432 |                                         0        
        67108864 |@                                        1        
       134217728 |@@@                                      3        
       268435456 |                                         0        
       536870912 |@@@@@                                    5        
      1073741824 |@@@@@@@@@@@@@@@@@@@@@@@@@                22       
      2147483648 |@                                        1        
      4294967296 |                                         0        

  cc                                                
           value  ------------- Distribution ------------- count
        33554432 |                                         0        
        67108864 |@@@                                      3        
       134217728 |@                                        1        
       268435456 |                                         0        
       536870912 |@@@@                                     4        
      1073741824 |@@@@@@@@@@@@@@                           13       
      2147483648 |@@@@@@@@@@@@                             11       
      4294967296 |@@@                                      3        
      8589934592 |                                         0        

  sh                                                
           value  ------------- Distribution ------------- count
          262144 |                                         0        
          524288 |@                                        5        
         1048576 |@@@@@@@                                  29       
         2097152 |                                         0        
         4194304 |                                         0        
         8388608 |@@@                                      12       
        16777216 |@@                                       9        
        33554432 |@@                                       9        
        67108864 |@@                                       8        
       134217728 |@                                        7        
       268435456 |@@@@@                                    20       
       536870912 |@@@@@@                                   26       
      1073741824 |@@@                                      14       
      2147483648 |@@                                       11       
      4294967296 |                                         3        
      8589934592 |                                         1        
     17179869184 |                                         0        

  make.bin                                          
           value  ------------- Distribution ------------- count
        16777216 |                                         0        
        33554432 |@                                        1        
        67108864 |@                                        1        
       134217728 |@@                                       2        
       268435456 |                                         0        
       536870912 |@@                                       2        
      1073741824 |@@@@@@@@@                                9        
      2147483648 |@@@@@@@@@@@@@@@                          14       
      4294967296 |@@@@@@                                   6        
      8589934592 |@@                                       2        
     17179869184 |                                         0

lwp-start and lwp-exit

Instead of knowing the amount of time that a particular process takes to run, you might want to know how long individual threads take to run. The following example shows how to use the lwp-start and lwp-exit probes for this purpose:

proc:::lwp-start
/tid != 1/
{
	self->start = timestamp;
}

proc:::lwp-exit
/self->start/
{
	@[execname] = quantize(timestamp - self->start);
	self->start = 0;
}

Running the example script on an NFS and calendar server results in output similar to the following example:


# dtrace -s ./lwptime.d
dtrace: script './lwptime.d' matched 3 probes
^C

  nscd                                              
           value  ------------- Distribution ------------- count
          131072 |                                         0        
          262144 |@                                        18       
          524288 |@@                                       24       
         1048576 |@@@@@@@                                  75       
         2097152 |@@@@@@@@@@@@@@@@@@@@@@@                  245      
         4194304 |@@                                       22       
         8388608 |@@                                       24       
        16777216 |                                         6        
        33554432 |                                         3        
        67108864 |                                         1        
       134217728 |                                         1        
       268435456 |                                         0        

  mountd                                            
           value  ------------- Distribution ------------- count
          524288 |                                         0        
         1048576 |@                                        15       
         2097152 |@                                        24       
         4194304 |@@@                                      51       
         8388608 |@                                        17       
        16777216 |@                                        24       
        33554432 |@                                        15       
        67108864 |@@@@                                     57       
       134217728 |@                                        28       
       268435456 |@                                        26       
       536870912 |@@                                       39       
      1073741824 |@@@                                      45       
      2147483648 |@@@@@                                    72       
      4294967296 |@@@@@                                    77       
      8589934592 |@@@                                      55       
     17179869184 |                                         14       
     34359738368 |                                         2        
     68719476736 |                                         0        

  automountd                                        
           value  ------------- Distribution ------------- count
         1048576 |                                         0        
         2097152 |                                         3        
         4194304 |@@@@                                     146      
         8388608 |                                         6        
        16777216 |                                         6        
        33554432 |                                         9        
        67108864 |@@@@@                                    203      
       134217728 |@@                                       87       
       268435456 |@@@@@@@@@@@@@@@                          534      
       536870912 |@@@@@@                                   223      
      1073741824 |@                                        45       
      2147483648 |                                         20       
      4294967296 |                                         26       
      8589934592 |                                         20       
     17179869184 |                                         19       
     34359738368 |                                         7        
     68719476736 |                                         2        
    137438953472 |                                         0        

  iCald
           value  ------------- Distribution ------------- count
         8388608 |                                         0        
        16777216 |@@@@@@@                                  20       
        33554432 |@@@                                      9        
        67108864 |@@                                       8        
       134217728 |@@@@@                                    16       
       268435456 |@@@@                                     11       
       536870912 |@@@@                                     11       
      1073741824 |@                                        4        
      2147483648 |                                         2        
      4294967296 |                                         0        
      8589934592 |@@                                       8        
     17179869184 |@                                        5        
     34359738368 |@                                        4        
     68719476736 |@@                                       6        
    137438953472 |@                                        4        
    274877906944 |                                         2        
    549755813888 |                                         0

signal-send

You can use the signal-send probe to determine the sending and receiving process associated with any signal, as shown in the following example:

#pragma D option quiet

proc:::signal-send
{
	@[execname, stringof(args[1]->pr_fname), args[2]] = count();
}

END
{
	printf("%20s %20s %12s %s\n",
	    "SENDER", "RECIPIENT", "SIG", "COUNT");
	printa("%20s %20s %12d %@d\n", @);
}

Running this script results in output similar to the following example:


# dtrace -s ./sig.d
^C
              SENDER            RECIPIENT          SIG COUNT
               xterm               dtrace            2 1
               xterm          soffice.bin            2 1
                  tr                 init           18 1
               sched                 test           18 1
               sched                fvwm2           18 1
                bash                 bash           20 1
                 sed                 init           18 2
               sched                  ksh           18 15
               sched                 Xsun           22 471