Solaris 动态跟踪指南

sleepwakeup

enqueuedequeue中,最后的示例说明因为可运行 xterm 进程而导致运行队列长度剧增。一种猜测是这种现象是因为虚拟桌面中的更改而造成的。要验证此猜测,可使用 wakeup 探测器来确定是谁唤醒了 xterm 进程以及是何时唤醒的,如下例所示:

#pragma D option quiet

dtrace:::BEGIN
{
	start = timestamp;
}

sched:::wakeup
/stringof(args[1]->pr_fname) == "xterm"/
{
	@[execname] = lquantize((timestamp - start) / 1000000000, 0, 10);
}

profile:::tick-1sec
/++x == 10/
{
	exit(0);
}

要验证此猜测,请运行以上脚本,等待大约 5 秒,然后切换一次虚拟桌面。如果 xterm 进程的剧增是因为切换虚拟桌面造成的,则输出应该在 5 秒标记处显示唤醒活动剧增。


# dtrace -s ./xterm.d

  Xsun

           value  -------------- Distribution ------------ count    
               4 |                                         0        
               5 |@                                        1        
               6 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@   32       
               7 |                                         0

此输出显示 X 服务器正在唤醒切换虚拟桌面时聚集的 xterm 进程。如果要了解 X 服务器与 xterm 进程之间的交互,可在 X 服务器触发 wakeup 探测器时聚集用户栈跟踪。

要了解像 X 窗口系统这样的客户机/服务器系统的性能,您需要了解服务器以其名义运行的客户机。常规性能分析工具很难回答这类问题。但是,如果某个模型中的客户机向服务器发送一条消息并且休眠,而且是在暂挂服务器处理时休眠,则可以使用 wakeup 探测器来确定对其执行请求的客户机,如下例所示:

self int last;

sched:::wakeup
/self->last && args[0]->pr_stype == SOBJ_CV/
{
	@[stringof(args[1]->pr_fname)] = sum(vtimestamp - self->last);
	self->last = 0;
}

sched:::wakeup
/execname == "Xsun" && self->last == 0/
{
	self->last = vtimestamp;
}

运行上面的脚本将会生成与以下示例类似的输出:


dtrace -s ./xwork.d
dtrace: script './xwork.d' matched 14 probes
^C
  xterm                                                       9522510
  soffice.bin                                                 9912594
  fvwm2                                                     100423123
  MozillaFirebird                                           312227077
  acroread                                                  345901577

此输出显示许多 Xsun 工作都是以进程 acroreadMozillaFirebird 的名义完成的,很少以 fvwm2 的名义完成。请注意,此脚本仅检查条件变量同步对象 (SOBJ_CV) 中的唤醒次数。如表 25–4 中所述,条件变量为通常用于同步(出于访问共享数据区域之外的原因)的同步对象类型。如果使用 X 服务器,客户机将通过对条件变量休眠来等待管道中的数据。

而且,您还可使用 sleep 探测器和 wakeup 探测器来了解哪些应用程序在哪些应用程序上阻塞,以及阻塞多长时间,如下例所示:

#pragma D option quiet

sched:::sleep
/!(curlwpsinfo->pr_flag & PR_ISSYS) && curlwpsinfo->pr_stype == SOBJ_CV/
{
	bedtime[curlwpsinfo->pr_addr] = timestamp;
}

sched:::wakeup
/bedtime[args[0]->pr_addr]/
{
	@[stringof(args[1]->pr_fname), execname] =
	    quantize(timestamp - bedtime[args[0]->pr_addr]);
	bedtime[args[0]->pr_addr] = 0;
}

END
{
	printa("%s sleeping on %s:\n%@d\n", @);
}

在桌面系统上运行以上示例若干秒生成的输出后半部分与以下示例类似:


# dtrace -s ./whofor.d
^C
...
 xterm sleeping on Xsun:

           value  -------------- Distribution ------------ count    
          131072 |                                         0        
          262144 |                                         12       
          524288 |                                         2        
         1048576 |                                         0        
         2097152 |                                         5        
         4194304 |@@@                                      45       
         8388608 |                                         1        
        16777216 |                                         9        
        33554432 |@@@@@                                    83       
        67108864 |@@@@@@@@@@@                              164      
       134217728 |@@@@@@@@@@                               147      
       268435456 |@@@@                                     56       
       536870912 |@                                        17       
      1073741824 |                                         9        
      2147483648 |                                         1        
      4294967296 |                                         3        
      8589934592 |                                         1        
     17179869184 |                                         0        

fvwm2 sleeping on Xsun:

           value  -------------- Distribution ------------ count    
           32768 |                                         0        
           65536 |@@@@@@@@@@@@@@@@@@@@@@                   67       
          131072 |@@@@@                                    16       
          262144 |@@                                       6        
          524288 |@                                        3        
         1048576 |@@@@@                                    15       
         2097152 |                                         0        
         4194304 |                                         0        
         8388608 |                                         1        
        16777216 |                                         0        
        33554432 |                                         0        
        67108864 |                                         1        
       134217728 |                                         0        
       268435456 |                                         0        
       536870912 |                                         1        
      1073741824 |                                         1        
      2147483648 |                                         2        
      4294967296 |                                         2        
      8589934592 |                                         2        
     17179869184 |                                         0        
     34359738368 |                                         2        
     68719476736 |                                         0        

syslogd sleeping on syslogd:

           value  -------------- Distribution ------------ count    
     17179869184 |                                         0        
     34359738368 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 3        
     68719476736 |                                         0        

MozillaFirebird sleeping on MozillaFirebird:

           value  -------------- Distribution ------------ count    
           65536 |                                         0        
          131072 |                                         3        
          262144 |@@                                       14       
          524288 |                                         0        
         1048576 |@@@                                      18       
         2097152 |                                         0        
         4194304 |                                         0        
         8388608 |                                         1        
        16777216 |                                         0        
        33554432 |                                         1        
        67108864 |                                         3        
       134217728 |@                                        7        
       268435456 |@@@@@@@@@@                               53       
       536870912 |@@@@@@@@@@@@@@                           78       
      1073741824 |@@@@                                     25       
      2147483648 |                                         0        
      4294967296 |                                         0        
      8589934592 |@                                        7        
     17179869184 |                                         0

您可能需要了解 MozillaFirebird 如何以及为何阻塞自身。可按以下示例中所示修改以上脚本来回答此问题:

#pragma D option quiet

sched:::sleep
/execname == "MozillaFirebird" && curlwpsinfo->pr_stype == SOBJ_CV/
{
	bedtime[curlwpsinfo->pr_addr] = timestamp;
}

sched:::wakeup
/execname == "MozillaFirebird" && bedtime[args[0]->pr_addr]/
{
	@[args[1]->pr_pid, args[0]->pr_lwpid, pid, curlwpsinfo->pr_lwpid] = 
	    quantize(timestamp - bedtime[args[0]->pr_addr]);
	bedtime[args[0]->pr_addr] = 0;
}

sched:::wakeup
/bedtime[args[0]->pr_addr]/
{
	bedtime[args[0]->pr_addr] = 0;
}

END
{
	printa("%d/%d sleeping on %d/%d:\n%@d\n", @);
}

运行修改后的脚本若干秒将会生成与以下示例类似的输出:


# dtrace -s ./firebird.d
^C

 100459/1 sleeping on 100459/13:

           value  -------------- Distribution ------------ count    
          262144 |                                         0        
          524288 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1        
         1048576 |                                         0        

100459/13 sleeping on 100459/1:

           value  -------------- Distribution ------------ count    
        16777216 |                                         0        
        33554432 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1        
        67108864 |                                         0        

100459/1 sleeping on 100459/2:

           value  -------------- Distribution ------------ count    
           16384 |                                         0        
           32768 |@@@@                                     5        
           65536 |@                                        2        
          131072 |@@@@@                                    6        
          262144 |                                         1        
          524288 |@                                        2        
         1048576 |                                         0        
         2097152 |@@                                       3        
         4194304 |@@@@                                     5        
         8388608 |@@@@@@@@                                 9        
        16777216 |@@@@@                                    6        
        33554432 |@@                                       3        
        67108864 |                                         0        

100459/1 sleeping on 100459/5:

           value  -------------- Distribution ------------ count    
           16384 |                                         0        
           32768 |@@@@@                                    12       
           65536 |@@                                       5        
          131072 |@@@@@@                                   15       
          262144 |                                         1        
          524288 |                                         1        
         1048576 |                                         2        
         2097152 |@                                        4        
         4194304 |@@@@@                                    13       
         8388608 |@@@                                      8        
        16777216 |@@@@@                                    13       
        33554432 |@@                                       6        
        67108864 |@@                                       5        
       134217728 |@                                        4        
       268435456 |                                         0        
       536870912 |                                         1        
      1073741824 |                                         0        

100459/2 sleeping on 100459/1:

           value  -------------- Distribution ------------ count    
           16384 |                                         0        
           32768 |@@@@@@@@@@@@@@                           11       
           65536 |                                         0        
          131072 |@@                                       2        
          262144 |                                         0        
          524288 |                                         0        
         1048576 |@@@@                                     3        
         2097152 |@                                        1        
         4194304 |@@                                       2        
         8388608 |@@                                       2        
        16777216 |@                                        1        
        33554432 |@@@@@@                                   5        
        67108864 |                                         0        
       134217728 |                                         0        
       268435456 |                                         0        
       536870912 |@                                        1        
      1073741824 |@                                        1        
      2147483648 |@                                        1        
      4294967296 |                                         0        

100459/5 sleeping on 100459/1:

           value  -------------- Distribution ------------ count    
           16384 |                                         0        
           32768 |                                         1        
           65536 |                                         2        
          131072 |                                         4        
          262144 |                                         7        
          524288 |                                         1        
         1048576 |                                         5        
         2097152 |                                         10       
         4194304 |@@@@@@                                   77       
         8388608 |@@@@@@@@@@@@@@@@@@@@@@@                  270      
        16777216 |@@@                                      43       
        33554432 |@                                        20       
        67108864 |@                                        14       
       134217728 |                                         5        
       268435456 |                                         2        
       536870912 |                                         1        
      1073741824 |                                         0        

还可使用 sleepwakeup 探测器来了解门服务器的性能(如名称服务高速缓存守护进程),如下例所示:

sched:::sleep
/curlwpsinfo->pr_stype == SOBJ_SHUTTLE/
{
	bedtime[curlwpsinfo->pr_addr] = timestamp;
}

sched:::wakeup
/execname == "nscd" && bedtime[args[0]->pr_addr]/
{
	@[stringof(curpsinfo->pr_fname), stringof(args[1]->pr_fname)] =
	    quantize(timestamp - bedtime[args[0]->pr_addr]);
	bedtime[args[0]->pr_addr] = 0;
}

sched:::wakeup
/bedtime[args[0]->pr_addr]/
{
	bedtime[args[0]->pr_addr] = 0;
}

在大型邮件服务器上运行以上脚本生成的输出后半部分与以下示例类似:


imapd
           value  -------------- Distribution ------------ count    
           16384 |                                         0        
           32768 |                                         2        
           65536 |@@@@@@@@@@@@@@@@@                        57       
          131072 |@@@@@@@@@@@                              37       
          262144 |                                         3        
          524288 |@@@                                      11       
         1048576 |@@@                                      10       
         2097152 |@@                                       9        
         4194304 |                                         1        
         8388608 |                                         0        

  mountd                                            
           value  -------------- Distribution ------------ count    
           65536 |                                         0        
          131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@            49       
          262144 |@@@                                      6        
          524288 |                                         1        
         1048576 |                                         0        
         2097152 |                                         0        
         4194304 |@@@@                                     7        
         8388608 |@                                        3        
        16777216 |                                         0        

  sendmail
           value  -------------- Distribution ------------ count    
           16384 |                                         0        
           32768 |@                                        18       
           65536 |@@@@@@@@@@@@@@@@@                        205      
          131072 |@@@@@@@@@@@@@                            154      
          262144 |@                                        23       
          524288 |                                         5        
         1048576 |@@@@                                     50       
         2097152 |                                         7        
         4194304 |                                         5        
         8388608 |                                         2        
        16777216 |                                         0        

  automountd                                        
           value  -------------- Distribution ------------ count    
           32768 |                                         0        
           65536 |@@@@@@@@@@                               22       
          131072 |@@@@@@@@@@@@@@@@@@@@@@@                  51       
          262144 |@@                                       6        
          524288 |                                         1        
         1048576 |                                         0        
         2097152 |                                         2        
         4194304 |                                         2        
         8388608 |                                         1        
        16777216 |                                         1        
        33554432 |                                         1        
        67108864 |                                         0        
       134217728 |                                         0        
       268435456 |                                         1        
       536870912 |                                         0

您可能会关心 automountd 的异常数据点或 sendmail 的超过 1 毫秒的持久数据点。可向以上脚本中添加其他谓词以有效查看造成任何异常或反常结果的原因。