2007-12-25

25 12 2007

So I kept profiling m-m today.

I found that g_get_language_names called g_getenv a lot, which in turn calls getenv. This account for ~5% of the startup time of m-m as seen below;

m-m-org-glib

Since I know that Michael Meeks came to this same conclusion in his blog about gnome-menus, I decided to run a quick test with gnome-menu-spec-test. The result is this;

g-m-org-glib

Having a look at g_get_language_names I found that it does have a cache for language names, but it didn’t seem to be used efficiently. Now, I don’t know if there is a reason to find out if the language has changed while a program is running, but for the life of me, I can’t think of one.

Here’s a small snippet of the code;


if (!cache)
{
cache = g_new0 (GLanguageNamesCache, 1);
g_static_private_set (&cache_private, cache, language_names_cache_free);
}
value = guess_category_value ("LC_MESSAGES");
if (!value)
value = "C";
if (!(cache->languages && strcmp (cache->languages, value) == 0))
{
gchar **languages;
gchar **alist, **a;

It checks to see if it cached the language and if it did, retrieve the cache. Then it goes to check the language variables (no matter if it had a cache or not). I made a simple code change to NOT check the variables if the cache exists. Since I’ve never looked at the glib2 code before, I don’t know if the patch is sane, so I’ve asked for a review. But the cache here is per application, so changing the environment variables and starting a new application will work.

Result of the code change is this for m-m;

m-m-new-glib

And this for gnome-menus;

g-m-new-glib





2007-12-23

23 12 2007

The openSUSE GNOME Team spent last week hunting bugs in the GNOME Main Menu. Since I was on site at a customer, I entirely missed the event :-/

So I thought I should try to make up for it, by profiling g-m-m today.

The first thing I found was this;

document_tile_private_setup

Adding Favorite Documents and Recently Used Documents to m-m accounts for >20% of it’s startup time. Out of that, 19% is spent in gnome_vfs_mime_get_default_application.

Looking at the code for it reveals (surprise surprise) that it’s used to figure out what default application to open the document with. It seemed unnecessary to call such an expensive function for each Document so I decided to move it out of there. That meant that for each application, document_tile_private_setup would now use a standard function (run a function which in turn opens nautilus) instead. That standard function will only be called if the user clicks on a Document, so I added the call to gnome_vfs_mime_get_default_application in there. This will not only save valuable startup time, but also a little bit of memory.

The next thing I looked at, and it is one of my favorite things to do in Slab, is the creation of a context menu for each Document. Again, the only time it would be used, is if the user right clicks on a Document. So I modified the code to only create the context menu if the user right-clicks on a document. Again, some savings in both startup time and memory.

Then the third thing, and which took most of the time today, was the fix up the following;

g-m-m-init

The create_rct_docs_section accounts for 45% of the initialization here. All up, tile_table_new, which is called by each function that adds an item to m-m, is using 57%.

After moving the code around a bit (sounds easy doesn’t it?), and also fixed a bug, I ended up with this;

g-m-m-opt1

Now, that looks alright for a days work. Although not all finished with this yet (need to fix a bug that I introduced :-), it was a good day overall.

I tried to publish the diff here but wordpress didn’t like it much. Download it from here instead.

UPDATE!
I just realized that it looks a bit funny when comparing the two charts above. To clarify, it does not mean that the startup time have been reduced by >50%. These are numbers from the current view that I was looking at. Some of the work is now done in other functions which is not visible in the last chart. Once done with this first round of optimizations, I’ll try to publish a better view which shows how much we’ve gained.





2007-12-16

16 12 2007

I’ve been putting experimental code in AB to use a sqlite database for application cache.

To start, I created three tables;

create table Category (name TEXT PRIMARY KEY, id INTEGER);
create table Desktop (name TEXT, genericname TEXT, comment TEXT, exec TEXT, path TEXT PRIMARY KEY, id INTEGER);
create table DesktopCategory (desktop INTEGER, category INTEGER);

I then populate Category with the different categories, Desktop with all the applications and then the relationship table between Desktop applications and Categories.

On a warm startup (ie. everything is in filesystem cache), it saves 20% of the startup time compared to using gnome-menus.

I need to play around with this a bit more, but if it proves to be a feasible solution, then it’d be a good idea to store even more data in the database.

The biggest problem with doing it this way instead of using realtime data is obviously if AB doesn’t get started for a while and new software is added or removed. We’d end up for bad data.

Here’s AB using gnome-menus

AB using gnome-menus

And here’s AB using sqlite

AB using sqlite





2007-12-13

13 12 2007

I’ve been playing with Application Browser from the tile-2 repo. It’s nothing like AB in the original code and it feels so much faster.

Unfortunately, the previous profiling were done on my old machine which is no longer with us. Although not very important, it’d still be interesting to see how the two versions compare, so I will get some numbers from both and put them up here.

I’ve been running the new AB through valgrind to get a handle on what this new code is doing. While checking the results in kcachegrind, I found this tab called “Call Graph”, so I clicked on it. And for a while, I thought I died and went to heaven 🙂

This fantastic graph popped up my screen

callgrind-output-tile-2

I have yet to figure out if it can give me time instead of percentage, but it will certainly make life easier either way!

Apparently, Mikael Meeks have some ideas on what to do with gnome-menus  (in which AB spends ~30% of it’s time), so looking forward to hear his ideas.





2007-11-17

12 12 2007

G’day!

To start off, just a disclaimer…
I’ve not done any GNOME/GTK development ever nor am I very experienced in GUI programming. What I’m hoping to get out of this is; 1) Experience with GNOME/GTK, 2) Experience with debugging and 3) A super fast menu system 🙂

