Skip to content

amdxdna: a kernel-log report of what TDR recovery did, and a test-only patch that makes a restart fail (Refs #1750) - #2032

Merged
bong-water-water-bong merged 3 commits into
mainfrom
cl-infra-1750-tdr-report
Nov 10, 2026
Merged

bong-water-water-bong merged 3 commits into
mainfrom
cl-infra-1750-tdr-report

Conversation

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator

Refs #1750. The code for that issue is merged (0010 in #1752, 0013 in #1940). What has kept it open is the measurement on the array. This PR adds the two things that measurement was missing, and records what the box's own log already says.

1. tools/amdxdna_tdr_report.py: what a recovery did, from the kernel log

Read-only, stdlib only, no device. Per module load: timeouts detected, power-cycle recoveries, throttled recoveries, skipped contexts, failed context restarts (context, error, the step that failed, and whether the module failed the parked jobs, which is 0013's log line), whether the array latched, and refused context creates by error. --json, --boot N, saved log files, and --fail-on-failed-restart as a check.

On strixhalo, this boot (2026-11-08 23:11 to 11-10 17:40 AST), the module the fleet runs (F87D0BDF248067862F83BA3, pin + 0001-0009):

$ python3 tools/amdxdna_tdr_report.py
module load 1: driver 0.18.0 (2636 amdxdna lines)
  timeouts detected        26
  power-cycle recoveries   18
  throttled                8
  skipped contexts         4
  failed restarts          0
  latched (reload needed)  0
  context creates refused  767 (ret -19 x767)

In 18 real recoveries under fleet load, no context restart failed. The path #1750 is about was not reached once. That is how often it happens here; it is not what firmware does when it happens.

2. A test-only patch that makes a restart fail

third_party/patches/amdxdna/test-only/restart-fault-injection.patch, outside the numbered series. Two module parameters (restart_inject_step: 1 = before the firmware context is created, 2 = after; restart_inject_count) make aie2_hwctx_restart() fail on request. A real failure needs firmware to refuse a message, which cannot be arranged from user space; that is why 0010 and 0013 are still "carried, NOT measured".

$ git apply <0001..0013>; git apply test-only/restart-fault-injection.patch       applies
$ ~/lb/thermal-run.sh make -C drivers/accel/amdxdna ARCH=x86 -j8                   rc=0, 0 errors, 0 warnings, 3m49s
$ ls -la .../amdxdna.ko                                                            14045256 bytes
$ modinfo amdxdna.ko | grep -E 'srcversion|restart_inject'
srcversion:     57DF58D0185B9D6E0397B6F
parm:           restart_inject_step:TEST ONLY: fail a context restart (1 = before create, 2 = after create) (uint)
parm:           restart_inject_count:TEST ONLY: number of context restarts restart_inject_step still fails (uint)

Never loaded. /lib/modules untouched, no modprobe, no parameter written.

It cannot reach a package: scripts/mk-kernel-packages.sh takes patches by number, and tests/amdxdna_restart_test.sh (ctest amdxdna_restart) now checks that the test-only patch still applies on top of the series and that no numbered patch carries TEST ONLY code:

$ ONEBIT_XDNA_SRC=~/.cache/xdna-km/src bash tests/amdxdna_restart_test.sh .
ok   13 patches apply in order on 526c6081974e
ok   test-only/restart-fault-injection.patch applies on top of them (checked, not applied)
ok   no numbered patch carries TEST ONLY code
...
ok   amdxdna restart

Both checks fail when they should: with a context line of the patch changed, and with a copy of it dropped in as 0014-*.patch, the test prints FAIL test-only/restart-fault-injection.patch does not apply ... and exits 1.

3. The run, written down

third_party/patches/amdxdna/README.md has the box's record above and the five-step procedure for the measurement (build, load, hold one client, inject, provoke one recovery, read the report), with what to expect from 0013 and which number answers the issue's first question (teardown ret: whether firmware accepts a destroy for a context it has half of).

Tests

$ python3 tools/amdxdna_tdr_report.py --self-test
amdxdna_tdr_report: ok

The self-test parses lines in the driver's own formats for three module generations (no failure; 0010 only; 0013), including that 0013's line from the restart and the walk's line for the same context count as one failure. Registered as ctest tool_selftest_amdxdna_tdr_report. copyright.py --check and tests_referenced_check pass.

What is left on #1750

The run in section 3. It needs a module load on the box, which is the owner's call. With this PR it is one build, two echos and one report.

🤖 Generated with Claude Code

bong-water-water-bong and others added 2 commits November 10, 2026 17:49
…y patch that makes a restart fail (Refs #1750)

tools/amdxdna_tdr_report.py counts, per module load, the timeouts, power-cycle
recoveries, throttled recoveries, skipped contexts, failed context restarts
(with the step and whether the module failed the parked jobs) and latches.

third_party/patches/amdxdna/test-only/restart-fault-injection.patch is outside
the numbered series: two module parameters make aie2_hwctx_restart() fail on
request, so the failed-restart path of 0010/0013 can be measured with one
provoked recovery. Compiled, never loaded. The README has the box's record
(18 recoveries, 0 failed restarts) and the owner-side procedure.

Co-Authored-By: Claude Fable 5.2 <noreply@anthropic.com>
Co-Authored-By: Claude Fable 5.2 <noreply@anthropic.com>
@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

ready for review at d2df5f9

CI build is green at this head (it ran tool_selftest_amdxdna_tdr_report; amdxdna_restart skips in CI because the runner has no driver source at the pin, and passes on the box with ONEBIT_XDNA_SRC set, output in the description). hrx_build passed. The head is the first commit plus a merge of main (one CMakeLists conflict with the #2013 rows, both kept); the diff against main is 5 files, +449.

@bong-water-water-bong bong-water-water-bong left a comment

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

VERDICT: READY at d2df5f9

The framing is the right one for an issue whose code is already merged: "The code for that issue is merged (0010 in #1752, 0013 in #1940). What has kept it open is the measurement on the array. This PR adds the two things that measurement was missing."

TDR recovery is the class of thing that cannot be verified by reading the diff — a recovery path that unpauses a context whose restart failed is a claim about a device's state after an error, and only a log from a real recovery says whether it did what it meant. So an issue held open by measurement rather than code is a correct state, and closing it on the merged code would have been the wrong kind of green.

And a "test-only patch that forces the recovery" is the piece that makes the measurement repeatable rather than a lucky capture — it converts a hardware event into a reproducible one, which is the difference between a log someone happened to get and an arm that runs.

One ask: the report should state the failure it was recovering from alongside what recovery did (which engine reset, which context, which queue), because "recovery succeeded" is only meaningful relative to the fault, and a TDR from a hung shader and one from an unmapped page take different paths.

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

VERDICT: READY at d2df5f9 — and I reproduced it independently, byte for byte, so the numbers in the body are not a claim to be trusted but a measurement anyone can redo.

I pulled tools/amdxdna_tdr_report.py out of the diff and ran it on this box's boot 0 from the journal (journalctl -k -b 0), which is the same boot the body measures — and got exactly the body's table:

module load 1: driver 0.18.0 (2636 amdxdna lines)
  timeouts detected        26
  power-cycle recoveries   18
  throttled                8
  skipped contexts         4
  failed restarts          0
  latched (reload needed)  0
  context creates refused  767 (ret -19 x767)

--self-test prints ok, and --fail-on-failed-restart exits 0 on this log (correct: nothing to fail on). One detail worth recording because it bit me: dmesg on this box now returns no amdxdna lines (ring buffer rotated) while the journal still has all 2636 — so a reader who runs this against dmesg will conclude "the driver never loaded". The tool's docs should say journal, not "the kernel log", or someone will file a false negative.

Three asks, in order of how much they change the reading:

  1. 767 refused context creates needs temporal anchoring. That is the largest number in the report by two orders of magnitude, and 767 bare counts cannot be interpreted: if they cluster around the 18 recoveries (~43 each) they are the expected consequence of the array being down while reloading, and if they are spread across the boot they are something else entirely. A per-recovery count (or first/last timestamp and a span) turns a number into a finding. This is the "count without its denominator" rule — I have been bitten by it twice this week (#1773, #2049).
  2. Prove --fail-on-failed-restart fires. On this boot failed restarts is 0, so the check has never been shown to fire on real data — the CI green is vacuous unless --self-test includes a synthetic log with 0013's failed-restart line and a non-zero exit. Say in the body which case the self-test covers, because "self-test ok" for a check that has only ever seen the pass path is the #1858 shape (an oracle that cannot fail).
  3. Name the array latch state as a field, not only as a count — latched (reload needed) 0 is a boolean the reader needs to decide whether a reload is pending; if it ever reads 1, the actionable output is "reload the module", and the report should say it.

For #1750, which this PR is evidence for: 0 failed restarts across ~42 hours on a module the fleet hammered is frequency evidence, not absence — I am posting the closing condition on the issue itself, and it is "a log where failed restarts ≥ 1", which this tool now makes cheap to detect.

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

VERDICT: READY at d2df5f9 with one finding to fold in before merge — and the report tool is the part I could actually run, so here is what it says about this box.

What the tool reports on the real kernel log here

$ tools/amdxdna_tdr_report.py
module load 1: driver 0.18.0 (2636 amdxdna lines)
  timeouts detected        26
  power-cycle recoveries   18
  throttled                 8
  skipped contexts          4
  failed restarts           0
  latched (reload needed)   0
  context creates refused  767 (ret -19 x767)      ← ENODEV

767 refused context creates is the number this issue has been missing: it is the cost side of the recovery path — after a power-cycle reset, every context create that loses the race fails with -19, and until now that was buried in 2,636 log lines with no per-load accounting. Per module load, not a global grep, is what makes it attributable: a reload starts a new epoch, and mixing epochs is how "0 failed restarts" would hide 18 recoveries.

Read-only, stdlib only, no device — I ran it against the live log without changing anything, which is the right property for a tool a release lane runs on a box it did not build.

The fault injection is a userspace harness, which keeps the box out of it

skip: cannot read the third_party/xdna-driver pin (not a git checkout)    → exit 77
git archive "$pin" drivers/accel/amdxdna | tar -x -C "$scratch/tree"

It exports the driver source at the pin and compiles the restart function against stubs — no modprobe, no patched module loaded, no driver install. That is the only form of fault injection this lane can accept on a shared box, and the exit 77 skips (no pin, no source, no CC) are honest: a harness that cannot build says so rather than passing.

The finding: mktemp -d puts the harness inside tmpfs

scratch=$(mktemp -d)

mktemp -d honours TMPDIR, and TMPDIR is unset here, so this creates a driver-source tree plus build in /tmp — which is tmpfs on this box. That is the class #2029/#2034 just fixed on the C++ side, and #2034 merged with exactly this rule: tests/tmp_root.h prefers ONEBIT_TEST_TMP, then $HOME/.cache/scratch-tests/tmp, and only falls back to temp_directory_path() if HOME is unusable.

The fix is two lines and needs no new idea: in the shell test, prefer the same order —

scratch=$(mktemp -d "${ONEBIT_TEST_TMP:-${HOME:-/tmp}/.cache/scratch-tests}/amdxdna-restart-XXXXXX" 2>/dev/null) \
  || scratch=$(mktemp -d)

— and note that my own ratchet (#2027) would not have caught this: it scans for the literal "/tmp/ and this site has none. That is a real limit of that check, worth stating once: a mktemp -d with no TMPDIR is a tmpfs consumer with no literal in the tree, so the shell test's own discipline is what has to cover it (#2034's rule, applied here).

Scope +289 report tool, +87 fault-injection patch, +16 shell test, +54 README. The README carrying the procedure (rather than the test claiming to run it) is the right split for a measurement that wants a quiet box.

@bong-water-water-bong bong-water-water-bong left a comment

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

VERDICT: READY at d2df5f9

A test-only patch that is fenced so it cannot ship, plus the report that reads what the recovery actually did. Both properties are enforced by the harness rather than described in a comment.

The fence has three arms, and the third is the one that matters (tests/amdxdna_restart_test.sh):

  1. the 13 numbered patches apply in order on the pin, failing with the patch name and the first five lines of apply.err;
  2. test-only/restart-fault-injection.patch still applies on top of the series — apply --check, "checked, not applied", so it cannot rot into an unbuildable test;
  3. it must stay out of the numbered glob: if ls "$series"/[0-9][0-9][0-9][0-9]-*.patch | xargs grep -l "TEST ONLY" → FAIL a numbered patch carries TEST ONLY code.

That third arm is the whole safety property, and it is stated as such: "it must stay out of the numbered glob above, which is what a package build takes". A fault-injection
patch that leaks into the numbered series would ship a driver that injects restart failures — the single worst outcome this directory could produce — and the check for it does
not depend on the author remembering.

The report tool parses what the driver actually prints, per outcome, which is what makes it a report rather than a grep for amdxdna:

FAILED          <ctx> restart failed, ret <n>
THROTTLED       TDR recovery throttled | NPU power-cycle throttled
SKIPPED         TDR: <n> context(s) skipped
LATCHED         NPU array is unusable until the driver is reloaded
NOT_RECOVERED   NPU power-cycle did not recover the array: <n>
CREATE_REFUSED  Init hwctx failed, ret <n>

Those are exactly the outcomes #1750 is about ("TDR recovery unpauses a context whose restart failed") and #4/#10/#13 carry — so the report names the case it is
reporting on instead of printing a wall of dmesg.

Ran: python3 tools/amdxdna_tdr_report.py --self-test → amdxdna_tdr_report: ok, and the CMake add_python_test(tool_selftest_amdxdna_tdr_report …) registration is present
so it runs in ctest.

Not run: the three harness arms — no local clone carries the driver pin 526c6081974e (checked three engine trees), so the harness takes its own honest path:
skip: no driver source at the pin 526c6081974e. That skip is correct behaviour (rc 77, not a silent pass), and it means the fence is only proven where the submodule is
checked out; if CI does not check out third_party/xdna-driver at that pin, arm 1–3 never run there either.

@bong-water-water-bong

Copy link
Copy Markdown
Collaborator Author

VERDICT: READY d2df5f9

The tool is the right kind of instrument, and the header describes its blast radius precisely: "It reads journalctl -k -b or saved logs, opens no device" —
so a TDR-recovery question can be answered on a box that is already wedged, without a ticket, and without adding a second failure while diagnosing the first.

The reported shape is the useful part:

context creates refused  767 (ret -19 x767)

That is an interpretation of a kernel log into a question ("are contexts being refused, and with what errno"), which is what makes it different from dmesg | grep. The refusal to simulate a restart failure — "a real restart failure needs firmware to refuse a message and cannot be arranged" — is the right call:
the tool reports what happened rather than pretending to reproduce it, and says why reproduction is not available.

ci_targets_check --check → rc 0 in a full worktree (the shell row names a script, not a target).

One thing worth adding to the row's own docs, since ret -19 is the number a reader will chase: what -19 is (ENODEV) and what the plausible causes are,
in one line. A report that prints an errno the reader has to look up is one query away from being read as "unknown failure".

I reviewed this as a reporting tool rather than as a kernel patch — the 0013 patch it accompanies is not something I can read meaningfully here, and the tool is
the half a lane can verify without a device.

@bong-water-water-bong bong-water-water-bong left a comment

Copy link
Copy Markdown
Collaborator Author

Choose a reason for hiding this comment

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

VERDICT at deb09ec: READY

The new head is a merge of main, and the PR's own diff is identical to d2df5f9 (verdicted READY). A three-way merge onto current main is clean. I ran it myself at this head:

  • tools/amdxdna_tdr_report.py on this box's kernel log reproduces the description exactly: module load 1, driver 0.18.0 (2636 lines), 26 timeouts, 18 power-cycle recoveries, 8 throttled, 4 skipped contexts, 0 failed restarts, 0 latched, 767 refused creates (ret -19). rc 0.
  • tests/amdxdna_restart_test.sh. It skips (77) in a checkout without third_party/xdna-driver, so I initialised the submodule at its pin 526c6081974e (shallow, 3.3 M) and ran it: every arm ok, including the two this PR adds: "test-only/restart-fault-injection.patch applies on top of them (checked, not applied)" and "no numbered patch carries TEST ONLY code".
  • The apply check can fail. With the test-only patch's context corrupted, the test fails "does not apply on top of the 13 carried patches". Restored, it's ok.

Keeping the fault injection outside the numbered glob, with a check that it still applies and that nothing TEST ONLY leaks into the series, is the right way to carry a patch that must never ship. The description is honest about the measurement it can't make here: a real failed restart needs firmware to refuse, and in 18 real recoveries none did.

@bong-water-water-bong
bong-water-water-bong merged commit fcc50c1 into main Nov 10, 2026
10 checks passed
@bong-water-water-bong
bong-water-water-bong deleted the cl-infra-1750-tdr-report branch November 10, 2026 23:23
@github-actions

Copy link
Copy Markdown

PR Reviewer Guide 🔍

Here are some key observations to aid the review process:

🎫 Ticket compliance analysis 🔶

1750 - Partially compliant

Compliant requirements:

  • The PR fixes the issue where TDR recovery unpauses a context whose restart failed
  • The PR adds a tool (tools/amdxdna_tdr_report.py) to report what TDR recovery did from kernel logs
  • The PR adds a test-only patch (third_party/patches/amdxdna/test-only/restart-fault-injection.patch) to inject restart failures for testing

Non-compliant requirements:

  • The PR does not fully address the hardware-specific testing requirements for the fix

Requires further human verification:

  • Verification of the fix's behavior on actual hardware with the test-only patch
  • Confirmation that the fix prevents jobs from being submitted to a dead context
⏱️ Estimated effort to review: 3 🔵🔵🔵⚪⚪
🧪 PR contains tests
🔒 No security concerns identified
⚡ Recommended focus areas for review

Tool for TDR recovery analysis

The new tool tools/amdxdna_tdr_report.py parses kernel logs to count TDR recovery events, including failed context restarts. It correctly identifies the different types of recovery events and provides detailed reporting. The tool is well-documented and handles various edge cases, such as multiple module loads and different failure scenarios.

#!/usr/bin/env python3
# Copyright 2026 bong-water-water-bong
# SPDX-License-Identifier: Apache-2.0
#
# Licensed under the Apache License, Version 2.0 (the "License");
# you may not use this file except in compliance with the License.
# You may obtain a copy of the License at
#
#     http://www.apache.org/licenses/LICENSE-2.0
#
# Unless required by applicable law or agreed to in writing, software
# distributed under the License is distributed on an "AS IS" BASIS,
# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
# See the License for the specific language governing permissions and
# limitations under the License.
"""amdxdna_tdr_report.py -- what the amdxdna driver's TDR recovery did, read from the kernel log.

    tools/amdxdna_tdr_report.py                 this boot's kernel log (journalctl -k -b)
    tools/amdxdna_tdr_report.py --boot -1       another boot (journalctl's numbering)
    tools/amdxdna_tdr_report.py FILE [FILE...]  saved logs (dmesg or journalctl text); - is stdin
    tools/amdxdna_tdr_report.py --json ...      the same numbers as JSON
    tools/amdxdna_tdr_report.py --fail-on-failed-restart ...   exit 1 when a context restart failed
    tools/amdxdna_tdr_report.py --self-test

Read-only: it opens no device and changes nothing. Stdlib only.

Why it exists (engine#1750). A timeout (TDR) makes the driver stop every context, power-cycle the array and
restart the contexts. The question that issue asks is what happens to a context whose restart FAILS, and
the first thing anyone needs is how often that has happened on a box. The driver logs every step, but the
answer was a grep one had to know how to write. This prints it per module load:

    timeouts detected          every "TDR timeout detected"
    power-cycle recoveries     the driver reset the array and walked the contexts
    throttled                  inside the minimum interval between resets; no context was touched
    skipped contexts           being torn down by their owner (-ESRCH), not a failure
    failed restarts            "<ctx> restart failed, ret <n>", with the context, the error, and the step
                               that failed when the driver logged one
    latched                    "NPU array is unusable until the driver is reloaded"
    context creates refused    "Init hwctx failed, ret <n>", by error

For a failed restart it also says which behaviour the loaded module has: the carried patch 0013 logs
"no firmware context (teardown ret <n>), failing <k> parked job(s)" from the restart itself; a module
without it logs only the bare line from the TDR walk, and one without 0010 unpauses the context anyway.

A module load is a "Initialized amdxdna_accel_driver" line. Lines before the first one in the input are
reported as a load of their own, since a saved log often starts mid-boot.
"""
import argparse
import json
import re
import subprocess
import sys

LINE = re.compile(r"amdxdna [0-9a-f:.]+: (?:\[drm\] )?(?:\*ERROR\* )?(?P<fn>[A-Za-z0-9_]+): (?P<msg>.*)$")
LOAD = re.compile(r"Initialized amdxdna_accel_driver (?P<ver>\S+)")
FAILED = re.compile(r"^(?P<ctx>\S+) restart failed, ret (?P<ret>-?\d+)"
                    r"(?:: no firmware context \(teardown ret (?P<td>-?\d+)\), failing (?P<parked>\d+) parked job)?")
STEP = re.compile(r"^(Create hwctx failed|Map host buf failed|Add heap \d+ failed|Config cu failed),? ?ret (-?\d+)")
THROTTLED = re.compile(r"^TDR recovery throttled|^NPU power-cycle throttled")
SKIPPED = re.compile(r"^TDR: (\d+) context\(s\) skipped")
LATCHED = re.compile(r"^NPU array is unusable until the driver is reloaded")
NOT_RECOVERED = re.compile(r"^NPU power-cycle did not recover the array: (-?\d+)")
CREATE_REFUSED = re.compile(r"^Init hwctx failed, ret (-?\d+)")


def new_load(version):
    return {"driver": version, "timeouts": 0, "power_cycles": 0, "throttled": 0, "skipped_contexts": 0,
            "failed_restarts": [], "latched": 0, "not_recovered": [], "creates_refused": {}, "lines": 0}


def parse(lines):
    """-> a list of module loads, each a dict of counts. Lines that are not the driver's are ignored."""
    loads, cur, step = [], None, None
    for raw in lines:
        m = LOAD.search(raw)
        if m:
            cur = new_load(m.group("ver"))
            loads.append(cur)
            step = None
            continue
        m = LINE.search(raw)
        if not m:
            continue
        if cur is None:
            cur = new_load(None)
            loads.append(cur)
        cur["lines"] += 1
        fn, msg = m.group("fn"), m.group("msg").strip()
        if msg == "TDR timeout detected":
            cur["timeouts"] += 1
        elif "power-cycling NPU" in msg and fn == "aie2_tdr_recover_all":
            # aie2_hw_reset() logs its own "power-cycling NPU" line for the same reset: count the walk's
            cur["power_cycles"] += 1
            step = None
        elif THROTTLED.search(msg):
            cur["throttled"] += 1
        elif SKIPPED.search(msg):
            cur["skipped_contexts"] += int(SKIPPED.search(msg).group(1))
        elif LATCHED.search(msg):
            cur["latched"] += 1
        elif NOT_RECOVERED.search(msg):
            cur["not_recovered"].append(int(NOT_RECOVERED.search(msg).group(1)))
        elif CREATE_REFUSED.search(msg):
            ret = CREATE_REFUSED.search(msg).group(1)
            cur["creates_refused"][ret] = cur["creates_refused"].get(ret, 0) + 1
        elif fn == "aie2_hwctx_restart" and STEP.search(msg):
            step = STEP.search(msg).group(1)
        elif FAILED.search(msg):
            f = FAILED.search(msg)
            entry = {"context": f.group("ctx"), "ret": int(f.group("ret")), "step": step,
                     "logged_by": fn, "teardown_ret": None, "parked_jobs": None}
            if f.group("td") is not None:
                entry["teardown_ret"], entry["parked_jobs"] = int(f.group("td")), int(f.group("parked"))
            prev = cur["failed_restarts"][-1] if cur["failed_restarts"] else None
            # with 0013 the restart logs the failure and the TDR walk logs it again: one failure, not two
            if (prev and prev["context"] == entry["context"] and prev["ret"] == entry["ret"]
                    and prev["logged_by"] != fn and not prev.get("paired")):
                prev["paired"] = True
                if entry["teardown_ret"] is not None:
                    prev["teardown_ret"], prev["parked_jobs"] = entry["teardown_ret"], entry["parked_jobs"]
            else:
                cur["failed_restarts"].append(entry)
            step = None
    for load in loads:
        for f in load["failed_restarts"]:
            f.pop("paired", None)
            f.pop("logged_by", None)
            f["module_fails_parked_jobs"] = f["teardown_ret"] is not None      # the 0013 line
    return loads


def render(loads):
    out = []
    if not loads:
        return "no amdxdna lines in the input\n"
    for i, l in enumerate(loads):
        head = f"driver {l['driver']}" if l["driver"] else "before the first driver load line in the input"
        out.append(f"module load {i + 1}: {head} ({l['lines']} amdxdna lines)")
        out.append(f"  timeouts detected        {l['timeouts']}")
        out.append(f"  power-cycle recoveries   {l['power_cycles']}")
        out.append(f"  throttled                {l['throttled']}")
        out.append(f"  skipped contexts         {l['skipped_contexts']}")
        out.append(f"  failed restarts          {len(l['failed_restarts'])}")
        for f in l["failed_restarts"]:
            where = f" at '{f['step']}'" if f["step"] else ""
            if f["module_fails_parked_jobs"]:
                tail = (f"; firmware context taken away (teardown ret {f['teardown_ret']}), "
                        f"{f['parked_jobs']} parked job(s) failed with -ENODEV (patch 0013)")
            else:
                tail = "; the module does not say what happened to the parked jobs (no patch 0013)"
            out.append(f"    {f['context']}: ret {f['ret']}{where}{tail}")
        out.append(f"  latched (reload needed)  {l['latched']}")
        if l["not_recovered"]:
            out.append(f"  power-cycle did not recover the array: {len(l['not_recovered'])} "
                       f"(ret {', '.join(str(r) for r in l['not_recovered'])})")
        if l["creates_refused"]:
            by = ", ".join(f"ret {k} x{v}" for k, v in sorted(l["creates_refused"].items(), key=lambda kv: -kv[1]))
            out.append(f"  context creates refused  {sum(l['creates_refused'].values())} ({by})")
    return "\n".join(out) + "\n"


def read_inputs(args):
    if args.files:
        for p in args.files:
            f = sys.stdin if p == "-" else open(p, errors="replace")
            with f:
                yield from f
        return
    cmd = ["journalctl", "-k", "--no-pager", "-b", str(args.boot)]
    try:
        r = subprocess.run(cmd, capture_output=True, text=True, errors="replace")
    except OSError as e:
        raise SystemExit(f"cannot run {' '.join(cmd)}: {e}; pass a saved log file instead")
    if r.returncode:
        raise SystemExit(f"{' '.join(cmd)} exited {r.returncode}: {r.stderr.strip()[:300]}; pass a saved log file instead")
    yield from r.stdout.splitlines()


# Lines as the driver prints them. The first block is from a box running pin + 0001-0009; the failed
# restarts are written from the format strings in the patched source (0010 alone, then 0013).
P = "Nov 09 04:46:22 host kernel: amdxdna 0000:c6:00.1: [drm] "
SELF = [
    "Nov 08 23:11:19 host kernel: [drm] Initialized amdxdna_accel_driver 0.18.0 for 0000:c6:00.1 on minor 0",
    P + "*ERROR* aie2_legacy_tdr_detect: TDR timeout detected",
    P + "aie2_tdr_work_func: Device isn't making progress",
    P + "*ERROR* aie2_set_cmd_timeout: Firmware timeout state capture:",
    P + "*ERROR* aie2_set_cmd_timeout:         Context ID: 15",
    P + "aie2_tdr_recover_all: Array stopped dispatching, power-cycling NPU to recover",
    P + "aie2_hw_reset: NPU firmware unhealthy: power-cycling NPU",
    P + "*ERROR* aie2_legacy_tdr_detect: TDR timeout detected",
    P + "aie2_tdr_recover_all: TDR recovery throttled: last power-cycle 45560 ms ago (< 60000 ms), retrying on "
        "the next watchdog tick; no context touched",
    P + "*ERROR* aie2_legacy_tdr_detect: TDR timeout detected",
    P + "aie2_tdr_recover_all: Array stopped dispatching, power-cycling NPU to recover",
    P + "aie2_tdr_recover_all: TDR: 2 context(s) skipped, being torn down",
    P + "*ERROR* aie2_hwctx_init: Alloc hw resource failed, ret -19",
    P + "*ERROR* amdxdna_drm_create_hwctx_ioctl: Init hwctx failed, ret -19",
    P + "*ERROR* amdxdna_drm_create_hwctx_ioctl: Init hwctx failed, ret -16",
    P + "*ERROR* amdxdna_drm_create_hwctx_ioctl: Init hwctx failed, ret -19",
    "Nov 09 05:00:00 host kernel: usb 1-1: new high-speed USB device number 4",          # not ours
    # a second load, a module with 0010 only: the TDR walk logs the failure, and the array latches
    "[  812.100000] [drm] Initialized amdxdna_accel_driver 0.18.0 for 0000:c6:00.1 on minor 0",
    "[  900.000000] amdxdna 0000:c6:00.1: [drm] *ERROR* aie2_legacy_tdr_detect: TDR timeout detected",
    "[  900.000100] amdxdna 0000:c6:00.1: [drm] aie2_tdr_recover_all: Firmware unresponsive, power-cycling NPU",
    "[  900.500000] amdxdna 0000:c6:00.1: [drm] *ERROR* aie2_hwctx_restart: Map host buf failed, ret -22",
    "[  900.500100] amdxdna 0000:c6:00.1: [drm] *ERROR* aie2_tdr_resume_hwctx: hwctx.4242.15 restart failed, ret -22",
    "[  900.500200] amdxdna 0000:c6:00.1: [drm] *ERROR* aie2_tdr_recover_all: NPU array is unusable until the driver is "
    "reloaded: TDR recovery failed (0, a context could not be restarted); new contexts and submissions are refused "
    "with -ENODEV",
    # a third load, a module with 0013: the restart logs it (with the jobs), then the walk logs it again
    "[ 1500.000000] [drm] Initialized amdxdna_accel_driver 0.18.0 for 0000:c6:00.1 on minor 0",
    "[ 1600.000000] amdxdna 0000:c6:00.1: [drm] *ERROR* aie2_legacy_tdr_detect: TDR timeout detected",
    "[ 1600.000100] amdxdna 0000:c6:00.1: [drm] aie2_tdr_recover_all: Array stopped dispatching, power-cycling NPU to recover",
    "[ 1600.400000] amdxdna 0000:c6:00.1: [drm] *ERROR* aie2_hwctx_restart: Create hwctx failed, ret -5",
    "[ 1600.400100] amdxdna 0000:c6:00.1: [drm] *ERROR* aie2_hwctx_restart: hwctx.77.14 restart failed, ret -5: no firmware "
    "context (teardown ret 0), failing 3 parked job(s) and later submissions with -ENODEV",
    "[ 1600.400200] amdxdna 0000:c6:00.1: [drm] *ERROR* aie2_tdr_resume_hwctx: hwctx.77.14 restart failed, ret -5",
    "[ 1600.400300] amdxdna 0000:c6:00.1: [drm] *ERROR* aie2_hwctx_restart: Config cu failed, ret -110",
    "[ 1600.400400] amdxdna 0000:c6:00.1: [drm] *ERROR* aie2_hwctx_restart: hwctx.78.13 restart failed, ret -110: no firmware "
    "context (teardown ret 0), failing 0 parked job(s) and later submissions with -ENODEV",
    "[ 1600.400500] amdxdna 0000:c6:00.1: [drm] *ERROR* aie2_tdr_resume_hwctx: hwctx.78.13 restart failed, ret -110",
    "[ 1600.400600] amdxdna 0000:c6:00.1: [drm] *ERROR* aie2_tdr_recover_all: NPU power-cycle did not recover the array: -110",
]


def self_test():
    fails = []

    def check(good, what):
        if not good:
            fails.append(what)

    loads = parse(SELF)
    check(len(loads) == 3, f"three module loads, got {len(loads)}")
    a, b, c = (loads + [new_load(None)] * 3)[:3]
    check(a["driver"] == "0.18.0", "the driver version is read from the load line")
    check(a["timeouts"] == 3, f"load 1: 3 timeouts, got {a['timeouts']}")
    check(a["power_cycles"] == 2, f"load 1: 2 power-cycles (aie2_hw_reset's own line is not a second one), got {a['power_cycles']}")
    check(a["throttled"] == 1 and a["skipped_contexts"] == 2, "load 1: 1 throttled, 2 skipped contexts")
    check(a["failed_restarts"] == [] and a["latched"] == 0, "load 1: no failed restart, not latched")
    check(a["creates_refused"] == {"-19": 2, "-16": 1}, f"load 1: creates refused by error, got {a['creates_refused']}")
    check(a["lines"] == 15, f"load 1: 15 driver lines (the usb line is not one), got {a['lines']}")
    fb = b["failed_restarts"]
    check(len(fb) == 1 and fb[0]["context"] == "hwctx.4242.15" and fb[0]["ret"] == -22, "load 2: one failed restart, named")
    check(fb and fb[0]["step"] == "Map host buf failed", "load 2: the failing step is the driver's own line before it")
    check(fb and fb[0]["module_fails_parked_jobs"] is False, "load 2: a bare line means no patch 0013")
    check(b["latched"] == 1 and b["power_cycles"] == 1, "load 2: latched, and 'Firmware unresponsive' is a power-cycle too")
    fc = c["failed_restarts"]
    check(len(fc) == 2, f"load 3: the restart's line and the walk's line are one failure each, got {len(fc)}")
    check(len(fc) == 2 and fc[0]["parked_jobs"] == 3 and fc[0]["teardown_ret"] == 0 and fc[0]["step"] == "Create hwctx failed",
          "load 3: the 0013 line gives the parked jobs and the teardown result")
    check(len(fc) == 2 and fc[1]["context"] == "hwctx.78.13" and fc[1]["ret"] == -110 and fc[1]["step"] == "Config cu failed"
          and fc[1]["parked_jobs"] == 0, "load 3: the second context keeps its own step and count")
    check(all(f["module_fails_parked_jobs"] for f in fc), "load 3: the module is one with patch 0013")
    check(c["not_recovered"] == [-110], "load 3: a power-cycle that did not recover is reported with its error")
    text = render(loads)
    check("failed restarts          0" in text and "context creates refused  3 (ret -19 x2, ret -16 x1)" in text, "the text for load 1")
    check("hwctx.77.14: ret -5 at 'Create hwctx failed'; firmware context taken away (teardown ret 0), 3 parked job(s) "
          "failed with -ENODEV (patch 0013)" in text, "the text for a 0013 failure")
    check("hwctx.4242.15: ret -22 at 'Map host buf failed'; the module does not say" in text, "the text for a bare failure")
    check(parse(["Nov 09 host kernel: usb 1-1: hello"]) == [] and "no amdxdna lines" in render([]), "an input with none of ours")
    mid = parse(SELF[1:6])
    check(len(mid) == 1 and mid[0]["driver"] is None and mid[0]["power_cycles"] == 1, "a log that starts mid-boot is still counted")
    json.dumps(loads)
    for f in fails:
        print("FAIL " + f)
    print("FAILED" if fails else "amdxdna_tdr_report: ok")
    return 1 if fails else 0


def main():
    p = argparse.ArgumentParser(description=__doc__.split("\n")[0])
    p.add_argument("files", nargs="*", help="saved kernel logs (- is stdin); default: journalctl -k -b")
    p.add_argument("--boot", default="0", help="journalctl boot to read when no file is given (default 0, this boot)")
    p.add_argument("--json", action="store_true")
    p.add_argument("--fail-on-failed-restart", action="store_true", help="exit 1 when any context restart failed")
    p.add_argument("--self-test", action="store_true")
    a = p.parse_args()
    if a.self_test:
        return self_test()
    loads = parse(read_inputs(a))
    sys.stdout.write(json.dumps(loads, indent=1) + "\n" if a.json else render(loads))
    if a.fail_on_failed_restart and any(l["failed_restarts"] for l in loads):
        return 1
    return 0


if __name__ == "__main__":
    sys.exit(main())
Test-only patch for restart failure injection

The test-only patch adds module parameters to inject restart failures for testing purposes. This allows for controlled testing of the TDR recovery path without relying on firmware-level failures. The patch is correctly marked as TEST ONLY and is excluded from the numbered patch series.

From: bong-water-water-bong <bong-water-water-bong@1bit.gg>
Subject: [PATCH TEST ONLY] accel/amdxdna: fail a context restart on request

TEST ONLY. Not part of the carried series, never built into a package or an
image: it sits in test-only/ so that nothing that takes the numbered patches
picks it up.

aie2_hwctx_restart() fails only when firmware refuses one of its four
messages, which cannot be arranged from user space, so what the driver does
with a context whose restart failed (engine#1750, patches 0010 and 0013)
could not be measured on the array. Two module parameters make the next
restarts fail on purpose:

  restart_inject_step   0 = off
                        1 = fail before the firmware context is created
                            (as if aie2_create_context() had failed)
                        2 = fail after it was created
                            (as if aie2_map_host_buf() had failed)
  restart_inject_count  how many restarts to fail; each one takes one

Each injected failure logs "TEST ONLY: injecting a restart failure for
<ctx> at step <n>" at error level, followed by the driver's own lines for a
failed restart. Applies on top of 0001-0013.
---
diff --git a/drivers/accel/amdxdna/aie2_ctx.c b/drivers/accel/amdxdna/aie2_ctx.c
index 100a07d..55d99a7 100644
--- a/drivers/accel/amdxdna/aie2_ctx.c
+++ b/drivers/accel/amdxdna/aie2_ctx.c
@@ -34,6 +34,36 @@ uint tdr_timeout_ms = 2000;
 module_param(tdr_timeout_ms, uint, 0400);
 MODULE_PARM_DESC(tdr_timeout_ms, "TDR (Timeout Detection and Recovery) timeout in milliseconds (0 = disable)");

+/*
+ * TEST ONLY (engine#1750), never part of a shipped module: make the next
+ * context restarts fail on purpose, so the failed-restart path can be
+ * measured with one provoked TDR instead of waiting for firmware to
+ * refuse a restart by itself.
+ *
+ * restart_inject_step: 0 = off; 1 = fail before the firmware context is
+ * created (as if aie2_create_context() had failed); 2 = fail after it was
+ * created (as if aie2_map_host_buf() had failed).
+ * restart_inject_count: how many restarts to fail; each injected failure
+ * takes one, and at 0 the injection is off again.
+ */
+static uint restart_inject_step;
+module_param(restart_inject_step, uint, 0600);
+MODULE_PARM_DESC(restart_inject_step, "TEST ONLY: fail a context restart (1 = before create, 2 = after create)");
+static uint restart_inject_count;
+module_param(restart_inject_count, uint, 0600);
+MODULE_PARM_DESC(restart_inject_count, "TEST ONLY: number of context restarts restart_inject_step still fails");
+
+static bool aie2_restart_inject(struct amdxdna_dev *xdna, struct amdxdna_hwctx *hwctx, uint step)
+{
+	if (READ_ONCE(restart_inject_step) != step || !READ_ONCE(restart_inject_count))
+		return false;
+
+	WRITE_ONCE(restart_inject_count, READ_ONCE(restart_inject_count) - 1);
+	XDNA_ERR(xdna, "TEST ONLY: injecting a restart failure for %s at step %u (%u left)",
+		 hwctx->name, step, READ_ONCE(restart_inject_count));
+	return true;
+}
+
 struct aie2_ctx_health {
 	struct amdxdna_ctx_health header;
 	u32 txn_op_idx;
@@ -174,6 +204,12 @@ int aie2_hwctx_restart(struct amdxdna_dev *xdna, struct amdxdna_hwctx *hwctx)
 		goto out;
 	}

+	if (aie2_restart_inject(xdna, hwctx, 1)) {
+		ret = -EIO;
+		XDNA_ERR(xdna, "Create hwctx failed, ret %d", ret);
+		goto out;
+	}
+
 	ret = aie2_create_context(xdna->dev_handle, hwctx);
 	if (ret) {
 		XDNA_ERR(xdna, "Create hwctx failed, ret %d", ret);
@@ -183,6 +219,8 @@ int aie2_hwctx_restart(struct amdxdna_dev *xdna, struct amdxdna_hwctx *hwctx)
 	ret = aie2_map_host_buf(xdna->dev_handle, hwctx->fw_ctx_id,
 				amdxdna_obj_dma_addr(heap),
 				heap->mem.size);
+	if (!ret && aie2_restart_inject(xdna, hwctx, 2))
+		ret = -EIO;
 	if (ret) {
 		XDNA_ERR(xdna, "Map host buf failed, ret %d", ret);
 		goto out;

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant