DTRACE简介(3)

     在上一篇blog中,我们了解了DTrace的内置变量、函数、操作等。DTrace还内建了一些宏变量(Macro Variable),在D程序中可以直接使用这些宏变量,以增强D程序的可移植性。

      表1 - D宏变量

 名称说明
参考相关系统调用
 
$[0-9]+
宏参数
  
$egid
有效组ID
getegid(2)
$euid
有效用户ID
geteuid(2)
$gid
实际组ID
getgid(2)
$pid
进程ID
getpid(2)
$pgid
进程组ID
getpgid(2)
$ppid
父进程ID
getppid(2)
$projid
项目ID
getprojid(2)
$sid
会话ID
getsid(2)
$target
目标进程ID


$taskid
任务ID
gettaskid(2)

$uid
实际用户ID
getuid(2)

      在上表中,除宏参数和$target外,其它宏变量都与当时触发探测器的进程相关联。

      宏参数表示传递给D程序的参数,如果D程序 macro.d接受3个参数,那么$0对应macro.d即D程序名,$1对应于第1个参数,$2对应于第2个参数,以此类推。如果要传递字符串给D程序,则相应的宏参数前面要再加上一个美元$符号。比如macro.d中,如果第3个参数是字符串,那么在D程序中应该使用$$3来引用。

      $target被Dtrace替换为目标的进程号,如果是使用-p参数指定,则$target就是该进程号,如果是-c,则target对应-c后面的命令运行时的进程号。为便于大家理解,我们编写一个简单的D程序,只打印target的信息。

target.d

#!/usr/sbin/dtrace -qs
BEGIN
{
     printf("target=%d\\n",$target);
     exit(0);
}

     再编写一个测试用的shell脚本,此脚本只打印自己的进程号

pid.sh

#!/bin/sh
echo mypid=$$

     然后我们执行以下操作

 


# echo $$
710
# ./target.d -p $$
target=710
# ./target.d -c ./pid.sh
mypid=766
target=766


      怎么样,明白$target的含义了吧。

      DTrace提供了可调整的选项,选项通过#pragma D option指定,有的选项也可以在命令行指定。

      表2 - DTrace选项

 选项名命令行开关

描述
aggrate
 时间或者频率(无后缀)
聚合读取的频率
aggsize

大小
聚合缓冲区的大小
bufresize

auto或者manual
缓冲区调整大小的策略
bufsize
-b
大小
主缓冲区大小
cleanrate

时间
清除的频率
cpu
-c
CPU标号
指定在该CPU上启用探测器跟踪
defaultargs


允许引用未指定的宏参数
destructive
-w

允许破坏性操作
dynvarsize


动态变量空间大小
flowindent
-F

在进入函数时缩进显示,并加前缀->,退出函数时取消缩进,并加前缀<-
grabanon
-a

声明匿名跟踪状态
jstackframe

数字
缺省的jstack()栈帧的数量
jstackstrsize

数字
jstack()缺省字符串大小
nspec

数字
推理缓冲区的个数
quiet
-q

仅输出显示跟踪的数据(比如printf)
specsize

大小
推理缓冲区的大小
strsize

大小
字符串大小
stackframes

数字
栈帧数
stackindent

数字
当缩进stack()和ustack()是的空
statusrate

时间
状态检查的频率
switchrate

时间
缓冲区切换的频率
ustackframes

数字
用户栈帧数



 

 

 

 

 

 

 

 

 

 

 

 

 

 

 

 

 

 

下面我们来了解一下DTrace中缓冲区及其管理(Data buffering and management)

      缓冲区及其管理是DTrace架构为其消费者提供的重要服务。DTrace操作有很多都是与数据记录相关的,这些数据是记录在DTrace的缓冲区中的。每次DTrace调用都会使用到“主缓冲区(Principal Buffer)”,主缓冲区是基于每个CPU分配的。对于缓冲区的管理有以下策略。

 

switch策略

      缺省情况下,主缓冲区采用switch策略。在此策略下,每个CPU的缓冲区成对分配:一个处于活动状态,另一个处于非活动状态。当DTrace使用者试图访问缓冲区时,内核会切换(switch)活动缓冲区和非活动缓冲区,切换方式会保证跟踪的数据不会丢失。切换完成后,新的非活动缓冲区将复制给DTrace使用者。切换的速率可以通过switchrate选项控制,如果不带时间后缀,则缺省是每秒的次数。可以使用bufsize来调整主缓冲区的大小。

fill策略 

      在此策略下,当任何一个CPU的缓冲区已经填充满时,Dtrace将停止跟踪,并处理所有缓冲区。 要使用此策略,需要将bufpolicy设置为fill,可以使用命令行-x bufpolicy=fill或者编译指令#pragma D option bufpolicy=fill

ring策略

      在此策略下,DTrace将主缓冲区作为一个环形缓冲区对待,即当缓冲区填满时,数据会重新从缓冲区开始记录。Dtrace只会在程序终止时才会输出信息。此策略指定方式,命令行-x bufpolicy=ring,编译指令#pragma D option bufpolicy=ring

其它缓冲区

     除了上面的缓冲区外,还有:聚合缓冲区(aggregate buffer)以及一个或者多个推理缓冲区(Speculative buffer)。聚合缓冲区是聚合函数会用到的缓冲区,而推理缓冲区则是推理跟踪会用到的缓冲区。

聚合

      如果需要调查与性能相关的系统问题,就可以用到Dtrace提供的聚合操作。聚合操作是针对聚合函数(Aggregating Functions)而言的。聚合函数具有以下属性:

       f( f(X0) U f(X1)  U ... U f(Xn) )  =  f ( X0 U X1 U ... U Xn )

      换句话讲,就是对整个数据集合的子集应用聚合函数,然后再对结果应用该聚合函数,得到的最终结果与对整个数据集合本身应用该聚合函数相同。比如求给定数据集合之和的SUM函数,就是一个聚合函数。

       DTrace中的聚合函数见下表:

       表3 - DTrace聚合函数

 函数名参数
结果
count

调用次数
sum
标量表达式
所指定表达式的总和
avg
标量表达式所指定表达式的算术平均值
min
标量表达式所指定表达式的最小值
max
标量表达式所指定表达式的最大值
lquantize
标量表达式,下限,上限,步长值所指定表达式的值的线性频率分布
quantize
标量表达式
所指定表达式的值的二次方幂频率分布
 

 

 



 

      DTrace将聚合函数的结果存储在称为聚合(Aggregation)的特殊对象中。其语法为:

        @name[keys]=aggfunc(args);

      name是聚合的名称,可以省略,keys是索引,可以是有逗号分隔的表达式,aggfunc是上表提到的函数,args是聚合函数的参数。聚合与关联数组的区别是其名字是以@作为前缀的,@name与name在不同的名称空间。

      比如我们想查看5秒钟内系统调用的次数


# dtrace -n 'syscall:::entry{@counts["syscall numbers"]=count();}tick-5sec{exit(0);}'
dtrace: description 'syscall:::entry' matched 232 probes
CPU     ID                    FUNCTION:NAME
  0  49049                       :tick-5sec

  syscall numbers                                                 241


     此例中聚合@count的key是字符串"syscall numbers"。

     我们还想再进一步了解到底是什么程序调用的系统调用最多,可能这个程序就是导致系统性能下降的主谋


 # dtrace -n 'syscall:::entry{@counts[execname]=count();}tick-5sec{exit(0);}'
dtrace: description 'syscall:::entry' matched 232 probes
CPU     ID                    FUNCTION:NAME
  0  49049                       :tick-5sec

  svc.configd                                                       1
  svc.startd                                                        1
  Xorg                                                              4
  nmbd                                                              4
  sendmail                                                         10
  dtrace                                                          229


     在此例中@counts的key是D内置变量execname。

     在进一步细化,看看什么系统调用最多


# dtrace -n 'syscall:::entry{@counts[execname,probefunc]=count();}tick-5sec{exit(0);}'
dtrace: description 'syscall:::entry' matched 232 probes
CPU     ID                    FUNCTION:NAME
  0  49049                       :tick-5sec

  automountd                         gtime                                    1
  dtrace                                  mmap                                   1
  dtrace                                 schedctl                                 1
  fmd                                     lwp_park                        1
  in.routed                             pollsys                                   1
  inetd                                   lwp_park                                1
  sendmail                             pollsys                                   1
  automountd                      doorfs                                   2
  sendmail                            lwp_sigmask                         2
  dtrace                                 sysconfig                             3
  sendmail                              pset                                    3
  dtrace                                 sigaction                             4
  sendmail                              gtime                                 4
  dtrace                                  lwp_park                            5
  dtrace                                  brk                                     8
  dtrace                                  p_online                             32
  dtrace                                 ioctl                                    177


      在此例中@counts的key是execname,probefunc。

      使用lquantize,我们了解需要调查的表达式的分布情况。比如,我们想知道系统调用write打开的文件描述符(file descriptor)的线性分布情况。

 


