CODEWITHSUNDEEP
pythonprofilerpypycprofile
user1179317
user1179317

Reputation: 2903

Python cprofile total time

I am doing some profiling of my code, and trying to optimize it as much as I could. But I notice that the total cumulative time for a specific function doesnt add up sometimes. So I wasnt sure which function was being the culprit.

To make this easier, I created a simple example below -- it doesnt do anything really.

L = [1,2,3,4,5]


class MyObj:
    __slots__ = "a", "b"

    def __init__(self, a="", b=""):
        self.a = a
        self.b = b


def get_top():
    return L[0]


def revert(x):
    return -x


def check():
    if True:
        return True
    else:
        return False


def main(x):
    if check():
        p = revert(x)
        q = get_top()
        o = MyObj(a=p, b=q)
    else:
        o = MyObj()


for x in range(10_000_000):
    main(x)

And if I execute this with pypy3 (same scenario happens with python3 really) with code:

python -m cProfile test.py

I get something like:

         50000005 function calls in 1.895 seconds

   Ordered by: standard name

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.522    0.522    1.895    1.895 test0.py:1(<module>)
 10000000    0.180    0.000    0.180    0.000 test0.py:12(get_top)
 10000000    0.153    0.000    0.153    0.000 test0.py:16(revert)
 10000000    0.140    0.000    0.140    0.000 test0.py:20(check)
 10000000    0.746    0.000    1.374    0.000 test0.py:27(main)
        1    0.000    0.000    0.000    0.000 test0.py:4(MyObj)
 10000000    0.156    0.000    0.156    0.000 test0.py:7(__init__)
        1    0.000    0.000    0.000    0.000 {built-in function __build_class__}
        1    0.000    0.000    1.895    1.895 {built-in function exec}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

As you can see, the main took 1.374 cumtime and 0.746 tottime, but when adding up the functions called, it will be less than this number. Is this always not going to add up? Just wondering how I can tell the function that is taking a while if each function time is not accurate -- assuming the function is like the main() which consists of multiple functions.

Upvotes: 1

Views: 2216

Answers (1)

mattip
mattip

Reputation: 2563

There are some hints for profiling PyPy here. In general, a deterministic profiler like cprofile will break the JIT, so it is not recommended for profiling with PyPy. A statistical approach is better where the profiler samples the program stack every X milliseconds. Profiling and optimization are hard problems when using a JIT because often things don't add up: there is overhead in the interpreter itself that are hard to measure.

Upvotes: 3

Related Questions