RE: Re: [PATCH] ena: Speed up initialization 90x by reducing poll delays

RE: Re: [PATCH] ena: Speed up initialization 90x by reducing poll delays

[Jubran, Samih]

Hi Josh,

Thanks for taking the time to write this patch. I have faced a bug while testing it that I haven't pinpointed yet the root cause of the issue, but it seems to me like a race in the netlink infrastructure.

Here is the bug scenario:
1. created ac  c5.24xlarge instance in AWS in v_virginia region using the default amazon Linux 2 AMI 
2. apply your patch won top of net-next v5.2 and install the kernel (currently I'm able to boot net-next v5.2 only, higher versions of net-next suffer from errors during boot time)
3. run "rmmod ena && insmod ena.ko" twice

Result:
The interface is not in up state

Expected result:
The interface should be in up state

What I know so far:
* ena_probe() seems to finish with no errors whatsoever
* adding prints / delays to ena_probe() causes the bug to vanish or less likely to occur depending on the amount of delays I add
* ena_up() is not called at all when the bug occurs, so it's something to do with netlink not invoking dev_open()

Did you face such issues? Do you have any idea what might be causing this?

> -----Original Message-----
> From: linux-kernel-owner@vger.kernel.org <linux-kernel-
> owner@vger.kernel.org> On Behalf Of Machulsky, Zorik
> <zorik@amazon.com>
> Sent: Tuesday, March 3, 2020 2:54 AM
> To: Josh Triplett <josh@joshtriplett.org>
> Cc: Belgazal, Netanel <netanel@amazon.com>; Kiyanovski, Arthur
> <akiyano@amazon.com>; Tzalik, Guy <gtzalik@amazon.com>; Bshara, Saeed
> <saeedb@amazon.com>; netdev@vger.kernel.org; linux-
> kernel@vger.kernel.org
> Subject: Re: [PATCH] ena: Speed up initialization 90x by reducing poll delays
> 
> 
> 
> On 3/2/20, 4:40 PM, "Josh Triplett" <josh@joshtriplett.org> wrote:
> 
> 
>     On Mon, Mar 02, 2020 at 11:16:32PM +0000, Machulsky, Zorik wrote:
>     >
>     > On 2/28/20, 4:29 PM, "Josh Triplett" <josh@joshtriplett.org> wrote:
>     >
>     >     Before initializing completion queue interrupts, the ena driver uses
>     >     polling to wait for responses on the admin command queue. The ena
> driver
>     >     waits 5ms between polls, but the hardware has generally finished long
>     >     before that. Reduce the poll time to 10us.
>     >
>     >     On a c5.12xlarge, this improves ena initialization time from 173.6ms to
>     >     1.920ms, an improvement of more than 90x. This improves server boot
> time
>     >     and time to network bringup.
>     >
>     > Thanks Josh,
>     > We agree that polling rate should be increased, but prefer not to do it
> aggressively and blindly.
>     > For example linear backoff approach might be a better choice. Please let
> us re-work a little this
>     > patch and bring it to review. Thanks!
> 
>     That's fine, as long as it has the same net improvement on boot time.
> 
>     I'd appreciate the opportunity to test any alternate approach you might
>     have.
> 
>     (Also, as long as you're working on this, you might wish to make a
>     similar change to the EFA driver, and to the FreeBSD drivers.)
> 
> Absolutely! Already forwarded this to the owners of these drivers.  Thanks!
> 
>     >     Before:
>     >     [    0.531722] calling  ena_init+0x0/0x63 @ 1
>     >     [    0.531722] ena: Elastic Network Adapter (ENA) v2.1.0K
>     >     [    0.531751] ena 0000:00:05.0: Elastic Network Adapter (ENA) v2.1.0K
>     >     [    0.531946] PCI Interrupt Link [LNKD] enabled at IRQ 11
>     >     [    0.547425] ena: ena device version: 0.10
>     >     [    0.547427] ena: ena controller version: 0.0.1 implementation version
> 1
>     >     [    0.709497] ena 0000:00:05.0: Elastic Network Adapter (ENA) found at
> mem febf4000, mac addr 06:c4:22:0e:dc:da, Placement policy: Low Latency
>     >     [    0.709508] initcall ena_init+0x0/0x63 returned 0 after 173616 usecs
>     >
>     >     After:
>     >     [    0.526965] calling  ena_init+0x0/0x63 @ 1
>     >     [    0.526966] ena: Elastic Network Adapter (ENA) v2.1.0K
>     >     [    0.527056] ena 0000:00:05.0: Elastic Network Adapter (ENA) v2.1.0K
>     >     [    0.527196] PCI Interrupt Link [LNKD] enabled at IRQ 11
>     >     [    0.527211] ena: ena device version: 0.10
>     >     [    0.527212] ena: ena controller version: 0.0.1 implementation version
> 1
>     >     [    0.528925] ena 0000:00:05.0: Elastic Network Adapter (ENA) found at
> mem febf4000, mac addr 06:c4:22:0e:dc:da, Placement policy: Low Latency
>     >     [    0.528934] initcall ena_init+0x0/0x63 returned 0 after 1920 usecs
> 

Re: Re: [PATCH] ena: Speed up initialization 90x by reducing poll delays

[Josh Triplett]

On Wed, Mar 11, 2020 at 01:24:17PM +0000, Jubran, Samih wrote:
> Hi Josh,
> 
> Thanks for taking the time to write this patch. I have faced a bug while testing it that I haven't pinpointed yet the root cause of the issue, but it seems to me like a race in the netlink infrastructure.
> 
> Here is the bug scenario:
> 1. created ac  c5.24xlarge instance in AWS in v_virginia region using the default amazon Linux 2 AMI 
> 2. apply your patch won top of net-next v5.2 and install the kernel (currently I'm able to boot net-next v5.2 only, higher versions of net-next suffer from errors during boot time)
> 3. run "rmmod ena && insmod ena.ko" twice
> 
> Result:
> The interface is not in up state
> 
> Expected result:
> The interface should be in up state
> 
> What I know so far:
> * ena_probe() seems to finish with no errors whatsoever
> * adding prints / delays to ena_probe() causes the bug to vanish or less likely to occur depending on the amount of delays I add
> * ena_up() is not called at all when the bug occurs, so it's something to do with netlink not invoking dev_open()
> 
> Did you face such issues? Do you have any idea what might be causing this?

I haven't observed anything like this. I didn't test with Amazon Linux
2, though.

To rule out some possibilities, could you try disabling *all* userspace
networking bits, so that userspace does nothing with a newly discovered
interface, and then testing again? (The interface wouldn't be "up" in
that case, but it should still have a link detected.)

If that works, then I wonder if the userspace used in Amazon Linux 2
might have some kind of race where it's still using the previous
incarnation of the device when you rmmod and insmod? Perhaps the
previous delays made it difficult or impossible to trigger that race?

- Josh Triplett

RE: Re: [PATCH] ena: Speed up initialization 90x by reducing poll delays

[Jubran, Samih]

Hi Josh,

I wanted to let you know that we are still looking into your patch. 
After some careful considerations we have decided to set the value of 
ENA_POLL_US to 100us. The rationale behind this choice is that the 
device might take up to 1ms to complete the reset operation and we 
don't want to bombard device. We do agree with most of your patch 
and we will be sending one based on it for review.

Thanks,
Sameeh

> -----Original Message-----
> From: Josh Triplett <josh@joshtriplett.org>
> Sent: Friday, March 13, 2020 2:28 PM
> To: Jubran, Samih <sameehj@amazon.com>
> Cc: Machulsky, Zorik <zorik@amazon.com>; Belgazal, Netanel
> <netanel@amazon.com>; Kiyanovski, Arthur <akiyano@amazon.com>;
> Tzalik, Guy <gtzalik@amazon.com>; Bshara, Saeed <saeedb@amazon.com>;
> netdev@vger.kernel.org; linux-kernel@vger.kernel.org
> Subject: RE: [EXTERNAL]Re: [PATCH] ena: Speed up initialization 90x by
> reducing poll delays
> 
> CAUTION: This email originated from outside of the organization. Do not click
> links or open attachments unless you can confirm the sender and know the
> content is safe.
> 
> 
> 
> On Wed, Mar 11, 2020 at 01:24:17PM +0000, Jubran, Samih wrote:
> > Hi Josh,
> >
> > Thanks for taking the time to write this patch. I have faced a bug while
> testing it that I haven't pinpointed yet the root cause of the issue, but it
> seems to me like a race in the netlink infrastructure.
> >
> > Here is the bug scenario:
> > 1. created ac  c5.24xlarge instance in AWS in v_virginia region using
> > the default amazon Linux 2 AMI 2. apply your patch won top of net-next
> > v5.2 and install the kernel (currently I'm able to boot net-next v5.2
> > only, higher versions of net-next suffer from errors during boot time)
> > 3. run "rmmod ena && insmod ena.ko" twice
> >
> > Result:
> > The interface is not in up state
> >
> > Expected result:
> > The interface should be in up state
> >
> > What I know so far:
> > * ena_probe() seems to finish with no errors whatsoever
> > * adding prints / delays to ena_probe() causes the bug to vanish or
> > less likely to occur depending on the amount of delays I add
> > * ena_up() is not called at all when the bug occurs, so it's something
> > to do with netlink not invoking dev_open()
> >
> > Did you face such issues? Do you have any idea what might be causing this?
> 
> I haven't observed anything like this. I didn't test with Amazon Linux 2,
> though.
> 
> To rule out some possibilities, could you try disabling *all* userspace
> networking bits, so that userspace does nothing with a newly discovered
> interface, and then testing again? (The interface wouldn't be "up" in that
> case, but it should still have a link detected.)
> 
> If that works, then I wonder if the userspace used in Amazon Linux 2 might
> have some kind of race where it's still using the previous incarnation of the
> device when you rmmod and insmod? Perhaps the previous delays made it
> difficult or impossible to trigger that race?
> 
> - Josh Triplett

Re: Re: [PATCH] ena: Speed up initialization 90x by reducing poll delays

[Josh Triplett]

On Sun, Apr 12, 2020 at 09:37:22AM +0000, Jubran, Samih wrote:
> I wanted to let you know that we are still looking into your patch. 
> After some careful considerations we have decided to set the value of 
> ENA_POLL_US to 100us. The rationale behind this choice is that the 
> device might take up to 1ms to complete the reset operation and we 
> don't want to bombard device. We do agree with most of your patch 
> and we will be sending one based on it for review.

Thank you, that sounds entirely reasonable.

Please also consider making the probing asynchronous (via linux/async.h)
to allow other initialization to happen in parallel.