<div dir="ltr"><div style>Hello again,</div><div style><br></div><div style>I have not received any sign of life since I suggested this modification. What is your current status?</div><div style><br></div>Is this the right place to ask?<div style>
<br></div><div style>Thanks,</div><div style><br></div><div style>Quentin</div><div style><br></div><div style><br></div></div><div class="gmail_extra"><br><br><div class="gmail_quote">On Fri, Apr 19, 2013 at 3:59 PM, Quentin de Metz <span dir="ltr"><<a href="mailto:quentin@box.com" target="_blank">quentin@box.com</a>></span> wrote:<br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr">Hello to the Python documentation team,<div><br></div><div>I work in a software company in the Silicon Valley and we are using Python (2.7) for one of our upcoming releases.</div>
<div><br></div><div>
I'm working on performance testing for this software and have been fiddling quite a bit with the profiling modules available. I believe there is a lack of information in the official documentation and would like to report it.</div>
<div><br></div><div>I've been trying to profile our software to see where CPU bottlenecks are. Despite reports of being able to use cProfile to measure CPU time, all of the documentation I found on the internet seems to portray cProfile measuring "wall time" - that is, time elapsed during a function, regardless of actual CPU usage. (Have a look at the UNIX "time" command if you don't know what I'm talking about.)</div>
<div><br></div><div>For example, take the following snippet:</div><div><br></div><div><div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace">import cProfile</font></div>
<div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace">import time</font></div><div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace"><br></font></div>
<div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace">def sleep():</font></div><div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace"> time.sleep(2)</font></div>
<div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace"><br></font></div><div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace">def count():</font></div>
<div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace"> for i in xrange(100000000):</font></div><div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace"> pass</font></div>
<div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace"><br></font></div><div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace">def test():</font></div>
<div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace"> sleep()</font></div><div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace"> count()</font></div>
<div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace"><br></font></div><div style="font-family:arial,sans-serif;font-size:13px"><b><font face="courier new, monospace">profiler = cProfile.Profile()</font></b></div>
<div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace">profiler.run('test()')</font></div><div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace">profiler.print_stats</font></div>
<div style="font-family:arial,sans-serif;font-size:13px"><font face="courier new, monospace"><br></font></div><div style="font-size:13px"><font face="arial, helvetica, sans-serif">Let's take a look at the functions defined here. </font></div>
<div style="font-size:13px"><font face="arial, helvetica, sans-serif">Obviously the sleep function uses no CPU time, however the count function should generate some CPU usage.</font></div><div style="font-size:13px"><font face="arial, helvetica, sans-serif"><br>
</font></div><div style="font-size:13px"><font face="arial, helvetica, sans-serif">The output I get from this script is the following:</font></div><div style="font-size:13px"><font face="arial, helvetica, sans-serif"><br>
</font></div><div><div style="font-size:13px;font-family:arial,sans-serif"><div><font face="courier new, monospace"> ncalls tottime percall cumtime percall filename:lineno(function)</font></div><div><font face="courier new, monospace"> 1 2.045 2.045 2.045 2.045 <stdin>:1(count)</font></div>
<div><font face="courier new, monospace"> 1 0.000 0.000 2.001 2.001 <stdin>:1(sleep)</font></div><div><font face="courier new, monospace"><b> 1 0.000 0.000 4.046 4.046 <stdin>:1(test)</b></font></div>
<div><font face="courier new, monospace"> 1 0.000 0.000 4.046 4.046 <string>:1(<module>)</font></div><div><font face="courier new, monospace"> 1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}</font></div>
<div><font face="courier new, monospace"> 1 2.001 2.001 2.001 2.001 {time.sleep}</font></div></div><div style="font-size:13px;font-family:arial,sans-serif"><font face="courier new, monospace"><br></font></div>
<div style="font-size:13px"><font face="arial, helvetica, sans-serif">And reading the <b>line</b> corresponding to the "test" function does not show the results I expect (I expect approx 2.045).</font></div><div style="font-size:13px">
<font face="arial, helvetica, sans-serif">Once again I have scoured the Internet and found no clues as to how to leverage cProfile to measure only CPU time.</font></div><div style="font-size:13px"><font face="arial, helvetica, sans-serif"><br>
</font></div><div style="font-size:13px"><font face="arial, helvetica, sans-serif">I wrote to Mike Mueller from Python Academy who was able to provide me with some useful information on how to obtain what I was looking for.</font></div>
<div style="font-size:13px"><br></div><div style="font-size:13px"><b>On a UNIX system,</b> writing </div><div style="font-size:13px"><span style="font-family:arial,sans-serif"><font face="courier new, monospace">profiler = cProfile.Profile(time.clock)</font></span><br>
</div><div style="font-size:13px"><font face="arial, helvetica, sans-serif">achieves the desired effet:</font></div><div style="font-size:13px"><span style="font-family:arial,sans-serif"><font face="courier new, monospace"><br>
</font></span></div><div style="font-size:13px"><div style="font-family:arial,sans-serif"><font face="courier new, monospace"> ncalls tottime percall cumtime percall filename:lineno(function)</font></div><div style="font-family:arial,sans-serif">
<font face="courier new, monospace"> 1 1.988 1.988 1.988 1.988 <stdin>:1(count)</font></div><div style="font-family:arial,sans-serif"><font face="courier new, monospace"> 1 0.000 0.000 0.000 0.000 <stdin>:1(</font><span style="font-family:'courier new',monospace">sleep</span><font face="courier new, monospace">)</font></div>
<div style="font-family:arial,sans-serif"><font face="courier new, monospace"><b> 1 0.000 0.000 1.989 1.989 <stdin>:1(test)</b></font></div><div style="font-family:arial,sans-serif"><font face="courier new, monospace"> 1 0.000 0.000 1.989 1.989 <string>:1(<module>)</font></div>
<div style="font-family:arial,sans-serif"><font face="courier new, monospace"> 1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}</font></div><div style="font-family:arial,sans-serif">
<font face="courier new, monospace"> 1 0.000 0.000 0.000 0.000 {time.sleep}</font></div><div style="font-family:arial,sans-serif"><font face="courier new, monospace"><br></font></div><div style="font-family:arial,sans-serif">
<font face="courier new, monospace"><br></font></div><div><font face="arial, helvetica, sans-serif"><b>On Windows</b>, one must first define:</font></div><div></div></div><div><font face="courier new, monospace"><font color="#333333"><span style="line-height:15.59375px">def win_clock():</span></font><table border="0" cellpadding="0" cellspacing="0" style="clear:left;width:2191px;border:0px!important;margin:0px!important;padding:0px!important;background-image:none!important;border-top-left-radius:0px!important;border-top-right-radius:0px!important;border-bottom-right-radius:0px!important;border-bottom-left-radius:0px!important;float:none!important;min-height:auto!important;outline:0px!important;overflow:visible!important;vertical-align:baseline!important;min-height:auto!important">
</table><font color="#333333"><span style="line-height:15.59375px"> return os.times()[0]</span></font><table border="0" cellpadding="0" cellspacing="0" style="clear:left;width:2191px;border:0px!important;margin:0px!important;padding:0px!important;background-image:none!important;border-top-left-radius:0px!important;border-top-right-radius:0px!important;border-bottom-right-radius:0px!important;border-bottom-left-radius:0px!important;float:none!important;min-height:auto!important;outline:0px!important;overflow:visible!important;vertical-align:baseline!important;min-height:auto!important">
</table></font></div><div style="font-size:13px"><font face="arial, helvetica, sans-serif">and write </font></div><div style="font-size:13px"><span style="font-family:'courier new',monospace">profiler = cProfile.Profile(win_clock)</span><font face="arial, helvetica, sans-serif"><br>
</font></div><div style="font-size:13px"><span style="font-family:'courier new',monospace"><br></span></div><div style="font-size:13px"><font face="arial, helvetica, sans-serif">which also achieves the desired effect:</font></div>
<div><div><font face="courier new, monospace">ncalls tottime percall cumtime percall filename:lineno(function)</font></div><div><font face="courier new, monospace"> 1 1.404 1.404 1.404 1.404 <stdin>:1(count)</font></div>
<div><font face="courier new, monospace"> 1 0.000 0.000 0.000 0.000 <stdin>:1(sleep)</font></div><div><font face="courier new, monospace"><b> 1 0.000 0.000 1.404 1.404 <stdin>:1(test)</b></font></div>
<div><font face="courier new, monospace"> 1 0.000 0.000 1.404 1.404 <string>:1(<module>)</font></div><div><font face="courier new, monospace"> 1 0.000 0.000 0.000 0.000 {method 'disable' of '_lsprof.Profiler' objects}</font></div>
<div><font face="courier new, monospace"> 1 0.000 0.000 0.000 0.000 {time.sleep}</font></div></div><div style="font-size:13px"><span style="font-family:'courier new',monospace"><br></span></div><div style="font-size:13px">
<span style="font-family:'courier new',monospace"><br></span></div><div style="font-size:13px"><font face="arial, helvetica, sans-serif">I sincerely believe some of this information belongs in the official Python documentation. Without Mike Mueller I think I would never have found it. I hope my description has been thorough and that you will have sufficient information to complete the existing documentation which has never disappointed me.</font></div>
<div style="font-size:13px"><font face="arial, helvetica, sans-serif"><br></font></div><div style="font-size:13px"><font face="arial, helvetica, sans-serif">Thank you very much for your consideration,</font></div><div style="font-size:13px">
<font face="arial, helvetica, sans-serif">Hoping to hear from you soon,</font></div><div style="font-size:13px"><font face="arial, helvetica, sans-serif"><br></font></div><div style="font-size:13px"><font face="arial, helvetica, sans-serif">Quentin de Metz</font></div>
<div style="font-size:13px"><font face="arial, helvetica, sans-serif">Box, Inc</font></div><div style="font-size:13px"><span style="font-family:'courier new',monospace"><br></span></div><div style="font-size:13px">
<span style="font-family:'courier new',monospace"><br></span></div><ul style="font-size:13px;font-family:arial,sans-serif"></ul></div></div></div>
</blockquote></div><br></div>