From fcf84b265c8aacae35942be0f2f7dba8e85ebb53 Mon Sep 17 00:00:00 2001 From: Antony Lesuisse Date: Thu, 2 Feb 2012 21:30:08 +0100 Subject: [PATCH] define a useful default logging config, display this config in DEBUG, rename and claen rpc debug to verbose or terse bzr revid: al@openerp.com-20120202203008-mkafq1oak33z6p6p --- openerp/netsvc.py | 27 ++++++++++++++++----------- openerp/tools/config.py | 20 ++++++++++++++++---- 2 files changed, 32 insertions(+), 15 deletions(-) diff --git a/openerp/netsvc.py b/openerp/netsvc.py index c2078c43952..8baac829ff0 100644 --- a/openerp/netsvc.py +++ b/openerp/netsvc.py @@ -200,6 +200,9 @@ def init_logger(): if loggername != '': logger.propagate = False + for logconfig_item in logconfig: + _logger.debug('logger level set: "%s"'%logconfig_item) + # A alternative logging scheme for automated runs of the # server intended to test it. @@ -315,23 +318,25 @@ def dispatch_rpc(service_name, method, params): NET-RPC) is done in a upper layer. """ try: - rpc_request = logging.getLogger(__name__ + '.rpc.request') - rpc_response = logging.getLogger(__name__ + '.rpc.response') - rpc_request_flag = rpc_request.isEnabledFor(logging.DEBUG) - rpc_response_flag = rpc_response.isEnabledFor(logging.DEBUG) - if rpc_request_flag or rpc_response_flag: + rpc_terse = logging.getLogger(__name__ + '.rpc.terse') + rpc_verbose = logging.getLogger(__name__ + '.rpc.verbose') + rpc_terse_flag = rpc_terse.isEnabledFor(logging.DEBUG) + rpc_verbose_flag = rpc_verbose.isEnabledFor(logging.DEBUG) + if rpc_terse_flag or rpc_verbose_flag: start_time = time.time() - if rpc_request and rpc_response_flag: - log(rpc_request,logging.DEBUG,'%s.%s'%(service_name,method), replace_request_password(params)) + if rpc_terse_flag: + log(rpc_terse,logging.DEBUG,'%s.%s:<-- '%(service_name,method), replace_request_password(params), depth=1) + else: + log(rpc_verbose,logging.DEBUG,'%s.%s:<-- '%(service_name,method), replace_request_password(params)) result = ExportService.getService(service_name).dispatch(method, params) - if rpc_request_flag or rpc_response_flag: + if rpc_terse_flag or rpc_verbose_flag: end_time = time.time() - if rpc_response_flag: - log(rpc_response,logging.DEBUG,'%s.%s time:%.3fs '%(service_name,method,end_time - start_time), result) + if rpc_terse_flag: + log(rpc_terse,logging.DEBUG,'%s.%s:--> (time: %.3fs) '%(service_name,method,end_time - start_time), result, depth=1) 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_verbose,logging.DEBUG,'%s.%s:--> (time: %.3fs) '%(service_name,method,end_time - start_time), result) return result except openerp.exceptions.AccessError: diff --git a/openerp/tools/config.py b/openerp/tools/config.py index 9d6ab3e0447..3b05a0d6eb3 100644 --- a/openerp/tools/config.py +++ b/openerp/tools/config.py @@ -175,14 +175,26 @@ class configmanager(object): parser.add_option_group(group) # Logging Group + log_handler_default = [ + 'openerp.netsvc.rpc.terse:INFO', + 'openerp.netsvc.rpc.verbose:INFO', + 'openerp.sql_db:INFO', + 'openerp.addons.web.common.http:INFO', + 'openerp.addons.web.common.openerplib:INFO', + ':INFO', + ] + group = optparse.OptionGroup(parser, "Logging Configuration") group.add_option("--logfile", dest="logfile", help="file where the server log will be stored") group.add_option("--no-logrotate", dest="logrotate", action="store_false", my_default=True, help="do not rotate the logfile") group.add_option("--syslog", action="store_true", dest="syslog", my_default=False, help="Send the log to the syslog server") - group.add_option('--log-handler', action="append", default=[':INFO'], my_default=[':INFO'], metavar="PREFIX:LEVEL", help='setup a handler at LEVEL for a given PREFIX. An empty PREFIX indicates the root logger. This option can be repeated. Example: "openerp.orm:DEBUG" or "werkzeug:CRITICAL" (default: ":INFO")') - group.add_option('--log-request', action="append_const", dest="log_handler", const="openerp.netsvc.rpc.request:DEBUG", help='shortcut for --log-handler=openerp.netsvc.rpc.request:DEBUG') - group.add_option('--log-response', action="append_const", dest="log_handler", const="openerp.netsvc.rpc.response:DEBUG", help='shortcut for --log-handler=openerp.netsvc.rpc.response:DEBUG') - group.add_option('--log-web', action="append_const", dest="log_handler", const="openerp.addons.web.common.http:DEBUG", help='shortcut for --log-handler=openerp.addons.web.common.http:DEBUG') + group.add_option('--log-handler', action="append", default=log_handler_default, my_default=log_handler_default, metavar="PREFIX:LEVEL", + help='setup a handler at LEVEL for a given PREFIX. An empty PREFIX indicates the root logger. \ + This option can be repeated. Example: "openerp.orm:DEBUG", "werkzeug:CRITICAL" or ":DEBUG". \ + By default: all rpc specific loggers, sql logger and the root logger are set to INFO') + group.add_option('--log-rpc-terse', action="append_const", dest="log_handler", const="openerp.netsvc.rpc.terse:DEBUG", help='shortcut for --log-handler=openerp.netsvc.rpc.terse:DEBUG') + group.add_option('--log-rpc-verbose', action="append_const", dest="log_handler", const="openerp.netsvc.rpc.verbose:DEBUG", help='shortcut for --log-handler=openerp.netsvc.rpc.verbose:DEBUG') + group.add_option('--log-rpc-web', action="append_const", dest="log_handler", const="openerp.addons.web.common.http:DEBUG", help='shortcut for --log-handler=openerp.addons.web.common.http:DEBUG') group.add_option('--log-sql', action="append_const", dest="log_handler", const="openerp.sql_db:DEBUG", help='shortcut for --log-handler=openerp.sql_db:DEBUG') parser.add_option_group(group)