I am able to generate a profile around my most visible slowdown (4.0.x vs 3.4.x).

https://www.gramps-project.org/wiki/index.php?title=GEPS_016:_Enhancing_GRAMPS_Processing_Speed#Profiling


Thu Mar 20 14:11:19 2014    profile-log

         5651234 function calls (5613304 primitive calls) in 39.119 seconds

   Ordered by: cumulative time
   List reduced from 3892 to 100 due to restriction <100>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.029    0.029   39.119   39.119 Gramps.py:28(<module>)
        1    0.000    0.000   37.064   37.064 gramps/grampsapp.py:442(main)
        1    0.030    0.030   37.064   37.064 gramps/grampsapp.py:371(run)
  5658/19    0.021    0.000   36.087    1.899 /usr/local/lib/python2.7/site-packages/gi/types.py:46(function)
  7925/19   11.696    0.001   36.087    1.899 {method 'invoke' of 'gi.CallableInfo' objects}
        1    0.000    0.000   35.598   35.598 gramps/gui/grampsgui.py:394(startgtkloop)
        1    0.018    0.018   14.849   14.849 gramps/gui/grampsgui.py:313(__startgramps)
        1    0.040    0.040   14.014   14.014 gramps/gui/grampsgui.py:250(__init__)
     1813    0.059    0.000   11.953    0.007 gramps/gui/views/treemodels/flatbasemodel.py:804(do_get_value)
     1813    0.020    0.000   11.879    0.007 gramps/gui/views/treemodels/flatbasemodel.py:790(_get_value)
      282    0.060    0.000   11.538    0.041 gramps/gui/views/treemodels/eventmodel.py:119(column_participant)
      282    0.038    0.000   11.478    0.041 gramps/gen/utils/db.py:252(get_participant_from_event)
      599    0.015    0.000   11.328    0.019 gramps/gen/db/write.py:1938(get_from_handle)
      292    0.037    0.000   11.303    0.039 gramps/gen/db/read.py:682(get_person_from_handle)
      292    0.603    0.002   10.958    0.038 gramps/gen/lib/person.py:212(unserialize)
    30/23    0.006    0.000    9.351    0.407 gramps/gui/utils.py:441(process_pending_events)
      2/1    0.000    0.000    8.544    8.544 gramps/gui/views/listview.py:592(column_clicked)
     10/8    0.001    0.000    7.043    0.880 gramps/gui/displaystate.py:532(set_busy_cursor)
        1    0.000    0.000    6.088    6.088 gramps/gui/viewmanager.py:699(post_init_interface)
        1    0.006    0.006    5.750    5.750 gramps/gui/viewmanager.py:1091(__open_activate)
   127766    2.004    0.000    5.482    0.000 gramps/gen/lib/eventref.py:110(unserialize)
     10/9    0.001    0.000    4.964    0.552 gramps/gui/displaystate.py:568(modify_statusbar)
        5    0.000    0.000    4.942    0.988 gramps/gui/views/listview.py:684(row_changed)
   127766    1.703    0.000    4.738    0.000 gramps/gen/lib/eventref.py:57(__init__)
        3    0.000    0.000    4.465    1.488 gramps/gui/viewmanager.py:918(goto_page)
   255532    0.839    0.000    4.398    0.000 gramps/gen/lib/eventroletype.py:72(__init__)
       82    0.058    0.001    3.862    0.047 gramps/gen/plug/_pluginreg.py:1177(type_plugins)
     5916    2.188    0.000    3.788    0.001 gramps/gen/plug/_pluginreg.py:1169(get_plugin)
       72    0.012    0.000    3.782    0.053 gramps/gui/pluginmanager.py:287(get_reg_gramplets)
       72    0.000    0.000    3.764    0.052 gramps/gen/plug/_manager.py:387(get_reg_gramplets)
       72    0.000    0.000    3.764    0.052 gramps/gen/plug/_pluginreg.py:1255(gramplet_plugins)
   258239    0.611    0.000    3.602    0.000 gramps/gen/lib/grampstype.py:131(__init__)
        2    0.000    0.000    3.438    1.719 gramps/gui/viewmanager.py:951(__create_page)
        4    0.000    0.000    3.377    0.844 gramps/gui/views/pageview.py:395(get_display)
        2    0.001    0.000    3.377    1.688 gramps/gui/views/pageview.py:145(build_interface)
        4    0.002    0.001    3.326    0.832 gramps/gui/widgets/grampletbar.py:99(__init__)
   258240    1.614    0.000    2.990    0.000 gramps/gen/lib/grampstype.py:169(set)
        1    0.047    0.047    2.794    2.794 gramps/gui/viewmanager.py:31(<module>)
        1    0.000    0.000    2.786    2.786 gramps/gui/dbman.py:348(run)
      2/1    0.000    0.000    2.699    2.699 gramps/plugins/sidebar/categorysidebar.py:150(__category_clicked)
        1    0.026    0.026    2.606    2.606 gramps/gui/plug/__init__.py:27(<module>)
       48    0.006    0.000    2.534    0.053 gramps/gui/widgets/grampletpane.py:87(AVAILABLE_GRAMPLETS)
        1    0.000    0.000    2.409    2.409 gramps/gui/viewmanager.py:665(init_interface)
        1    0.045    0.045    2.026    2.026 gramps/grampsapp.py:32(<module>)
        1    0.000    0.000    1.917    1.917 gramps/gui/dbloader.py:279(read_file)
        3    0.002    0.001    1.872    0.624 gramps/gui/viewmanager.py:1016(__change_page)
        1    0.034    0.034    1.848    1.848 gramps/gui/plug/_guioptions.py:30(<module>)
  579/577    0.002    0.000    1.806    0.003 gramps/gen/db/write.py:281(try_)
        1    0.054    0.054    1.802    1.802 gramps/gen/const.py:28(<module>)
        1    0.001    0.001    1.633    1.633 gramps/gen/db/write.py:566(load)
  315/149    0.231    0.001    1.533    0.010 {__import__}
  1064960    1.428    0.000    1.429    0.000 {isinstance}
        1    0.000    0.000    1.404    1.404 gramps/gui/viewmanager.py:738(quit)
  1543666    1.396    0.000    1.396    0.000 gramps/gen/plug/_pluginreg.py:418(_get_id)
        1    0.001    0.001    1.305    1.305 gramps/gui/grampsgui.py:112(register_stock_icons)
        1    0.019    0.019    1.302    1.302 gramps/gui/pluginmanager.py:58(base_reg_stock_icons)
     2267    0.028    0.000    1.302    0.001 /usr/local/lib/python2.7/site-packages/gi/types.py:72(constructor)
       12    0.004    0.000    1.290    0.107 gramps/gui/widgets/grampletpane.py:172(make_requested_gramplet)
        1    0.051    0.051    1.273    1.273 gramps/gui/grampsgui.py:29(<module>)
        1    0.000    0.000    1.272    1.272 gramps/gui/viewmanager.py:1038(__delete_pages)
        2    0.000    0.000    1.272    0.636 gramps/gui/views/listview.py:963(on_delete)
        2    0.000    0.000    1.271    0.635 gramps/gui/views/pageview.py:526(on_delete)
        4    0.000    0.000    1.269    0.317 gramps/gui/widgets/grampletbar.py:271(on_delete)
        4    0.004    0.001    1.268    0.317 gramps/gui/widgets/grampletbar.py:200(__save)
       12    0.000    0.000    1.267    0.106 gramps/gui/widgets/grampletpane.py:138(get_gramplet_opts)
       24    0.003    0.000    1.262    0.053 gramps/gui/widgets/grampletpane.py:90(GET_AVAILABLE_GRAMPLETS)
       12    0.000    0.000    1.259    0.105 gramps/gui/widgets/grampletpane.py:152(get_gramplet_options_by_name)
        1    0.055    0.055    1.165    1.165 gramps/gui/widgets/__init__.py:24(<module>)
        1    0.000    0.000    1.134    1.134 gramps/gui/viewmanager.py:276(__init__)
    13/10    0.000    0.000    1.099    0.110 /usr/local/lib/python2.7/site-packages/gi/importer.py:56(load_module)
    13/10    0.000    0.000    1.099    0.110 /usr/local/lib/python2.7/site-packages/gi/module.py:225(_load)
        2    0.000    0.000    1.010    0.505 gramps/gui/viewmanager.py:987(view_changed)
        1    0.016    0.016    0.992    0.992 gramps/gui/widgets/dateentry.py:23(<module>)
        1    0.000    0.000    0.967    0.967 gramps/gui/viewmanager.py:1115(_post_load_newdb)
      294    0.005    0.000    0.964    0.003 /usr/lib/python2.7/re.py:226(_compile)
        1    0.015    0.015    0.960    0.960 gramps/gui/widgets/monitoredwidgets.py:24(<module>)
       84    0.001    0.000    0.958    0.011 /usr/lib/python2.7/sre_compile.py:495(compile)
        1    0.085    0.085    0.945    0.945 gramps/gen/datehandler/__init__.py:25(<module>)
      135    0.000    0.000    0.925    0.007 /usr/lib/python2.7/re.py:188(compile)
        2    0.000    0.000    0.904    0.452 gramps/gui/views/listview.py:294(set_active)
        2    0.000    0.000    0.904    0.452 gramps/gui/views/navigationview.py:151(set_active)
        2    0.000    0.000    0.897    0.448 gramps/gui/views/pageview.py:305(set_active)
        1    0.000    0.000    0.897    0.897 gramps/gui/viewmanager.py:1123(_post_load_newdb_gui)
        1    0.018    0.018    0.895    0.895 gramps/gen/utils/grampslocale.py:29(<module>)
        1    0.000    0.000    0.868    0.868 gramps/gui/viewmanager.py:723(do_reg_plugins)
        1    0.015    0.015    0.866    0.866 /usr/lib/python2.7/dist-packages/icu.py:24(<module>)
        1    0.005    0.005    0.857    0.857 /usr/local/lib/python2.7/site-packages/gi/overrides/Gtk.py:22(<module>)
        1    0.851    0.851    0.851    0.851 /usr/lib/python2.7/dist-packages/docs.py:23(<module>)
        1    0.000    0.000    0.815    0.815 gramps/gen/datehandler/_dateparser.py:268(__init__)
        1    0.000    0.000    0.815    0.815 gramps/gen/datehandler/_date_fr.py:192(init_strings)
        1    0.033    0.033    0.780    0.780 gramps/gui/dialog.py:28(<module>)
        1    0.769    0.769    0.769    0.769 {method 'open' of 'DBEnv' objects}
        1    0.000    0.000    0.754    0.754 gramps/cli/grampscli.py:307(do_reg_plugins)
        2    0.001    0.001    0.754    0.377 gramps/gen/plug/_manager.py:107(reg_plugins)
        1    0.014    0.014    0.669    0.669 gramps/gui/display.py:23(<module>)
       84    0.001    0.000    0.628    0.007 /usr/lib/python2.7/sre_parse.py:663(parse)
        1    0.007    0.007    0.627    0.627 gramps/gui/plug/_windows.py:31(<module>)
   383/84    0.015    0.000    0.624    0.007 /usr/lib/python2.7/sre_parse.py:301(_parse_sub)
  2401/93    0.157    0.000    0.623    0.007 /usr/lib/python2.7/sre_parse.py:379(_parse)
        1    0.077    0.077    0.619    0.619 gramps/gui/editors/__init__.py:25(<module>)


I suppose that my problem is around "method 'invoke' of 'gi.CallableInfo' objects"?

I see some references on the web. eg,
https://www.mail-archive.com/python-hackers-list@gnome.org/msg00267.html
https://bugzilla.gnome.org/show_bug.cgi?id=693243

Is it common on python/gi to have such issue?
I do not understand why this occurs, 
anyone knows how or when this will be improved?


Jérôme



Le mer. 19 mars 2014 at 21:05, Vassilii Khachaturov <vassilii@tarunz.org> a écrit :

Profile is your friend, but I reckon it's mostly due to the gtk3/gi transition.