A function called by different function should have different called-info

[witie41]

hello if function A called by function B and function C,there is only one called-info of function A in Snakeviz which is sum by both called by B and C.it leading to some incorrect graph such as some function's cumtime is smaller than their child's.

def A():
    pass
def B():
    A()
def C():
    for i in range(1000):
        A()
if __name__ == "__main__":
    B()
    C()

thanks

[witie41]

sorry,I just have a look about the result of cProfile,which give too less info to restore the call stack...

[embray]

Just to follow up, since I was just investigating this, I actually got a totally different result from you, where the call stack shows C but not B:

However, looking at the profile data, I see that zero time is reported in B. I'm not 100% certain but the Python interpreter does have a few built-in optimizations, so it's possible that it detected that B() does nothing but call A() and optimized away the call to B().

If I change it to something like:

def B():
    time.sleep(0.001)
    A()

then the call stack looks more like you're expecting:

I'm not sure why you had such different results though.

[witie41]

Sorry to reply you late. I think you are right about the optimize of fun B,but my question is why the time showed below will more than itself. e.g.the function A's time is longer than function C's in my first picture.

[embray]

I'm not really sure I understand your question, since your original picture didn't show a call graph for C, only A and B. In any case, with such "do nothing" functions, so little time is spent in them that it may be difficult for the profiler to provide accurate accounting.

[witie41]

I mean that a function's time spent should be separated by it's different caller,such as C's time spent should be separated into C from A and C from B if C called by A and B both. if not, it's just look like the time spent of C is longer than it`s caller B or A

[jiffyclub]

This is definitely a weird case! But yeah, what you're observing is due to cProfile only reporting the total time spent in a function, not differentiating how much time is spent when called in different call trees. SnakeViz displays exactly what's in the cProfile data.

[witie41]

yeah,it can`t be solved by snakeviz,but thank you for discussion~

[embray]

@witie41 (As an aside, please do not use the backtick symbol ` when you mean to use an apostrophe ', as the backtick has special meaning in GitHub markdown. If for some reason you can't use the apostrophe I would just omit it.)

[witie41]

hahahaha,I get it thanks~