Support: record torch backend autoload state

.claude/skills/hbg-bind-phases/SKILL.md

@@ -22,10 +22,10 @@ HEAD_SHA=$(git rev-parse --short HEAD)
 LOG="outputs/bind_${HEAD_SHA}.log"; mkdir -p outputs
 MARK="outputs/.bind_start"; : >"$MARK"   # fixed mtime; "$LOG" keeps being appended to
 
-ENVS="SIMPLER_HBG_BIND_BREAKDOWN_ENABLE=1 SIMPLER_LOG_LEVEL=TIMING \
+ENVS="SIMPLER_HBG_BIND_BREAKDOWN_ENABLE=1 \
 TORCH_DEVICE_BACKEND_AUTOLOAD=0 SIMPLER_SKIP_DEVICE_RUN=1"          # + mode delta
 CASE="examples/.../<entry>.py -p a2a3"                # exactly as the case table gives it
-TAIL="--rounds 6"                                                    # per mode
+TAIL="--rounds 6 --log-level timing"                                 # per mode
 
 .claude/skills/onboard-arch-precheck/check.sh a2a3 || exit 1
 echo "[stamp] $HEAD_SHA env $ENVS python $CASE $TAIL" >"$LOG"
@@ -65,7 +65,7 @@ while the run still passed.)
 | Field | numbers | timeline |
 | ----- | ------- | -------- |
 | `ENVS` delta | none | `+ SIMPLER_HBG_HOST_PHASE_RECORDS_ENABLE=1` |
-| `TAIL` | `--rounds 6` | `--rounds 1 --enable-pmu 2` |
+| `TAIL` | `--rounds 6 --log-level timing` | `--rounds 1 --enable-pmu 2 --log-level timing` |
 | finish with | the parser, below | `strace_timing`, below |
 
 `--rounds > 1` force-disables every diagnostic (it warns per flag), so one run

docs/dfx/hbg-bind-phases.md

@@ -101,11 +101,20 @@ Four switches and one flag make the measurement, and each is load-bearing:
 | Switch | Why |
 | ------ | --- |
 | `SIMPLER_HBG_BIND_BREAKDOWN_ENABLE=1` | emits the `bind phase=` lines at all |
-| `SIMPLER_LOG_LEVEL=TIMING` | the level they are emitted at |
-| `TORCH_DEVICE_BACKEND_AUTOLOAD=0` | otherwise `torch_npu` grabs a device on import, which a host-only measurement does not want — and nothing in the log records whether it was set |
+| `--log-level timing` | enables the TIMING records used by the report; this is the SceneTest default |
+| `TORCH_DEVICE_BACKEND_AUTOLOAD=0` | keeps CPU golden imports from loading `torch_npu`; the `torch_backend_autoload` timing record confirms the effective setting and observed module state |
 | `SIMPLER_SKIP_DEVICE_RUN=1` | returns at `simpler_launch_run`, so the host path is measured without a working device run |
 | `--skip-golden` | with the device skipped the outputs a golden check compares are never produced, so a checking case such as qwen otherwise fails at validation with the whole measurement already complete in the log. On dsv4 it also skips the fixture upload its driver does by default, which is 42.6 GiB per rank of H2D you are not measuring |
 
+SceneTest emits one `torch_backend_autoload` record per interpreter after
+torch-dependent argument preparation and before the first dispatch. `effective`
+reports the environment's dispatch-time intent using torch's current private
+autoload predicate; `torch_npu_loaded` reports the observed module state and is
+the authoritative field if the environment changed after torch was imported.
+`raw` is the JSON-encoded environment value (`null` when unset); values longer
+than 64 characters carry their first 64 characters and
+`raw_truncated=true`, keeping the record single-line and bounded.
+
 **`SIMPLER_SKIP_DEVICE_RUN` is presence-based.** `SIMPLER_SKIP_DEVICE_RUN=0` still
 skips; `unset` it. It is a temporary handle from the dsv4 bring-up and is deleted
 once that case's device execution works.
