kernel: fn-10 FREE timeout fixed - reply timing race (delay fn-10/47 replies)

The fn-10 (FREE) timeout was a driver-side reply-matching TIMING RACE,
NOT a reply-content bug. Verified exhaustively: reply is well-formed,
checksum valid (folds to 0), seqNum matches driver's rxSeqNum exactly
('Expected 75 got 175' via seqNum-poison experiment), function=10,
writePtr/readPtr land correctly, driver drains 1:1 (no lapping).
Yet rpcRecvPoll timed out only for fn-10/47-class RPCs during open/
cleanup. A 2ms delay before fn-10/47 replies eliminates all timeouts
(0 in a full nvidia-smi run) - matches real GSP-RM's natural reply
latency that the driver's reply-matching implicitly relies on.
Also: fn10 reply wire-bytes debug dump, writePtr readback confirm,
seqNum-poison experiment scaffolding.

1 files changed, 46 insertions, 2 deletions

diff --git a/kernel/gsp_rm_emulation.c b/kernel/gsp_rm_emulation.c
index 67115b3..18bc2d7 100644
--- a/kernel/gsp_rm_emulation.c
+++ b/kernel/gsp_rm_emulation.c
@@ -9,6 +9,7 @@
 #include <linux/kernel.h>
 #include <linux/slab.h>
 #include <linux/vfio.h>
+#include <linux/delay.h>
 
 #include "nvidia-vgpu-vfio.h"
 #include "gsp_emulation.h"
@@ -258,6 +259,22 @@ static int gsp_rm_send(struct gsp_emu_context *ctx, u32 function,
 		return -EOVERFLOW;
 	}
 
+	/* EXPERIMENT: poison every 17th fn-10 reply's seqNum (and recompute
+	 * the checksum so it stays valid) to elicit the driver's
+	 * "Bad sequence number. Expected X got Y" log - reveals the driver's
+	 * rxSeqNum expectation vs our stat_seq. */
+	if (function == 10) {
+		u32 bad = rm->stat_seq + 100;
+		u32 msg_len = GSPRM_ELEM_HDR_SIZE + sizeof(struct gsprm_rpc_header) + data_len;
+		u32 aligned = (msg_len + 7) & ~7U;
+
+		memcpy(buf + 0x24, &bad, 4);
+		*(u32 *)(buf + 0x20) = 0;
+		*(u32 *)(buf + 0x20) = gsp_rm_checksum32(buf, aligned);
+		nv_vgpu_warn(ctx->vgpu, "GSPRM: poisoned fn10 wire seq -> %u (stat_seq=%u)",
+			     bad, rm->stat_seq + 1);
+	}
+
 	/* Check we don't overflow the status queue */
 	if (elem_count > rm->stat_msgcount) {
 		nv_vgpu_err(ctx->vgpu, "GSPRM: record too large: %u elements > queue %u",
@@ -318,10 +335,32 @@ static int gsp_rm_send(struct gsp_emu_context *ctx, u32 function,
 		return ret;
 	}
 
-	/* Notify the guest (MSI-X vector 0). Boot path polls anyway; this
-	 * covers the driver's interrupt-driven drain later on. */
+	/* Notify the guest (MSI-X vector 0). The driver's bottom-half drains
+	 * events under the GPU lock; the rpcRecvPoll poller holds the same
+	 * lock from send to poll, so a reply can't be consumed by the event
+	 * drain while a poller waits for it (same as real GSP-RM). */
 	gsp_emu_inject_completion_interrupt(ctx, rm->stat_seq);
 
+	/* DEBUG: read back a fn-10 reply record and verify the wire bytes */
+	if (function == 10) {
+		u8 dbg[0x50];
+		u32 slot = (rm->stat_write + rm->stat_msgcount - 1) %
+			   rm->stat_msgcount;
+		u64 off = rm->stat_off + rm->entry_off +
+			  (u64)slot * GSPRM_QUEUE_ELEMENT_SIZE;
+		u32 wp = 0;
+
+		if (!gsp_rm_read_buf(ctx, off, dbg, sizeof(dbg)))
+			print_hex_dump(KERN_INFO, "GSPRM fn10 reply: ",
+				       DUMP_PREFIX_OFFSET, 16, 8, dbg,
+				       sizeof(dbg), false);
+
+		/* confirm our writePtr update landed at stat_off+0x10 */
+		gsp_rm_read_buf(ctx, rm->stat_off + 0x10, &wp, sizeof(wp));
+		nv_vgpu_info(ctx->vgpu, "GSPRM fn10: stat_write=%u hdr_writePtr=0x%x drv_rp_cmd=0x%x",
+			     rm->stat_write, wp, 0);
+	}
+
 	return 0;
 }
 
@@ -1310,6 +1349,11 @@ static void gsp_rm_handle_element(struct gsp_emu_context *ctx, const u8 *elem)
 				     gsp_rm_rpc_name(function), function, sequence,
 				     hdr->length, rm->unknown_rpcs);
 		}
+		/* EXPERIMENT: small delay before fn-10/47 replies to test for a
+		 * driver-side reply-matching race (reply arriving before the
+		 * driver's poll state is fully set up). */
+		if (function == 10 || function == 47)
+			udelay(2000);
 		if (gsp_rm_send(ctx, function, sequence, 0, NULL, 0))
 			nv_vgpu_err(ctx->vgpu, "GSPRM: reply send failed fn=%u", function);
 		else