gsp-phys: drain and decode the status queue on a failed CE submission

After a doorbell the GSP-RM status ring accumulated unconsumed records
that nothing drained: the host readPtr stayed behind the writePtr and
the engine's error text was never decoded. Add a bounded drain (max 64
records) using the existing validated ring walk: each record is logged
with its function/status/seqNum, function 0x1006 (OS_ERROR_LOG) is
decoded into exceptType/runlistId/chid/prevXid/errString, and function
0x1020 (GSP_POST_NOCAT_RECORD) into recType/errorCode/subsystem/
bugcheck/faultingEngine plus a bounded printable view of the diagnostic
buffer. The host read pointer advances per consumed record (the normal
consumer side), so the ring keeps free space. Stage 4's poll-timeout
path drains before returning -ETIMEDOUT, and a new read-only debugfs
file gsp-phys-status-drain triggers one bounded drain per read. No
locks are taken and no device register is written.

1 files changed, 281 insertions, 1 deletions

diff --git a/kernel/gsp_phys_booter.c b/kernel/gsp_phys_booter.c
index 943e5f2..6f509e1 100644
--- a/kernel/gsp_phys_booter.c
+++ b/kernel/gsp_phys_booter.c
@@ -135,6 +135,7 @@ bool gsp_phys_boot_requested(void)
 #define GSP_PHYS_MSG_ELEMENT_RPC_RESULT_OFF	64
 #define GSP_PHYS_MSG_FUNC_GSP_INIT_DONE	0x1001
 #define GSP_PHYS_MSG_FUNC_RUN_CPU_SEQUENCER	0x1002
+#define GSP_PHYS_MSG_FUNC_OS_ERROR_LOG		0x1006
 #define GSP_PHYS_MSG_FUNC_GSP_POST_NOCAT_RECORD	0x1020
 
 /*
@@ -2892,6 +2893,225 @@ static void gsp_phys_rx_readptr_publish(u32 read_ptr)
 	dma_wmb();
 }
 
+/*
+ * Status-queue drain + decode on a failed submission. Stage 4's poll-timeout
+ * path calls gsp_phys_status_drain(NULL); the read-only debugfs file
+ * gsp-phys-status-drain calls the same walk with a seq_file sink. It consumes
+ * the unconsumed records with the validated stage-3e ring walk, decodes the two
+ * event payloads that carry engine errors, prints one compact line per record
+ * and advances the host read pointer (the normal consumer side) so GSP-RM's
+ * status-ring free space is restored and a later walk cannot re-read them.
+ * Bounded to GSP_PHYS_STATUS_DRAIN_MAX records, no lock is taken, nothing
+ * blocking is done while walking, and no device register is touched.
+ */
+#define GSP_PHYS_STATUS_DRAIN_MAX	64
+#define GSP_PHYS_STATUS_LINE_MAX	512
+#define GSP_PHYS_STATUS_DIAG_MAX	192
+
+/*
+ * rpc_os_error_log_v17_00 payload (function 0x1006, OS_ERROR_LOG): exceptType
+ * (ROBUST_CHANNEL_* / Xid), runlistId, chid, a 256-byte errString and the
+ * preemptiveRemovalPreviousXid that the v17_00 revision appends. Offsets are
+ * payload-relative (element + 80). This revision carries no engineType; the
+ * errString is the engine/Xid text.
+ */
+#define GSP_PHYS_OSERR_OFF_EXCEPTTYPE	0
+#define GSP_PHYS_OSERR_OFF_RUNLISTID	4
+#define GSP_PHYS_OSERR_OFF_CHID		8
+#define GSP_PHYS_OSERR_OFF_ERRSTRING	12
+#define GSP_PHYS_OSERR_LEN_ERRSTRING	256
+#define GSP_PHYS_OSERR_OFF_PREVXID	268
+
+/* One decoded line: "gsp-phys-status:" prefix in dmesg and in the seq_file. */
+static void gsp_phys_status_emit(struct seq_file *m, const char *fmt, ...)
+{
+	char line[GSP_PHYS_STATUS_LINE_MAX];
+	va_list args;
+	int n;
+
+	va_start(args, fmt);
+	n = vsnprintf(line, sizeof(line), fmt, args);
+	va_end(args);
+	if (n <= 0)
+		return;
+	pr_info("gsp-phys-status: %s\n", line);
+	if (m)
+		seq_printf(m, "gsp-phys-status: %s\n", line);
+}
+
+static void gsp_phys_status_os_error_log(struct seq_file *m,
+					 const struct gsp_phys_rx_record *rec)
+{
+	const u8 *p = rec->buf + GSP_PHYS_MSG_ELEMENT_PAYLOAD_OFF;
+	u32 len = rec->payload_len;
+	char err[GSP_PHYS_OSERR_LEN_ERRSTRING];
+	u32 except_type = 0, runlist_id = 0, chid = 0, prev_xid = 0;
+	bool have_prev;
+
+	if (len > rec->buf_len - GSP_PHYS_MSG_ELEMENT_PAYLOAD_OFF)
+		len = rec->buf_len - GSP_PHYS_MSG_ELEMENT_PAYLOAD_OFF;
+	if (len >= GSP_PHYS_OSERR_OFF_EXCEPTTYPE + 4)
+		except_type = get_unaligned_le32(p +
+						 GSP_PHYS_OSERR_OFF_EXCEPTTYPE);
+	if (len >= GSP_PHYS_OSERR_OFF_RUNLISTID + 4)
+		runlist_id = get_unaligned_le32(p +
+						GSP_PHYS_OSERR_OFF_RUNLISTID);
+	if (len >= GSP_PHYS_OSERR_OFF_CHID + 4)
+		chid = get_unaligned_le32(p + GSP_PHYS_OSERR_OFF_CHID);
+	have_prev = len >= GSP_PHYS_OSERR_OFF_PREVXID + 4;
+	if (have_prev)
+		prev_xid = get_unaligned_le32(p + GSP_PHYS_OSERR_OFF_PREVXID);
+	gsp_phys_nocat_copy_str(err, sizeof(err), p, len,
+				GSP_PHYS_OSERR_OFF_ERRSTRING,
+				GSP_PHYS_OSERR_LEN_ERRSTRING);
+
+	if (have_prev)
+		gsp_phys_status_emit(m,
+			"func=0x1006 status=%u seq=%u elem=%u slot=%u exceptType=0x%x runlistId=%u chid=%u prevXid=0x%x errString=\"%s\"",
+			rec->rpc_result, rec->seq_num, rec->elem_count,
+			rec->first_slot, except_type, runlist_id, chid,
+			prev_xid, err);
+	else
+		gsp_phys_status_emit(m,
+			"func=0x1006 status=%u seq=%u elem=%u slot=%u exceptType=0x%x runlistId=%u chid=%u errString=\"%s\"",
+			rec->rpc_result, rec->seq_num, rec->elem_count,
+			rec->first_slot, except_type, runlist_id, chid, err);
+}
+
+/*
+ * Function 0x1020 (GSP_POST_NOCAT_RECORD) with the diagnostic buffer. Reuses
+ * the NOCAT offsets above; diagBufferLen bounds the printable copy only when
+ * the producer set it, and the copy itself is capped at
+ * GSP_PHYS_STATUS_DIAG_MAX bytes with non-printable bytes dotted out.
+ */
+static void gsp_phys_status_nocat_record(struct seq_file *m,
+					 const struct gsp_phys_rx_record *rec)
+{
+	const u8 *p = rec->buf + GSP_PHYS_MSG_ELEMENT_PAYLOAD_OFF;
+	u32 len = rec->payload_len;
+	char engine[GSP_PHYS_NOCAT_LEN_SOURCE];
+	char diag[GSP_PHYS_STATUS_DIAG_MAX + 1];
+	u8 rec_type = 0;
+	u32 subsystem = 0, bugcheck = 0, diag_len = 0, diag_avail = 0, i;
+	u64 error_code = 0;
+
+	if (len > rec->buf_len - GSP_PHYS_MSG_ELEMENT_PAYLOAD_OFF)
+		len = rec->buf_len - GSP_PHYS_MSG_ELEMENT_PAYLOAD_OFF;
+	if (len > GSP_PHYS_NOCAT_OFF_RECTYPE)
+		rec_type = p[GSP_PHYS_NOCAT_OFF_RECTYPE];
+	if (len >= GSP_PHYS_NOCAT_OFF_BUGCHECK + 4)
+		bugcheck = get_unaligned_le32(p +
+					      GSP_PHYS_NOCAT_OFF_BUGCHECK);
+	if (len >= GSP_PHYS_NOCAT_OFF_SUBSYSTEM + 4)
+		subsystem = get_unaligned_le32(p +
+					       GSP_PHYS_NOCAT_OFF_SUBSYSTEM);
+	if (len >= GSP_PHYS_NOCAT_OFF_ERRORCODE + 8)
+		error_code = get_unaligned_le64(p +
+						GSP_PHYS_NOCAT_OFF_ERRORCODE);
+	if (len >= GSP_PHYS_NOCAT_OFF_DIAGBUFLEN + 4)
+		diag_len = get_unaligned_le32(p +
+					      GSP_PHYS_NOCAT_OFF_DIAGBUFLEN);
+	if (len > GSP_PHYS_NOCAT_OFF_DIAGBUF)
+		diag_avail = len - GSP_PHYS_NOCAT_OFF_DIAGBUF;
+	if (diag_len && diag_avail > diag_len)
+		diag_avail = diag_len;
+	if (diag_avail > GSP_PHYS_STATUS_DIAG_MAX)
+		diag_avail = GSP_PHYS_STATUS_DIAG_MAX;
+	for (i = 0; i < diag_avail; i++) {
+		u8 c = p[GSP_PHYS_NOCAT_OFF_DIAGBUF + i];
+
+		diag[i] = (c >= 0x20 && c < 0x7f) ? (char)c : '.';
+	}
+	diag[diag_avail] = '\0';
+	gsp_phys_nocat_copy_str(engine, sizeof(engine), p, len,
+				GSP_PHYS_NOCAT_OFF_FAULTENGINE,
+				GSP_PHYS_NOCAT_LEN_SOURCE);
+
+	gsp_phys_status_emit(m,
+		"func=0x1020 status=%u seq=%u elem=%u slot=%u recType=%u errorCode=0x%llx subsystem=0x%x bugcheck=0x%x diagLen=%u printed=%u faultingEngine=\"%s\" diag=\"%s\"",
+		rec->rpc_result, rec->seq_num, rec->elem_count,
+		rec->first_slot, rec_type, error_code, subsystem, bugcheck,
+		diag_len, diag_avail, engine, diag);
+}
+
+/* Any other function: one compact header line. */
+static void gsp_phys_status_generic(struct seq_file *m,
+				    const struct gsp_phys_rx_record *rec)
+{
+	gsp_phys_status_emit(m,
+		"func=0x%x status=%u seq=%u elem=%u slot=%u rpc.len=%u checksum=%s",
+		rec->function, rec->rpc_result, rec->seq_num,
+		rec->elem_count, rec->first_slot, rec->rpc_length,
+		rec->checksum_ok ? "ok" : "bad");
+}
+
+/*
+ * Drain at most GSP_PHYS_STATUS_DRAIN_MAX records. Returns 0 when the drain
+ * completed (possibly empty or truncated by the bound), -EINVAL when the queue
+ * was never staged/validated and a negative transport error otherwise. The
+ * read pointer is published per consumed record by the ring walk itself, so an
+ * interrupted walk still accounts for everything it consumed.
+ */
+static int gsp_phys_status_drain(struct seq_file *m)
+{
+	struct gsp_phys_status_queue sq;
+	struct gsp_phys_rx_record rec;
+	u32 drained = 0;
+	int ret;
+
+	gsp_phys_status_queue_init(&sq);
+	ret = gsp_phys_status_queue_link(&sq, &boot_stage.queue);
+	if (ret == -EINVAL) {
+		gsp_phys_status_emit(m,
+			"drain: status queue not staged (queue_pages=%u); nothing to drain",
+			boot_stage.queue.pages);
+		return ret;
+	}
+	if (ret == -EAGAIN) {
+		gsp_phys_status_emit(m,
+			"drain: status TX header not linked yet (readPtr=%u); nothing to drain",
+			boot_stage.status_read_ptr);
+		return ret;
+	}
+	if (ret) {
+		gsp_phys_status_emit(m, "drain: status queue link failed: %d",
+				     ret);
+		return ret;
+	}
+
+	while (drained < GSP_PHYS_STATUS_DRAIN_MAX) {
+		ret = gsp_phys_status_queue_next(&sq, &rec);
+		if (ret == -EAGAIN)
+			break;
+		if (ret) {
+			gsp_phys_status_emit(m,
+				"drain: walk stopped after %u record(s): %d (readPtr=%u)",
+				drained, ret, sq.read_ptr);
+			return ret;
+		}
+
+		switch (rec.function) {
+		case GSP_PHYS_MSG_FUNC_OS_ERROR_LOG:
+			gsp_phys_status_os_error_log(m, &rec);
+			break;
+		case GSP_PHYS_MSG_FUNC_GSP_POST_NOCAT_RECORD:
+			gsp_phys_status_nocat_record(m, &rec);
+			break;
+		default:
+			gsp_phys_status_generic(m, &rec);
+			break;
+		}
+		gsp_phys_rx_record_free(&rec);
+		drained++;
+	}
+	gsp_phys_status_emit(m, "drain: %u record(s) consumed%s, host readPtr now %u",
+			     drained,
+			     drained >= GSP_PHYS_STATUS_DRAIN_MAX ?
+				     " (bound reached; more may remain)" : "",
+			     sq.read_ptr);
+	return 0;
+}
+
 void gsp_phys_boot_rmwait(struct gsp_phys_boot *boot, void __iomem *bar0,
 			  resource_size_t bar0_len)
 {
@@ -5719,6 +5939,14 @@ static int gsp_phys_rmcall_stage4(void __iomem *bar0)
 			pr_err("gsp-phys-boot: rm-call: no semaphore release within %u ms (sem=0x%08x want=0x%08x GPGet=%u GPPut=%u); the channel did not execute the CE block\n",
 			       GSP_PHYS_RMCALL_TIMEOUT_MS, poll,
 			       GSP_PHYS_RMCALL_SEM_PAYLOAD, gpget, gpput);
+			/*
+			 * Consume and decode whatever GSP-RM queued after the
+			 * doorbell (0x1006 OS_ERROR_LOG / 0x1020 NOCAT): the
+			 * burst otherwise stays unconsumed and the engine's
+			 * error text (method fault, faultingEngine, errString)
+			 * is never seen. Advances only the host read pointer.
+			 */
+			gsp_phys_status_drain(NULL);
 			return -ETIMEDOUT;
 		}
 		msleep(GSP_PHYS_RMCALL_POLL_MS);
