[Dev] profile of startup using wx 2.5
John Anderson
john at osafoundation.org
Mon Apr 26 15:27:43 PDT 2004
I thought it would be interesting to see what a hotshot profile looks
like after the switch to wx 2.5, so here's the results:
The following profile is Chandler startup with a repository already
created. On a 3Gh Pentium the wall clock time is about 13 seconds (does
that really mean it takes about 40 billion instructions to display the app?)
Note that hotshot times are not accurate in an absolute sense, only in a
relative to each other.
The routine we spent the most time when I profiled the last time on wx
2.4 is completely absent, thanks to work Robin did.
Today, most of the time--perhaps 85%--is spent in the repository or
routines called by the repository. So making the repository faster, or
using it less seems like the most obvious place to look for improvement
John
P.S. Here are the details
603532 function calls (590437 primitive calls) in 35876.401 CPU
seconds
Ordered by: internal time, call count
List reduced from 1683 to 100 due to restriction <100>
ncalls tottime percall cumtime percall filename:lineno(function)
1 1650.123 1650.123 1650.123 1650.123 dbxml.py:70(open)
13892/12918 1563.082 0.113 4415.550 0.342
item.py:412(getAttributeValue)
7974/7522 1229.827 0.154 13606.546 1.809 itemhandler.py:67(endElement)
11828 1054.430 0.089 1054.430 0.089 uuid.py:20(__init__)
30217 908.861 0.030 1288.944 0.043
threadlocal.py:39(_getCurrentThreadLocals)
1 822.373 822.373 2945.822 2945.822 xmlrepository.py:88(open)
299 807.819 2.702 935.064 3.127
sre_compile.py:180(_optimize_charset)
591/454 768.373 1.300 25847.900 56.934 libxml2.py:4594(parseChunk)
2348 749.633 0.319 2711.852 1.155 dbcontainer.py:351(readName)
1167 726.688 0.623 781.837 0.670
netserver.pyc:961(NotifyImport)
27250/26995 714.857 0.026 968.833 0.036 item.py:135(__setattr__)
8605/8381 686.033 0.080 2817.255 0.336 linkedmap.py:203(get)
1584 658.102 0.415 2252.339 1.422 dbcontainer.py:95(loadRef)
7974/7048 619.364 0.078 13522.047 1.919
itemhandler.py:47(startElement)
19441 582.259 0.030 1852.317 0.095 xmlrepository.py:455(_getTxn)
21089 472.699 0.022 1380.312 0.065 threadlocal.py:21(__getattr__)
13760 467.006 0.034 576.609 0.042 values.py:18(__getitem__)
33809 432.278 0.013 432.278 0.013
threading.py:609(currentThread)
463 411.856 0.890 4171.770 9.010 classloader.py:11(loadClass)
1009/359 410.105 0.406 410.105 1.142 sre_parse.py:147(getwidth)
343/52 398.956 1.163 764.895 14.710 sre_parse.py:367(_parse)
4559 397.765 0.087 1640.614 0.360
xmlrepository.py:446(_abortTransaction)
5155 390.295 0.076 1403.882 0.272
xmlrepository.py:429(_startTransaction)
1083/661 351.450 0.325 23028.631 34.839 linkedmap.py:240(iterkeys)
3958/3408 349.499 0.088 11850.705 3.477 kind.py:75(getAttribute)
4749/4418 344.650 0.073 8253.883 1.868 item.py:1453(getItemChild)
17782 337.893 0.019 337.893 0.019 item.py:1856(_countAccess)
3890/3865 321.252 0.083 748.600 0.194 item.py:1089(setDirty)
1167 314.064 0.269 1095.900 0.939
dbgserver.pyc:1955(_NotifyImport)
8 308.683 38.585 308.812 38.602 dbcontainer.py:21(__init__)
2859/2469 307.412 0.108 6951.152 2.815 repository.py:316(find)
5109/5041 306.196 0.060 2991.581 0.593 attribute.py:28(getAspect)
1718 278.172 0.162 1188.745 0.692 linkedmap.py:105(__setitem__)
9124 277.711 0.030 857.350 0.094 xmlrepository.py:463(_setTxn)
3992/3980 270.038 0.068 5716.657 1.436 kind.py:64(resolve)
1859/1807 268.890 0.145 9446.502 5.228
itemhandler.py:308(attributeStart)
3496 241.276 0.069 3228.260 0.923 item.py:728(getValue)
1112/766 238.765 0.215 3796.794 4.957 itemref.py:606(_load)
4559 238.104 0.052 637.369 0.140 dbcontainer.py:66(cursor)
1132/901 226.209 0.200 3257.314 3.615 itemref.py:520(__setitem__)
1175/1153 214.691 0.183 3323.681 2.883 itemhandler.py:97(refStart)
6332 209.057 0.033 376.261 0.059 dbcontainer.py:77(_readValue)
6225/6191 206.817 0.033 1362.089 0.220 itemref.py:114(other)
6314 199.505 0.032 244.360 0.039 itemref.py:34(getItem)
9128 198.564 0.022 579.896 0.064 threadlocal.py:28(__setattr__)
2616/2597 191.669 0.073 800.317 0.308 repository.py:460(__getitem__)
3496 190.660 0.055 2298.946 0.658 itemref.py:652(get)
591/552 189.101 0.320 5678.994 10.288 itemhandler.py:146(itemEnd)
6225/6191 187.686 0.030 913.666 0.148 itemref.py:45(getOther)
10311 187.568 0.018 187.568 0.018 item.py:993(hasAttributeValue)
1175 187.499 0.160 1098.596 0.935 itemhandler.py:260(refEnd)
20331 185.916 0.009 185.916 0.009 uuid.py:51(__hash__)
3 180.105 60.035 181.005 60.335
xmlrepository.py:437(_commitTransaction)
702/50 176.117 0.251 1127.334 22.547 sre_compile.py:24(_compile)
3520 172.036 0.049 223.184 0.063 repository.py:277(setLoading)
591 168.934 0.286 1295.201 2.192 item.py:66(_fillItem)
1499/633 162.789 0.109 4408.307 6.964 itemref.py:329(attach)
1499 153.328 0.102 153.328 0.102 itemref.py:313(__init__)
2019 150.492 0.075 908.166 0.450
itemhandler.py:464(setupTypeDelegate)
9389 148.915 0.016 148.915 0.016 item.py:1337(getRepository)
3221 148.204 0.046 256.055 0.079 values.py:51(__setitem__)
1689 148.078 0.088 1884.441 1.116
xmlrepositoryview.py:493(resolveAlias)
591/428 143.949 0.244 26622.388 62.202 repository.py:681(_loadDoc)
10675 140.337 0.013 140.337 0.013 uuid.py:64(__eq__)
591 139.432 0.236 350.909 0.594 dbxml.py:88(getDocument)
4428/4422 135.643 0.031 1298.671 0.294
itemhandler.py:407(getCardinality)
4064/3706 132.990 0.033 2157.470 0.582 item.py:125(__getattr__)
16981 131.875 0.008 131.875 0.008 values.py:26(_getAccess)
591 127.032 0.215 262.771 0.445 dbcontainer.py:244(getDocId)
797/796 123.935 0.156 2852.059 3.583 itemref.py:56(attach)
38 123.761 3.257 123.761 3.257 sre_compile.py:229(_mk_bitmap)
1859/1836 121.106 0.065 1266.067 0.690
itemhandler.py:420(getTypeName)
833/448 118.882 0.143 28227.586 63.008 repository.py:757(_loadChild)
1584 112.800 0.071 2445.409 1.544
xmlrepositoryview.py:423(_loadRef_)
1859 110.816 0.060 210.353 0.113
itemhandler.py:351(attributeEnd)
2460/1223 109.545 0.045 23013.301 18.817 linkedmap.py:80(_get)
1 105.992 105.992 105.992 105.992 html.py:966(LoadPage)
1584 103.984 0.066 2725.970 1.721
xmlrepositoryview.py:411(_loadRef)
3737 102.545 0.027 102.545 0.027 sre_parse.py:187(__next)
5 98.739 19.748 98.739 19.748 controls.py:2841(Realize)
378 96.806 0.256 107.172 0.284 ntpath.py:266(isdir)
524/496 95.863 0.183 4163.763 8.395 itemref.py:360(_attach)
998 94.125 0.094 305.532 0.306 types.py:491(fieldEnd)
1 91.186 91.186 1161.579 1161.579 urllib2.py:71(?)
2672 90.928 0.034 90.928 0.034 dbxml.py:5(_swig_setattr)
591 90.803 0.154 192.887 0.326 itemhandler.py:128(itemStart)
591 90.411 0.153 128.186 0.217
libxml2.py:1381(createPushParser)
6367 88.335 0.014 88.335 0.014 repository.py:269(isLoading)
587 87.219 0.149 532.336 0.907 item.py:1421(_addItem)
1 87.070 87.070 87.618 87.618 dbxml.py:62(__init__)
12511 85.531 0.007 85.531 0.007 item.py:1772(_loadItem)
1182 84.628 0.072 116.258 0.098
repository.py:533(_registerItem)
361/67 83.777 0.232 298.733 4.459 os.py:206(walk)
1 82.854 82.854 201.348 201.348 controlblocks.py:1(?)
1585 80.325 0.051 80.325 0.051
xmlrepositoryview.py:516(_packKey)
3422/3151 79.218 0.023 9159.721 2.907
itemhandler.py:457(getAttribute)
591 77.857 0.132 273.054 0.462 item.py:1297(_setRoot)
2019 77.396 0.038 985.563 0.488 itemhandler.py:323(valueStart)
2838 73.827 0.026 149.769 0.053 sre_parse.py:206(get)
2101 73.652 0.035 370.042 0.176 linkedmap.py:25(_setNext)
More information about the Dev
mailing list