用dTrace捕捉内存分配于释放

Posted on 七月 1, 2008 by arrowpig1979

dTrace是Solaris 10中一个非常强大的工具，有了它，不需要更改代码，就可以“打入”程序内部“探听”我所要知道的一切。其中一个非常重要的就是记录内存分配与释放，然后方便我进一步的分析。

 

我们所要做的就是写一个很简单的dtrace的脚本，比如叫memlog.d

 

上王道：

 

pid$1:libc:malloc:entry    //->当malloc被调用的时候执行的动作
{    
        self->trace = 1;      //设一个标志位，用于确定只捕捉已经被置位的return动作
        self->size = arg0;   //arg0就是传给malloc的第一个参数，就是需要分配的内存大小
}

pid$1:libc:malloc:return     //->当malloc返回的时候
/self->trace == 1 && self->size > 0/     //->条件：只捕捉trace==1并且内存分配>0的动作
{
        printf("Ptr=0x%p Size=%d TS=%d AllocTime=%Y", arg1, self->size, timestamp, walltimestamp);         //打印需要的信息，Ptr和Size很重要，能够方便我们查找内存泄漏
        ustack();           //打印调用栈，这点很重要，能够帮助我们对应源代码
        self->trace = 0;
        self->size = 0; 
}

 

以上两段代码就能捕捉所有通过malloc来分配内存的情况。pid$1是一个pid provider，用来探听给定的进程，进程ID 是调用dtrace 脚本的第一个参数。这样我们就可以通过命令参数传入我关心的进程ID。

 

下面看内存释放：->相信一看就懂了

pid$1:libc:free:entry
{
        printf("Ptr=0x%p Size=%d TS=%d FreeTime=%Y", arg0, self->size, timestamp, walltimestamp);
        ustack();
}

 

 

其实分配内存还有calloc和realloc,都是类似的：

pid$1:libc:realloc:entry
/self->trace == 1 && self->size > 0/
{
        self->trace = 1;
        self->size = arg1;
        self->oldptr = arg0;
}

 

pid$1:libc:realloc:return
/self->trace == 1 && self->size > 0/
{
        printf("Ptr=0x%p Oldptr=0x%p Size=%d TS=%d ReallocTime=%Y", arg1, self->oldptr, self->size, timestamp, walltimestamp);
        ustack();
        self->trace = 0;
        self->size = 0;
}

 

pid$1:libc:calloc:entry
/self->trace == 1 && self->size > 0/
{
        self->trace = 1;
        self->size = arg0 * arg1;
}

 

pid$1:libc:calloc:return
/self->trace == 1 && self->size > 0/
{
        printf("Ptr=0x%p Size=%d TS=%d CallocTime=%Y", arg1, self->size, timestamp, walltimestamp);
        ustack();
        self->trace = 0;
        self->size = 0;
}

 

 

好了，代码贴完了，看看怎么运行吧～假设我的程序名字叫jianxu_arrowpig

-bash-3.00$ ps -ef | grep jianxu_arrowpig

就可以拿到进程号，假设进程ID=6666

运行dtrace:

-bash-3.00$ dtrace -s memlog.d 6666

 

 

给一段实例输出吧：

-bash-3.00$ sudo dtrace -s memlog.d 6666   //–>我这里用sudo是因为dtrace 需要 root运行权限。
dtrace: script ‘mallco.d’ matched 7 probes
CPU     ID                    FUNCTION:NAME
  0    534                    malloc:return Ptr=0×9890130 Size=20 TS=27532231842644751 AllocTime=2008 Jun 27 02:25:17
              libc.so.1`malloc+0×49
              scrubber`_ZN23PartitionOutputDbAction4InitEv+0x69a
              scrubber`_ZN23PartitionOutputDbActionC1EP7XMLNode+0x10b6
              scrubber`_Z26ParseSearchTransformationsP7XMLNodePFvPKcE+0×3442
              scrubber`_Z8ReadFileR10FileReader+0x3fb
              scrubber`_Z10RefreshXMLPKc+0xc4
              scrubber`_Z13DaemonProcessv+0x1f9b
              scrubber`main+0xbd6
              scrubber`_start+0×80

 

 

注意，给出的 trace是c++ mangled的symbol如果要看unmangled name:

-bash-3.00$ gc++filt _ZN23PartitionOutputDbActionC1EP7XMLNode
PartitionOutputDbAction::PartitionOutputDbAction(XMLNode*)

 

通常我会重定向输出，这样可以用perl做offline的分析：

-bash-3.00$ sudo dtrace -s memlog.d 6666 > mem.log

 

还真巧了，今天就在查memory leak.
egrep ‘malloc:return|free:entry’ mem.log > mem.log.simple  //–>先弄个小点的
cat mem.log.simple | perl memanalyze.pl > memleak.log
 
##memanalyze.pl ##写了个很傻的，不知道好用不好用
#! /usr/bin/perl -wuse strict;use warnings;
my $line;

my %result;

while ($line=<STDIN>)

{   

     if(  $line=~/malloc/:return/sPtr=0x([0-9a-f]+)/sSize=(/d+)/sTS=(/d+)/)  

    {       

             #Use Ptr as the Key, Hash value is Ts, so I can locate in the original log       

             $result{$1}= $3;   

     }   

     elsif( $line=~/free/:entryn/sPtr=0x([0-9a-f]+)/sSize=(/d+)/sTS=(/d+)/)  

     {       

             delete $result{$1};  #delete the entry   

      }

}

my $MyPtr;

my $MyTs;

while ( ($MyPtr, $MyTs) = each %result)

{   

     print "Ptr=0x$MyPtr, TS=$MyTs/n";

}