Subject: RE: [PATCH v2 net-next 07/11] net: ena: Add more information on TX timeouts

From: "Arinzon, David" <[email-masked]>
Date: Thu, 1 Feb 2024 15:43:23 +0000

> On Thu, 2024-02-01 at 13:21 +0000, Arinzon, David wrote:
> > > On Tue, 2024-01-30 at 09:53 +0000, [email-masked] wrote:
> > > > @@ -3408,25 +3437,45 @@ static int
> > > check_missing_comp_in_tx_queue(struct ena_adapter *adapter,
> > > >                       adapter->missing_tx_completion_to);
> > > >
> > > >               if (unlikely(is_tx_comp_time_expired)) {
> > > > -                     if (!tx_buf->print_once) {
> > > > -                             time_since_last_napi = jiffies_to_usecs(jiffies - tx_ring-
> > > > tx_stats.last_napi_jiffies);
> > > > -                             missing_tx_comp_to = jiffies_to_msecs(adapter-
> > > > missing_tx_completion_to);
> > > > -                             netif_notice(adapter, tx_err, adapter->netdev,
> > > > -                                          "Found a Tx that wasn't completed on time, qid
> %d,
> > > index %d. %u usecs have passed since last napi execution. Missing Tx
> > > timeout value %u msecs\n",
> > > > -                                          tx_ring->qid, i, time_since_last_napi,
> > > missing_tx_comp_to);
> > > > +                     time_since_last_napi =
> > > > +                             jiffies_to_usecs(jiffies - tx_ring-
> >tx_stats.last_napi_jiffies);
> > > > +                     napi_scheduled = !!(ena_napi->napi.state &
> > > > + NAPIF_STATE_SCHED);
> > > > +
> > > > +                     if (missing_tx_comp_to <
> > > > + time_since_last_napi &&
> > > napi_scheduled) {
> > > > +                             /* We suspect napi isn't called because the
> > > > +                              * bottom half is not run. Require a bigger
> > > > +                              * timeout for these cases
> > > > +                              */
> > >
> > > Not blocking this series, but I guess the above "the bottom half is
> > > not run", after commit d15121be7485655129101f3960ae6add40204463,
> > > happens only when running in napi threaded mode, right?
> > >
> > > cheers,
> > >
> > > Paolo
> >
> > Hi Paolo,
> >
> > The ENA driver napi routine doesn't run in threaded mode.
> 
> ... unless you do:
> 
> echo 1 > /sys/class/net/<nic name>/threaded
> 
> :)
> 

Thanks for pointing this out. We will look into this further.

> > We've seen cases where napi is indeed scheduled, but didn't get a
> > chance to run for a noticeable amount of time and process TX
> > completions, and based on that we conclude that there's a high CPU
> > load that doesn't allow the routine to run in a timely manner.
> > Based on the information in
> d15121be7485655129101f3960ae6add40204463,
> > the observed stalls are in the magnitude of milliseconds, the above
> > code is actually an additional grace time, and the timeouts here are in
> seconds.
> 
> Do I read correctly that in your scenario the napi instance is not scheduled for
> _seconds_?  That smells like a serious bug somewhere else really worthy of
> more investigation.
> 
> Cheers,
> 
> Paolo
> 

Thanks for noting this. It is something that we're actively monitoring and looking to improve.

Thanks,
David