| Message ID | alpine.DEB.2.20.1707211817260.11359@wilk (mailing list archive) |
|---|---|
| State | RFC |
| Delegated to: | Kalle Valo |
| Headers | show |
On 7/21/2017 6:20 PM, Rafal wrote: > Again, ap6212 device on board. When the module gets unloaded and then > loaded again, sometimes the driver fails to bring up the device - it > stops with the following errors: > > [ 125.668000] brcmfmac: brcmf_sdio_txfail: sdio error, abort command > and terminate frame > [ 125.676000] brcmfmac: brcmf_sdio_txfail: sdio error, abort command > and terminate frame > [ 125.680000] brcmfmac: brcmf_sdio_txfail: sdio error, abort command > and terminate frame > [ 125.684000] brcmfmac: brcmf_sdio_dpc: failed backplane access over > SDIO, halting operation > [ 125.684000] brcmfmac: brcmf_proto_bcdc_query_dcmd: > brcmf_proto_bcdc_msg failed w/status -84 > [ 125.684000] brcmfmac: brcmf_c_preinit_dcmds: Retreiving cur_etheraddr > failed, -84 > [ 125.684000] brcmfmac: brcmf_bus_started: failed: -84 > > I have made some investigations and it looks the problem is caused by > too short time between getting CM3 core out of reset and first > communication attempt with the device. It looks the device needs about > 50ms to boot up. Usually the appropriate delay is introduced by function > sdio_enable_func which is called just after activation of the core to > enable F2 function on device. Usually the sdio function introduces the > needed 50ms delay and everything is OK. But sometimes the function > returns immediately. In this case the driver breaks down with the above > error. But if the additional delay is added in place of > sdio_enable_func, everything is okay. Hi Rafal, That is an interesting find. I took a dive into the SDIO code. After enabling F2 there are actually three signals from the device that indicate its readiness to handle communication with the host. However, none of them are waited for before activating higher layer operations in the driver. So instead of the delay it may be better to wait for the device to come up properly and indicate its readiness. If we do need this delay I would rather put it in sdio.c. Anyway, if I come up with a patch for testing would you be willing to give it a spin. Thanks for digging deeper. Regards, Arend
On Tue, 25 Jul 2017, Arend van Spriel wrote: > On 7/21/2017 6:20 PM, Rafal wrote: >> Again, ap6212 device on board. When the module gets unloaded and then >> loaded again, sometimes the driver fails to bring up the device - it >> stops with the following errors: >> >> [ 125.668000] brcmfmac: brcmf_sdio_txfail: sdio error, abort command >> and terminate frame >> [ 125.676000] brcmfmac: brcmf_sdio_txfail: sdio error, abort command >> and terminate frame >> [ 125.680000] brcmfmac: brcmf_sdio_txfail: sdio error, abort command >> and terminate frame >> [ 125.684000] brcmfmac: brcmf_sdio_dpc: failed backplane access over >> SDIO, halting operation >> [ 125.684000] brcmfmac: brcmf_proto_bcdc_query_dcmd: >> brcmf_proto_bcdc_msg failed w/status -84 >> [ 125.684000] brcmfmac: brcmf_c_preinit_dcmds: Retreiving cur_etheraddr >> failed, -84 >> [ 125.684000] brcmfmac: brcmf_bus_started: failed: -84 >> >> I have made some investigations and it looks the problem is caused by >> too short time between getting CM3 core out of reset and first >> communication attempt with the device. It looks the device needs about >> 50ms to boot up. Usually the appropriate delay is introduced by function >> sdio_enable_func which is called just after activation of the core to >> enable F2 function on device. Usually the sdio function introduces the >> needed 50ms delay and everything is OK. But sometimes the function >> returns immediately. In this case the driver breaks down with the above >> error. But if the additional delay is added in place of >> sdio_enable_func, everything is okay. > > Hi Rafal, > > That is an interesting find. I took a dive into the SDIO code. After enabling > F2 there are actually three signals from the device that indicate its > readiness to handle communication with the host. However, none of them are > waited for before activating higher layer operations in the driver. So > instead of the delay it may be better to wait for the device to come up > properly and indicate its readiness. If we do need this delay I would rather > put it in sdio.c. Anyway, if I come up with a patch for testing would you be > willing to give it a spin. Thanks for digging deeper. > > Regards, > Arend I don't insist to add the fix. After sending this email I have started to think about many things. But, at first, the facts. Below is the output from two runs of the driver without the additional delay. I have added some traces in the driver, namely, four pr_info calls: one call in brcmf_chip_cm3_set_active, just before brcmf_chip_resetcore. Two calls surrounding sdio_enable_func call to turn on the F2 and one call at brcmf_c_preinit_dcmds begin, just before attempt to obtain cur_etheraddr. Below are two outputs: one successful, one with failure: [13065.924000] brcmfmac: >> brcmf_chip_cm3_set_active: before brcmf_chip_resetcore [13065.928000] brcmfmac: >> brcmf_sdio_firmware_callback: before sdio_enable_func [13065.928000] brcmfmac: >> brcmf_sdio_firmware_callback: after sdio_enable_func [13065.928000] brcmfmac: >> brcmf_c_preinit_dcmds: begin [13065.928000] brcmfmac: brcmf_sdio_txfail: sdio error, abort command and terminate frame [13211.944000] brcmfmac: >> brcmf_chip_cm3_set_active: before brcmf_chip_resetcore [13211.948000] brcmfmac: >> brcmf_sdio_firmware_callback: before sdio_enable_func [13211.984000] brcmfmac: >> brcmf_sdio_firmware_callback: after sdio_enable_func [13211.984000] brcmfmac: >> brcmf_c_preinit_dcmds: begin [13211.984000] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: Jun 6 2014 14:50:39 version 7.10.226.49 (r) FWID 01-8962686a As you can see in the first output, it was only one tick between core reset and getting cur_etheraddr iovar (device has 250Hz timer). In second output it was some delay in sdio_enable_func, about 40ms. It is not an accident - always when sdio_enable_func returns immediately, gettting iovar fails and always when sdio_enable_func waits, getting iovar finishes successfully. You can believe me that F2 function is disabled before the enable call in both cases, i.e. SDIO_CCCR_IOEx register is set to 2. You can believe me also that sleep added before brcmf_chip_resetcore does not help, but sleep added just after brcmf_chip_resetcore - helps. Now, what are my doubts. I'm wondering why enable_timeout for F1 is set to 0 but for F2 is set to 3000 (3 seconds)? Does it mean that SDIO_CCCR_IORx register value should be changed by device (firmware?) when it is ready to operate, but from some reason it responds sometimes when is not ready? I'm not familiar with the ideas, how it should work. Is it a bug in the ap6212 device firmware? If so, the problem occurrence may depend not only on the chip version, but also on firmware version? Rafal
diff --git a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/chip.c b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/chip.c index 05f22ff..a913285 100644 --- a/drivers/net/wireless/broadcom/brcm80211/brcmfmac/chip.c +++ b/drivers/net/wireless/broadcom/brcm80211/brcmfmac/chip.c @@ -1215,6 +1215,14 @@ static bool brcmf_chip_cm3_set_active(struct brcmf_chip_priv *chip) core = brcmf_chip_get_core(&chip->pub, BCMA_CORE_ARM_CM3); brcmf_chip_resetcore(core, 0, 0, 0); + if( chip->pub.chip == BRCM_CC_43430_CHIP_ID && chip->pub.chiprev == 0 ) { + /* ap6212: fix occasional I/O timeout occuring after this reset. + * Usually appropriate delay (~50ms) provides sdio_enable_func() + * invoked after reset to enable F2. But sometimes (after rmmod + * followed by insmod) the enable function returns immediately. + */ + usleep_range(40000, 60000); + } return true; }