Skip to content

[fix] Store background task timestamps as naive UTC - #5142

Open
theluckystrike wants to merge 1 commit into
Ericsson:masterfrom
theluckystrike:fix/codechecker-task-utc-timestamps
Open

theluckystrike wants to merge 1 commit into
Ericsson:masterfrom
theluckystrike:fix/codechecker-task-utc-timestamps

Conversation

@theluckystrike

Copy link
Copy Markdown

Fixes #5106

CodeChecker store on the async path fails with a false TaskTimeoutError when the server's PostgreSQL session runs in a non-UTC timezone. The background task columns (enqueued_at, started_at, finished_at, last_seen_at) are timezone-less DateTime, but BackgroundTask writes aware datetime.now(timezone.utc) values. psycopg2 sends those as timestamptz, and PostgreSQL stores them as local wall time. _db_timestamp_to_posix_epoch then reads that local time as UTC, so in America/Denver every heartbeat lands 6 hours in the past and the client gives up on its first poll while the task completes on the server.

The fix stores naive UTC, which matches the column type and what SQLite and pg8000 already store.

  • config_db_model.py adds _utc_now() (aware UTC now, tzinfo dropped) and uses it for the six task timestamp assignments.
  • api/tasks.py makes _posix_epoch_to_db_timestamp return naive UTC too, so the getTasks time filters compare like with like.

There's no schema change and no migration. Rows written before the upgrade keep their old values, and they belong to tasks that already terminated. Nothing reads them to decide a timeout. CI's PostgreSQL service runs in UTC, which is why the matrix never caught it.

New unit tests in web/server/tests/unit/test_background_task_timestamps.py check that every task transition stores a naive UTC value and that the epoch conversion round trips. On master with only the test file added they fail, and with the fix they pass.

$ cd web && REPO_ROOT=.. BUILD_DIR=../build pytest -v server/tests/unit/test_background_task_timestamps.py
master 29100d4:
  ...test_abandoned_task_stores_naive_utc FAILED
  ...test_epoch_db_timestamp_round_trip FAILED
  ...test_task_transitions_store_naive_utc FAILED
  E   AssertionError: datetime.timezone.utc is not None
  3 failed, 1 warning in 1.95s
this branch:
  3 passed, 1 warning in 0.18s

$ make -C web test_unit_server
64 passed, 1 warning in 2.53s
$ make -k pycodestyle pylint
exit 0, every pylint run rated 10.00/10

End to end I ran a server built with BUILD_UI_DIST=NO make package against PostgreSQL 16.13 with timezone = 'America/Denver' and CODECHECKER_DB_DRIVER=psycopg2, then stored a one file clangsa analysis.

$ CodeChecker store reports -j 1 -n e2e --url http://localhost:8765/Default
master 29100d4:
  TaskTimeoutError: Task '5a00f8d8...' is still 'RUNNING', but did not have
  any progress for '6:00:00.411283' (21600.411283 seconds)!
  store_exit=1
  background_tasks: last_seen_at 06:58:28 while UTC now is 12:58:28;
  the task reached 'completed' on the server right after
this branch:
  Storing the reports finished successfully.
  store_exit=0
  background_tasks: completed, last_seen_at 12:59:27, UTC now 12:59:33

$ CodeChecker cmd serverside-tasks --url http://localhost:8765 --enqueued-after 2026:10:7:12:59:0 --output json
one task, "enqueuedAt": "2026-10-07 12:59:27"
$ CodeChecker cmd serverside-tasks --url http://localhost:8765 --enqueued-after 2026:10:7:13:0:0 --output json
[]

The same store against a SQLite product on this branch also exits 0. I didn't run make -C web test_matrix_psql_psycopg2 or the functional suites locally. CI runs them, and its PostgreSQL runs in UTC, so the check above is the one that covers this bug.

Fixes Ericsson#5106.

The enqueued_at, started_at, finished_at and last_seen_at columns of
BackgroundTask are timezone-less DateTime columns, but
config_db_model.py assigned aware datetime.now(timezone.utc) values.
psycopg2 sends an aware value as timestamptz and PostgreSQL casts it
to timestamp in the session TimeZone, so a database in America/Denver
stored Denver wall time. _db_timestamp_to_posix_epoch reads the value
back as UTC, so lastHeartbeatEpoch came out 21600 seconds in the past
and CodeChecker store raised a false TaskTimeoutError while the task
completed on the server. pg8000 and SQLite keep the UTC wall time,
and the CI PostgreSQL service runs in UTC, so CI didn't show it.

I added _utc_now() in config_db_model.py, which returns the current
UTC time without tzinfo, and use it for the six task timestamp
assignments. _posix_epoch_to_db_timestamp in api/tasks.py returns naive
UTC as well, so the getTasks time filters compare like with like.
Column types and migrations stay unchanged. Rows written before this
change keep their old values. Those rows belong to tasks that already
terminated, nothing reads them to decide a timeout, and every new task
row is correct, so there's no migration.

On base 29100d4 with only the new test file added, all three new
tests fail on the tzinfo check

    $ cd web && REPO_ROOT=.. BUILD_DIR=../build \
        pytest -v server/tests/unit/test_background_task_timestamps.py
    ...test_abandoned_task_stores_naive_utc FAILED
    ...test_epoch_db_timestamp_round_trip FAILED
    ...test_task_transitions_store_naive_utc FAILED
    E   AssertionError: datetime.timezone.utc is not None
    3 failed, 1 warning in 1.95s

With the fix they pass

    3 passed, 1 warning in 0.18s

Server unit suite and the CI linters on the fixed tree

    $ make -C web test_unit_server
    64 passed, 1 warning in 2.53s
    $ make -k pycodestyle pylint
    exit 0, every pylint run rated 10.00/10

End to end on macOS with PostgreSQL 16.13, timezone America/Denver,
CODECHECKER_DB_DRIVER=psycopg2, a server built with
BUILD_UI_DIST=NO make package and a one file clangsa analysis

    $ CodeChecker store reports -j 1 -n e2e \
        --url http://localhost:8765/Default
    base 29100d4
      TaskTimeoutError: Task '5a00f8d8...' is still 'RUNNING', but did
      not have any progress for '6:00:00.411283' (21600.411283 seconds)!
      store_exit=1
      background_tasks status running, last_seen_at 06:58:28,
      UTC now 12:58:28, the task completed on the server right after
    with the fix
      Storing the reports finished successfully.
      store_exit=0
      background_tasks status completed, last_seen_at 12:59:27,
      UTC now 12:59:33

    $ CodeChecker cmd serverside-tasks --url http://localhost:8765 \
        --enqueued-after 2026:10:7:12:59:0 --output json
    one task, enqueuedAt 2026-10-07 12:59:27
    $ ... --enqueued-after 2026:10:7:13:0:0 --output json
    []

The same store against a SQLite product with the fix also finished
with exit 0.

Not run are make -C web test_matrix_psql_psycopg2 and the functional
suites. CI runs them, and its PostgreSQL service runs in UTC, so the
end to end check above is the one that covers this bug.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

CodeChecker store fails with false "TaskTimeoutError" when server is not running in UTC timezone

1 participant