Closed GoogleCodeExporter closed 9 years ago
profiled:
WARNING: This test case will take about 5 minutes and is recommended to be done
before major releases.
Removing existing cing project "<Project 1v0e>"
==> Parsing pdbFile
"/Users/jd/workspace35/cing/Tests/data/pdb/1v0e/pdb1v0e.ent" ...
WARNING: Skipping non N-terminal residue without doublet <Residue SER245>
(missing preceding neighbour but not N-terminal)
==> Molecule pdb1v0e: No potential disulfide bridged residues found
Calculating rmsd's (ranges: None, models: 0-0)
DEBUG: pdbParser.importCoordinates: <Molecule "pdb1v0e"
(C:1,R:1194,A:16483,M:1)>
-------------------------------------------------------
==> Saving <Project 1v0e>
==> Saved <Molecule "pdb1v0e" (C:1,R:1194,A:16483,M:1)> to
"1v0e.cing/Data/Molecules/pdb1v0e.molecule"
.Tue Mar 2 15:30:14 2010 /Users/jd/tmp/cingTmp/testPdbFileProfile.log
15660100 function calls (13284598 primitive calls) in 241.601 CPU seconds
Ordered by: internal time
List reduced from 324 to 100 due to restriction <100>
ncalls tottime percall cumtime percall filename:lineno(function)
4588513/2326175 67.242 0.000 82.758 0.000
/Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1216(__eq__)
2234143 33.227 0.000 47.498 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1177(__getattr__)
2530991 16.439 0.000 16.439 0.000 :0(has_key)
2307338 15.837 0.000 15.837 0.000 :0(isinstance)
4662 12.034 0.003 68.371 0.015 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:249(index)
1 7.325 7.325 41.346 41.346 /Users/jd/workspace35/cing/python/cing/core/molecule.py:1676(calculateRMSDs)
167746 4.144 0.000 5.222 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1581(__len__)
551552 3.862 0.000 3.862 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1190(__setattr__)
51652 3.847 0.000 10.068 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1902(next)
489250 3.384 0.000 3.384 0.000 :0(len)
16483 2.774 0.000 26.180 0.002 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3165(__init__)
1 2.674 2.674 30.768 30.768 /Users/jd/workspace35/cing/python/cing/core/molecule.py:1181(updateTopology)
27036 2.585 0.000 6.540 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1645(saveXML)
256665 2.582 0.000 2.582 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:190(append)
100353/1208 2.412 0.000 3.386 0.003
/Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1925(subNodes)
51811 2.360 0.000 3.720 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1159(__init__)
5894 2.345 0.000 4.384 0.001 /Users/jd/workspace35/cing/python/cing/Libs/PyMMLib.py:120(read)
16483 2.157 0.000 34.249 0.002 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2609(addAtom)
16483 2.137 0.000 6.035 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3297(calculateMeanCoordinate)
38724 1.957 0.000 4.942 0.000 /Users/jd/workspace35/cing/python/cing/core/database.py:809(translate)
253140 1.679 0.000 1.679 0.000 :0(setdefault)
121135 1.671 0.000 2.007 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:87(__init__)
16483 1.666 0.000 7.659 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3686(nameTuple)
24633 1.659 0.000 9.900 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1750(__init__)
27999 1.639 0.000 4.005 0.000 /Users/jd/workspace35/cing/python/cing/core/database.py:550(getAtomDefByName)
16483 1.535 0.000 12.792 0.001 /Users/jd/workspace35/cing/python/cing/core/sml.py:649(toSML)
24629 1.445 0.000 3.533 0.000 /Users/jd/workspace35/cing/python/cing/core/database.py:282(getResidueDefByName)
166604 1.415 0.000 1.415 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:112(__getitem__)
5965 1.301 0.000 6.172 0.001 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2984(calculateValues)
4638 1.273 0.000 44.767 0.010 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2923(__init__)
24631 1.264 0.000 2.942 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1798(_addChild)
35356 1.179 0.000 2.951 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1940(header)
22241 1.150 0.000 8.702 0.000 /Users/jd/workspace35/cing/python/cing/core/database.py:321(getAtomDefByName)
16483 1.110 0.000 3.246 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3215(toString)
1 1.064 1.064 6.344 6.344 /Users/jd/workspace35/cing/python/cing/Libs/pdb.py:126(_records2tree)
63976 1.058 0.000 1.741 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:3286(fprintf)
1 0.980 0.980 159.114 159.114 /Users/jd/workspace35/cing/python/cing/Libs/pdb.py:348(importCoordinates)
133961 0.956 0.000 0.956 0.000 :0(startswith)
5758 0.874 0.000 3.292 0.001 /Users/jd/workspace35/cing/python/cing/Libs/pdb.py:532(matchAtom2Cing)
1 0.851 0.851 2.873 2.873 /Users/jd/workspace35/cing/python/cing/core/molecule.py:1881(__init__)
17681 0.823 0.000 2.798 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1355(footer)
4662 0.818 0.000 71.049 0.015 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1836(_sibling)
1 0.767 0.767 9.011 9.011 /Users/jd/workspace35/cing/python/cing/Libs/pdb.py:297(map2molecule)
17682 0.759 0.000 2.529 0.000 /Users/jd/workspace35/cing/python/cing/core/ROGscore.py:23(__init__)
5758 0.720 0.000 5.430 0.001 /Users/jd/workspace35/cing/python/cing/core/molecule.py:422(decodeNameTuple)
94184 0.683 0.000 0.683 0.000 :0(strip)
25823 0.677 0.000 1.772 0.000 /Users/jd/workspace35/cing/python/cing/core/database.py:518(translate)
6955/2 0.651 0.000 13.892 6.946 /Users/jd/workspace35/cing/python/cing/core/sml.py:366(toSML)
1 0.647 0.647 4.718 4.718 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3981(criticize)
86370 0.633 0.000 0.633 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3050(__setattr__)
81675 0.578 0.000 0.578 0.000 :0(isspace)
78344 0.541 0.000 0.541 0.000 :0(append)
16483 0.532 0.000 1.342 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3703(isPseudoAtom)
11516 0.525 0.000 0.942 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3030(__init__)
3308 0.524 0.000 41.649 0.013 /Users/jd/workspace35/cing/python/cing/core/molecule.py:4240(translateTopology)
10666 0.516 0.000 1.251 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:3897(angle3Dopt)
1194 0.515 0.000 38.741 0.032 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2623(addAllAtoms)
63985 0.494 0.000 0.494 0.000 :0(write)
42456 0.476 0.000 71.770 0.002 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1861(sibling)
16483 0.434 0.000 1.149 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3606(isProton)
51071 0.428 0.000 0.428 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1250(__hash__)
1 0.404 0.404 2.772 2.772 /Users/jd/workspace35/cing/python/cing/core/molecule.py:1355(syncModels)
16483 0.404 0.000 0.664 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3986(append)
16483 0.398 0.000 2.853 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3386(translate)
41128 0.373 0.000 0.373
----------------------------------------------------------------------
Ran 1 test in 561.420s
OK
0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:3302(sprintf)
5758 0.354 0.000 1.418 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3234(addCoordinate)
5333 0.341 0.000 0.585 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:2405(NTcAverage)
47715 0.339 0.000 0.339 0.000 :0(endswith)
5333 0.335 0.000 0.621 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:2294(NTlimit)
1 0.321 0.321 5.371 5.371 /Users/jd/workspace35/cing/python/cing/Libs/PyMMLib.py:1516(load_file)
1194 0.302 0.000 58.026 0.049 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2634(addDihedralsAll)
3582 0.301 0.000 1.242 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2734(hasProperties)
21332 0.297 0.000 0.433 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:3891(length3Dopt)
31678 0.294 0.000 0.342 0.000 :0(hasattr)
38826 0.279 0.000 0.279 0.000 :0(split)
5333 0.269 0.000 1.661 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:4117(NTdihedralOpt)
17274 0.242 0.000 0.364 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3076(__setitem__)
1194 0.239 0.000 12.749 0.011 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2781(addDihedralD1)
17274 0.239 0.000 0.360 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3063(__getitem__)
1194 0.226 0.000 2.044 0.002 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2411(__init__)
32425 0.220 0.000 0.220 0.000 :0(sqrt)
2390 0.198 0.000 1.608 0.001 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:2073(__init__)
5758 0.183 0.000 3.281 0.001 /Users/jd/workspace35/cing/python/cing/core/database.py:1163(translateAtomName)
6953 0.178 0.000 3.688 0.001 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1792(addChild)
1 0.177 0.177 5.558 5.558 /Users/jd/workspace35/cing/python/cing/Libs/pdb.py:228(_matchResiduesAndAtoms)
1194 0.169 0.000 0.626 0.001 /Users/jd/workspace35/cing/python/cing/Libs/pdb.py:426(matchResidue2Cing)
6952 0.169 0.000 0.792 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2655(translate)
1194 0.160 0.000 0.679 0.001 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2460(_nameResidue)
6955/2 0.158 0.000 13.892 6.946 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:601(toSML)
5758 0.151 0.000 0.314 0.000 /Users/jd/workspace35/cing/python/cing/core/database.py:851(hasProperties)
1 0.149 0.149 6.783 6.783 /Users/jd/workspace35/cing/python/cing/core/molecule.py:1227(updateMean)
5758 0.142 0.000 0.581 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3567(isSidechain)
15999 0.141 0.000 0.141 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:3881(cross3Dopt)
1194 0.141 0.000 2.489 0.002 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2238(addResidue)
1195 0.137 0.000 0.597 0.000 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2103(_average)
16627 0.130 0.000 0.130 0.000 :0(range)
16483 0.126 0.000 0.126 0.000 /Users/jd/workspace35/cing/python/cing/core/ROGscore.py:110(setMaxColor)
1 0.122 0.122 1.377 1.377 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3991(appendFromMolecule)
1 0.112 0.112 50.763 50.763 /Users/jd/workspace35/cing/python/cing/Libs/pdb.py:272(initMolecule)
5333 0.107 0.000 0.692 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:453(cAverage)
Tue Mar 2 15:30:14 2010 /Users/jd/tmp/cingTmp/testPdbFileProfile.log
15660100 function calls (13284598 primitive calls) in 241.601 CPU seconds
Ordered by: cumulative time
List reduced from 324 to 100 due to restriction <100>
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.000 0.000 241.601 241.601 profile:0(unittest.main())
1 0.000 0.000 241.601 241.601 <string>:1(<module>)
1 0.000 0.000 241.601 241.601 /opt/local/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/unittest.py:800(__init__)
1 0.000 0.000 241.595 241.595 /opt/local/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/unittest.py:851(runTests)
1 0.000 0.000 241.595 241.595 /opt/local/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/unittest.py:749(run)
3/1 0.000 0.000 241.594 241.594 /opt/local/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/unittest.py:463(__call__)
3/1 0.000 0.000 241.594 241.594 /opt/local/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/unittest.py:456(run)
1 0.000 0.000 241.594 241.594 /opt/local/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/unittest.py:299(__call__)
1 0.000 0.000 241.594 241.594 /opt/local/Library/Frameworks/Python.framework/Versions/2.6/lib/python2.6/unittest.py:264(run)
1 0.000 0.000 241.594 241.594 /Users/jd/workspace35/cing/python/cing/Libs/test/test2_pdb.py:23(testPdbFile)
1 0.004 0.004 227.166 227.166 /Users/jd/workspace35/cing/python/cing/core/classes.py:942(initPDB)
1 0.000 0.000 227.161 227.161 /Users/jd/workspace35/cing/python/cing/Libs/pdb.py:786(initPDB)
1 0.980 0.980 159.114 159.114 /Users/jd/workspace35/cing/python/cing/Libs/pdb.py:348(importCoordinates)
1 0.011 0.011 154.780 154.780 /Users/jd/workspace35/cing/python/cing/core/molecule.py:1395(updateAll)
4588513/2326175 67.242 0.000 82.758 0.000
/Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1216(__eq__)
42456 0.476 0.000 71.770 0.002 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1861(sibling)
4662 0.818 0.000 71.049 0.015 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1836(_sibling)
4662 12.034 0.003 68.371 0.015 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:249(index)
1194 0.302 0.000 58.026 0.049 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2634(addDihedralsAll)
1 0.112 0.112 50.763 50.763 /Users/jd/workspace35/cing/python/cing/Libs/pdb.py:272(initMolecule)
2234143 33.227 0.000 47.498 0.000 /Users/jd/workspace35/cing/python/cing/Libs/NTutils.py:1177(__getattr__)
4638 1.273 0.000 44.767 0.010 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2923(__init__)
3308 0.524 0.000 41.649 0.013 /Users/jd/workspace35/cing/python/cing/core/molecule.py:4240(translateTopology)
1 7.325 7.325 41.346 41.346 /Users/jd/workspace35/cing/python/cing/core/molecule.py:1676(calculateRMSDs)
1194 0.515 0.000 38.741 0.032 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2623(addAllAtoms)
16483 2.157 0.000 34.249 0.002 /Users/jd/workspace35/cing/python/cing/core/molecule.py:2609(addAtom)
1 2.674 2.674 30.768 30.768 /Users/jd/workspace35/cing/python/cing/core/molecule.py:1181(updateTopology)
16483 2.774 0.000 26.180 0.002 /Users/jd/workspace35/cing/python/cing/core/molecule.py:3165(__init__)
1 0.001 0.001 17.275 17.275 /Users/jd/workspace35/cing/python/cing/Libs/pdb.py:99(__init__)
2530991 16.439 0.000 16.439 0.000 :0(has_key)
2307338 15.837 0.000 15.837 0.000 :0(isinstance)
Original comment by jurge...@gmail.com
on 2 Mar 2010 at 2:57
Can be repeated by doing:
python $CINGROOT/python/cing/Libs/test/test2_pdb.py
from r729.
Original comment by jurge...@gmail.com
on 2 Mar 2010 at 3:36
I've optimized the operations in NTdict a bit already in r729.
Ok, profiled it now takes 4 minutes for one of the hexamers.
Unprofiled it now takes 3 minutes for full entry and that's acceptable at this
point.
Original comment by jurge...@gmail.com
on 3 Mar 2010 at 1:38
Original issue reported on code.google.com by
jurge...@gmail.com
on 2 Mar 2010 at 2:55