DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org D379520672
MIME-Version: 1.0
References: <CAHYQr0pKurSS=nvLEaLzup1hgx4+RJ0CezA2nFeA=C4XBDQQog@mail.gmail.com>
 <20181211181944.GW39861@atomide.com> <CAHYQr0pk-WKM-aYR7ubM4GHx8PA82XP5ze9TW9WEJLzdO0f88A@mail.gmail.com>
 <20181211190128.GX39861@atomide.com> <CAHYQr0qc_Lav=1sEGcOmOykUftWRzd6+vis97eBpanEXzfUHaA@mail.gmail.com>
 <CALAqxLUVajBw_PkyhA0s=FhQQHWu1FBEMX+4oDTStRXr6L5Txw@mail.gmail.com>
 <20181211201221.GY39861@atomide.com> <CAHYQr0qffa_G2ZVnSsDfjqSgxuBBZB+8e6ZODpAWV_TMhqzFYg@mail.gmail.com>
In-Reply-To: <CAHYQr0qffa_G2ZVnSsDfjqSgxuBBZB+8e6ZODpAWV_TMhqzFYg@mail.gmail.com>
From:   Ricardo Salveti <rsalveti@rsalveti.net>
Date:   Tue, 11 Dec 2018 19:50:26 -0200
Message-ID: <CAHYQr0onAAMZ21YU59XOgNsVrZ-+33tUHfOa9aPr+hG2M0zb3g@mail.gmail.com>
Subject: Re: wlcore getting stuck on hikey after the runtime PM autosuspend
 support change
To:     Tony Lindgren <tony@atomide.com>
Cc:     John Stultz <john.stultz@linaro.org>,
        linux-wireless@vger.kernel.org, anders.roxell@linaro.org
Content-Type: text/plain; charset="UTF-8"
Sender: linux-wireless-owner@vger.kernel.org
Precedence: bulk

On Tue, Dec 11, 2018 at 6:23 PM Ricardo Salveti <rsalveti@rsalveti.net> wrote:
> And now with while true:
> Dec 11 20:18:13 hikey kernel: wlcore: mac80211 configure filter
> changed 0 total 80000000
> Dec 11 20:18:13 hikey kernel: wlcore: waking up chip from elp
> Dec 11 20:18:13 hikey kernel: wlcore: wakeup time: 8 ms
> Dec 11 20:18:13 hikey kernel: wlcore: acx group address tbl
> Dec 11 20:18:13 hikey kernel: wlcore: cmd configure (63)
> Dec 11 20:18:13 hikey kernel: wlcore: mac80211 remove interface
> Dec 11 20:18:13 hikey kernel: wlcore: down
> Dec 11 20:18:13 hikey kernel: wlcore: cmd role disable
> Dec 11 20:18:13 hikey kernel: wlcore: IRQ work
> Dec 11 20:18:13 hikey kernel: wlcore: mac80211 stop
> Dec 11 20:18:13 hikey kernel: wlcore: intr: 0x20 (fw_rx_counter = 0,
> drv_rx_counter = 0, tx_results_counter = 0)
> Dec 11 20:18:13 hikey kernel: wlcore: WL1271_ACX_INTR_HW_AVAILABLE
>
> Dec 11 20:18:13 hikey kernel: wlcore: mac80211 start
> Dec 11 20:18:13 hikey kernel: wlcore: mac80211 add interface type 2
> mac 84:dd:20:92:54:5b
> Dec 11 20:18:13 hikey kernel: wlcore: allocating hw queue base: 0
> Dec 11 20:18:13 hikey kernel: wlcore: clock freq 5 (13, 120, 0, 0, spit)
> Dec 11 20:18:13 hikey kernel: wlcore: chip id 0x6030111
> Dec 11 20:18:13 hikey kernel: wlcore: firmware chunks to be uploaded: 15
> Dec 11 20:18:13 hikey kernel: wlcore: chunk 14 addr 0x0 len 120432
> Dec 11 20:18:13 hikey kernel: wlcore: starting firmware upload
> Dec 11 20:18:13 hikey kernel: wlcore: fw_data_len 120432 chunk_size 16384
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x000000002d8a6a40 to 0x0
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x0000000048dff62f to 0x4000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x00000000f9372750 to 0x8000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x00000000f2685ee4 to 0xc000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x00000000c4fc484d to 0x10000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x00000000a6d3c9bf to 0x14000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x000000007404dc0f to 0x18000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw last chunk (5744 B)
> 0x00000000d7beb1f6 to 0x1c000
> Dec 11 20:18:13 hikey kernel: wlcore: chunk 13 addr 0x100000 len 131072
> Dec 11 20:18:13 hikey kernel: wlcore: starting firmware upload
> Dec 11 20:18:13 hikey kernel: wlcore: fw_data_len 131072 chunk_size 16384
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x00000000c3cad69f to 0x100000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x00000000a9e4f338 to 0x104000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x000000003169e0a1 to 0x108000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x00000000cc5b7549 to 0x10c000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x000000009c0bb98a to 0x110000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x00000000f4d0b2c2 to 0x114000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x0000000026e1d203 to 0x118000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x00000000a3905e9c to 0x11c000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw last chunk (0 B)
> 0x00000000f0c022b6 to 0x120000
> Dec 11 20:18:13 hikey kernel: wlcore: chunk 12 addr 0x20400000 len 52600
> Dec 11 20:18:13 hikey kernel: wlcore: starting firmware upload
> Dec 11 20:18:13 hikey kernel: wlcore: fw_data_len 52600 chunk_size 16384
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x000000004f52801e to 0x20400000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x0000000066503358 to 0x20404000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x00000000433fff1b to 0x20408000
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw last chunk (3448 B)
> 0x00000000a38c9bd9 to 0x2040c000
> Dec 11 20:18:13 hikey kernel: wlcore: chunk 11 addr 0xb00000 len 536
> Dec 11 20:18:13 hikey kernel: wlcore: starting firmware upload
> Dec 11 20:18:13 hikey kernel: wlcore: fw_data_len 536 chunk_size 16384
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw last chunk (536 B)
> 0x00000000ced82f93 to 0xb00000
> Dec 11 20:18:13 hikey kernel: wlcore: chunk 10 addr 0xb0ae40 len 28120
> Dec 11 20:18:13 hikey kernel: wlcore: starting firmware upload
> Dec 11 20:18:13 hikey kernel: wlcore: fw_data_len 28120 chunk_size 16384
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x00000000d6832925 to 0xb0ae40
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw last chunk (11736
> B) 0x0000000037ae96d5 to 0xb0ee40
> Dec 11 20:18:13 hikey kernel: wlcore: chunk 9 addr 0x80900000 len 61140
> Dec 11 20:18:13 hikey kernel: wlcore: starting firmware upload
> Dec 11 20:18:13 hikey kernel: wlcore: fw_data_len 61140 chunk_size 16384
> Dec 11 20:18:13 hikey kernel: wlcore: uploading fw chunk
> 0x0000000096b9ba67 to 0x80900000 -------> hangs
>
> See the missing 'mmc_host mmc2' messages, which probably indicates
> that mmc_host wasn't properly set after the down/up sequence, causing
> the hang when uploading the firmware.

Tried to change back wl12xx_sdio_power_off to use pm_runtime_put_sync
as a test, and noticed I always get -EBUSY when reproducing the hang,
so it looks like this could be a race between pm_runtime_put/get when
doing if down/up (and the side effect on the mmc controller).

Cheers,
-- 
Ricardo Salveti de Araujo