dtrace discuss - Feb 2008 - Emulating truss -u with DTrace...Impossible?

Hi All,
  I am trying to create a D script to emulate the command 
"truss -o ls.truss -f -d -l -t \!all -u
a.out,*::malloc,realloc,free,calloc,fork,vfork,mmap,munmap,mprotect,brk
/bin/firefox"

Is this possible with DTrace due to forking issues?  I created this D Script
which I beleive should capture all the calls that truss has but in reality only
captures about 1/4...Ideas?

#!/usr/sbin/dtrace -s
#pragma D option quiet
BEGIN{
self->start = vtimestamp;

printf("Base Time Stamp: %d [ %Y ] \n", vtimestamp, walltimestamp);
}
pid$target::malloc:entry
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer;
  printf("%d/1 at 1:\t%d.%0.8d ->
libc:%s(0x%x,0x%x,0x%x,0x%x)\n",pid, self->timer, self->extra,
probefunc, arg0, arg1, arg2, arg3);
  self->timer = 0;
  self->extra = 0;
}
pid$target::malloc:return
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer; 
     printf("%d/1 at 1:\t%d.%0.8d <- libc:%s() = 0x%p\n",pid,
self->timer, self->extra, probefunc,arg1);
       self->timer = 0;
       self->extra = 0;       
    self->trace = 0;
}

/*pid$target::malloc_internal:return,
pid$target::oversize:return
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer; 
     printf("%d/1 at 1:\t%d.%0.8d <- libc:malloc() = 0x%p\n",pid,
self->timer, self->extra,arg1);
       self->timer = 0;
       self->extra = 0;       
    self->trace = 0;
}*/
pid$target::realloc:entry
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer;
  printf("%d/1 at 1:\t%d.%0.8d ->
libc:%s(0x%x,0x%x,0x%x,0x%x)\n",pid, self->timer, self->extra,
probefunc, arg0, arg1, arg2, arg3);
  self->timer = 0;
  self->extra = 0;
  self->trace = 1;

}
pid$target::realloc:return
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer; 
     printf("%d/1 at 1:\t%d.%0.8d <- libc:%s() = 0x%p\n",pid,
self->timer, self->extra, probefunc,arg1);
       self->timer = 0;
       self->extra = 0;       
self->trace = 0;
}
pid$target::calloc:entry
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer;
  printf("%d/1 at 1:\t%d.%0.8d ->
libc:%s(0x%x,0x%x,0x%x,0x%x)\n",pid, self->timer, self->extra,
probefunc, arg0, arg1, arg2, arg3);
  self->timer = 0;
  self->extra = 0;
  self->trace = 1;

}
pid$target::calloc:return
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer; 
     printf("%d/1 at 1:\t%d.%0.8d <- libc:%s() = 0x%p\n",pid,
self->timer, self->extra, probefunc,arg1);
       self->timer = 0;
       self->extra = 0;       
    self->trace = 0;
}
pid$target::free:entry
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer;
  printf("%d/1 at 1:\t%d.%0.8d ->
libc:%s(0x%x,0x%x,0x%x,0x%x)\n",pid, self->timer, self->extra,
probefunc, arg0, arg1, arg2, arg3);
  self->timer = 0;
  self->extra = 0;
  self->trace = 1;

}
pid$target::free:return
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer; 
     printf("%d/1 at 1:\t%d.%0.8d <- libc:%s() = 0x%p\n",pid,
self->timer, self->extra, probefunc,arg1);
       self->timer = 0;
       self->extra = 0;       
    self->trace = 0;
}
pid$target::mmap:entry
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer;
  printf("%d/1 at 1:\t%d.%0.8d ->
libc:%s(0x%x,0x%x,0x%x,0x%x)\n",pid, self->timer, self->extra,
probefunc, arg0, arg1, arg2, arg3);
  self->timer = 0;
  self->extra = 0;
  self->trace = 1;

}
pid$target::mmap:return
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer; 
     printf("%d/1 at 1:\t%d.%0.8d <- libc:%s() = 0x%p\n",pid,
self->timer, self->extra, probefunc,arg1);
       self->timer = 0;
       self->extra = 0;       
    self->trace = 0;
}
pid$target::munmap:entry
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer;
  printf("%d/1 at 1:\t%d.%0.8d ->
libc:%s(0x%x,0x%x,0x%x,0x%x)\n",pid, self->timer, self->extra,
probefunc, arg0, arg1, arg2, arg3);
  self->timer = 0;
  self->extra = 0;
  self->trace = 1;

}
pid$target::munmap:return
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer; 
     printf("%d/1 at 1:\t%d.%0.8d <- libc:%s() = 0x%p\n",pid,
self->timer, self->extra, probefunc,arg1);
       self->timer = 0;
       self->extra = 0;       
    self->trace = 0;
}
pid$target::mprotect:entry
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer;
  printf("%d/1 at 1:\t%d.%0.8d ->
libc:%s(0x%x,0x%x,0x%x,0x%x)\n",pid, self->timer, self->extra,
probefunc, arg0, arg1, arg2, arg3);
  self->timer = 0;
  self->extra = 0;
  self->trace = 1;

}
pid$target::mprotect:return
{
self->timer = (vtimestamp - self->start)/10000000;
self->extra = (vtimestamp - self->start) - self->timer; 
     printf("%d/1 at 1:\t%d.%0.8d <- libc:%s() = 0x%p\n",pid,
self->timer, self->extra, probefunc,arg1);
       self->timer = 0;
       self->extra = 0;       
    self->trace = 0;
}


--
This message posted from opensolaris.org

is it possible to follow a forked process with a D script?  Would I have to
spawn a second dscript to follow it since the probes may no be enabled for the
forked process?


--
This message posted from opensolaris.org

I don''t think this is usually an issue because (with the exception of
apache using prefork) there are n''t that many multi-process apps out
there. Everything is multi-threaded.

Here is an example that will trace all libc method entries in a process and
it''s children.

Execute with: ./follow.d -p PID or ./follow.d -c CMD

*** START: follow.d ****

#!/usr/sbin/dtrace -s

#pragma D option destructive
#pragma D option quiet
#pragma D option switchrate=10

proc:::start
/progenyof($target)/
{
        printf("New process %d created, a progeny of %d\n", pid,
$target);
        stop();
        printf("Stopped %d to allow for tracing to be enabled\n",
pid);
        system("./tracepid.d -p %d", pid);
}

pid$target:libc.so.1::entry {
        printf("%s:%s:%s:%s\n", probeprov, probemod, probefunc,
probename);
}

syscall::rexit:entry
/pid == $target/
{
        exit(0);
}

*** END: follow.d ****

*** START: tracepid.d ****

!/usr/sbin/dtrace -s

#pragma D option destructive
#pragma D option quiet
#pragma D option switchrate=10

BEGIN
{
        printf("Resuming %d\n", $target);
}

pid$target:libc.so.1::entry {
        printf("%s:%s:%s:%s\n", probeprov, probemod, probefunc,
probename);
}

syscall::rexit:entry
/pid == $target/
{
        exit(0);
}

*** END: tracepid.d ****

It would be nice if there was a way to dynamically enable the pid provider for
an unknown pid but I haven''t seen any way to do it yet. Without this
ability there would be no way to aggregate userspace method completion times in
a process and all it''s dynamically created children.


--
This message posted from opensolaris.org

I am assuming you looked at DTT by Brendan Gregg which has a dtrace
script called dtruss..

On Feb 13, 2008 4:23 PM, David Weston <david.g.weston at saic.com>
wrote:
> is it possible to follow a forked process with a D script?  Would I have to
spawn a second dscript to follow it since the probes may no be enabled for the
forked process?
>
>
>
> --
> This message posted from opensolaris.org
> _______________________________________________
> dtrace-discuss mailing list
> dtrace-discuss at opensolaris.org
>


-- 
Asif Iqbal
PGP Key: 0xE62693C5 KeyServer: pgp.mit.edu

G''Day,

On Wed, Feb 13, 2008 at 04:55:06PM -0500, Asif Iqbal
wrote:
> I am assuming you looked at DTT by Brendan Gregg which has a dtrace
> script called dtruss..
dtruss follows syscalls (like truss -f), but not pid provider probes
(like truss -u).  dapptrace is more like truss -u, however I didn''t
code a follow mode.  As Matthieu showed, it''s possible to hack a
solution
using the system() call and the destructive pragma (which I believe is
the best solution if you really must do this).

When you want to track latencies across forked children, it''s often
possible to do so via the other providers - syscall, proc, sched, etc,
and using progenyof().  Although, David''s original script was tracing
some malloc() family calls - which can only be currently traced directly
via pid (a malloc USDT provider anyone?).

David, the syscall provider can give you mmap(), munmap() and mprotect(),
and progenyof() can follow children.  It might be possible to infer some
malloc(), calloc() and free() events via syscall brk() and vminfo probes.

Brendan

> On Feb 13, 2008 4:23 PM, David Weston <david.g.weston at saic.com>
wrote:
> > is it possible to follow a forked process with a D script?  Would I
have to spawn a second dscript to follow it since the probes may no be enabled
for the forked process?
> >
> >
> >
> > --
> > This message posted from opensolaris.org
> > _______________________________________________
> > dtrace-discuss mailing list
> > dtrace-discuss at opensolaris.org
> >
> 
> 
> 
> -- 
> Asif Iqbal
> PGP Key: 0xE62693C5 KeyServer: pgp.mit.edu
> _______________________________________________
> dtrace-discuss mailing list
> dtrace-discuss at opensolaris.org
-- 
Brendan
[CA, USA]