[Python-Dev] proposal+patch: sys.gettickeraccumulation()

[Nick Coghlan]

Ralf W. Grosse-Kunstleve wrote:
>>Knowing "I'm spending x% of the time executing Python code" just isn't 
>>really all that interesting,
> 
> 
> Right. Sorry if I gave the wrong impression that this could be
> interesting. It is indeed not. What is interesting is the estimated
> benefit of reimplementing a piece of Python in C/C++. This is in
> fact highly correlated with the time/tick.

Ah, OK, I think I better understand what you're trying to achieve now. 
Does knowing that the 2.4 profiler splits out C invocations from the 
calling Python methods make a difference here?

The 2.4 profiler is the only one I've made heavy use of - I'd forgotten 
that the 2.3 profiler didn't split out the C functions.

I've also discovered that the profiler documentation in Python 2.4 still 
describes the old behaviour (i.e. C-code time getting charged to the 
calling Python function). (I'll put a bug report on SF for that one)

I've got some sample output comparing the 2.3 and 2.4 profilers below. 
The interesting lines in the 2.4 output are the ones without a filename 
- those are the C functions.

Cheers,
Nick.

Python 2.3 profiler:
==================
$ python /usr/lib/python2.3/profile.py /usr/lib/python2.3/profile.py
usage: profile.py scriptfile [arg] ...
          6 function calls in 0.031 CPU seconds

    Ordered by: standard name

    ncalls  tottime  percall  cumtime  percall filename:lineno(function)
         1    0.015    0.015    0.015    0.015 <string>:1(?)
         1    0.000    0.000    0.000    0.000 profile.py:10(?)
         1    0.000    0.000    0.000    0.000 profile.py:103(Profile)
         1    0.000    0.000    0.000    0.000 profile.py:334(fake_code)
         1    0.000    0.000    0.000    0.000 profile.py:344(fake_frame)
         1    0.016    0.016    0.031    0.031 
profile:0(execfile('/usr/lib/pytho
n2.3/profile.py'))
         0    0.000             0.000          profile:0(profiler)
==================

And with Python 2.4:
==================
$ ./python -m profile -s time /usr/lib/python2.3/profile.py
usage: profile.py scriptfile [arg] ...
          10 function calls in 0.048 CPU seconds

    Ordered by: internal time

    ncalls  tottime  percall  cumtime  percall filename:lineno(function)
         1    0.032    0.032    0.032    0.032 :0(setprofile)
         1    0.016    0.016    0.016    0.016 :0(execfile)
         1    0.000    0.000    0.000    0.000 profile.py:334(fake_code)
         1    0.000    0.000    0.000    0.000 :0(exit)
         1    0.000    0.000    0.000    0.000 profile.py:10(?)
         1    0.000    0.000    0.000    0.000 profile.py:344(fake_frame)
         1    0.000    0.000    0.000    0.000 :0(hasattr)
         1    0.000    0.000    0.000    0.000 profile.py:103(Profile)
         1    0.000    0.000    0.048    0.048 
profile:0(execfile('/usr/lib/pytho
n2.3/profile.py'))
         1    0.000    0.000    0.048    0.048 <string>:1(?)
         0    0.000             0.000          profile:0(profiler)
==================

-- 
Nick Coghlan               |     Brisbane, Australia
Email: ncoghlan at email.com  | Mobile: +61 409 573 268