Profiling GMarkup – Take 2

Here we go again profiling GMarkup.

Finally, I’ve been able to compile sysprof, and launch a profiling session of the BookmarkFile parser under it. This time, I’ve been using a 1.6MB file, with 3360 bookmark elements. Just to shed a bit more light on the storage format, here’s a single entry:

<?xml version="1.0" encoding="utf-8"?>
<xbel version="1.0"
  <bookmark href="file:///tmp/test-xbel/test-1.txt"
      <metadata owner="">
        <mime:mime-type type="text/plain"/>
          <bookmark:application name="populate-recent"
                                exec="populate-recent --info %u"

This is a valid bookmark expressed using XBEL version 1.0; the important bit is contained in the href attribute of the bookmark element, and it’s the URI of the bookmark; then, we have three timestamps, expressed using the ISO8601 format (time relative to UTC). Everything else, is our meta-data for the bookmark entry: the MIME type, the registering applications, etc. The non-mandatory bits which are missing are the document’s name and description, the “private” hint, and the groups (or meta-classes) to which the entry belongs.

Now, picture three thousands of these entries, and you’ll have the needed background.

As a profiling thought experiment, we could already define plausible hot spots; first of all, since GMarkup is an event-driven parser, we will spend most of our time inside the callbacks defined for when the start of an element is found, for the end of the element and for the text node inside the element itself; we will also have hot spots when we have to deal with attributes and with data parsing – like the conversion from the ISO8601 timestamps to something usable under Un*x.

Some numbers…

After some thought profiling, here’s some real data.

Function %
main 92.56
egg_bookmark_file_load_from_file 91.14
egg_bookmark_file_load_from_data 90.16
start_element_raw 37.81
is_element_full 34.24
end_element_raw 22.94
timestamp_from_iso8601 9.58
egg_bookmark_file_add_item 9.23
text_raw_cb 1.36
egg_bookmark_file_free 1.01
egg_bookmark_item_free 0.94

These numbers come from a sysprof session during a thousand runs of the testbookmarkfile program (included in CVS) on a custom file containing ~3300 bookmark entries.

… Many words…

The testbookmarkfile program is really simple: it loads an XBEL file and prints the number of bookmarks that has been successfully parsed, before quitting. So, having the most of the time spent inside the egg_bookmark_file_load_* functions is really pretty much understandable. As I said in the first profile run, the file is loaded into memory using a buffered load, 4096 bytes at a time; the I/O, on a pretty decent machine, takes just .98% of the total time – which means that it’s basically drowned inside the system’s I/O latency.

Then, we have the three callbacks: start_element_raw_cb, end_element_raw_cb and text_raw_cb. The first one and the second one control the state machine used in order to recognize the element hierarchy and context, while the third gets the text stored inside the text nodes. This means that these functions are big “if…else if… else” blocks, where the actual state is checked and changed accordingly to the hierarchy rules defined by the storage format.

The first unknown entry, at this point, is the is_element_full function: what does it do? It checks if an element’s name is what we want it to be – in order to change the state of the FSM. Then why does it take ~34% of the computation time? Because of the xmlns:bookmark and xmlns:mime attributes you find inside the xbel element. These attributes are special: they are XML Namespace Declarations – that is, they say that whenever an element is prepended with a string matching the part after the colon of the xmlns attribute, then the element belongs to the namespace defined by the URI inside the relative xmlns attribute. Using namespaces we are able to include other elements than the one defined for a specific document, avoiding clashes, etc.; the custom meta-data we use inside the metadata tag is possible only because we use namespaced elements. All you have to do when you parse this stream, is to “resolve” the namespace before checking the element’s name – and that exactly is what is_element_full does: it resolves an element to a full element, that is an element prepended with the namespace URI, and then checks it against a URI and an element name we pass to it.

Obviously, even though it should be a fast operation (actually, is pretty much a constant-time operation), it must be done for each element, and for both start and end element callbacks, so we end up in there many times; fortunately, we provide a bunch of fast paths in it, and we also store namespaces inside an hashtable, so that it does take just a third of the total time. I was a bit skeptic on its reliability, though – and always felt that the check was a little to “sensible”; so far, is_element_full has proved me wrong – but I’ll always feel restless, and await the dreaded moment when someone breaks it.

