diff options
Diffstat (limited to 'tools/guest-diag/wall2/README-session77.md')
| -rw-r--r-- | tools/guest-diag/wall2/README-session77.md | 525 |
1 files changed, 525 insertions, 0 deletions
diff --git a/tools/guest-diag/wall2/README-session77.md b/tools/guest-diag/wall2/README-session77.md index 97f9a84..1ae9a62 100644 --- a/tools/guest-diag/wall2/README-session77.md +++ b/tools/guest-diag/wall2/README-session77.md @@ -536,3 +536,528 @@ data/info/status; compare against the guest's _kgspRpcPostEvent -> gpuNotifySubDeviceEvent expectations) so the guest signals the event and nvidia_poll returns POLLIN; then the same t94-pattern (or a service-side equivalent) durably unblocks both waits per boot. + +**10. Session 92: THE AUTOMATED PIPELINE - fresh boot to VKDEVICE with ZERO manual steps.** +On a fresh r692 boot (cycle params unchanged, gr_forward=0) a single gdb +script (t99.py) carrying two breakpoint handlers drove the client end-to-end: +(a) the instance-phase marker cleaner at eglcore+0xB33D30 (t94 pattern: clear +u16@slot+0xe / u16@slot+0xc / u32@slot to 0 per entry at ptr+n*0x10 for +entries *(obj+0x1428+i*8), cnt *(obj+0x22efc)) - fired CLEAR#1..#5 across +five module objects; (b) the device-phase wait-word chaser at +eglcore+0xDCEBD9 (t79 chain: rbx -> *(rbx+0x70) -> *(sub+0x58)=obj2 -> + off=*(u32)(obj2+0x60), holder=*(obj2+0x58), base=*(holder+0x58), +word=base+off) - found WORD addr=0x734781a86080 val=0x0 and wrote 1. +Result: `VKINSTANCE ok / VKDEVS 2 / VKPICK / VKDEVICE ok family=0` with no +manual intervention (r692 client 1725). The client then sat in the +POST-DEVICE wait (the next phase - allocation/engine-init), which t99 does +not cover. The live_walk PT-walk injector ran alongside and injected the +window/ring VAs (0x4d20000, 0x4923000...; note 0x4b19b10 resolved ap=FB - +the GL init release is vidmem-mapped and skipped by the SYS-only injector). + +**11. HARD LESSON (attach discipline, again).** A gdb attached to a client +that never hits its breakpoints wedges: `continue` never returns, the +timeout's SIGTERM does not tear it down, and the ptrace slot blocks all +later attaches (hit 3x this session: 146084, the t91-on-1725 attach, both +left holding). RULE: only attach with breakpoints that are KNOWN to fire +for the client's current phase, keep windows <= ~60 s, and prefer +self-terminating handlers (hit caps). A wedged attach leaves the client +RUNNING (state R) but unattachable; cycle the VM for a clean environment +when more attaches are needed. + +**12. Continuing the chain (next session).** (1) Identify the post-device +wait of the VKDEVICE-ok client (bt sample once attachable; likely the +allocation/UVM phase or the A8/NvOgl engine-init with its count gate at +lib_base+0x2070b7c=4 -> 0 and/or the 0xdceb80 wait loop - add the t91 +count-clear BP to the t99 bundle if the A8 path is live). (2) Extend t99 +into the "durable harness bundle": marker-clean + word-chase + count-clear ++ (once VKFRAME) the release/alloc phases. (3) The bNotifyList=1 +(gsp_rm_ev_nlist) path stays armed for the event-signal experiment; +post/EVPOST logging re-budgeted (gsp_rm_ev_log=2000 set). + +**13. Session 93: THE ZERO-PTRACE PIPELINE (r693) - VKDEVICE with no gdb-wedge risk.** +Split the harness by risk: (a) ONE gdb (t101.py) for the INSTANCE-phase +marker clears only (base+0xB33D30 handler, clears u16@+0xe/+0xc and u32@+0 +of each entry; self-disables after 24 clears; NO other BPs so it cannot +fire constantly); (b) the WAIT WORDS handled by /tmp/unwait.py - a guest +python poller with ZERO ptrace that scans the newest vk_frame's rw-s +nvidia mappings of exactly 0x4000 bytes and writes 1 to any zero u32 at +mapping+0x80 via /proc/PID/mem (the session-77 geometry, confirmed by t79 +chains: word = the +0x80 of a 16 KB rw-s nvidiactl mapping). Result on +fresh r693 (mdev 261980af): t101 CLEAR#1..#5 then idle; unwait wrote FIVE +wait words (0x7876ead57080, 0x7876f1816080, 0x7876ea47f080, +0x7876ea81a080, 0x7876ead51080); client reached `VKINSTANCE ok / VKDEVS 2 +/ VKPICK / VKDEVICE ok family=0` with NO wedge exposure. live_walk (PT-walk +injector) ran alongside. The client then sat in the post-device wait that +the +0x80 poller does not cover (t102.py = the one-shot safe diagnostic: +attach -> print PC/base/A8-count(base+0x2070b7c)/bt -> detach, NO continue +and NO breakpoints - use it when the slot is free). + +**14. THE RM-LOCK WEDGE ROOT CAUSE + RULE.** A gdb killed (SIGTERM) while +the tracee sits AT a breakpoint leaves the tracee STOPPED; if that stop is +inside an RM api critical section (the rwlock held across an RM call!), the +RM write lock stays held and EVERY other client blocks in +os_acquire_rwlock_write (state D) - observed directly: old client 1725 +stopped by its wedged t99 gdb -> new client 7967 hung `state=D wchan= +os_acquire_rwlock_write` on ioctl 0xc020462b; killing the gdb + `kill -CONT` +resumed 1725 out of the ptrace stop but it resumed INSIDE the same RM wait, +so the lock stayed held until the VM was cycled. RULES: never let a gdb +timeout fire while a tracee is at a frequent-firing BP; prefer BPs that +fire once or self-disable; prefer no-ptrace pollers for anything with a +repeating pattern; the safe diagnostic is attach -> read -> detach without +continue. + +**15. Session 94: THE INSTANCE CLEARS ARE REQUIRED (zero-gdb disproved); t104 is the safe form.** +Pure zero-gdb run (fresh r694, client + unwait.py ONLY, no gdb): unwait +wrote three +0x80 words and the client still ended `VKFAIL vkCreateDevice +... -4` - WITHOUT the instance-phase marker clears the device gate fails +even with the words. With t104.py (single BP at +0xB33D30; clears +u16@+0xe/+0xc/u32@+0; self-exits on cleared>=8 OR chits>=40 OR 25 s since +the last clear -> returns True so the script tail runs and batch gdb exits +cleanly, no outer-timeout dependence) + unwait + live_walk: CLEAR#1..#5, +two words written, client reached `VKINSTANCE ok / VKDEVS 2 / VKPICK / +VKDEVICE ok family=0` (r694 client 3725). The client then sat in the +post-device wait again; the t102 diagnostic could not attach because the +t104 gdb still held the slot (its 25 s-idle exit never fired - no +post-instance B33D30 hits - and its 150 s timeout likely fired at a stop += the known wedge risk). NEXT FORM: make t104 detach ITSELF from inside +the handler once the clears are done (`gdb.execute("detach")` from the +stop handler; the tracee resumes; the script ends and gdb exits) so NO +gdb is ever held while the client runs - then t102 always has the slot +and the wedge class disappears end-to-end. + +**16. The allocation/post-device phase is the remaining gate.** With +VKDEVICE green the client waits in a site that is neither the +0x80 word +pattern nor (likely) the A8 count path; the next session should (a) get +the detach-first t104 live, (b) run t102 immediately after VKDEVICE to +name the wait (read PC/bt/A8 count = base+0x2070b7c), and (c) inspect the +service for this client (pushes decoded / releases applied / counter +pub_calls) to see whether the allocation needs the live injections only +or a service-side gap. + +**17. Session 95: THE GDB THREAD-STOP INTERFERENCE + the SIGKILL nuance.** +The t105 attach (t=1.5 s, before the client's worker threads spawned) left +four worker threads in `ptrace_stop.part.0` (futex) - the client's main +thread span waiting on them, so the client froze at the post-device wait +with the gdb holding the trace. TERM/INT/HUP on the wedged gdb were all +ignored (batch gdb stuck in continue). SIGKILL on the gdb (1584) was tried +with the reasoning that all stopped threads sat at futex (NO RM lock held): +result - the tracer died, the tracees DETACHED+RESUMED (client 1518 +SURVIVED with its workers back in futex_wait_queue; contrast session 88 +where SIGKILLed-tracer tracees were KILLED mid-syscall). So the SIGKILL +outcome depends on the tracee's stop context; the mission's never-SIGKILL +rule stands, but this datapoint matters when judging recoverability. +After the gdb died, 1518 still held the RM write lock from its own +post-device wait (its wait word was no longer polled because unwait.py +tracks the NEWEST vk_frame and a fresh test client 6555 was launched and +blocked D-state on os_acquire_rwlock_write) - the unwait-newest coupling +must be replaced by ALL-clients polling in the next form. + +**18. HARNESS DESIGN RULES (accumulated).** (1) A gdb attached across +thread-spawn windows stops worker threads and freezes the client - attach +only AFTER all threads exist, or ensure the gdb explicitly resumes new +threads, or do the work with NO gdb. (2) Any gdb that must run through +thread-spawn windows MUST self-detach quickly (the instance phase spans +~10-20 s and the clears arrive in ~5 bursts) and NEVER rely on outer +timeouts. (3) unwait.py should poll EVERY live vk_frame (not just the +newest). (4) The durable answer for all of this is the service-side +folding: the instance markers and the +0x80 words are guest-RAM writes a +kernel-side service can perform on the same triggers (the marker semantics +and the word semantics are understood) - that removes gdb and /proc +helpers from the loop entirely. + +**19. Session 96: THE DETACH-FIRST CLEARER PROVEN (t106) + the orphan-tracer plague.** +t106.py (single +0xB33D30 BP; clears markers; detaches FROM THE HANDLER as +soon as cleared>=5 or chits>=14: `gdb.execute("detach")` + return True so +the batch gdb exits) on fresh r696 (mdev 241af1c1): CLEAR#1..#5, +`BC-DETACHED cleaned=5 chits=5`, `T106-DONE chits=5 cleared=5`, +`TracerPid: 0` - THE SLOT IS LEFT FREE. unwait.py wrote five words and the +client (1549) reached `VKINSTANCE ok / VKDEVS 2 / VKPICK / VKDEVICE ok +family=0`. THE CLEAN FORM OF THE CLEARER EXISTS NOW. + +**20. THE ORPHAN-TRACER PLAGUE (root cause of every t102 failure).** Every +INTERRUPTED gdb attempt leaves an attached orphan: (a) piping gdb to +`head` closes the pipe early and the gdb stays attached (hit twice); (b) an +ssh command dying/timing out mid-gdb-add leaves the gdb running (hit +again). Symptoms: later attaches fail with `Could not attach ... already +traced by process N` / `ptrace: Inappropriate ioctl for device` and the +t102 log stays empty. RECOVERY (session-95 evidence): TERM is usually +ignored (wedged in continue); SIGKILL the orphan + `kill -CONT <client>`; +the tracee SURVIVES when it was running/at-futex and detaches cleanly +(TracerPid 0). STRICT DISCIPLINE: never pipe gdb output (redirect to a +file, read it after); never let an ssh command end while a gdb may be +attached (generous timeouts); after every gdb run verify TracerPid 0. + +**21. THE NEXT FORM (t107, one gdb, one window).** Combine the proven +clearer and the diagnostic in ONE batch gdb: attach -> clears -> detach -> +`python time.sleep(...)` idle -> RE-ATTACH (gdb can attach again after +detach) -> read PC / bt / A8 count (t102 content) -> detach -> print - +one ssh session, one window, everything self-contained, no orphan risk +(every path ends in an explicit detach; wrap each phase in try/except with +a final detach). Expected: names the post-device wait (allocation/UVM vs +A8 count base+0x2070b7c) so the allocation can be passed and the first +VKFRAME reached. + +**22. Session 97: THE DEEP SUBMISSION STATE + THE COUNTER-SLOT WEB.** +The r696 client (1549) reached the deepest state yet: the service reported +`gpfifo done=11576 pushes=10932 counter pub_calls=1356` and climbing +(gpfifo done was 0 in the pre-pipeline boots) - the client submits the full +work stream and the service decodes/processes it (pairs=14395 map=14318, +ipins=9240 from live_walk). The client then sits in the KNOWN userspace +post-device spin (main thread `running` in all samples; one tid in +os_acquire_rwlock_read). NEW: a counter-slot collision spam +(`counter auto ... pa=0x5fedfff0 rejected (slot owned by another channel; +not installed)`, 232+ callbacks suppressed) - the 0x20400f000 injection +resolved the WHOLE counter VA family to ONE page, so both live channels +collided; the manual bypass `echo <h>,<pa> > .../parameters/sema_counter` +(h_object,pa syntax, main.c:2965) was applied for both handles +(0xbeee0100,0xbeec0100 -> 0x5fedfff0) and pub_calls jumped 1356 -> 3739. +The client gate (VKDEVICE -> frames) persists: its remaining wait is the +userspace spin word NOT covered by the +0x80/16K poller (candidate: the +tracker/counter the service now advances - watch whether pub traffic +alone resolves the spin, else t107-GDB the spin site). ENVIRONMENT: one +orphan gdb (10092 on 1549) + stale channels (beec0100) from prior +attempts; the orphan-kill discipline applies (SIGKILL by PID + CONT + +verify TracerPid). + +**23. THE IOCTL-ARG SAMPLING AXIS (no ptrace).** /proc/<tid>/syscall shows +the running ioctl's ARGS (fd, cmd, arg) when caught - sampling the main +thread repeatedly during an ioctl-loop phase names the exact stuck RM +control without any gdb. Use it before ptrace-based diagnostics when the +thread does syscalls at a catchable rate. + +**24. Session 98: THE POST-DEVICE SPIN NAMED - THE SEC2 SCRUBBER AUTH-TAG WAIT.** +perf (no ptrace!) on the spun client: top symbol `channelReadChannelMemdesc` +24.33% (then scheduler internals) - the guest's nvidia driver hot-loops +reading the CHANNEL MEMDESC. Source decode (nvidia-570.144-reference, +sec2_utils.c): the only reference caller is +`_sec2utilsUpdateGetPtr` -> `channelReadChannelMemdesc(pChannel, +authTagBufSemaOffset)` inside `_sec2utilsGetNextAuthTagSlot`, whose loop +waits for the scrub auth-tag slots to free; `authTagBufSemaOffset = +finishPayloadOffset + CHANNEL_ENGINE_SEMAPHORE_SIZE` (4). So the spin = +the SEC2 MEMORY-SCRUBBER channel waiting for its auth-tag semaphore (a u32 +inside the channel memdesc buffer) to advance - the GPU never delivers it +in our emulation, so the client waits forever (each poll = one full memdesc +transfer = the 24% cost). THE FIX DIRECTION: the service must complete the +scrubber's semaphore updates - the scrubber channel registers in the +service (`scrubber channel 0x... detected (gpfifo=... userd=...)`) and its +submits carry semaphore releases targeting the auth-tag VA +(pbGpuVA + authTagBufSemaOffset) in the channel buffer; on decode, write +the release value to that VA's page (the channel buffer is a guest-RAM +allocation the service can resolve/pin; the pending queue holding 17 +entries is the suspect pool for the unresolvable ones - inspect +svc_pending[]). Service-side counter to watch after the fix: the scrub +loop exits, the client proceeds to the allocation/pipeline. Tool: perf +record/report on the guest is the no-ptrace spin-pointer (`perf record -p +<pid> -- sleep 3; perf report --stdio --sort=symbol,dso`). + +**25. Session 99: THE SCRUBBER GATE CONNECTED TO THE CE CHANNELS' ok=0.** +chan_dump on r696 (client 1549 spun): six channels - +`h=0xbeee0100 eng=0 gpfifo=0x44a0000 userd=0xfee00 ok=1 get=6 sub=6354 rel=0x4213020 crel=0x5fedfff0 notif=0x11cd51060` +`h=0xbeec0100 eng=0 gpfifo=0x4cc0000 userd=0xfee00 ok=1 rel=0x4923020 crel=0x5fedfff0` +`h=0xbeec0104 eng=0 gpfifo=0x4d20000 userd=0xfee00 ok=1 rel=0x4b17e30 crel=0x5fedffe0` +and the CE-class channels `beee0101 (eng=11, gpfifo=0x4500000 userd=0x8f600 as=2 ok=0)`, +`beee0102 (eng=12, gpfifo=0x4560000 userd=0x8f400 ok=0)`, `beed0101 (eng=12, +gpfifo=0x49c0000 userd=0x8f200 ok=0)` - ALL ok=0: the CE userd discovery +(failed probe: EAGAIN 0/0 or EINVAL) means no CE pump, no CE sema applies, +so the SEC2 scrubber channel (a CE-class channel) never sees its auth-tag +semaphore advance and the client spins in _sec2utilsGetNextAuthTagSlot. +The service's candidates (registered PA, ring+0x10000 in both apertures, +8-slot list) all miss for the CE channels. `find_userd` (FB scan for a +live put@0x8c/get@0x88 pair) found ZERO candidates - the CE userds are not +in FB with live puts (either the client's PUT writes go to a page the +service's candidates miss, or the CE userds genuinely idle). A raw host-RAM +shape scan (put in 1..65535, get<=put) is too noisy (24 hits in the first +28KB of BIOS-era low RAM) - needs tighter validation. NEXT APPROACH: find +the REAL userd page by DIFF-WATCH - sample the candidate pages (and the +CE ring pages) twice around a scrub submit and diff for the page whose ++0x88/+0x8c pair changes; the guest kernel writes GP_PUT there, so the +changing page is the true userd. Then fix the discovery (or add a +sema_userd-style injection param) so the CE pump engages and the scrubber +completes. NOTE: the GR channels' userd=0xfee00 (as=2, FB) and ok=1 with +get=6/sub=6354 - the GR machinery runs fine; only the CE/scrubber path is +dark. + +**26. Session 100: THE CE USERD HUNT EXHAUSTED THE STANDARD LAYOUTS; THE CIRCULAR WAIT.** +Candidates examined for the CE userds this session: (a) the registered FB +offsets (0x8f600/0x8f400/0x8f200 as=2) - ALL ZERO in the FB shadow +(sema_vidmem_dump 0x8f100,0x600 twice); (b) the ring-PA + 0x10000 linear +guess - random/zero/table garbage (the allocations are NON-CONTIGUOUS); +(c) the PDB walks of gpfifo+0x10000 (0x4501000->pa 0x125e91000, +0x4561000->pa 0x132032000, 0x49c1000->pa 0x11bddd000 via pdb 0x1152f4000) +- ALL THREE PAGES ALL ZERO. The CE userds were never written - and the +deeper reading: the SEC2 scrub flow is a CIRCULAR WAIT: the scrubber waits +for its previous scrub pushes to be CONSUMED (the auth-tag sema advances +only when the GPU runs the scrub) -> the consumption needs the CE pump -> +the CE pump needs a live userd -> the userd is written BY SUBMITS -> the +submits are held by the wait. In a working boot the guest's first scrub +push happens BEFORE the wait loop (the loop only waits when the slots are +full) - so in our boots the FIRST scrub push must have gone into the CE +ring, the service failed to consume it (ok=0/userd dark), and the client +now waits for a completion that will never come. + +**27. THE DIRECT BYPASS (next session, ranked).** (1) Write the auth-tag +semaphore in the CHANNEL BUFFER (memdesc) page directly: the scrub loop's +`_sec2utilsUpdateGetPtr` reads `channelReadChannelMemdesc(pChannel, +authTagBufSemaOffset)` = a u32 at memdesc+finishPayloadOffset+4; advancing +that value frees the slots and unblocks the client WITHOUT the CE pump. +The memdesc = the channel buffer allocation (a VA in the client's space); +resolve it via the PDB (the guest's channel struct gives the buffer VA; +the service's channel registration/alloc params carry it) and write the +incremented value from the service (or the host RAM file). (2) OR decode +the scrub pushes the service already sees (check sema-push for the SCRUBBER +channel - its submits carry the auth-tag VA; the release decode should +target it; the service's release applies would write the sema if the VA +resolves). (3) The registered FB userd offsets being zero suggests the +client's kernel maps the userd through a VA whose PA the discovery misses; +the diff-watch (two samples around activity) remains the fallback proof. + +**28. Session 101: THE LOOP SEMANTICS + perf trace (NO-PTRACE SYSCALL TRACING).** +The wait loop decoded exactly (sec2_utils.c:420-441): +`while (nextPut == pSec2Utils->authTagGetIndex) { gpuCheckTimeout(); +authTagGetIndex = _sec2utilsUpdateGetPtr(); osSpinLoop(); }` - it exits +when the memdesc sema (u32 at pChannelBufferMemdesc + +authTagBufSemaOffset; authTagBufSemaOffset = finishPayloadOffset + 4) +advances past nextPut; it also has a GPU timeout that would error out. +perf trace on the spun client (no ptrace!) revealed the live pattern: +tid 1793 = a 10ms-timed futex loop (WAKE val=1 then +WAIT_BITSET|CLOCK_REALTIME 10ms - the paced retry); tid 1788 = repeated +`openat -> read(fd, 299 bytes) -> close -> futex-wait` - a transient-fd +POLLING READER of a small blob (the fd is opened and closed each cycle, so +fd 28 no longer exists; the client's persistent fds: /dev/nvidia-modeset +(10), /dev/nvidia0 (11/12/14/15), GLCache .toc/.bin (16/17), memfd +\"allocation fd\" (18)). The 299-byte read is the likely userland face of +the memdesc read path (the 24% channelReadChannelMemdesc hot loop). +NEXT: (a) catch the transient fd path by sampling `ls -l /proc/<pid>/fd` +every ~0.2 s in a loop around the burst (or perf trace -s during a burst); +(b) if it is a driver read() of the memdesc, resolve its buffer and write +the auth-tag sema value (advance past nextPut) via the RAM file; (c) the +loop timeout (gpuCheckTimeout) may eventually error the client - the write +must land first. + +**29. Session 102: fd-sampler miss, no nvidia debugfs; the memdesc hunt narrows.** +The 0.15 s /proc/1549/fd sampler over 20 s caught NO transient path (the +open/read(299)/close reader is bursty or dormant between bursts; the static +fds are /dev/nvidiactl, /dev/nvidia0, /dev/nvidia-modeset, a socket, the +GLCache .toc/.bin pair, and a memfd "allocation fd"). No nvidia debugfs +tree exists in the guest. Remaining ranked paths to the auth-tag sema +(memdesc + finishPayloadOffset + 4): (1) content-locate the scrubber's +channel buffer by its method stream (the C5B5/C56F shapes: SET_OBJECT +0xc5c0/0xc5b5, headers 0x200121ed/0x200120a9 observed in the session-78 +window dumps) and read/write the sema inside; (2) the scrubber channel's +own sema-push decodes (its pushes carry the auth-tag VA = pbGpuVA + +authTagBufSemaOffset; grep the boot's sema-pushall for the scrubber +channel id and read the rel= VA - then PDB-walk it); (3) sample the fd +burst narrower (0.02 s) right after a client restart when the burst is +hot. The service-side ideal: on detecting the scrubber channel, resolve +its channel buffer and pre-advance the auth-tag sema (a durable fold). + +**30. Session 103: THE SCRUB STREAM FOUND; ONE RELEASE DELIVERED; THE SEMA PAGE STILL AMBIGUOUS.** +Content-located the CE/scrub init method stream (headers 0x200121ed/ +0x200120a9 searched): full stream at `pa=0x114e98000` = SET_OBJECT +0xC5C0/0xC5B5 (0x20012000/0x20012080 headers), engine-init methods +0x200121ed(3)/0x200120a9(1)/0x2001209c(0x0c000001), bulk methods +(0x8000xxxx), then TWO REPORT_SEM releases in one buffer: +`0x200426c0 00000000 04b19b10 ...` (va=0x4b19b10) and +`0x200426c0 00000000 04b17e30 ...` (va=0x4b17e30), tail 0x2001c00d +70/68. Twins at pa=0x1026ad000+0x87c and pa=0x12afba000+0x87c (identical +content at identical offsets - multi-mapped copies). Release resolution: +`0x4b17e30 -> pa=0x114efbe30 (SYS) cur=1` - THAT release WAS delivered (the +service applied it, cur=1). `0x4b19b10` resolves via the walker's big-half +2MB branch to FB 0x660b10 holding garbage (0xD9F26F94) - poke_vidmem +tests ([0x660b10]=1 then =0x40000000) did NOT flip the client, and the +linear-block guesses (buffer VA 0x4b00000 <-> stream pa 0x114e98000, sema +candidate 0x114eb1b10) read all zero. NEXT: the auth-tag sema page must be +picked by VALIDATION (the existing value must be a small plausible +GetPtr): walk 0x4b19000 returning ALL chains (small/64K/2MB both +apertures), pick the page whose u32 at +0x1b10 (or the offset the memdesc +actually uses) is a small number; or take the buffer aperture from the +channel's alloc params (the service's registration) and walk with that +aperture exclusively. The fix remains: advance that u32 (write via the +host RAM file if SYS, poke_vidmem if FB). + +**31. Session 104: THE SEMA VA 0x4b19b10 IS NOT THE LOOP'S PAGE; THE KPROBE IS THE ANSWER.** +The validated multi-chain walk (small-4KB and big chains BOTH) resolves +VA 0x4b19b10 -> FB 0x660b10 (both chains converge; the guest's own PTs say +the object lives in vidmem). poke_vidmem writes at 0x660b10 (0x1, +0x40000000) and 0x660b14 (0x1, 0x40000000) LANDED (verified via +sema_vidmem_dump: [0x660b10]=0x11112222) yet the client does not flip and +perf still shows channelReadChannelMemdesc at 24.52%. CONCLUSION: the +REPORT_SEM VA 0x4b19b10 (and 0x4b17e30) are NOT the auth-tag sema the loop +reads - they are the GL-init release objects; the real auth-tag sema is at +pChannelBufferMemdesc + finishPayloadOffset + 4 (a VA and page we do not +yet know; finishPayloadOffset is NOT 0x19b10). THE DEFINITIVE INSTRUMENT: +a guest kprobe on channelReadChannelMemdesc (the offset argument = %si = +the authTagBufSemaOffset VALUE; and the pChannel pointer lets us read the +channel struct -> pChannelBufferMemdesc): `echo 'p:crcd +channelReadChannelMemdesc offset=%si' >> /sys/kernel/tracing/kprobe_events` ++ enable the event + read tracing pipe WHILE the loop runs. This names the +offset and the memdesc in one shot, then the sema page = walk(memdesc+off) +and the advance (RAM file if SYS; FB + poke if the converged mapping). + +**32. Session 105: KPROBE BLOCKED (notrace); THE BAR1-PATH ANALYSIS; THE CHANNEL-FIELD OFFSETS.** +(1) The kprobe on channelReadChannelMemdesc is IMPOSSIBLE: the guest's +dmesg says `trace_kprobe: Could not probe notrace function +channelReadChannelMemdesc [nvidia]` - the function is annotated notrace +(ftrace/perf-probe/BPF-kprobe all blocked). The tracefs filesystem had to +be mounted first (mount -t tracefs tracefs /sys/kernel/tracing) and it +already carries UVM kprobes from earlier sessions (uvmt/uvch/uvbp/uvtw/ +uvsv...). The static sec2utils functions (the callers) are absent from +kallsyms (inlined) - no probe target on that path. +(2) BAR1-path analysis: the guest driver's memdesc read uses +TRANSFER_FLAGS_USE_BAR1|SHADOW_ALLOC|SHADOW_INIT_MEM - a CPU read of the +GUEST'S BAR1 mapping, which the mdev mmap maps onto the HOST's vidmem +shadow (the same buffer poke_vidmem writes). The pokes at FB 0x660b10/ +0x660b14 LANDED (verified) yet the loop did not advance, so the memdesc +page is NOT the FB 0x660b10 the PT walk converged on (VA 0x4b19b10 belongs +to the GL-init release object, not the channel-buffer memdesc). +(3) The channel registration parse exposes the guest-visible channel +fields and their alloc-param offsets (gsp_rm_emulation.c +gsp_rm_register_channel: GSPRM_CHAN_GPFIFO_OFFSET/ENTRIES, ENGINE_TYPE, +CID, INSTANCE_MEM, USERD_MEM(+APERTURE), NOTIFIER_MEM(+APERTURE)) - the +channel-buffer/memdesc field (pChannelBufferMemdesc) is not among them; +the next session should dump a CE channel's FULL alloc params (the +service's rate-limited alloc dumps or a fresh boot) and look for the +channel-buffer VA/PA field, then sema = buffer + finishPayloadOffset + 4 +(per-channel offset, e.g. the 0x19b10-style for the GL channel). +(4) Fallback if the field is not in the params: per-VA content hunt for +the auth-tag sema VALUE (the retprobe would have given it; without +kprobes: the sema value = a small slot counter - scan the CE channel's +allocation candidates for a plausible counter that CHANGES across two +samples). + +**33. Session 106: THE CHANNEL BUFFER IS NOT A CLIENT PARAM; THE TAIL SWEEP AND HASH SCAN NEGATIVE.** +NV_CHANNEL_ALLOC_PARAMS (alloc_channel.h:300-341) layout mapped to the +service offsets: gpFifoOffset@8/entries@16, engineType@128, cid@132, +instanceMem@144, userdMem@168, ramfcMem@192, mthdbufMem@216, +hPhysChannelGroup/internalFlags, errorNotifierMem@248... - THE CHANNEL +BUFFER (pChannelBufferMemdesc) IS NOT IN THE PARAMS: it is a +driver-internal memdesc created by channelAlloc, so the alloc-params path +cannot name it (the kprobe/debuginfo path was the right one; it is +notrace-blocked). The finish-payload tail of the stream page +(0x114e98000 +0xd4..+0x118) was swept with 0x40000000 (18 u32s; the +pre-sweep values: +0xd8=0x68000000 finish marker, +0xe0=0x901025a6, ++0xe4..+0xec=0x8000xxxx methods) - no flip. A 16-page high-entropy scan of +0x114e98000..0x114ea8000 for the auth-tag SHA-256 array: ZERO high-entropy +32-byte blocks (the hash array is elsewhere / another allocation). NEXT: +(1) the memmgrMemDescBeginTransfer SHADOW insight - the read happens from +a FRESH kmalloc'd shadow copied from the memdesc each call; the shadow's +source = the memdesc's backing page; the memdesc page must be found by +TRANSFER-TIME properties (not the VA walk); (2) or a guest perf hardware +watchpoint on the driver's BAR1 ioremap VA + the (unknown) memdesc offset; +(3) or the service-side broad assist: increment a RANGE of plausible FB +sema cells periodically (blind but bounded), watching for the flip. + +**34. Session 107: FB ASSIST SWEEPS NEGATIVE - THE READ IS NOT FB-SOURCED; THE TWINS ARE THE NEXT TARGET.** +Two bounded FB "sema assist" sweeps (distinct values per cell, +0x40000000|idx): (a) the walked page 0x660b00..0x661000 (320 cells) - no +flip; (b) the CE-channel allocation cluster 0x8f000..0x90000 (1024 cells, +where the registered userds live) - no flip; perf re-confirmed +channelReadChannelMemdesc 23.13% (the loop still runs). CONCLUSION: the +memdesc read does NOT come from the FB shadow the CPU can poke - the +transfer's SHADOW_INIT must read the memdesc through a path that bypasses +these bytes, or the memdesc backing is SYSTEM memory via an unknown VA. +NEXT (one-minute test): the STREAM TWINS - pa 0x1026ad000 and +0x12afba000 hold BYTE-IDENTICAL copies of the CE method stream (verified at ++0x7c0/+0x880: same 0x68000000 finish marker area, same 0x200120a9/9c +methods) - one of them is very likely the memdesc BACKING in sysmem (the +driver copies the same stream per channel/boot). Sweep BOTH twins' +stream-area pages (reuse the assist code; 1 page each) and watch for the +flip; if it flips, bisect the winning page to the sema cell and make it +durable (host RAM file writes = zero-cost, no poke_vidmem needed for +sysmem). Failing that: content-diff the twins across a driver transition +(the memdesc copy updates during submits; the copy that CHANGES is the +backing). + +**35. Session 108: THE CONTENT-DIFF - 9 ACTIVE PAGES + THE CONSTANT-READ DEDUCTION.** +Page-hash diff over three +/-256KB windows (twins 0x1026ad000/0x12afba000, +stream 0x114e98000) across 15 s: NINE pages change: +0x102690000, 0x102698000 (440 word diffs - a buffer written continuously = +the push copy!), 0x1026a7000 (+0xe8: 934 -> 940 - a slow clean counter), +0x1026b3000 (+0x48: 32768 -> 1 transition), 0x1026b5000 (+0x244/+0x24c: +24987 -> 32765, two u16s at ~650/s), 0x1026c2000 (+0xe8: 232 -> 3, a +wrapping counter mod ~233), 0x1026e6000 (+0x18: 2764 -> 1930, +0x88/+0x90 +decreasing - countdowns), 0x114e6b000, 0x114e6e000. THE DEDUCTION: the +stuck loop's read value must be CONSTANT (its page shows no writes; the +GPU never advances the sema), so the auth-tag sema is a static cell - +likely zero - and the fix is to make the read NONZERO (advance it) at the +right page. None of the 9 changing pages is it (their cells move on their +own). NEXT: (1) restrict the search to CONSTANT pages among the CE +channel's candidate backing (the twins region pages that DID NOT change +but sit adjacent to the active set); (2) target the sema cell: the cell +that equals nextPut (small constant, e.g. 0) at the memdesc+off; sweep the +CONSTANT pages' zero u32s in a bounded ring around the twins/active set +with 1 (the sysmem write is free); (3) the durable service fold once +found. + +**36. Session 109: THE BURST vs HEARTBEAT DISCOVERY + THE 200ms READER.** +perf trace of the whole process over 10 s with -e ioctl: ZERO ioctls from +ANY thread; meanwhile the process shows a strict 200 ms pattern on thread +1788: `openat(filename ptr 0x5eaec740) -> read(fd 28, count 299) -> close` +(the transient fd the fd-sampler missed!) and thread 1793's 10 ms +futex re-arms. The perf-reported 24% channelReadChannelMemdesc (a kernel +function only reachable via RM calls) CONTRADICTS the zero-ioctl window: +the hot kernel work is BURSTY (periodic rounds between the 200 ms +heartbeats), not continuous. The 299-byte blob read every 200 ms = the +client's health poll (unnamed path; candidate: /proc/driver/nvidia/... +informational node - find it by reading /proc/PID/io or by narrowing the +sampler to the 200 ms phase). THE MODEL NOW: the client idles (futex +waits) + wakes every 200 ms to poll a node + periodically runs RM bursts +(the burst = a full retry round hitting channelReadChannelMemdesc). NEXT: +(1) name the 299-byte node (it may BE the wait's condition - a status the +service must change); (2) capture the BURST with perf (a long record + +per-thread breakdown) to see which thread runs the memdesc reads (the RM +burst thread) and correlate with the host-side RPC traffic in the same +window (the host dmesg RPC lines during a burst = the exact RM call!). + +**37. Session 110: THE LOOP IS CONTINUOUS INSIDE ONE LONG IOCTL (THE LOCK MODEL CLOSED).** +(1) The 299-byte/200ms reader: the filename pointer 0x5eaec740 is NEVER in +the client's maps (30 Hz sampler over 15 s, zero hits) yet openat returns +28 every cycle - a decode artifact/transience, and at 5 reads/s it is +irrelevant to the 24% blocker. Treat it as a RED HERRING. (2) A 20-second +perf record (80K samples): channelReadChannelMemdesc 24.65% + a scheduler +family (pick_next_task_fair/update_curr/pick_eevdf/__schedule/ +schedule_timeout/os_schedule ~30% total) = the SEC2 wait loop running +CONTINUOUSLY. The earlier zero-ioctl windows are explained: THE MAIN +THREAD SITS INSIDE ONE LONG-LIVED ioctl (entered hours ago; the loop runs +in the kernel inside it) - and that ioctl HOLDS THE RM WRITE LOCK, which +closes the lock model: tid 1791 waits on the RM read lock, new clients +block D-state (os_acquire_rwlock_write), all consistent. (3) PEBS/ +mem-loads events are unavailable in the guest perf (no memory-address +sampling) - the read address cannot be sampled. Instruments for the sema +address are now exhausted short of the notrace blocker or the blind +service-side assist. +NEXT: (1) the blind assist, refined: the loop's READ is CONTINUOUS and +the sema is CONSTANT - sweep ONLY constant small-value cells in the CE +candidate pages (see session 108's active set for the region), one value +at a time, 2 s per batch, watching the flip; (2) or a graft: since the +loop runs inside the client's blocked ioctl, unloading the CLIENT (kill) +releases the RM lock and the fresh client restarts the same phase - use +fresh-client runs for any A/B of service-side fixes; (3) the durable +service-side fold remains the endgame once the cell is known. + +**38. Session 111: THE FB IS FULLY DISPROVED (WHOLE-FB FILL, NO FLIP); THE SYS-FILL WEDGED THE GUEST (CYCLE NEXT).** +(1) scan_vidmem for the stream signatures (0x200121ed, 0x200120a9) and even +0x68: ZERO hits across 256MB - THE FB SHADOW WAS ALL ZEROS (before any +pokes): the GPU-side objects are never written in our emulation (the +driver->GPU DMA never runs), so the driver's memdesc SHADOW_INIT copies +zeros and the sec2 loop reads 0 forever (nextPut==authTagGetIndex==0 -> +infinite wait; the complete model). (2) The refined assist: swept FB +0x80000..0x90000 (16384 cells, distinct values; 60s/32KB via poke_vidmem) +- no flip. (3) THE DEFINITIVE TEST: `fill_vidmem 0x40000000` filled the +WHOLE 256MB FB shadow in-kernel (`vgsp: fill_vidmem value=0x40000000 +size=0x10000000 done`) - STILL NO FLIP: THE LOOP'S READ DOES NOT COME FROM +THE FB SHADOW AT ALL; the channel-buffer memdesc is SYS-BACKED (or another +backing) in our emulation, not the FB. (4) The follow-up SYS fill (128 +candidate pages near the active set overwritten with 0x40000000 via the +RAM file) CLOBBERED LIVE DRIVER DATA and WEDGED THE GUEST (SSH banner +timeout; QEMU alive) - the next session MUST CYCLE (fresh boot); lesson: +never bulk-overwrite pages adjacent to the identified active set (0x102698000 +was a hot staging buffer). +NEXT: (1) fresh cycle; (2) the sema is a SYS page - apply the full-page +marker fill ONLY to genuinely-constant, non-active pages (re-run the +content-diff first, then fill the constant set in small batches with a +client check after each, NOT the active neighborhoods); (3) or the +service-side durable route: have the SERVICE write the marker into the +channel-buffer page once it can resolve it (the memdesc VA = the CE +channel's buffer; the service's channel registration fields + the PT walk +give the page candidates). |
