Boot poster challenge

[Owen Taylor]

On Mon, 2004-11-15 at 23:24 +0100, Ziga Mahkovec wrote:
> On Sat, 2004-11-13 at 12:18 -0500, Owen Taylor wrote:
> > It should be possible to start with a limited set of easily collected
> > data and already get a useful picture. Useful data collection could be
> > as simple as taking a snapshot of the data that the "top" program
> > displays a few times a second during boot. That already gives you a
> > list of the running processes, their states, and some statistics about
> > global system load.
> 
> So I gave this a try:
> 
> 1. I modified the boot procedure so that early in rc.sysinit, a tmpfs is
> mounted and top is run in batch mode (to output every 0.2 seconds).  The
> logged output is later parsed only up to the point where gdmgreeter is
> running and the system is relatively idle (i.e. boot complete and ready
> for login).
> 
> 2. A Java program parses the log file, builds the process tree and
> finally renders a PNG chart.  Processes are sorted by PID and traversed
> depth first.
> 
> This still needs more work but here's a sneak preview:
> http://www.klika.si/ziga/bootchart/bootchart.png

Wow, this is fabulous work, and fast too!

What sort of libraries are you using in the Java program? Do you have
any idea whether getting it to run on top of open source Java would
be feasible?

How are you computing the different shades of yellow and gray? Are
you looking at differences in the TIME column?

> (as a result of http://www.klika.si/ziga/bootchart/bootop.log.gz )
> 
> Some processes were filtered out for clarity -- mostly sleepy kernel
> processes and the ones that only live for the duration of a single top
> sample.  This skews the chart a bit but is definitely more
> comprehensible (compare with
> http://www.klika.si/ziga/bootchart/bootchart-complete.png ).
> 
> Some things I plan on adding:
> - start logging earlier in the boot process (possibly in initrd),
> - add additional layers (e.g. make use of the kernel patch Arjan
> suggested for showing the number of open files),
> - improve process tree representation and add dependency lines,
> - render SVG instead, for scalability and interactivity.

All sound good. Grouping processes by the process tree would clearly
make things a little clearer, though if you know what's going on,
it's not hard to figure out that xkbcomp is being run by X, not
by wait_for_sysfs.

Disk throughput would probably be the extra layer I'd be most
interested in. We seem to be IO bound during almost the entire process,
but how are we doing for efficiency? Are we doing significantly better
during readahead than during start-random-services?

> This definitely helped me with my boot times -- the 4-second load gap at
> the start I found to be "modprobe floppy", apparently timing out on my
> floppyless laptop :)

Just glancing at the initial image certainly brings all sorts of
questions to mind:

 - Why is rhgb eating so much CPU? if you run 'rhgb -i' it displays
   basically 0 CPU to display the animation. That looks like a
   pretty obvious bug we completely missed.

 - Is it just a coincidence that dhclient gets the lease almost 
   exactly simultaneously with readahead finishing? Is readahead
   blocking the rest of the system?

 - Is readahead doing any good at all? Would it still be doing good
   if we fixed blocking boot for 20 seconds on dhclient?

 - What does GNOME login look like?

You can also see that most of the time is eaten in just a few things ...
initial module probing, starting X twice, dhclient. There are only 7
seconds from when dhclient finishes until the point prefdm starts, and
that's the portion people have mostly worked on parallelizing.

Anyways, I'm very impressed, looks like I'll have to start figuring
out shipping to Slovenia :-) (*)
						Owen

(*) Let me know when you think you you are at a point where you think
    you have something you'd like to have as a poster, and we can
    work out how to best implement the details of my offer.

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 189 bytes
Desc: This is a digitally signed message part
URL: <http://listman.redhat.com/archives/fedora-devel-list/attachments/20041115/e5ea165c/attachment.sig>