[PATCH v2 07/31] gpu: nova-core: distinguish async GSP RPC traffic in debug logs

The receive path logged every message at the transport layer and did not
distinguish events from command replies. Async sends shared the RPC
sequence with waited-for commands, and GSP-initiated events arrived
with that field unset.

Print a distinct debug line for async send, sync send, event, and
command reply. Number async sends and events with driver-local counters,
which wrap rather than trap, since they only number log lines.

IS_ASYNC selects only the send log line. Every command still carries the
next RPC sequence on the wire.

Assisted-by: Cursor:claude-opus-5
Reviewed-by: Timur Tabi <[email protected]>
Reviewed-by: Zhi Wang <[email protected]>
Signed-off-by: John Hubbard <[email protected]>
---
 drivers/gpu/nova-core/gsp/cmdq.rs             | 111 ++++++++++++++----
 .../gpu/nova-core/gsp/cmdq/continuation.rs    |   1 +
 drivers/gpu/nova-core/gsp/commands.rs         |   2 +
 drivers/gpu/nova-core/gsp/fw.rs               |  19 +++
 4 files changed, 107 insertions(+), 26 deletions(-)

diff --git a/drivers/gpu/nova-core/gsp/cmdq.rs b/drivers/gpu/nova-core/gsp/cmdq.rs
index ac3e6642031a..1eeef2120b6e 100644
--- a/drivers/gpu/nova-core/gsp/cmdq.rs
+++ b/drivers/gpu/nova-core/gsp/cmdq.rs
@@ -87,6 +87,12 @@ pub(crate) trait CommandToGsp {
     /// Function identifying this command to the GSP.
     const FUNCTION: MsgFunction;
 
+    /// Classifies the send-side debug log as an async send.
+    ///
+    /// Default is `false`. Set this only on commands that are sent without waiting for a reply. A
+    /// [`NoReply`] continuation of a waited-for command stays `false`.
+    const IS_ASYNC: bool = false;
+
     /// Type generated by [`CommandToGsp::init`], to be written into the command queue buffer.
     type Command: FromBytes + AsBytes;
 
@@ -528,6 +534,8 @@ pub(crate) fn new(dev: &device::Device<device::Bound>) -> impl PinInit<Self, Err
                     gsp_mem,
                     elem_seq: 0,
                     rpc_seq: 0,
+                    tx_async_seq: 0,
+                    rx_event_seq: 0,
                     poisoned: Cell::new(false),
                 }),
             }))
@@ -672,6 +680,12 @@ struct CmdqInner {
     /// [`CmdqInner::receive_msg`] match that reply to the awaiting command. Advances once per
     /// logical command.
     rpc_seq: u32,
+    /// Debug-log sequence for async sends. Those commands do not wait for a reply, so this
+    /// counter is the number printed in the send log.
+    tx_async_seq: u32,
+    /// Debug-log sequence for GSP-initiated events. The GSP leaves the RPC sequence unset on
+    /// those messages, so the driver numbers them itself.
+    rx_event_seq: u32,
     /// Set once a message with corrupt framing or a bad checksum is seen. Such a message has an
     /// untrusted length, so the queue cannot be advanced past it, and every later receive fails
     /// until the queue is torn down and reset.
@@ -738,13 +752,24 @@ fn send_single_command<M>(&mut self, bar: Bar0<'_>, command: M, rpc_seq: u32) ->
                 dst.contents.1,
             ])));
 
-        dev_dbg!(
-            &self.dev,
-            "GSP RPC: send: seq# {}, function={:?}, length=0x{:x}\n",
-            rpc_seq,
-            M::FUNCTION,
-            dst.header.length(),
-        );
+        if M::IS_ASYNC {
+            dev_dbg!(
+                &self.dev,
+                "GSP RPC: async send: seq# {}, function={:?}, length=0x{:x}\n",
+                self.tx_async_seq,
+                M::FUNCTION,
+                dst.header.length(),
+            );
+            self.tx_async_seq = self.tx_async_seq.wrapping_add(1);
+        } else {
+            dev_dbg!(
+                &self.dev,
+                "GSP RPC: send: seq# {}, function={:?}, length=0x{:x}\n",
+                rpc_seq,
+                M::FUNCTION,
+                dst.header.length(),
+            );
+        }
 
         // All set - update the write pointer and inform the GSP of the new command.
         let elem_count = dst.header.element_count();
