Re: Login time

[Chris Ball <cjb laptop org>]

Hi Federico!

On Wed, Apr 11, 2007 at 11:30:37AM -0500, Federico Mena Quintero wrote:
> The overhead from strace doesn't seem to be terrible... it's certainly
> better than not being able to get any timings at all :)  I haven't timed
> it with a stopwatch, though.
> 
> I'd *love* to use a less pedestrian tool.  Does anyone know if Systemtap
> is mature enough for this?  We'd need to say, "tell me every time
> <function> gets called in this process", for a bunch of processes.

No, systemtap is kernelspace only right now.  Dtrace/Solaris is doing 
much better than Linux for that kind of userspace probing.

> [Can anyone with Solaris and Dtrace help us out?]
> 
> In the end, what we need is a one-step, reproducible way to get login
> timings.  Otherwise, whatever optimizations we do right now will go to
> hell when people start piling more code on top of everything.  We need
> to be able to run these tests regularly and without a lot of manual
> work.

We've also been using sysprof at OLPC, but that doesn't help answer your
"how many times does <n> get called" question, it just answers "for how 
many time samples did we find ourselves in <n>"; sysprof is a statistical
profiler.

Systemtap *can* be used for whatever you're using strace for -- in fact,
it works well as a "global strace".  For example. here's a simple script
that attaches to open(2) and tells you, for every call system-wide, 
which pid made it and whether they were reading or writing:

probe kernel.function("sys_open") {
  if ($flags & 1) {
    print(proc() . " writes " . user_string($filename) . "\n")
  } else {
    print(proc() . " reads " . user_string($filename) . "\n")
  }
} 

You can attach like this to any syscall/kernel function.  In fact, the
above probe, if you have a known set of file reads that signify the
start and end of login, could be used for measuring login time
automatically (we do this in the OLPC tinderbox).  You can also monitor
fork/exec/exit to work out whether login's finished.  Here's an example
of what we log in our tinderbox:

http://learn.laptop.org/tinderbox/builds/build385/olpc.html#performance

Also, here's a set of useful systemtap scripts/examples:

http://sourceware.org/systemtap/wiki/WarStories

Hope that helps,

- Chris.
-- 
Chris Ball   <cjb laptop org>