openerp/netsvc.py

   1 #!/usr/bin/env python
   2 # -*- coding: utf-8 -*-
   3 ##############################################################################
   4 #
   5 #    OpenERP, Open Source Management Solution
   6 #    Copyright (C) 2004-2012 OpenERP SA (<http://www.openerp.com>)
   7 #
   8 #    This program is free software: you can redistribute it and/or modify
   9 #    it under the terms of the GNU Affero General Public License as
  10 #    published by the Free Software Foundation, either version 3 of the
  11 #    License, or (at your option) any later version.
  12 #
  13 #    This program is distributed in the hope that it will be useful,
  14 #    but WITHOUT ANY WARRANTY; without even the implied warranty of
  15 #    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  16 #    GNU Affero General Public License for more details.
  17 #
  18 #    You should have received a copy of the GNU Affero General Public License
  19 #    along with this program.  If not, see <http://www.gnu.org/licenses/>.
  20 #
  21 ##############################################################################
  22
  23 import errno
  24 import logging
  25 import logging.handlers
  26 import os
  27 import platform
  28 import release
  29 import socket
  30 import sys
  31 import threading
  32 import time
  33 import types
  34 from pprint import pformat
  35
  36 # TODO modules that import netsvc only for things from loglevels must be changed to use loglevels.
  37 from loglevels import *
  38 import tools
  39 import openerp
  40
  41 _logger = logging.getLogger(__name__)
  42
  43
  44
  45 #.apidoc title: Common Services: netsvc
  46 #.apidoc module-mods: member-order: bysource
  47
  48 def abort_response(dummy_1, description, dummy_2, details):
  49     # TODO Replace except_{osv,orm} with these directly.
  50     raise openerp.osv.osv.except_osv(description, details)
  51
  52 class Service(object):
  53     """ Base class for Local services
  54     Functionality here is trusted, no authentication.
  55     Workflow engine and reports subclass this.
  56     """
  57     _services = {}
  58     def __init__(self, name):
  59         Service._services[name] = self
  60         self.__name = name
  61
  62     @classmethod
  63     def exists(cls, name):
  64         return name in cls._services
  65
  66     @classmethod
  67     def remove(cls, name):
  68         if cls.exists(name):
  69             cls._services.pop(name)
  70
  71 def LocalService(name):
  72     # Special case for addons support, will be removed in a few days when addons
  73     # are updated to directly use openerp.osv.osv.service.
  74     if name == 'object_proxy':
  75         return openerp.osv.osv.service
  76
  77     return Service._services[name]
  78
  79 class ExportService(object):
  80     """ Proxy for exported services.
  81
  82     Note that this class has no direct proxy, capable of calling
  83     eservice.method(). Rather, the proxy should call
  84     dispatch(method, params)
  85     """
  86
  87     _services = {}
  88
  89     def __init__(self, name):
  90         ExportService._services[name] = self
  91         self.__name = name
  92         _logger.debug("Registered an exported service: %s" % name)
  93
  94     @classmethod
  95     def getService(cls,name):
  96         return cls._services[name]
  97
  98     # Dispatch a RPC call w.r.t. the method name. The dispatching
  99     # w.r.t. the service (this class) is done by OpenERPDispatcher.
 100     def dispatch(self, method, params):
 101         raise Exception("stub dispatch at %s" % self.__name)
 102
 103 BLACK, RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE, _NOTHING, DEFAULT = range(10)
 104 #The background is set with 40 plus the number of the color, and the foreground with 30
 105 #These are the sequences need to get colored ouput
 106 RESET_SEQ = "\033[0m"
 107 COLOR_SEQ = "\033[1;%dm"
 108 BOLD_SEQ = "\033[1m"
 109 COLOR_PATTERN = "%s%s%%s%s" % (COLOR_SEQ, COLOR_SEQ, RESET_SEQ)
 110 LEVEL_COLOR_MAPPING = {
 111     logging.DEBUG: (BLUE, DEFAULT),
 112     logging.INFO: (GREEN, DEFAULT),
 113     logging.TEST: (WHITE, BLUE),
 114     logging.WARNING: (YELLOW, DEFAULT),
 115     logging.ERROR: (RED, DEFAULT),
 116     logging.CRITICAL: (WHITE, RED),
 117 }
 118
 119 class DBFormatter(logging.Formatter):
 120     def format(self, record):
 121         record.pid = os.getpid()
 122         record.dbname = getattr(threading.currentThread(), 'dbname', '?')
 123         return logging.Formatter.format(self, record)
 124
 125 class ColoredFormatter(DBFormatter):
 126     def format(self, record):
 127         fg_color, bg_color = LEVEL_COLOR_MAPPING[record.levelno]
 128         record.levelname = COLOR_PATTERN % (30 + fg_color, 40 + bg_color, record.levelname)
 129         return DBFormatter.format(self, record)
 130
 131 def init_logger():
 132     from tools.translate import resetlocale
 133     resetlocale()
 134
 135     # create a format for log messages and dates
 136     format = '%(asctime)s %(pid)s %(levelname)s %(dbname)s %(name)s: %(message)s'
 137
 138     if tools.config['syslog']:
 139         # SysLog Handler
 140         if os.name == 'nt':
 141             handler = logging.handlers.NTEventLogHandler("%s %s" % (release.description, release.version))
 142         else:
 143             handler = logging.handlers.SysLogHandler('/dev/log')
 144         format = '%s %s' % (release.description, release.version) \
 145                 + ':%(dbname)s:%(levelname)s:%(name)s:%(message)s'
 146
 147     elif tools.config['logfile']:
 148         # LogFile Handler
 149         logf = tools.config['logfile']
 150         try:
 151             dirname = os.path.dirname(logf)
 152             if dirname and not os.path.isdir(dirname):
 153                 os.makedirs(dirname)
 154             if tools.config['logrotate'] is not False:
 155                 handler = logging.handlers.TimedRotatingFileHandler(logf,'D',1,30)
 156             elif os.name == 'posix':
 157                 handler = logging.handlers.WatchedFileHandler(logf)
 158             else:
 159                 handler = logging.handlers.FileHandler(logf)
 160         except Exception:
 161             sys.stderr.write("ERROR: couldn't create the logfile directory. Logging to the standard output.\n")
 162             handler = logging.StreamHandler(sys.stdout)
 163     else:
 164         # Normal Handler on standard output
 165         handler = logging.StreamHandler(sys.stdout)
 166
 167     if isinstance(handler, logging.StreamHandler) and os.isatty(handler.stream.fileno()):
 168         formatter = ColoredFormatter(format)
 169     else:
 170         formatter = DBFormatter(format)
 171     handler.setFormatter(formatter)
 172
 173     # Configure handlers
 174     default_config = [
 175         'openerp.netsvc.rpc.request:INFO',
 176         'openerp.netsvc.rpc.response:INFO',
 177         'openerp.addons.web.http:INFO',
 178         'openerp.sql_db:INFO',
 179         ':INFO',
 180     ]
 181
 182     if tools.config['log_level'] == 'info':
 183         pseudo_config = []
 184     elif tools.config['log_level'] == 'debug_rpc':
 185         pseudo_config = ['openerp:DEBUG','openerp.netsvc.rpc.request:DEBUG']
 186     elif tools.config['log_level'] == 'debug_rpc_answer':
 187         pseudo_config = ['openerp:DEBUG','openerp.netsvc.rpc.request:DEBUG', 'openerp.netsvc.rpc.response:DEBUG']
 188     elif tools.config['log_level'] == 'debug':
 189         pseudo_config = ['openerp:DEBUG']
 190     elif tools.config['log_level'] == 'test':
 191         pseudo_config = ['openerp:TEST']
 192     elif tools.config['log_level'] == 'warn':
 193         pseudo_config = ['openerp:WARNING']
 194     elif tools.config['log_level'] == 'error':
 195         pseudo_config = ['openerp:ERROR']
 196     elif tools.config['log_level'] == 'critical':
 197         pseudo_config = ['openerp:CRITICAL']
 198     elif tools.config['log_level'] == 'debug_sql':
 199         pseudo_config = ['openerp.sql_db:DEBUG']
 200     else:
 201         pseudo_config = []
 202
 203     logconfig = tools.config['log_handler']
 204
 205     for logconfig_item in default_config + pseudo_config + logconfig:
 206         loggername, level = logconfig_item.split(':')
 207         level = getattr(logging, level, logging.INFO)
 208         logger = logging.getLogger(loggername)
 209         logger.handlers = []
 210         logger.setLevel(level)
 211         logger.addHandler(handler)
 212         if loggername != '':
 213             logger.propagate = False
 214
 215     for logconfig_item in default_config + pseudo_config + logconfig:
 216         _logger.debug('logger level set: "%s"', logconfig_item)
 217
 218 # A alternative logging scheme for automated runs of the
 219 # server intended to test it.
 220 def init_alternative_logger():
 221     class H(logging.Handler):
 222         def emit(self, record):
 223             if record.levelno > 20:
 224                 print record.levelno, record.pathname, record.msg
 225     handler = H()
 226     # Add the handler to the 'openerp' logger.
 227     logger = logging.getLogger('openerp')
 228     logger.addHandler(handler)
 229     logger.setLevel(logging.ERROR)
 230
 231 def replace_request_password(args):
 232     # password is always 3rd argument in a request, we replace it in RPC logs
 233     # so it's easier to forward logs for diagnostics/debugging purposes...
 234     if len(args) > 2:
 235         args = list(args)
 236         args[2] = '*'
 237     return tuple(args)
 238
 239 def log(logger, level, prefix, msg, depth=None):
 240     indent=''
 241     indent_after=' '*len(prefix)
 242     for line in (prefix+pformat(msg, depth=depth)).split('\n'):
 243         logger.log(level, indent+line)
 244         indent=indent_after
 245
 246 def dispatch_rpc(service_name, method, params):
 247     """ Handle a RPC call.
 248
 249     This is pure Python code, the actual marshalling (from/to XML-RPC or
 250     NET-RPC) is done in a upper layer.
 251     """
 252     try:
 253         rpc_request = logging.getLogger(__name__ + '.rpc.request')
 254         rpc_response = logging.getLogger(__name__ + '.rpc.response')
 255         rpc_request_flag = rpc_request.isEnabledFor(logging.DEBUG)
 256         rpc_response_flag = rpc_response.isEnabledFor(logging.DEBUG)
 257         if rpc_request_flag or rpc_response_flag:
 258             start_time = time.time()
 259             if rpc_request and rpc_response_flag:
 260                 log(rpc_request,logging.DEBUG,'%s.%s'%(service_name,method), replace_request_password(params))
 261
 262         threading.current_thread().uid = None
 263         threading.current_thread().dbname = None
 264         result = ExportService.getService(service_name).dispatch(method, params)
 265
 266         if rpc_request_flag or rpc_response_flag:
 267             end_time = time.time()
 268             if rpc_response_flag:
 269                 log(rpc_response,logging.DEBUG,'%s.%s time:%.3fs '%(service_name,method,end_time - start_time), result)
 270             else:
 271                 log(rpc_request,logging.DEBUG,'%s.%s time:%.3fs '%(service_name,method,end_time - start_time), replace_request_password(params), depth=1)
 272
 273         return result
 274     except openerp.exceptions.AccessError:
 275         raise
 276     except openerp.exceptions.AccessDenied:
 277         raise
 278     except openerp.exceptions.Warning:
 279         raise
 280     except openerp.exceptions.DeferredException, e:
 281         _logger.exception(tools.exception_to_unicode(e))
 282         post_mortem(e.traceback)
 283         raise
 284     except Exception, e:
 285         _logger.exception(tools.exception_to_unicode(e))
 286         post_mortem(sys.exc_info())
 287         raise
 288
 289 def post_mortem(info):
 290     if tools.config['debug_mode'] and isinstance(info[2], types.TracebackType):
 291         import pdb
 292         pdb.post_mortem(info[2])
 293
 294 # vim:expandtab:smartindent:tabstop=4:softtabstop=4:shiftwidth=4: