Some notes on translation

[Tom Zanussi <zanussi at us dot ibm dot com>]

Hi,

I've been thinking about what work needs to be done on the user side
of systemtap, more specifically about things that correspond to the
translation phase and bits of the execution and output phases.  To
help me think more concretely about the issues at hand, I came up with
a few of what I think are simple and typical probes, and elaborated on
what might be produced for each one.  It was a useful exercise, but it
seemed to raise more questions than it answered...

Anyway, here are my current notes.  Since the probe language and
runtime functions are still in flux, I didn't pay too much attention
to getting those things correct and of course the generated code is
also just pseudocode.  None of these examples generates any
safety-checking or locking code - I'm kind of assuming, probably
wrongly, that that would be straightforward boilerplate-type stuff
tacked on to certain language elements.  Some notes on the notes:

- self->xxx means xxx is a thread-local variable

- $xxx is shorthand for values to be substituted by runtime library
  functions or probe variables, similar to Perl interpolation

- rtl_xxx() are runtime library functions.  rtl_set_tl_val() is the
  runtime function used for setting a thread-local variable value,
  rtl_get_tl_val() for getting one, and I assume they automatically
  use the current thread under the covers.

- XX_SYMBOL_LOC() are symbolic systemtap language variable locations.
  This basically is shorthand for saying that I don't really know where
  these come from or how they end up being translated into code - I need
  to think about it some more but in any case I assume these originate
  from the parser or another pre-translation step and end up generating
  the code needed to access or assign to the given variable.  There seem
  to be 3 separate namespaces that we need to know the locations of
  variables in: thread-local, external, and probe-global.  The
  corresponding locations of variables in these namespaces would be:
  TL_SYMBOL_LOC(), EXTERN_SYMBOL_LOC(), and SYMBOL_LOC().

=======================

Here's a simple probe that accumulates time spent in read(2) for all
processes.  In terms of what gets generated for the probe module, this
is pretty much as simple as it gets (entry/exit probes on a single
function).  It uses jprobes for the entry probe:

/* total time spent in read() for all processes */
probe syscall:entry("read")
{
	self->entry_time = $timestamp;
	self->my_count = count;
	self->my_fd = fd;
}


probe syscall:exit("read")
{
	if (self->entry_time) {
		read_times[$syscall_name] += $timestamp - self->entry_time;
		self->entry_time = 0;
	}
}

----generated code----

And here's a rough idea of the module code that might be generated:

/* generated entry point jprobes handler */
static ssize_t jsys_read(unsigned int fd, char __user *buf, size_t count)
{
	timestamp_t entry_time = rtl_cur_timestamp();
	rtl_set_tl_val(TL_SYMBOL_LOC(entry_time), entry_time);
	rtl_set_tl_val(TL_SYMBOL_LOC(my_count), SYMBOL_LOC(count));
	rtl_set_tl_val(TL_SYMBOL_LOC(my_fd), SYMBOL_LOC(fd));
}

/* generated exit point rprobes handler */
static rsys_read(void)
{
	timestamp_t entry_time = rtl_get_tl_val(TL_SYMBOL_LOC(entry_time));
	if (entry_time) {
		char *key = rtl_cur_syscall_name();
		timestamp_t total = rtl_get_hash_val(SYMBOL_LOC(read_times), key);
		rtl_add_times(total, rtl_cur_timestamp() - entry_time);
		rtl_set_hash_val(SYMBOL_LOC(read_times), key, total);
		rtl_set_tl_val(TL_SYMBOL_LOC(entry_time), 0);
	}
}

/* Boilerplate probe setup code */

#define N_PROBES 1

/* see netpktlog for a better way of doing this */
static struct jrprobe
{
	const char *funcname;
	struct jprobe jp;
	struct rprobe rp;
} jrp[] = { .funcname = "sys_read", jp.entry = jsys_read, rp.handler = rsys_read)}; 

static int __init systemtap_init(void)
{
	int i;

	for (i = 0; i < N_PROBES; i++)
		jrp[i].kp.addr = kallsyms_lookup_name(jrp[i].funcname);
		register_jrprobe(&jrp[i].jp, &jrp[i].rp);
	}

	return 0;
}

static void systemtap_fini(void)
{
	for (i = 0; i < N_PROBES; i++)
		unregister_jrprobe(&jrp[i].jp, &jrp[i].rp);
}

module_init(systemtap_init)
module_exit(systemtap_exit)
MODULE_LICENCE("GPL")


Notes:

- Jim's register/unregister_jrprobe() API is used here to
  simultaneously register the entry jprobe handler, and the exit rprobe
  handler.

