Coverage for adhoc-cicd-odoo-odoo / odoo / netsvc.py: 56%
203 statements
« prev ^ index » next coverage.py v7.13.4, created at 2026-03-09 18:22 +0000
1# -*- coding: utf-8 -*-
2# Part of Odoo. See LICENSE file for full copyright and licensing details.
3import contextlib
4import json
5import logging
6import logging.handlers
7import os
8import platform
9import pprint
10import sys
11import threading
12import traceback
13import warnings
15import werkzeug.serving
17from . import release
18from . import sql_db
19from . import tools
21_logger = logging.getLogger(__name__)
23def log(logger, level, prefix, msg, depth=None):
24 warnings.warn(
25 "odoo.netsvc.log is deprecated starting Odoo 18, use normal logging APIs",
26 category=DeprecationWarning,
27 stacklevel=2,
28 )
29 indent=''
30 indent_after=' '*len(prefix)
31 for line in (prefix + pprint.pformat(msg, depth=depth)).split('\n'):
32 logger.log(level, indent+line)
33 indent=indent_after
36class WatchedFileHandler(logging.handlers.WatchedFileHandler):
37 def __init__(self, filename):
38 self.errors = None # py38
39 super().__init__(filename)
40 # Unfix bpo-26789, in case the fix is present
41 self._builtin_open = None
43 def _open(self):
44 return open(self.baseFilename, self.mode, encoding=self.encoding, errors=self.errors)
46class PostgreSQLHandler(logging.Handler):
47 """ PostgreSQL Logging Handler will store logs in the database, by default
48 the current database, can be set using --log-db=DBNAME
49 """
51 def __init__(self):
52 super().__init__()
53 self._support_metadata = False
54 if tools.config['log_db'] != '%d': 54 ↛ exitline 54 didn't return from function '__init__' because the condition on line 54 was always true
55 with contextlib.suppress(Exception), tools.mute_logger('odoo.sql_db'), sql_db.db_connect(tools.config['log_db'], allow_uri=True).cursor() as cr:
56 cr.execute("""SELECT 1 FROM information_schema.columns WHERE table_name='ir_logging' and column_name='metadata' AND table_schema = current_schema""")
57 self._support_metadata = bool(cr.fetchone())
59 def emit(self, record):
60 ct = threading.current_thread()
61 ct_db = getattr(ct, 'dbname', None)
62 dbname = tools.config['log_db'] if tools.config['log_db'] and tools.config['log_db'] != '%d' else ct_db
63 if not dbname: 63 ↛ 64line 63 didn't jump to line 64 because the condition on line 63 was never true
64 return
65 with contextlib.suppress(Exception), tools.mute_logger('odoo.sql_db'), sql_db.db_connect(dbname, allow_uri=True).cursor() as cr:
66 # preclude risks of deadlocks
67 cr.execute("SET LOCAL statement_timeout = 1000")
68 msg = str(record.msg)
69 if record.args: 69 ↛ 71line 69 didn't jump to line 71 because the condition on line 69 was always true
70 msg = msg % record.args
71 traceback = getattr(record, 'exc_text', '')
72 if traceback: 72 ↛ 73line 72 didn't jump to line 73 because the condition on line 72 was never true
73 msg = f"{msg}\n{traceback}"
74 # we do not use record.levelname because it may have been changed by ColoredFormatter.
75 levelname = logging.getLevelName(record.levelno)
77 val = ('server', ct_db, record.name, levelname, msg, record.pathname, record.lineno, record.funcName)
79 if self._support_metadata: 79 ↛ 93line 79 didn't jump to line 93 because the condition on line 79 was always true
80 from . import modules
81 metadata = {}
82 if modules.module.current_test: 82 ↛ 83line 82 didn't jump to line 83 because the condition on line 82 was never true
83 with contextlib.suppress(Exception):
84 metadata['test'] = modules.module.current_test.get_log_metadata()
86 if metadata: 86 ↛ 87line 86 didn't jump to line 87 because the condition on line 86 was never true
87 cr.execute("""
88 INSERT INTO ir_logging(create_date, type, dbname, name, level, message, path, line, func, metadata)
89 VALUES (NOW() at time zone 'UTC', %s, %s, %s, %s, %s, %s, %s, %s, %s)
90 """, (*val, json.dumps(metadata)))
91 return
93 cr.execute("""
94 INSERT INTO ir_logging(create_date, type, dbname, name, level, message, path, line, func)
95 VALUES (NOW() at time zone 'UTC', %s, %s, %s, %s, %s, %s, %s, %s)
96 """, val)
98BLACK, RED, GREEN, YELLOW, BLUE, MAGENTA, CYAN, WHITE, _NOTHING, DEFAULT = range(10)
99#The background is set with 40 plus the number of the color, and the foreground with 30
100#These are the sequences needed to get colored output
101RESET_SEQ = "\033[0m"
102COLOR_SEQ = "\033[1;%dm"
103BOLD_SEQ = "\033[1m"
104COLOR_PATTERN = f"{COLOR_SEQ}{COLOR_SEQ}%s{RESET_SEQ}"
105LEVEL_COLOR_MAPPING = {
106 logging.DEBUG: (BLUE, DEFAULT),
107 logging.INFO: (GREEN, DEFAULT),
108 logging.WARNING: (YELLOW, DEFAULT),
109 logging.ERROR: (RED, DEFAULT),
110 logging.CRITICAL: (WHITE, RED),
111}
113class PerfFilter(logging.Filter):
115 def format_perf(self, query_count, query_time, remaining_time):
116 return (f"{query_count:d}", f"{query_time:.3f}", f"{remaining_time:.3f}")
118 def format_cursor_mode(self, cursor_mode):
119 return cursor_mode or '-'
121 def filter(self, record):
122 if hasattr(threading.current_thread(), "query_count"):
123 query_count = threading.current_thread().query_count
124 query_time = threading.current_thread().query_time
125 perf_t0 = threading.current_thread().perf_t0
126 remaining_time = tools.real_time() - perf_t0 - query_time
127 record.perf_info = '%s %s %s' % self.format_perf(query_count, query_time, remaining_time)
128 if tools.config['db_replica_host'] or 'replica' in tools.config['dev_mode']:
129 cursor_mode = threading.current_thread().cursor_mode
130 record.perf_info = f'{record.perf_info} {self.format_cursor_mode(cursor_mode)}'
131 delattr(threading.current_thread(), "query_count")
132 else:
133 if tools.config['db_replica_host'] or 'replica' in tools.config['dev_mode']:
134 record.perf_info = "- - - -"
135 record.perf_info = "- - -"
136 return True
138class ColoredPerfFilter(PerfFilter):
139 def format_perf(self, query_count, query_time, remaining_time):
140 def colorize_time(time, format, low=1, high=5):
141 if time > high:
142 return COLOR_PATTERN % (30 + RED, 40 + DEFAULT, format % time)
143 if time > low:
144 return COLOR_PATTERN % (30 + YELLOW, 40 + DEFAULT, format % time)
145 return format % time
146 return (
147 colorize_time(query_count, "%d", 100, 1000),
148 colorize_time(query_time, "%.3f", 0.1, 3),
149 colorize_time(remaining_time, "%.3f", 1, 5),
150 )
152 def format_cursor_mode(self, cursor_mode):
153 cursor_mode = super().format_cursor_mode(cursor_mode)
154 cursor_mode_color = (
155 RED if cursor_mode == 'ro->rw'
156 else YELLOW if cursor_mode == 'rw'
157 else GREEN
158 )
159 return COLOR_PATTERN % (30 + cursor_mode_color, 40 + DEFAULT, cursor_mode)
162class ColoredFormatter(logging.Formatter):
163 def format(self, record):
164 fg_color, bg_color = LEVEL_COLOR_MAPPING.get(record.levelno, (GREEN, DEFAULT))
165 record.levelname = COLOR_PATTERN % (30 + fg_color, 40 + bg_color, record.levelname)
166 return super().format(record)
169class LogRecord(logging.LogRecord):
170 def __init__(self, name, level, pathname, lineno, msg, args, exc_info, func=None, sinfo=None, **kwargs):
171 super().__init__(name, level, pathname, lineno, msg, args, exc_info, func=func, sinfo=sinfo, **kwargs)
172 self.perf_info = ""
173 self.pid = os.getpid()
174 self.dbname = getattr(threading.current_thread(), 'dbname', '?')
177showwarning = None
178def init_logger():
179 global showwarning # noqa: PLW0603
180 if logging.getLogRecordFactory() is LogRecord: 180 ↛ 181line 180 didn't jump to line 181 because the condition on line 180 was never true
181 return
183 logging.setLogRecordFactory(LogRecord)
185 logging.captureWarnings(True)
186 # must be after `loggin.captureWarnings` so we override *that* instead of
187 # the other way around
188 showwarning = warnings.showwarning
189 warnings.showwarning = showwarning_with_traceback
191 # enable deprecation warnings (disabled by default)
192 warnings.simplefilter('default', category=DeprecationWarning)
193 # https://github.com/urllib3/urllib3/issues/2680
194 warnings.filterwarnings('ignore', r'^\'urllib3.contrib.pyopenssl\' module is deprecated.+', category=DeprecationWarning)
195 # ignore a bunch of warnings we can't really fix ourselves
196 for module in [
197 'babel.util', # deprecated parser module, no release yet
198 'zeep.loader',# zeep using defusedxml.lxml
199 'reportlab.lib.rl_safe_eval',# reportlab importing ABC from collections
200 'ofxparse',# ofxparse importing ABC from collections
201 'astroid', # deprecated imp module (fixed in 2.5.1)
202 'requests_toolbelt', # importing ABC from collections (fixed in 0.9)
203 ]:
204 warnings.filterwarnings('ignore', category=DeprecationWarning, module=module)
206 # rsjmin triggers this with Python 3.10+ (that warning comes from the C code and has no `module`)
207 warnings.filterwarnings('ignore', r'^PyUnicode_FromUnicode\(NULL, size\) is deprecated', category=DeprecationWarning)
208 # reportlab<4.0.6 triggers this in Py3.10/3.11
209 warnings.filterwarnings('ignore', r'the load_module\(\) method is deprecated', category=DeprecationWarning, module='importlib._bootstrap')
210 # the SVG guesser thing always compares str and bytes, ignore it
211 warnings.filterwarnings('ignore', category=BytesWarning, module='odoo.tools.image')
212 # reportlab does a bunch of bytes/str mixing in a hashmap
213 warnings.filterwarnings('ignore', category=BytesWarning, module='reportlab.platypus.paraparser')
215 # need to be adapted later but too muchwork for this pr.
216 warnings.filterwarnings('ignore', r'^datetime.datetime.utcnow\(\) is deprecated and scheduled for removal in a future version.*', category=DeprecationWarning)
218 # pkg_ressouce is used in google-auth < 1.23.0 (removed in https://github.com/googleapis/google-auth-library-python/pull/596)
219 # unfortunately, in ubuntu jammy and noble, the google-auth version is 1.5.1
220 # starting from noble, the default pkg_ressource version emits a warning on import, triggered when importing
221 # google-auth
222 warnings.filterwarnings('ignore', r'pkg_resources is deprecated as an API.+', category=DeprecationWarning)
223 warnings.filterwarnings('ignore', r'Deprecated call to \`pkg_resources.declare_namespace.+', category=DeprecationWarning)
225 # This warning is triggered library only during the python precompilation which does not occur on readonly filesystem
226 warnings.filterwarnings("ignore", r'invalid escape sequence', category=DeprecationWarning, module=".*vobject")
227 warnings.filterwarnings("ignore", r'invalid escape sequence', category=SyntaxWarning, module=".*vobject")
228 from .tools.translate import resetlocale
229 resetlocale()
231 # create a format for log messages and dates
232 format = '%(asctime)s %(pid)s %(levelname)s %(dbname)s %(name)s: %(message)s %(perf_info)s'
233 # Normal Handler on stderr
234 handler = logging.StreamHandler()
236 if tools.config['syslog']: 236 ↛ 238line 236 didn't jump to line 238 because the condition on line 236 was never true
237 # SysLog Handler
238 if os.name == 'nt':
239 handler = logging.handlers.NTEventLogHandler(f"{release.description} {release.version}")
240 elif platform.system() == 'Darwin':
241 handler = logging.handlers.SysLogHandler('/var/run/log')
242 else:
243 handler = logging.handlers.SysLogHandler('/dev/log')
244 format = f'{release.description} {release.version}:%(dbname)s:%(levelname)s:%(name)s:%(message)s'
246 elif tools.config['logfile']: 246 ↛ 248line 246 didn't jump to line 248 because the condition on line 246 was never true
247 # LogFile Handler
248 logf = tools.config['logfile']
249 try:
250 # We check we have the right location for the log files
251 dirname = os.path.dirname(logf)
252 if dirname and not os.path.isdir(dirname):
253 os.makedirs(dirname)
254 if os.name == 'posix':
255 handler = WatchedFileHandler(logf)
256 else:
257 handler = logging.FileHandler(logf)
258 except Exception:
259 sys.stderr.write("ERROR: couldn't create the logfile directory. Logging to the standard output.\n")
261 # Check that handler.stream has a fileno() method: when running OpenERP
262 # behind Apache with mod_wsgi, handler.stream will have type mod_wsgi.Log,
263 # which has no fileno() method. (mod_wsgi.Log is what is being bound to
264 # sys.stderr when the logging.StreamHandler is being constructed above.)
265 def is_a_tty(stream):
266 return hasattr(stream, 'fileno') and os.isatty(stream.fileno())
268 if os.name == 'posix' and isinstance(handler, logging.StreamHandler) and (is_a_tty(handler.stream) or os.environ.get("ODOO_PY_COLORS")): 268 ↛ 269line 268 didn't jump to line 269 because the condition on line 268 was never true
269 formatter = ColoredFormatter(format)
270 perf_filter = ColoredPerfFilter()
271 else:
272 formatter = logging.Formatter(format)
273 perf_filter = PerfFilter()
274 werkzeug.serving._log_add_style = False
275 handler.setFormatter(formatter)
276 logging.getLogger().addHandler(handler)
277 logging.getLogger('werkzeug').addFilter(perf_filter)
279 if tools.config['log_db']: 279 ↛ 292line 279 didn't jump to line 292 because the condition on line 279 was always true
280 db_levels = {
281 'debug': logging.DEBUG,
282 'info': logging.INFO,
283 'warning': logging.WARNING,
284 'error': logging.ERROR,
285 'critical': logging.CRITICAL,
286 }
287 postgresqlHandler = PostgreSQLHandler()
288 postgresqlHandler.setLevel(int(db_levels.get(tools.config['log_db_level'], tools.config['log_db_level'])))
289 logging.getLogger().addHandler(postgresqlHandler)
291 # Configure loggers levels
292 pseudo_config = PSEUDOCONFIG_MAPPER.get(tools.config['log_level'], [])
294 logconfig = tools.config['log_handler']
296 logging_configurations = DEFAULT_LOG_CONFIGURATION + pseudo_config + logconfig
297 for logconfig_item in logging_configurations:
298 loggername, level = logconfig_item.strip().split(':')
299 level = getattr(logging, level, logging.INFO)
300 logger = logging.getLogger(loggername)
301 logger.setLevel(level)
303 for logconfig_item in logging_configurations:
304 _logger.debug('logger level set: "%s"', logconfig_item)
307DEFAULT_LOG_CONFIGURATION = [
308 'odoo.http.rpc.request:INFO',
309 'odoo.http.rpc.response:INFO',
310 ':INFO',
311]
312PSEUDOCONFIG_MAPPER = {
313 'debug_rpc_answer': ['odoo:DEBUG', 'odoo.sql_db:INFO', 'odoo.http.rpc:DEBUG'],
314 'debug_rpc': ['odoo:DEBUG', 'odoo.sql_db:INFO', 'odoo.http.rpc.request:DEBUG'],
315 'debug': ['odoo:DEBUG', 'odoo.sql_db:INFO'],
316 'debug_sql': ['odoo.sql_db:DEBUG'],
317 'info': [],
318 'runbot': ['odoo:RUNBOT', 'werkzeug:WARNING'],
319 'warn': ['odoo:WARNING', 'werkzeug:WARNING'],
320 'error': ['odoo:ERROR', 'werkzeug:ERROR'],
321 'critical': ['odoo:CRITICAL', 'werkzeug:CRITICAL'],
322}
324logging.RUNBOT = 25
325logging.addLevelName(logging.RUNBOT, "INFO") # displayed as info in log
326IGNORE = {
327 'Comparison between bytes and int', # a.foo != False or some shit, we don't care
328}
329def showwarning_with_traceback(message, category, filename, lineno, file=None, line=None):
330 if category is BytesWarning and message.args[0] in IGNORE:
331 return
333 # find the stack frame matching (filename, lineno)
334 filtered = []
335 for frame in traceback.extract_stack():
336 if frame.name == '__call__' and frame.filename.endswith('/odoo/http.py'):
337 # we don't care about the frames above our wsgi entrypoint
338 filtered.clear()
339 if 'importlib' not in frame.filename:
340 filtered.append(frame)
341 if frame.filename == filename and frame.lineno == lineno:
342 break
343 return showwarning(
344 message, category, filename, lineno,
345 file=file,
346 line=''.join(traceback.format_list(filtered))
347 )
349def runbot(self, message, *args, **kws):
350 self.log(logging.RUNBOT, message, *args, **kws)
351logging.Logger.runbot = runbot