# dtrace -n 'syscall::write:entry{@fds[execname]=lquantize(arg0,0,100,1)}'
dtrace: description 'syscall::write:entry' matched 1 probe
\^C

  dtrace
           value  ------------- Distribution ------------- count
               0 |                                         0
               1 |@@@@@@@@@@@@@@@@@@@@ 1
               2 |                                         0

  sshd
           value  ------------- Distribution ------------- count
               3 |                                         0
               4 |@@@@@@@@@@@@@@@@@@@@                     1
               5 |                                         0
               6 |                                         0
               7 |                                         0
               8 |@@@@@@@@@@@@@@@@@@@@                     1
               9 |                                         0


      在上例中,我们可以看到,在该时间内,sshd进程对文件描述符4操作了1次,对文件描述符8操作了1次。虽然不具有实际意义,但可以帮助我们理解lquantize的作用。

      如果要聚合的表达式的值非常大,使用lquantize可能会输出太多信息,这种情况下可以使用quantize来聚合。

 


下面是一个统计执行程序系统调用的时间分布的D脚本: time.d
#!/usr/sbin/dtrace -s
syscall:::entry
{
        self->ts=timestamp;
}
syscall:::return
/self->ts/
{
        @time[execname]=quantize(timestamp-self->ts);
}

执行一段时间,按Ctrl+C中断。限于篇幅,下面只列出部分信息。

# ./time.d
dtrace: script './time.d' matched 462 probes
\^C

  sendmail
           value  ------------- Distribution ------------- count
            1024 |                                         0
            2048 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@          7
            4096 |@@@@                                     1
            8192 |@@@@                                     1
           16384 |                                         0

  sshd
           value  ------------- Distribution ------------- count
            1024 |                                         0
            2048 |@@@@@@@@@@@@@@@@@@@                      7
            4096 |@@@@@                                    2
            8192 |@@@@@                                    2
           16384 |@@@@@                                    2
           32768 |                                         0
           65536 |@@@@@                                    2
          131072 |                                         0

  

     以sendmail程序为例:

     系统调用执行时间(从entry到return)在大于等于2048纳秒并小于4096纳秒区间共有7次,在大于等于4096纳秒小于8192纳秒区间共有1次,在大于等于8192纳秒小于16384纳秒区间共有1次。


      在聚合一段时间后,可能需要对某个常数因子进行标准化(normalize),以更好的分析数据。如下例,我们按照执行的时间来标准化聚合数据,以得到每秒钟的系统调用数。

#pragma D option quiet
BEGIN
{
     start=timestamp;
     /\*获得起始的时间戳\*/
}
syscall:::entry
{
     @func[execname]=count();
     /\*按执行程序名称聚合系统调用的次数\*/
}
END
{
      normalize(@func,(timestamp-start)/1000000000);
      /\*退出时间戳减去启动时间戳就是运行的总时间,然后除以1000000000就转换为以秒为单位,再用这个描述去标准化系统掉调用次数的聚合\*/
}

      标准化不会修改原始数据。与标准化相对应的是“取消标准化(denormalize)"函数,此函数可以将聚合恢复到标准化之前的状态。

      聚合的数据会随着时间的增加而增加,你可以定期使用clear()和trunc()函数进行清除。clear()与trunc()的区别是clear()只会清除聚合的值,而trunc()则会同时清除聚合的值和键(key)。

       下面的例子每秒钟打印上一秒程序对系统调用的使用情况

 


# dtrace -n 'syscall:::entry{@counts[execname]=count();}tick-1sec{printa(@counts);trunc(@counts);}'
dtrace: description 'syscall:::entry' matched 232 probes
CPU     ID                    FUNCTION:NAME
  0  49050                       :tick-1sec
  syslogd                                                          16
  dtrace                                                           91

  0  49050                       :tick-1sec
  fmd                                                               1
  inetd                                                             1
  sendmail                                                         11
  sshd                                                             40
  dtrace                                                           45

  0  49050                       :tick-1sec
  sshd                                                              8
  dtrace                                                           42

  0  49050                       :tick-1sec
  sshd                                                              8
  dtrace                                                           39

  0  49050                       :tick-1sec
  nmbd                                                              4
  sshd                                                              8
  dtrace                                                           39

  0  49050                       :tick-1sec
  svc.configd                                                       1
  svc.startd                                                        1
  sshd                                                              8
  dtrace                                                           40

  0  49050                       :tick-1sec
  sshd                                                              8
  sendmail                                                         10
  dtrace                                                           41

