[Sugar-devel] A trick to profile activities startup time

[Gonzalo Odiard]

One trick is the following (example using the Abacus activity):

* In sugar, start one activity
* without close the activity, go tot the terminal, and see the command line
used to run it
$ ps ax | grep Abacus
2250  ?             Sl         0:10  python2 /usr/bin/sugar-activity
AbacusActivity.AbacusActivity -b org.sugarlabs.AbacusActivity -a
ff8dc731a329b184b7d28c40cc85c47ff2e433cb -o
7ae05000-b61c-4fd8-9b66-e5125f3ba81f > abacus_profile.log

* close the activity you want profile.
* in the terminal do:
$ cd Activities/Abacus.activity
$ python2 *-m cProfile */usr/bin/sugar-activity
AbacusActivity.AbacusActivity -b org.sugarlabs.AbacusActivity -a
ff8dc731a329b184b7d28c40cc85c47ff2e433cb -o
7ae05000-b61c-4fd8-9b66-e5125f3ba81f *> abacus_profile.log*

Adding -m cProfile to get the profile information, and redirecting to a file
The activity will start, in this case, some of the icons are not displayed.
Close the activity and check the generated file, in this case
abacus_profile.log

The content of the file is attached, have columns like:

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.002    0.002    0.002    0.002 <string>:1(<module>)

Explanation about what means every column is here:

https://docs.python.org/2/library/profile.html#instant-user-s-manual

Sorting by the second column (tottime) , and filtering the top 20 we can
see:

[gonzalo at localhost sugar]$ sort -nr -k2
/run/media/gonzalo/0824-E6BD/abacus_profile.log | head -20
        1    2.879    2.879    5.105    5.105 activity.py:375(run_main_loop)
      504    1.177    0.002    1.212    0.002
abacus_window.py:108(_svg_str_to_pixbuf)
       30    0.696    0.023    1.392    0.046 abacus_window.py:329(update)
      420    0.559    0.001    1.289    0.003 sprites.py:312(draw)
      448    0.433    0.001    0.786    0.002
sprites.py:120(remove_from_list)
5642/5394    0.387    0.000    0.666    0.000 module.py:252(__getattr__)
     1156    0.359    0.000    0.359    0.000 {method 'remove' of 'list'
objects}
      309    0.236    0.001    1.142    0.004 sprites.py:232(set_layer)
        1    0.221    0.221    0.512    0.512 activity.py:231(__init__)
      363    0.207    0.001    0.455    0.001 sprites.py:347(draw_label)
       20    0.198    0.010    0.198    0.010 {method 'paint' of
'cairo.Context' objects}
      420    0.145    0.000    0.145    0.000 {method 'fill' of
'cairo.Context' objects}
       63    0.143    0.002    0.143    0.002 {method 'write' of 'file'
objects}
    18935    0.143    0.000    0.202    0.000 sprites.py:96(get_sprite)
12193/11504    0.127    0.000    0.354    0.000 {getattr}
27982/27779    0.117    0.000    0.118    0.000 {len}
        1    0.115    0.115    5.313    5.313 AbacusActivity.py:72(__init__)
       31    0.099    0.003    0.099    0.003 {method
'send_message_with_reply_and_block' of '_dbus_bindings.Connection' objects}
    10858    0.098    0.000    0.098    0.000 {method 'append' of 'list'
objects}
       43    0.088    0.002    0.253    0.006 icon.py:133(_get_icon_info)

-- 
Gonzalo Odiard

SugarLabs - Software for children learning
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sugarlabs.org/archive/sugar-devel/attachments/20140520/70ececf5/attachment-0001.html>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: abacus_profile.log
Type: text/x-log
Size: 124505 bytes
Desc: not available
URL: <http://lists.sugarlabs.org/archive/sugar-devel/attachments/20140520/70ececf5/attachment-0001.bin>