Re: brcm 4329 problems

[Arend van Spriel <arend@broadcom.com>]

On 02/10/2014 12:27 AM, Russell King - ARM Linux wrote:
> On Sun, Feb 09, 2014 at 08:59:17PM +0000, Russell King - ARM Linux wrote:
>> On Sun, Feb 09, 2014 at 10:05:13AM +0100, Arend van Spriel wrote:
>>> Yeah. I did not mention this, but indeed the first log you provided
>>> already made that clear (to me). In your last log the driver sends an UP
>>> command to the firmware on which no response is given. So I was hoping
>>> the forensics file (which is firmware console buffer) would show an
>>> error message of some kind. Also that is not the case. Have to come up
>>> with new ideas about what is going wrong here.
>>
>> I'm chasing a theory at the moment, but it's being complicated by the
>> driver oopsing on unload...
> 
> Theory proven.
> 
> May I first take the time to apologise to Arend for wasting his time with
> this issue; the issue is not the Broadcom driver, but the SDHCI driver.

'Nice' find. There were too many communications going fine to blame it
on generic interrupt issue. I was not aware runtime PM was enabled for
the device by default.

> My theory was that it's the sdhci driver causing the problems...  My
> suspicions were first raised when I read through various SDHCI driver
> functions such as the set_ios methods when chasing down a problem with
> UHS-1 SD cards, and later when I was reading it's interrupt handling
> code.
> 
> The driver looks very much like a patchwork quilt of different hacks,
> all trying to co-operate with each other in the semblence of something
> working - the result is something which does stuff in ways that the SD
> card spec doesn't allow, but also does some pretty stupid things when
> you have a SDIO device attached.

Yeah. It seems development has been driven mostly by SD memory cards as
by SDIO devices.

> The SDIO problems become pretty obvious when you see this log:
> 
> [   51.112923] brcmfmac: brcmf_fil_cmd_int_set cmd=2, value=0
> [   51.112937] brcmfmac: brcmf_proto_bcdc_set_dcmd Enter, cmd 2 len 4
> [   51.112946] brcmfmac: brcmf_proto_bcdc_msg Enter
> [   51.112981] brcmfmac: brcmf_sdio_bus_sleep request WAKE currently WAKE
> [   51.112989] brcmfmac: brcmf_sdio_clkctl Enter
> [   51.113498] brcmfmac: brcmf_proto_bcdc_cmplt Enter
> [   51.128501] brcmfmac: brcmf_sdio_bus_watchdog idle
> [   51.128522] brcmfmac: brcmf_sdio_bus_sleep request SLEEP currently WAKE
> [   51.128532] brcmfmac: brcmf_sdio_clkctl Enter
> [   51.128540] brcmfmac: brcmf_sdio_htclk Enter
> [   51.128549] brcmfmac: brcmf_sdiod_regwb addr:0x0001000e, data:0x00
> [   51.128560] brcmfmac: brcmf_sdiod_request_data rw=1, func=1, addr=0x1000e, nbytes=1
> [   51.128645] brcmfmac: brcmf_sdio_htclk CLKCTL: turned OFF
> [   51.128655] brcmfmac: brcmf_sdio_sdclk Enter
> [   51.128667] brcmfmac: brcmf_sdio_clkctl 3 -> 0
> [   51.180385] mmc0: runtime suspend
> [   53.112272] brcmfmac: brcmf_sdio_bus_rxctl: resumed on timeout
> [   53.118290] brcmfmac: brcmf_sdio_bus_sleep request WAKE currently WAKE
> [   53.118302] brcmfmac: brcmf_sdio_clkctl Enter
> [   53.118312] brcmfmac: brcmf_sdio_sdclk Enter
> [   53.118319] brcmfmac: brcmf_sdio_htclk Enter
> [   53.118329] brcmfmac: brcmf_sdiod_regwb addr:0x0001000e, data:0x10
> [   53.118341] brcmfmac: brcmf_sdiod_request_data rw=1, func=1, addr=0x1000e, nbytes=1
> [   53.118537] sdhci-esdhc-imx 2190000.usdhc: desired SD clock: 50000000, actual: 49500000
> [   53.118550] mmc0: esdhc_pltfm_set_clock: CLK on
> [   53.119723] sdhci-esdhc-imx 2190000.usdhc: change pinctrl state for uhs 0
> [   53.125880] mmc0: sdio irq enabled: 007f0003 007f0003
> [   53.125898] mmc0: runtime resume
> [   53.125910] mmc0: card irq raised
> [   53.125925] mmc0: sdio irq disabled: 007f0103 007f0103
> [   53.126030] brcmfmac: brcmf_sdiod_regrb addr:0x0001000e
> [   53.126055] brcmfmac: brcmf_sdiod_request_data rw=0, func=1, addr=0x1000e, nbytes=1
> 
> The values printed in "sdio irq *abled" are the INT_ENABLE and SIGNAL_ENABLE
> register values immediately before the stated action is taken bit 8 is
> the interrupt enable for card interrupts.  Earlier in the log, SDIO card
> interrupts were enabled (one was handled immediately before the above
> broadcom cmd=2 message was sent.
> 
> Yep, that's right - at 51.180385, the SDIO host has /all/ interrupts
> disabled by a runtime suspend - including any interrupt from the card.
> The brcmfmac driver times out after 2 seconds having sent the "up"
> command, and re-awakens the host, which is runtime resumed at 53.125898,
> enabling the SDIO card interrupt at that time.
> 
> And lo and behold - the card has an interrupt pending!  Too bad, we're
> too late for the driver to forward the interrupt to the SDIO interrupt
> thread and get it to the driver before the time-out is processed.
> 
> Here's the proof - the above messages came from:
> 
> int sdhci_runtime_suspend_host(struct sdhci_host *host)
> {
>         unsigned long flags;
>         int ret = 0;
>         
> printk(KERN_DEBUG "%s: runtime suspend\n",
>         mmc_hostname(host->mmc));
> ...
>         spin_lock_irqsave(&host->lock, flags);
>         sdhci_mask_irqs(host, SDHCI_INT_ALL_MASK);
>         spin_unlock_irqrestore(&host->lock, flags);
> 
> int sdhci_runtime_resume_host(struct sdhci_host *host)
> {
>         unsigned long flags;
>         int ret = 0, host_flags = host->flags;
> ...
>         /* Enable SDIO IRQ */
>         if ((host->flags & SDHCI_SDIO_IRQ_ENABLED))
>                 sdhci_enable_sdio_irq_nolock(host, true);
>         
>         /* Enable Card Detection */
>         sdhci_enable_card_detection(host);
>          
> printk(KERN_DEBUG "%s: runtime resume\n",
>         mmc_hostname(host->mmc));
>         spin_unlock_irqrestore(&host->lock, flags);
>         
>         return ret;   
> }
> EXPORT_SYMBOL_GPL(sdhci_runtime_resume_host);
> 
> To me, it looks like SDHCI needs a major rework...  And there needs to
> be some recognition that - maybe - leaving SDIO interrupts enabled even
> though we may want the host to enter a low power mode is something that's
> really very very desirable...

The brcmfmac driver does not support runtime PM at the moment.
Should/could it explicitly disable runtime PM for the host?

Regards,
Arend