11.9. Finding the Time Differences

Now that we have narrowed down which functions do the work of creating the menu, we want to figure out which pieces are taking up all the time and which pieces are relatively lightweight. A great way to do that, without using any performance tools at all, is to just disable pieces of code and see how it changes performance. Even though this causes nautilus to function incorrectly, it will at least indicate which of the functions are taking all the time.

We first have to start by taking a baseline, because the binaries we are testing have been compiled with different flags than those provided by Red Hat. We time the scripts as we did before. In this case, a run of 100 iterations takes 30.5 seconds on the version that we have compiled ourselves. Next, we comment out the eel_pop_up_context_menu call. This shows us how much time it took nautilus to detect the mouse click and decide that a context menu needed to be created. Even if we completely optimize away all the commands in these functions, we will not be able to run any faster than this. In this case, it takes 7.6 seconds to run all 100 iterations. Next, we comment out bonobo_window_add_popup to see how much time it costs us to actually call the function that ltrace says is taking the most amount of time. If we comment out bonobo_window_add_popup, the 100 iterations take 21.9 seconds to complete. This says that if we optimize away the bonobo_window_add_popup, it can shave ~8 seconds off the total run, which is nearly a 25 percent improvement.