new varwatch example

["Frank Ch. Eigler" <fche at redhat dot com>]

Hi -

With the new @defined() and try{}/catch{} constructs, a simple generic
script can be used to robustly monitor the evolution of $variables in
a program.  This could apply to global or local variables, even on a
per-statement basis, such as in this example:


# stap -wv varwatch.stp 'kernel.statement("do_sys_open@fs/open.c:*")' '$$vars'
Pass 1: parsed user script and 65 library script(s) using 48648virt/19500res/1688shr kb, in 110usr/10sys/127real ms.
Pass 2: analyzed script: 18 probe(s), 12 function(s), 2 embed(s), 2 global(s) using 197792virt/68912res/2756shr kb, in 640usr/170sys/811real ms.
Pass 3: translated to C into "/tmp/stapRq6RS2/stap_cc7f87b98905b3ca5cae3bdf214f2ecd_13324.c" using 195416virt/71828res/5748shr kb, in 300usr/20sys/315real ms.
Pass 4: compiled C into "stap_cc7f87b98905b3ca5cae3bdf214f2ecd_13324.ko" in 1750usr/460sys/2141real ms.
Pass 5: starting run.
kernel.statement("do_sys_open@fs/open.c:1029") $$vars changed in thread 3897 from  to dfd=0xffffffffffffff9c filename=0x2abd51712421 flags=0x8000 mode=0x1b6 tmp=? fd=?
kernel.statement("do_sys_open@fs/open.c:1033") $$vars changed in thread 3897 from dfd=0xffffffffffffff9c filename=0x2abd51712421 flags=0x8000 mode=0x1b6 tmp=? fd=? to dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=? fd=?
kernel.statement("do_sys_open@fs/open.c:1034") $$vars changed in thread 3897 from dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=? fd=? to dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=? fd=0x5f182000
kernel.statement("do_sys_open@fs/open.c:1035") $$vars changed in thread 3897 from dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=? fd=0x5f182000 to dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=0xffff88005f182000 fd=0x5f182000
kernel.statement("do_sys_open@fs/open.c:1036") $$vars changed in thread 3897 from dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=0xffff88005f182000 fd=0x5f182000 to dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=0xffff88005f182000 fd=0x8
kernel.statement("do_sys_open@fs/open.c:1041") $$vars changed in thread 3897 from dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=0xffff88005f182000 fd=0x8 to dfd=? filename=? flags=0x8000 mode=0x1b6 tmp=0xffff88005f182000 fd=0x8
kernel.statement("do_sys_open@fs/open.c:1042") $$vars changed in thread 3897 from dfd=? filename=? flags=0x8000 mode=0x1b6 tmp=0xffff88005f182000 fd=0x8 to dfd=? filename=? flags=? mode=? tmp=0xffff88005f182000 fd=0x8
kernel.statement("do_sys_open@fs/open.c:1045") $$vars changed in thread 3897 from dfd=? filename=? flags=? mode=? tmp=0xffff88005f182000 fd=0x8 to dfd=0xffffffffea9c8f00 filename=? flags=0x20 mode=0x6abdca10 tmp=0xffff88005f182000 fd=0x8
kernel.statement("do_sys_open@fs/open.c:1048") $$vars changed in thread 3897 from dfd=0xffffffffea9c8f00 filename=? flags=0x20 mode=0x6abdca10 tmp=0xffff88005f182000 fd=0x8 to dfd=0xffffffffea9c8f00 filename=? flags=0x20 mode=0x6abdca10 tmp=0xffff88005f182000 fd=?
kernel.statement("do_sys_open@fs/open.c:1029") $$vars changed in thread 3897 from dfd=0xffffffffea9c8f00 filename=? flags=0x20 mode=0x6abdca10 tmp=0xffff88005f182000 fd=? to dfd=0xffffffffffffff9c filename=0x2abd51712421 flags=0x8000 mode=0x1b6 tmp=? fd=?
kernel.statement("do_sys_open@fs/open.c:1033") $$vars changed in thread 3897 from dfd=0xffffffffffffff9c filename=0x2abd51712421 flags=0x8000 mode=0x1b6 tmp=? fd=? to dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=? fd=?
kernel.statement("do_sys_open@fs/open.c:1034") $$vars changed in thread 3897 from dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=? fd=? to dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=? fd=0x5f182000
kernel.statement("do_sys_open@fs/open.c:1035") $$vars changed in thread 3897 from dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=? fd=0x5f182000 to dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=0xffff88005f182000 fd=0x5f182000
kernel.statement("do_sys_open@fs/open.c:1036") $$vars changed in thread 3897 from dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=0xffff88005f182000 fd=0x5f182000 to dfd=0xffffffffffffff9c filename=? flags=0x8000 mode=0x1b6 tmp=0xffff88005f182000 fd=0x8
[...]


# cat varwatch.stp
#! /usr/bin/env stap

global var, varerr

probe $1 {
  t=tid() # or t=0 for thread-agnostic checking
  if (@defined($2)) {
     try {
         newvar = $2;
         if (var[t] != newvar) {
            printf("%s %s changed in thread %d from %s to %s\n", pp(), @2, t, sprint(var[t]), sprint(newvar));
            var[t] = newvar;
         }
     } catch { varerr ++ }  # error during $2 resolution or perhaps var[] assignment
  }
}

probe kprocess.release { # if using per-thread checking
  delete var[$p->pid] # thread
}

probe never {
  var[0]=""  # assigns a type to var in case no probes match $1 above
}

probe error,end {
  if (varerr) printf("%s %s access errors: %d", @1, @2, varerr);
}


- FChE