Skip to content

Prevent scheduler crash when process/thread missing from log format - #69402

Merged
potiuk merged 2 commits into
apache:mainfrom
anxkhn:fix/log-formatter-missing-process-thread
Jul 12, 2026
Merged

Prevent scheduler crash when process/thread missing from log format#69402
potiuk merged 2 commits into
apache:mainfrom
anxkhn:fix/log-formatter-missing-process-thread

Conversation

@anxkhn

@anxkhn anxkhn commented Jul 5, 2026

Copy link
Copy Markdown
Contributor

When a log record reaches the percent formatter without callsite information, for
example a standard-library warning routed through Airflow's logging bridge, the
process and thread fields are absent. The formatter fell back to the
"(unknown)" string for every missing callsite field, so a log format using
the numeric %(process)d or %(thread)d specifiers (the default console
format renders a process-id column) raised
TypeError: %d format: a real number is required, not str and could take down
the scheduler at startup.

This gives those two numeric callsite parameters a numeric fallback of 0, the
same way lineno is already handled a few lines above, so the format string
never receives a string where a number is expected. The "(unknown)" string
fallback is left intact for the text callsite parameters
(pathname/module/threadName/processName), which are rendered with
%s.

A parametrized regression test formats %(process)d:%(thread)d for a record
with no callsite info (the exact issue reproduction) and for one where those keys
are explicitly None, asserting it renders 0:0 instead of raising; it fails
with the TypeError before the change and passes after.

closes: #66195


Was generative AI tooling used to co-author this PR?
  • Yes

Final diff (2 files, +24/-0)

  1. shared/logging/src/airflow_shared/logging/percent_formatter.py (+6): in
    _LazyLogRecordDict.__getitem__, add
    if key == "process" or key == "thread": return self.event.get(key) or 0
    immediately after the existing lineno numeric-fallback case, with a short
    comment explaining why (numeric %d params must not fall back to the
    "(unknown)" string used for text params).
  2. shared/logging/tests/logging/test_percent_formatter.py (+18): add
    test_numeric_callsite_without_process_or_thread, parametrized missing
    (no callsite keys, the issue repro) and none (keys present but None), in
    the existing TestPercentFormatRender class next to test_no_callsite; adds
    the import pytest it needs.

When a record reaches the percent formatter without callsite information,
for example a stdlib warning routed through the logging bridge, the process
and thread fields are absent. The formatter fell back to the "(unknown)"
string for them, so a format string using the numeric "%(process)d" or
"%(thread)d" specifiers raised "TypeError: %d format: a real number is
required" and could take down the scheduler at startup.

Give those two numeric callsite parameters a numeric fallback of 0, the same
way lineno is already handled, so the format never receives a string where a
number is expected.
@potiuk

potiuk commented Jul 5, 2026

Copy link
Copy Markdown
Member

Nice!

@potiuk potiuk added this to the Airflow 3.3.1 milestone Jul 5, 2026
@potiuk potiuk added the backport-to-v3-3-test Backport to v3-3-test label Jul 5, 2026
@Vamsi-klu

Copy link
Copy Markdown
Contributor

Confirmed the root cause: _LazyLogRecordDict.getitem fell back to the "(unknown)" string (missing key) or None (key present but None) for callsite params, so a format using %(process)d/%(thread)d raised "TypeError: %d format: a real number is required" when callsite info was absent (e.g. a stdlib warning routed through the logging bridge before CallsiteParameterAdder runs). Returning self.event.get(key) or 0 mirrors the lineno branch directly above it, and since CallsiteParameter.PROCESS.value/THREAD.value equal "process"/"thread", get(key) reads the same keys the callsite adder populates -- equivalent to the generic lookup below, just with a numeric default. The "(unknown)" fallback is correctly kept for the %s text params. The parametrized regression test covers both the missing-keys repro and the explicit-None case and is red before / green after. This also cleanly supersedes the now-closed #66230, which took a heavier route (live os.getpid()/threading.get_ident() plus a warning-bridge change in structlog.py). LGTM.

@anxkhn
anxkhn requested a review from potiuk July 8, 2026 09:45
@potiuk potiuk added the ready for maintainer review Set after triaging when all criteria pass. label Jul 11, 2026
@potiuk
potiuk merged commit fd7d535 into apache:main Jul 12, 2026
93 checks passed
@boring-cyborg

