diff --git a/addons/test_mail/tests/test_performance.py b/addons/test_mail/tests/test_performance.py index 239fdf8e470..ad499e32a2d 100644 --- a/addons/test_mail/tests/test_performance.py +++ b/addons/test_mail/tests/test_performance.py @@ -1,7 +1,7 @@ # -*- coding: utf-8 -*- # Part of Odoo. See LICENSE file for full copyright and licensing details. -import base64 +from contextlib import nullcontext from odoo.addons.base.tests.common import TransactionCaseWithUserDemo from odoo.addons.mail.tests.common import MailCommon @@ -1197,8 +1197,8 @@ class TestMailHeavyPerformancePost(BaseMailPerformance): ('attach tuple 3', "attachement tupple content 3", {'cid': 'cid2'}), ] attachments = self.env['ir.attachment'].with_user(self.env.user).create(self.test_attachments_vals) - with self.assertQueryCount(employee=49): - self.cr.sql_log = self.warm and self.cr.sql_log_count + enable_logging = self.cr._enable_logging() if self.warm else nullcontext() + with self.assertQueryCount(employee=49), enable_logging: record_container.with_context({}).message_post( body='

Test body

', subject='Test Subject', @@ -1212,7 +1212,6 @@ class TestMailHeavyPerformancePost(BaseMailPerformance): model_description=False, mail_auto_delete=True ) - self.cr.sql_log = False new_message = record_container.message_ids[0] self.assertEqual(attachments.mapped('res_model'), [record_container._name for i in range(3)]) self.assertEqual(attachments.mapped('res_id'), [record_container.id for i in range(3)]) diff --git a/odoo/addons/base/tests/test_db_cursor.py b/odoo/addons/base/tests/test_db_cursor.py index 1edaf62c766..8492026a7dd 100644 --- a/odoo/addons/base/tests/test_db_cursor.py +++ b/odoo/addons/base/tests/test_db_cursor.py @@ -4,6 +4,7 @@ import logging from functools import partial import psycopg2 +from psycopg2.extensions import ISOLATION_LEVEL_REPEATABLE_READ import odoo from odoo.sql_db import TestCursor @@ -41,6 +42,10 @@ class TestRealCursor(BaseCase): cr.close() cr.close() + def test_transaction_isolation_cursor(self): + with registry().cursor() as cr: + self.assertEqual(cr.connection.isolation_level, ISOLATION_LEVEL_REPEATABLE_READ) + class TestTestCursor(common.TransactionCase): def setUp(self): super().setUp() diff --git a/odoo/addons/base/tests/test_ir_sequence.py b/odoo/addons/base/tests/test_ir_sequence.py index e9a3b97bbf7..cddef73012c 100644 --- a/odoo/addons/base/tests/test_ir_sequence.py +++ b/odoo/addons/base/tests/test_ir_sequence.py @@ -9,6 +9,7 @@ import psycopg2.errorcodes import odoo from odoo.tests import common from odoo.tests.common import BaseCase +from odoo.tools.misc import mute_logger ADMIN_USER_ID = common.ADMIN_USER_ID @@ -85,13 +86,13 @@ class TestIrSequenceNoGap(BaseCase): n = env['ir.sequence'].next_by_code('test_sequence_type_2') self.assertTrue(n) + @mute_logger('odoo.sql_db') def test_ir_sequence_draw_twice_no_gap(self): """ Try to draw a number from two transactions. This is expected to not work. """ with environment() as env0: with environment() as env1: - env1.cr._default_log_exceptions = False # Prevent logging a traceback # NOTE: The error has to be an OperationalError # s.t. the automatic request retry (service/model.py) works. with self.assertRaises(psycopg2.OperationalError) as e: diff --git a/odoo/sql_db.py b/odoo/sql_db.py index 3f82a6c263c..45917e22763 100644 --- a/odoo/sql_db.py +++ b/odoo/sql_db.py @@ -8,45 +8,42 @@ the database, *not* a database abstraction toolkit. Database abstraction is what the ORM does, in fact. """ -from contextlib import contextmanager -from datetime import timedelta, datetime -import itertools import logging import os -import time +import re import threading +import time import uuid import warnings - +from contextlib import contextmanager +from datetime import datetime, timedelta from inspect import currentframe + import psycopg2 -import psycopg2.extras import psycopg2.extensions +import psycopg2.extras from psycopg2.extensions import ISOLATION_LEVEL_AUTOCOMMIT, ISOLATION_LEVEL_READ_COMMITTED, ISOLATION_LEVEL_REPEATABLE_READ from psycopg2.pool import PoolError from psycopg2.sql import SQL, Identifier from werkzeug import urls +from . import tools from .tools.func import frame_codeinfo, locked psycopg2.extensions.register_type(psycopg2.extensions.UNICODE) +def undecimalize(value, cr): + if value is None: + return None + return float(value) + +psycopg2.extensions.register_type(psycopg2.extensions.new_type((700, 701, 1700), 'float', undecimalize)) + _logger = logging.getLogger(__name__) _logger_conn = _logger.getChild("connection") real_time = time.time.__call__ # ensure we have a non patched time for query times when using freezegun -def undecimalize(symb, cr): - if symb is None: - return None - return float(symb) - -psycopg2.extensions.register_type(psycopg2.extensions.new_type((700, 701, 1700,), 'float', undecimalize)) - - -from . import tools - -import re re_from = re.compile('.* from "?([a-zA-Z_0-9]+)"? .*$') re_into = re.compile('.* into "?([a-zA-Z_0-9]+)"? .*$') @@ -225,13 +222,7 @@ class Cursor(BaseCursor): As a result of the above, we have selected ``REPEATABLE READ`` as the default transaction isolation level for OpenERP cursors, as it will be mapped to the desired ``snapshot isolation`` level for - all supported PostgreSQL version (8.3 - 9.x). - - Note: up to psycopg2 v.2.4.2, psycopg2 itself remapped the repeatable - read level to serializable before sending it to the database, so it would - actually select the new serializable mode on PostgreSQL 9.1. Make - sure you use psycopg2 v2.4.2 or newer if you use PostgreSQL 9.1 and - the performance hit is a concern for you. + all supported PostgreSQL version (>10). .. attribute:: cache @@ -246,31 +237,28 @@ class Cursor(BaseCursor): """ IN_MAX = 1000 # decent limit on size of IN queries - guideline = Oracle limit - def __init__(self, pool, dbname, dsn, serialized=True): + def __init__(self, pool, dbname, dsn, **kwargs): super().__init__() - + if 'serialized' in kwargs: + warnings.warn("Since 16.0, 'serialized' parameter is not used anymore.", DeprecationWarning, 2) + assert kwargs.keys() <= {'serialized'} self.sql_from_log = {} self.sql_into_log = {} # default log level determined at cursor creation, could be # overridden later for debugging purposes - self.sql_log = _logger.isEnabledFor(logging.DEBUG) - self.sql_log_count = 0 # avoid the call of close() (by __del__) if an exception - # is raised by any of the following initialisations + # is raised by any of the following initializations self._closed = True self.__pool = pool self.dbname = dbname - # Whether to enable snapshot isolation level for this cursor. - # see also the docstring of Cursor. - self._serialized = serialized self._cnx = pool.borrow(dsn) self._obj = self._cnx.cursor() - if self.sql_log: + if _logger.isEnabledFor(logging.DEBUG): self.__caller = frame_codeinfo(currentframe(), 2) else: self.__caller = False @@ -278,18 +266,19 @@ class Cursor(BaseCursor): # See the docstring of this class. self.connection.set_isolation_level(ISOLATION_LEVEL_REPEATABLE_READ) - self._default_log_exceptions = True - self.cache = {} self._now = None def __build_dict(self, row): return {d.name: row[i] for i, d in enumerate(self._obj.description)} + def dictfetchone(self): row = self._obj.fetchone() return row and self.__build_dict(row) + def dictfetchmany(self, size): return [self.__build_dict(row) for row in self._obj.fetchmany(size)] + def dictfetchall(self): return [self.__build_dict(row) for row in self._obj.fetchall()] @@ -312,28 +301,28 @@ class Cursor(BaseCursor): encoding = psycopg2.extensions.encodings[self.connection.encoding] return self._obj.mogrify(query, params).decode(encoding, 'replace') - def execute(self, query, params=None, log_exceptions=None): + def execute(self, query, params=None, log_exceptions=True): global sql_counter if params and not isinstance(params, (tuple, list, dict)): # psycopg2's TypeError is not clear if you mess up the params raise ValueError("SQL query parameters should be a tuple, list or dict; got %r" % (params,)) - if self.sql_log: - _logger.debug("query: %s", self._format(query, params)) + _logger.debug("query: %s", self._format(query, params)) + start = real_time() try: params = params or None res = self._obj.execute(query, params) except Exception as e: - if self._default_log_exceptions if log_exceptions is None else log_exceptions: + if log_exceptions: _logger.error("bad query: %s\nERROR: %s", tools.ustr(self._obj.query or query), e) raise + delay = real_time() - start # simple query count is always computed self.sql_log_count += 1 sql_counter += 1 - delay = (real_time() - start) current_thread = threading.current_thread() if hasattr(current_thread, 'query_count'): current_thread.query_count += 1 @@ -343,8 +332,8 @@ class Cursor(BaseCursor): for hook in getattr(current_thread, 'query_hooks', ()): hook(self, query, params, start, delay) - # advanced stats only if sql_log is enabled - if self.sql_log: + # advanced stats only if logging.DEBUG is enabled + if _logger.isEnabledFor(logging.DEBUG): delay *= 1E6 query_lower = self._obj.query.decode().lower() @@ -368,7 +357,7 @@ class Cursor(BaseCursor): def print_log(self): global sql_counter - if not self.sql_log: + if not _logger.isEnabledFor(logging.DEBUG): return def process(type): sqllogs = {'from': self.sql_from_log, 'into': self.sql_into_log} @@ -387,7 +376,6 @@ class Cursor(BaseCursor): process('from') process('into') self.sql_log_count = 0 - self.sql_log = False @contextmanager def _enable_logging(self): @@ -395,14 +383,12 @@ class Cursor(BaseCursor): Updates the logger in-place, so not thread-safe. """ - previous, self.sql_log = self.sql_log, True level = _logger.level _logger.setLevel(logging.DEBUG) try: yield finally: _logger.setLevel(level) - self.sql_log = previous def close(self): if not self._closed: @@ -414,7 +400,7 @@ class Cursor(BaseCursor): del self.cache - # advanced stats only if sql_log is enabled + # advanced stats only at logging.DEBUG level self.print_log() self._obj.close() @@ -435,8 +421,7 @@ class Cursor(BaseCursor): self._cnx.leaked = True else: chosen_template = tools.config['db_template'] - templates_list = tuple(set(['template0', 'template1', 'postgres', chosen_template])) - keep_in_pool = self.dbname not in templates_list + keep_in_pool = self.dbname not in ('template0', 'template1', 'postgres', chosen_template) self.__pool.give_back(self._cnx, keep_in_pool=keep_in_pool) def autocommit(self, on): @@ -447,10 +432,7 @@ class Cursor(BaseCursor): if on: isolation_level = ISOLATION_LEVEL_AUTOCOMMIT else: - isolation_level = \ - ISOLATION_LEVEL_REPEATABLE_READ \ - if self._serialized \ - else ISOLATION_LEVEL_READ_COMMITTED + isolation_level = ISOLATION_LEVEL_REPEATABLE_READ if self._serialized else ISOLATION_LEVEL_READ_COMMITTED self._cnx.set_isolation_level(isolation_level) def commit(self): @@ -701,13 +683,16 @@ class Connection(object): self.dsn = dsn self.__pool = pool - def cursor(self, serialized=True): - cursor_type = serialized and 'serialized ' or '' + def cursor(self, **kwargs): + if 'serialized' in kwargs: + warnings.warn("Since 16.0, 'serialized' parameter is deprecated", DeprecationWarning, 2) + cursor_type = kwargs.pop('serialized', True) and 'serialized ' or '' _logger.debug('create %scursor to %r', cursor_type, self.dsn) - return Cursor(self.__pool, self.dbname, self.dsn, serialized=serialized) + return Cursor(self.__pool, self.dbname, self.dsn) - # serialized_cursor is deprecated - cursors are serialized by default - serialized_cursor = cursor + def serialized_cursor(self, **kwargs): + warnings.warn("Since 16.0, 'serialized_cursor' is deprecated, use `cursor` instead", DeprecationWarning, 2) + return self.cursor(**kwargs) def __bool__(self): raise NotImplementedError()