Jobs are executed multiple times if scheduled in the same transaction using with_delay()

[laithfawwaz]

Summary: When calling with_delay() multiple times within the same transaction (i.e., before env.cr.commit()), the queue_job system enqueues and executes each job multiple times based on its position in the list. This results in unintended duplicate executions.

Steps to Reproduce:

record.with_delay().write({})  # Expected: 1 execution, Actual: runs once
record.with_delay().write({})  # Expected: 1 execution, Actual: runs twice
record.with_delay().write({})  # Expected: 1 execution, Actual: runs three times
env.cr.commit()

Expected Behavior: Each call to with_delay() should schedule exactly one job to be run after commit.

Actual Behavior Each job appears to be executed multiple times, depending on how many prior with_delay() calls were made in the same transaction. You can observe this by the current retry count on the job record — even though no exceptions are raised that would normally trigger retries.

Environment: Odoo Version: Odoo 17.0+e-20240201 (Enterprise Edition)

[laithfawwaz]

for example this

<Job 3248304e-3b54-48f2-be16-663ff78271d6, priority:10>
>>> self.with_delay().write({})
<Job 93b1fa16-41cc-4fd8-9933-98e4237624b4, priority:10>
>>> env.cr.commit()

I got this logs

2025-05-13 18:02:09,805 72 INFO ? odoo.addons.queue_job.jobrunner.runner: asking Odoo to run job 3248304e-3b54-48f2-be16-663ff78271d6 on db odoo_care_04 

2025-05-13 18:02:09,808 72 INFO ? odoo.addons.queue_job.jobrunner.runner: asking Odoo to run job 93b1fa16-41cc-4fd8-9933-98e4237624b4 on db odoo_care_04 
2025-05-13 18:02:14,866 72 INFO ? odoo.addons.queue_job.jobrunner.runner: asking Odoo to run job 3248304e-3b54-48f2-be16-663ff78271d6 on db odoo_care_04 

Note that for job #1 ran twice

[sbidoul]

That's surprising. Can you provide debug level log for odoo.addons.queue_job for your reproducer?

[laithfawwaz]

This is my commands

>>> self.with_delay().write({})
<Job bd97594e-a1ed-4cdb-b412-95c1d8b519ee, priority:10>
>>> self.with_delay().write({})
<Job e6292452-7eb4-4182-8c19-0522472d5e21, priority:10>
>>> self.with_delay().write({})
<Job a24ad001-0b80-4a32-bbce-b2c1b404b355, priority:10>
>>> self.with_delay().write({})
<Job ed134922-cf28-4db9-a00f-ff94c154f92e, priority:10>
>>> env.cr.commit()

and this is the debug logs

