14.3 Using DTrace to Test Modules with Static Probes

You can use DTrace to display information when one of the embedded static probes in a module fires.

To test the example module revdev.ko:

  1. Set up a udev rule to create the /dev/revdev device file:

    # echo "KERNEL==\"revdev\", MODE=\"0660\"" > /etc/udev/rules.d/10-revdev.rules
  2. Load the dtrace, sdt, systrace, and revdev.ko modules:

    # modprobe dtrace
    # modprobe sdt
    # modprobe systrace
    # insmod revdev.ko

    You can use dtrace to test that the probes are now available:

    # dtrace -l -m revdev
       ID   PROVIDER            MODULE                          FUNCTION NAME
        4        sdt            revdev                      revdev_ioctl ioctl-return
        5        sdt            revdev                      revdev_ioctl ioctl-entry
        6        sdt            revdev                      revdev_write write-return
        7        sdt            revdev                      revdev_write write-entry
        8        sdt            revdev                       revdev_read read-return
        9        sdt            revdev                       revdev_read read-entry
  3. Enter the following DTrace script (traceflow):

    #!/usr/sbin/dtrace -qs
    #pragma D option nspec=10
    
    self int indent;
    
    syscall:::entry
    /execname == "testrevdev"/
    {
      self->specflag = 0;
      self->spec = speculation();
      self->indent += 2;
      speculate(self->spec);
    }
    
    syscall:::entry
    /self->spec/
    {
      speculate(self->spec);
      printf("%*s ", self->indent, "->");
      printf("%s() entry\n",probefunc);
      self->indent += 2;
    }
    
    syscall:::return
    /self->spec/
    {
      speculate(self->spec);
      self->indent -= 2;
      printf("%*s ", self->indent, "<-");
      printf("%s() return\n",probefunc);
    }
    
    syscall:::return
    /self->spec && self->specflag == 0/
    {
      discard(self->spec);
      self->indent -= 2;
      self->spec = 0;
    }
    
    syscall:::return
    /self->spec && self->specflag == 1/
    {
      commit(self->spec);
      self->indent -= 2;
      self->spec = 0;
    }
    
    sdt:revdev::ioctl-entry
    /self->spec/
    {
      speculate(self->spec);
      self->specflag = 1;
      printf("%*s ", self->indent, "=>");
      printf("%s() entry file: %s cmd: %d arg: %d\n",
             probefunc, d_path(&(((struct file *)arg0)->f_path)), arg1, arg2);
    }
    
    sdt:revdev::ioctl-return
    /self->spec/
    {
      speculate(self->spec);
      printf("%*s ", self->indent, "<=");
      printf("%s() return cpstr: %s\n", probefunc, stringof((char*)arg0));
    }
    
    sdt:revdev::read-entry
    /self->spec/
    {
      speculate(self->spec);
      self->specflag = 1;
      printf("%*s ", self->indent, "=>");
      printf("%s() entry file: %s devbuf: %s\n",
             probefunc, d_path(&(((struct file *)arg0)->f_path)),
             stringof((char *)arg1));
    }
    
    sdt:revdev::read-return
    /self->spec/
    {
      speculate(self->spec);
      printf("%*s ", self->indent, "<=");
      printf("%s() return string: %s len: %d\n",
             probefunc, stringof((char *)arg0), arg1);
    }
    
    sdt:revdev::write-entry
    /self->spec/
    {
      speculate(self->spec);
      self->specflag = 1;
      printf("%*s ", self->indent, "=>");
      printf("%s() entry file: %s string: %s len: %d\n",
             probefunc, d_path(&(((struct file *)arg0)->f_path)),
             stringof((char *)arg1), arg2);
    }
    
    sdt:revdev::write-return
    /self->spec/
    {
      speculate(self->spec);
      printf("%*s ", self->indent, "<=");
      printf("%s() return string: %s len: %d\n",
             probefunc, stringof((char *)arg0), arg1);
    }

    When one of the inserted probes fires, traceflow displays information about data values in the module by using the probe argument variables (arg0, arg1, arg2,...).

    Note

    Argument variables that return pointer types such as file * and char * must be explicitly cast.

    The script uses d_path and stringof to create printable file paths and strings. For example, (struct file *)arg0 casts the value of arg0 to a file pointer (struct file *). The f_path member of the struct file contains the path structure (struct path) for a file. As d_path takes a path pointer (struct path *) as its argument, the & operator is used to return a pointer to the struct path.

    See Section 4.6.8, “d_path” and Section 2.11.4, “String Conversion”.

  4. Use chmod to make traceflow executable:

    # chmod 750 tracedev
  5. In one window, run traceflow:

    # ./traceflow
  6. In another window, run testrevdev and enter input, for example:

    # ./testrevdev
    Write: hello
     Read: olleh
    Write: world
     Read: dlrow
    Write: ioctl
    Write: ioctl
    Write: exit 

    In the window where traceflow is running, you should see output similar to the following as DTrace responds to the probes in revdev.ko firing:

    # ./traceflow 
    -> write() entry
      => revdev_write() entry file: /dev/revdev string: hello len: 5
      <= revdev_write() return string: hello len: 5
    <- write() return
    -> read() entry
      => revdev_read() entry file: /dev/revdev devbuf: hello
      <= revdev_read() return string: olleh len: 5
    <- read() return
    -> write() entry
      => revdev_write() entry file: /dev/revdev string: world len: 5
      <= revdev_write() return string: world len: 5
    <- write() return
    -> read() entry
      => revdev_read() entry file: /dev/revdev devbuf: world
      <= revdev_read() return string: dlrow len: 5
    <- read() return
    -> ioctl() entry
      => revdev_ioctl() entry file: /dev/revdev cmd: 128 arg: 3
      <= revdev_ioctl() return cpstr: Odd
    <- ioctl() return
    -> ioctl() entry
      => revdev_ioctl() entry file: /dev/revdev cmd: 128 arg: 4
      <= revdev_ioctl() return cpstr: Even
    <- ioctl() return