And off course, chances are that posts that has nothing to do with Slab finds is way here as well.

So this is my first post about Slab, the new GNOME Main Menu. I’m currently looking at ways to make it perform as it was on drugs.

I will start off by profiling the Application Browser (AB).

In order to improve performance, one should start by profiling the application. At least that’s what Federico says, so that is what I will do 🙂
After profiling is complete, one needs to decide what to optimize. Again, Federico says that you can’t optimize without having goals, and again, I will obey.

I’ve actually already cheated and done some profiling that I posted on the openSUSE wiki. But for the purpose of this blog, I will start all over 🙂

So the first thing to do is to add some debug code. I’m going to use the following (very simple, but yet not very elegant function 🙂

void timeCount(char *funcName)
{
    struct timeval tv;
    gettimeofday(&tv, NULL);
    long tms;
    int i = 0;
    int func = -1;
    char *formatted, *str;

    tms = tv.tv_sec * 1000 + tv.tv_usec / 1000;
    while(lapse[i].last) {
        if(!strcmp(funcName, lapse[i].funcName)) {
        func = i;
        break;
        }
        i++;
    }

    if(func == -1)
        func = i;

    if(!lapse[func].last) {
        strcpy(lapse[func].funcName, funcName);
        lapse[func].hello = 0;
    }

    if(!lapse[func].init) {
        lapse[func].last = tms;
        lapse[func].init = 1;
        lapse[func].hello += 1;
        str = g_strdup_printf ("MARK: %s: %s Begin", g_get_prgname(), funcName);
        }
    else {
        lapse[func].curtime = (tms-lapse[func].last)+lapse[func].curtime;
        lapse[func].init = 0;
        str = g_strdup_printf ("MARK: %s: %s End", g_get_prgname(), funcName);
        }

    access (str, F_OK);
    g_free (str);
}

Now I need to add this function to the beginning and end of various functions that I want to profile. I also add an exit statement in the application instead of calling gtk_main(). This allows me to run in batch mode without having to kill AB.

Then I start the application as follows;
strace -ttt -f -o test-strace.log application-browser

Once done, I use plot-timeline.py to generate a pretty picture.

The end result becomes this;

Prof1

And this (Second column is the number of times the function was called and the third column is the total time spent in that function);

"generate_categories","1","1919"
"generate_categories ==> gmenu_tree_get_root_directory (app_data->tree)","1","854"
"generate_new_apps","1","44"
"layout_shell","1","12"
"create_main_window","1","1374"
"show_shell","1","1361"
"gtk_widget_show_all","1","1361"

After sprinkling some more debug code (and also added the option to not include a specific function in the plot), the result is;

Prof2

"main","1","0"
"generate_categories","1","2588"
"generate_categories ==> gmenu_tree_get_root_directory (app_data->tree)","1","860"
"generate_category","9","1666"
"generate_launchers","95","762"
"check_specific_apps_hack","154","19"
"insert_launcher_into_category","162","1545"
"application_tile_new_full","162","1130"
"nameplate_tile_class_init","1","0"
"nameplate_tile_constructor","172","117"
"nameplate_tile_init","172","11"
"nameplate_tile_setup","172","41"
"application_tile_setup","162","851"
"themed_icon_new","162","52"
"themed_icon_set_property","324","18"
"nameplate_tile_set_property","678","198"
"themed_icon_show","162","127"
"libslab_get_gconf_value","1","7"
"libslab_gconf_notify_add","1","0"
"libslab_gnome_desktop_item_new_from_unknown_id","13","12"
"application_launcher_compare","3212","193"
"generate_new_apps","1","62"
"layout_shell","1","27"
"app_resizer_new","1","0"
"app_resizer_get_type","24","0"
"app_resizer_class_init","1","0"
"create_application_category_sections","1","13"
"populate_application_category_sections","1","9"
"remove_container_entries","12","1"
"populate_application_category_section","10","8"
"app_resizer_layout_table_default","10","5"
"resize_table","10","2"
"relayout_table","10","3"
"app_resizer_set_table_cache","1","0"
"create_filter_section","1","1"
"create_groups_section","1","0"
"populate_groups_section","1","0"
"create_actions_section","1","0"
"create_main_window","1","1377"
"show_shell","1","1364"
"gtk_widget_show_all","1","1364"
"themed_icon_style_set","162","202"
"app_resizer_size_allocate","3","65"
"relayout_tables_if_needed","2","0"
"calculate_num_cols","2","0"

Running the same as above, but without strace will render completely different numbers. So for the sake of being able to create pretty pictures throughout this exercise, strace will only be used when we need to create a new pretty picture and we can then compare that to what we have above. The numbers below were generated without using strace.

"generate_categories","1","821"
"generate_categories ==> gmenu_tree_get_root_directory (app_data->tree)","1","337"
"generate_category","9","463"
"generate_launchers","95","216"
"check_specific_apps_hack","154","0"
"insert_launcher_into_category","162","453"
"application_tile_new_full","162","400"
"nameplate_tile_class_init","1","0"
"nameplate_tile_constructor","172","53"
"nameplate_tile_init","172","0"
"nameplate_tile_setup","172","29"
"application_tile_setup","162","314"
"themed_icon_new","162","6"
"themed_icon_set_property","324","0"
"nameplate_tile_set_property","678","76"
"themed_icon_show","162","54"
"libslab_get_gconf_value","1","0"
"libslab_gconf_notify_add","1","1"
"libslab_gnome_desktop_item_new_from_unknown_id","13","2"
"application_launcher_compare","3212","2"
"generate_new_apps","1","21"
"layout_shell","1","11"
"app_resizer_new","1","0"
"app_resizer_get_type","24","0"
"app_resizer_class_init","1","0"
"create_application_category_sections","1","6"
"populate_application_category_sections","1","2"
"remove_container_entries","12","0"
"populate_application_category_section","10","1"
"app_resizer_layout_table_default","10","1"
"resize_table","10","0"
"relayout_table","10","1"
"app_resizer_set_table_cache","1","0"
"create_filter_section","1","0"
"create_groups_section","1","1"
"populate_groups_section","1","0"
"create_actions_section","1","0"
"create_main_window","1","1156"
"show_shell","1","1144"
"gtk_widget_show_all","1","1144"
"themed_icon_style_set","162","178"
"app_resizer_size_allocate","3","58"
"relayout_tables_if_needed","2","0"
"calculate_num_cols","2","0"