Profiling gives very different predictions of best algorithm

[Rick Muller]

I'm the main programmer for the PyQuante package, a quantum chemistry
package in Python. I'm trying to speed up one of my rate determining
steps. Essentially, I have to decide between two algorithms:

1. Packed means that I compute N**4/8 integrals, and then do a bunch
of indexing operations to unpack;
2. Unpacked means that I compute all N**4 integrals, but don't have to
do any indexing.

Raw timing the two options show that packed is clearly faster (12.5
sec vs 20.6 sec). However, the profilings show very different results.
I have the results below. Clearly I'm going to use the packed scheme.
My question to the mailing list is what am I doing wrong with my
profiling that it shows such poor predictions? I rely on profiling a
great deal to tune my algorithms, and I'm used to seeing differences,
but nothing close to this magnitude.

Here is packed:
 ncalls  tottime  percall  cumtime  percall filename:lineno(function)
 11021725   84.493    0.000   84.493    0.000 :0(ijkl2intindex)
       18   62.064    3.448  119.865    6.659 Ints.py:150(getK)
       18   32.063    1.781   61.186    3.399 Ints.py:131(getJ)
    52975    9.404    0.000   19.658    0.000 CGBF.py:189(coulomb)
   313643    2.542    0.000    2.542    0.000 :0(range)
    52975    2.260    0.000    2.260    0.000 :0(contr_coulomb)
   218200    1.377    0.000    1.377    0.000 CGBF.py:51(norm)
   211900    1.337    0.000    1.337    0.000 CGBF.py:53(powers)
   211900    1.336    0.000    1.336    0.000 CGBF.py:56(exps)
   211900    1.329    0.000    1.329    0.000 CGBF.py:58(pnorms)
   211900    1.328    0.000    1.328    0.000 CGBF.py:52(origin)
   211900    1.328    0.000    1.328    0.000 CGBF.py:57(coefs)
        1    0.979    0.979   21.108   21.108 Ints.py:112(get2ints)
    11790    0.197    0.000    0.197    0.000 :0(dot)
    11828    0.166    0.000    0.166    0.000 :0(zeros)

Here is unpacked:
ncalls  tottime  percall  cumtime  percall filename:lineno(function)
       18   16.158    0.898   17.544    0.975 Ints.py:167(getK)
    52975    9.301    0.000   19.515    0.000 CGBF.py:189(coulomb)
       18    4.584    0.255    5.904    0.328 Ints.py:146(getJ)
   313643    2.630    0.000    2.630    0.000 :0(range)
    52975    2.254    0.000    2.254    0.000 :0(contr_coulomb)
   218200    1.375    0.000    1.375    0.000 CGBF.py:51(norm)
   211900    1.330    0.000    1.330    0.000 CGBF.py:58(pnorms)
   211900    1.325    0.000    1.325    0.000 CGBF.py:53(powers)
   211900    1.325    0.000    1.325    0.000 CGBF.py:57(coefs)
   211900    1.323    0.000    1.323    0.000 CGBF.py:56(exps)
   211900    1.321    0.000    1.321    0.000 CGBF.py:52(origin)
        1    0.782    0.782   20.373   20.373 Ints.py:114(get2ints)
     1875    0.156    0.000    0.384    0.000 CGBF.py:106(nuclear)
    11790    0.147    0.000    0.147    0.000 :0(dot)
    17856    0.112    0.000    0.112    0.000 PGBF.py:63(coef)