Hi, 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 Shell.py was called 695 times. 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 (http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/picker.stats) http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/picker.stats.svg 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 (http://lists.laptop.org/pipermail/devel/2008-July/016722.html). The shell is taking the 7% of cpu-time; isn't it too much for this task? cProfile statistics (KCacheGrind format) for the journal: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/cProfile-journalactivity The journal spends 69.4% of it's time in __refresh_idle_cb in listview.py. 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/palettes.py (2211 calls) 3.7 : cairo.Context.paint() 3.3 : __init__ sugar/graphics/palette.py Asynchronous dbus calls ? Perhaps icons and palettes could be cached ? cProfile statistics (KCacheGrind format) for Write: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/cProfile-write Similar results were already commented at http://lists.laptop.org/pipermail/devel/2008-July/016722.html 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): http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/cProfile-datastore cProfile statistics (KCacheGrind format) for sugar-shell: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/cProfile-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/icon.py (1509 calls) 2.9 : wnck.Window.activate() 2.1 : __init_ in sugar/graphics/palette.py (859 calls) Perhaps icons and palettes could be cached ? sysprof statistics: http://dev.laptop.org/~rlucchese/ActivitiesSwitching/journal-write/sysprof.data Similar results were already commented at http://lists.laptop.org/pipermail/devel/2008-July/016722.html 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 ? thanks, riccardo _______________________________________________ Devel mailing list Devel@lists.laptop.org http://lists.laptop.org/listinfo/devel