Repository navigation
soc: apple: rtkit: read the crash logs T6050 co-processors write late or as containers - #942
Conversation
A co-processor whose crashlog endpoint was never discovered or started, such as a DCP adopted from the bootloader, requests the crashlog buffer only when it crashes and writes the log after receiving it. The header read right after mapping the buffer then fails, and the report was dropped without a word: on T6050 all three DCPs crashed this way within 8 s, display swaps stopped completing and the compositor froze, with nothing in the log but "Message to undiscovered endpoint 0x01". Report such a crash and poll the buffer until the log is written, then dump it. Only do this when APPLE_RTKIT_EP_CRASHLOG is not in rtk->endpoints. On a started crashlog endpoint the first message without a buffer is the normal boot-time buffer request, not a crash; treating it as one reported a crash for every other co-processor at boot (SMC, NVMe, PMP and the DP PHY on T6050). That path stays as it was: map the buffer and return silently. Nothing else changes: the consumer is not told, as before. Signed-off-by: Diljit Singh <hey@djdev.me> Signed-off-by: Erik Bourget <erik@ebourget.net>
In a session that went through the handshake, the crashlog handler takes the first message on the crashlog endpoint for the buffer request that answers the endpoint's start: it sets the buffer up and returns. That has been the rule since RTKit was added. Two later commits made an inherited session's first message a crash report and kept the rule for every other session: commit e52b589 ("soc: apple: rtkit: recognise an initial crash log in adopted sessions") commit 8a2875a ("soc: apple: rtkit: Only parse an initial crash log in inherited sessions") The previous commit reads the log of such a report when it is written after the report, but only in an inherited session, and without telling the client. The rule only holds when the endpoint was in the endpoint map and was started. The external DCP on T6050 (dcpext0 on J775D) does not list the crashlog endpoint in its map, so the endpoint is never started and the co-processor is never asked for a buffer. Its firmware still reports a crash there, naming a buffer of its own, in a session that went through the handshake as well. That report was set up as a buffer and dropped: the instance was never marked crashed and the DCP driver's crash handling never ran. Presents stopped (a swap timed out 36 s later) and every later modeset failed with -EINVAL until a reboot, with nothing in the log but "Message to undiscovered endpoint 0x01". Handle a crashlog message on an undiscovered endpoint as an inherited session's report is handled, in any session: set up the buffer it names and dump a valid log if there is one, then mark the instance crashed and notify the client at once, with or without a readable log. A log that is not written yet is still read once it is there, after the client has been told. A buffer that could not be set up and a buffer that holds no valid log yet are reported separately. Log when the endpoint map lacks the crashlog endpoint. A crashlog message still being handled may queue that late read, so stopping and reinitializing flush the work queue before cancelling it. A discovered endpoint is unchanged: its first message is still the buffer request. This builds on the inherited-session path those commits added, so a backport needs them. Testing: on J775D the map line appears for dcpext0 and for no other co-processor. A crash caused on dcpext0, by an IOMFB call to a method neither of its firmware tables has, was reported on the crashlog endpoint 4.7 ms after the call, with the same buffer as a crash seen in normal use. The instance was marked crashed and the DCP driver's crash handling ran ("DCP has crashed", the connector then reported disconnected). Fixes: 9bd1d9a ("soc: apple: Add RTKit IPC library") Signed-off-by: Jeff Queisser <funkzy@users.noreply.github.com> Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Signed-off-by: Erik Bourget <erik@ebourget.net>
The external DCP of T6050 (dcpext0 on J775D) writes its crashlog as a container: a 'CLGH' header and a table of records (ID, offset), where the record whose ID is the container's current ID holds this crash's log. That record can be a container itself; on this DCP the buffer holds one per co-processor and, inside, one per task. The log at the end is an ordinary 'CLHE' crashlog with the usual sections. RTKit looked for 'CLHE' at offset 0 only, so such a log was never valid: the crash was reported "without a readable log" although the log was in the buffer. Follow the container to its log, through at most 8 levels and with offsets that only move forward, both when checking that a log is there and when dumping it. A log selected through a container is not complete while bit 8 of its flags is set. Decode the 'Crl4' register frame, at the offsets of Diljit Singh's T8140 DCP decoder. The DCP logs read on J775D so far carry no register frame section, neither 'Crg8' nor 'Crl4', so this decoder has not run on a real log, only in the host test below. Container logs come from firmware that has just crashed, so the section walk no longer trusts their sizes. A section header must fit in the log; a section's size must cover its own 16-byte header and stay inside the log; and a section is decoded only with at least the footer's 16-byte header after it, since the decoders read up to the section's size from 16 bytes in. A zero size used to loop forever, and a size past the log, or a mailbox section under 28 bytes, made the decoders read past the copy. The version and message strings are bounded by the section's size instead of a terminating NUL, and a buffer shorter than a log header is refused. A buffer that starts with 'CLHE' is checked as before, and a well-formed log there is decoded exactly as before. Testing: on J775D, the crash caused on dcpext0 as in the previous commit now prints "Crashlog container: log 'RTAL' at 0x2000 (depth 2)", the log's message naming the method the firmware could not find, and the firmware's mailbox history (128 entries), whose last entry is that call. The log was complete when the crash was reported. A buffer read back after an earlier crash on the 27.2 firmware has the same layout (logs for the root task, RTAL and one untagged task). These runs predate the section bounds, which change nothing for a well-formed log. A host test, tools/asahi/rtkit-crashlog-tests.py, builds this file with ASan and UBSan and feeds it a log with the layout of that crash (two containers, then RTAL's log with its eleven sections and footer) and malformed logs: zero, oversized and footer-less sections, a truncated section header, mailbox sections of 16 to 27 bytes, short, truncated and undecodable 'Crl4' sections, unterminated strings, short buffers and broken containers. Each is decoded or refused without a loop or a read past the log, and removing any one bound makes it fail. The buffer read back after the earlier crash decodes the same with and without the bounds. The container selection, the record layout, the incomplete flag and the 'Crl4' offsets follow that decoder. Here they are in RTKit, so that every client gets them. Co-developed-by: Diljit Singh <hey@djdev.me> Signed-off-by: Diljit Singh <hey@djdev.me> Signed-off-by: Jeff Queisser <funkzy@users.noreply.github.com> Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Signed-off-by: Erik Bourget <erik@ebourget.net>
a2b7f75 to
edbf321
Compare
DjDeveloperr
left a comment
There was a problem hiding this comment.
Approved.
- Host tests:
tools/asahi/rtkit-crashlog-tests.pypasses on this head (container log decoded, malformed logs refused under ASan/UBSan). Each of the 7 bound mutations (buffer-header, section-header, section-size, footer-room, mailbox-minimum, version-string, message-string) makes it fail, as it should. - M5 Pro (J714sAP): our M5 kit has run this exact code since 11-08, on every RAM boot and on the default SSD boot. DCP, GPU, MTP and ANS sessions all start and run with no RTKit regressions. No co-processor crashed in these boots, so the late and container paths weren't hit on hardware.
Merges cleanly into current integration/aurora.
RyanTheTide
left a comment
There was a problem hiding this comment.
Merged into current integration/aurora, this breaks tools/asahi/rtkit-oslog-tests.py (all six runs in run-host-tests.py): the test extracts apple_rtkit_reinit(), which now calls cancel_delayed_work_sync(&rtk->crashlog_late_work), and its mock struct apple_rtkit has neither that field nor a cancel_delayed_work_sync() stub. Could you extend the oslog harness (field plus a no-op stub) along with this change?
apple_rtkit_reinit() now cancels the late crashlog read (cancel_delayed_work_sync(&rtk->crashlog_late_work)). The OSLog test extracts that function, so give its mock struct apple_rtkit the field and add a no-op cancel_delayed_work_sync(). Older sources don't use either, so the --ref runs still build. Signed-off-by: Diljit Singh <hey@djdev.me>
|
Added 904c734 on top (no rebase; the branch still merges cleanly into integration/aurora): the OSLog harness's mock On a local merge of this head into integration/aurora (8d98b7a), 🤖 Generated with Claude Code |
|
Retested before merging on the M5 Pro (J714sAP, bare metal, SSD boot), kernel 7.3.0-m5-merge: the M5's integration kernel with this round's rebased heads in place of the old ones (every PR's own patch identical to what is merged; logs in work/m5-pr-merge-20261109). CI green. Before merging, this round (these 14 PRs, #1323 and the rebased #1254/#1306/#938/#1316/#1199) was test-merged in order onto integration/aurora f9cf6f9 with no conflicts:
🤖 Generated with Claude Code |
On T6050, co-processor crashes left nothing useful in the log. Display co-processors adopted from the boot loader crashed within seconds, and the only line was "Message to undiscovered endpoint 0x01".
Commits by Diljit Singh and Jeff Queisser. On J716c (MacBook Pro 16-inch, M5 Max) this runs as part of the full T6050 stack (
j716c/t6050-platform): the machine boots to userspace from NVMe with all 18 CPUs, N1 Wi-Fi up and CPU frequency scaling active.Created with Claude Opus 5.5 in Claude Code.