2025-05-14 15:20:02,599 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job 6cc1c074-296e-4288-bf94-20c7d37e5630 marked done in channel root(C:6,Q:0,R:0,F:132057) 
2025-05-14 15:20:02,600 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 60.00 sec 
2025-05-14 15:20:22,396 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job a24ad001-0b80-4a32-bbce-b2c1b404b355 marked pending in channel root(C:6,Q:2,R:0,F:132057) 
2025-05-14 15:20:22,399 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job e6292452-7eb4-4182-8c19-0522472d5e21 marked pending in channel root(C:6,Q:3,R:0,F:132057) 
2025-05-14 15:20:22,402 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job bd97594e-a1ed-4cdb-b412-95c1d8b519ee marked pending in channel root(C:6,Q:4,R:0,F:132057) 
2025-05-14 15:20:22,403 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job bd97594e-a1ed-4cdb-b412-95c1d8b519ee marked running in channel root(C:6,Q:3,R:1,F:132057) 
2025-05-14 15:20:22,403 69 INFO ? odoo.addons.queue_job.jobrunner.runner: asking Odoo to run job bd97594e-a1ed-4cdb-b412-95c1d8b519ee on db odoo_care_04 
2025-05-14 15:20:22,408 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job e6292452-7eb4-4182-8c19-0522472d5e21 marked running in channel root(C:6,Q:2,R:2,F:132057) 
2025-05-14 15:20:22,411 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job a24ad001-0b80-4a32-bbce-b2c1b404b355 marked running in channel root(C:6,Q:1,R:3,F:132057) 
2025-05-14 15:20:22,411 69 INFO ? odoo.addons.queue_job.jobrunner.runner: asking Odoo to run job a24ad001-0b80-4a32-bbce-b2c1b404b355 on db odoo_care_04 
2025-05-14 15:20:22,414 69 INFO ? odoo.addons.queue_job.jobrunner.runner: asking Odoo to run job ed134922-cf28-4db9-a00f-ff94c154f92e on db odoo_care_04 
2025-05-14 15:20:22,428 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 60.00 sec 
2025-05-14 15:20:22,440 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 60.00 sec 
2025-05-14 15:20:22,442 52 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job ed134922-cf28-4db9-a00f-ff94c154f92e, priority:10> started 
2025-05-14 15:20:22,445 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 60.00 sec 
2025-05-14 15:20:22,463 50 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job a24ad001-0b80-4a32-bbce-b2c1b404b355, priority:10> done 
2025-05-14 15:20:22,464 52 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job ed134922-cf28-4db9-a00f-ff94c154f92e, priority:10> OperationalError, postponed 
2025-05-14 15:20:22,467 50 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job a24ad001-0b80-4a32-bbce-b2c1b404b355, priority:10> enqueue depends done 
2025-05-14 15:20:22,467 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 60.00 sec 
2025-05-14 15:20:22,475 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job ed134922-cf28-4db9-a00f-ff94c154f92e properties changed, rescheduling it 
2025-05-14 15:20:22,476 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job ed134922-cf28-4db9-a00f-ff94c154f92e marked pending in channel root(C:6,Q:1,R:2,F:132057) 
2025-05-14 15:20:22,476 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 4.99 sec 
2025-05-14 15:20:22,510 64 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job bd97594e-a1ed-4cdb-b412-95c1d8b519ee, priority:10> started 
2025-05-14 15:20:22,511 62 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job e6292452-7eb4-4182-8c19-0522472d5e21, priority:10> started 
2025-05-14 15:20:22,516 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 4.95 sec 
2025-05-14 15:20:22,535 64 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job bd97594e-a1ed-4cdb-b412-95c1d8b519ee, priority:10> done 
2025-05-14 15:20:22,536 62 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job e6292452-7eb4-4182-8c19-0522472d5e21, priority:10> OperationalError, postponed 
2025-05-14 15:20:22,538 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job bd97594e-a1ed-4cdb-b412-95c1d8b519ee marked done in channel root(C:6,Q:1,R:1,F:132057) 
2025-05-14 15:20:22,538 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 4.93 sec 
2025-05-14 15:20:22,539 64 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job bd97594e-a1ed-4cdb-b412-95c1d8b519ee, priority:10> enqueue depends done 
2025-05-14 15:20:22,546 62 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job e6292452-7eb4-4182-8c19-0522472d5e21, priority:10> postponed 
2025-05-14 15:20:22,548 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job e6292452-7eb4-4182-8c19-0522472d5e21 properties changed, rescheduling it 
2025-05-14 15:20:22,548 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job e6292452-7eb4-4182-8c19-0522472d5e21 marked pending in channel root(C:6,Q:2,R:0,F:132057) 
2025-05-14 15:20:22,549 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 4.92 sec 
2025-05-14 15:20:27,472 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job ed134922-cf28-4db9-a00f-ff94c154f92e marked running in channel root(C:6,Q:1,R:1,F:132057) 
2025-05-14 15:20:27,472 69 INFO ? odoo.addons.queue_job.jobrunner.runner: asking Odoo to run job ed134922-cf28-4db9-a00f-ff94c154f92e on db odoo_care_04 
2025-05-14 15:20:27,478 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job ed134922-cf28-4db9-a00f-ff94c154f92e properties changed, rescheduling it 
2025-05-14 15:20:27,478 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job ed134922-cf28-4db9-a00f-ff94c154f92e marked running in channel root(C:6,Q:1,R:1,F:132057) 
2025-05-14 15:20:27,479 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 0.06 sec 
2025-05-14 15:20:27,540 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job e6292452-7eb4-4182-8c19-0522472d5e21 marked running in channel root(C:6,Q:0,R:2,F:132057) 
2025-05-14 15:20:27,540 69 INFO ? odoo.addons.queue_job.jobrunner.runner: asking Odoo to run job e6292452-7eb4-4182-8c19-0522472d5e21 on db odoo_care_04 
2025-05-14 15:20:27,546 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job e6292452-7eb4-4182-8c19-0522472d5e21 marked running in channel root(C:6,Q:0,R:2,F:132057) 
2025-05-14 15:20:27,547 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 60.00 sec 
2025-05-14 15:20:27,567 50 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job e6292452-7eb4-4182-8c19-0522472d5e21, priority:10> started 
2025-05-14 15:20:27,570 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 60.00 sec 
2025-05-14 15:20:27,580 50 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job e6292452-7eb4-4182-8c19-0522472d5e21, priority:10> done 
2025-05-14 15:20:27,580 50 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job e6292452-7eb4-4182-8c19-0522472d5e21, priority:10> enqueue depends started 
2025-05-14 15:20:27,582 60 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job ed134922-cf28-4db9-a00f-ff94c154f92e, priority:10> started 
2025-05-14 15:20:27,583 50 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job e6292452-7eb4-4182-8c19-0522472d5e21, priority:10> enqueue depends done 

2025-05-14 15:20:27,587 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 60.00 sec 
2025-05-14 15:20:27,607 60 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job ed134922-cf28-4db9-a00f-ff94c154f92e, priority:10> done 
2025-05-14 15:20:27,607 60 DEBUG odoo_care_04 odoo.addons.queue_job.controllers.main: <Job ed134922-cf28-4db9-a00f-ff94c154f92e, priority:10> enqueue depends started 
2025-05-14 15:20:27,609 69 DEBUG ? odoo.addons.queue_job.jobrunner.channels: job ed134922-cf28-4db9-a00f-ff94c154f92e marked done in channel root(C:6,Q:0,R:0,F:132057) 
2025-05-14 15:20:27,610 69 DEBUG ? odoo.addons.queue_job.jobrunner.runner: select() timeout: 60.00 sec 

You can notice that job # 2 was executed twice

[laithfawwaz]

I think I got it, It seems because Operational Error which means a DB error happened such as Postgres could not serialize access due to concurrent update

[sarthakmetazone]

@laithfawwaz , how you resolved, I am also getting the same?