r4 - 08 Feb 2006 - 09:57:36 - LisaDusseaultYou are here: OSAF > Journal Web > DevelopmentHome > PerformanceProject > DetailViewPerformance20040913
from donn's email:
All,
I did some hotshot performance testing on render() of the Detail View. We're spending a LOT of time in Toolbar.Realize(), which is called to lay out the toolbar when you have added items to it. We need to do this every time synchronizeWidget is called and the toolbar has changed. Unfortunately, each time you switch Active Views, by clicking in the sidebar, all new widgets are built, so the toolbar is changed, and gets rebuilt. We now have three toolbars active, the Nav bar (which doesn't change), the LayoutSelector and the MarkupBar.
- Donn
DETAILS
----------------
FYI, I've dumped 3 test cases, with 3 profiles each: one with the top 50 times, one with the top 10 callcount, one with the top 10 cumtime.
These lines are the TextControl, StaticText:
3 4.488 1.496 4.979 1.660 controls.py:1218(__init__)
5 4.480 0.896 4.975 0.995 controls.py:754(__init__)
This line is the Choice control:
1 13.870 13.870 14.139 14.139 controls.py:349(__init__)
.
Ordered by: internal time, call count
List reduced from 174 to 50 due to restriction <50>
ncalls tottime percall cumtime percall filename:lineno(function)
1 129.779 129.779 129.779 129.779 controls.py:2841(Realize)
849/639 38.066 0.045 151.169 0.237 item.py:444(getAttributeValue)
919/774 16.375 0.018 59.657 0.077 item.py:138(__setattr__)
117 14.933 0.128 54.328 0.464 dbcontainer.py:446(readName)
1 14.262 14.262 14.533 14.533 controls.py:349(__init__)
12 13.281 1.107 13.932 1.161 core.py:1971(__init__)
560/105 11.453 0.020 30.687 0.292 item.py:1492(_getPath)
12 10.281 0.857 10.820 0.902 core.py:2242(ConvertToBitmap)
732/592 8.451 0.012 155.864 0.263 item.py:128(__getattr__)
851 7.779 0.009 7.779 0.009 item.py:2271(_countAccess)
468 6.901 0.015 16.830 0.036 xmlrepository.py:494(_getTxn)
702 6.495 0.009 9.784 0.014 threadlocal.py:39(_getCurrentThrea
dLocals)
560 6.330 0.011 9.475 0.017 item.py:1533(__getParent)
34/1 6.227 0.183 457.969 457.969 block.py:36(render)
18 6.035 0.335 6.035 0.335 core.py:6404(Freeze)
117 5.622 0.048 14.922 0.128 xmlrepository.py:461(startTransact
ion)
117 5.236 0.045 16.705 0.143 xmlrepository.py:481(abortTransact
ion)
117 4.581 0.039 61.165 0.523 xmlrefdict.py:77(resolveAlias)
9 4.502 0.500 5.813 0.646 windows.py:13(__init__)
3 4.488 1.496 4.979 1.660 controls.py:1218(__init__)
5 4.480 0.896 4.975 0.995 controls.py:754(__init__)
8 4.319 0.540 4.319 0.540 core.py:6560(SetFont)
70 4.268 0.061 73.714 1.053 kind.py:119(getAttribute)
117 4.229 0.036 79.457 0.679 kind.py:108(resolve)
105 4.206 0.040 4.206 0.040 path.py:28(__repr__)
117 3.807 0.033 7.768 0.066 dbcontainer.py:73(cursor)
18 3.755 0.209 3.755 0.209 core.py:6421(Thaw)
117 3.724 0.032 5.327 0.046 item.py:1838(getItemChild)
210 3.610 0.017 3.610 0.017 path.py:57(set)
16 3.495 0.218 83.724 5.233 dynamiccontainerblocks.py:570(addT
ool)
560 3.427 0.006 3.427 0.006 path.py:84(append)
703 3.298 0.005 3.298 0.005 threading.py:609(currentThread)
190 3.216 0.017 4.024 0.021 linkedmap.py:80(_get)
264 3.173 0.012 3.923 0.015 itemref.py:39(getItem)
468 3.160 0.007 9.929 0.021 threadlocal.py:21(__getattr__)
9 3.104 0.345 3.104 0.345 core.py:7014(Layout)
234 3.045 0.013 7.900 0.034 xmlrepository.py:502(_setTxn)
455 2.708 0.006 2.708 0.006 item.py:1182(isStale)
95 2.414 0.025 6.217 0.065 itemref.py:849(_getRef)
152 2.339 0.015 2.569 0.017 linkedmap.py:196(get)
354 2.316 0.007 2.316 0.007 item.py:1127(hasAttributeValue)
156 2.261 0.014 4.692 0.030 linkedmap.py:233(iterkeys)
156 2.013 0.013 20.523 0.132 linkedmap.py:228(__iter__)
33/1 1.946 0.059 38.254 38.254 detail.py:61(reNotifyInside)
167 1.939 0.012 8.204 0.049 itemref.py:121(other)
247 1.927 0.008 1.927 0.008 item.py:1161(isNew)
167 1.901 0.011 2.343 0.014 itemref.py:50(getOther)
82 1.867 0.023 5.798 0.071 item.py:1033(hasValue)
234 1.841 0.008 4.855 0.021 threadlocal.py:28(__setattr__)
105 1.726 0.016 2.659 0.025 path.py:17(__init__)
14263 function calls (13244 primitive calls) in 457.969 CPU seconds
Ordered by: call count
List reduced from 174 to 10 due to restriction <10>
ncalls tottime percall cumtime percall filename:lineno(function)
919/774 16.375 0.018 59.657 0.077 item.py:138(__setattr__)
851 7.779 0.009 7.779 0.009 item.py:2271(_countAccess)
849/639 38.066 0.045 151.169 0.237 item.py:444(getAttributeValue)
732/592 8.451 0.012 155.864 0.263 item.py:128(__getattr__)
703 3.298 0.005 3.298 0.005 threading.py:609(currentThread)
702 6.495 0.009 9.784 0.014 threadlocal.py:39(_getCurrentThrea
dLocals)
560/105 11.453 0.020 30.687 0.292 item.py:1492(_getPath)
560 6.330 0.011 9.475 0.017 item.py:1533(__getParent)
560 3.427 0.006 3.427 0.006 path.py:84(append)
468 6.901 0.015 16.830 0.036 xmlrepository.py:494(_getTxn)
14263 function calls (13244 primitive calls) in 457.969 CPU seconds
Ordered by: cumulative time
List reduced from 174 to 10 due to restriction <10>
ncalls tottime percall cumtime percall filename:lineno(function)
34/1 6.227 0.183 457.969 457.969 block.py:36(render)
18 0.746 0.041 238.488 13.249 block.py:211(synchronizeWidget)
1 0.912 0.912 220.376 220.376 dynamiccontainerblocks.py:508(wxSy
nchronizeWidget)
732/592 8.451 0.012 155.864 0.263 item.py:128(__getattr__)
849/639 38.066 0.045 151.169 0.237 item.py:444(getAttributeValue)
1 129.779 129.779 129.779 129.779 controls.py:2841(Realize)
16 3.495 0.218 83.724 5.233 dynamiccontainerblocks.py:570(addT
ool)
117 4.229 0.036 79.457 0.679 kind.py:108(resolve)
70 4.268 0.061 73.714 1.053 kind.py:119(getAttribute)
117 4.581 0.039 61.165 0.523 xmlrefdict.py:77(resolveAlias)
----------------------------------------------------------------------
Run, starting up from XML, with an already populated repository, Detail View visible and an item selected:
Ordered by: internal time, call count
List reduced from 334 to 50 due to restriction <50>
ncalls tottime percall cumtime percall filename:lineno(function)
4083/3752 141.820 0.035 389.290 0.104 item.py:444(getAttributeValue)
1 128.943 128.943 128.943 128.943 controls.py:2841(Realize)
666 79.045 0.119 299.718 0.450 dbcontainer.py:446(readName)
4927/4779 78.040 0.016 126.951 0.027 item.py:138(__setattr__)
33 47.481 1.439 1143.588 34.654 libxml2.py:4680(parseChunk)
5096 46.422 0.009 75.463 0.015 threadlocal.py:39(_getCurrentThrea
dLocals)
3190 46.372 0.015 113.290 0.036 xmlrepository.py:494(_getTxn)
860 40.438 0.047 388.571 0.452 itemhandler.py:68(endElement)
4331 39.099 0.009 39.099 0.009 item.py:2271(_countAccess)
814 34.256 0.042 94.500 0.116 xmlrepository.py:461(startTransact
ion)
781 34.152 0.044 114.443 0.147 xmlrepository.py:481(abortTransact
ion)
1830 31.867 0.017 51.269 0.028 linkedmap.py:196(get)
868 31.703 0.037 646.468 0.745 kind.py:119(getAttribute)
5097 29.048 0.006 29.048 0.006 threading.py:609(currentThread)
915 27.393 0.030 449.895 0.492 kind.py:108(resolve)
1885 26.259 0.014 136.846 0.073 attribute.py:28(getAspect)
781 23.606 0.030 50.373 0.064 dbcontainer.py:73(cursor)
3387 23.495 0.007 23.495 0.007 item.py:1127(hasAttributeValue)
696 23.399 0.034 335.876 0.483 xmlrefdict.py:77(resolveAlias)
833 23.254 0.028 79.689 0.096 itemref.py:854(get)
948 22.619 0.024 37.709 0.040 item.py:1838(getItemChild)
3534 22.346 0.006 75.622 0.021 threadlocal.py:21(__getattr__)
860 21.978 0.026 702.594 0.817 itemhandler.py:48(startElement)
1912/1772 20.664 0.011 232.028 0.131 item.py:128(__getattr__)
1562 20.543 0.013 55.105 0.035 xmlrepository.py:502(_setTxn)
833 20.127 0.024 140.458 0.169 item.py:785(getValue)
1762/168 18.396 0.010 1212.832 7.219 itemref.py:50(getOther)
1815 18.131 0.010 24.662 0.014 itemref.py:39(getItem)
543 17.310 0.032 17.310 0.032 uuid.py:22(__init__)
1762/168 16.175 0.009 1218.187 7.251 itemref.py:121(other)
1 13.977 13.977 14.261 14.261 controls.py:349(__init__)
12 13.920 1.160 14.639 1.220 core.py:1971(__init__)
399 12.693 0.032 60.837 0.152 itemhandler.py:515(setupTypeDelega
te)
82 12.665 0.154 48.827 0.595 dbcontainer.py:166(loadRef)
398 12.530 0.031 439.368 1.104 itemhandler.py:345(attributeStart)
1562 12.373 0.008 34.562 0.022 threadlocal.py:28(__setattr__)
515 12.046 0.023 18.664 0.036 values.py:51(__setitem__)
12 11.917 0.993 12.557 1.046 core.py:2242(ConvertToBitmap)
560/105 11.472 0.020 30.646 0.292 item.py:1492(_getPath)
1657 11.371 0.007 11.371 0.007 item.py:1161(isNew)
3544 11.164 0.003 11.164 0.003 item.py:2228(_loadItem)
631 10.918 0.017 40.612 0.064 itemhandler.py:452(getCardinality)
227/78 9.594 0.042 1209.305 15.504 repositoryview.py:226(find)
2020 8.708 0.004 8.708 0.004 uuid.py:60(__hash__)
116 8.681 0.075 141.576 1.220 itemhandler.py:281(refEnd)
398 8.640 0.022 19.799 0.050 itemhandler.py:388(attributeEnd)
398 8.631 0.022 56.742 0.143 itemhandler.py:465(getTypeName)
248 8.363 0.034 19.483 0.079 item.py:1248(setDirty)
33 8.120 0.246 13.257 0.402 dbxml.py:88(getDocument)
666 8.112 0.012 307.831 0.462 xmlrepository.py:409(readName)
88482 function calls (83968 primitive calls) in 1735.264 CPU seconds
Ordered by: call count
List reduced from 334 to 10 due to restriction <10>
ncalls tottime percall cumtime percall filename:lineno(function)
5097 29.048 0.006 29.048 0.006 threading.py:609(currentThread)
5096 46.422 0.009 75.463 0.015 threadlocal.py:39(_getCurrentThrea
dLocals)
4927/4779 78.040 0.016 126.951 0.027 item.py:138(__setattr__)
4331 39.099 0.009 39.099 0.009 item.py:2271(_countAccess)
4083/3752 141.820 0.035 389.290 0.104 item.py:444(getAttributeValue)
3544 11.164 0.003 11.164 0.003 item.py:2228(_loadItem)
3534 22.346 0.006 75.622 0.021 threadlocal.py:21(__getattr__)
3387 23.495 0.007 23.495 0.007 item.py:1127(hasAttributeValue)
3190 46.372 0.015 113.290 0.036 xmlrepository.py:494(_getTxn)
2020 8.708 0.004 8.708 0.004 uuid.py:60(__hash__)
88482 function calls (83968 primitive calls) in 1735.264 CPU seconds
Ordered by: cumulative time
List reduced from 334 to 10 due to restriction <10>
ncalls tottime percall cumtime percall filename:lineno(function)
34/1 6.878 0.202 1735.264 1735.264 block.py:36(render)
156 2.173 0.014 1288.594 8.260 linkedmap.py:228(__iter__)
95 1.729 0.018 1222.982 12.873 itemref.py:685(__getitem__)
1762/168 16.175 0.009 1218.187 7.251 itemref.py:121(other)
1762/168 18.396 0.010 1212.832 7.219 itemref.py:50(getOther)
33 0.954 0.029 1210.265 36.675 itemref.py:283(_loadItem)
227/78 9.594 0.042 1209.305 15.504 repositoryview.py:226(find)
37/35 1.208 0.033 1207.807 34.509 item.py:2001(find)
33 1.741 0.053 1202.091 36.427 repositoryview.py:781(_loadItem)
33 3.335 0.101 1166.314 35.343 repositoryview.py:727(_loadDoc)
----------------------------------------------------------------------
With DetailView already loaded and an item selected.
Ordered by: internal time, call count
List reduced from 179 to 50 due to restriction <50>
ncalls tottime percall cumtime percall filename:lineno(function)
1 129.363 129.363 129.363 129.363 controls.py:2841(Realize)
852/642 33.798 0.040 143.684 0.224 item.py:444(getAttributeValue)
12 28.098 2.342 28.857 2.405 core.py:1971(__init__)
922/774 15.954 0.017 60.213 0.078 item.py:138(__setattr__)
118 15.625 0.132 54.402 0.461 dbcontainer.py:446(readName)
1 13.870 13.870 14.139 14.139 controls.py:349(__init__)
560/105 11.410 0.020 30.358 0.289 item.py:1492(_getPath)
12 10.468 0.872 11.421 0.952 core.py:2242(ConvertToBitmap)
734/594 7.947 0.011 147.991 0.249 item.py:128(__getattr__)
854 7.438 0.009 7.438 0.009 item.py:2271(_countAccess)
472 6.803 0.014 16.707 0.035 xmlrepository.py:494(_getTxn)
34/1 6.348 0.187 464.622 464.622 block.py:36(render)
708 6.307 0.009 9.556 0.013 threadlocal.py:39(_getCurrentThrea
dLocals)
560 6.220 0.011 9.201 0.016 item.py:1533(__getParent)
18 6.027 0.335 6.027 0.335 core.py:6404(Freeze)
118 5.583 0.047 14.660 0.124 xmlrepository.py:461(startTransact
ion)
118 5.138 0.044 16.476 0.140 xmlrepository.py:481(abortTransact
ion)
118 4.933 0.042 61.625 0.522 xmlrefdict.py:77(resolveAlias)
3 4.643 1.548 5.129 1.710 controls.py:1218(__init__)
9 4.597 0.511 5.898 0.655 windows.py:13(__init__)
5 4.459 0.892 4.923 0.985 controls.py:754(__init__)
71 4.391 0.062 73.143 1.030 kind.py:119(getAttribute)
8 4.381 0.548 4.381 0.548 core.py:6560(SetFont)
118 4.356 0.037 79.407 0.673 kind.py:108(resolve)
18 3.810 0.212 3.810 0.212 core.py:6421(Thaw)
118 3.687 0.031 7.642 0.065 dbcontainer.py:73(cursor)
16 3.656 0.229 97.576 6.098 dynamiccontainerblocks.py:570(addT
ool)
210 3.646 0.017 3.646 0.017 path.py:57(set)
560 3.446 0.006 3.446 0.006 path.py:84(append)
190 3.443 0.018 4.462 0.023 linkedmap.py:80(_get)
709 3.258 0.005 3.258 0.005 threading.py:609(currentThread)
472 3.206 0.007 9.904 0.021 threadlocal.py:21(__getattr__)
118 3.206 0.027 4.805 0.041 item.py:1838(getItemChild)
9 3.109 0.345 3.109 0.345 core.py:7014(Layout)
236 2.995 0.013 7.662 0.032 xmlrepository.py:502(_setTxn)
455 2.615 0.006 2.615 0.006 item.py:1182(isStale)
221 2.564 0.012 3.204 0.014 itemref.py:39(getItem)
95 2.499 0.026 6.026 0.063 itemref.py:849(_getRef)
359 2.393 0.007 2.393 0.007 item.py:1127(hasAttributeValue)
154 2.333 0.015 2.543 0.017 linkedmap.py:196(get)
105 2.315 0.022 2.315 0.022 path.py:28(__repr__)
168 2.055 0.012 2.488 0.015 itemref.py:50(getOther)
156 2.008 0.013 18.644 0.120 linkedmap.py:228(__iter__)
82 1.940 0.024 5.850 0.071 item.py:1033(hasValue)
249 1.929 0.008 1.929 0.008 item.py:1161(isNew)
33/1 1.920 0.058 36.879 36.879 detail.py:61(reNotifyInside)
236 1.809 0.008 4.666 0.020 threadlocal.py:28(__setattr__)
270 1.716 0.006 1.716 0.006 uuid.py:60(__hash__)
47 1.715 0.036 44.863 0.955 kind.py:153(hasAttribute)
168 1.714 0.010 7.406 0.044 itemref.py:121(other)
14289 function calls (13267 primitive calls) in 464.622 CPU seconds
Ordered by: call count
List reduced from 179 to 10 due to restriction <10>
ncalls tottime percall cumtime percall filename:lineno(function)
922/774 15.954 0.017 60.213 0.078 item.py:138(__setattr__)
854 7.438 0.009 7.438 0.009 item.py:2271(_countAccess)
852/642 33.798 0.040 143.684 0.224 item.py:444(getAttributeValue)
734/594 7.947 0.011 147.991 0.249 item.py:128(__getattr__)
709 3.258 0.005 3.258 0.005 threading.py:609(currentThread)
708 6.307 0.009 9.556 0.013 threadlocal.py:39(_getCurrentThrea
dLocals)
560/105 11.410 0.020 30.358 0.289 item.py:1492(_getPath)
560 6.220 0.011 9.201 0.016 item.py:1533(__getParent)
560 3.446 0.006 3.446 0.006 path.py:84(append)
472 6.803 0.014 16.707 0.035 xmlrepository.py:494(_getTxn)
14289 function calls (13267 primitive calls) in 464.622 CPU seconds
Ordered by: cumulative time
List reduced from 179 to 10 due to restriction <10>
ncalls tottime percall cumtime percall filename:lineno(function)
34/1 6.348 0.187 464.622 464.622 block.py:36(render)
18 0.774 0.043 251.155 13.953 block.py:211(synchronizeWidget)
1 1.002 1.002 234.208 234.208 dynamiccontainerblocks.py:508(wxSy
nchronizeWidget)
734/594 7.947 0.011 147.991 0.249 item.py:128(__getattr__)
852/642 33.798 0.040 143.684 0.224 item.py:444(getAttributeValue)
1 129.363 129.363 129.363 129.363 controls.py:2841(Realize)
16 3.656 0.229 97.576 6.098 dynamiccontainerblocks.py:570(addT
ool)
118 4.356 0.037 79.407 0.673 kind.py:108(resolve)
71 4.391 0.062 73.143 1.030 kind.py:119(getAttribute)
118 4.933 0.042 61.625 0.522 xmlrefdict.py:77(resolveAlias)
-- KatieCappsParlante - 13 Sep 2004
Log In
Except where otherwise noted, this site and its content are licensed by OSAF under an Creative Commons License, Attribution Only 3.0.
See list of page contributors for attributions.
See list of page contributors for attributions.