@@ -826,14 +851,6 @@ fn wait_for_msg(&self, timeout: Delta) -> Result<GspMessage<'_>> {
             return Err(EIO);
         };
 
-        dev_dbg!(
-            &self.dev,
-            "GSP RPC: receive: seq# {}, function={:?}, length=0x{:x}\n",
-            header.sequence(),
-            header.function(),
-            header.length(),
-        );
-
         let payload_length = header.payload_length();
 
         // Check that the driver read area is large enough for the message.
@@ -877,6 +894,41 @@ fn wait_for_msg(&self, timeout: Delta) -> Result<GspMessage<'_>> {
         })
     }
 
+    /// Writes the classified receive debug line for a decoded GSP message.
+    ///
+    /// Events print [`Self::rx_event_seq`]. Command replies print `seq`. An unrecognized function
+    /// code prints nothing here.
+    fn log_received(&self, function: Result<MsgFunction, u32>, seq: u32, length: usize) {
+        match function {
+            Ok(f) if f.is_event() => {
+                dev_dbg!(
+                    &self.dev,
+                    "GSP RPC: async received: seq# {}, function={:?}, length=0x{:x}\n",
+                    self.rx_event_seq,
+                    f,
+                    length,
+                );
+            }
+            Ok(f) => {
+                dev_dbg!(
+                    &self.dev,
+                    "GSP RPC: response received: seq# {}, function={:?}, length=0x{:x}\n",
+                    seq,
+                    f,
+                    length,
+                );
+            }
+            Err(_) => {}
+        }
+    }
+
+    /// Advances [`Self::rx_event_seq`] after a GSP-initiated event has been consumed.
+    fn advance_rx_event_seq(&mut self, function: Result<MsgFunction, u32>) {
+        if matches!(function, Ok(f) if f.is_event()) {
+            self.rx_event_seq = self.rx_event_seq.wrapping_add(1);
+        }
+    }
+
     /// Receive a message from the GSP.
     ///
     /// The expected message type is given by the `M` generic parameter. With `expected_seq` set,
