Skip to content

fix(compile): format Inductor's implicit-fallback log text only when emitted - #3073

Merged
valarLip merged 1 commit into
ROCm:mainfrom
yhl-amd:hyi/inductor-operator-str
Nov 10, 2026
Merged

valarLip merged 1 commit into
ROCm:mainfrom
yhl-amd:hyi/inductor-operator-str

Conversation

@yhl-amd

@yhl-amd yhl-amd commented Nov 6, 2026

Copy link
Copy Markdown
Collaborator

Motivation

On torch < 2.13 a cold --level 3 compile can sit for a long time with no log output and an idle GPU, which looks like a hung startup. A Python stack dump of every rank shows the same frames:

OperatorIssue.operator_str (torch/_inductor/exc.py)
GraphLowering.call_function (torch/_inductor/graph.py)
...
InductorStandaloneAdaptor.compile (atom/utils/compiler_inferface.py)
...
DeepseekV41RuntimeModel._late_layers (atom/models/deepseek_v41/runtime.py)

with dozens of nested ExternKernel.__str__ frames above operator_str.

We hit it with DeepSeek-V4.1-Flash + DSpark whenever the first graph (backbone) is served from the Inductor FX graph cache and the second one (backbone_late) is not, for example after changing --max-num-batched-tokens (which changes only the late graph's key) while keeping /tmp/torchinductor_<user>. The custom ops are then lowered for the first time inside the late graph, deep in a chain of extern kernels.

Technical Details

Root cause (PyTorch). When an op has no Inductor lowering, GraphLowering.call_function registers an implicit fallback and logs it. Before torch 2.13 the log call is

log.info(
    "Creating implicit fallback for:\n%s",
    error.operator_str(target, args, kwargs),
)

so operator_str runs even though INFO is filtered out. It builds the full str() of every argument's IR, and ExternKernel.__str__ prints its inputs recursively, so for an op whose inputs come from a long chain of custom ops the text is very large and building it dominates the compile. torch 2.13 defers it with LazyString(error.operator_str, ...) (pytorch/pytorch#185951); 2.10, 2.11 and 2.12 all format eagerly. ROCm images that ATOM ships today are on torch 2.10.

Fix. atom/utils/compiler_inferface.py (already the place ATOM adapts Inductor/Triton at import, next to _patch_triton_cluster_dims_for_rocm) replaces OperatorIssue.operator_str on torch < 2.13 with a function that returns a small object whose __str__ calls the original. This is the 2.13 behaviour applied to older torch:

  • The filtered log.info never stringifies its argument, so nothing is built.
  • When the line is emitted (INFO enabled) or an OperatorIssue is raised (its subclasses embed the text through f-strings), str() produces exactly the original text. On 2.10-2.12 these are the only callers.
  • From torch 2.13 on it does nothing: there LazyString.__str__ must receive a real str from operator_str.
  • Idempotent, no new environment variable, on by default.

Test Plan

Unit (CPU): tests/test_compiler_interface.py

  • a filtered log.info in the pre-2.13 call shape does not print the IR arguments;
  • the deferred text is byte-identical to the original format;
  • a LoweringException message still contains the operator text.

(Skipped on torch >= 2.13.)

E2E: DeepSeek-V4.1-Flash, TP4 with DP attention + EP, DSpark, --level 3, stock torch 2.10 exc.py. The Inductor cache dir is a copy of one populated by earlier runs at other --max-num-batched-tokens values, and the ATOM compile cache is empty, so the backbone graph hits the Inductor cache and the late graph is lowered cold.

Test Result

Without this change With this change
Backbone graph served from the Inductor FX graph cache same
Late graph no log output, GPU idle; every rank's stack is in OperatorIssue.operator_str under GraphLowering.call_function; still there when stopped by the watchdog lowered and compiled normally, no long silent stretch in the log
Startup did not finish server ready

Without this change, a run with a cold Inductor cache for both graphs did not hit the slow path (the custom ops get their fallbacks registered early in the backbone graph, where their inputs are shallow), which is why the problem only shows up after a partial Inductor cache hit.

Unit: the new tests and the existing ones in tests/test_compiler_interface.py pass on torch 2.10. Black is clean; Ruff reports no new diagnostics on the changed files.

Submission Checklist

🤖 Generated with Claude Code

…emitted

Before torch 2.13, GraphLowering.call_function builds
OperatorIssue.operator_str(target, args, kwargs) eagerly as the argument of
a log.info call that is normally filtered out. The text is the full str()
of every argument's Inductor IR, and ExternKernel.__str__ prints its inputs
recursively, so for an op that falls back late in a long chain of custom
ops building it can keep a cold compile busy for a long time with no log
output and an idle GPU, which looks like a startup hang.

torch 2.13 defers this with LazyString (pytorch/pytorch#185951). Do the
same on older torch: operator_str returns an object that formats the
original text in __str__. All pre-2.13 callers only stringify the result
(the log call's %s and the OperatorIssue subclasses' f-strings), so emitted
logs and exception messages are unchanged. No-op from torch 2.13 on.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@yhl-amd yhl-amd added the ci:atom label Nov 6, 2026
@github-actions

github-actions Bot commented Nov 6, 2026

Copy link
Copy Markdown
Contributor

🏷️ CI Guide

Runs automatically on every eligible PR before approval:

  • ✅ Pre Checkin: Black, Ruff, catalog schema validation, non-GPU unit tests

Heavy model tests:

  • ✅ Run after the PR is approved and Pre Checkin passes
  • ✅ Run immediately when an approval review is submitted
  • ✅ Can be requested before approval with labels
Label Tests
ci:full Run all heavy PR model tests: native ATOM, vLLM, and SGLang
ci:atom Run native ATOM model accuracy tests
ci:vllm Run ATOM vLLM OOT model accuracy tests
ci:sglang Run ATOM SGLang model accuracy tests

Heavy jobs are skipped when the PR is not approved and no matching ci:* label is present.
Add labels via the sidebar or gh pr edit 3073 --add-label <label>

@valar-cop valar-cop 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.

LGTM

ci green.

@valarLip
valarLip merged commit d228a89 into ROCm:main Nov 10, 2026
35 of 52 checks passed
rdoshi-amd added a commit to rdoshi-amd/ATOM that referenced this pull request Nov 10, 2026
Brings in main through 03b584b (ROCm#3109 V4.1 gfx1250 single-launch decode
step, ROCm#3169, ROCm#3167, ROCm#3052, ROCm#3073, ROCm#3153, README news). One conflict, in
model_runner.py: ROCm#3109's step override (`_step_override` / `_served`) and
this branch's model head output (`compute_head`) sit side by side, in
__init__ and as two branches of postprocess's verdict (a tuple head
output; an overridden step's `verify_outputs`). The two are exclusive: an
overridden step returns no head output. The hi runner test's stand-in
runner gains ROCm#3109's `_served` and the stream argument of
`forward_done_event.record`.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants