%include "style.mgp" %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% %page %nodefault %size 7, font "standard", fore "white", vgap 20 %bquality 10 %center Why userspace (still) sucks. %size 4 Trainwrecks, Gore and other programming tragedies. %size 4 Dave Jones Red Hat %page Motivation %size 7, font "standard", fore "white", vgap 20 Reducing boot time, increase idle time. %page Reducing boot time. %size 6, font "standard", fore "white", vgap 20 %center Doing readahead whilst idle. Profiling kernel patch to log every stat()/open() %page Reducing boot time. %size 5, font "standard", fore "white", vgap 20 %center Enhanced kernel patch to monitor all I/O (deletes too etc). Later used systemtap %page Reducing noise. %size 6, font "standard", fore "white", vgap 20 %center Disable readahead. %page Watching the horror show. %size 7, font "standard", fore "white", vgap 20 155234 line log. %page Boot up. %size 7, font "standard", fore "white", vgap 20 79576 files were stat()'d 26769 were open()'d 1382 commands were exec'd. %page Shutdown %size 7, font "standard", fore "white", vgap 20 23246 files were stat()'d 8724 files were open()'d. %page Magnanimous disclaimer. %page Let the gorefest begin. %size 7, font "standard", fore "white", vgap 20 %center WARNING: %size 5, font "standard", fore "white", vgap 20 Those of a sensitive disposition may want to look away. %page HAL. "If it's a file, I'll open it". %pause %size 5, font "standard", fore "white", vgap 20 Re-read and reparsed *dozens* of XML files during startup. In some cases, it did this 54 times per XML file. Performed no caching. Read a bunch of files describing devices that were not even present. %size 5, font "standard", fore "white", vgap 20 Accounted for a total of 1918 open()'s, and 7106 stat()'s %page HAL. "I'm sorry Dave". %size 4, font "standard", fore "white", vgap 20 %center Polls the cd drive every 2 seconds even when no user is logged in. Turns out to be a really bad idea on big boxen. %page CUPS %size 4, font "standard", fore "white", vgap 20 %center Read in ppd files describing every printer known to man... %pause ... Even though there was not even a printer connected. %center Responsible for around 2500 stat()'s, and around 500 open()'s %page About that no printer.. %pause %size 4 %center "The Hewlett-Packard Linux Imaging and Printing Project provides drivers for HP printers and multi-function peripherals." %size 5, font "standard", fore "white", vgap 20 hplip wakes up every half second for a select() timeout.. .. socket events will wake it up anyway. %page Xorg %size 7, font "standard", fore "white", vgap 20 %center How not to probe for PCI devices. %page How not to probe for PCI devices. %size 5, font "standard", fore "white", vgap 20 Scans through /proc/bus/pci/ in order Seemed to *guess* at random bus numbers Tried to open those devices in /proc/bus/pci/ Sequentially probed for devices on busses 0xf6 through 0xfb (even though they didn't exist) Retried entries that it had already attempted to scan regardless of whether they succeeded or not. %page Xorg (cont-d). %size 4, font "standard", fore "white", vgap 20 %center X really likes to stat & reopen lots of files it had already opened. like libGLcore.so. %page irqbalance. %center %size 5, font "standard", fore "white", vgap 20 Wakes up every 10 seconds to re-balance interrupts. %pause re-balanced interrupts where no IRQs had ever occurred. %pause Also re-balanced interrupts where an IRQ had not occurred in some time. %size 4, font "standard", fore "white", vgap 20 A two line change saved a few dozen syscalls. %pause %size 5, font "standard", fore "white", vgap 20 Reopens fd's. %page A brief history of file notification. %pause %size 5, font "standard", fore "white", vgap 20 %center Apps spin in a loop polling files. %pause SGI 'fam' daemon for IRIX %pause Linux dnotify %pause Linux port of fam %pause inotify %pause gamin %page A brief history of file notification. %size 7, font "standard", fore "white", vgap 20 %center %page gamin %center It's like inotify never happened.. %pause This causes an incredibly high number of context switches/sec %page nautilus %size 4 Spends lots of time stat'ing $HOME/Templates, /usr/share/applications, $HOME/.local/share/applications even though they had not changed. %size 7, font "standard", fore "white", vgap 20 %center INOTIFY! %pause Well, almost... %page Madness with fonts %size 6, font "standard", fore "white", vgap 20 %center apps stat()/open() fonts, and never actually use them. Make the problem worse to highlight it.. %pause .. by moving 6000 TTF's to $HOME/.fonts %pause The log file almost doubled in size. %page font madness. %size 4 gnome-session stat()'d 2473 and open()'d 2434 ttf's. %pause metacity open()'d another 238. %pause Just to be on the safe side, wnck-applet open()'s another 349 too. %pause Nautilus decides it does not want to be left out of the fun, and open()s up another 301. %pause mixer_applet rounds things off by open()ing up 860 ttfs. %pause X font server. Was rebuilding the font cache every time it booted, even if no changes had occurred in the fonts directories. %page Bugs from the twilight zone.. %size 5, font "standard", fore "white", vgap 20 %center mixer_applet2 did a stat on libgstffmpegcolorspace.so %pause Also wakes up every 100 ms to check if the volume changed. gstreamer has a 'volume-changed' signal for this. %page Fun with timers. %pause %size 2 peer_check_expire 181 crond dst_run_gc 194 syslogd rt_check_expire 251 auditd process_timeout 334 hald it_real_fn 410 automount process_timeout 437 kjournald process_timeout 1260 it_real_fn 1564 rpc.idmapd commit_timeout 1574 wb_timer_fn 1615 init process_timeout 1652 sendmail process_timeout 1653 process_timeout 1833 neigh_periodic_timer 1931 process_timeout 2218 hald-addon-stor process_timeout 3492 cpuspeed delayed_work_timer_fn 4447 process_timeout 7620 watchdog/0 it_real_fn 7965 Xorg process_timeout 13269 gdmgreeter process_timeout 15607 python cursor_timer_handler 34096 i8042_timer_func 35437 rh_timer_func 52912 %page (Secret: The kernel sucks too) %size 5, font "standard", fore "white", vgap 20 %center USB: Every 256ms, a timer was firing in the USB code. %page (Secret: The kernel sucks too) %size 5, font "standard", fore "white", vgap 20 keyboard controller. %center i8042 code polls the keyboard controller at HZ/20 to see if someone has hot-plugged a PS2 keyboard/mouse or not. %page (Secret: The kernel sucks too) %size 5, font "standard", fore "white", vgap 20 %center Cursor blinking. Hilariously, at HZ/5 we wake up to blink the cursor. Even if we are running X, and not sat at a VT %size 4, font "standard", fore "white", vgap 20 And it used to be worse.. %page gnome-terminal whilst idle %size 4 Even when cursor blinking is turned off. %page Xorg %size 4 X uses interval timers to wake up a *lot* Even if it was not the currently active VT. Ironically, this is due to X using its 'smart scheduler' -dumbsched 'fixes' it. Historically, gettimeofday was slow. And interval timers were fast.. I guess? %page Sendmail %size 5, font "standard", fore "white", vgap 20 %center Wakes up every 5 seconds, even when it's totally unused/idle. (It wakes up quicker if a signal comes in about actual mail). %page Network Manager %size 5, font "standard", fore "white", vgap 20 %center nm-applet wakes up every second to redraw its icon. Even if the daemon isn't running. Even if the state hasn't changed. %page gnome power manager. %size 5, font "standard", fore "white", vgap 20 %center "gnome powermanager makes the system eat more power" %pause Asks the X server twice per second what the current video mode is to find out if it changed. Totally unnecessary: X sends apps an event when the mode changes %page Battery applet. %size 5, font "standard", fore "white", vgap 20 %center battery applet polls every second Even if running on AC %page gnome-screensaver %size 5, font "standard", fore "white", vgap 20 %center Polls X every second instead of using the X screensaver API.. .. to find out the mouse position, to detect user activity. Totally unnecessary, X has an entire API for this! %pause Has some weird smart card event monitoring voodoo. Polls several times a second. %page gpm %size 4, font "standard", fore "white", vgap 20 %center gpm wakes up every 2 seconds to poll the console, even in runlevel 5 .. to wait for X to go away. %page pcscd - smart card daemon %size 4, font "standard", fore "white", vgap 20 a daemon for dealing with smart card readers. Scans all USB devices once per second to find smart card readers. %size 2, font "standard", fore "white", vgap 20 Pid 2224 pcscd run 301599+ ms... reads /dev/bus/usb/001/001 301 times, once every 1000 ms avg 43 bytes reads /dev/bus/usb/002/001 301 times, once every 1000 ms avg 43 bytes reads /dev/bus/usb/003/001 301 times, once every 1000 ms avg 43 bytes reads /dev/bus/usb/004/001 301 times, once every 1000 ms avg 43 bytes reads /dev/bus/usb/004/002 301 times, once every 1000 ms avg 57 bytes reads /dev/bus/usb/005/001 301 times, once every 1000 ms avg 43 bytes reads /dev/bus/usb/005/002 301 times, once every 1000 ms avg 43 bytes reads /dev/bus/usb/005/005 301 times, once every 1000 ms avg 52 bytes reads /dev/bus/usb/005/006 301 times, once every 1000 ms avg 52 bytes reads /dev/bus/usb/005/008 301 times, once every 1000 ms avg 50 bytes %page pcscd - smart card daemon %size 4, font "standard", fore "white", vgap 20 %center The pcsc daemon wakes up once per second for no reason at all. has a 1 second select loop time out, but all it does on timeout is loop again. the pcsc-lite library has a 200msec polling loop that gets called from gdm-binary. %page xenstored - Xen metadata database %size 6, font "standard", fore "white", vgap 20 %center xenstored is 'special'. %size 4, font "standard", fore "white", vgap 20 Its implementation of transactions requires it to take a complete copy of the database backend file everytime it starts & ends a transaction. %pause XenD performs about 16 transactions every time you ask for info about a domain %pause if you monitor 20 guest domains once a second, this translates into xenstored doing 80 MB of disk I/O every second. %page nautilus-cd-burner wakes up every 2.5 secs %size 2 /usr/libexec/mapping-daemon Process 2977 attached - interrupt to quit poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 144) = 0 poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 5000) = 0 poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 5000) = 0 poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 5000) = 0 poll([{fd=4, events=POLLIN}, {fd=3, events=POLLIN}], 2, 5000) = 0 %size 4 Its just a lame timeout to clean up when not in use: g_timeout_add (5000, &cleanup_timeout, NULL); %page Tools %size 4 you don't *need* to use kernel patches. strace, ltrace, strace-account oprofile systemtap scripts %page Tools Measuring context switches. vmstat 10 and check the "cs" column. %page Context switches idle runlevel 3 this should be between 10 and 20 gnome (FC6) ~400 gnome+assorted hacks ~35-40 (More on this in Ryan Lortie's talk) %page %size 6, font "standard", fore "white", vgap 20 %center Spare stuff... %page autofs daemon %size 4 automount wakes the system up every second, even when it's not in use at all /* We often start several automounters at the same time. Add some randomness so we don't all expire at the same time. */ make all timers fire at the same time instead. %page dhcdbd %size 4 dhcdbd wakes up 5 times per second needlessly Why does it have its own homegrown mainloop implementation anyway, instead of using glib's mainloop, which doesn't have this flaw ? %page ipw3945d %size 4 Another reason binary blobs suck. Pid 1888 ipw3945d run 301538+ ms... reads /sys/bus/pci/drivers/ipw3945/0000:03:00.0/cmd 2954 times, once every 102 ms avg 3008 bytes writes /sys/bus/pci/drivers/ipw3945/0000:03:00.0/cmd 9 times, once every 29654 ms avg 20.3333333333333 bytes This activity doesn't appear to be at all related to level of network I/O, pretty much a constant rate of access regardless of what the system is doing. %page Random detritus.. %size 3, font "standard", fore "white", vgap 20 pam_timestamp_check wakes up every 5 seconds to poll if a file or two have changed. Ideally, it would just use inotify for this rather than polling. stickynotes applet wakes up every 100ms to manually poke in the X event queue. It should just use an event filter gnome-settings-daemon wakes up for every keypress It probably has the same problem gtk had a while ago, it selects for some xkb events, without making sure to unselect all the others: clock applet updates every second even when seconds aren't showing the clock applet updates itself every second, even when the clock isn't configured to show seconds.