Report on `switching between activities and the journal'

riccardo riccardo.lucchese at
Mon Jul 21 10:20:13 EDT 2008


Problem: switching between activities and the journal is slow

Test-case: the test consist of starting Write and switching between it
and the journal for a sensible amount of time. All tests were run on a
xo; the journal had 50 entries. Switching was automated by calling
shell.activate_next_activity() every ~730ms (as the minimum value at
which both activities could get completely redrawn).

Real transition timings differ from the timer's period value of 730ms.
The `switch' journal -> write takes an average of 735ms while the
transition write -> journal takes values from 1 to 2 seconds.

During the test, activate_next_activity() in was called 695

cpu usage data gathered with Picker (pid 2564 is the Write activity):
tot% ps% cmdline
     34.6 python /usr/bin/sugar-activity journalactivity ...
57.1 22.6 python /usr/sbin/rainbow-daemon --daemon ...   [Write]
77.9 20.8 python /usr/bin/datastore-service
85.0 7.2  python /usr/bin/sugar-shell
91.5 6.5  /usr/bin/X :0 -fp built-ins -wr -auth ...
97.1 5.6  picker


They were obtained by running:
$ picker
$ grapher -c6 -r cpu

The 22.6% took by Write is due to the activity saving and loading its
state (taking screnshots, reading/writing files..) regardless it change
or not (

The shell is taking the 7% of cpu-time; isn't it too much for this task?

cProfile statistics (KCacheGrind format) for the journal:

The journal spends 69.4% of it's time in __refresh_idle_cb in

Ordering by function self-time:
29.7 : send_message_with_reply_and_block of dbus
15.7 : gtk.main()
10.9 : __init__ in activities/Journal.activity/ (2211 calls)
3.7  : cairo.Context.paint()
3.3  : __init__ sugar/graphics/

Asynchronous dbus calls ? Perhaps icons and palettes could be cached ?

cProfile statistics (KCacheGrind format) for Write:

Similar results were already commented at for a
similar task.

cProfile statistics (KCacheGrind format) for the datastore-service
aren't much interesting this time (a separate test case should be
designed for it):

cProfile statistics (KCacheGrind format) for sugar-shell:

51.3% of time in the shell is going to send_message_with_reply_and_block
of dbus. I guess this is because of the calls to the activities's
services; maybe some of them can be made asynchronous ?

Other functions showing particularly up by self-time are:
20.8 : gtk.main()
4.1  : __init_ in sugar/graphics/ (1509 calls)
2.9  : wnck.Window.activate()
2.1  : __init_ in sugar/graphics/ (859 calls)

Perhaps icons and palettes could be cached ?

sysprof statistics:

Similar results were already commented at for a
similar task.

Only one more thing I note particularly:
1. Python is spending a lot of time in the kernel.
   Too much reading/writing to the nand ?


More information about the Devel mailing list