sql loggin cleanups
- prepare for netsvc will be renamed to logging - move back log from http.py has it's used by the cron - move sql handler to netsvc, simplify to use sql_db - remove unused handler - close plaform specific #ifdef pandora's box bzr revid: al@openerp.com-20140316182933-jkcji9yqfbsokcmg
This commit is contained in:
parent
4bbcfddc13
commit
e9d047e611
|
@ -21,7 +21,6 @@ import time
|
||||||
import traceback
|
import traceback
|
||||||
import urlparse
|
import urlparse
|
||||||
import warnings
|
import warnings
|
||||||
from pprint import pformat
|
|
||||||
|
|
||||||
import babel.core
|
import babel.core
|
||||||
import psutil
|
import psutil
|
||||||
|
@ -36,9 +35,7 @@ import werkzeug.wrappers
|
||||||
import werkzeug.wsgi
|
import werkzeug.wsgi
|
||||||
|
|
||||||
import openerp
|
import openerp
|
||||||
import openerp.netsvc
|
|
||||||
from openerp.service import security, model as service_model
|
from openerp.service import security, model as service_model
|
||||||
import openerp.tools
|
|
||||||
|
|
||||||
_logger = logging.getLogger(__name__)
|
_logger = logging.getLogger(__name__)
|
||||||
|
|
||||||
|
@ -61,13 +58,6 @@ def replace_request_password(args):
|
||||||
args[2] = '*'
|
args[2] = '*'
|
||||||
return tuple(args)
|
return tuple(args)
|
||||||
|
|
||||||
def log(logger, level, prefix, msg, depth=None):
|
|
||||||
indent=''
|
|
||||||
indent_after=' '*len(prefix)
|
|
||||||
for line in (prefix+pformat(msg, depth=depth)).split('\n'):
|
|
||||||
logger.log(level, indent+line)
|
|
||||||
indent=indent_after
|
|
||||||
|
|
||||||
def dispatch_rpc(service_name, method, params):
|
def dispatch_rpc(service_name, method, params):
|
||||||
""" Handle a RPC call.
|
""" Handle a RPC call.
|
||||||
|
|
||||||
|
@ -84,7 +74,7 @@ def dispatch_rpc(service_name, method, params):
|
||||||
start_rss, start_vms = 0, 0
|
start_rss, start_vms = 0, 0
|
||||||
start_rss, start_vms = psutil.Process(os.getpid()).get_memory_info()
|
start_rss, start_vms = psutil.Process(os.getpid()).get_memory_info()
|
||||||
if rpc_request and rpc_response_flag:
|
if rpc_request and rpc_response_flag:
|
||||||
log(rpc_request, logging.DEBUG, '%s.%s' % (service_name, method), replace_request_password(params))
|
openerp.netsvc.log(rpc_request, logging.DEBUG, '%s.%s' % (service_name, method), replace_request_password(params))
|
||||||
|
|
||||||
threading.current_thread().uid = None
|
threading.current_thread().uid = None
|
||||||
threading.current_thread().dbname = None
|
threading.current_thread().dbname = None
|
||||||
|
@ -106,9 +96,9 @@ def dispatch_rpc(service_name, method, params):
|
||||||
end_rss, end_vms = psutil.Process(os.getpid()).get_memory_info()
|
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)
|
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:
|
if rpc_response_flag:
|
||||||
log(rpc_response, logging.DEBUG, logline, result)
|
openerp.netsvc.log(rpc_response, logging.DEBUG, logline, result)
|
||||||
else:
|
else:
|
||||||
log(rpc_request, logging.DEBUG, logline, replace_request_password(params), depth=1)
|
openerp.netsvc.log(rpc_request, logging.DEBUG, logline, replace_request_password(params), depth=1)
|
||||||
|
|
||||||
return result
|
return result
|
||||||
except (openerp.osv.orm.except_orm, openerp.exceptions.AccessError, \
|
except (openerp.osv.orm.except_orm, openerp.exceptions.AccessError, \
|
||||||
|
|
|
@ -1 +0,0 @@
|
||||||
from handlers import PostgreSQLHandler
|
|
|
@ -1,107 +0,0 @@
|
||||||
##############################################################################
|
|
||||||
#
|
|
||||||
# OpenERP, Open Source Management Solution
|
|
||||||
# Copyright (C) 2014 OpenERP SA (<http://www.openerp.com>)
|
|
||||||
#
|
|
||||||
# This program is free software: you can redistribute it and/or modify
|
|
||||||
# it under the terms of the GNU Affero General Public License as
|
|
||||||
# published by the Free Software Foundation, either version 3 of the
|
|
||||||
# License, or (at your option) any later version.
|
|
||||||
#
|
|
||||||
# This program is distributed in the hope that it will be useful,
|
|
||||||
# but WITHOUT ANY WARRANTY; without even the implied warranty of
|
|
||||||
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
|
|
||||||
# GNU Affero General Public License for more details.
|
|
||||||
#
|
|
||||||
# You should have received a copy of the GNU Affero General Public License
|
|
||||||
# along with this program. If not, see <http://www.gnu.org/licenses/>.
|
|
||||||
#
|
|
||||||
##############################################################################
|
|
||||||
|
|
||||||
import contextlib
|
|
||||||
import datetime
|
|
||||||
import logging
|
|
||||||
import threading
|
|
||||||
|
|
||||||
import psycopg2
|
|
||||||
|
|
||||||
from openerp import tools
|
|
||||||
|
|
||||||
# The PostgreSQL Handler for the logging module, will be used by OpenERP to store the logs
|
|
||||||
# in the database, --log-pgsql-database=YOUR_DBNAME
|
|
||||||
# By default the system will use the current database
|
|
||||||
|
|
||||||
class NoDatabaseError(Exception):
|
|
||||||
pass
|
|
||||||
|
|
||||||
class PostgreSQLHandler(logging.Handler):
|
|
||||||
@contextlib.contextmanager
|
|
||||||
def create_connection(self):
|
|
||||||
db_name = None
|
|
||||||
|
|
||||||
db_name_from_cli = tools.config['log_pgsql_database']
|
|
||||||
if not db_name_from_cli:
|
|
||||||
# If there is no database, and only in this case, we are going to use the database
|
|
||||||
# from the current thread and create a connection to this database.
|
|
||||||
|
|
||||||
current_thread = threading.current_thread()
|
|
||||||
|
|
||||||
db_name_from_thread = getattr(current_thread, 'dbname', None)
|
|
||||||
if isinstance(db_name_from_thread, basestring):
|
|
||||||
db_name = db_name_from_thread
|
|
||||||
else:
|
|
||||||
db_name = db_name_from_cli
|
|
||||||
|
|
||||||
if not db_name:
|
|
||||||
raise NoDatabaseError("There is no defined database on this request")
|
|
||||||
|
|
||||||
parameters = {
|
|
||||||
'user': tools.config['db_user'] or None,
|
|
||||||
'password': tools.config['db_password'] or None,
|
|
||||||
'host': tools.config['db_host'] or None,
|
|
||||||
'port': tools.config['db_port'] or None,
|
|
||||||
'database': db_name,
|
|
||||||
}
|
|
||||||
try:
|
|
||||||
connection = psycopg2.connect(**parameters)
|
|
||||||
|
|
||||||
if connection:
|
|
||||||
yield connection
|
|
||||||
except Exception, ex: # Use a specific exception
|
|
||||||
print ex
|
|
||||||
|
|
||||||
def _internal_emit(self, record):
|
|
||||||
with self.create_connection() as conn:
|
|
||||||
exception = False
|
|
||||||
if record.exc_info:
|
|
||||||
exception = record.exc_text
|
|
||||||
|
|
||||||
now = datetime.datetime.utcnow()
|
|
||||||
|
|
||||||
current_thread = threading.current_thread()
|
|
||||||
uid = getattr(current_thread, 'uid', False)
|
|
||||||
dbname = getattr(current_thread, 'dbname', False)
|
|
||||||
|
|
||||||
parameters = (
|
|
||||||
now, uid, now, uid, 'server', dbname, record.name,
|
|
||||||
logging.getLevelName(record.levelno), record.msg, exception,
|
|
||||||
record.filename, record.funcName, record.lineno
|
|
||||||
)
|
|
||||||
|
|
||||||
with conn.cursor() as cursor:
|
|
||||||
cursor.execute("""
|
|
||||||
INSERT INTO ir_logging(
|
|
||||||
create_date, create_uid, write_date, write_uid,
|
|
||||||
type, dbname, name, level, message, exception, path, func,
|
|
||||||
line
|
|
||||||
)
|
|
||||||
VALUES(%s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s)
|
|
||||||
""", parameters)
|
|
||||||
conn.commit()
|
|
||||||
|
|
||||||
def emit(self, record):
|
|
||||||
# We use a context manager to be tolerant to the errors (error of connections,...)
|
|
||||||
try:
|
|
||||||
self._internal_emit(record)
|
|
||||||
except NoDatabaseError:
|
|
||||||
pass
|
|
|
@ -19,20 +19,32 @@
|
||||||
#
|
#
|
||||||
##############################################################################
|
##############################################################################
|
||||||
|
|
||||||
|
import contextlib
|
||||||
import logging
|
import logging
|
||||||
import logging.handlers
|
import logging.handlers
|
||||||
import os
|
import os
|
||||||
|
import platform
|
||||||
import release
|
import release
|
||||||
import sys
|
import sys
|
||||||
import threading
|
import threading
|
||||||
|
from pprint import pformat
|
||||||
|
|
||||||
|
import psycopg2
|
||||||
|
|
||||||
import tools
|
import tools
|
||||||
import openerp
|
import openerp
|
||||||
import openerp.loggers
|
import sql_db
|
||||||
|
|
||||||
|
|
||||||
_logger = logging.getLogger(__name__)
|
_logger = logging.getLogger(__name__)
|
||||||
|
|
||||||
|
def log(logger, level, prefix, msg, depth=None):
|
||||||
|
indent=''
|
||||||
|
indent_after=' '*len(prefix)
|
||||||
|
for line in (prefix+pformat(msg, depth=depth)).split('\n'):
|
||||||
|
logger.log(level, indent+line)
|
||||||
|
indent=indent_after
|
||||||
|
|
||||||
def LocalService(name):
|
def LocalService(name):
|
||||||
"""
|
"""
|
||||||
The openerp.netsvc.LocalService() function is deprecated. It still works
|
The openerp.netsvc.LocalService() function is deprecated. It still works
|
||||||
|
@ -59,6 +71,38 @@ def LocalService(name):
|
||||||
with registry.cursor() as cr:
|
with registry.cursor() as cr:
|
||||||
return registry['ir.actions.report.xml']._lookup_report(cr, name[len('report.'):])
|
return registry['ir.actions.report.xml']._lookup_report(cr, name[len('report.'):])
|
||||||
|
|
||||||
|
class PostgreSQLHandler(logging.Handler):
|
||||||
|
""" PostgreSQL Loggin Handler will store logs in the database, by default
|
||||||
|
the current database, can be set using --log-db=DBNAME
|
||||||
|
"""
|
||||||
|
def emit(self, record):
|
||||||
|
print "Emit PG", record
|
||||||
|
ct = threading.current_thread()
|
||||||
|
ct_db = getattr(ct, 'dbname')
|
||||||
|
ct_uid = getattr(ct, 'uid')
|
||||||
|
dbname = tools.config['log_db'] or ct_db
|
||||||
|
if dbname:
|
||||||
|
cr = None
|
||||||
|
try:
|
||||||
|
cr = sql_db.db_connect(dbname).cursor()
|
||||||
|
exception = False
|
||||||
|
if record.exc_info:
|
||||||
|
exception = record.exc_text
|
||||||
|
level = logging.getLevelName(record.levelno)
|
||||||
|
val = (uid, uid, 'server', dbname, record.name, level, record.msg, exception, record.filename, record.funcName, record.lineno)
|
||||||
|
cr.execute("""
|
||||||
|
INSERT INTO ir_logging(create_date, write_date, create_uid, write_uid, type, dbname, name, level, message, exception, path, func, line)
|
||||||
|
VALUES (NOW() at time zone 'UTC', NOW() at time zone 'UTC', %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s)
|
||||||
|
""", val )
|
||||||
|
cr.commit()
|
||||||
|
except Exception, e:
|
||||||
|
print "Exception",e
|
||||||
|
print repr(e)
|
||||||
|
pass
|
||||||
|
finally:
|
||||||
|
if cr:
|
||||||
|
cr.close()
|
||||||
|
|
||||||
BLACK, RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE, _NOTHING, DEFAULT = range(10)
|
BLACK, RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE, _NOTHING, DEFAULT = range(10)
|
||||||
#The background is set with 40 plus the number of the color, and the foreground with 30
|
#The background is set with 40 plus the number of the color, and the foreground with 30
|
||||||
#These are the sequences need to get colored ouput
|
#These are the sequences need to get colored ouput
|
||||||
|
@ -86,19 +130,6 @@ class ColoredFormatter(DBFormatter):
|
||||||
record.levelname = COLOR_PATTERN % (30 + fg_color, 40 + bg_color, record.levelname)
|
record.levelname = COLOR_PATTERN % (30 + fg_color, 40 + bg_color, record.levelname)
|
||||||
return DBFormatter.format(self, record)
|
return DBFormatter.format(self, record)
|
||||||
|
|
||||||
import platform
|
|
||||||
def is_posix_operating_system():
|
|
||||||
return os.name == 'posix'
|
|
||||||
|
|
||||||
def is_windows_operating_system():
|
|
||||||
return os.name == 'nt'
|
|
||||||
|
|
||||||
def is_linux_operating_system():
|
|
||||||
return is_posix_operating_system() and platform.system() == 'Linux'
|
|
||||||
|
|
||||||
def is_macosx_operating_system():
|
|
||||||
return is_posix_operating_system() and platform.system() == 'Darwin'
|
|
||||||
|
|
||||||
def init_logger():
|
def init_logger():
|
||||||
from tools.translate import resetlocale
|
from tools.translate import resetlocale
|
||||||
resetlocale()
|
resetlocale()
|
||||||
|
@ -108,15 +139,10 @@ def init_logger():
|
||||||
|
|
||||||
if tools.config['syslog']:
|
if tools.config['syslog']:
|
||||||
# SysLog Handler
|
# SysLog Handler
|
||||||
if is_windows_operating_system():
|
if os.name == 'nt':
|
||||||
handler = logging.handlers.NTEventLogHandler("%s %s" % (release.description, release.version))
|
handler = logging.handlers.NTEventLogHandler("%s %s" % (release.description, release.version))
|
||||||
elif is_linux_operating_system():
|
|
||||||
handler = logging.handlers.SysLogHandler('/dev/log')
|
|
||||||
elif is_macosx_operating_system(): # There is no /dev/log on OSX
|
|
||||||
handler = logging.handlers.SysLogHandler('/var/run/log')
|
|
||||||
else:
|
else:
|
||||||
raise Exception("There is no syslog handler for this Operating System: %s", platform.system())
|
handler = logging.handlers.SysLogHandler()
|
||||||
|
|
||||||
format = '%s %s' % (release.description, release.version) + ':%(dbname)s:%(levelname)s:%(name)s:%(message)s'
|
format = '%s %s' % (release.description, release.version) + ':%(dbname)s:%(levelname)s:%(name)s:%(message)s'
|
||||||
|
|
||||||
elif tools.config['logfile']:
|
elif tools.config['logfile']:
|
||||||
|
@ -130,12 +156,11 @@ def init_logger():
|
||||||
|
|
||||||
if tools.config['logrotate'] is not False:
|
if tools.config['logrotate'] is not False:
|
||||||
handler = logging.handlers.TimedRotatingFileHandler(filename=logf, when='D', interval=1, backupCount=30)
|
handler = logging.handlers.TimedRotatingFileHandler(filename=logf, when='D', interval=1, backupCount=30)
|
||||||
|
elif os.name == 'posix':
|
||||||
elif is_posix_operating_system():
|
|
||||||
handler = logging.handlers.WatchedFileHandler(logf)
|
handler = logging.handlers.WatchedFileHandler(logf)
|
||||||
|
|
||||||
else:
|
else:
|
||||||
handler = logging.handlers.FileHandler(logf)
|
handler = logging.handlers.FileHandler(logf)
|
||||||
|
|
||||||
except Exception:
|
except Exception:
|
||||||
sys.stderr.write("ERROR: couldn't create the logfile directory. Logging to the standard output.\n")
|
sys.stderr.write("ERROR: couldn't create the logfile directory. Logging to the standard output.\n")
|
||||||
handler = logging.StreamHandler(sys.stdout)
|
handler = logging.StreamHandler(sys.stdout)
|
||||||
|
@ -147,10 +172,10 @@ def init_logger():
|
||||||
# behind Apache with mod_wsgi, handler.stream will have type mod_wsgi.Log,
|
# behind Apache with mod_wsgi, handler.stream will have type mod_wsgi.Log,
|
||||||
# which has no fileno() method. (mod_wsgi.Log is what is being bound to
|
# which has no fileno() method. (mod_wsgi.Log is what is being bound to
|
||||||
# sys.stderr when the logging.StreamHandler is being constructed above.)
|
# sys.stderr when the logging.StreamHandler is being constructed above.)
|
||||||
def has_fileno(stream):
|
def is_a_tty(stream):
|
||||||
return hasattr(stream, 'fileno') and os.isatty(stream.fileno())
|
return hasattr(stream, 'fileno') and os.isatty(stream.fileno())
|
||||||
|
|
||||||
if isinstance(handler, logging.StreamHandler) and has_fileno(handler.stream):
|
if isinstance(handler, logging.StreamHandler) and is_a_tty(handler.stream):
|
||||||
formatter = ColoredFormatter(format)
|
formatter = ColoredFormatter(format)
|
||||||
else:
|
else:
|
||||||
formatter = DBFormatter(format)
|
formatter = DBFormatter(format)
|
||||||
|
@ -165,9 +190,7 @@ def init_logger():
|
||||||
logging_configurations = DEFAULT_LOG_CONFIGURATION + pseudo_config + logconfig
|
logging_configurations = DEFAULT_LOG_CONFIGURATION + pseudo_config + logconfig
|
||||||
for logconfig_item in logging_configurations:
|
for logconfig_item in logging_configurations:
|
||||||
loggername, level = logconfig_item.split(':')
|
loggername, level = logconfig_item.split(':')
|
||||||
|
|
||||||
level = getattr(logging, level, logging.INFO)
|
level = getattr(logging, level, logging.INFO)
|
||||||
|
|
||||||
logger = logging.getLogger(loggername)
|
logger = logging.getLogger(loggername)
|
||||||
logger.handlers = []
|
logger.handlers = []
|
||||||
logger.setLevel(level)
|
logger.setLevel(level)
|
||||||
|
@ -175,9 +198,8 @@ def init_logger():
|
||||||
if loggername != '':
|
if loggername != '':
|
||||||
logger.propagate = False
|
logger.propagate = False
|
||||||
|
|
||||||
# magic ;-)
|
|
||||||
# we manage the connection in the postgresqlhandler
|
# we manage the connection in the postgresqlhandler
|
||||||
postgresqlHandler = openerp.loggers.handlers.PostgreSQLHandler()
|
postgresqlHandler = PostgreSQLHandler()
|
||||||
postgresqlHandler.setLevel(logging.WARNING)
|
postgresqlHandler.setLevel(logging.WARNING)
|
||||||
logger = logging.getLogger()
|
logger = logging.getLogger()
|
||||||
logger.addHandler(postgresqlHandler)
|
logger.addHandler(postgresqlHandler)
|
||||||
|
@ -204,17 +226,4 @@ PSEUDOCONFIG_MAPPER = {
|
||||||
'critical': ['openerp:CRITICAL'],
|
'critical': ['openerp:CRITICAL'],
|
||||||
}
|
}
|
||||||
|
|
||||||
# A alternative logging scheme for automated runs of the
|
|
||||||
# server intended to test it.
|
|
||||||
def init_alternative_logger():
|
|
||||||
class H(logging.Handler):
|
|
||||||
def emit(self, record):
|
|
||||||
if record.levelno > 20:
|
|
||||||
print record.levelno, record.pathname, record.msg
|
|
||||||
handler = H()
|
|
||||||
# Add the handler to the 'openerp' logger.
|
|
||||||
logger = logging.getLogger('openerp')
|
|
||||||
logger.addHandler(handler)
|
|
||||||
logger.setLevel(logging.ERROR)
|
|
||||||
|
|
||||||
# vim:expandtab:smartindent:tabstop=4:softtabstop=4:shiftwidth=4:
|
# vim:expandtab:smartindent:tabstop=4:softtabstop=4:shiftwidth=4:
|
||||||
|
|
|
@ -1,4 +1,4 @@
|
||||||
# -*- coding: utf-8 -*-
|
#openerp.loggers.handlers. -*- coding: utf-8 -*-
|
||||||
##############################################################################
|
##############################################################################
|
||||||
#
|
#
|
||||||
# OpenERP, Open Source Management Solution
|
# OpenERP, Open Source Management Solution
|
||||||
|
@ -187,7 +187,7 @@ class configmanager(object):
|
||||||
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-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.http:DEBUG", help='shortcut for --log-handler=openerp.addons.web.http:DEBUG')
|
group.add_option('--log-web', action="append_const", dest="log_handler", const="openerp.addons.web.http:DEBUG", help='shortcut for --log-handler=openerp.addons.web.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')
|
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')
|
||||||
group.add_option('--log-pgsql-database', dest='log_pgsql_database', help="database where OpenERP will store the exceptions", my_default=False)
|
group.add_option('--log-db', dest='log_db', help="database where OpenERP will store the exceptions", my_default=False)
|
||||||
# For backward-compatibility, map the old log levels to something
|
# For backward-compatibility, map the old log levels to something
|
||||||
# quite close.
|
# quite close.
|
||||||
levels = [
|
levels = [
|
||||||
|
|
Loading…
Reference in New Issue