Skip to content

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

Merged
dimitri-yatsenko merged 1 commit into
maint/2.3from
fix/jobs-completed-time-precision-2.3
Oct 21, 2026
Merged

dimitri-yatsenko merged 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
@dimitri-yatsenko

Copy link
Copy Markdown
Member Author

Merging on the strength of #1613's review: this is the same commit, cherry-picked to maint/2.3 for v2.3.5, and its CI passes.

@dimitri-yatsenko
dimitri-yatsenko merged commit 821253d into maint/2.3 Oct 21, 2026
9 checks passed
@dimitri-yatsenko
dimitri-yatsenko deleted the fix/jobs-completed-time-precision-2.3 branch October 21, 2026 15:40

@MilagrosMarin MilagrosMarin left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM. The diff matches #1613 line for line, the *_by_backend fixtures the new tests use are on maint/2.3, and CI is green.

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.

2 participants