[IMP] memory usage logging

bzr revid: al@openerp.com-20121229125912-rlt4g0b6xhajqxwm
This commit is contained in:
Antony Lesuisse 2012-12-29 13:59:12 +01:00
parent 30c12aff36
commit 551e6bc78d
2 changed files with 25 additions and 3 deletions

View File

@ -36,6 +36,11 @@ import time
import types
from pprint import pformat
try:
import psutil
except ImportError:
psutil = None
# TODO modules that import netsvc only for things from loglevels must be changed to use loglevels.
from loglevels import *
import tools
@ -273,6 +278,9 @@ def dispatch_rpc(service_name, method, params):
rpc_response_flag = rpc_response.isEnabledFor(logging.DEBUG)
if rpc_request_flag or rpc_response_flag:
start_time = time.time()
start_rss, start_vms = 0, 0
if psutil:
start_rss, start_vms = psutil.Process(os.getpid()).get_memory_info()
if rpc_request and rpc_response_flag:
log(rpc_request,logging.DEBUG,'%s.%s'%(service_name,method), replace_request_password(params))
@ -282,10 +290,14 @@ def dispatch_rpc(service_name, method, params):
if rpc_request_flag or rpc_response_flag:
end_time = time.time()
end_rss, end_vms = 0, 0
if psutil:
end_rss, end_vms = psutil.Process(os.getpid()).get_memory_info()
logline = '%s.%s time:%.3fs mem: %sk -> %sk (diff: %sk)' % (service_name, method, end_time - start_time, start_vms / 1024, end_vms / 1024, (end_vms - start_vms)/1024)
if rpc_response_flag:
log(rpc_response,logging.DEBUG,'%s.%s time:%.3fs '%(service_name,method,end_time - start_time), result)
log(rpc_response,logging.DEBUG, logline, result)
else:
log(rpc_request,logging.DEBUG,'%s.%s time:%.3fs '%(service_name,method,end_time - start_time), replace_request_password(params), depth=1)
log(rpc_request,logging.DEBUG, logline, replace_request_password(params), depth=1)
return result
except openerp.exceptions.AccessError:

View File

@ -355,12 +355,17 @@ class WorkerCron(Worker):
time.sleep(interval)
def process_work(self):
rpc_request = logging.getLogger(__name__ + '.rpc.request')
rpc_request_flag = rpc_request.isEnabledFor(logging.DEBUG)
_logger.debug("WorkerCron (%s) polling for jobs", self.pid)
if config['db_name']:
db_names = config['db_name'].split(',')
else:
db_names = openerp.netsvc.ExportService._services['db'].exp_list(True)
for db_name in db_names:
if rpc_request_flag:
start_time = time.time()
start_rss, start_vms = psutil.Process(os.getpid()).get_memory_info()
while True:
# acquired = openerp.addons.base.ir.ir_cron.ir_cron._acquire_job(db_name)
# TODO why isnt openerp.addons.base defined ?
@ -371,7 +376,12 @@ class WorkerCron(Worker):
# dont keep cursors in multi database mode
if len(db_names) > 1:
openerp.sql_db.close_db(db_name)
# TODO Each job should be considered as one request instead of each db
if rpc_request_flag:
end_time = time.time()
end_rss, end_vms = psutil.Process(os.getpid()).get_memory_info()
logline = '%s time:%.3fs mem: %sk -> %sk (diff: %sk)' % (db_name, end_time - start_time, start_vms / 1024, end_vms / 1024, (end_vms - start_vms)/1024)
_logger.debug("WorkerCron (%s) %s", self.pid, logline)
# TODO Each job should be considered as one request instead of each run
self.request_count += 1
def start(self):