\^C


      在分析实际的性能问题时,建议使用聚合作为你的出发点。

推理跟踪(Speculative Tracing)

      推理跟踪是DTrace提供的用于试探性地跟踪数据的工具,它可以在事后才来决定是将这些数据提交(commit())到跟踪缓冲区,还是放弃(discard())

      DTrace为推理跟踪提供了以下函数:

      表4 - DTrace推理函数

  

 函数名参数
说明
speculation

返回一个新的推理缓冲区的标志符
speculate
推理缓冲区的标志符ID
子句的其余部分会把数据存放到由ID指定的推理缓冲区里
commit
推理缓冲区的标志符ID提交与ID相关的推理缓冲区
discard
推理缓冲区的标志符ID放弃与ID

     


    

       推理缓冲区是一种有限的资源,如果无推理缓冲区可用,则speculation()返回0,表示无效的ID。

       speculate()操作要放在所有需要跟踪的数据记录操作之前。speculate()不能放在数据记录之后,否则DTrace会编译出错。不能对聚合操作,破坏性操作和exit()进行推理跟踪。通常的做法是将speculation()的结果赋给线程局部变量,然后使用该变量作为其它探测器的谓词以及speculate()的参数。

      当推理缓冲区被提交时,其数据将被复制到主缓冲区中。如果放弃推理缓冲区,其数据将被丢弃。

      下面的示例einvalspec.d展示了推理跟踪的一种应用方式,用来显示特定的代码路径。当系统调用返回错误代码EINVAL时,我们就打印出其代码路径。

       #pragma D option flowindet 表示当进入函数时,缩进显示,并加上前缀 ->,当退出函数时,取消缩进,并加上前缀<-

       #pragma D option nspec=200 表示推理缓冲区的个数(如果不指定,缺省只有一个)

       /\* \*/ 之间的内容是注释,

#!/usr/sbin/dtrace -s
#pragma D option flowindent
#pragma D option nspec=200
syscall:::entry                    /\*syscall提供器的entry探测器,在进入相应的系统调用之前被触发\*/
{
    self->spec=speculation();        /\*申请一个推理缓冲区\*/
    speculate(self->spec);            /\*把缺省操作(就是记录当前探测器的信息)的数据放到指定的推理缓冲区\*/
}
fbt:::                     /\*fbt是函数边界跟踪(Function Boundary Tracing)提供器,它提供了对所有函数的跟踪\*/
/self->spec/         /\*只针对已经申请了推理缓冲区的线程\*/
{
    speculate(self->spec);     /\*将函数名放到推理缓冲区\*/
}
syscall:::return                  /\*syscall提供器的return探测器,在退出相应的系统调用之后被触发\*/
/self->spec && arg0 != -1/      /\*系统调用的返回值不是-1(表示系统调用成功)\*/
{
    discard(self->spec);        /\*不是我们关心的情况,丢弃推理缓冲区数据\*/
    self->spec=0;                 /\* 赋0值,以释放变量空间(养成好习惯)\*/
}
syscall:::return                   /\*与上一个探测器描述一样(对于同样的探测器描述,可以指定多个子句块)\*/
/self->spec && arg0==-1 && errno==EINVAL/    /\*返回值为-1并且errno就是EINVAL\*/
{
    commit(self->spec);          /\*这就是我们想要的信息,因此提交推理缓冲区\*/
    committed=1;                   /\*赋值一个变量committed,以表示我们已经提交了\*/
}
syscall:::return                      /\*同上\*/
/committed/                           /\*是否已提交\*/
{      
    exit(0);                               /\*如果已提交,就退出DTrace\*/
}
syscall:::return                       /\*同上\*/
/self->spec && arg0==-1 && errno!=EINVAL/    /\*返回值为-1但是errno不是EINVAL(可能是其它错误)\*/
{
    discard(self->spec);           /\*也不是我们关心的,丢弃\*/
    self->spec=0;                    /\*释放变量空间\*/
}

       你还可以将上面程序中的EINVAL改为你关心的其它错误代码(具体错误代码信息,请查阅intro(2)手册页)。
  

 

 


 

评论:

发表一条评论:
  • HTML语法: 禁用
About

samwan

Search

Categories
Archives
« 四月 2014
星期日星期一星期二星期三星期四星期五星期六
  
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
   
       
今天