Skip to content

fix(#355): keep the job timer intact through the download stage - #357

Open
tino097 wants to merge 1 commit into
mainfrom
355-elapsed-time-timer
Open

tino097 wants to merge 1 commit into
mainfrom
355-elapsed-time-timer

Conversation

@tino097

@tino097 tino097 commented Oct 28, 2026

Copy link
Copy Markdown
Member

Fixes #355

Proposed fixes:

Every successful job ended with DATAPUSHER+ v3.0.0a0 JOB DONE! Total elapsed time: 1,792,617,918.06 seconds. for a two second job, and the Prefect path reported the same value as duration_seconds.

pipeline_core stamps context.timer_start with time.time(), and local_runner._log_done plus five places in prefect_flow.py subtract it from time.time(). DownloadStage.process reassigned the same field to time.perf_counter() to time the fetch and never restored it, so the final subtraction was roughly the Unix epoch.

The download stage now keeps a local fetch_start for its "Fetched ... in N seconds" line and leaves context.timer_start alone. The readers are unchanged.

Check Observed result
pytest tests/test_issue_355_elapsed_time.py before the fix 2 failed; the assertion shows the 1,792,617,916 second figure
pytest tests/test_issue_355_elapsed_time.py after the fix 2 passed
pytest tests --ignore=tests/integration --ignore=tests/js (with --ckan-ini) 344 passed, 1 skipped
flake8 --extend-ignore=E501 on download.py and the test file clean
  • No field was added to ProcessingContext. A local variable is enough; the fetch duration is only used for the log line in the same method.
  • The five readers in prefect_flow.py and the one in local_runner.py are untouched. They were computing the right thing against a wrong start value.

🤖 Generated with Claude Code

pipeline_core stamps context.timer_start with time.time() and the JOB
DONE line (plus the Prefect duration_seconds) subtract it from
time.time(). DownloadStage reassigned the same field to perf_counter()
to time the fetch, so every job reported an elapsed time of roughly the
Unix epoch.

Use a local perf_counter start for the fetch log line and leave
context.timer_start alone. Regression test asserts the stamp survives
the stage and the total elapsed stays in seconds.

Co-Authored-By: Claude Fable 5.1 <noreply@anthropic.com>
@tino097

tino097 commented Oct 28, 2026

Copy link
Copy Markdown
Member Author

The failing unit and integration checks here die on import prefect (TypeError: Body() got an unexpected keyword argument 'min_items', FastAPI 0.155+ vs Prefect 3.7.8) before any test runs. That is #353, not this change; main fails the same way. #358 pins fastapi<0.155; once it lands, rerunning the checks here should go green.

@tino097
tino097 requested a review from jqnatividad October 28, 2026 18:10
@codacy-production

Copy link
Copy Markdown

Up to standards ✅

🟢 Issues 0 issues

Results:
0 new issues

View in Codacy

🟢 Metrics 4 complexity · 0 duplication

Metric Results
Complexity 4
Duplication 0

View in Codacy

AI Reviewer: first review requested successfully. AI can make mistakes. Always validate suggestions.

Run reviewer

TIP This summary will be updated as you push new changes.

@codacy-production codacy-production Bot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

Pull Request Overview

✅ No blocking issues noticed

No blocking findings were identified.

Test suggestions

  • A successful download preserves context.timer_start.
  • Elapsed time calculated after the download is a realistic duration rather than an epoch-scale value.
  • The fetch-completion log uses the local fetch timer and reports the expected duration.
  • Timer preservation is verified when deduplication causes an early return.
  • Final duration behavior is verified through the local runner and Prefect duration readers.
Prompt proposal for missing tests
Consider implementing these tests if applicable:
1. The fetch-completion log uses the local fetch timer and reports the expected duration.
2. Timer preservation is verified when deduplication causes an early return.
3. Final duration behavior is verified through the local runner and Prefect duration readers.

TIP Improve review quality by adding custom instructions
TIP How was this review? Give us feedback

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.

"Total elapsed time" in the JOB DONE line is ~1.79 billion seconds (perf_counter overwrites the time.time() start)

1 participant