1

When running

time python3 -mcProfile -o program.prof foo.py

on

import time

def prime(n):
     # Called from
     #   . -> a() -> prime()
     #   . -> b() -> prime()
     #   . -> c() -> a() -> prime()
     #   . -> c() -> b() -> prime()
     time.sleep(n)
     return 2

def a():
    return prime(1)

def b():
    return prime(3)

def c():
    a()
    b()
    return


if __name__ == '__main__':
    a()
    b()
    c()

the information in the profile file is

('foo.py', 1, '<module>'):
  (1, 1, 2.1e-05, 8.008853, {
    ('~', 0, '<built-in method builtins.exec>'): (1, 1, 2.1e-05, 8.008853)
    }),

// Take note here
('foo.py', 3, 'prime'):
  (4, 4, 3.2999999999999996e-05, 8.008799, {
    ('foo.py', 8, 'a'): (2, 2, 1.4e-05, 2.00237),
    ('foo.py', 11, 'b'): (2, 2, 1.8999999999999998e-05, 6.006429)
    }),

('foo.py', 8, 'a'):
  (2, 2, 1.1e-05, 2.0023809999999997, {
    ('foo.py', 1, '<module>'): (1, 1, 4.9999999999999996e-06, 1.001307),
    ('foo.py', 14, 'c'): (1, 1, 6e-06, 1.001074)
    }),

('foo.py', 11, 'b'):
  (2, 2, 1.2e-05, 6.006441, {
    ('foo.py', 1, '<module>'): (1, 1, 6e-06, 3.003311),
    ('foo.py', 14, 'c'): (1, 1, 6e-06, 3.00313)
    }),

('foo.py', 14, 'c'):
  (1, 1, 9.999999999999999e-06, 4.004214, {
    ('foo.py', 1, '<module>'): (1, 1, 9.999999999999999e-06, 4.004214)
    }),

('~', 0, '<built-in method builtins.exec>'):
  (1, 1, 4.9999999999999996e-06, 8.008858, {}
  ),

('~', 0, '<built-in method time.sleep>'):
  (4, 4, 8.008766, 8.008766, {
    ('foo.py', 3, 'prime'): (4, 4, 8.008766, 8.008766)
    }),

('~', 0, "<method 'disable' of '_lsprof.Profiler' objects>"):
  (1, 1, 1e-06, 1e-06, {})

For each method X, you have information on how often it was called, what the own time and the total runtime is, and what other methods called X.

I'm trying to create a timed call-tree from this, but here's a difficulty: The info in 'prime' (second in the above list) tells me it took 2 seconds when called from a(), 3 seconds when called from b(), that it was called twice from each, but I cannot distinguish between

root -> a() -> prime()
root -> c() -> a() -> prime()

This means I cannot construct a timed call tree from Stats. Is this correct? Are there any workarounds?

Nico Schlömer
  • 53,797
  • 27
  • 201
  • 249
  • Can't you look at the `Callers` of the `prime` function to determine which one took more time there? – AKS Feb 23 '17 at 08:37
  • You are looking for the fraction of stack samples in which `b` directly calls `prime`. You're not likely to get that information from any summary, but you can easily get it from the raw call stacks. That's one reason why [*this method*](http://stackoverflow.com/a/4299378/23771) is useful. – Mike Dunlavey Feb 24 '17 at 13:50

0 Answers0