@@ -6303,6 +6531,44 @@ static const struct file_operations gsp_phys_log_dump_fops = {
 };
 
 /* ============================================================
+ * Debugfs status-queue drain (read-only): gsp-phys-status-drain
+ * ============================================================ */
+
+/*
+ * gsp-phys-status-drain (read-only, mode 0444): every read runs one bounded
+ * status-queue drain (the same consumer the stage-4 timeout path uses) and
+ * prints the decoded records. The device side is untouched: only the host
+ * status read pointer advances, which is the normal consumer-side protocol.
+ */
+static int gsp_phys_status_drain_show(struct seq_file *m, void *v)
+{
+	if (!gsp_phys_gpu_claimed() || !boot_stage.primed ||
+	    !boot_stage.queue.pages) {
+		seq_printf(m,
+			   "gsp-phys-status: inactive: claimed=%u primed=%u queue_pages=%u; no status queue to drain\n",
+			   gsp_phys_gpu_claimed(), boot_stage.primed,
+			   boot_stage.queue.pages);
+		return 0;
+	}
+
+	gsp_phys_status_drain(m);
+	return 0;
+}
+
+static int gsp_phys_status_drain_open(struct inode *inode, struct file *file)
+{
+	return single_open(file, gsp_phys_status_drain_show, NULL);
+}
+
+static const struct file_operations gsp_phys_status_drain_fops = {
+	.owner = THIS_MODULE,
+	.open = gsp_phys_status_drain_open,
+	.read = seq_read,
+	.llseek = seq_lseek,
+	.release = single_release,
+};
+
+/* ============================================================
  * Debugfs trigger (test-enabling; inert unless a live boot ran)
  * ============================================================ */
 
@@ -6604,7 +6870,21 @@ int gsp_phys_boot_debugfs_init(void)
 			err);
 		return (int)err;
 	}
-	pr_info("gsp-phys-boot: debugfs files /sys/kernel/debug/open-iov-vfio/{gsp-phys-state read-only, gsp-phys-log-dump read-only, gsp-phys-unload-rpc write-only, gsp-phys-rm-probe write-only, gsp-phys-rm-call write-only} ready\n");
+	file = debugfs_create_file("gsp-phys-status-drain", 0444,
+				   gsp_phys_debugfs_root, NULL,
+				   &gsp_phys_status_drain_fops);
+	if (IS_ERR_OR_NULL(file)) {
+		long err = IS_ERR(file) ? PTR_ERR(file) : -ENODEV;
+
+		/*
+		 * The status-queue drain is diagnostic; the triggers, the
+		 * log dump and the state snapshot stay registered.
+		 */
+		pr_warn("gsp-phys-boot: debugfs file gsp-phys-status-drain creation failed: %ld (triggers, log dump and state snapshot stay available)\n",
+			err);
+		return (int)err;
+	}
+	pr_info("gsp-phys-boot: debugfs files /sys/kernel/debug/open-iov-vfio/{gsp-phys-state read-only, gsp-phys-log-dump read-only, gsp-phys-status-drain read-only, gsp-phys-unload-rpc write-only, gsp-phys-rm-probe write-only, gsp-phys-rm-call write-only} ready\n");
 	return 0;
 }