[Dev] Why is launching Chandler so slow?

John Anderson john at osafoundation.org
Thu Sep 25 16:28:50 PDT 2003


I've noticed that Chandler launch has been gotten way to slow. One
factor is including wxPython, which varies widely on the different
platforms -- and I think Robin is on top of the issue. But a bigger
factor is creating a new wxApplication, which is really slow: Here's a
profile I did with python hotshot on Linux of

application = wxApplication(argv)

that I think everyone might find interesting

   Ordered by: internal time, call count
   List reduced from 1025 to 100 due to restriction <100>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      209    2.812    0.013    2.941    0.014 dbxml.py:90(queryWithXPath)
1065/756    2.089    0.002    5.427    0.007
expatreader.py:311(start_element)
        1    1.429    1.429    1.886    1.886 controls2.py:1130(SelectItem)
        1    1.193    1.193    1.215    1.215 xrc.py:109(LoadFrame)
     1491    1.174    0.001    1.174    0.001 UUID.py:17(__init__)
      118    1.050    0.009    1.318    0.011 ItemHandler.py:283(dbEnd)
       20    1.040    0.052    1.040    0.052 windows.py:820(AppendItem)
      118    1.014    0.009    1.014    0.009 fsindex.py:64(get)
      108    1.008    0.009    1.058    0.010
expatreader.py:419(create_parser)
        1    1.002    1.002    1.105    1.105 gizmos.py:2(?)
     2021    0.642    0.000    0.914    0.000 warnings.py:24(warn)
        4    0.389    0.097    0.390    0.097
securechannel.pyc:80(safe_select)
     2021    0.273    0.000    0.273    0.000 warnings.py:59(warn_explicit)
       97    0.243    0.003    0.298    0.003
sre_compile.py:180(_optimize_charset)
      209    0.218    0.001    0.315    0.002 dbxml.py:210(next)
     4419    0.185    0.000    0.185    0.000 dbxml.py:5(_swig_setattr)
        5    0.167    0.033    0.169    0.034 windows.py:486(Show)
     1655    0.163    0.000    0.387    0.000 Item.py:524(setDirty)
        1    0.146    0.146    0.181    0.181 xrc.py:115(LoadObject)
  214/122    0.133    0.001    9.562    0.078 expatreader.py:205(feed)
      149    0.121    0.001    1.159    0.008 XMLRepository.py:337(__init__)
   107/61    0.120    0.001    9.627    0.158 expatreader.py:101(parse)
        1    0.120    0.120    0.123    0.123 dbxml.py:4(?)
     1462    0.117    0.000    0.186    0.000
XMLRepository.py:175(addTransaction)
1065/906    0.116    0.000    5.562    0.006 ItemHandler.py:56(endElement)
        1    0.101    0.101    0.101    0.101
gizmos.py:58(wxDynamicSashSplitEvent)
      181    0.093    0.001    0.173    0.001 ItemHandler.py:246(refEnd)
  681/199    0.092    0.000    7.225    0.036 Repository.py:144(find)
    71/25    0.092    0.001    0.240    0.010 sre_parse.py:367(_parse)
1065/756    0.091    0.000    4.337    0.006
ItemHandler.py:37(startElement)
      351    0.089    0.000    0.404    0.001 dbxml.py:263(__init__)
      474    0.084    0.000    0.126    0.000 XMLRepository.py:437(_dbRefs)
     2407    0.081    0.000    0.081    0.000 codecs.py:174(write)
     2696    0.080    0.000    0.080    0.000 UUID.py:35(__hash__)
     1179    0.079    0.000    5.787    0.005 Item.py:756(getItemChild)
     1070    0.078    0.000    0.250    0.000 ItemRef.py:278(__setitem__)
      480    0.073    0.000    0.183    0.000 dbxml.py:288(__init__)
  498/478    0.072    0.000    0.538    0.001 ItemRef.py:399(__setitem__)
     1430    0.068    0.000    0.068    0.000 dbxml.py:16(_swig_getattr)
      419    0.067    0.000    0.644    0.002 ItemRef.py:197(attach)
     2400    0.066    0.000    0.066    0.000 xmlreader.py:324(get)
      427    0.061    0.000    5.977    0.014 Kind.py:47(resolve)
       22    0.060    0.003    0.064    0.003 dbxml.py:81(putDocument)
        1    0.058    0.058    0.059    0.059 dbxml.py:70(open)
1065/906    0.057    0.000    5.611    0.006
expatreader.py:314(end_element)
      418    0.057    0.000    0.152    0.000 dbxml.py:221(__init__)
      142    0.056    0.000    3.576    0.025
XMLRepository.py:228(loadChild)
  621/546    0.054    0.000    3.129    0.006 ItemRef.py:95(other)
       18    0.051    0.003    0.051    0.003 sre_compile.py:229(_mk_bitmap)
      214    0.050    0.000    0.059    0.000 expatreader.py:253(reset)
        1    0.050    0.050    0.098    0.098
ContactsSingleContactView.py:6(?)
   146/24    0.050    0.000    0.337    0.014 sre_compile.py:24(_compile)
      446    0.050    0.000    0.145    0.000 ItemRef.py:535(get)
     36/1    0.049    0.001    1.990    1.990
Application.py:440(LoadParcelsInDirectory)
     1968    0.049    0.000    0.049    0.000 Item.py:691(getRepository)
      536    0.048    0.000    0.498    0.001 Attribute.py:18(getAspect)
       22    0.048    0.002    0.055    0.003 dbxml.py:86(deleteDocument)
      239    0.047    0.000    0.201    0.001 saxutils.py:243(startElement)
     2118    0.047    0.000    0.047    0.000 Repository.py:66(isLoading)
1065/906    0.046    0.000    5.651    0.006 pyexpat.c:630(EndElement)
      758    0.046    0.000    0.077    0.000 sre_parse.py:206(get)
  752/427    0.046    0.000    0.073    0.000 Namespace.py:13(getDomain)
      816    0.045    0.000    0.275    0.000 ItemRef.py:302(__setitem__)
     1652    0.044    0.000    0.044    0.000 UUID.py:39(__eq__)
     1253    0.043    0.000    0.043    0.000 Item.py:86(__setattr__)
1065/756    0.043    0.000    5.457    0.007 pyexpat.c:578(StartElement)
      758    0.041    0.000    0.080    0.000
ItemHandler.py:358(getCardinality)
      556    0.041    0.000    0.192    0.000
XMLRepository.py:346(_changeRef)
      377    0.040    0.000    0.125    0.000 saxutils.py:194(writeattr)
  427/375    0.039    0.000    6.370    0.017 Kind.py:55(getAttribute)
      994    0.039    0.000    0.039    0.000 sre_parse.py:187(__next)
      537    0.039    0.000    0.080    0.000 saxutils.py:178(writetext)
  415/414    0.038    0.000    0.233    0.001 ItemRef.py:47(attach)
       65    0.038    0.001    1.805    0.028 serialize.py:198(getState)
      351    0.038    0.000    0.108    0.000 dbxml.py:182(setVariableValue)
      529    0.038    0.000    0.183    0.000 Item.py:330(getValue)
      107    0.038    0.000    0.079    0.001 ItemHandler.py:116(itemStart)
      831    0.038    0.000    0.067    0.000 dbxml.py:266(__del__)
      218    0.038    0.000    0.084    0.000
ItemHandler.py:228(attributeEnd)
      831    0.037    0.000    0.077    0.000 dbxml.py:253(<lambda>)
      363    0.037    0.000    0.057    0.000 posixpath.py:184(isdir)
        1    0.037    0.037    1.144    1.144 TableViewer.py:4(?)
      107    0.037    0.000    0.503    0.005 Item.py:50(_fillItem)
      835    0.036    0.000    0.056    0.000 pyexpat.c:457(CharacterData)
  621/546    0.036    0.000    3.068    0.006 ItemRef.py:36(getOther)
     1123    0.035    0.000    0.035    0.000 xmlreader.py:315(__getitem__)
      107    0.034    0.000    1.223    0.011 ItemHandler.py:133(itemEnd)
  218/184    0.034    0.000    2.453    0.013
ItemHandler.py:85(attributeStart)
      852    0.034    0.000    0.034    0.000 LinkedMap.py:171(get)
     1464    0.034    0.000    0.034    0.000 Repository.py:62(isOpen)
  181/157    0.033    0.000    1.902    0.012 ItemHandler.py:100(refStart)
      154    0.033    0.000    0.196    0.001 ItemRef.py:221(_attach)
  625/557    0.031    0.000    0.944    0.002 Item.py:194(getAttributeValue)
   107/61    0.030    0.000    9.707    0.159 __init__.py:33(parseString)
     1065    0.030    0.000    0.030    0.000 xmlreader.py:278(__init__)
      185    0.030    0.000    0.048    0.000 file.py:418(_read_data_header)
        2    0.029    0.014    0.029    0.015 xrc.py:86(LoadMenuBar)
      427    0.029    0.000    3.996    0.009 Namespace.py:17(resolve)
  307/291    0.028    0.000    3.821    0.013
Item.py:126(getAttributeAspect)
  415/414    0.028    0.000    0.260    0.001 ItemRef.py:15(__init__)

I'd encourage everyone to try out hotshot. Here's the code I used for
this test:

    import hotshot, hotshot.stats
    prof = hotshot.Profile("chandler.prof")
    benchtime = prof.run("application = wxApplication(argv)")
    prof.close()
    stats = hotshot.stats.load("chandler.prof")
    stats.strip_dirs()
    stats.sort_stats('time', 'calls')
    stats.print_stats(100)

One last warning. I tried hotshot on Windows and Python crashed, so it's
not bulletproof.

John






More information about the Dev mailing list