Hi Ulf,
thank you very much for taking the time to look into this!
On Wed, Apr 15, 2020 at 2:57 PM Ulf Hansson <ulf.hansson@xxxxxxxxxx> wrote:
[...]
> Thanks for sending this! I assume it's a regression and caused by one
> of my patches that went in for 5.7. Probably this one:
> 0d84c3e6a5b2 mmc: core: Convert to mmc_poll_for_busy() for erase/trim/discard
indeed, I only observed this with 5.7-rc1-ish, before everything was
working fine
> Now, even if enabling MMC_CAP_WAIT_WHILE_BUSY seems like the correct
> thing to do, I suggest we really try understand why it works, so we
> don't overlook some other issue that needs to be fixed.
great, that's why I'm seeking for help!
> Would you be willing to try a few debug patches, according to the below?
sure
while reading your suggestions I went back to the vendor driver and
observed that they don't implement card_busy for this controller
Thus I added the following line to meson_mx_mmc_card_busy for all of
your tests to see what the controller sees in terms of our card busy
implementation:
dev_info(mmc_dev(host->mmc), "%s read IRQC = 0x%08x\n",
__func__, irqc);
> First, can you double check so the original polling with CMD13 is
> still okay, by trying the below minor change. The intent is to force
> polling with CMD13 for the erase/discard operation.
I have tried this one and it seems to work around the problem (before
I reverted my change and dropped MMC_CAP_WAIT_WHILE_BUSY from
mmc->caps)
also I did not see meson_mx_mmc_card_busy being invoked (not even
once, but I don't know if that's expected)
[...]
> Second, if the above works, it looks like the polling with
> ->card_busy() isn't really working for meson-mx-sdio.c, together with
> erase/discard. To narrow down that problem, I suggest to try with a
> longer erase/discard timeout in a retry fashion, while using
> ->card_busy(). Along the lines of the below:
I have tried this one as well (before I reverted the earlier CMD13
patch) and with MMC_CAP_WAIT_WHILE_BUSY unset in mmc->caps
This doesn't seem to work around the issue - kernel log extract attached.
Also I'm seeing that the the current meson_mx_mmc_card_busy
implementation returns that the card is busy.
example: 0x1f001f10 & 0x3c00 = 0x1c00. the busy logic in the driver
is: !!0x1c00 = 1
My conclusion is:
- meson_mx_mmc_card_busy is not working and should be removed (because
I don't know how to make it work). it probably never worked but we
didn't notice until a recent change
- set MMC_CAP_WAIT_WHILE_BUSY as per my initial patch
- use Fixes: ed80a13bb4c4c9 ("mmc: meson-mx-sdio: Add a driver for the
Amlogic Meson8 and Meson8b SoCs")
Does this make sense?
Also please let me know if you want me to try something else
Martin
[ 136.688684] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 136.734286] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 136.788674] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 136.828895] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 136.896875] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 136.964967] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 137.000656] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 137.068678] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 137.104682] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 137.150289] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 137.196679] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 137.264766] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 137.312879] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 137.348998] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 137.400843] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 137.468977] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 137.520872] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 137.562247] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 137.604680] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 137.672768] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 137.728642] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 137.774148] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 137.832685] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 137.878630] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 137.881232] mmc1: Card stuck being busy! __mmc_poll_for_busy
[ 137.886845] blk_update_request: I/O error, dev mmcblk1, sector 4120744 op 0x3:(DISCARD) flags 0x800 phys_seg 1 prio class 0
[ 137.898190] EXT4-fs (mmcblk1p1): discard request in group:15 block:22549 count:122 failed with -5
[ 138.172111] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 138.181275] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 138.187839] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 138.196747] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 138.203222] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 138.214490] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 138.220361] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 138.229318] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 138.241393] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 138.260297] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 138.295505] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 138.359822] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 138.408629] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 138.476712] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 138.512871] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 138.581011] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 138.616843] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 138.684982] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 138.720859] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 138.786511] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 138.824741] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 138.876723] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 138.912731] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 138.980795] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.032735] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.100826] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 139.136868] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.204966] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.240871] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 139.309008] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.311408] mmc1: Card stuck being busy! __mmc_poll_for_busy
[ 139.317168] mmc1: Erase poll failed err=-110 timeout_ms=1066 - retry!
[ 139.323578] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.331681] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 139.339749] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 139.347895] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.357540] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.366460] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.372529] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.383528] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 139.395631] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 139.414480] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.448738] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.516828] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 139.584881] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.634555] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 139.702775] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.760744] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 139.828833] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 139.864895] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 139.900718] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 139.968883] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 140.004688] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 140.072649] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
[ 140.136750] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 140.176860] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 140.236251] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f003f10
[ 140.280695] platform c1108c20.mmc:slot@1: meson_mx_mmc_card_busy read IRQC = 0x1f001f10
