Evolution Data Server Under Sysprof
June 4, 2008
My gsoc task is to speed up calendar part of e-d-s. These days I have been using evo calendar extensively. My aim was to identify the most serious bottlenecks by sysprof.
Here are the results of my 5 minute session. The tests were carried out on big calendars, which I received from Federico.
Several things should be noticed:
- Almost all system time is divided between Evo and Firefox
- About 30% of system time was spent in Evolution, 15% in e-d-s.
- I was using only file backend (e-d-s time was spent in e_cal_backend_file_start_query - 14%)
Analysis:
- Almost all e-d-s time was spent in e_cal_backend_start_query – 14%. This method is called by e-d-s clients (Evolution, clocks…) and does complete sweep through the calendar. Clients want to get back calendar objects filtered by some expression (sexp).
- For every calendar object, test against the expression is carried out (e_cal_backend_sexp_match_comp - 11%), generating all recurrences. Usually, the evaluation of expression leads to test, if event occurs in some time range (func_occur_in_time_range - 6%). The second very often used function seems to be e_cal_backend_sexp_func_make_time – 3.9%. Both these functions sooner or later call function icaltime_as_timet_with_zone, in which is spent 3.60% and 3.13% – summing up to about 6.7% of system time. In fact, these functions are usually called together, because the typical test is “occur-in-time-range? (make-time \”ISO_DATE_STR\”) (make-time \”ISO_DATE_STR\”)”. The expression make-time “ISO_DATE_STR” leads to calling e_cal_backend_sexp_func_make_time, which converts date from iso string to time_t value. Expression occur-in-time-range leads to calling func_occur_in_time_range.
- When constructing expression “occur-in-time-range? (make-time \”ISO_DATE_STR\”) (make-time \”ISO_DATE_STR\”)”, time_t value is converted to the string. Later, when evaluating expression, string is converted to time_t (by make-time).
Conclusions:
- In e-d-s we spent about 15% of system time, and almost 7% was spent in icaltime_as_timet_with_zone. The function is called to find out, if calendar event occurs in some time range. There is a lot of time conversion from time_t to string and back. The rest was spent by sweeping through the calendar objects and generating recurrences.



I can give you some monster calendars for testing. Please hit me up on #evolution on the IRC. My account is dave_largo.
So is icaltime_as_timet_with_zone too slow or called too many times?
I was profiling some Java code the other day and it said that most time was spent in MyObject.compareTo(). Fairly difficult to make that function much faster, but it was possible to stop it being called O(n^2) times. Looking forward to next post.