@@ -191,10 +200,14 @@ its failure modes have already produced wrong answers on this box.
 **Both arms must be the same ruler, and the log is the only witness you get.** A
 baseline missing `TORCH_DEVICE_BACKEND_AUTOLOAD=0` produced a wrong number once:
 it alone paid for `torch_npu` grabbing a device on import, and the difference was
-attributed to the branch. Nothing in this repo reads that variable — it is
-`torch_npu`'s own — so no log line records whether it was set. The recipe
-therefore echoes the command it is about to run, verbatim, as the log's first
-line, and `hbg_bind_phases` prints that line above the table:
+attributed to the branch. Compare the `torch_backend_autoload` timing record in
+both logs; the measurement recipe produces
+`setting=0 raw="0" raw_truncated=false effective=disabled torch_imported=true torch_npu_loaded=false`.
+`hbg_bind_phases` prints every distinct record above its table and warns when the
+log does not carry one.
+
+The recipe also echoes the command it is about to run, verbatim, as the log's
+first line, and `hbg_bind_phases` prints that line above the table:
 
 ```bash
 diff <(head -1 base.log) <(head -1 measure.log)   # must differ only in the commit

simpler_setup/scene_test.py

@@ -24,6 +24,7 @@
 
 import gc
 import inspect
+import json
 import logging
 import os
 import platform as host_platform
@@ -32,11 +33,12 @@
 from concurrent.futures import ThreadPoolExecutor
 from contextlib import contextmanager
 from enum import IntEnum
+from functools import cache
 from pathlib import Path
 from typing import Any, NamedTuple
 
 from .compile_pool import compile_slot, current_compile_workers
-from .log_config import DEFAULT_LOG_LEVEL, LOG_LEVEL_CHOICES, configure_logging
+from .log_config import DEFAULT_LOG_LEVEL, LOG_LEVEL_CHOICES, TIMING, configure_logging
 from .pto_isa import ensure_pto_isa_root
 from .scene_test_cache import (
     compile_artifact_key,
@@ -50,6 +52,8 @@
 _compile_cache: dict[tuple, object] = {}
 
 _CASE_CONFIG_KEYS = frozenset({"aicpu_thread_num", "runtime_env", "device_count", "num_sub_workers"})
+_TORCH_BACKEND_AUTOLOAD_ENV = "TORCH_DEVICE_BACKEND_AUTOLOAD"
+_TORCH_BACKEND_AUTOLOAD_VALUE_LIMIT = 64
 _RUNTIME_ENV_KEYS = frozenset({"ring_task_window", "ring_heap", "ring_dep_pool"})
 
 
@@ -103,6 +107,35 @@ def effective_diagnostic_options(
     return _DiagnosticOptions(0, 0, 0, False, False, False)
 
 
+@cache
+def _log_torch_backend_autoload_once() -> None:
+    """Record torch backend autoload configuration and module state once."""
+    raw_setting = os.environ.get(_TORCH_BACKEND_AUTOLOAD_ENV)
+    if raw_setting is None:
+        setting = "unset"
+    elif raw_setting in {"0", "1"}:
+        setting = raw_setting
+    else:
+        setting = "invalid"
+    raw_truncated = raw_setting is not None and len(raw_setting) > _TORCH_BACKEND_AUTOLOAD_VALUE_LIMIT
+    raw_value = None if raw_setting is None else raw_setting[:_TORCH_BACKEND_AUTOLOAD_VALUE_LIMIT]
+    raw_json = json.dumps(raw_value, ensure_ascii=True)
+    # torch._is_device_backend_autoload_enabled() uses getenv(..., "1") == "1".
+    effective = "enabled" if (raw_setting is None or raw_setting == "1") else "disabled"
+
+    # SceneTest configures TIMING on "simpler"; the module logger filters this level.
+    logging.getLogger("simpler").log(
+        TIMING,
+        "torch_backend_autoload setting=%s raw=%s raw_truncated=%s effective=%s torch_imported=%s torch_npu_loaded=%s",
+        setting,
+        raw_json,
+        str(raw_truncated).lower(),
+        effective,
+        str("torch" in sys.modules).lower(),
+        str("torch_npu" in sys.modules).lower(),
+    )
+
+
 def _pto_isa_compile_cache_token() -> str:
     """Pin SHA included in session compile-cache keys.
 
@@ -1695,6 +1728,8 @@ def _run_and_validate_l2(  # noqa: PLR0913 -- threads CLI diagnostic flags + cas
             with _golden_thread_cap():
                 self.compute_golden(golden_args, params)
 
+        _log_torch_backend_autoload_once()
+
         # Save initial output tensor values for reset between rounds
         initial_outputs = {}
         if rounds > 1:
@@ -1778,6 +1813,8 @@ def _run_and_validate_l3(  # noqa: PLR0913 -- threads CLI diagnostic flags + L3
         # reset, dispatch, and compare below all operate on the rehosted views.
         rehosted = _RehostedTaskArgs(worker, test_args)
         try:
+            _log_torch_backend_autoload_once()
+
             # Save initial tensor values for reset between rounds
             all_tensor_names = test_args.tensor_names()
             initial_tensors = {}

simpler_setup/tools/README.md

@@ -412,8 +412,9 @@ A run whose control plane is missing a phase entirely — a change can retire on
 is still totalled, over the phases it has, with the absent ones named. A phase
 missing from only *some* passes is a truncated log instead, and those passes are
 excluded with a warning. If the log's first line is a `[stamp]` line naming the
-command and commit, it is echoed above the table; without one, the conditions
-behind the numbers have to be established by hand.
+command and commit, it is echoed above the table. Distinct
+`torch_backend_autoload` records are printed alongside it. Missing stamps or
+autoload records produce an explicit comparison warning.
 
 ---
 

simpler_setup/tools/hbg_bind_phases.py

@@ -26,6 +26,12 @@
 # The recipe's first log line, recording the command and the commit the run used.
 # Two runs are comparable only if it matches, so it is echoed above the table.
 STAMP_LINE = re.compile(r"^\[stamp\] (.*)$")
+_JSON_STRING = r'"(?:\\.|[^"\\])*"'
+TORCH_AUTOLOAD_LINE = re.compile(
+    rf"(torch_backend_autoload setting=\S+ "
+    rf"(?:raw=(?:null|{_JSON_STRING}) raw_truncated=(?:true|false) )?effective=\S+ "
+    r"torch_imported=(?:true|false) torch_npu_loaded=(?:true|false))"
+)
 
 # The segments between "the caller's data is in place" and "the device can run".
 # `args` is a per-byte staging cost. `host_view_close` remains excluded for
@@ -83,6 +89,22 @@ def parse_stamp(path: str) -> str:
     return ""
 
 
+def parse_torch_autoload(path: str) -> list[str]:
+    """Unique torch backend autoload records in log order."""
+    records: list[str] = []
+    seen: set[str] = set()
+    with open(path, encoding="utf-8", errors="replace") as handle:
+        for line in handle:
+            match = TORCH_AUTOLOAD_LINE.search(line)
+            if match is None:
+                continue
+            record = match.group(1)
+            if record not in seen:
+                seen.add(record)
+                records.append(record)
+    return records
+
+
 def spread(values: list[float]) -> tuple[float, float, float]:
     """Minimum, median and maximum. The median averages the two central values."""
     return min(values), statistics.median(values), max(values)
@@ -107,7 +129,7 @@ def main() -> int:
     if not binds:
         print(
             f"{args.log}: no `bind phase=` lines. SIMPLER_HBG_BIND_BREAKDOWN_ENABLE=1 and "
-            "SIMPLER_LOG_LEVEL=TIMING must both be set, and a multi-device case must be "
+            "--log-level timing must both be set, and a multi-device case must be "
             "invoked as its own child command -- see docs/dfx/hbg-bind-phases.md.",
             file=sys.stderr,
         )
@@ -134,6 +156,13 @@ def main() -> int:
     else:
         print("  (no `[stamp]` line: the command and commit behind these numbers have")
         print("   to be established by hand before comparing them to anything)")
+    torch_autoload = parse_torch_autoload(args.log)
+    if torch_autoload:
+        for record in torch_autoload:
+            print(f"  {record}")
+    else:
+        print("  (no `torch_backend_autoload` record: backend-autoload state")
+        print("   must be established before comparing this log)")
     print(f"  {len(binds)} binds, {len(warm)} warm ({dropped} cold dropped, ranks={ranks})\n")
     print(f"  {'phase':<18}{'min':>10}{'median':>10}{'max':>10}   n")
     for phase in PHASE_ORDER:
@@ -170,7 +199,7 @@ def main() -> int:
             print(f"    WARNING: {', '.join(partial)} is missing from some binds but not all;")
             print("    those binds are excluded, and the total may not describe the run")
         print("\n  Compare by min, over the same phase set, against a log with the same")
-        print("  stamp; see docs/dfx/hbg-bind-phases.md 'Comparing two branches'.")
+        print("  stamp and torch autoload state; see docs/dfx/hbg-bind-phases.md 'Comparing two branches'.")
     else:
         print(f"\n  no bind carries any of {CONTROL_PLANE}; the control-plane total is not computable")
     return 0

tests/ut/py/test_hbg_bind_phases_torch_autoload.py

@@ -0,0 +1,69 @@
+# Copyright (c) PyPTO Contributors.
+# This program is free software, you can redistribute it and/or modify it under the terms and conditions of
+# CANN Open Software License Agreement Version 2.0 (the "License").
+# Please refer to the License for details. You may not use this file except in compliance with the License.
+# THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY KIND, EITHER EXPRESS OR IMPLIED,
+# INCLUDING BUT NOT LIMITED TO NON-INFRINGEMENT, MERCHANTABILITY, OR FITNESS FOR A PARTICULAR PURPOSE.
+# See LICENSE in the root of the software repository for the full text of the License.
+# -----------------------------------------------------------------------------------------------------------
+"""Tests for torch backend autoload state in bind-phase reports."""
+
+from __future__ import annotations
+
+import sys
+
+from simpler_setup.tools import hbg_bind_phases
+
+
+def _write_log(path, autoload_records: tuple[str, ...]) -> None:
+    lines = ["[stamp] command commit=abc"]
+    lines.extend(f"TIMING simpler: {record}" for record in autoload_records)
+    lines.extend(
+        [
+            "bind phase=host_orch start_ns=1 dur_ns=1000000",
+            "bind phase=arena_h2d start_ns=2 dur_ns=1000000",
+            "bind phase=host_orch start_ns=3 dur_ns=500000",
+            "bind phase=arena_h2d start_ns=4 dur_ns=500000",
+        ]
+    )
+    path.write_text("\n".join(lines) + "\n", encoding="utf-8")
+
+
+def test_report_shows_each_torch_autoload_state(tmp_path, monkeypatch, capsys):
+    log = tmp_path / "run.log"
+    first = (
+        'torch_backend_autoload setting=invalid raw="a b\\"c" raw_truncated=false '
+        "effective=disabled torch_imported=true torch_npu_loaded=false"
+    )
+    second = (
+        'torch_backend_autoload setting=1 raw="1" raw_truncated=false '
+        "effective=enabled torch_imported=true torch_npu_loaded=true"
+    )
+    _write_log(log, (first, first, second))
+    monkeypatch.setattr(sys, "argv", ["hbg_bind_phases", str(log), "--rounds", "2"])
+
+    assert hbg_bind_phases.main() == 0
+
+    output = capsys.readouterr().out
+    assert output.count(first) == 1
+    assert output.count(second) == 1
+
+
+def test_report_warns_when_torch_autoload_state_is_missing(tmp_path, monkeypatch, capsys):
+    log = tmp_path / "run.log"
+    _write_log(log, ())
+    monkeypatch.setattr(sys, "argv", ["hbg_bind_phases", str(log), "--rounds", "2"])
+
+    assert hbg_bind_phases.main() == 0
+
+    output = capsys.readouterr().out
+    assert "no `torch_backend_autoload` record" in output
+    assert "must be established before comparing" in output
+
+
+def test_parser_accepts_record_without_raw_fields(tmp_path):
+    log = tmp_path / "run.log"
+    record = "torch_backend_autoload setting=0 effective=disabled torch_imported=true torch_npu_loaded=false"
+    _write_log(log, (record,))
+
+    assert hbg_bind_phases.parse_torch_autoload(str(log)) == [record]