- I put in the gratuitious self->my_count and self->my_fd statements
  here mainly to have something that needs to access the param values in
  this probe.  In this case, we're using jprobes, so it doesn't seem to
  me that anything else needs to be done for the probe to be able to
  access the param values than to substitute SYMBOL_LOC(count) with the
  literal param name in the code i.e. SYMBOL_LOC(param) translates
  directly into param for jprobes handlers:

	rtl_set_tl_val(TL_SYMBOL_LOC(my_count), count);
	rtl_set_tl_val(TL_SYMBOL_LOC(my_fd), fd);

  Will this still work if count isn't a int value but say an int *?

	self->my_count = *count;

  Seems to - if jprobes is being used, it's just a straight pass-thru.
	
- The rest is pretty straightforward


=====================================

Here's a probe that looks much simpler than the previous one, but
brings up some fundamental questions about what should be generated.
It simply accumulates the number of syscall entries over all
processes.  It uses kprobes but not jprobes for the entry probe:

/* total #syscalls by syscall name */
probe syscall:entry(*)
{
	syscall_counts[$syscall_name]++;
}

----generated code----

/* generated entry point kprobes handler */
static syscall_handler(void)
{
	char *key = rtl_cur_syscall_name();
	int total = rtl_get_hash_val(SYMBOL_LOC(syscall_counts), key);
	total++;
	rtl_set_hash_val(SYMBOL_LOC(syscall_counts), key, total);
}

/* Boilerplate probe setup code */

#define N_PROBES NR_SYSCALLS

/* see netpktlog for a better way of doing this */
static struct probe
{
	struct kprobe kp;
} syscalls[NR_SYSCALLS];


static int __init systemtap_init(void)
{
	int i;

	for (i = 0; i < N_PROBES; i++) {
		syscalls[i].kp.addr = kallsyms_lookup_name(SYSCALL_NAME(i));
		syscalls[i].kp.handler = syscall_handler;
		register_kprobe(&syscalls[i].kp);
	}

	return 0;
}

static void systemtap_fini(void)
{
	for (i = 0; i < N_PROBES; i++)
		unregister_kprobe(&syscalls[i].kp);
}

module_init(systemtap_init)
module_exit(systemtap_exit)
MODULE_LICENCE("GPL")


Notes:

- This is an example of a probe where you have multiple
  instrumentation points e.g. an entry probe on each syscall, but a
  single probe handler handling them all.  In general, this would be the
  case anytime you want to probe a set of functions at the same time but
  don't want or need a special handler for each one, which further
  implies that you're not interested in the specifics of any one
  function (I suppose if you knew each had at least one arg, you could
  log that for instance, but it would be pretty meaningless; looking at
  return vals might be slightly more useful).  I don't know if the *
  syntax in the probe specifier is supported in the language, but the
  idea is that you should be able to do this in general e.g. to probe
  all functions in a module, you'd similarly probe mymodule:entry(*).

- To set up the probes, this example loops over each syscall and
  registers the single probe handler for each one.  In the case of
  syscalls, this might be ok (or not, instrumenting 300 functions at one
  go seems like too much already), but in general this approach doesn't
  scale well.  It seems to me that we need a way to enable and disable
  probes as needed or 'just in time'.  For example, here's a probe that
  we should be able to write:

/* trace all functions called from open */
probe syscall:entry("open")
{
	self->trace_all = 1;
	enable(*:entry(*)); /* enable probes on _all_ functions */
}

/* handler for _all_ functions */
probe *:entry(*)
{
	if (self->trace_all)
		print("function called: $funcname\n");	
}

probe syscall:exit("open")
{
	disable(*:entry(*)); /* disable probes on _all_ functions */
	self->trace_all = 0;
}

Here, we enable entry tracing for all functions when we enter open()
and disable them again when open() exits.  Clearly, we can't generate
a probe module for this, and even if we could, it wouldn't make sense
to actually register probes for 30,000 functions in the kernel at the
same time.  So, assuming we'll need at some point to support this use
case, it might make sense to solve the general problem now and use the
result for the simpler case of instrumenting all syscalls.

- assuming the brute-force approach, will the role of the syscall
  'provider' be mainly to enumerate the names of the available syscall
  functions available to make it easy for the probe to register the
  syscall kprobes, or would it provide a function that does the
  registration on the probe's behalf?  The latter sounds nicer, but the
  question may be moot anyway.  Either way, it makes sense to me to have
  the providers provide the registration/enabling/etc for the probe
  handlers regardless of the method used.  Also, for the syscall
  provider, since these will be some of the most-used probes, does it
  make sense for the provider to also provide an enumeration of the
  argument names that can be used in each syscall probe rather than
  arg0, arg1, etc.?

