Re: Example looking at the periodic timers

[Mark Wielaard <mjw@redhat.com>]

[-- Attachment #1: Type: text/plain, Size: 2153 bytes --]

On Wed, Dec 14, 2011 at 09:52:18AM -0500, William Cohen wrote:
> > Looks nice. I would add a begin probe to announce the script started and
> > that the user must press control-C to get results and/or make the end
> > probe a end,timer.s(10) probe so that you get output every 10 seconds
> > (then you can also clean up the tables).
> 
> The begin probe would be easy enough to add. Loading in thing with the
> "--all-modules" can slow things down, so that would give people some
> useful feedback.  The timer.s(10) might not be so useful when people
> are looking for things that have a period longer than 10 seconds.
> There are things in the kernel that run every 600 seconds or so,
> and timer.s(10) would miss those. Maybe make an optional argument
> for periodic output/cleanup.

Nice elegant solution. To nitpick, I would make the output more explicit:
-probe begin { printf("#monitoring timer periods\n") }
+probe begin { printf("# Monitoring timer periods (press ctrl-C for output)\n") }

> > I also got some functions that don't immediately make sense, they don't
> > seem to fall inside either the kernel nor a module. Did you figure out
> > where they point at? From seeing the high address I assume they are
> > actually dynamically allocated structures, not direct functions.
> 
> Which functions are you referring to? I think that the raw addresses in
> the output are might the timers related to the systemtap instrumentation
> module.

Aha. You are right.
I even have a patch for modname() to get "unknown" module names.
I haven't checked it in because I found the preempt_disable() so
incredible ugly. We cannot use the module_mutex because we could
theoretically be probing some code that holds that mutex. What do
people think, is it useful enough to warrant the ugliness?

Since stap module names are so incredibly long you do need the following
patch to truncate the module names in periodic.stp:

-      fname = sprintf("%s:%s", modname(funct[timer]), fname)
+      fname = sprintf("%.16s:%s", modname(funct[timer]), fname)


This does expose that we (systemtap) are responsible for most timer
interrupts... hmmmm.

Cheers,

Mark

[-- Attachment #2: modname.patch --]
[-- Type: text/plain, Size: 1006 bytes --]

diff --git a/tapset/context-symbols.stp b/tapset/context-symbols.stp
index 1ab3a61..79d45f5 100644
--- a/tapset/context-symbols.stp
+++ b/tapset/context-symbols.stp
@@ -154,11 +154,28 @@ function probemod:string () %{ /* pure */
  */
 function modname:string (addr: long) %{ /* pure */
 	struct _stp_module *m;
+#ifdef STAPCONF_MODULE_TEXT_ADDRESS
+	struct module *ko;
+#endif
 	m = _stp_kmod_sec_lookup (THIS->addr, NULL);
 	if (m && m->name)
-          strlcpy (THIS->__retvalue, m->name, MAXSTRINGLEN);
-	else
-	  strlcpy (THIS->__retvalue, "<unknown>", MAXSTRINGLEN);
+	  {
+	    strlcpy (THIS->__retvalue, m->name, MAXSTRINGLEN);
+	    return;
+	  }
+
+#ifdef STAPCONF_MODULE_TEXT_ADDRESS
+	preempt_disable();
+	ko = __module_text_address (THIS->addr);
+	if (ko && ko->name)
+	  {
+	    strlcpy (THIS->__retvalue, ko->name, MAXSTRINGLEN);
+	    preempt_enable_no_resched();
+	    return;
+	  }
+	preempt_enable_no_resched();
+#endif
+	strlcpy (THIS->__retvalue, "<unknown>", MAXSTRINGLEN);
 %}
 
 /**