Re: [PATCH 06/27] gpu: nova-core: distinguish async GSP RPC traffic in debug logs

On Tue, 18 Aug 2026 20:51:59 -0700
John Hubbard <[email protected]> wrote:

Looks good to me with one nit: should we use wrapping_add(1) for
tx_async_seq/rx_event_seq?

Reviewed-by: Zhi Wang <[email protected]>

Z.

> 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.
> 
> 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
> 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..d3afe3f9bb37
> 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 += 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 += 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.