boring-cyborg Bot commented Jul 12, 2026

Copy link
Copy Markdown

Awesome work, congrats on your first merged pull request! You are invited to check our Issue Tracker for additional contributions.

@github-actions

Copy link
Copy Markdown
Contributor

Backport successfully created: v3-3-test

Note: As of Merging PRs targeted for Airflow 3.X
the committer who merges the PR is responsible for backporting the PRs that are bug fixes (generally speaking) to the maintenance branches.

In matter of doubt please ask in #release-management Slack channel.

Status Branch Result
v3-3-test PR Link

github-actions Bot pushed a commit to aws-mwaa/upstream-to-airflow that referenced this pull request Jul 12, 2026
…rom log format (apache#69402)

When a record reaches the percent formatter without callsite information,
for example a stdlib warning routed through the logging bridge, the process
and thread fields are absent. The formatter fell back to the "(unknown)"
string for them, so a format string using the numeric "%(process)d" or
"%(thread)d" specifiers raised "TypeError: %d format: a real number is
required" and could take down the scheduler at startup.

Give those two numeric callsite parameters a numeric fallback of 0, the same
way lineno is already handled, so the format never receives a string where a
number is expected.
(cherry picked from commit fd7d535)

Co-authored-by: Anas Khan <anxkhn28@gmail.com>
aws-airflow-bot pushed a commit to aws-mwaa/upstream-to-airflow that referenced this pull request Jul 12, 2026
…rom log format (apache#69402)

When a record reaches the percent formatter without callsite information,
for example a stdlib warning routed through the logging bridge, the process
and thread fields are absent. The formatter fell back to the "(unknown)"
string for them, so a format string using the numeric "%(process)d" or
"%(thread)d" specifiers raised "TypeError: %d format: a real number is
required" and could take down the scheduler at startup.

Give those two numeric callsite parameters a numeric fallback of 0, the same
way lineno is already handled, so the format never receives a string where a
number is expected.
(cherry picked from commit fd7d535)

Co-authored-by: Anas Khan <anxkhn28@gmail.com>
potiuk pushed a commit that referenced this pull request Jul 13, 2026
…rom log format (#69402) (#69787)

When a record reaches the percent formatter without callsite information,
for example a stdlib warning routed through the logging bridge, the process
and thread fields are absent. The formatter fell back to the "(unknown)"
string for them, so a format string using the numeric "%(process)d" or
"%(thread)d" specifiers raised "TypeError: %d format: a real number is
required" and could take down the scheduler at startup.

Give those two numeric callsite parameters a numeric fallback of 0, the same
way lineno is already handled, so the format never receives a string where a
number is expected.
(cherry picked from commit fd7d535)

Co-authored-by: Anas Khan <anxkhn28@gmail.com>
joshuabvarghese pushed a commit to joshuabvarghese/airflow that referenced this pull request Jul 16, 2026
…at (apache#69402)

When a record reaches the percent formatter without callsite information,
for example a stdlib warning routed through the logging bridge, the process
and thread fields are absent. The formatter fell back to the "(unknown)"
string for them, so a format string using the numeric "%(process)d" or
"%(thread)d" specifiers raised "TypeError: %d format: a real number is
required" and could take down the scheduler at startup.

Give those two numeric callsite parameters a numeric fallback of 0, the same
way lineno is already handled, so the format never receives a string where a
number is expected.
vatsrahul1001 pushed a commit that referenced this pull request Aug 5, 2026
…rom log format (#69402) (#69787)

When a record reaches the percent formatter without callsite information,
for example a stdlib warning routed through the logging bridge, the process
and thread fields are absent. The formatter fell back to the "(unknown)"
string for them, so a format string using the numeric "%(process)d" or
"%(thread)d" specifiers raised "TypeError: %d format: a real number is
required" and could take down the scheduler at startup.

Give those two numeric callsite parameters a numeric fallback of 0, the same
way lineno is already handled, so the format never receives a string where a
number is expected.
(cherry picked from commit fd7d535)

Co-authored-by: Anas Khan <anxkhn28@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

area:logging backport-to-v3-3-test Backport to v3-3-test ready for maintainer review Set after triaging when all criteria pass.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

Warning error formatting crashes the scheduler

3 participants