As another big offender, we find the timestamp_from_iso8601 function. As its name implies, it transforms a ISO8601 timestamp into a Un*x one – that is, seconds from the Epoch (00:00:01 1.1.1970). I’ve taken part of the function’s logic from Mr. Project’s code, while the inverse function (timestamp_to_iso8601) was taken from Drivel’s XML:RPC code. I adapted them both, and made them a little bit stronger on the payload constraints. Anyway, while producing a ISO8601 formatted date is quite easy (just call strftime), the other way round is really not for the faint of heart. I was considering the option of producing a patch for making it a GLib function – many web-based projects would benefit from it, since the ISO8601 format should be the standard for expressing dates on the intarweb. As you can see, every bookmark element has three timestamps – so this function must be run three times per bookmark entry. That is probably why it’s accountable for the 9% of the overall time.

Another 9% of the time is spent adding a new item inside the list held by the BookmarkFile object. This is because the bookmarks are stored inside a GList, and indexed using an hashtable for faster lookup times. I’ve just noticed that I’ve used g_list_append in order to store a new BookmarkItem structure; we could shave of some time by using g_list_prepend instead, since we really don’t care of how the bookmarks are sorted – both on disk and in memory; actually, the only way to get a list of bookmarks is to get the URIs, and then access them one at a time, by its URI. So, thanks sysprof for this. (While I was writing this, I did the change; now the egg_bookmark_file_add_item time has become just ~3% of the total time – yay).

The lowest offenders are the egg_bookmark_*_free functions – which do nothing except… well… free the data. Since we have a couple of lists, we end up having to cycle through them in order to free the data.

… And a point

The point is that, surprisingly enough, BookmarkFile is performing quite well – and I say “suprisingly” because I didn’t expect it to at this point in time (it is a second iteration parser, written as a replacement for a libxml2-based parser); most of the time is spent in places where we could shave off something by micro-optimizing stuff (inlining some functions might yield better timings, as well as marking some unlikely path and letting the compiler do the dirty work).

This allows the code inside libegg/recentchooser to appear quite fast – or, at least, to put the blame on the performance issues of the RecentChooser widgets on Gtk instead of my parser code – heh.

The End (for now)

This profiling sessions wouldn’t have been possible without the great job of Søren Sandmann, who wrote sysprof, and – of course – Federico Mena Quintero, our profiling overlord. I’ve learned a great deal of things in order to correctely profile my code, and it really paid off in terms of speed and reliability.


Today I had a couple of hours to spare at the university, so I decided to implement a couple of items in my “to do” list.

The first is the creation of a simple function for adding items to the RecentManager – ideally, it should require just a URI and retrieve the data where possible. For the MIME of the resource, I used the xdgmime library, which is also used by GTK in order to interface the RecentManager code to the FreeDesktop.Org shared MIME informations; the application_name, application_exec tuple is filled with the default program name (as supplied by GLib). This should cut back some of the API complexity, and be useful just for the local file case. If you are dealing with remotely-placed resources, you should really use gnome-vfs, and fill up these meta-data fields by yourself.

The other item in my list was the thumbnailing support. James Cape did a wonderful job, implementing the fd.o thumbnailing specification inside a libegg module (for his IconChooser widget), so I just linked his code, and added an appropriate function for the RecentInfo object.

recent documents thumbnails
Now, both the RecentChooserMenu and the RecentChooserWidget can display thumbnails of the resources.

Profiling GMarkup – take 2. After having profiled GMarkup with a medium sized file (under 1000 bookmark entries, approx. 400KB), I’ve set off to profile it using a >1MB file, in order to get some more experimental data on the edges of GMarkup. During the last GTK meeting, Federico suggested that GTK could read the GConf XML and retrieve some of the preferences from there – instead of making GTK depending on GConf (which would mean making it depending on ORBit2, libxml2 and others). I’ve expressed some doubts about this operation; mainly because reading the recently used resources file one in a while is not so intensive: after all, we are talking about one thousand entries at most (I do clean my recent documents once in a while), while a common $HOME/.gconf directory spans typically more than 1 MB on disk. The preliminary figures I gathered last night are that parsing a 1.5 MB file with GMarkup will take up at most ~2.5 seconds with cold cache and ~1 second with hot cache (on a test with 10000 sequential runs). Federico is trying to shave off decimals of seconds from the FileChooser – a 2 seconds delay just for reading the GConf database is just wrong; also, what if the configuration is not local or user-defined? We can’t read (let alone modify) some of the settings if the system administrators locked them down. So, in the end, I think that this is just not the way to go.

Jody Goldberg proposed the creation of a KeyFile-based configuration system just for GTK; this would bring GNOME into the exciting nineties, right at the side of Windows 3.1 with its .INI files.

While I wholeheartedly agree with Federico and Jody that GTK should be able to save some of its state data, I also feel that both GConf and a INI-like solutions are not the best one for this issue. I don’t know what to propose in place, though, so I’ll just shut up for the time being.


Today, Marta went to Trento to visit some relatives of hers, so I spent the entire day alone. I’ve studied for a while (I have a OS exam monday, mostly Linux-based on the case studies, even though the kernel shown is a 2.0 at most), and then I spent the entire afternoon rewriting the recent files storage parser using just GMarkup, in order to drop the libxml2 dependency.

Now, after looking at the resulting 3000+ LOC I really need my eyeballs to be removed and cleaned. I had to put tugether a state machine in order to validate the incoming data, and in order to remove part of the if (...) { ... } else if (...) { ... } else { ... } madness resulting of having to deal with an event-based parser.

Anyway, seems that it worked out pretty well.


The EggRecentChooserWidget code is in CVS since a bunch of minutes, complete with a context menu allowing the removal of items from the list, the ability to add a custom RecentManager instance instead of using its own (still requires some polishing, but the interesting bits are there), and filtering based on a custom function. Also, I’ve fixed a nasty bug in the parser library that left garbage at the end of the storage file when removing items.

The next step is to allow the creation of RecentManager objects (maybe using runtime loadable modules) so that Gnome could use a GnomeVFS enabled resource monitoring in order to track location/file changes. This would require the implementation of RecentManager as a GInterface, as a plausible approach.

Anyway, now I’ll work on an applet/technology demonstrator, in order to have more to show to the Gtk people.


I’ve pretty much finished my EggRecentChooserWidget widget, which (I noticed) is roughly modelled on the Document History window of the Gimp:


Also, as you can see, I’ve enable the filtering code, so that you can now filter the contents of the recently used resources list on the fly:

Display all recently used resources.
Display today’s recently used resources.

The EggRecentChooserWidget will also have a dialog window (EggRecentChooserDialog) and a button widget (EggRecentChooserButton), much in the same philosophy of the GtkFileChooser widget set. In the source tree I’ve put a simple test program which basically recreates the same Open Recent menu of the Gimp (except for the little preview, which is replaced by the icon bound to the file’s MIME type).

There are some rough edges I’d like to address before committing the code, but I plan to have the widget and the dialog inside CVS by this week.

On a related news, I’ve began porting the panel to the RecentChooser and RecentManager code; other than changing the Open Recent menu widget with the EggRecentChooserMenu one (complete with a menu item launching the EggRecentChooserDialog dialog in order to display all the recently used resources), I plan to add a list of recently used applications inside the Run Application dialog; using this list as a default, we could hide the currently used entry.

Check out

I’m back from Amsterdam with a ton of pictures (most of them really ugly: I’m not much of a photographer), that will be uploaded on Flickr, if and when I find the time/bandwidth.

Since my parents first, and my brother next are leaving for their holidays too, me and Marta are going to stay at my parents place for a week or so; unfortunately, here I don’t have a broadband connection but just a 56k one – and that is paaaainfully sloooooow: how on earth did we use it and survive after using it? And mind you me: I’ve used any connection from a 14.4k to a T3 connection, only that now I have a couple of CVS trees to look up and a box to maintain up to date.

Anyway, I’m preparing coffee and chocolate for a long night of downloads – just like when I dist-upgraded my old Potato to Unstable, three years ago.

Now boarding…

holidays: I’m leaving for a week in Amsterdam, with Marta.

I’ve already been in Netherlands, years ago with my family, so I already know the city; it’ll be fun to track down what changed, and to see new things.

work: As of july 26th I’m officially unemployed – or, better, in recovery (in a Scary Devil Monastery sense). And, by the way, if you are hiring, and you need a C/Perl developer with sysadmin skills, please feel free to contact me.

hacking: Well, the infamous RecentChooserWidget is finally here:


Still lacking the filter and drag and drop on the list, but everything else is here.

I’m planning to write an applet soon as I return from Amsterdam.

Hit me

cvs: The New! And! Improved! code for handling and viewing the recently used resources list has hit


It basically works, even though the menu has still some rough edges.

I plan to work on the list widget until this week-end.

life: Marta got graduated! She held her dissertation last friday, and got full grades with a cum laude. Now she is a Math major, and she’d like to get a Ph.D., possibly abroad and not in Italy. That would mean a job in a foreign country also for me.

holidays: A week in Amsterdam. And I think I said all that is needed to be said.

Recent files woes

Yesterday, on IRC, there has been some discussion about my recently used resources handling proposal – especially with regards to the storage format.

I hate discussing on IRC; I’m not fast enough a typist – and since english is not my primary language, I find it very difficult to make myself understandable. So, I decided to put here some of the rationales for changing the storage format of the recently used resources list, written down in form of Q&A.

Storage format

Q: Why did you have to change the format?
A: Because the old format, as defined by the recent-file spec has shown its limits, since it has been proposed. Also, that spec is still a draft, and it’s not used by anyone else but Gnome.

Q: What limits the recent-file spec has?
A: It lacks the meta-data needed to know which applications registered a recently used resources. It lacks descriptors for meta-data such as a human readable name for the recently used reosurce.

Q: But recently used files need not a human readable name. Why should we use it?
A: The “human readable” name and description are not mandatory. Anyway, a user might have set that meta-data on its document; we strongly encourage the existence of this metadata. It would be totally unfriendly to show the file name instead of what the user decided to use as a name for that document. Also, “Wireless adapter WX-6615 Manual” is more readable than “wx-6615.pdf”. Anyway, the XBEL DTD makes the title and desc entities non-mandatory, so we can use them only if needed.

Q: Still, a recent file is not bookmark; then, why allow things that a bookmark allows on a recently used file pointer?
A: For me, a recent file is a bookmark to a file, with a lifetime that is kept artificially short, so it makes perfectly sense to use a bookmark-definition language in order to store it. You are gladly invited to prove me wrong, by providing examples on how a pointer to a recently used resource could be described apart from using a URI, and why does XBEL fail to store and describe a pointer to a recently used resource on.

Q: We could extend the recent-file spec, then, instead of using XBEL; did you think about it?
A: Yes, in fact I did. The first proposal of the desktop-bookmark spec used an updated version of the recent-file spec, but it was shot down, and usage of XBEL was proposed.

I’ll add more entries…

Update: directly from the libegg/recentchooser/README file:


Q: Why did you wrote the RecentManager?
A: The code living recent-files started to bit-rot, after being unmaintained for a long time; also, we never made clear whether the RecentModel code should live in a Gnome platform library on the same level of libgnome, or on a lower position on the dependency chain. The RecentManager code should go into Gtk, so it does not depend on anything more than GLib, Gtk+ and libxml2.

Q: In which library this code should go?
A: Inside Gtk+, starting from the 2.9 development cycle (I hope).

Q: Why Gtk? Why not libgnome?
A: We are in the process of getting rid of libgnome, so Gtk makes sense.

Q: Why this shouldn’t go inside a custom library?
A: Because I don’t want to create Yet Another Library upon which Gnome should depend; also, the requirements of this library would really be Glib, Gtk+ and libxml2, so there would be nothing gained by keeping this code outside Gtk+.

Q: The old recent-files code depended on libgnomevfs. Why yours does not?
A:The recent-files code depended on libgnomevfs for the fancy stuff needed in order to retrieve the MIME type of a file, and on the conversion of the URI in order to be displayable; also, it needed libgnomevfs for the monitor on the storage file. The MIME stuff could go away, since we require the user of this code to pass the MIME type of the resource when registering it; it makes sense, because if you used libgnomevfs yourself in your code, you wouldn’t have to check the MIME type twice. Also, many of the UTF-8 and URI manipulation code it’s now available directly inside GLib. At the end of the day, the recent-files code only needed the GnomeVFSMonitor from libgnomevfs – and that could be easily replaced with a timed poll() on the file.

Q: The old recent-files code depended on libgnomeui. Why yours does not?
A: The only left-over of the libgnomeui dependency inside libegg/recent-files was the usage of gnome_icon_lookup() function in order to retrieve the icon bound to the MIME type. I removed it, and switched to the same system used by the GtkFileChooser object (we’ll also share the icon cache, so it should even be more efficient once this code goes in Gtk+).

Manager API

Q: Shouldn’t you have tried to save the RecentModel object first?
A: I tried, at first. It soon became obvious that the RecentModel code had become a collection of hacks, especially WRT visualization, trying to hide its usage of Gnome-VFS; also, the storage file format was subject to a review process, both for enhancements and for interoperability. The model code would have been subject to a mass rewrite process anyway.

Q: No, really, I liked the RecentModel API, can’t you please keep it?
A: The short answer is no. The long answer is: it’s not worth it. The RecentModel tried to retrieve for itself most of the metadata reguarding a recently used resource. While this kept the API simple (what you had to do was to feed it a URI, in most of the cases), it also had a negative impact on the performances of the RecentModel object – which, obviously, negatively impacted on the overall performance of the widgets. Even if you did not use Gnome-VFS, the RecentModel was depending on it for querying the file metadata; if you did use it, you ended up with twice the number of the queries: one did by you code, and one did by the RecentModel code; this, especially in a networked environment, had caused many performance issues that the only solution was to create a RecentItem by yourself – and that made the API as complex as the RecentManager API could be (in fact, a bit more complex, since a RecentData structure is very lightweight when compared to a RecentItem object).


Q: You even changed the viewer widget. Why did you scrapped the entire EggRecentViewGtk object?
A: I really hated its name.

Q: Now, be serious…
A: Okay: I hated the whole thing – starting from the name. It was a clever hack, which tried to be useful for both the “inlined recent files” and the “recent files sub-menu” concepts. But it was an hack – which, clever or not, had passed the point of being maintainable. The interface upon which was based was too simple for being useful (EggRecentView only has two methods: “set_model” and “get_model”), so it had to be refactored; the menu API was too dependent on the RecentModel code – which led to separation issues when it came to visualization; for instance, you don’t sort a ListStore: you pass a sorting function to the TreeView, so that you can have multiple views of the same data. The same should happen with the Recently Used Resources List: same data, multiple viewers. Oh, and did I mention that the name was ugly?

Q: Why the RecentChooserMenu shows up in a sub-menu? Wasn’t this removed from the HIG?
A: It was indeed removed, and I consider it a mistake made by the GUP. The rationale for its removal was, shortly: “recently used files should live on the same level of the Open menu item”; which could be fine – if it didn’t bring up issues involving latency when building the File menu; or issues involving the total utility of a list composed of just four items. I believe that the “Open Recent” menu just as appears in OS-X should be the right approach, WRT recently used resources shown in a menu. Also, this keeps the code compact (the entire RecentChooserMenu size is < 1 kLOC), and maintainable.

Q: What if I wanted an inlined recently used resources list?
A: It’s not difficult to build, using the list returned by the RecentManager; you don’t even need to implement a widget:

     menu_item = gtk_separator_menu_item_new ();
     gtk_menu_shell_append (GTK_MENU_SHELL (file_menu), menu_item);
     gtk_widget_show (menu_item);

     manager = egg_recent_manager_new ();
     egg_recent_manager_set_limit (manager, 4);
     egg_recent_manager_set_sort_type (manager, EGG_RECENT_SORT_MRU);

     items = egg_recent_manager_get_items (manager);
     for (l = items, count = 1; l != NULL; l = l->next, count++)
         EggRecentInfo *info = (EggRecentInfo *) l->data;
         gchar *text, *name;

         name = egg_recent_info_get_display_name (info);
         text = g_strdup_printf ("_%d. %s", count, name);

         menu_item = gtk_menu_item_new_with_mnemonic (text);
         gtk_menu_shell_append (GTK_MENU_SHELL (file_menu), menu_item);
         gtk_widget_show (menu_item);

         egg_recent_info_unref (info);

     g_list_free (item);

     menu_item = gtk_separator_menu_item_new ();
     gtk_menu_shell_append (GTK_MENU_SHELL (file_menu), menu_item);
     gtk_widget_show (menu_item);

Less than thirty lines of code.

Q: Do you plan to create a inlined menu widget?
A: Eventually; if the HIG does not change, or if the demand is high enough. Or you could implement it. It’s Open Source, you know…

Recent Menu

recent-chooser: Finally, after more than one month of hacking on the RecentManager object, I’ve been able to create a reasonable “Open Recent” menu widget:

Obligatory screenshot of the new and improved recent menu

The icon code is placed in the RecentInfo object, and it’s based on the GtkFileSystemUnix code, complete with the pixbuf cache (ideally, it should be shared across GtkFileChooser implementations and GtkRecentChooser implementations).

Right now, it does not have filtering abilities other than a filter function you must feed to the RecentManager (for that, I’ll implement a RecentFilter object); also, the “Clear” item is always shown, and the tooltips aren’t attached yet.

But it’s a start, and it’s also a way lot saner than the current EggRecentViewGtk object (starting from the class name).

recent-files: bug-fixing still going on… The bug count is down to twenty items, with 6 marked as enhancement (which I keep open as a feature reminder).