Re: wlcore getting stuck on hikey after the runtime PM autosuspend support change

From: John Stultz <john.stultz@linaro.org>
To: rsalveti@rsalveti.net
Cc: Tony Lindgren <tony@atomide.com>,
	linux-wireless@vger.kernel.org,
	Anders Roxell <anders.roxell@linaro.org>
Subject: Re: wlcore getting stuck on hikey after the runtime PM autosuspend support change
Date: Tue, 11 Dec 2018 11:50:56 -0800	[thread overview]
Message-ID: <CALAqxLUVajBw_PkyhA0s=FhQQHWu1FBEMX+4oDTStRXr6L5Txw@mail.gmail.com> (raw)
In-Reply-To: <CAHYQr0qc_Lav=1sEGcOmOykUftWRzd6+vis97eBpanEXzfUHaA@mail.gmail.com>

On Tue, Dec 11, 2018 at 11:25 AM Ricardo Salveti <rsalveti@rsalveti.net> wrote:
>
> On Tue, Dec 11, 2018 at 5:01 PM Tony Lindgren <tony@atomide.com> wrote:
> >
> > * Ricardo Salveti <rsalveti@rsalveti.net> [181211 18:53]:
> > > Hi,
> > >
> > > On Tue, Dec 11, 2018 at 4:19 PM Tony Lindgren <tony@atomide.com> wrote:
> > > >
> > > > Hi,
> > > >
> > > > * Ricardo Salveti <rsalveti@rsalveti.net> [181211 18:06]:
> > > > > John, did you have any similar issue on your test environment with
> > > > > kernel >= 4.19?
> > > >
> > > > This sounds like the same issue that got fixed in the dts
> > > > earlier?
> > > >
> > > > f904390ac8b2 ("arm64: dts: hikey: Define wl1835 power capabilities")
> > >
> > > keep-power-in-suspend was removed in 8883ac1db3e2 ("arm64: dts: hikey:
> > > Remove keep-power-in-suspend property"), but I just tested after
> > > adding that property back in and made no difference.
> >
> > OK
> >
> > > The funny thing is that it works fine if I disable NetworkManager MAC
> > > address randomization.
> >
> > Hmm. I wonder if there's pm_runtime_get() and put missing
> > around some calls. Do you know the related iw commands
> > that happen there to try to reproduce this manually?
>
> Checking why this only happens with NetworkManager when MAC address
> randomization is enabled, I noticed that NM performs the following
> when starting:
>
> Dec 11 18:59:04 hikey NetworkManager[1506]: <debug> [1544554744.3914]
> device[0x5575703fe0] (wlan0): bringing up device 3
> Dec 11 18:59:04 hikey NetworkManager[1506]: <debug> [1544554744.3915]
> platform: link: setting up "wlan0" (3)
> Dec 11 18:59:04 hikey NetworkManager[1506]: <debug> [1544554744.3939]
> device[0x5575703fe0] (wlan0): taking down device 3
> Dec 11 18:59:04 hikey NetworkManager[1506]: <debug> [1544554744.3940]
> platform: link: setting down "wlan0" (3)
> Dec 11 18:59:04 hikey NetworkManager[1506]: <info>  [1544554744.4072]
> device (wlan0): set-hw-addr: set MAC address to 22:D4:B1:49:B5:DB
> (scanning)
> Dec 11 18:59:04 hikey NetworkManager[1506]: <debug> [1544554744.4072]
> device[0x5575703fe0] (wlan0): bringing up device 3
> Dec 11 18:59:04 hikey NetworkManager[1506]: <debug> [1544554744.4073]
> platform: link: setting up "wlan0" (3)
>
> Then tried to reproduce with a simple 'while true; do ip link set dev
> wlan0 down; ip link set dev wlan0 up; done;' and it was already enough
> to cause the same hang. Adding a simple sleep 1 after down/up is
> already enough to make it work, so something might be missing during
> the down/up process that only happens when they get called right after
> the other.
>
> And it works fine with NetworkManager when I disable MAC address
> randomization simply because it only brings the interface up once,
> avoiding the hang.
>
> Will enable debug and try to get a better trace.

I'm not totally sure you're both seeing the same issue, but if its
helpful, here's the bug that Anders was working:
https://bugs.linaro.org/show_bug.cgi?id=3960

There's some mixing of a separate USB issue that has since been
resolved. But from the notes in that bug, Anders had possibly isolated
the wlcore issue down to the following commit:
https://git.linaro.org/people/anders.roxell/linux.git/commit/?h=tests-lwcore&id=598bfffb593d3fd0e31e790d604b44c9c5df368e

I wonder if something in that pm_runtime change effects this?

thanks
-john