25

I am using Python's (v2.4) profile module to profile a numpy script, and the following entry appears to account for the bulk of the execution time:

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
 256/1    0.000    0.000    7.710    7.710 <string>:1(?)

Unfortunately, its appearance makes it hard to Google.

How do I go about figuring out what this is exactly?

edit The profiler is run from the shell as follows: python -m profile -s cumulative script.py

NPE
  • 486,780
  • 108
  • 951
  • 1,012
  • Are you using `profile.run()` to run the profiler? Then `:1` refers to the first line of the statement string you passed to this function. If you are calling the profiler in a different way, please specify. – Sven Marnach May 11 '11 at 12:47
  • @Sven Marnach: Good point, I've added this info to the question. – NPE May 11 '11 at 12:49
  • 1
    Assuming you're asking because you want higher performance, [try this](http://stackoverflow.com/questions/4295799/how-to-improve-performance-of-this-code/4299378#4299378). – Mike Dunlavey May 11 '11 at 13:30

1 Answers1

26

Ignore this line. It is an artifact of how the profiler is implemented. It is not telling you anything useful. Look at the "tottime" value for it: 0.000. "tottime" is the amount of time spent executing "<string>:1(?)" excluding time spent executing children of it. So, no time is spent here. "cumtime" and "percall" are large because they include time spent in children. See http://docs.python.org/library/profile.html#cProfile.run for more details.

Jean-Paul Calderone
  • 47,755
  • 6
  • 94
  • 122
  • 3
    but what if the *largest* tottime is `:1()`? – endolith Apr 15 '12 at 21:46
  • 7
    `:1()` is top-level code in the entry-point Python script invoked. So if all your code is top-level in "foo.py" and you do `python foo.py`, then you'll see a high tottime for `:1()`. By "top-level", I mean not inside any function definition - just run directly. – Jean-Paul Calderone Apr 16 '12 at 20:59
  • if I order the %prun output by tottime I have 8.9 seconds (of 9.6 overall) in :1(). The next entry is 0.2 s and then it decreases quickly. What happens in the top entry? – Barden May 04 '22 at 12:31