Strange and Magical world

This IS a reproduction

I've been trying to reproduce the slow nautilus startup times that Federico had been seeing on the CVS version of Gnome that I have checked out. I was reading through code first, but that was really the wrong thing to do. I should have actually timed how long things were taking, and THEN if it was still a problem read through the code.

That's what I did.

On the good news/weird new side, my total nautilus startup times (from the beginning of nautilus main to the expose_event sent to the icon_container) have been much much lower than the times that Federico reported in his blogs. My total startup time avg was ~2secs. His time between gtk_main and the icon_container expose event was 2 seconds! (His time was only including the time between when control was handed over to gtk, and when things were finally painted. Mine included the whole nautilius initialization AND the time for gtk to paint things.)

I don't know WHY things would be so much better. I really wonder if strace was skewing his results like it was doing for the X server. I was also doing this from a WARM cache (his might have been from a cold cache.) I'm not sure.

Highly Variability

I wrote a few wrapper scripts to automatically launch gnome, time nautilus's startup, and then gather the results. I was curious to see how consistent the startup time was.

Short answer: It wasn't. I had a minimum time of 0.398 sec and a maximum time of 4.411 sec.

I've sorted the 44 runs that I made by time, so here's a picture of it:




When I used to do SPEC CPU benchmarking, the variability from run-to-run would drive us crazy. Some applications would be very fast in one run, and slow in another. Ideally, you could have a run where all of the applications ran at their top speed. It was frustrating.

The compiler writers saw it differently. If there was a variation, that meant it was possible for the application to always run as fast as the fastest time if they could only figure out what was slowing it down in the other times.

The nice thing about the SPEC runs was that each of the programs were independent, so you really should be able to optimize things for each app to run at it's ideal time. Gnome is a little different, since it is a complicated interlocking system. The fast runs of Nautilus MIGHT be because some other startup program has already initialized the components that nautilus needs. Hower, it does say that we have the possiblity for a VERY fast nautilus startup.

Variablility makes it REALLY hard to optimize things, and can often times hide a race, so it really needs to be investigated.

Ideally we could get nautilus to start in 0.398 secs. Why doesn't it do it every time? (This is what I'll be looking at for the next blog entry. Stay tuned... )

Cold cache vs. Warm cache

So far, I've been looking at the warm cache startup time of Nautilus. Why?

Basically I see the warm cache time as the "best we can do". As we eliminate I/O in the cold cache time, we will eventually get closer and closer to the warm cache time.

So while it does make sense to also optimize the cold cache time (as this will be what the first user logging on to a system will experience), starting with the optimization of the warm cache will allow me to understand and optimize the different parts of nautilus, and then see how adding disk I/O slows them down. Also, I/O is scary. ;-) (Ie, Once I/O is added to the mix, things get much less repeatable. Although the "flush the cache" app should help with that.)