test_profile 128 function calls (108 primitive calls) in 1.000 CPU seconds Ordered by: standard name ncalls tottime percall cumtime percall filename:lineno(function) 4 0.000 0.000 0.000 0.000 :0(append) 4 0.000 0.000 0.000 0.000 :0(exc_info) 1 0.000 0.000 1.000 1.000 :0(exec) 12 0.000 0.000 0.012 0.001 :0(hasattr) 8 0.000 0.000 0.000 0.000 :0(range) 1 0.000 0.000 0.000 0.000 :0(setprofile) 1 0.000 0.000 1.000 1.000 :1() 0 0.000 0.000 profile:0(profiler) 1 0.000 0.000 1.000 1.000 profile:0(testfunc()) 8 0.064 0.008 0.080 0.010 test_profile.py:103(subhelper) 28 0.028 0.001 0.028 0.001 test_profile.py:115(__getattr__) 1 0.270 0.270 1.000 1.000 test_profile.py:30(testfunc) 23/3 0.150 0.007 0.170 0.057 test_profile.py:40(factorial) 20 0.020 0.001 0.020 0.001 test_profile.py:53(mul) 2 0.040 0.020 0.600 0.300 test_profile.py:60(helper) 4 0.116 0.029 0.120 0.030 test_profile.py:78(helper1) 2 0.000 0.000 0.140 0.070 test_profile.py:89(helper2_indirect) 8 0.312 0.039 0.400 0.050 test_profile.py:93(helper2) Ordered by: standard name Function called... :0(append) -> :0(exc_info) -> :0(exec) -> :1()(1) 1.000 :0(hasattr) -> test_profile.py:115(__getattr__)(12) 0.028 :0(range) -> :0(setprofile) -> :1() -> test_profile.py:30(testfunc)(1) 1.000 profile:0(profiler) -> profile:0(testfunc())(1) 1.000 profile:0(testfunc()) -> :0(exec)(1) 1.000 :0(setprofile)(1) 0.000 test_profile.py:103(subhelper) -> :0(range)(8) 0.000 test_profile.py:115(__getattr__)(16) 0.028 test_profile.py:115(__getattr__) -> test_profile.py:30(testfunc) -> test_profile.py:40(factorial)(1) 0.170 test_profile.py:60(helper)(2) 0.600 test_profile.py:40(factorial) -> test_profile.py:40(factorial)(20) 0.170 test_profile.py:53(mul)(20) 0.020 test_profile.py:53(mul) -> test_profile.py:60(helper) -> test_profile.py:78(helper1)(4) 0.120 test_profile.py:89(helper2_indirect)(2) 0.140 test_profile.py:93(helper2)(6) 0.400 test_profile.py:78(helper1) -> :0(append)(4) 0.000 :0(exc_info)(4) 0.000 :0(hasattr)(4) 0.012 test_profile.py:89(helper2_indirect) -> test_profile.py:40(factorial)(2) 0.170 test_profile.py:93(helper2)(2) 0.400 test_profile.py:93(helper2) -> :0(hasattr)(8) 0.012 test_profile.py:103(subhelper)(8) 0.080 Ordered by: standard name Function was called by... :0(append) <- test_profile.py:78(helper1)(4) 0.120 :0(exc_info) <- test_profile.py:78(helper1)(4) 0.120 :0(exec) <- profile:0(testfunc())(1) 1.000 :0(hasattr) <- test_profile.py:78(helper1)(4) 0.120 test_profile.py:93(helper2)(8) 0.400 :0(range) <- test_profile.py:103(subhelper)(8) 0.080 :0(setprofile) <- profile:0(testfunc())(1) 1.000 :1() <- :0(exec)(1) 1.000 profile:0(profiler) <- profile:0(testfunc()) <- profile:0(profiler)(1) 0.000 test_profile.py:103(subhelper) <- test_profile.py:93(helper2)(8) 0.400 test_profile.py:115(__getattr__) <- :0(hasattr)(12) 0.012 test_profile.py:103(subhelper)(16) 0.080 test_profile.py:30(testfunc) <- :1()(1) 1.000 test_profile.py:40(factorial) <- test_profile.py:30(testfunc)(1) 1.000 test_profile.py:40(factorial)(20) 0.170 test_profile.py:89(helper2_indirect)(2) 0.140 test_profile.py:53(mul) <- test_profile.py:40(factorial)(20) 0.170 test_profile.py:60(helper) <- test_profile.py:30(testfunc)(2) 1.000 test_profile.py:78(helper1) <- test_profile.py:60(helper)(4) 0.600 test_profile.py:89(helper2_indirect) <- test_profile.py:60(helper)(2) 0.600 test_profile.py:93(helper2) <- test_profile.py:60(helper)(6) 0.600 test_profile.py:89(helper2_indirect)(2) 0.140