From ca91b75f21c074ff7d977c0009f6598056eb13a4 Mon Sep 17 00:00:00 2001
From: Vo Minh Thu <vmt@openerp.com>
Date: Mon, 20 Jun 2011 17:26:15 +0200
Subject: [PATCH] [IMP] netsvc+ir_cron: display the execution time in
 debug_rpc.

bzr revid: vmt@openerp.com-20110620152615-kyl8s7z6we2or1yw
---
 openerp/addons/base/ir/ir_cron.py | 11 ++++++++++-
 openerp/netsvc.py                 |  9 ++++++++-
 2 files changed, 18 insertions(+), 2 deletions(-)

diff --git a/openerp/addons/base/ir/ir_cron.py b/openerp/addons/base/ir/ir_cron.py
index 6bde5c4b468..d9abc0701b2 100644
--- a/openerp/addons/base/ir/ir_cron.py
+++ b/openerp/addons/base/ir/ir_cron.py
@@ -99,10 +99,19 @@ class ir_cron(osv.osv, netsvc.Agent):
             try:
                 netsvc.log('cron', (cr.dbname,uid,'*',model,func)+tuple(args), channel=logging.DEBUG,
                             depth=(None if self._logger.isEnabledFor(logging.DEBUG_RPC_ANSWER) else 1), fn='object.execute')
-                f(cr, uid, *args)
+                logger = logging.getLogger('execution time')
+                if logger.isEnabledFor(logging.DEBUG_RPC):
+                    start_time = time.time()
+                    f(cr, uid, *args)
+                    end_time = time.time()
+                    logger.log(logging.DEBUG_RPC, '%.3fs (%s, %s)' % (end_time - start_time, model, func))
+                else:
+                    f(cr, uid, *args)
             except Exception, e:
                 self._handle_callback_exception(cr, uid, model, func, args, job_id, e)
 
+    def yeah(self, cr, uid):
+        print "YEAH"
 
     def _poolJobs(self, db_name, check=False):
         try:
diff --git a/openerp/netsvc.py b/openerp/netsvc.py
index 42ccab414c7..5e12b5c450d 100644
--- a/openerp/netsvc.py
+++ b/openerp/netsvc.py
@@ -434,7 +434,14 @@ class OpenERPDispatcher:
             logger = logging.getLogger('result')
             self.log('service', tuple(replace_request_password(params)), depth=(None if logger.isEnabledFor(logging.DEBUG_RPC_ANSWER) else 1), fn='%s.%s'%(service_name,method))
             auth = getattr(self, 'auth_provider', None)
-            result = ExportService.getService(service_name).dispatch(method, auth, params)
+            if logger.isEnabledFor(logging.DEBUG_RPC):
+                start_time = time.time()
+                result = ExportService.getService(service_name).dispatch(method, auth, params)
+                end_time = time.time()
+                logger = logging.getLogger('execution time')
+                self.log('execution time', tuple(replace_request_password(params)), depth=1, fn='%.3fs '%(end_time - start_time))
+            else:
+                result = ExportService.getService(service_name).dispatch(method, auth, params)
             self.log('result', result, channel=logging.DEBUG_RPC_ANSWER)
             return result
         except Exception, e: