log and figure out what bits are slow and optimize them.

[sajuptpm]

Hi,

I want to log time taken to complete database requests inside a method/
function using decorator . is it possible ????
I think, i have to inject log code inside the method/fuctions or
modify it.
I wrote a decorator to log taken by a method/function to complete it
execution and its working well.

My requirement : log everything and figure out what bits are slow and
optimize them.

What are your suggestions ??

 

[Arnaud Delobelle]

Hi,

I want to log time taken to complete database requests inside a method/
function using decorator .  is it possible ????
I think, i have to inject log code inside the method/fuctions or
modify it.
I wrote a decorator to log taken by a method/function to complete it
execution and its working well.

My requirement : log everything and figure out what bits are slow and
optimize them.

What are your suggestions ??

Are you familiar with this?

http://docs.python.org/library/profile.html

 

[sajuptpm]

Hi,

Yes i saw profile module,
I think i have to do function call via

cProfile.run('foo()')

I know, we can debug this way.

But, i need a fixed logging system and want to use it in production.
I think, we can't permanently include profile's debugging code
in source code,
will cause any performance issue ??

 

[Mark Lawrence]

Please don't top post.

Yes i saw profile module,
I think, i have to do function call via
cProfile.run('foo()')
I know, we can debug this way.
But, I need a fixed logging system and want to use it in production.
I think, we can't permanently include profile's debugging code in
source code,
will cause any performance issue ??

How about http://docs.python.org/library/logging.html ?

 

[Kev Dwyer]

Hi,

Yes i saw profile module,
I think i have to do function call via

cProfile.run('foo()')

I know, we can debug this way.

But, i need a fixed logging system and want to use it in production.
I think, we can't permanently include profile's debugging code
in source code,
will cause any performance issue ??

*Any* instrumentation code is going to affect performance.

It's a trade-off that you need to analyse and manage in the context of your
application.

 

[John Gordon]

*Any* instrumentation code is going to affect performance.

Funny story about that...

I wanted to profile some code of mine, and a colleague recommended the
'hotshot' module.

It's pretty easy to use: there are functions to start profiling, stop
profiling and print results.

So I added the function calls and ran my code.... and it took a really
long time. I mean a REALLY long time. In fact I eventually had to kill
the process.

I briefly wondered if my coworker was playing a prank on me... then I
realized that I had neglected to call the function to stop profiling!

So when I went to print the results, it was still profiling... endlessly.

(Okay, maybe it wasn't that funny.)

 

[sajuptpm]

I decided to create a decorator like.

import cProfile
def debug_time(method):
def timed(*args, **kw):
prof = cProfile.Profile()
prof.enable(subcalls=False, builtins=False)
result = prof.runcall(method, *args, **kw)
#prof.print_stats()
msg = "\n\n\n\n#######################################"
msg += "\n\nURL : %s" %(tg.request.url)
msg += "\nMethod: %r" %(method.__name__)
print "--ddd--------", type(prof.getstats())
msg += "\n\nStatus : %s" %(prof.print_stats())
msg += "\n\n#######################################"
print msg
LOGGER.info(msg)
return result
return timed

Ref : http://stackoverflow.com/questions/...s-a-method-call-and-logs-the-profiling-result


I want to log it in existing log file in my project,
so i tried prof.print_stats() and prof.getstats(). prof.getstats()
will need extra loop for fetch data.
prof.print_stats() will log library calls also.

Please suggest a better way to log profiler output.