| msg143813 - (view) |
Author: Hagen Fürstenau (hagen) |
Date: 2011-09-09 22:37 |
| I noticed that some function calls don't get reported by profile/cProfile. For example, 'len' works fine, but calls to 'range' or functions in 'itertools' don't show up. Is this a known limitation? I remember that there was a bug in profiling C-functions with keyword arguments (, fixed), but I don't have the time right now to investigate whether this is related. |
|
|
| msg144137 - (view) |
Author: Terry J. Reedy (terry.reedy) *  |
Date: 2011-09-16 16:46 |
| Thanks for the report, which I verified on 3.2.2, Win7. When reporting a bug, please give a minimal example of code showing the bug, and the buggy output. I presume you mean something like the following (slightly edited): >>> profile.run('for i in range(10): len({})') ncalls tottime percall cumtime percall filename:lineno(function) 1 0.000 0.000 0.000 0.000 :0(exec) 10 0.000 0.000 0.000 0.000 :0(len) 1 0.016 0.016 0.016 0.016 :0(setprofile) 1 0.000 0.000 0.000 0.000 :1() 1 0.000 0.000 0.016 0.016 profile:0(for i in range(10): len({})) 0 0.000 0.000 profile:0(profiler) >>> profile.run('for i in range(10): range(1)') ncalls tottime percall cumtime percall filename:lineno(function) 1 0.000 0.000 0.000 0.000 :0(exec) 1 0.000 0.000 0.000 0.000 :0(setprofile) 1 0.000 0.000 0.000 0.000 :1() 1 0.000 0.000 0.000 0.000 profile:0(for i in range(10): range(1)) 0 0.000 0.000 profile:0(profiler) The one call to range(10) and in the second case, the 10 calls to range(1) are missing while in the first case, the 10 calls to len(()) are reported. This looks like a bug to me. As far as I know, len and range are equal status builtin functions. The only Limitations reported in the doc are about timing accuracy. A minimal test for this would be to look for ":0(range)" in the output, to match the way ":0(len)" does now. |
|
|
| msg144139 - (view) |
Author: R. David Murray (r.david.murray) * |
Date: 2011-09-16 16:57 |
| I wonder if it has something to do with range returning a special type? range and len are very different things under the hood. |
|
|
| msg144140 - (view) |
Author: Hagen Fürstenau (hagen) |
Date: 2011-09-16 17:01 |
| It happens for other C functions as well, e.g. itertools.permutations: >>> profile.run('itertools.permutations(range(10), 3)') 4 function calls in 0.000 seconds Ordered by: standard name ncalls tottime percall cumtime percall filename:lineno(function) 1 0.000 0.000 0.000 0.000 :0(exec) 1 0.000 0.000 0.000 0.000 :0(setprofile) 1 0.000 0.000 0.000 0.000 :1() 1 0.000 0.000 0.000 0.000 profile:0(itertools.permutations(range(10), 3)) 0 0.000 0.000 profile:0(profiler) |
|
|
| msg144144 - (view) |
Author: Terry J. Reedy (terry.reedy) * |
Date: 2011-09-16 18:02 |
| Range and most of the itertools functions are exposed at the Python level as iterator classes. (But since C does not have classes, they must be C-level functions!) The int 'class' is also not profiled. I think this is wrong behavior. Int and range used to be non-class functions, which means the output of profile must have once included them (in 2.7 for range). Classes *are* functions in the wider sense, as used in the title of the 'Builtin functions'. User callables can also switch implementations. A closure might be replaced by a class; a class might be replaced by a factory function. One could argue that this is such a long time bug (probably) that it should be handled as a feature request. The docs are a bit vague as to what is profiled, except that 26.3.1. Introduction to the profilers does refer to 'C-level functions'. However, the more important issue, at present, is keeping profile and cProfile, which wraps lsprof, in sync. |
|
|