public inbox for systemtap@sourceware.org
 help / color / mirror / Atom feed
From: Jonathan Lebon <jlebon@redhat.com>
To: systemtap@sourceware.org
Cc: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Subject: SystemTap upcoming feature: boot-time probing
Date: Thu, 09 Jan 2014 21:30:00 -0000	[thread overview]
Message-ID: <1769953313.6141568.1389303043384.JavaMail.root@redhat.com> (raw)
In-Reply-To: <1056138144.5919711.1389293601415.JavaMail.root@redhat.com>

Hello everyone,

I've been working on making SystemTap use dracut in order to
insert the kernel module at early boot-time. The goal of
this email is to provide some more details and demonstrate
how to use it.

To implement this feature, I've added a dracut module which
simply adds staprun, stapio, and the target SystemTap
module(s) to the initramfs during creation.

Users select which scripts go in the initramfs by using the
new 'onboot' command of SystemTap's initscript. The
initscript then calls dracut to create the image.

Upon boot, staprun inserts the module during the cmdline
hook (the earliest possible using dracut) and detaches from
it. Users can then attach to the module to read in the data.

For testing, see the jlebon/boot-time branch of the
SystemTap git repo:

https://sourceware.org/git/gitweb.cgi?p=systemtap.git

Also take a look at the README.systemtap documentation diff
to see everything that has changed w.r.t. to the initscript:

https://sourceware.org/git/gitweb.cgi?p=systemtap.git;a=commitdiff;h=b0d4bb7

_____
USAGE

To play with the kind of information we can gain during
early-boot, I wrote the following script, which registers
calls to fork(), exec(), do_exit(), init_module(), and
delete_module():

procmod_watcher.stp
===================
function print_time() {
   timer = read_stopwatch_us("timer")
   printf("%4d.%.6d: ", timer/1000000, timer%1000000)
}

probe begin {
   start_stopwatch("timer")
   printf("   0.000000: Started module_watcher on %s\n",
          ctime(gettimeofday_s()))
}

probe kernel.function("do_execve"),
      kernel.function("compat_do_execve")? {

   print_time()
   printf("EXEC: (%4d) %s: file %s",
          pid(), execname(), kernel_string($filename))
   
   # Uncomment below to also print out arguments (can make
   # the output harder to read). You will also need to do
   # the following to enable guru mode:
   #   echo "procmod_watcher_OPT=\"-g\"" > \
   #       /etc/systemtap/conf.d/procmod_watcher.conf
   #arg = $__argv + %{ sizeof(char*) %}
   #ptr = kernel_pointer(arg)
   #if (ptr != 0)
   #   printf(" with args ")
   #while (ptr != 0) {
   #   printf("%s ", user_string2(ptr, "<NA>"))
   #   arg = arg + %{ sizeof(char*) %}
   #   ptr = kernel_pointer(arg)
   #}

   println("")
}

probe kprocess.create {
   print_time()
   printf("FORK: (%4d) %s: pid %d\n",
          pid(), execname(), new_pid)
}

probe kprocess.exit {
   print_time()
   printf("EXIT: (%4d) %s: exit code %d\n",
          pid(), execname(), code)
}

probe kernel.function("do_init_module") {
   print_time()
   printf("LOAD: (%4d) %s: module %s",
          pid(), execname(), kernel_string($mod->name))
   args = kernel_string($mod->args)
   if (args != "")
      printf(" with args \"%s\"", args)
   println("")
}

probe syscall.delete_module {
   print_time()
   printf("UNLD: (%4d) %s: module %s with flags %x\n",
          pid(), execname(), user_string($name_user), flags);
}

probe end {
   print_time()
   printf("Exiting module_watcher on %s\n",
          ctime(gettimeofday_s()))
}
==========

To set up this script for boot-time loading, we first copy
it to the script.d directory:

# cp procmod_watcher.stp /etc/systemtap/script.d/
# 

Then, we use the 'onboot' command:

# service systemtap onboot procmod_watcher
 Compiling procmod_watcher ... done
Creating initramfs: procmod_watcher                        [  OK  ]
# 

We can now restart the computer:

# reboot
# 

And finally, after the system finishes booting up, we can
re-attach to the module (I've only pasted bits of the output):

# staprun -A procmod_watcher
   0.000000: Started module_watcher on Thu Jan  9 19:21:34 2014
   0.004567: FORK: (  90) stapio: pid 90
   0.004598: EXIT: (  90) stapio: exit code 0
   0.004602: EXIT: (  90) stapio: exit code 0
   0.004625: EXIT: (  90) stapio: exit code 0
   0.004923: FORK: (  73) dracut-cmdline: pid 93
   0.005710: EXIT: (  93) dracut-cmdline: exit code 256
   0.005889: FORK: (  73) dracut-cmdline: pid 94
   0.006200: FORK: (  94) dracut-cmdline: pid 95
   0.006659: EXIT: (  95) dracut-cmdline: exit code 256
   0.006829: FORK: (  94) dracut-cmdline: pid 96
   0.007302: EXIT: (  96) dracut-cmdline: exit code 256
   0.007481: FORK: (  94) dracut-cmdline: pid 97
   <...snip...>
   2.843626: FORK: ( 410) firewalld: pid 868
   2.843831: EXEC: ( 868) firewalld: file /sbin/iptables
   2.844514: EXIT: ( 868) iptables: exit code 0
   2.844829: FORK: ( 410) firewalld: pid 869
   2.845034: EXEC: ( 869) firewalld: file /sbin/iptables
   2.845722: EXIT: ( 869) iptables: exit code 0
   2.846036: FORK: ( 410) firewalld: pid 870
   2.846240: EXEC: ( 870) firewalld: file /sbin/iptables
   <...etc...>
# 

If you've enabled argument printing, you will also see
cool things like:

<...snip...>
   1.665215: EXEC: ( 459) netconsole: file /bin/sed with args s|.* src \([^ ]*\).*|\1| 
   1.665678: EXIT: ( 459) sed: exit code 0
   1.665774: EXIT: ( 457) netconsole: exit code 0
   1.665921: FORK: ( 448) netconsole: pid 460
   1.666110: FORK: ( 460) netconsole: pid 461
   1.666177: FORK: ( 460) netconsole: pid 462
   1.666283: EXEC: ( 461) netconsole: file /sbin/arping with args -f -c 1 -I 192.168.122.1
   1.668700: EXEC: ( 462) netconsole: file /bin/awk with args / reply from .*[.*]/ { print gensub(".* reply from .* \\[(.*)\\].*","\\1","G"); exit } 
   1.690545: EXIT: ( 461) arping: exit code 512
   1.690605: EXIT: ( 462) awk: exit code 0
   1.696796: EXIT: ( 460) netconsole: exit code 0
<...snip...>

Hopefully this little exercise gives you an idea as to how
SystemTap can be used in your workflow when trying to find
out more about something that happens during boot-time.

Comments and feedback welcome,

Jonathan

       reply	other threads:[~2014-01-09 21:30 UTC|newest]

Thread overview: 2+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
     [not found] <1056138144.5919711.1389293601415.JavaMail.root@redhat.com>
2014-01-09 21:30 ` Jonathan Lebon [this message]
2014-01-10 21:30   ` Jonathan Lebon

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=1769953313.6141568.1389303043384.JavaMail.root@redhat.com \
    --to=jlebon@redhat.com \
    --cc=masami.hiramatsu.pt@hitachi.com \
    --cc=systemtap@sourceware.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for read-only IMAP folder(s) and NNTP newsgroup(s).