2 Replies Latest reply: Feb 23, 2012 12:09 AM by 810988 RSS

    dtrace buffer monitor script not working as expected

    810988
      I wrote a dtrace script to monitor the bytes returned by the read() system call to the user programme, but I am getting really strange results. basically, if I type between 4 and 7 characters, I see the bytes 4-7 as I would expect, the other bytes however are not printed correctly.

      Here's the code ...

      #pragma D option quiet

      self char *addr;
      self uint64_t *bufferaddr;

      syscall::read:entry
      /execname == "foobar"/
      {
      printf("%6d %6d %6d %-8s %-11s %d %X %d\n", uid,pid, ppid, execname, probefunc, arg0,arg1,arg2);
      self->bufferaddr=(uint64_t *)arg1;
      }
      syscall::read:return
      /execname == "foobar"/
      {
      printf("%6d %6d %6d %-8s %-11s %d (read return)\n", uid,pid, ppid, execname, probefunc, arg0);
      self->nbytes=arg0;
      self->addr=(char *) copyin((uintptr_t) self->bufferaddr, self->nbytes);
      self->bufferaddr=0;
      }
      syscall::read:return
      /execname == "foobar" && self->nbytes!=0/
      {
      printf("bytes=%d\n",self->nbytes);
      }
      syscall::read:return
      /execname == "foobar" && self->nbytes > 0/
      {
      printf(" 0- 3: %02x %02x %02x %02x \n", self->addr[0], self->addr[1], self->addr[2], self->addr[3] );
      }

      syscall::read:return
      /execname == "foobar" && self->nbytes > 4/
      {
      printf(" 4- 7: %02x %02x %02x %02x \n", self->addr[4], self->addr[5], self->addr[6], self->addr[7] );
      }

      syscall::read:return
      /execname == "foobar" && self->nbytes > 8/
      {
      printf(" 8-11: %02x %02x %02x %02x \n", self->addr[8], self->addr[9], self->addr[10], self->addr[11] );
      }

      syscall::read:return
      /execname == "foobar" && self->nbytes > 12/
      {
      printf("12-15: %02x %02x %02x %02x \n", self->addr[12], self->addr[13], self->addr[14], self->addr[15] );
      }

      syscall::read:return
      /execname == "foobar" && self->nbytes > 16/
      {
      printf("16-20: %02x %02x %02x %02x \n", self->addr[16], self->addr[17], self->addr[18], self->addr[19] );
      }

      syscall::read:return
      {
      self->addr=0;
      self->nbytes=0;
      }

      and i copy /bin/cat to /tmp/foobar so I have a pogram called foo bar


      When I run

      dtrace -Cs myscript &
      truss -tread /tmp/foobar
      123456

      I get

      0 9207 9206 foobar read 0 80621B8 8192
      read(0, 0x080621B8, 8192) (sleeping...)
      123456 <------------------------------------------ this is what I type as input
      read(0, " 1 2 3 4 5 6\n", 8192) = 7
      123456
      0 9207 9206 foobar read 7 (read return)
      bytes=7
      0- 3: 03 00 00 00
      4- 7: 35 36 0a 00
      0 9207 9206 foobar read 0 80621B8 8192
      read(0, 0x080621B8, 8192) (sleeping...)

      As you can see bytes 4-7 are correct (5,6, newline)


      ---> Any one any idea why my bytes 0-3 are wrong (and, incidentally so are 8 onewards)
      ---> Is there a better way of doing this?

      regards
      Monathan

      Edited by: m1436 on Feb 6, 2012 7:59 PM
        • 1. Re: dtrace buffer monitor script not working as expected
          kvh
          Let me first explain why your script is not working for you.

          Basically, the problem you encounter is a result of a common misconception about copyin(). It is intended to be used to copy content of userspace memory into a scratch buffer so that it can be accessed directly from within kernel space (where the DTrace core executes). That said, it is often interpreted as somehow being equivalent to malloc() whereas in reality it actually works like alloca() instead. So, what you are seeing is basically the artefact of the scratch buffer being overwritten with other data. And unfortunately, that is perfectly legal.

          The content of the scratch buffer pointed to by self->addr in your script is only valid for as long as the specific probe enabling is executing (it is clause-local). So, your clauses to print out the actual bytes in the buffer are looking at a buffer that is for all intends and purposes no longer reserved, and therefore you are looking at it after other data was written to the scratch space.

          So... in order for this to work, you should do things a bit different. Rather than trying to get a copy of the buffer in one clause, and then read from it in following clauses, you can simply collect the buffer address in the entry read:entry clause, get the number of bytes read in the first read:return clause, and then for every clause in which you print 4 bytes do the following (example for bytes 4-7):

          syscall::read:return
          /execname == "foobar" && self->nbytes > 4/
          {
          this->addr = (char *)copyin((uintptr_t)self->bufferaddr + 4, 4);
          printf(" 4- 7: %02x %02x %02x %02x\n", this->addr[0], this->addr[1], this->addr[2], this->addr[3]);
          }

          So basically, for every clause that print 4 bytes you copyin those bytes, and then print them out.
          • 2. Re: dtrace buffer monitor script not working as expected
            810988
            Thanks, I wasn't aware of the clause-local bit. Makes sense -- and works!