Re: [Intel-wired-lan] [PATCH iwl-next] libie: log more info when virtchnl fails

[Li Li]

On Mon, Apr 27, 2026 at 3:40 AM Paul Menzel <pmenzel@xxxxxxxxxxxxx> wrote:
>
> Dear Li,
>
>
> Thank you for your patch.
>
> Am 24.04.26 um 05:15 schrieb Li Li via Intel-wired-lan:
> > Virtchnl failures can be hard to debug without logs. Logging the details
> > of virtchnl transactions can be useful for debugging virtchnl-related
> > issues.
>
> Why is the first added one added as error, and the second as info?

Originally I was thinking the second log doesn't warrant an err level
log, but on second thought, I think it makes more sense to use
dev_err_ratelimited() in both places. I will send out a v3 patch to
update it.

>
>
> Do you have a reproducer to get each of the new log messages?

We recently had an IOMMU subsystem bug in our internal kernel that
caused virtchnl failures, and this patch helped root cause the IOMMU
subsystem issue. However, the patch we used internally was applied to
the OOT driver, which is implemented slightly differently than the
upstream driver. Example log we saw in our OOT driver, with the patch
applied:

idpf 0000:43:00.0: Non-zero virtchnl ret val (msg: 523, ret val: 6,
data_len: 0) (xn 523, id: 254, salt: 40, iov len: 128)

The message looks slightly different from the log added in this patch
because the OOT driver uses different terminology.

>
> > Tested: Built and booted on a test machine.
>
> Please paste the new messages.

As mentioned above, I don't have a reproducer for a real virtchnl
error in the upstream kernel, but I synthetically produced an error by
changing ctlq_msg->chnl_retval, and the following message appeared:

[  309.891790] idpf 0000:01:00.0: Non-zero virtchnl ret val (msg op:
1, ret val: 6, msg_cookie: 0, data_len: 8); xn op: 1, id: 0, cookie: 0
[  309.892357] idpf 0000:01:00.0: Transaction failed (op 1, xn state:
3, id: 0, cookie: 0, size: 8)

I will mention it in the v3 patch as well.



>
> > Signed-off-by: Li Li <boolli@xxxxxxxxxx>
> > ---
> >   drivers/net/ethernet/intel/libie/controlq.c | 15 +++++++++++++++
> >   1 file changed, 15 insertions(+)
> >
> > diff --git a/drivers/net/ethernet/intel/libie/controlq.c b/drivers/net/ethernet/intel/libie/controlq.c
> > index ebc05355e39d..7eaa77413621 100644
> > --- a/drivers/net/ethernet/intel/libie/controlq.c
> > +++ b/drivers/net/ethernet/intel/libie/controlq.c
> > @@ -762,6 +762,16 @@ libie_ctlq_xn_process_recv(struct libie_ctlq_xn_recv_params *params,
> >       status = ctlq_msg->chnl_retval ? -EFAULT : 0;
> >
> >       xn = &xnm->ring[xn_index];
> > +
> > +     if (ctlq_msg->chnl_retval) {
> > +             dev_err_ratelimited(
> > +                     params->ctlq->dev,
> > +                     "Non-zero virtchnl ret val (msg op: %u, ret val: %u, msg_cookie: %u, data_len: %u); xn op: %u, id: %u, cookie: %u\n",
> > +                     ctlq_msg->chnl_opcode, ctlq_msg->chnl_retval,
> > +                     msg_cookie, ctlq_msg->data_len, xn->virtchnl_opcode,
> > +                     xn->index, xn->cookie);
> > +     }
> > +
> >       if (ctlq_msg->chnl_opcode != xn->virtchnl_opcode ||
> >           msg_cookie != xn->cookie)
> >               return false;
> > @@ -1011,6 +1021,11 @@ int libie_ctlq_xn_send(struct libie_ctlq_xn_send_params *params)
> >               params->recv_mem = xn->recv_mem;
> >               break;
> >       default:
> > +             dev_notice_ratelimited(
> > +                     params->ctlq->dev,
> > +                     "Transaction failed (op %u, xn state: %d, id: %u, cookie: %u, size: %zu)\n",
> > +                     params->chnl_opcode, xn->state, xn->index, xn->cookie,
> > +                     xn->recv_mem.iov_len);
> >               ret = -EBADMSG;
> >               break;
> >       }
>
>
> Kind regards,
>
> Paul