@@ -910,9 +962,12 @@ fn receive_msg<M: MessageFromGsp>(
         let message = self.wait_for_msg(timeout)?;
         let function = message.header.function();
         let seq = message.header.sequence();
+        let length = message.header.length();
         let func_matches = matches!(function, Ok(f) if f == M::FUNCTION);
         let matched = func_matches && expected_seq.is_none_or(|expected| seq == expected);
 
+        self.log_received(function, seq, length);
+
         // Every path must advance the read pointer past this message, including a failed decode.
         let result = if matched {
             match M::Message::from_bytes_prefix(message.contents.0) {
@@ -938,9 +993,10 @@ fn receive_msg<M: MessageFromGsp>(
         };
 
         // Advance the read pointer past this message.
-        self.gsp_mem.advance_cpu_read_ptr(u32::try_from(
-            message.header.length().div_ceil(GSP_PAGE_SIZE),
-        )?);
+        self.gsp_mem
+            .advance_cpu_read_ptr(u32::try_from(length.div_ceil(GSP_PAGE_SIZE))?);
+
+        self.advance_rx_event_seq(function);
 
         if !matched {
             if func_matches {
@@ -962,8 +1018,8 @@ fn receive_msg<M: MessageFromGsp>(
     /// Routes a GSP message that is not the reply a caller is waiting for.
     ///
     /// GSP-reported errors are logged at error level and unrecognized function codes at warning
-    /// level. Every other known function code is consumed without a log line, because the RPC
-    /// receive trace in [`Self::wait_for_msg`] already records its arrival.
+    /// level. Every other known function code is consumed without a log line, because
+    /// [`Self::log_received`] already records its arrival.
     fn dispatch_event(&self, function: Result<MsgFunction, u32>, seq: u32) {
         match function {
             Ok(MsgFunction::OsErrorLog) => {
@@ -1004,16 +1060,19 @@ fn drain(&mut self) -> Result {
         while !self.gsp_mem.driver_read_area().0.is_empty() {
             // A message is available, so this returns without waiting.
             let msg = self.wait_for_msg(Delta::ZERO)?;
-
-            let pages =
-                u32::try_from(msg.header.length().div_ceil(GSP_PAGE_SIZE)).map_err(|_| {
-                    dev_err!(&self.dev, "GSP drain: message length overflow\n");
-                    EIO
-                })?;
             let function = msg.header.function();
             let seq = msg.header.sequence();
+            let length = msg.header.length();
+
+            self.log_received(function, seq, length);
+
+            let pages = u32::try_from(length.div_ceil(GSP_PAGE_SIZE)).map_err(|_| {
+                dev_err!(&self.dev, "GSP drain: message length overflow\n");
+                EIO
+            })?;
 
             self.gsp_mem.advance_cpu_read_ptr(pages);
+            self.advance_rx_event_seq(function);
             self.dispatch_event(function, seq);
         }
 
diff --git a/drivers/gpu/nova-core/gsp/cmdq/continuation.rs b/drivers/gpu/nova-core/gsp/cmdq/continuation.rs
index 05e904f18097..a606c7be52a7 100644
--- a/drivers/gpu/nova-core/gsp/cmdq/continuation.rs
+++ b/drivers/gpu/nova-core/gsp/cmdq/continuation.rs
@@ -147,6 +147,7 @@ fn new(command: C, payload: KVVec<u8>) -> Self {
 
 impl<C: CommandToGsp> CommandToGsp for SplitCommand<C> {
     const FUNCTION: MsgFunction = C::FUNCTION;
+    const IS_ASYNC: bool = C::IS_ASYNC;
     type Command = C::Command;
     type Reply = C::Reply;
     type InitError = C::InitError;
diff --git a/drivers/gpu/nova-core/gsp/commands.rs b/drivers/gpu/nova-core/gsp/commands.rs
index 61fe93db9e7e..d5575c036eb9 100644
--- a/drivers/gpu/nova-core/gsp/commands.rs
+++ b/drivers/gpu/nova-core/gsp/commands.rs
@@ -52,6 +52,7 @@ pub(crate) fn new(pdev: &'a pci::Device<device::Bound>, chipset: Chipset) -> Sel
 
 impl<'a> CommandToGsp for SetSystemInfo<'a> {
     const FUNCTION: MsgFunction = MsgFunction::GspSetSystemInfo;
+    const IS_ASYNC: bool = true;
     type Command = fw::commands::GspSetSystemInfo;
     type Reply = NoReply;
     type InitError = Error;
@@ -122,6 +123,7 @@ pub(crate) fn new(vgpu_state: VgpuState) -> Result<Self> {
 
 impl CommandToGsp for SetRegistry {
     const FUNCTION: MsgFunction = MsgFunction::SetRegistry;
+    const IS_ASYNC: bool = true;
     type Command = fw::commands::PackedRegistryTable;
     type Reply = NoReply;
     type InitError = Infallible;
diff --git a/drivers/gpu/nova-core/gsp/fw.rs b/drivers/gpu/nova-core/gsp/fw.rs
index d3678f16750a..857d53c77297 100644
--- a/drivers/gpu/nova-core/gsp/fw.rs
+++ b/drivers/gpu/nova-core/gsp/fw.rs
@@ -359,6 +359,25 @@ fn try_from(value: u32) -> Result<MsgFunction> {
     }
 }
 
+impl MsgFunction {
+    /// Returns true if this is a GSP-initiated async event (`NV_VGPU_MSG_EVENT_*`), as opposed to
+    /// a command response (`NV_VGPU_MSG_FUNCTION_*`).
+    pub(crate) fn is_event(&self) -> bool {
+        matches!(
+            self,
+            Self::GspInitDone
+                | Self::GspRunCpuSequencer
+                | Self::PostEvent
+                | Self::RcTriggered
+                | Self::MmuFaultQueued
+                | Self::OsErrorLog
+                | Self::GspPostNoCat
+                | Self::GspLockdownNotice
+                | Self::UcodeLibOsPrint //
+        )
+    }
+}
+
 impl From<MsgFunction> for u32 {
     fn from(value: MsgFunction) -> Self {
         // CAST: `MsgFunction` is `repr(u32)` and can thus be cast losslessly.
-- 
2.55.0