server-tools icon indicating copy to clipboard operation
server-tools copied to clipboard

[18.0][FIX] auditlog: Enabling read logging raises ReadOnlySqlTransaction error.

Open amh-mw opened this issue 3 months ago • 9 comments

Odoo 18 introduced read-only database cursors ^1. Enabling auditlog read logging causes each read-only request to raise a ReadOnlyTransaction error, which is handled internally by Odoo by retrying the request with a writable cursor. This seems guaranteed to cause slowness or repeated side effects.

ERROR odoo odoo.sql_db: bad query: b'INSERT INTO "auditlog_http_session" ("create_date", "create_uid", "name", "user_id", "write_date", "write_uid") VALUES (\'2025-09-25 12:41:48.826030\', 2, \'Kr70qQDV58xbpTy0o0mGGciI2XyMFWD39iNZQrKDnRbN-5RPc47W0jh9RliwdMlOqz9aaZD-81htkrF9sWDB\', 2, \'2025-09-25 12:41:48.826030\', 2) RETURNING "id"'
ERROR: cannot execute INSERT in a read-only transaction
 
WARNING odoo odoo.http: cannot execute INSERT in a read-only transaction, retrying with a read/write cursor 
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/odoo/http.py", line 2146, in _transactioning
    return service_model.retrying(func, env=self.env)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/odoo/service/model.py", line 156, in retrying
    result = func()
             ^^^^^^
  File "/usr/lib/python3/dist-packages/odoo/http.py", line 2113, in _serve_ir_http
    response = self.dispatcher.dispatch(rule.endpoint, args)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/odoo/http.py", line 2361, in dispatch
    result = self.request.registry['ir.http']._dispatch(endpoint)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/odoo/addons/base/models/ir_http.py", line 333, in _dispatch
    result = endpoint(**request.params)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/odoo/http.py", line 756, in route_wrapper
    result = endpoint(self, *args, **params_ok)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/odoo/addons/web/controllers/dataset.py", line 36, in call_kw
    return call_kw(request.env[model], method, args, kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/odoo/api.py", line 535, in call_kw
    result = getattr(recs, name)(*args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/mnt/extra-addons/oca/server-tools/auditlog/models/rule.py", line 378, in read
    rule_model.sudo().create_logs(
  File "/mnt/extra-addons/oca/server-tools/auditlog/models/rule.py", line 563, in create_logs
    "http_request_id": http_request_model.current_http_request(),
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/mnt/extra-addons/oca/server-tools/auditlog/models/http_request.py", line 63, in current_http_request
    "http_session_id": http_session_model.current_http_session(),
                       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/mnt/extra-addons/oca/server-tools/auditlog/models/http_session.py", line 51, in current_http_session
    httpsession.auditlog_http_session_id = self.create(vals).id
                                           ^^^^^^^^^^^^^^^^^
  File "<decorator-gen-0>", line 2, in create
  File "/usr/lib/python3/dist-packages/odoo/api.py", line 497, in _model_create_multi
    return create(self, [arg])
           ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/odoo/models.py", line 5032, in create
    records = self._create(data_list)
              ^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/odoo/models.py", line 5216, in _create
    cr.execute(SQL(
  File "/usr/lib/python3/dist-packages/odoo/sql_db.py", line 582, in execute
    return self._cursor.execute(*args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3/dist-packages/odoo/sql_db.py", line 357, in execute
    res = self._obj.execute(query, params)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
psycopg2.errors.ReadOnlySqlTransaction: cannot execute INSERT in a read-only transaction

amh-mw avatar Sep 25 '25 12:09 amh-mw

Will you work on a fix?

I could, but I don't have a design in mind.

amh-mw avatar Oct 01 '25 12:10 amh-mw

Would it work to check the readonly attribute of the cursor and then only log a warning? https://github.com/odoo/odoo/blob/18.0/odoo/sql_db.py#L510-L512

StefanRijnhart avatar Oct 01 '25 13:10 StefanRijnhart

Would it work to check the readonly attribute of the cursor and then only log a warning?

I don't believe so. I think it will be necessary to grab a writeable cursor just for audit logging and to reuse that cursor as there could be a large number of audit log writes.

amh-mw avatar Oct 01 '25 13:10 amh-mw

That sounds risky. Would it work to reset the _readonly attribute on the method during patching? https://github.com/odoo/odoo/blob/18.0/odoo/api.py#L436-L446 / https://github.com/odoo/odoo/blob/18.0/addons/web/controllers/dataset.py#L26-L29

StefanRijnhart avatar Oct 01 '25 14:10 StefanRijnhart

It seems that any design is going to contradict the guidance from the commit:

The developers shouldn't open new read/write or read-only cursors
themselves but instead declare their controller endpoints as read/write
or read-only via the new `readonly` argument of `@route`. This new
argument is understood by the HTTP stack which will open its cursor
according to the `@route` spec.

Would it work to reset the _readonly attribute on the method during patching? h

I don't think that helps because the cursor is created according to the @api.readonly marking on the controller method, not the patched model method. A starting point for the design might be inside auditlog.rule.create_logs:

if self.env.cr.readonly:
    with self.env.registry.cursor(readonly=False) as cr:
        env = api.Environment(cr, SUPERUSER_ID, {})
        return self.with_env(env).create_logs(...)

amh-mw avatar Oct 01 '25 15:10 amh-mw

Another source of inspiration could be how Odoo --log_db logs to a database outside of the main transaction ^1. Spoiler: Plain SQL without models.

amh-mw avatar Oct 01 '25 15:10 amh-mw

I don't think that helps because the cursor is created according to the @api.readonly marking on the controller method, not the patched model method. A starting point for the design might be inside auditlog.rule.create_logs:

The first link in my previous comment shows that what the decorator does is set the _readonly attribute on the method. The controller then iterates over all the overrides and selects a readonly route if the first _readonly attribute it finds is True.

Our patch would be the first method encountered in the controller, so if we set _readonly to False, it wins. This change satisfies the test:

diff --git a/auditlog/models/rule.py b/auditlog/models/rule.py
index 1cbabdfa3..80dbe80c2 100644
--- a/auditlog/models/rule.py
+++ b/auditlog/models/rule.py
@@ -210,6 +210,7 @@ class AuditlogRule(models.Model):
             new_method = self._make_create()
         elif method_name == "read":
             new_method = self._make_read()
+            new_method._readonly = False
         elif method_name == "write":
             new_method = self._make_write()
         elif method_name == "unlink":

StefanRijnhart avatar Oct 01 '25 16:10 StefanRijnhart

Our patch would be the first method encountered in the controller, so if we set _readonly to False, it wins.

Terrific! That covers the most direct case. I've added a second test to see if read logging is encountered for field computation, but it doesn't seem to be. Is that correct? None of my customers use "read" logging, so I don't have any expectation as to what the expected behavior is.

amh-mw avatar Oct 01 '25 17:10 amh-mw

@amh-mw I think that's alright. 'read' logs are not very practical in general I think, so if you are not invested in whatever logging is caused by Odoo internals maybe just leave out the second test. Seems to interfere with the first one as well.

StefanRijnhart avatar Oct 01 '25 18:10 StefanRijnhart