search

jakesylvestre / cing

Automatically exported from code.google.com/p/cing
0 stars 0 forks source link

Need for speed #228

Closed GoogleCodeExporter closed 8 years ago

GoogleCodeExporter commented 8 years ago 
What steps will reproduce the problem?
1. Just reading an X-ray entry with lots of waters takes 4 minutes. That's 
unacceptable.

One of the hexamer units with 666 AA residues and 500+ water molecules of entry 
1v0e takes 4 
minutes just loading.

Original issue reported on code.google.com by jurge...@gmail.com on 2 Mar 2010 at 2:55

GoogleCodeExporter commented 8 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

GoogleCodeExporter commented 8 years ago 
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

GoogleCodeExporter commented 8 years ago 
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