Velocity Reviews - Computer Hardware Reviews

Velocity Reviews > Newsgroups > Programming > Python > profiling differences using an extra function call

Reply
Thread Tools

profiling differences using an extra function call

 
 
marc magrans de abril
Guest
Posts: n/a
 
      11-23-2009
Hi,

I was a trying to profile a small script and after shrinking the code
to the minimum I got a interesting profile difference.
Given two test functions test1 and test2, that only differs from an
extra level of indirection (i.e. find_substr), I wonder why I got a
timming difference >50%? What is the recommended way to factorize the
code? Should I write a big method containing everything?
#!/usr/bin/python
def find_substr(l):
return l[15:20]
def test1(t):
for i in xrange(1000000):
s = find_substr(t)
def test2(t):
for i in xrange(1000000):
sub = t[15:20]
import cProfile
t = "This a long string containing several things apart from the end"
cProfile.run("test1(t)")
cProfile.run("test2(t)")

----Profiles test1
Profiles results:
1000003 function calls in 0.666 CPU seconds

Ordered by: standard name

ncalls tottime percall cumtime percall filename:lineno
(function)
1 0.000 0.000 0.666 0.666 <string>:1(<module>)
1000000 0.260 0.000 0.260 0.000 test.py:3(find_substr)
1 0.406 0.406 0.666 0.666 test.py:7(test1)
1 0.000 0.000 0.000 0.000 {method 'disable' of
'_lsprof.Profiler' objects}

----Profile test2:
3 function calls in 0.248 CPU seconds

Ordered by: standard name

ncalls tottime percall cumtime percall filename:lineno
(function)
1 0.000 0.000 0.248 0.248 <string>:1(<module>)
1 0.248 0.248 0.248 0.248 test.py:12(test2)
1 0.000 0.000 0.000 0.000 {method 'disable' of
'_lsprof.Profiler' objects}

Thank you very much for the advice!
marc
 
Reply With Quote
 
 
 
 
Lie Ryan
Guest
Posts: n/a
 
      11-24-2009
marc magrans de abril wrote:
> Hi,
>
> I was a trying to profile a small script and after shrinking the code
> to the minimum I got a interesting profile difference.
> Given two test functions test1 and test2, that only differs from an
> extra level of indirection (i.e. find_substr),


That's because there is a function call overhead.

> I wonder why I got a
> timming difference >50%?


A very simple function body will (in terms of percentage) have larger
function overhead. With a slightly more complex function body, the body
will takes much more time than the function call overhead.

> What is the recommended way to factorize the
> code? Should I write a big method containing everything?


Look in the absolute numbers: 0.666 CPU seconds vs. 0.248 CPU seconds
over 1000000 loops means if you put everything into one big method
you'll only save 418 nanoseconds per loop. Even over 1000000 loops; you
only save 0.418 seconds. Is it worth optimizing?

> ----Profiles test1
> Profiles results:
> 1000003 function calls in 0.666 CPU seconds
>
> ----Profile test2:
> 3 function calls in 0.248 CPU seconds


I got a more striking difference: 5.291 CPU seconds vs 0.589 CPU
seconds. But knowing how the profiler works, this is to be expected.
Function call overhead become much (and I mean much) heavier with
profiler ON. I get a more sane result with timing manually:

import time
start = time.time()
test1(t)
print time.time() - start

start = time.time()
test2(t)
print time.time() - start

It's 1.186 vs 0.608, which is blink of an eye vs. blink of an eye.
 
Reply With Quote
 
 
 
Reply

Thread Tools

Posting Rules
You may not post new threads
You may not post replies
You may not post attachments
You may not edit your posts

BB code is On
Smilies are On
[IMG] code is On
HTML code is Off
Trackbacks are On
Pingbacks are On
Refbacks are Off


Similar Threads
Thread Thread Starter Forum Replies Last Post
Does return-by-value mean extra copies and extra overhead? mathieu C++ 3 09-04-2009 04:25 PM
DEVELOP THE WINNING EDGE, SMALL DIFFERENCES IN YOUR PERFORMANCE CANLEAD TO LARGE DIFFERENCES IN YOUR RESULTS Home_Job_opportunity C Programming 0 01-14-2009 03:51 PM
DEVELOP THE WINNING EDGE, SMALL DIFFERENCES IN YOUR PERFORMANCE CANLEAD TO LARGE DIFFERENCES IN YOUR RESULTS Home_Job_opportunity C Programming 0 01-08-2009 04:31 PM
profiling C code an generating call graphs horacius.rex@gmail.com C Programming 7 05-29-2007 10:49 AM
write a function such that when ever i call this function in some other function .it should give me tha data type and value of calling function parameter komal C++ 6 01-25-2005 11:13 AM



Advertisments