Change in vdsm[master]: Add profiling decorator utility.

Antoni Segura Puimedon has uploaded a new change for review.

Change subject: Add profiling decorator utility.
......................................................................

Add profiling decorator utility.

This decorator is meant to be used while testing performance. It
leaves a temp file with the profiling info and logs the name
of that file.

The profiling information is binary so that it can be analyzed
easily from a python session like so:

import pstats
stats = pstats.Stats('/tmp/func_namexxxx')
stats.sort_stats('cumulative').print_stats()

which gives an output like:

Thu Jun 27 10:35:22 2013    /tmp/addNetworkMep9tp

24586 function calls (24392 primitive calls) in 0.774 CPU seconds

Ordered by: cumulative time

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.774    0.774 /usr/share/vdsm/configNetwork.py:151(addNetwork)
        1    0.000    0.000    0.688    0.688 /usr/share/vdsm/netmodels.py:128(configure)
        1    0.000    0.000    0.688    0.688 /usr/share/vdsm/netconf/ifcfg.py:68(configureBridge)
        6    0.000    0.000    0.586    0.098 /usr/lib64/python2.6/site-packages/vdsm/utils.py:447(execCmd)
        6    0.000    0.000    0.575    0.096 /usr/lib64/python2.6/site-packages/vdsm/utils.py:434(communicate)
       24    0.000    0.000    0.573    0.024 /usr/lib64/python2.6/io.py:752(close)
       36    0.000    0.000    0.573    0.016 /usr/lib64/python2.6/site-packages/vdsm/utils.py:254(close)
        7    0.000    0.000    0.573    0.082 /usr/lib64/python2.6/site-packages/vdsm/utils.py:358(_processStreams)
        7    0.000    0.000    0.573    0.082 /usr/lib64/python2.6/site-packages/vdsm/utils.py:214(NoIntrPoll)
        7    0.573    0.082    0.573    0.082 {method 'poll' of 'select.epoll' objects}
        1    0.000    0.000    0.497    0.497 /usr/share/vdsm/netmodels.py:91(configure)
        1    0.000    0.000    0.497    0.497 /usr/share/vdsm/netconf/ifcfg.py:79(configureVlan)
        1    0.000    0.000    0.470    0.470 /usr/share/vdsm/netmodels.py:161(configure)
        1    0.000    0.000    0.470    0.470 /usr/share/vdsm/netconf/ifcfg.py:87(configureBond)

Change-Id: I540d0200f488a6de6b5c43e7439e8eb352ea456b
Signed-off-by: Antoni S. Puimedon 
---
M lib/vdsm/utils.py
1 file changed, 20 insertions(+), 2 deletions(-)

git pull ssh://gerrit.ovirt.org:29418/vdsm refs/changes/75/16175/1

diff --git a/lib/vdsm/utils.py b/lib/vdsm/utils.py
index 4847a68..1ce2b91 100644
--- a/lib/vdsm/utils.py
+++ b/lib/vdsm/utils.py
@@ -29,21 +29,23 @@
 from collections import namedtuple
 from SimpleXMLRPCServer import SimpleXMLRPCServer
 from StringIO import StringIO
+from tempfile import NamedTemporaryFile
 from weakref import proxy
-import SocketServer
+import cProfile
 import errno
 import fcntl
 import functools
 import glob
 import io
 import logging
-import sys
 import os
 import pwd
 import select
 import signal
+import SocketServer
 import stat
 import subprocess
+import sys
 import threading
 import time

@@ -898,3 +900,19 @@
     logging.error("Panic: %s", msg, exc_info=True)
     os.killpg(0, 9)
     sys.exit(-3)
+
+
+def profile(func):
+    func_name = func.__name__
+
+    def profiled_execution(*args, **kwargs):
+        logging.info('profiling method %s' % func_name)
+        profiler = cProfile.Profile()
+        ret = profiler.runcall(func, *args, **kwargs)
+        prof_file = NamedTemporaryFile(mode='w', prefix=func_name,
+                                       delete=False)
+        profiler.dump_stats(prof_file.name)
+        logging.info('profiled method %s and dumped results to %s' %
+                     (func_name, prof_file.name))
+        return ret
+    return profiled_execution

Antoni Segura Puimedon has posted comments on this change.

Change subject: Add profiling decorator utility.
......................................................................

Patch Set 1: Verified

Tested by verifiend configNetwork:addNetwork as seen in the commit-msg.

Giuseppe Vallarelli has posted comments on this change.

Change subject: Add profiling decorator utility.
......................................................................

Patch Set 1: I would prefer that you didn't submit this

(1 inline comment)

Only a minor fix is needed.

....................................................
File lib/vdsm/utils.py
Line 902:     sys.exit(-3)
Line 903: 
Line 904: 
Line 905: def profile(func):
Line 906:     func_name = func.__name__
You should use http://docs.python.org/2/library/functools.html#functools.wraps.
Line 907: 
Line 908:     def profiled_execution(*args, **kwargs):
Line 909:         logging.info('profiling method %s' % func_name)
Line 910:         profiler = cProfile.Profile()

[Jenkins CI RO]

oVirt Jenkins CI Server has posted comments on this change.

Change subject: Add profiling decorator utility.
......................................................................

Patch Set 1:

Build Successful

http://jenkins.ovirt.org/job/vdsm_pep8_gerrit/2976/ : SUCCESS

http://jenkins.ovirt.org/job/vdsm_unit_tests_gerrit/3054/ : SUCCESS

http://jenkins.ovirt.org/job/vdsm_unit_tests_gerrit_el/2165/ : SUCCESS

[Jenkins CI RO]

oVirt Jenkins CI Server has posted comments on this change.

Change subject: Add profiling decorator utility.
......................................................................

Patch Set 2:

Build Successful

http://jenkins.ovirt.org/job/vdsm_pep8_gerrit/2996/ : SUCCESS

http://jenkins.ovirt.org/job/vdsm_unit_tests_gerrit/3074/ : SUCCESS

http://jenkins.ovirt.org/job/vdsm_unit_tests_gerrit_el/2185/ : SUCCESS

Antoni Segura Puimedon has posted comments on this change.

Change subject: Add profiling decorator utility.
......................................................................

Patch Set 2: Verified

Thanks for the improvement idea Giuseppe!

Giuseppe Vallarelli has posted comments on this change.

Change subject: Add profiling decorator utility.
......................................................................

Patch Set 2: I would prefer that you didn't submit this

(1 inline comment)

Toni have a look at the link.

....................................................
File lib/vdsm/utils.py
Line 903:     sys.exit(-3)
Line 904: 
Line 905: 
Line 906: def profile(func):
Line 907:     func_name = func.__name__
Sorry I've been a little cryptic in the previous comment, you don't need to create this func_name variable, @wraps takes care of that meaning that func.__name__ is the name of the original one (not the name of decorator) have a look to the example (http://docs.python.org/2/library/functools.html#functools.wraps).
Line 908: 
Line 909:     @wraps(func)
Line 910:     def profiled_execution(*args, **kwargs):
Line 911:         logging.info('profiling method %s' % func_name)

[Jenkins CI RO]

oVirt Jenkins CI Server has posted comments on this change.

Change subject: Add profiling decorator utility.
......................................................................

Patch Set 3:

Build Successful

http://jenkins.ovirt.org/job/vdsm_unit_tests_gerrit/3286/ : SUCCESS

http://jenkins.ovirt.org/job/vdsm_pep8_gerrit/3206/ : SUCCESS

http://jenkins.ovirt.org/job/vdsm_unit_tests_gerrit_el/2396/ : SUCCESS

Giuseppe Vallarelli has posted comments on this change.

Change subject: Add profiling decorator utility.
......................................................................

Patch Set 3: Looks good to me, but someone else must approve

Antoni Segura Puimedon has posted comments on this change.

Change subject: Add profiling decorator utility.
......................................................................

Patch Set 4:

Rebased

[Jenkins CI RO]

oVirt Jenkins CI Server has posted comments on this change.

Change subject: Add profiling decorator utility.
......................................................................

Patch Set 4:

Build Successful

http://jenkins.ovirt.org/job/vdsm_pep8_gerrit/4753/ : SUCCESS

http://jenkins.ovirt.org/job/vdsm_unit_tests_gerrit/4829/ : SUCCESS

http://jenkins.ovirt.org/job/vdsm_unit_tests_gerrit_el/3944/ : SUCCESS

Antoni Segura Puimedon has abandoned this change.

Change subject: Add profiling decorator utility.
......................................................................

Abandoned

It's not going in.