From 41ce0925628b7061edc6d26da5d201f94d42fec7 Mon Sep 17 00:00:00 2001 From: Patrick Tombez Date: Thu, 3 Sep 2020 10:48:59 +0200 Subject: [PATCH 1/2] monitoring_log_requests: Improve data output * Add environment var to enable/disable requests log * Add ability to send data to an UDP listener instead of stdout --- monitoring_log_requests/README.rst | 14 +++++++++++++- monitoring_log_requests/__init__.py | 1 + monitoring_log_requests/models/__init__.py | 5 ++++- monitoring_log_requests/models/ir_http.py | 19 ++++++++++++++++--- monitoring_log_requests/utils.py | 10 ++++++++++ 5 files changed, 44 insertions(+), 5 deletions(-) create mode 100644 monitoring_log_requests/utils.py diff --git a/monitoring_log_requests/README.rst b/monitoring_log_requests/README.rst index 9b4af8d..addeb5b 100644 --- a/monitoring_log_requests/README.rst +++ b/monitoring_log_requests/README.rst @@ -6,7 +6,14 @@ Monitoring: Requests Logging This addon is used to output in the logs informations about the user's requests. Data such as *what* is the request, *who* requested it and *how -much* time did it took to complete could then be extracted from the logs and +much* time did it took to complete. + +The requests logging is activated with the environment variable `ODOO_REQUESTS_LOGGING` set to `1`. + +Data output +########### + +The data could then be extracted from the logs and loaded in an analysis tool such as ElasticSearch/Kibana. Each log line is a JSON with the monitored fields, so it is easier to parse. @@ -15,3 +22,8 @@ The logs are prefixed with ``monitoring.http.requests`` so be sure to enable this path in the log handler:: - LOG_HANDLER=":WARNING,monitoring.http.requests:INFO" + +It is also possible to send the data directly to an UDP listener without +outputting anything to the logs to avoid flooding on busy instances. +To do so, use the environment variable `ODOO_REQUESTS_LOGGING_UDP` +set to a value like `
:` (`address` can be an IP or a domain). \ No newline at end of file diff --git a/monitoring_log_requests/__init__.py b/monitoring_log_requests/__init__.py index a9e3372..911b582 100644 --- a/monitoring_log_requests/__init__.py +++ b/monitoring_log_requests/__init__.py @@ -1,2 +1,3 @@ +from . import utils from . import models diff --git a/monitoring_log_requests/models/__init__.py b/monitoring_log_requests/models/__init__.py index 0d643ba..77afcad 100644 --- a/monitoring_log_requests/models/__init__.py +++ b/monitoring_log_requests/models/__init__.py @@ -1,2 +1,5 @@ -from . import ir_http +from ..utils import is_enabled + +if is_enabled(): + from . import ir_http diff --git a/monitoring_log_requests/models/ir_http.py b/monitoring_log_requests/models/ir_http.py index abaf46b..c5bf9b9 100644 --- a/monitoring_log_requests/models/ir_http.py +++ b/monitoring_log_requests/models/ir_http.py @@ -2,15 +2,28 @@ # License AGPL-3.0 or later (http://www.gnu.org/licenses/agpl.html) import json -import logging import time +from os import environ from odoo import models from odoo.http import request as http_request from odoo.tools.config import config +udp_dest = environ.get('ODOO_REQUESTS_LOGGING_UDP') +if udp_dest: + import socket + import atexit -_logger = logging.getLogger('monitoring.http.requests') + sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM, 0) + atexit.register(sock.close) + ip, port = udp_dest.split(':') + + def output_method(data): + sock.sendto(data.encode('utf-8'), (ip, port)) +else: + import logging + _logger = logging.getLogger('monitoring.http.requests') + output_method = _logger.info class IrHttp(models.AbstractModel): @@ -80,4 +93,4 @@ class IrHttp(models.AbstractModel): @classmethod def _monitoring_log(cls, info): - _logger.info(json.dumps(info)) + output_method(json.dumps(info)) diff --git a/monitoring_log_requests/utils.py b/monitoring_log_requests/utils.py new file mode 100644 index 0000000..7a2a690 --- /dev/null +++ b/monitoring_log_requests/utils.py @@ -0,0 +1,10 @@ +# Copyright 2020 Camptocamp SA +# License AGPL-3.0 or later (http://www.gnu.org/licenses/agpl.html) + +from distutils.util import strtobool +from os import environ + + +def is_enabled(): + env_val = environ.get('ODOO_REQUESTS_LOGGING') + return bool(strtobool(env_val or '0'.lower())) From 2451f475bd83cddc1c7042de129ff0076735d9bf Mon Sep 17 00:00:00 2001 From: Patrick Tombez Date: Tue, 22 Sep 2020 12:00:34 +0200 Subject: [PATCH 2/2] fixup! monitoring_log_requests: Improve data output --- monitoring_log_requests/models/ir_http.py | 91 +++++++++++++---------- 1 file changed, 50 insertions(+), 41 deletions(-) diff --git a/monitoring_log_requests/models/ir_http.py b/monitoring_log_requests/models/ir_http.py index c5bf9b9..b465683 100644 --- a/monitoring_log_requests/models/ir_http.py +++ b/monitoring_log_requests/models/ir_http.py @@ -4,46 +4,62 @@ import json import time from os import environ +from collections import MutableMapping +from contextlib import suppress from odoo import models from odoo.http import request as http_request from odoo.tools.config import config -udp_dest = environ.get('ODOO_REQUESTS_LOGGING_UDP') + +udp_dest = environ.get("ODOO_REQUESTS_LOGGING_UDP") if udp_dest: import socket import atexit sock = socket.socket(socket.AF_INET, socket.SOCK_DGRAM, 0) atexit.register(sock.close) - ip, port = udp_dest.split(':') + ip, port = udp_dest.split(":") + port = int(port) def output_method(data): - sock.sendto(data.encode('utf-8'), (ip, port)) + data += "\n" + sock.sendto(data.encode("utf-8"), (ip, port)) else: import logging - _logger = logging.getLogger('monitoring.http.requests') + + _logger = logging.getLogger("monitoring.http.requests") output_method = _logger.info +def delete_from_dict(d, keys): + for key in keys: + with suppress(KeyError): + del d[key] + for value in d.values(): + if isinstance(value, MutableMapping): + delete_from_dict(value, keys) + + class IrHttp(models.AbstractModel): - _inherit = 'ir.http' + _inherit = "ir.http" @classmethod def _dispatch(cls): begin = time.time() response = super()._dispatch() end = time.time() - if (not cls._monitoring_blacklist(http_request) and - cls._monitoring_filter(http_request)): + if not cls._monitoring_blacklist(http_request) and cls._monitoring_filter( + http_request + ): info = cls._monitoring_info(http_request, response, begin, end) cls._monitoring_log(info) return response @classmethod def _monitoring_blacklist(cls, request): - path_info = request.httprequest.environ.get('PATH_INFO') - if path_info.startswith('/longpolling/'): + path_info = request.httprequest.environ.get("PATH_INFO") + if path_info.startswith("/longpolling/"): return True return False @@ -51,46 +67,39 @@ class IrHttp(models.AbstractModel): def _monitoring_filter(cls, _): return True + @classmethod + def _json_blacklist(cls): + return ["HTTP_COOKIE", "session_token"] + @classmethod def _monitoring_info(cls, request, response, begin, end): - path = request.httprequest.environ.get('PATH_INFO') info = { # timing - 'start_time': time.strftime("%Y-%m-%d %H:%M:%S", - time.gmtime(begin)), - 'duration': end - begin, + "start_time": time.strftime("%Y-%m-%d %H:%M:%S", time.gmtime(begin)), + "duration": end - begin, # HTTP things - 'method': request.httprequest.method, - 'url': request.httprequest.url, - 'path': path, - 'content_type': request.httprequest.environ.get('CONTENT_TYPE'), - 'user_agent': request.httprequest.environ.get('HTTP_USER_AGENT'), + "method": request.httprequest.method, + "url": request.httprequest.url, + "status_code": response.status_code, + "headers": request.httprequest.environ.copy(), # Odoo things - 'db': None, - 'uid': request.uid, - 'login': None, - 'server_environment': config.get('running_env'), - 'model': None, - 'model_method': None, - 'workflow_signal': None, - # response things - 'response_status_code': None, + "uid": request.uid, + "server_environment": config.get("running_env"), } - if hasattr(request, 'status_code'): - info['status_code'] = response.status_code - if hasattr(request, 'session'): - info.update({ - 'login': request.session.get('login'), - 'db': request.session.get('db'), - }) - if hasattr(request, 'params'): - info.update({ - 'model': request.params.get('model'), - 'model_method': request.params.get('method'), - 'workflow_signal': request.params.get('signal'), - }) + if hasattr(request, "session"): + info["session"] = dict(request.session) + if hasattr(request, "params"): + info["params"] = dict(request.params) + return info @classmethod def _monitoring_log(cls, info): - output_method(json.dumps(info)) + delete_from_dict(info, cls._json_blacklist()) + output_method( + json.dumps( + info, + ensure_ascii=True, + default=lambda o: f"", + ) + )