[IMP] openerp.wsgi: _logger with fully qualified module name.
bzr revid: vmt@openerp.com-20120124111438-730miqdcm3eljgds
This commit is contained in:
parent
e972052a93
commit
eadcdd1fd6
|
@ -46,6 +46,8 @@ import warnings
|
||||||
|
|
||||||
psycopg2.extensions.register_type(psycopg2.extensions.UNICODE)
|
psycopg2.extensions.register_type(psycopg2.extensions.UNICODE)
|
||||||
|
|
||||||
|
_logger = logging.getLogger(__name__)
|
||||||
|
|
||||||
types_mapping = {
|
types_mapping = {
|
||||||
'date': (1082,),
|
'date': (1082,),
|
||||||
'time': (1083,),
|
'time': (1083,),
|
||||||
|
@ -139,7 +141,6 @@ class Cursor(object):
|
||||||
|
|
||||||
"""
|
"""
|
||||||
IN_MAX = 1000 # decent limit on size of IN queries - guideline = Oracle limit
|
IN_MAX = 1000 # decent limit on size of IN queries - guideline = Oracle limit
|
||||||
__logger = None
|
|
||||||
|
|
||||||
def check(f):
|
def check(f):
|
||||||
@wraps(f)
|
@wraps(f)
|
||||||
|
@ -153,14 +154,12 @@ class Cursor(object):
|
||||||
return wrapper
|
return wrapper
|
||||||
|
|
||||||
def __init__(self, pool, dbname, serialized=True):
|
def __init__(self, pool, dbname, serialized=True):
|
||||||
if self.__class__.__logger is None:
|
|
||||||
self.__class__.__logger = logging.getLogger('db.cursor')
|
|
||||||
self.sql_from_log = {}
|
self.sql_from_log = {}
|
||||||
self.sql_into_log = {}
|
self.sql_into_log = {}
|
||||||
|
|
||||||
# default log level determined at cursor creation, could be
|
# default log level determined at cursor creation, could be
|
||||||
# overridden later for debugging purposes
|
# overridden later for debugging purposes
|
||||||
self.sql_log = self.__logger.isEnabledFor(logging.DEBUG_SQL)
|
self.sql_log = _logger.isEnabledFor(logging.DEBUG_SQL)
|
||||||
|
|
||||||
self.sql_log_count = 0
|
self.sql_log_count = 0
|
||||||
self.__closed = True # avoid the call of close() (by __del__) if an exception
|
self.__closed = True # avoid the call of close() (by __del__) if an exception
|
||||||
|
@ -196,14 +195,14 @@ class Cursor(object):
|
||||||
msg += "Cursor was created at %s:%s" % self.__caller
|
msg += "Cursor was created at %s:%s" % self.__caller
|
||||||
else:
|
else:
|
||||||
msg += "Please enable sql debugging to trace the caller."
|
msg += "Please enable sql debugging to trace the caller."
|
||||||
self.__logger.warn(msg)
|
_logger.warn(msg)
|
||||||
self._close(True)
|
self._close(True)
|
||||||
|
|
||||||
@check
|
@check
|
||||||
def execute(self, query, params=None, log_exceptions=None):
|
def execute(self, query, params=None, log_exceptions=None):
|
||||||
if '%d' in query or '%f' in query:
|
if '%d' in query or '%f' in query:
|
||||||
self.__logger.warn(query)
|
_logger.warn(query)
|
||||||
self.__logger.warn("SQL queries cannot contain %d or %f anymore. "
|
_logger.warn("SQL queries cannot contain %d or %f anymore. "
|
||||||
"Use only %s")
|
"Use only %s")
|
||||||
|
|
||||||
if self.sql_log:
|
if self.sql_log:
|
||||||
|
@ -214,18 +213,18 @@ class Cursor(object):
|
||||||
res = self._obj.execute(query, params)
|
res = self._obj.execute(query, params)
|
||||||
except psycopg2.ProgrammingError, pe:
|
except psycopg2.ProgrammingError, pe:
|
||||||
if (self._default_log_exceptions if log_exceptions is None else log_exceptions):
|
if (self._default_log_exceptions if log_exceptions is None else log_exceptions):
|
||||||
self.__logger.error("Programming error: %s, in query %s", pe, query)
|
_logger.error("Programming error: %s, in query %s", pe, query)
|
||||||
raise
|
raise
|
||||||
except Exception:
|
except Exception:
|
||||||
if (self._default_log_exceptions if log_exceptions is None else log_exceptions):
|
if (self._default_log_exceptions if log_exceptions is None else log_exceptions):
|
||||||
self.__logger.exception("bad query: %s", self._obj.query or query)
|
_logger.exception("bad query: %s", self._obj.query or query)
|
||||||
raise
|
raise
|
||||||
|
|
||||||
if self.sql_log:
|
if self.sql_log:
|
||||||
delay = mdt.now() - now
|
delay = mdt.now() - now
|
||||||
delay = delay.seconds * 1E6 + delay.microseconds
|
delay = delay.seconds * 1E6 + delay.microseconds
|
||||||
|
|
||||||
self.__logger.log(logging.DEBUG_SQL, "query: %s", self._obj.query)
|
_logger.log(logging.DEBUG_SQL, "query: %s", self._obj.query)
|
||||||
self.sql_log_count+=1
|
self.sql_log_count+=1
|
||||||
res_from = re_from.match(query.lower())
|
res_from = re_from.match(query.lower())
|
||||||
if res_from:
|
if res_from:
|
||||||
|
@ -256,16 +255,16 @@ class Cursor(object):
|
||||||
if sqllogs[type]:
|
if sqllogs[type]:
|
||||||
sqllogitems = sqllogs[type].items()
|
sqllogitems = sqllogs[type].items()
|
||||||
sqllogitems.sort(key=lambda k: k[1][1])
|
sqllogitems.sort(key=lambda k: k[1][1])
|
||||||
self.__logger.log(logging.DEBUG_SQL, "SQL LOG %s:", type)
|
_logger.log(logging.DEBUG_SQL, "SQL LOG %s:", type)
|
||||||
sqllogitems.sort(lambda x,y: cmp(x[1][0], y[1][0]))
|
sqllogitems.sort(lambda x,y: cmp(x[1][0], y[1][0]))
|
||||||
for r in sqllogitems:
|
for r in sqllogitems:
|
||||||
delay = timedelta(microseconds=r[1][1])
|
delay = timedelta(microseconds=r[1][1])
|
||||||
self.__logger.log(logging.DEBUG_SQL, "table: %s: %s/%s",
|
_logger.log(logging.DEBUG_SQL, "table: %s: %s/%s",
|
||||||
r[0], delay, r[1][0])
|
r[0], delay, r[1][0])
|
||||||
sum+= r[1][1]
|
sum+= r[1][1]
|
||||||
sqllogs[type].clear()
|
sqllogs[type].clear()
|
||||||
sum = timedelta(microseconds=sum)
|
sum = timedelta(microseconds=sum)
|
||||||
self.__logger.log(logging.DEBUG_SQL, "SUM %s:%s/%d [%d]",
|
_logger.log(logging.DEBUG_SQL, "SUM %s:%s/%d [%d]",
|
||||||
type, sum, self.sql_log_count, sql_counter)
|
type, sum, self.sql_log_count, sql_counter)
|
||||||
sqllogs[type].clear()
|
sqllogs[type].clear()
|
||||||
process('from')
|
process('from')
|
||||||
|
@ -359,7 +358,6 @@ class ConnectionPool(object):
|
||||||
The connections are *not* automatically closed. Only a close_db()
|
The connections are *not* automatically closed. Only a close_db()
|
||||||
can trigger that.
|
can trigger that.
|
||||||
"""
|
"""
|
||||||
__logger = logging.getLogger('db.connection_pool')
|
|
||||||
|
|
||||||
def locked(fun):
|
def locked(fun):
|
||||||
@wraps(fun)
|
@wraps(fun)
|
||||||
|
@ -383,7 +381,7 @@ class ConnectionPool(object):
|
||||||
return "ConnectionPool(used=%d/count=%d/max=%d)" % (used, count, self._maxconn)
|
return "ConnectionPool(used=%d/count=%d/max=%d)" % (used, count, self._maxconn)
|
||||||
|
|
||||||
def _debug(self, msg, *args):
|
def _debug(self, msg, *args):
|
||||||
self.__logger.log(logging.DEBUG_SQL, ('%r ' + msg), self, *args)
|
_logger.log(logging.DEBUG_SQL, ('%r ' + msg), self, *args)
|
||||||
|
|
||||||
@locked
|
@locked
|
||||||
def borrow(self, dsn):
|
def borrow(self, dsn):
|
||||||
|
@ -399,7 +397,7 @@ class ConnectionPool(object):
|
||||||
delattr(cnx, 'leaked')
|
delattr(cnx, 'leaked')
|
||||||
self._connections.pop(i)
|
self._connections.pop(i)
|
||||||
self._connections.append((cnx, False))
|
self._connections.append((cnx, False))
|
||||||
self.__logger.warn('%r: Free leaked connection to %r', self, cnx.dsn)
|
_logger.warn('%r: Free leaked connection to %r', self, cnx.dsn)
|
||||||
|
|
||||||
for i, (cnx, used) in enumerate(self._connections):
|
for i, (cnx, used) in enumerate(self._connections):
|
||||||
if not used and dsn_are_equals(cnx.dsn, dsn):
|
if not used and dsn_are_equals(cnx.dsn, dsn):
|
||||||
|
@ -423,7 +421,7 @@ class ConnectionPool(object):
|
||||||
try:
|
try:
|
||||||
result = psycopg2.connect(dsn=dsn, connection_factory=PsycoConnection)
|
result = psycopg2.connect(dsn=dsn, connection_factory=PsycoConnection)
|
||||||
except psycopg2.Error:
|
except psycopg2.Error:
|
||||||
self.__logger.exception('Connection to the database failed')
|
_logger.exception('Connection to the database failed')
|
||||||
raise
|
raise
|
||||||
self._connections.append((result, True))
|
self._connections.append((result, True))
|
||||||
self._debug('Create new connection')
|
self._debug('Create new connection')
|
||||||
|
@ -447,7 +445,7 @@ class ConnectionPool(object):
|
||||||
|
|
||||||
@locked
|
@locked
|
||||||
def close_all(self, dsn):
|
def close_all(self, dsn):
|
||||||
self.__logger.info('%r: Close all connections to %r', self, dsn)
|
_logger.info('%r: Close all connections to %r', self, dsn)
|
||||||
for i, (cnx, used) in tools.reverse_enumerate(self._connections):
|
for i, (cnx, used) in tools.reverse_enumerate(self._connections):
|
||||||
if dsn_are_equals(cnx.dsn, dsn):
|
if dsn_are_equals(cnx.dsn, dsn):
|
||||||
cnx.close()
|
cnx.close()
|
||||||
|
@ -457,7 +455,6 @@ class ConnectionPool(object):
|
||||||
class Connection(object):
|
class Connection(object):
|
||||||
""" A lightweight instance of a connection to postgres
|
""" A lightweight instance of a connection to postgres
|
||||||
"""
|
"""
|
||||||
__logger = logging.getLogger('db.connection')
|
|
||||||
|
|
||||||
def __init__(self, pool, dbname):
|
def __init__(self, pool, dbname):
|
||||||
self.dbname = dbname
|
self.dbname = dbname
|
||||||
|
@ -465,7 +462,7 @@ class Connection(object):
|
||||||
|
|
||||||
def cursor(self, serialized=True):
|
def cursor(self, serialized=True):
|
||||||
cursor_type = serialized and 'serialized ' or ''
|
cursor_type = serialized and 'serialized ' or ''
|
||||||
self.__logger.log(logging.DEBUG_SQL, 'create %scursor to %r', cursor_type, self.dbname)
|
_logger.log(logging.DEBUG_SQL, 'create %scursor to %r', cursor_type, self.dbname)
|
||||||
return Cursor(self._pool, self.dbname, serialized=serialized)
|
return Cursor(self._pool, self.dbname, serialized=serialized)
|
||||||
|
|
||||||
# serialized_cursor is deprecated - cursors are serialized by default
|
# serialized_cursor is deprecated - cursors are serialized by default
|
||||||
|
|
|
@ -43,6 +43,8 @@ import openerp.modules
|
||||||
import openerp.tools.config as config
|
import openerp.tools.config as config
|
||||||
import service.websrv_lib as websrv_lib
|
import service.websrv_lib as websrv_lib
|
||||||
|
|
||||||
|
_logger = logging.getLogger(__name__)
|
||||||
|
|
||||||
# XML-RPC fault codes. Some care must be taken when changing these: the
|
# XML-RPC fault codes. Some care must be taken when changing these: the
|
||||||
# constants are also defined client-side and must remain in sync.
|
# constants are also defined client-side and must remain in sync.
|
||||||
# User code must use the exceptions defined in ``openerp.exceptions`` (not
|
# User code must use the exceptions defined in ``openerp.exceptions`` (not
|
||||||
|
@ -422,12 +424,12 @@ def serve():
|
||||||
try:
|
try:
|
||||||
import werkzeug.serving
|
import werkzeug.serving
|
||||||
httpd = werkzeug.serving.make_server(interface, port, application, threaded=True)
|
httpd = werkzeug.serving.make_server(interface, port, application, threaded=True)
|
||||||
logging.getLogger('wsgi').info('HTTP service (werkzeug) running on %s:%s', interface, port)
|
_logger.info('HTTP service (werkzeug) running on %s:%s', interface, port)
|
||||||
except ImportError:
|
except ImportError:
|
||||||
import wsgiref.simple_server
|
import wsgiref.simple_server
|
||||||
logging.getLogger('wsgi').warn('Werkzeug module unavailable, falling back to wsgiref.')
|
logging.getLogger('wsgi').warn('Werkzeug module unavailable, falling back to wsgiref.')
|
||||||
httpd = wsgiref.simple_server.make_server(interface, port, application)
|
httpd = wsgiref.simple_server.make_server(interface, port, application)
|
||||||
logging.getLogger('wsgi').info('HTTP service (wsgiref) running on %s:%s', interface, port)
|
_logger.info('HTTP service (wsgiref) running on %s:%s', interface, port)
|
||||||
|
|
||||||
httpd.serve_forever()
|
httpd.serve_forever()
|
||||||
|
|
||||||
|
@ -473,7 +475,7 @@ def on_starting(server):
|
||||||
msg = """
|
msg = """
|
||||||
The `web` module is provided by the addons found in the `openerp-web` project.
|
The `web` module is provided by the addons found in the `openerp-web` project.
|
||||||
Maybe you forgot to add those addons in your addons_path configuration."""
|
Maybe you forgot to add those addons in your addons_path configuration."""
|
||||||
logging.exception('Failed to load server-wide module `%s`.%s', m, msg)
|
_logger.exception('Failed to load server-wide module `%s`.%s', m, msg)
|
||||||
|
|
||||||
# Install our own signal handler on the master process.
|
# Install our own signal handler on the master process.
|
||||||
def when_ready(server):
|
def when_ready(server):
|
||||||
|
@ -503,7 +505,7 @@ def post_request(worker, req, environ):
|
||||||
import psutil
|
import psutil
|
||||||
rss, vms = psutil.Process(os.getpid()).get_memory_info()
|
rss, vms = psutil.Process(os.getpid()).get_memory_info()
|
||||||
if vms > config['virtual_memory_reset']:
|
if vms > config['virtual_memory_reset']:
|
||||||
logging.getLogger('wsgi.worker').info('Virtual memory consumption '
|
_logger.info('Virtual memory consumption '
|
||||||
'too high, rebooting the worker.')
|
'too high, rebooting the worker.')
|
||||||
worker.alive = False # Commit suicide after the request.
|
worker.alive = False # Commit suicide after the request.
|
||||||
|
|
||||||
|
@ -515,7 +517,7 @@ def make_winch_handler(server):
|
||||||
|
|
||||||
# SIGXCPU (exceeded CPU time) signal handler will raise an exception.
|
# SIGXCPU (exceeded CPU time) signal handler will raise an exception.
|
||||||
def time_expired(n, stack):
|
def time_expired(n, stack):
|
||||||
logging.getLogger('wsgi.worker').info('CPU time limit exceeded.')
|
_logger.info('CPU time limit exceeded.')
|
||||||
raise Exception('CPU time limit exceeded.') # TODO one of openerp.exception
|
raise Exception('CPU time limit exceeded.') # TODO one of openerp.exception
|
||||||
|
|
||||||
# Kill gracefuly the workers (e.g. because we want to clear their cache).
|
# Kill gracefuly the workers (e.g. because we want to clear their cache).
|
||||||
|
|
Loading…
Reference in New Issue