Re: Write errors on Cherrytrail eMMC

[Bastien Nocera <hadess@hadess.net>]

On Sun, 2015-10-11 at 19:45 +0200, Bastien Nocera wrote:
> On Sat, 2015-10-10 at 09:05 +0800, Shawn Lin wrote:
> > 
> <snip>
> > No, sdhci finally complete the tansfer. So, you can try to augment
> > the 
> > timeout [here, mod_timer(&host->timer, timeout)] to see how the
> > things 
> > going.
> 
> I applied this patch to get some more debug, and increase the default
> timeout. I'm not certain this was actually used for all the
> codepaths,
> but I certainly saw that it was getting applied at least in some
> cases.
> 
> What would those errors be this time?

Looks like one of:
commit 66c39dfc92f9d35ed9f713833156547842086891
Author: Adrian Hunter <adrian.hunter@intel.com>
Date:   Thu May 7 13:10:21 2015 +0300

    mmc: sdhci: Change to new way of doing re-tuning
    
    Make use of mmc core support for re-tuning instead
    of doing it all in the sdhci driver.
    
    This patch also changes to flag the need for re-tuning
    always after runtime suspend when tuning has been used
    at initialization. Previously it was only done if
    the re-tuning timer was in use.
    
    Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
    Signed-off-by: Ulf Hansson <ulf.hansson@linaro.org>

commit b69587e2d5b09a192c45c604ea1f9e8d51f4c3a1
Author: Adrian Hunter <adrian.hunter@intel.com>
Date:   Fri Feb 6 14:13:01 2015 +0200

    mmc: sdhci-pci: Enable HS400 for some Intel host controllers
    
    Enable detection of HS400 support via capability bit-63
    for some Intel host controllers.
    
    Signed-off-by: Adrian Hunter <adrian.hunter@intel.com>
    Signed-off-by: Ulf Hansson <ulf.hansson@linaro.org>

is responsible for the errors seen on this device. Reverting those 2
allowed me to perform the installation without the controller timing
out.

I'll try to pinpoint which one of the two is responsible for the
timeout errors on this Surface 3.

Cheers

> Cheers
> 
> Oct 11 12:12:53 localhost kernel: mmc0: starting CMD25 arg 06ec2808 flags 000000b5
> Oct 11 12:12:53 localhost kernel: mmc0:     blksz 512 blocks 1024 flags 00000100 tsac 1200 ms nsac 8000
> Oct 11 12:12:53 localhost kernel: mmc0:     CMD12 arg 00000000 flags 0000049d
> Oct 11 12:12:53 localhost kernel: mmc0: SDHCI controller on ACPI[80860F14:00], timeout is 10000, increasing to 100000 
> Oct 11 12:12:53 localhost kernel: sdhci [sdhci_irq()]: *** mmc0 got interrupt: 0x00000001
> Oct 11 12:14:33 localhost kernel: mmc0: Timeout waiting for hardware interrupt.
> Oct 11 12:14:33 localhost kernel: sdhci: =========== REGISTER DUMP (mmc0)===========
> Oct 11 12:14:33 localhost kernel: sdhci: Sys addr: 0x00000400 | Version:  0x00001002
> Oct 11 12:14:33 localhost kernel: sdhci: Blk size: 0x00007200 | Blk cnt:  0x000003f8
> Oct 11 12:14:33 localhost kernel: sdhci: Argument: 0x06ec2808 | Trn mode: 0x0000002b
> Oct 11 12:14:33 localhost kernel: sdhci: Present:  0x1fff0106 | Host ctl: 0x00000035
> Oct 11 12:14:33 localhost kernel: sdhci: Power:    0x0000000b | Blk gap:  0x00000080
> Oct 11 12:14:33 localhost kernel: sdhci: Wake-up:  0x00000000 | Clock:    0x00000007
> Oct 11 12:14:33 localhost kernel: sdhci: Timeout:  0x00000008 | Int stat: 0x00000000
> Oct 11 12:14:33 localhost kernel: sdhci: Int enab: 0x02ff000b | Sig enab: 0x02ff000b
> Oct 11 12:14:33 localhost kernel: sdhci: AC12 err: 0x00000000 | Slot int: 0x00000000
> Oct 11 12:14:33 localhost kernel: sdhci: Caps:     0x446cc8b2 | Caps_1:   0x00000007
> Oct 11 12:14:33 localhost kernel: sdhci: Cmd:      0x0000193a | Max curr: 0x00000000
> Oct 11 12:14:33 localhost kernel: sdhci: Host ctl2: 0x0000008b
> Oct 11 12:14:33 localhost kernel: sdhci: ADMA Err: 0x00000000 | ADMA Ptr: 0x3fa28008
> Oct 11 12:14:33 localhost kernel: sdhci: ===========================================
> Oct 11 12:14:33 localhost kernel: mmc0: SDHCI controller on ACPI[80860F14:00], timeout is 10000, increasing to 100000 
> Oct 11 12:14:33 localhost kernel: sdhci [sdhci_irq()]: *** mmc0 got interrupt: 0x00000003
> Oct 11 12:14:33 localhost kernel: mmc0: req done : 0: 00000000 00000000 00000000 00000000
> Oct 11 12:14:33 localhost kernel: mmc0: req done (CMD25): 0: 00000900 00000000 00000000 00000000
> Oct 11 12:14:33 localhost kernel: mmc0:     0 bytes transferred: -110
> Oct 11 12:14:33 localhost kernel: mmc0:     (CMD12): 0: 00000d00 00000000 00000000 00000000
> Oct 11 12:14:33 localhost kernel: mmc0: starting CMD13 arg 00010000 flags 00000195
> Oct 11 12:14:33 localhost kernel: mmc0: SDHCI controller on ACPI[80860F14:00], timeout is 10000, increasing to 100000 
> Oct 11 12:14:33 localhost kernel: sdhci [sdhci_irq()]: *** mmc0 got interrupt: 0x00000001
> Oct 11 12:14:33 localhost kernel: mmc0: req done (CMD13): 0: 00000900 00000000 00000000 00000000
> Oct 11 12:14:33 localhost kernel: mmc0: starting CMD13 arg 00010000 flags 00000195
> Oct 11 12:14:33 localhost kernel: mmc0: SDHCI controller on ACPI[80860F14:00], timeout is 10000, increasing to 100000 
> Oct 11 12:14:33 localhost kernel: sdhci [sdhci_irq()]: *** mmc0 got interrupt: 0x00000001
> Oct 11 12:14:33 localhost kernel: mmc0: req done (CMD13): 0: 00000900 00000000 00000000 00000000
> Oct 11 12:14:33 localhost kernel: mmcblk0: error -110 transferring data, sector 116140040, nr 1024, cmd response 0x900, card status 0xd00
> Oct 11 12:14:33 localhost kernel: blk_update_request: I/O error, dev mmcblk0, sector 116140040
> Oct 11 12:14:33 localhost kernel: Buffer I/O error on dev mmcblk0p6, logical block 2676993, lost async page write
> Oct 11 12:14:33 localhost kernel: blk_update_request: I/O error, dev mmcblk0, sector 116140048
> Oct 11 12:14:33 localhost kernel: Buffer I/O error on dev mmcblk0p6, logical block 2676994, lost async page write
> Oct 11 12:14:33 localhost kernel: blk_update_request: I/O error, dev mmcblk0, sector 116140056