========================================

Here's a probe that counts the total number of bytes read by a
particular program, in this case apache.  It uses kprobes but not
jprobes, and uses the probed function argument values without needing
to know their types.

/* total bytes read() by apache */
probe syscall:entry("read")
{
	if ($execname == "apache") {
		self->fd = $arg0; /* read(fd, buf, count) */
		self->count = $arg2; /* read(fd, buf, count) */
	}
}

probe syscall:exit("read")
{
	if (self->fd && $retval > 0) {
		read_counts[$pid] += self->count;
		print("apache(pid = $pid) read $self->count bytes, total now $read_counts[$pid]");
	}
}

----generated code----

/* generated entry point kprobes handler */
static void sys_read_handler(void)
{
	const char *execname = rtl_get_execname();
	if (!strcmp(execname, "apache")) {
		int arg0val = (int)rtl_fetch(EXTERN_SYMBOL_LOC(arg0), EXTERN_SYMBOL_LEN(arg0));
		int arg2val = (int)rtl_fetch(EXTERN_SYMBOL_LOC(arg2), EXTERN_SYMBOL_LEN(arg2));
		rtl_set_tl_val(TL_SYMBOL_LOC(fd), arg0val);
		rtl_set_tl_val(TL_SYMBOL_LOC(count), arg1val);
	}
}

/* generated exit point kprobes handler */
static rsys_read(void)
{
	int fd = rtl_get_tl_val(TL_SYMBOL_LOC(fd));
	int retval = rtl_fetch(EXTERN_SYMBOL_LOC(retval));	
	if (fd && retval > 0) {
		int key = rtl_cur_pid();
		int read_count = rtl_get_tl_val(TL_SYMBOL_LOC(count));
		int total_count = rtl_get_hash_val(SYMBOL(read_counts), key);
		total_count += read_count;
		rtl_set_hash_val(SYMBOL(read_counts), key, total_count);
		rtl_print("apache(pid = $pid) read $self->count bytes, total now $read_counts[$pid]");
	}
}

/* Boilerplate probe setup code */

#define N_PROBES 1

/* see netpktlog for a better way of doing this */
struct krprobe
{
	const char *funcname;
	struct kprobe kp;
	struct rprobe rp;
} krp[] = { .funcname = "sys_read", kp.entry = sys_read_handler, rp.handler = rsys_read)}; 


static int __init systemtap_init(void)
{
	int i;

	for (i = 0; i < N_PROBES; i++)
		krp[i].kp.addr = kallsyms_lookup_name(krp[i].funcname);
		register_krprobe(&krp[i].kp, &krp[i].rp);
	}

	return 0;
}

static void systemtap_fini(void)
{
	for (i = 0; i < N_PROBES; i++)
		unregister_krprobe(&krp[i].kp, &krp[i]rp);
}

module_init(systemtap_init)
module_exit(systemtap_exit)
MODULE_LICENCE("GPL")

Notes:

- this probe doesn't used jprobes, and therefore doesn't have access
  to the param values directly.  Instead, it uses a function I'm
  assuming here will be in the runtime library, called rtl_fetch().  The
  function of rtl_fetch is just to fetch a certain value from memory.
  What and how much it fetches is determined by the values of
  EXTERN_SYMBOL_LOC() and EXTERN_SYMBOL_LEN(), which are in turn
  determined at compilation time by the dwarf2 library.  The generated
  code will have to do the proper casting etc.

- this probe also uses the retval in the exit handler.

- for syscalls, we always know where the arguments are on the stack,
  so we could possibly simplify this case, but in general we need the
  debugging info to find and fetch stuff.

- we assume read_counts[x] is auto-initialized to 0 before first use

- the print() function and the rtl_print() function I'm assuming will
  be in the runtime library are generic functions that format and send
  data to userspace immediately in a packet-oriented fashion.  A user
  space application would be listening for these and immediately print
  them to stdout as they arrive (assuming an initial systemtap command
  that creates and inserts the probe module and then sits around waiting
  for Control-C to end the session).  Expanding on this a bit, there
  should be a generic communication channel between the user application
  and the probe module or some proxy.  It should support the print()
  function from probe handlers, and it should also support queries from
  userspace applications such that they can retrieve data from the probe
  at any time e.g. the current contents of a hash table or global
  variable.  For this, a simple protocol built on top of netlink seems
  to me to be the best fit.  Because a probe might be managing several
  important data structures e.g. a couple hashtables, an array, and a
  global counter, there needs to be some way of uniquely identifying the
  particular data of interest - these might be just the name of the data
  structure or some opaque id.  Since there might be multiple probes
  running at the same time, each probe probably also needs a unique id.
  The actual implementation and protocol would be hidden from users on
  both the kernel and user sides - the kernel API available to users
  would consist of just the print() probe function (the runtime library
  would use a lower-level API like handle_data_request(),
  send_data_item(), etc).  The format of each data item isn't
  important - could just be binary or XML-ized, whatever makes sense.

  A possible userspace API might be something as simple as:

      request_probe_data(probe_id, data_id);

 and maybe a couple of callbacks:

      handle_print(data);
      handle_data(data_id);

- there should be a userspace library (taplib, maybe?) that makes it
  easy to create alternatives to the standard vanilla systemtap command,
  whatever that turns out to be.  The communication channel and protocol
  and common data manipulation or display functions should be put in
  there to start with.  Of course there should also be language bindings
  for Tcl/Tk and Perl, etc somewhere, to make it _really_ easy to create
  spiffy new GUIs or whatever.


========================================

This probe isn't really meant to do anything useful - mostly it's just
here to raise questions ;-) It instruments a random kernel function,
maintains a hash table with a composite key, accesses struct members
of a retval pointer value, one of which needs atomic_read().

probe entry("filp_open") /* filename, flags, mode, returns file*  */
{
	/* no need for magical and elusive copy_from_user here */
	callers[$pid, arg[0]]++; /* filename is type char* */ 
}

probe exit("filp_open")
{
	filp = $retval;
	print(filp->f_owner.pid);
	print(filp->f_owner.uid);
	print(filp->f_owner.euid);
	inode = filp->f_dentry->d_inode;
	print("inode count: %i\n", atomic_get(&inode->i_count));
}

----generated code----

/* generated entry point kprobes handler */
static void sys_read_handler(void)
{
	int pid = rtl_get_pid();
	const char *key = rtl_make_key(pid, arg[0]);
	
	int total = rtl_get_hash_val(SYMBOL(callers), key);
	total++;
	rtl_set_hash_val(SYMBOL(callers), key, total);	
}

/* generated exit point rprobes handler */
static void rsys_read(void)
{
	void *inode;
	void *count;
	void *filp = rtl_fetch(EXTERN_SYMBOL_LOC(retval));	
	rtl_print(rtl_fetch(EXTERN_SYMBOL_LOC(filp->f_owner.pid), EXTERN_SYMBOL_LEN(filp->f_owner.pid)));
	rtl_print(rtl_fetch(EXTERN_SYMBOL_LOC(filp->f_owner.uid), EXTERN_SYMBOL_LEN(filp->f_owner.uid)));
	rtl_print(rtl_fetch(EXTERN_SYMBOL_LOC(filp->f_owner.euid), EXTERN_SYMBOL_LEN(filp->f_owner.euid)));
	inode = rtl_fetch(EXTERN_SYMBOL_LOC(filp->f_dentry->d_inode), EXTERN_SYMBOL_LEN(filp->f_dentry->d_inode));
	count = rtl_fetch(EXTERN_SYMBOL_LOC(inode->i_count), EXTERN_SYMBOL_LEN(inode->i_count));
	print("inode count: %i\n", atomic_read((atomic_t *)count));	
}

/* Boilerplate probe setup code */

#define N_PROBES 1

/* see netpktlog for a better way of doing this */
struct krprobe
{
	const char *funcname;
	struct kprobe kp;
	struct rprobe rp;
} krp[] = { .funcname = "filp_open", kp.entry = sys_read_handler, rp.handler = rsys_read")}; 


static int __init systemtap_init(void)
{
	int i;

	for (i = 0; i < N_PROBES; i++)
		krp.kp.addr = kallsyms_lookup_name(krp.funcname);
		register_krprobe(&krp.kp[i], &krp.rp[i]);
	}

	return 0;
}

static void systemtap_fini(void)
{
	for (i = 0; i < N_PROBES; i++)
		unregister_krprobe(&krp.kp[i], &krp.rp[i]);
}

module_init(systemtap_init)
module_exit(systemtap_exit)
MODULE_LICENCE("GPL")

Notes:

- the main problem this probe illustrates is that it's not yet clear
  how to access data represented by composite data types, or how to
  handle types like atomic_t which need to use an accessor function.
  The location and size of the struct members is known from dwarf2 info,
  but how do we seamlessly access and use it in the probe?

- What about looping over external lists e.g. starting with list_head?


Thanks,

Tom