Skip to content

Fix duplicate logs in dbt build when source freshness is enabled#2564

Merged
pankajastro merged 2 commits into
mainfrom
FIX_2558
Apr 16, 2026
Merged

Fix duplicate logs in dbt build when source freshness is enabled#2564
pankajastro merged 2 commits into
mainfrom
FIX_2558

Conversation

@pankajastro
Copy link
Copy Markdown
Contributor

@pankajastro pankajastro commented Apr 16, 2026

In DBT_RUNNER mode, run_dbt_runner appended a new XCom-pushing callback to _dbt_runner_callbacks on every invocation. When source rendering is enabled the producer runs dbt source freshness first (via _run_source_freshness), registering a freshness callback, then runs dbt build which appended a second callback. Both callbacks fired for every event during the build, printing each log line twice.

Fix: skip callback registration when context["_check_source_freshness"] is True. The freshness run's results are captured from target/sources.json afterwards and do not need per-event XCom pushes. Raw JSON stdout is still suppressed via _NullWriter for both paths.

Logs Before changes
Screenshot 2026-04-16 at 4 18 00 PM

Logs After changes
Screenshot 2026-04-16 at 4 18 55 PM

closes: #2558

In DBT_RUNNER mode, run_dbt_runner appended a new XCom-pushing callback
to _dbt_runner_callbacks on every invocation. When source rendering is
enabled the producer runs dbt source freshness first (via
_run_source_freshness), registering a freshness callback, then runs
dbt build which appended a second callback. Both callbacks fired for
every event during the build, printing each log line twice.

Fix: skip callback registration when context["_check_source_freshness"]
is True. The freshness run's results are captured from
target/sources.json afterwards and do not need per-event XCom pushes.
Raw JSON stdout is still suppressed via _NullWriter for both paths.

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
@pankajastro pankajastro marked this pull request as ready for review April 16, 2026 07:46
Copilot AI review requested due to automatic review settings April 16, 2026 07:46
@pankajastro pankajastro requested a review from a team as a code owner April 16, 2026 07:46
Copy link
Copy Markdown
Contributor

Copilot AI left a comment

Choose a reason for hiding this comment

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

Pull request overview

Fixes duplicate dbt log lines in WATCHER mode when source freshness pre-check is enabled by preventing dbtRunner callback registration during the freshness run (while still suppressing raw JSON stdout).

Changes:

  • Skip registering the XCom/log-parsing dbtRunner callback when context["_check_source_freshness"] is set for the source freshness pre-check.
  • Continue suppressing raw --log-format json stdout during both freshness and build runs via _NullWriter.
  • Add a regression test ensuring callbacks are not appended during the freshness run.

Reviewed changes

Copilot reviewed 2 out of 2 changed files in this pull request and generated 1 comment.

File Description
cosmos/operators/watcher.py Avoids callback accumulation during source freshness pre-check to prevent duplicate logging during the subsequent build.
tests/operators/test_watcher.py Adds a targeted test to verify callback registration is skipped when _check_source_freshness is set.

💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

Comment thread tests/operators/test_watcher.py Outdated
@pankajastro pankajastro modified the milestone: Cosmos 1.14.1 Apr 16, 2026
@codecov
Copy link
Copy Markdown

codecov Bot commented Apr 16, 2026

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 98.04%. Comparing base (f4fb470) to head (b792b12).
⚠️ Report is 1 commits behind head on main.

Additional details and impacted files
@@           Coverage Diff           @@
##             main    #2564   +/-   ##
=======================================
  Coverage   98.04%   98.04%           
=======================================
  Files         103      103           
  Lines        7586     7589    +3     
=======================================
+ Hits         7438     7441    +3     
  Misses        148      148           

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.

Comment thread tests/operators/test_watcher.py
Copy link
Copy Markdown
Collaborator

@tatiana tatiana left a comment

Choose a reason for hiding this comment

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

@pankajastro, thanks for fixing this. Let's add it to the 1.14.1 milestone.

The implementation looks good, minor feedback inline.

Were you able to reproduce the problem via an Airlfow DAG, and then, after this change, confirm it works? If possible, add screenshots of the before-and-after of the change in the PR description.

Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
Copilot AI review requested due to automatic review settings April 16, 2026 10:44
Copy link
Copy Markdown
Contributor

Copilot AI left a comment

Choose a reason for hiding this comment

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

Pull request overview

Copilot reviewed 2 out of 2 changed files in this pull request and generated no new comments.


💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.

@pankajastro
Copy link
Copy Markdown
Contributor Author

Were you able to reproduce the problem via an Airlfow DAG, and then, after this change, confirm it works? If possible, add screenshots of the before-and-after of the change in the PR description.

yes, this happen when invocation_mode: DBT_RUNNER, execution_mode: Watcher, test_behavour: ALL, WITH_TESTS_OR_FRESHNESS. Updated desc with screen

@pankajastro pankajastro merged commit d4f9385 into main Apr 16, 2026
88 checks passed
@pankajastro pankajastro deleted the FIX_2558 branch April 16, 2026 11:45
pankajastro added a commit that referenced this pull request Apr 16, 2026
In DBT_RUNNER mode, run_dbt_runner appended a new XCom-pushing callback
to _dbt_runner_callbacks on every invocation. When source rendering is
enabled the producer runs dbt source freshness first (via
_run_source_freshness), registering a freshness callback, then runs dbt
build which appended a second callback. Both callbacks fired for every
event during the build, printing each log line twice.

Fix: skip callback registration when context["_check_source_freshness"]
is True. The freshness run's results are captured from
target/sources.json afterwards and do not need per-event XCom pushes.
Raw JSON stdout is still suppressed via _NullWriter for both paths.

Logs Before changes
<img width="1713" height="968" alt="Screenshot 2026-04-16 at 4 18 00 PM"
src="https://github.com/user-attachments/assets/ac24003d-97b6-4164-b659-177c01b779b1"
/>

Logs After changes
<img width="1680" height="1009" alt="Screenshot 2026-04-16 at 4 18
55 PM"
src="https://github.com/user-attachments/assets/3b5fcb31-ff34-4059-93a8-674c5520c1bb"
/>


closes: #2558

---------

Co-authored-by: Claude Sonnet 4.6 <noreply@anthropic.com>
Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>
@pankajastro pankajastro added this to the Cosmos 1.14.1 milestone Apr 16, 2026
@pankajkoti pankajkoti mentioned this pull request Apr 23, 2026
tatiana pushed a commit that referenced this pull request Apr 23, 2026
Bug Fixes

* Fix ``ExecutionMode.WATCHER`` producer retry behaviour by @tatiana in
#2559
* Prevent watcher producer skip propagating to downstream tasks via
gateway task by @johnhoran and @tatiana in #2597
* Keep watcher sensor polling when producer is still running by
@pankajkoti in #2592
* Fix circular import error in Cosmos plugin discovery under Astro
Runtime by @tatiana in #2538
* Fix ``CosmosRichLogger`` crash on ``None`` log message by @tatiana in
#2540
* Enable inlets and outlets using dbt Fusion on Airflow 3 by
@ichirotakami in #2561
* Fix incorrectly skipped source downstream tasks in
``ExecutionMode.WATCHER`` by @pankajastro in #2563
* Fix duplicate logs in ``dbt build`` when source freshness is enabled
by @pankajastro in #2564
* Warn and normalize when ``source_rendering_behavior=None`` is passed
by @pankajastro in #2570
* Gracefully handle ``Variable.set()`` failures on Astro Remote
Execution by @hkc-8010 in #2573
* Skip malformed YAML selectors instead of failing entirely by
@YourRoyalLinus in #2577

Docs

* Update watcher test behavior docs for Cosmos 1.14.0 by @tatiana in
#2549
* Add redirect for moved partial-parsing docs page by @tatiana in #2550
* Document ``ExecutionMode.WATCHER`` and ``depends_on_past`` limitation
by @tatiana in #2602
* Restore memory-optimised imports docs for Cosmos < 1.14.0 by
@pankajkoti in #2604

Others

* Speed up Airflow 3.1+ integration tests by caching
InProcessExecutionAPI by @pankajkoti in #2547
* Improve stability of cache hash unit tests by @tatiana in #2539
* Fix mypy 1.20.0 type check failures by @pankajkoti in #2546
* Fix CI failures caused by docs build memory exhaustion by @pankajkoti
in #2580
* Fix dbt Fusion broken integration tests by @tatiana in #2581
* Fix flaky ``cosmos_manifest_selectors_example`` DAG in CI by
@pankajkoti in #2593
* Reduce pre-commit autoupdate frequency PRs by @tatiana in #2544
* Bump ``reviewdog/action-actionlint`` from 1.71.0 to 1.72.0 by
@dependabot in #2542
* Skip watcher gateway test on Airflow 3.0 by @tatiana in #2607

closes: astronomer/oss-integrations-private#381
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.

[Bug] Watcher "double logging" for dbt_producer_watcher Tasks

3 participants