-
Sunrise today.
-
Here is a tremendous bunch of whiners: bug #136541. People have spent enormous amounts of energy and bile whining about the file chooser not having a file name entry in OPEN mode.
It has been two years since that bug was opened. One would think that after such a long time of people being genuinely annoyed by the bug, they would have sat on their asses to write a patch. "Scratch an itch?" What for? It's easier to whine and whine and be useless.
Default mode:
File name entry mode:
This is in the federico-filename-entry branch of GTK+ in CVS. I'll merge it to HEAD right after Kris's asynchronous patch goes in.
Now let's look at the weather forecast, which will undoubtedly mention a shitstorm.
-
In other excellent news, Emmanuele merged the GtkRecent code into GTK+ HEAD. This will let us have recently-used files everywhere: in applications, in the file chooser, in the panel, in Gimmie. We can use this to present a view of the user's working set of files and folders at all times: one should never have to browse the file system for a file that you just used; it should just be there as an option in the right places.
-
Kurt Pfeifle describes a neat trick to use "tc" to add latency to the loopback interface. You can use this to test whether your GNOME app is usable on a remote X server over a high-latency network link.
-
Today I casually put a glass lid on a Dutch oven while heating some soup. With the glass lid on, you can actually see the convection current in the steam. Pretty cool.
-
We have had a few days with 28°C in the shade, wherein Oralia surprised me with the first really good mangoes of the year.
-
To make a good red salsa, first you boil some tomatoes until they are soft. Then you put them on your piglet-shaped stone mortar along with chile de árbol to taste, onions, garlic, and some salt.
Then, you pound on the mixture until it is a good salsa, as chunky or as liquid as you want.
You should boil the result for a little while to bring out the flavor and remove some of the liquid. Or even better, you can heat a little oil and pour the mixture there, and wait until it cooks a bit.
But on what can you pour the salsa? You can lightly fry some tortillas and dip them in refried beans.
Then you serve them topped with shredded lettuce, cream, crumb cheese, and the salsa. This will yield a delicious breakfast of enfrijoladas, which will give you plenty of gas to last you throughout the day.
-
Improving login time, part 4: Gnome-session's clients
(Index to the "Improving login time" series)
Gnome-session has ancient code, going back to 1997 when Tom Tromey wrote it.
Today I was investigating why it takes quite a while for gnome-session to start each client. It starts metacity, then it pauses; then it starts gnome-panel, and pauses; then it starts nautilus, and pauses...
Look for the white annotations on the right side of this plot:
- 0:34 - gnome-session starts
- 1.38 - gnome-session starts gnome-wm/metacity
- 1:42 - gnome-session enters main loop
- *gap*
- 2:28 - metacity replies back
- 2:29 - gnome-session starts gnome-panel
- *gap*
- 2:50 - gnome-panel replies back
- 2:50 - gnome-session starts nautilus
- *gap*
- 3:71 - nautilus replies back
- *gap*
- 4:12 - gnome-session starts resapplet
Gnome-session uses a state machine to decide what to do at each iteration of its main loop. It does everything in idle handlers because it needs to be able to receive ICE messages through a GIOChannel.
There is a function, update_save_state(), which decides what to do based on the state. When the state is STARTING_SESSION, it sees if there is pending stuff in the start_list of clients, and launches one of them. Then, it waits until the client replies back. Then it launches the next client. The period of waiting for a client to reply back can be quite significant: it adds about three seconds to the start of the session.
Gnome-session could probably run through the start_list quickly, and simply wait for each client to reply whenever it wants. Is this possible? Who wants to figure out the code for that?
-
Improving login time, part 3: The desktop's menu bar?
(Index to the "Improving login time" series)
Michael did some tremendous work; he cooked a patch to add threading to bonobo-activation-server. The result is that now we don't wait as much when launching services at startup. It's not done yet, but it helps Nautilus by about 4 seconds. The patch is in libbonobo HEAD.
I suspect that gconfd has the same problem; maybe it is also a contention point during login because everything wants to fetch keys from it at the same time. I still need to test this; it should be enough to instrument client-side calls to the libgconf functions, and the gconfd-side CORBA implementations. This will tell us if gconfd is serializing things and causing apps to wait.
In the meantime, I've been looking at other gaps in the Nautilus timeline. The most obvious ones are the two-second gap between reaching the main loop and painting the desktop, and a one-second gap in Nautilus_Shell_start_desktop().
I added some instrumentation to the main-loop-to-desktop part, but haven't found the culprit yet.
But Nautilus_Shell_start_desktop() was interesting. NautilusDesktopWindow inherits from NautilusSpatialWindow, which in turn inherits from NautilusWindow. Whenever you instantiate a NautilusWindow or a subclass, it creates a menu bar and a status bar for the window. But the desktop doesn't have a menu bar! This was taking 1 second.
Digging deeper, I discovered this:
if (!have_burn_uri ()) { action = gtk_action_group_get_action (window->details->main_action_group, NAUTILUS_ACTION_GO_TO_BURN_CD); gtk_action_set_visible (action, FALSE); }This means "if we don't support burn:/// URIs because nautilus-cd-burner is not installed, don't show the Burn CD command at all". In turn, have_burn_uri() simply does this:
static gboolean have_burn_uri (void) { static gboolean initialized = FALSE; static gboolean res; GnomeVFSURI *uri; if (!initialized) { uri = gnome_vfs_uri_new ("burn:///"); res = uri != NULL; if (uri != NULL) { gnome_vfs_uri_unref (uri); } initialized = TRUE; } return res; }See that innocent-looking gnome_vfs_uri_new()? Well, since it is not a file:/// URI, gnome-vfs sees if there is a "burn" method installed. Then it sees that that method's library is called libmapping.so. So it links in the library and initializes it. The initialization function for this module spawns the mapping-daemon process. This can easily take a whole second during login, due to all the extra churning that is going on.
So I cooked a patch to avoid doing that for the case of the desktop window. Ideally the desktop wouldn't get a menu bar created for it at all, but the code to do that would be a lot harder: right now, keyboard accelerators like Ctrl-r (reload) and Shift-Ctrl-n (new folder) work in the desktop precisely because its hidden menu bar takes care of handling those accelerators. But in the meantime, I'm really happy to see that this knocks a full second away from the profile.
In total, with Manny's, Michael's, and Bastien's patches, we have removed about 4 seconds from Nautilus startup, and about 6 seconds from the whole session. There are still a bunch of slow places to chip away, and we haven't even begun to instrument gnome-panel, Tomboy (a 12-second pig), or metacity. For example, gnome-settings-daemon takes 4 full seconds to initialize itself.
It's like peeling potatoes. You first peel away the big chunks of skin, but some little holes remain. You then take care of those one by one. Who wants to help us peel these potatoes?
-
Improving login time, part 2: Nautilus, gnome-vfs-daemon, and bonobo-activation-server
(Index to the "Improving login time" series)
The school of rock:
- Johan takes my plotting script and adds the machinery to let it monitor exec()s, and add colors.
- Bastien has a patch for the Totem extension to Nautilus to make it start faster.
- Manny has a patch to speed up registration of icons in Nautilus.
- Michael digs into his private stash and brings out a patch to monitor bonobo-activation-server.
The tools:
-
Download plot-timeline.py. You'll need the Python bindings to Cairo to run it.
-
Take the program you want to monitor, and put this function in it:
static void program_log (const char *format, ...) { va_list args; char *formatted, *str; va_start (args, format); formatted = g_strdup_vprintf (format, args); va_end (args); str = g_strdup_printf ("MARK: %s: %s", g_get_prgname(), formatted); g_free (formatted); access (str, F_OK); g_free (str); } -
Sprinkle this among interesting places in your code:
program_log ("here is where we load a configuration file"); ... program_log ("loading plugin %s", plugin_name); -
Run strace with these options:
strace -ttt -f -o /tmp/logfile.strace my-program
-
Run the plotting program:
python plot-timeline.py -o prettygraph.png /tmp/logfile.strace
-
Look at prettygraph.png, scratch your head, slap your forehead, fix the code, go back to step 4 until satisfied.
WTF for today:
I added color-coding to the plotting script; now it codes the rows by the program to which they belong. This is useful to distinguish nautilus from bonobo-activation-server, for example.
I'm trying to see why there's such a big gap between Nautilus requesting that gnome-vfs-daemon be launched, and the time when it actually gets notified that g-v-d got launched.
See how tomboy and main-menu seem to block the activation of gnome-vfs-daemon? Nautilus is blue, for reference. I guess Michael needs to come to the rescue.
Instrumentation patches:
- libbonobo-instrument.diff - Monitor registration and activation in bonobo-activation-server.
- gnome-vfs-instrument.diff - Monitor when gnome-vfs-daemon gets launched and registered.
- nautilus-instrument.diff - Monitor various places during initialization.
Those are the raw patches. Note that some calls to program_log() are commented out; that's to reduce the amount of noise in that last log I took. You can uncomment them to get the full picture.
-
UPDATE: I now have proof that bonobo-activation-server recurses, and starves out callers if they are unlucky enough for b-a-s to get another request in the middle. Look for the big annotations in white.
This is going to be a bit tricky to fix. Michael says we can use some threading action in b-a-s to process incoming requests. I don't know if the CORBA architecture lets us do this elegantly, with a single thread and a single main loop, with a state machine and a big poll() — is there an API to *receive* CORBA calls asynchronously, rather than *make* them?
-
Improving login time, part 1: Nautilus startup
(Index to the "Improving login time" series)
This is a timeline of Nautilus starting up while logging in.
We have to reduce the white gaps on the left. The bottom rows of the plot indicate where Nautilus finally gets to painting the desktop; everything else is initialization.
The tools to make this plot are still a bit raw; I'll polish them and post them soon.
Who wants to help to fix each part? We can fix these problems in parallel; look at the numbers in the diagram:
-
nautilus-main.c calls register_icons(), and takes about 1.6 seconds. This initializes the GTK+ icon cache — if this part of the process takes a really long time (say, tens of seconds), it means that your icon cache is outdated and you should run gtk-update-icon-cache on the appropriate directories. Still, it is pretty slow at 1.6 seconds. What's going on here?
-
The initial call to gnome_vfs_get_volume_monitor(). I think this is what launches gnome-vfs-daemon. No idea on why it takes almost 4 seconds; I'm currently looking into this.
-
bonobo_activation_register_for_display(). Why does this take 0.35 seconds? Is bonobo-activation-server really busy during login, and so are applications contesting for it?
-
libtotem-properties-page.so, a Nautilus extension, 0.3 seconds. It initializes GStreamer on startup (!). Can it delay the initialization of GStreamer until Nautilus makes the first real call into any of the extension's methods?
-
libnautilus-ifolder.so, another Nautilus extension, 0.24 seconds. I'll ask the Novell guys about this.
-
Nautilus_Shell_start_desktop(), 1.5 seconds. No idea of what this really does.
-
This is the time from calling gtk_main() until the desktop gets painted: an enormous 2.1 seconds. Why is there such a large gap between entering the main loop and actually loading/painting the desktop? The ~/Desktop in that account is empty (it's a test account with no data in the home directory apart from dotfiles).
-
-
Kris, a very modest man indeed, wrote this in his slides about GTK+ 2.10:
"Work has been done on making the file chooser fully asynchronous"
He even made it the last bullet point in an otherwise unremarkable slide. Of course, what Kris meant to say is that he is my hero, as he took the entire sources for GtkFileChooser, and reworked them to have an asynchronous interface to the file system. I'm reviewing his extensive patch, and it is fantastic work.
Once this patch is in CVS (hopefully within the next two weeks), we can resume profiling the file chooser and making other important usability enhancements.
-
Last weekend Oralia went totally crazy and made arroz a la tumbada, my favorite seafood dish.
This is is red rice with crab, shrimp, fish, and octopus, and a ton of the magical epazote herb. We didn't manage to get fresh oysters or fish eggs. It turned out amazingly delicious; better than anything we have had in Veracruz. And a lot cheaper, too! For about 230 pesos, we were able to make seven portions — at a restaurant, that much would let you get three portions. We invited Hans Petter and Maru, and had a good time.
-
It's so sunny and warm but it is still winter.
-
Mexico City Metro stations replaced with anagrams:
