Skip to content

fix(jobs): record completed_time at millisecond precision (2.3) - #1614

Open
dimitri-yatsenko wants to merge 1 commit into
maint/2.3from
fix/jobs-completed-time-precision-2.3
Open

dimitri-yatsenko wants to merge 1 commit into
maint/2.3from
fix/jobs-completed-time-precision-2.3

Conversation

@dimitri-yatsenko

Copy link
Copy Markdown
Member

Backport of #1613 to maint/2.3 for v2.3.5, cherry-picked unchanged.

complete() and error() took completed_time from SELECT CURRENT_TIMESTAMP,
which on MySQL has no fractional seconds, while reserve() writes
reserved_time as CURRENT_TIMESTAMP(3) into the same datetime(3) columns.
A job that finished within the second it was reserved recorded a
completed_time earlier than its reserved_time. Error records carry no
duration, so that difference is the only record of how long a failed job
ran, and it came out negative or up to a second short.

Both now read SELECT CURRENT_TIMESTAMP(3), as reserve() does. populate()
calls them after the make() transaction has been committed or cancelled,
and the PostgreSQL connection runs in autocommit mode, so there the value
is the time of the statement, not the start of an enclosing transaction.

The tests populate three keys through a make() that sleeps 0.15 s, once
succeeding with keep_completed=True and once raising, and check that every
job's completed_time is at least 0.1 s after its reserved_time, on MySQL
and PostgreSQL. Both fail on MySQL without the change.

Fixes #1600.

complete() and error() took completed_time from SELECT CURRENT_TIMESTAMP,
which on MySQL has no fractional seconds, while reserve() writes
reserved_time as CURRENT_TIMESTAMP(3) into the same datetime(3) columns.
A job that finished within the second it was reserved recorded a
completed_time earlier than its reserved_time. Error records carry no
duration, so that difference is the only record of how long a failed job
ran, and it came out negative or up to a second short.

Both now read SELECT CURRENT_TIMESTAMP(3), as reserve() does. populate()
calls them after the make() transaction has been committed or cancelled,
and the PostgreSQL connection runs in autocommit mode, so there the value
is the time of the statement, not the start of an enclosing transaction.

The tests populate three keys through a make() that sleeps 0.15 s, once
succeeding with keep_completed=True and once raising, and check that every
job's completed_time is at least 0.1 s after its reserved_time, on MySQL
and PostgreSQL. Both fail on MySQL without the change.

Closes #1600.

(cherry picked from commit d47ca3b)
@dimitri-yatsenko dimitri-yatsenko added this to the v2.3.5 milestone Oct 17, 2026
@dimitri-yatsenko dimitri-yatsenko added the bug Indicates an unexpected problem or unintended behavior label Oct 17, 2026

This branch has not been deployed

No deployments
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bug Indicates an unexpected problem or unintended behavior

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant