[13.0] Concurrent update access error when eta undefined.

[mads-vkd]

Hi,

Having bit of an issue with using queue_job. Specifically, the job always fails the first time if the eta argument is undefined in the with_delay() call.

I've tied the call to a function that is called on button press:

 def action_update_one(self):
        _logger.info("UPDATE ONE IS RUNNING: ETA 5")
        self.with_delay(priority=3, eta=5, channel='root.module_registry', max_retries=1).update_one_repo()

If I exclude "eta", set it to 0, or the like, I consistently get a concurrency error after the function has been called. In testing, I set a logger after the function call above, and it still failed after that logger, so the function call did go through the 1st time (from what I can tell), but something went wrong after that, so the function was called and completed a 2nd time. Here's a log where ETA is and isn't defined, respectively:

ETA = 1:
2021-08-27 07:03:33,356 30395 INFO redacted odoo.addons.module_registry_github.models.module_registry_module: UPDATE ONE IS RUNNING: ETA 1
2021-08-27 07:03:38,365 30405 INFO ? odoo.addons.queue_job.jobrunner.runner: asking Odoo to run job d4baa186-ddc9-4d48-a085-7403aa28c92d on db redacted
2021-08-27 07:03:38,389 30394 INFO redacted odoo.addons.module_registry_github.models.module_registry_module: ----------- Updating odoo-edi
2021-08-27 07:03:40,869 30394 INFO redacted odoo.addons.module_registry_github.models.module_registry_module: Deleted /home/redacted/tmp/repos/odoo-edi
2021-08-27 07:03:40,883 30394 INFO redacted werkzeug: 127.0.0.1 - - [27/Aug/2021 07:03:40] "GET /queue_job/runjob?db=redacted&job_uuid=d4baa186-ddc9-4d48-a085-7403aa28c92d HTTP/1.1" 200 - 289 0.081 2.428


Undefined ETA:
2021-08-27 07:07:32,130 31199 INFO redacted odoo.addons.module_registry_github.models.module_registry_module: UPDATE ONE IS RUNNING: ETA undefined
2021-08-27 07:07:32,136 31209 INFO ? odoo.addons.queue_job.jobrunner.runner: asking Odoo to run job 0a8fcad3-33f4-4e74-804f-9e699bb70133 on db redacted
2021-08-27 07:07:32,158 31199 INFO redacted odoo.addons.module_registry_github.models.module_registry_module: ----------- Updating odoo-edi
2021-08-27 07:07:34,646 31199 INFO redacted odoo.addons.module_registry_github.models.module_registry_module: Deleted /home/redacted/tmp/repos/odoo-edi
2021-08-27 07:07:34,658 31199 ERROR redacted odoo.sql_db: bad query: UPDATE "module_registry_module" SET "write_uid"=2,"last_update"='2021-08-27 07:07:34.251220',"write_date"=(now() at time zone 'UTC') WHERE id IN (443)
ERROR: could not serialize access due to concurrent update
2021-08-27 07:07:34,664 31199 INFO redacted werkzeug: 127.0.0.1 - - [27/Aug/2021 07:07:34] "GET /queue_job/runjob?db=redacted&job_uuid=0a8fcad3-33f4-4e74-804f-9e699bb70133 HTTP/1.1" 200 - 287 0.083 2.441
2021-08-27 07:07:39,664 31209 INFO ? odoo.addons.queue_job.jobrunner.runner: asking Odoo to run job 0a8fcad3-33f4-4e74-804f-9e699bb70133 on db redacted
2021-08-27 07:07:39,686 31199 INFO redacted odoo.addons.module_registry_github.models.module_registry_module: ----------- Updating odoo-edi
2021-08-27 07:07:42,205 31199 INFO redacted odoo.addons.module_registry_github.models.module_registry_module: Deleted /home/redacted/tmp/repos/odoo-edi
2021-08-27 07:07:42,219 31199 INFO redacted werkzeug: 127.0.0.1 - - [27/Aug/2021 07:07:42] "GET /queue_job/runjob?db=redacted&job_uuid=0a8fcad3-33f4-4e74-804f-9e699bb70133 HTTP/1.1" 200 - 289 0.082 2.466

Note also I actually specify the function with max_retries = 1, but it's actually run twice (also noted in the job view):

I've tried messing around with the configs to see if that makes any difference, as well as just about everything else I can think of, but the only way of "fixing" the issue, is to pass an eta value > 0. In the grand scheme of things not a big deal, but not really desired to have some functions being called twice, when the parameter that can avoid such behaviour isn't required, and standard behaviour actually encourages it to happen.

[guewen]

IIRC, the number of try may ignore the max when the job is retried because of a concurrency error. Do you get this behavior with all the job methods? Or only this one? If so, what is the content of the method executed by the job?

[guewen]

The channel name channel='root.module_registry triggers a doubt. Is the job doing something related to the odoo registry? Such as updating or installing modules? When doing so, odoo would invalidate the registry, which is used by the job mechanic...

[mads-vkd]

As I recall, the error occured on every method I tried, so long as "eta" remained undefined (or 0) in the with_delay() call. The methods in question primarily made use of the Github API to go into a repository, in order to count the lines of code for each of them, and update a new model in Odoo with that data; it's not actually installing or updating any modules, just fetching data and adding it to Odoo for statistical purposes.

[github-actions[bot]]

There hasn't been any activity on this issue in the past 6 months, so it has been marked as stale and it will be closed automatically if no further activity occurs in the next 30 days. If you want this issue to never become stale, please ask a PSC member to apply the "no stale" label.

[github-actions[bot]]

There hasn't been any activity on this issue in the past 6 months, so it has been marked as stale and it will be closed automatically if no further activity occurs in the next 30 days. If you want this issue to never become stale, please ask a PSC member to apply the "no stale" label.