Postcards from the Fridge

Monday, May 29, 2006

X startup & other goodies

I've been automating the generation of the boot charts for gnome-session. (More on that later)

I've begun to notice a few things.

1) X takes a long time (3-4 seconds) to startup even with a warm cache.

In all of my warm-cache charts, gnome-session didn't execute until a few seconds after X started.

I was wondering if this was something to do with the gnome-session (ie, it has a lot of libraries that need to be loaded, etc.), so I decided to start X with the simplest of all xapps "xdpyinfo".

Even with this simple application, the whole startup/teardown takes 3-4 seconds.

It is easy to reproduce this:
A) Drop to the console mode (init 3)
B) Create a script called "startup-xdpyinfo.sh"

"xinit /usr/bin/xdpyinfo -- /usr/bin/X :0"
C) time "startup-xdpyinfo.sh"

(NOTE: I would be really interested to hear what other's times are. I am using the Xorg 7.0 release from FC5, and "ATI Radeon XPRESS 200M 5955", and my times are 3-4 seconds for the entire startup/shutdown. )

When running bootchart, I get the following (all of my runs look very similar to this) :



Here's the script I used to generate the graphs:

#!/bin/bash
TIME=`date +%m%d%H%M.%S`
script -c "time /sbin/bootchartd start /home/gnome/no_xinit/startup-xdpyinfo.sh" ./xdpy-$TIME.log
bootchart bootchart.tgz
#rm bootchart.tgz
mv ./bootchart.svgz ./xdpy-$TIME.svgz

NOTE: If I run X with the "-probeonly" option, the times are only 2
seconds, so it is appears as if X is probing for 2 seconds.

Here's a graph of that:



2) Components don't startup in the same sequences during the login.

The startup sequence is not always constant. There may be some inefficiencies because of this.

If Process A depends on Process B, but they start in parallel, Process A could be waiting, but Process B can't run because Process A is on the CPU.

However, you also don't want to add dependencies that don't exist.

I have to look into this more. Here's my first pass at determining the startup order:

A) gnome-session -> gconfd-2 -> gnome-keyring-daemon -> bonobo-activation-run-query->

B) gnome-settings- -or- metacity (Start in Parallel?)

C) (Always after Metacity) gnome-panel -> Nautilus

D) The rest:

gnome-volume-manager -> gnome-vfs-daemon-> wnck-applet -> gnome-settings -> notification-ar -> clock-applet -> mixer_applet2 -> mapping-deamon ->

3) xrdb is almost always in a "zombie" state.

All of the graphs that I've looked at show the 'xrb' command started by gnome-settings becomes a Zombie. This might be related to an error message that I receive about "gnome-settings-daemon" failing during startup.

NOTE: I was able to initiate a gnome-session shutdown programmability (Thanks Vincent) using "gnome-session-save --kill".

Questions:
1) What is the most appropriate time to start a shutdown? (ie, how do we know that everything is up and initialized? ) Currently, the shutdown command is is one of the startup programs that gnome-session runs.

However, since the startup programs don't run in any particular order, it can begin the shutdown early or late in the startup cycle. This means that there is a large variation in the total startup/shutdown time. This is annoying when trying to profile, and improve startup time.

3 Comments:

  • xinit /usr/bin/xdpyinfo -- /usr/bin/X :0

    real: 4.023s

    on an AMD Sempron(tm) 2200+
    and 9250 ATI Radeon.

    Thx for your work... you rock!

    By Blogger bag, at 9:22 AM  

  • real 0m3.801s

    on Gentoo w/ XOrg 7.0-r1, ATI drivers 8.23.7 , Radeon 9700 Pro, and AMD Athlon XP 2200+.

    Thanks for all the effort!

    By Blogger Spencer Tanner, at 4:50 PM  

  • Thanks for the stats.

    I also ran this against my wife's laptop with an Nvidia card. (Using the opensource driver)

    Real: 2.2s for xdpyinfo
    1.4s for -probeonly

    HW:
    Geforce4 440 Go 64M
    AMD Athlon 64 3200+

    SW:
    FC5
    Using the opensource "nv"
    xorg-x11-drv-nv-1.0.1.5-3.1
    xorg-x11-server-Xorg-1.0.1-9.fc5.1.1

    SO, it seems like Nvidia is a bit faster than ATI at startup. (For the one datapoint I've tried...)

    By Blogger ezolt, at 12:10 PM  

Post a Comment

<< Home