Re:Scalene: a high-performance, high-precision CPU and memor...
by emeryberger on Thursday January 09, 2020 @07:27PM
(#22007355)
Re: being impressed by the memory profiling hacks, thanks! :)
And you persuaded me. New version to be uploaded momentarily that attributes time to line 22.
% python3 -m scalene sample-sample.py
f1 1.8081 312499987500000
f2 1.7910 2812499962500000
f3 1.5034 1.5
sample-sample.py: % of CPU time = 70.53% out of 5.10s.
Line | CPU % | [sample-sample.py]
1 | | #!/usr/bin/env python
2 | |
3 | | import time
4 | |
5 | | def timed(f):
6 | | def f_timed(*args, **kwargs):
7 | | t = time.time()
8 | | r = f(*args, **kwargs)
9 | 0.32% | t = time.time() - t
10 | | print('%s %.4f %s' % (f.__name__, t, r))
11 | | return f_timed
12 | |
13 | | @timed
14 | | def f1(n):
15 | | s = 0
16 | 8.58% | for i in range(n):
17 | 41.34% | s += i
18 | | return s
19 | |
20 | | @timed
21 | | def f2(n):
22 | 49.76% | return sum(range(n))
23 | |
24 | | @timed
25 | | def f3(t):
26 | | time.sleep(t)
27 | | return t
28 | |
29 | | if __name__ == '__main__':
30 | | f1(25000000)
31 | | f2(75000000)
32 | | f3(1.5)
Re:Scalene: a high-performance, high-precision CPU and memor...
by emeryberger on Thursday January 09, 2020 @08:36PM
(#22007730)
This discussion inspired me to refine Scalene's output further. Scalene now separates out CPU time spent in Python from time spent in C (that is, not executing in the interpreter). I think this is the best of both worlds: all CPU time is accounted for, and it's easy for users to see what code is running where. Thanks!
sample-sample.py: % of CPU time = 99.58% out of 3.34s.
| CPU % | CPU % |
Line | (Python) | (C) | [sample-sample.py]
--------------------------------------------------------------------------------
1 | | | #!/usr/bin/env python
2 | | |
3 | | | import time
4 | | |
5 | | | def timed(f):
6 | | | def f_timed(*args, **kwargs):
7 | | | t = time.time()
8 | | | r = f(*args, **kwargs)
9 | | | t = time.time() - t
10 | | | print('%s %.4f %s' % (f.__name__, t, r))
11 | | | return f_timed
12 | | |
13 | | | @timed
14 | | | def f1(n):
15 | | | s = 0
16 | 6.61% | 0.41% | for i in range(n):
17 | 35.17% | 3.97% | s += i
18 | | | return s
19 | | |
20 | | | @timed
21 | | | def f2(n):
22 | 0.30% | 53.53% | return sum(range(n))
23 | | |
24 | | | @timed
25 | | | def f3(t):
26 | | | time.sleep(t)
27 | | | return t
28 | | |
29 | | | if __name__ == '__main__':
30 | | | f1(25000000)
31 | | | f2(75000000)
32 | | | f3(1.5)
Re:Scalene: a high-performance, high-precision CPU and memor...
by bawr_hszm on Thursday January 09, 2020 @11:13PM
(#22008251)
I like it, and I appreciate that you changed your mind - I'm still staunchly in the flamgraph camp of capturing and displaying whole stacks, but now I could see using this for small code samples, especially with the memory usage information added on top.
Thanks for being good with my grumpy feedback!
Re:Scalene: a high-performance, high-precision CPU and memor...
by gshulegaard on Thursday January 09, 2020 @11:00PM
(#22008215)
Just wanted to take a moment to appreciate the awesome response to feedback and new added feature.
In this example, the program spends a third of the time just sleeping / blocked, a third of the time on CPU but at the C level, and the remainder just evaluating Python loops. Unless you already know how it's implemented, that 33.66% is not easy to interpret, and the docs don't mention what exactly is being profiled. Specifically, these samples aren't a % of CPU time, they're a % of real time that we happened to have been able to do a Python-level interrupt, and even that isn't a great explanation. I think most users would still expect line 22 to get traced properly.
I very much do want to know about C time, too, because it's very much actionable for most of the optimizations I end up making in production systems.
That said, I don't think this line of discussion is super productive for either of us, we seem to have different goals in mind, which is fine. ;)
So I'll close by saying that I was impressed by your LD_PRELOAD hacks for memory profiling, which isn't an approach that I've ever seen in other Python profilers.