Userland DTrace support on FreeBSD

NOTE: The information on this page is outdated and may be inaccurate. The dtrace chapter in the handbook will be updated with information on userland dtrace: http://www.freebsd.org/doc/handbook/dtrace.html

FreeBSD 9.0 supports the following new providers:

New neat features:

make.conf configuration

The following might help with userland DTrace (depends on what you want to do)

STRIP=
CFLAGS+=-fno-omit-frame-pointer

pid provider

The pid provider allows the creation of probes that match a particular function inside your userland program.

https://wikis.oracle.com/display/DTrace/pid+Provider

pid provider example

Suppose we have the following C program (test.c):

#include <unistd.h>

int
main()
{
        for (;;)
                sleep(1);
}

We want to know when we enter the main function and the sleep function. The following D script accomplishes this:

pid$target:test:main:entry
{
}
pid$target:libc*:sleep:entry
{
}

Call this script pid.d and execute DTrace:

# dtrace -s pid.d -c test
dtrace: script 'pid.d' matched 2 probes
dtrace: buffer size lowered to 2m
CPU     ID                    FUNCTION:NAME
  0  22753                       main:entry 
  0  22754                     _sleep:entry 
  0  22754                     _sleep:entry 
  0  22754                     _sleep:entry 
  0  22754                     _sleep:entry 
  0  22754                     _sleep:entry 
  0  22754                     _sleep:entry 
^C
  0  22754                     _sleep:entry 

USDT (Userland Statically Defined Traces)

If you know what SDT means, USDT is easy to understand for you (think userland).

Otherwise, please read: http://www.solarisinternals.com/wiki/index.php/DTrace_Topics_USDT http://www.ibm.com/developerworks/aix/library/au-dtraceprobes.html https://wikis.oracle.com/display/DTrace/Statically+Defined+Tracing+for+User+Applications

USDT example

The following example is based on https://blogs.oracle.com/ahl/entry/user_land_tracing_gets_better

First we need to create a DTrace provider. We'll use a database as an example:

% cat provider.d
provider database {
        probe query__start(char *);
        probe query__done(char *);
};

If you run:

dtrace -h -s provider.d

You'll have a provider.h file that you can now include in your program:

% cat provider.h 
/*
 * Generated by dtrace(1M).
 */

#ifndef _PROVIDER_H
#define _PROVIDER_H

#include <unistd.h>

#ifdef  __cplusplus
extern "C" {
#endif

#if _DTRACE_VERSION

#define DATABASE_QUERY_DONE(arg0) \
        __dtrace_database___query__done(arg0)
#ifndef __sparc
#define DATABASE_QUERY_DONE_ENABLED() \
        __dtraceenabled_database___query__done()
#else
#define DATABASE_QUERY_DONE_ENABLED() \
        __dtraceenabled_database___query__done(0)
#endif
#define DATABASE_QUERY_START(arg0) \
        __dtrace_database___query__start(arg0)
#ifndef __sparc
#define DATABASE_QUERY_START_ENABLED() \
        __dtraceenabled_database___query__start()
#else
#define DATABASE_QUERY_START_ENABLED() \
        __dtraceenabled_database___query__start(0)
#endif


extern void __dtrace_database___query__done(char *);
#ifndef __sparc
extern int __dtraceenabled_database___query__done(void);
#else
extern int __dtraceenabled_database___query__done(long);
#endif
extern void __dtrace_database___query__start(char *);
#ifndef __sparc
extern int __dtraceenabled_database___query__start(void);
#else
extern int __dtraceenabled_database___query__start(long);
#endif

#else

#define DATABASE_QUERY_DONE(arg0)
#define DATABASE_QUERY_DONE_ENABLED() (0)
#define DATABASE_QUERY_START(arg0)
#define DATABASE_QUERY_START_ENABLED() (0)

#endif


#ifdef  __cplusplus
}
#endif

#endif  /* _PROVIDER_H */

We'll now use a simple C source file to trigger these probes. Edit src.c and write:

#include <stdio.h>

#include <sys/sdt.h>
#include "provider.h"

int
main(void)
{
        /* Give us time to start DTrace */
        sleep(5);

        DATABASE_QUERY_START("SELECT * FROM apples");
        /* simulate a long query */
        sleep(1);
        DATABASE_QUERY_DONE("TOO MANY APPLES");

        return (0);
}

You should also create a Makefile to make your life easier:

SRCS=main.c provider.d
PROG=db
MK_MAN=no

.include <bsd.prog.mk>

Please note that on FreeBSD, you must link your program with libelf!. (bsd.dtrace.mk does this for you)

After typing make, you should have a executable file called db. Before running it, you should make sure that you have a DTrace script for the new provider:

% cat db.d 
database$target:::query-start
{
        self->ts = timestamp;
        printf("Query: %s", copyinstr(arg0));
}

database$target:::query-done
{
        printf("Query time: %d ms / Result: %s",
            (timestamp - self->ts) / 1000000,
            copyinstr(arg0));

}

This will show us how much time it takes to execute that query (if you understood the above C program, we should have 1000 ms + overhead).

Now run the following command to have dtrace(1) execute db, attach to it and run the DTrace script db.d:

# dtrace -s db.d -c ./db
dtrace: script 'db.d' matched 2 probes
dtrace: buffer size lowered to 2m
CPU     ID                    FUNCTION:NAME
  0  22766                 main:query-start Query: SELECT * FROM apples
  0  22765                  main:query-done Query time: 1005 ms / Result: TOO MANY APPLES
^C

plockstat provider

TBD

plockstat example

TBD

dtruss

dtruss example

# dtruss date      
dtrace: buffer size lowered to 2m
Tue Aug 31 23:17:36 WEST 2010
SYSCALL(args)            = return
mmap(0x0, 0x8000, 0x3)           = 5455872 0
issetugid(0x0, 0x0, 0x0)                 = 0 0
open("/etc/libmap.conf\0", 0x0, 0x1B6)           = -1 Err#2
open("/var/run/ld-elf.so.hints\0", 0x0, 0x2F)            = 3 0
read(0x3, "Ehnt\001\0", 0x80)            = 128 0
lseek(0x3, 0x80, 0x0)            = 128 0
read(0x3, "/lib:/usr/lib:/usr/lib/compat:/usr/local/lib:/usr/local/lib/compat/pkg:/usr/local/lib/compat:/usr/local/lib/zsh\0", 0x70)             = 112 0
close(0x3)               = 0 0
access("/lib/libc.so.7\0", 0x0, 0x0)             = 0 0
open("/lib/libc.so.7\0", 0x0, 0x63E1A0)          = 3 0
fstat(0x3, 0x7FFFFFFFE380, 0x0)          = 0 0
pread(0x3, "\177ELF\002\001\001\t\0", 0x1000)            = 4096 0
mmap(0x0, 0x245000, 0x0)                 = 6598656 0
mmap(0x80064B000, 0x109000, 0x5)                 = 6598656 0
mmap(0x800854000, 0x21000, 0x3)          = 8732672 0
mprotect(0x800875000, 0x1B000, 0x3)              = 0 0
close(0x3)               = 0 0
sysarch(0x81, 0x7FFFFFFFE458, 0x0)               = 0 0
mmap(0x0, 0x19000, 0x3)          = 5488640 0
sigprocmask(0x1, 0x80063D080, 0x7FFFFFFFE420)            = 0x0 0
sigprocmask(0x3, 0x80063D090, 0x0)               = 0x0 0
sigprocmask(0x1, 0x80063D080, 0x7FFFFFFFE3F0)            = 0x0 0
sigprocmask(0x3, 0x80063D090, 0x0)               = 0x0 0
clock_gettime(0xD, 0x7FFFFFFFE580, 0x0)          = 0 0
access("/etc/localtime\0", 0x4, 0x0)             = 0 0
open("/etc/localtime\0", 0x0, 0x1)               = 3 0
fstat(0x3, 0x7FFFFFFEF730, 0x0)          = 0 0
close(0x3)               = 0 0
issetugid(0x0, 0x0, 0x0)                 = 0 0
open("/usr/share/zoneinfo/posixrules\0", 0x0, 0x2E)              = 3 0
fstat(0x3, 0x7FFFFFFE0790, 0x0)          = 0 0
close(0x3)               = 0 0
fstat(0x1, 0x7FFFFFFFE3E0, 0x0)          = 0 0
readlink("/etc/malloc.conf\0", 0x7FFFFFFFDFB0, 0x400)            = -1 Err#2
issetugid(0x0, 0x0, 0x0)                 = 0 0
break(0x800000, 0x0, 0x0)                = 0 0
mmap(0x0, 0x400000, 0x3)                 = 8978432 0
mmap(0x800C90000, 0x370000, 0x3)                 = 13172736 0
munmap(0x800890000, 0x370000)            = 0 0
ioctl(0x1, 0x402C7413, 0x7FFFFFFFE430)           = 0 0
write(0x1, "Tue Aug 31 23:17:36 WEST 2010\n\0", 0x1E)            = 30 0
sigprocmask(0x1, 0x80063D080, 0x7FFFFFFFE4B0)            = 0x0 0
sigprocmask(0x3, 0x80063D090, 0x0)               = 0x0 0
sigprocmask(0x1, 0x80063D080, 0x7FFFFFFFE460)            = 0x0 0
sigprocmask(0x3, 0x80063D090, 0x0)               = 0x0 0

One neat feature of dtruss is that you can combine kernel system calls with userland stack traces. Here's an example:

dtrace: buffer size lowered to 2m
SYSCALL(args)            = return
mmap(0x0, 0x8000, 0x3)           = 5455872 0

              ld-elf.so.1`__sys_mmap+0xc
              ld-elf.so.1`malloc+0x15e
              ld-elf.so.1`strdup+0x2a
              ld-elf.so.1`xstrdup+0x9
              ld-elf.so.1`_rtld+0x19c
              ld-elf.so.1`0x800507849

issetugid(0x0, 0x0, 0x0)                 = 0 0

              ld-elf.so.1`__sys_issetugid+0xc
              ld-elf.so.1`0x800507849

...

write(0x1, "Tue Aug 31 23:19:20 WEST 2010\n\0", 0x1E)            = 30 0

              libc.so.7`__sys_write+0xc
              libc.so.7`_swrite+0x50
              libc.so.7`__sflush+0x56
              libc.so.7`fflush+0x34
              date`main+0x425
              date`pututxline@@FBSD_1.2+0x2fa
              ld-elf.so.1`0x800536000


CategoryDtrace CategoryStale

DTrace/userland (last edited 2018-04-03T22:35:09+0000 by OleksandrTymoshenko)