eMMC initialisation fails: invalid UHS-I mode

eMMC initialisation fails: invalid UHS-I mode

[Ludovic Desroches]

Hi,

I have discovered a bit late that the eMMC on sama5d2_xplained board is 
no longer working since the initialisation fails.

It was working with 4.9. Doing a git bisect, the commit which causes my 
issue is e173f891:
mmc: core: Update CMD13 polling policy when switch to HS DDR mode

Here are the logs:
mmc0: Invalid UHS-I mode selected
mmc0: switch to bus width 8 ddr failed
mmc0: error -110 whilst initialising MMC card

I have not dig much yet. Did someone already report or experience the 
same thing?

It seems that switching to the new timing before checking the switch 
status doesn't work so the timing is set back to MMC_TIMING_MMC_HS that 
causes the invalid UHS-I mode when getting preset value.

Regards

Ludovic

[RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Ludovic Desroches]

From: Ludovic Desroches <ludovic.desroches@microchip.com>

The commit e173f8911f09 mmc: core: Update CMD13 polling policy when
switch to HS DDR mode in addition to fix the management of CRC error,
changes the place where the DDR52 timing is set.

Before this commit, the sequence was:
- set width to 8 with MMC_HS timing
- send the switch command
- check the status
- set width to 8 with MMC_DDR52 timing
- send the switch command
- check the status
Now:
- set width to 8 with MMC_HS timing
- send the switch command
- set width to 8 with MMC_DDR52 timing
- check the status

It may lead to get an error when checking the status with some devices.

Signed-off-by: Ludovic Desroches <ludovic.desroches@microchip.com>
---
 drivers/mmc/core/mmc.c | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/drivers/mmc/core/mmc.c b/drivers/mmc/core/mmc.c
index 0fccca0..b837148 100644
--- a/drivers/mmc/core/mmc.c
+++ b/drivers/mmc/core/mmc.c
@@ -1062,7 +1062,7 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
 			   EXT_CSD_BUS_WIDTH,
 			   ext_csd_bits,
 			   card->ext_csd.generic_cmd6_time,
-			   MMC_TIMING_MMC_DDR52,
+			   0,
 			   true, true, true);
 	if (err) {
 		pr_err("%s: switch to bus width %d ddr failed\n",
@@ -1106,6 +1106,9 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
 	if (err)
 		err = __mmc_set_signal_voltage(host, MMC_SIGNAL_VOLTAGE_330);
 
+	if (!err)
+		mmc_set_timing(host, MMC_TIMING_MMC_DDR52);
+
 	return err;
 }
 
-- 
2.9.0

Re: [RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Nicolas Ferre]

Le 10/03/2017 à 15:21, Ludovic Desroches a écrit :
> From: Ludovic Desroches <ludovic.desroches@microchip.com>
> 
> The commit e173f8911f09 mmc: core: Update CMD13 polling policy when
> switch to HS DDR mode in addition to fix the management of CRC error,
> changes the place where the DDR52 timing is set.
> 
> Before this commit, the sequence was:
> - set width to 8 with MMC_HS timing
> - send the switch command
> - check the status
> - set width to 8 with MMC_DDR52 timing
> - send the switch command
> - check the status
> Now:
> - set width to 8 with MMC_HS timing
> - send the switch command
> - set width to 8 with MMC_DDR52 timing
> - check the status
> 
> It may lead to get an error when checking the status with some devices.
> 
> Signed-off-by: Ludovic Desroches <ludovic.desroches@microchip.com>

If RFC is positive and regression confirmed here
are the tags the shall be added:
Fixes: e173f8911f09 ("mmc: core: Update CMD13 polling policy when switch to HS DDR mode")
Cc: <stable@vger.kernel.org> # v4.10+

> ---
>  drivers/mmc/core/mmc.c | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/drivers/mmc/core/mmc.c b/drivers/mmc/core/mmc.c
> index 0fccca0..b837148 100644
> --- a/drivers/mmc/core/mmc.c
> +++ b/drivers/mmc/core/mmc.c
> @@ -1062,7 +1062,7 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>  			   EXT_CSD_BUS_WIDTH,
>  			   ext_csd_bits,
>  			   card->ext_csd.generic_cmd6_time,
> -			   MMC_TIMING_MMC_DDR52,
> +			   0,
>  			   true, true, true);
>  	if (err) {
>  		pr_err("%s: switch to bus width %d ddr failed\n",
> @@ -1106,6 +1106,9 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>  	if (err)
>  		err = __mmc_set_signal_voltage(host, MMC_SIGNAL_VOLTAGE_330);
>  
> +	if (!err)
> +		mmc_set_timing(host, MMC_TIMING_MMC_DDR52);
> +
>  	return err;
>  }
>  
> 


-- 
Nicolas Ferre

Re: [RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Nicolas Ferre]

Le 10/03/2017 à 15:21, Ludovic Desroches a écrit :
> From: Ludovic Desroches <ludovic.desroches@microchip.com>
> 
> The commit e173f8911f09 mmc: core: Update CMD13 polling policy when
> switch to HS DDR mode in addition to fix the management of CRC error,
> changes the place where the DDR52 timing is set.
> 
> Before this commit, the sequence was:
> - set width to 8 with MMC_HS timing
> - send the switch command
> - check the status
> - set width to 8 with MMC_DDR52 timing
> - send the switch command
> - check the status
> Now:
> - set width to 8 with MMC_HS timing
> - send the switch command
> - set width to 8 with MMC_DDR52 timing
> - check the status
> 
> It may lead to get an error when checking the status with some devices.
> 
> Signed-off-by: Ludovic Desroches <ludovic.desroches@microchip.com>

Tested-by: Nicolas Ferre <nicolas.ferre@microchip.com>

On sama5d2 Xplained (eMMC on sdhci).

Note that without this patch the system is unable to boot. Even if it
was present on 4.10 but we didn't spot it, I see now this as a regression.

We would also need to add the tags:
Cc: stable <stable@vger.kernel.org> #4.10+
Fixes: e173f8911f09 ("mmc: core: Update CMD13 polling policy when switch
to HS DDR mode")


Best regards,

> ---
>  drivers/mmc/core/mmc.c | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/drivers/mmc/core/mmc.c b/drivers/mmc/core/mmc.c
> index 0fccca0..b837148 100644
> --- a/drivers/mmc/core/mmc.c
> +++ b/drivers/mmc/core/mmc.c
> @@ -1062,7 +1062,7 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>  			   EXT_CSD_BUS_WIDTH,
>  			   ext_csd_bits,
>  			   card->ext_csd.generic_cmd6_time,
> -			   MMC_TIMING_MMC_DDR52,
> +			   0,
>  			   true, true, true);
>  	if (err) {
>  		pr_err("%s: switch to bus width %d ddr failed\n",
> @@ -1106,6 +1106,9 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>  	if (err)
>  		err = __mmc_set_signal_voltage(host, MMC_SIGNAL_VOLTAGE_330);
>  
> +	if (!err)
> +		mmc_set_timing(host, MMC_TIMING_MMC_DDR52);
> +
>  	return err;
>  }
>  
> 


-- 
Nicolas Ferre

[RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Nicolas Ferre]

Le 10/03/2017 ? 15:21, Ludovic Desroches a ?crit :
> From: Ludovic Desroches <ludovic.desroches@microchip.com>
> 
> The commit e173f8911f09 mmc: core: Update CMD13 polling policy when
> switch to HS DDR mode in addition to fix the management of CRC error,
> changes the place where the DDR52 timing is set.
> 
> Before this commit, the sequence was:
> - set width to 8 with MMC_HS timing
> - send the switch command
> - check the status
> - set width to 8 with MMC_DDR52 timing
> - send the switch command
> - check the status
> Now:
> - set width to 8 with MMC_HS timing
> - send the switch command
> - set width to 8 with MMC_DDR52 timing
> - check the status
> 
> It may lead to get an error when checking the status with some devices.
> 
> Signed-off-by: Ludovic Desroches <ludovic.desroches@microchip.com>

Tested-by: Nicolas Ferre <nicolas.ferre@microchip.com>

On sama5d2 Xplained (eMMC on sdhci).

Note that without this patch the system is unable to boot. Even if it
was present on 4.10 but we didn't spot it, I see now this as a regression.

We would also need to add the tags:
Cc: stable <stable@vger.kernel.org> #4.10+
Fixes: e173f8911f09 ("mmc: core: Update CMD13 polling policy when switch
to HS DDR mode")


Best regards,

> ---
>  drivers/mmc/core/mmc.c | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/drivers/mmc/core/mmc.c b/drivers/mmc/core/mmc.c
> index 0fccca0..b837148 100644
> --- a/drivers/mmc/core/mmc.c
> +++ b/drivers/mmc/core/mmc.c
> @@ -1062,7 +1062,7 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>  			   EXT_CSD_BUS_WIDTH,
>  			   ext_csd_bits,
>  			   card->ext_csd.generic_cmd6_time,
> -			   MMC_TIMING_MMC_DDR52,
> +			   0,
>  			   true, true, true);
>  	if (err) {
>  		pr_err("%s: switch to bus width %d ddr failed\n",
> @@ -1106,6 +1106,9 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>  	if (err)
>  		err = __mmc_set_signal_voltage(host, MMC_SIGNAL_VOLTAGE_330);
>  
> +	if (!err)
> +		mmc_set_timing(host, MMC_TIMING_MMC_DDR52);
> +
>  	return err;
>  }
>  
> 


-- 
Nicolas Ferre

Re: [RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Ulf Hansson]

On 10 March 2017 at 15:21, Ludovic Desroches
<ludovic.desroches@atmel.com> wrote:
> From: Ludovic Desroches <ludovic.desroches@microchip.com>
>
> The commit e173f8911f09 mmc: core: Update CMD13 polling policy when
> switch to HS DDR mode in addition to fix the management of CRC error,
> changes the place where the DDR52 timing is set.
>
> Before this commit, the sequence was:
> - set width to 8 with MMC_HS timing
> - send the switch command
> - check the status
> - set width to 8 with MMC_DDR52 timing
> - send the switch command
> - check the status
> Now:
> - set width to 8 with MMC_HS timing
> - send the switch command
> - set width to 8 with MMC_DDR52 timing
> - check the status
>
> It may lead to get an error when checking the status with some devices.
>
> Signed-off-by: Ludovic Desroches <ludovic.desroches@microchip.com>
> ---
>  drivers/mmc/core/mmc.c | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
>
> diff --git a/drivers/mmc/core/mmc.c b/drivers/mmc/core/mmc.c
> index 0fccca0..b837148 100644
> --- a/drivers/mmc/core/mmc.c
> +++ b/drivers/mmc/core/mmc.c
> @@ -1062,7 +1062,7 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>                            EXT_CSD_BUS_WIDTH,
>                            ext_csd_bits,
>                            card->ext_csd.generic_cmd6_time,
> -                          MMC_TIMING_MMC_DDR52,
> +                          0,
>                            true, true, true);
>         if (err) {
>                 pr_err("%s: switch to bus width %d ddr failed\n",
> @@ -1106,6 +1106,9 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>         if (err)
>                 err = __mmc_set_signal_voltage(host, MMC_SIGNAL_VOLTAGE_330);
>
> +       if (!err)
> +               mmc_set_timing(host, MMC_TIMING_MMC_DDR52);
> +
>         return err;
>  }
>
> --
> 2.9.0
>

We had other reports for similar problems. The following change fix
those issues, have you tried this out?

[PATCH] mmc: core: Restore parts of the polling policy when switch to HS/HS DDR
https://patchwork.kernel.org/patch/9515239/

Kind regards
Uffe

Re: [RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Ludovic Desroches]

On Fri, Mar 17, 2017 at 04:14:18PM +0100, Ulf Hansson wrote:
> On 10 March 2017 at 15:21, Ludovic Desroches
> <ludovic.desroches@atmel.com> wrote:
> > From: Ludovic Desroches <ludovic.desroches@microchip.com>
> >
> > The commit e173f8911f09 mmc: core: Update CMD13 polling policy when
> > switch to HS DDR mode in addition to fix the management of CRC error,
> > changes the place where the DDR52 timing is set.
> >
> > Before this commit, the sequence was:
> > - set width to 8 with MMC_HS timing
> > - send the switch command
> > - check the status
> > - set width to 8 with MMC_DDR52 timing
> > - send the switch command
> > - check the status
> > Now:
> > - set width to 8 with MMC_HS timing
> > - send the switch command
> > - set width to 8 with MMC_DDR52 timing
> > - check the status
> >
> > It may lead to get an error when checking the status with some devices.
> >
> > Signed-off-by: Ludovic Desroches <ludovic.desroches@microchip.com>
> > ---
> >  drivers/mmc/core/mmc.c | 5 ++++-
> >  1 file changed, 4 insertions(+), 1 deletion(-)
> >
> > diff --git a/drivers/mmc/core/mmc.c b/drivers/mmc/core/mmc.c
> > index 0fccca0..b837148 100644
> > --- a/drivers/mmc/core/mmc.c
> > +++ b/drivers/mmc/core/mmc.c
> > @@ -1062,7 +1062,7 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
> >                            EXT_CSD_BUS_WIDTH,
> >                            ext_csd_bits,
> >                            card->ext_csd.generic_cmd6_time,
> > -                          MMC_TIMING_MMC_DDR52,
> > +                          0,
> >                            true, true, true);
> >         if (err) {
> >                 pr_err("%s: switch to bus width %d ddr failed\n",
> > @@ -1106,6 +1106,9 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
> >         if (err)
> >                 err = __mmc_set_signal_voltage(host, MMC_SIGNAL_VOLTAGE_330);
> >
> > +       if (!err)
> > +               mmc_set_timing(host, MMC_TIMING_MMC_DDR52);
> > +
> >         return err;
> >  }
> >
> > --
> > 2.9.0
> >
> 
> We had other reports for similar problems. The following change fix
> those issues, have you tried this out?
> 
> [PATCH] mmc: core: Restore parts of the polling policy when switch to HS/HS DDR
> https://patchwork.kernel.org/patch/9515239/

I did the test with next and the behavior is the same.

mmc0: Invalid UHS-I mode selected                          
mmc0: switch to bus width 8 ddr failed                  
mmc0: error -110 whilst initialising MMC card 

It seems the root cause is to perform mmc_set_timing before mmc_switch_status.

Regards

Ludovic

Re: [RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Ulf Hansson]

On 17 March 2017 at 17:33, Ludovic Desroches
<ludovic.desroches@microchip.com> wrote:
> On Fri, Mar 17, 2017 at 04:14:18PM +0100, Ulf Hansson wrote:
>> On 10 March 2017 at 15:21, Ludovic Desroches
>> <ludovic.desroches@atmel.com> wrote:
>> > From: Ludovic Desroches <ludovic.desroches@microchip.com>
>> >
>> > The commit e173f8911f09 mmc: core: Update CMD13 polling policy when
>> > switch to HS DDR mode in addition to fix the management of CRC error,
>> > changes the place where the DDR52 timing is set.
>> >
>> > Before this commit, the sequence was:
>> > - set width to 8 with MMC_HS timing
>> > - send the switch command
>> > - check the status
>> > - set width to 8 with MMC_DDR52 timing
>> > - send the switch command
>> > - check the status
>> > Now:
>> > - set width to 8 with MMC_HS timing
>> > - send the switch command
>> > - set width to 8 with MMC_DDR52 timing
>> > - check the status
>> >
>> > It may lead to get an error when checking the status with some devices.
>> >
>> > Signed-off-by: Ludovic Desroches <ludovic.desroches@microchip.com>
>> > ---
>> >  drivers/mmc/core/mmc.c | 5 ++++-
>> >  1 file changed, 4 insertions(+), 1 deletion(-)
>> >
>> > diff --git a/drivers/mmc/core/mmc.c b/drivers/mmc/core/mmc.c
>> > index 0fccca0..b837148 100644
>> > --- a/drivers/mmc/core/mmc.c
>> > +++ b/drivers/mmc/core/mmc.c
>> > @@ -1062,7 +1062,7 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>> >                            EXT_CSD_BUS_WIDTH,
>> >                            ext_csd_bits,
>> >                            card->ext_csd.generic_cmd6_time,
>> > -                          MMC_TIMING_MMC_DDR52,
>> > +                          0,
>> >                            true, true, true);
>> >         if (err) {
>> >                 pr_err("%s: switch to bus width %d ddr failed\n",
>> > @@ -1106,6 +1106,9 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>> >         if (err)
>> >                 err = __mmc_set_signal_voltage(host, MMC_SIGNAL_VOLTAGE_330);
>> >
>> > +       if (!err)
>> > +               mmc_set_timing(host, MMC_TIMING_MMC_DDR52);
>> > +
>> >         return err;
>> >  }
>> >
>> > --
>> > 2.9.0
>> >
>>
>> We had other reports for similar problems. The following change fix
>> those issues, have you tried this out?
>>
>> [PATCH] mmc: core: Restore parts of the polling policy when switch to HS/HS DDR
>> https://patchwork.kernel.org/patch/9515239/
>
> I did the test with next and the behavior is the same.
>
> mmc0: Invalid UHS-I mode selected
> mmc0: switch to bus width 8 ddr failed
> mmc0: error -110 whilst initialising MMC card
>
> It seems the root cause is to perform mmc_set_timing before mmc_switch_status.

Okay, I see! This sounds a bit weird.

As you know, the CMD6 has been a problematic historically, mostly
because of busy detection issues. We have now tried to make the code
more robust in __mmc_switch() and its friends.
That said, before considering to apply your fix, I would really like
us to investigate this a bit more, to make sure we find the correct
solution and of course to avoid regressions for other cases.

Recently reported issues [1] that was observed for sdhci-esdc-imx,
which has been fixed now, can be summarized in these two issues:

*) Only 3.3V I/O voltage DDR mode was supported by the SoC. Still the
mmc core tried to set 1.8V, which caused errors when switching to HS
DDR mode.
-> To fix this, we invented MMC_CAP_3_3V_DDR [2] and a corresponding
DT binding ("mmc-ddr-3_3v"). Hosts/SoCs, that supports only 3.3V DDR
mode, should set this.

**). Changing host's timings couldn't be done while the card was busy,
because of internal limitations by the sdhci-esdhc-imx controller. The
consequence was that the following CMD13 command (to get the switch
status), returned the error code -110, perhaps similar to your case.
->To fix this, we decided to move the update of the host's timing, to
after we verified the card isn't being busy [3].


>From your description to the problem you encounter, I would recommend
the following debug steps to try to understand what really goes on.
1.
Check if the 3.3V DDR issue is applicable for your case as well, and
fix it if it is.

2.
Both sdhci-esdhc-imx and sdhci-of-at91, don't have
MMC_CAP_WAIT_WHILE_BUSY set. However, both sdhci variants are using
the ->card_busy() host ops (assigned to sdhci_card_busy()), which
triggers __mmc_switch() to call mmc_poll_for_busy() when it switches
to HS DDR mode (CMD6). Could it be that sdhci_card_busy() isn't
working properly for sdhci-of-at91? This could lead to that that
mmc_poll_for_busy() believes the card isn't busy, while it actually
is.

To check whether theory 2 stands, I would explore these debug alternatives.
*) Remove the assignment of ->card_busy() in sdhci.c, which makes
mmc_poll_for_busy() to use CMD13 polling instead. If this works, it
would be useful to know how many times a CMD13 is sent to find out
when card moves out of busy state.
**) While using ->card_busy(), I would just add some simple debug
prints in mmc_poll_for_busy() to prints its return values.

Kind regards
Uffe

[1]
https://patchwork.kernel.org/patch/9514583
[2]
https://www.spinics.net/lists/linux-mmc/msg41967.html
[3]
https://patchwork.kernel.org/patch/9515239

Re: [RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Ludovic Desroches]

Hi Ulf,

On Wed, Mar 22, 2017 at 09:41:28AM +0100, Ulf Hansson wrote:
> On 17 March 2017 at 17:33, Ludovic Desroches
> <ludovic.desroches@microchip.com> wrote:
> > On Fri, Mar 17, 2017 at 04:14:18PM +0100, Ulf Hansson wrote:
> >> On 10 March 2017 at 15:21, Ludovic Desroches
> >> <ludovic.desroches@atmel.com> wrote:
> >> > From: Ludovic Desroches <ludovic.desroches@microchip.com>
> >> >
> >> > The commit e173f8911f09 mmc: core: Update CMD13 polling policy when
> >> > switch to HS DDR mode in addition to fix the management of CRC error,
> >> > changes the place where the DDR52 timing is set.
> >> >
> >> > Before this commit, the sequence was:
> >> > - set width to 8 with MMC_HS timing
> >> > - send the switch command
> >> > - check the status
> >> > - set width to 8 with MMC_DDR52 timing
> >> > - send the switch command
> >> > - check the status
> >> > Now:
> >> > - set width to 8 with MMC_HS timing
> >> > - send the switch command
> >> > - set width to 8 with MMC_DDR52 timing
> >> > - check the status
> >> >
> >> > It may lead to get an error when checking the status with some devices.
> >> >
> >> > Signed-off-by: Ludovic Desroches <ludovic.desroches@microchip.com>
> >> > ---
> >> >  drivers/mmc/core/mmc.c | 5 ++++-
> >> >  1 file changed, 4 insertions(+), 1 deletion(-)
> >> >
> >> > diff --git a/drivers/mmc/core/mmc.c b/drivers/mmc/core/mmc.c
> >> > index 0fccca0..b837148 100644
> >> > --- a/drivers/mmc/core/mmc.c
> >> > +++ b/drivers/mmc/core/mmc.c
> >> > @@ -1062,7 +1062,7 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
> >> >                            EXT_CSD_BUS_WIDTH,
> >> >                            ext_csd_bits,
> >> >                            card->ext_csd.generic_cmd6_time,
> >> > -                          MMC_TIMING_MMC_DDR52,
> >> > +                          0,
> >> >                            true, true, true);
> >> >         if (err) {
> >> >                 pr_err("%s: switch to bus width %d ddr failed\n",
> >> > @@ -1106,6 +1106,9 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
> >> >         if (err)
> >> >                 err = __mmc_set_signal_voltage(host, MMC_SIGNAL_VOLTAGE_330);
> >> >
> >> > +       if (!err)
> >> > +               mmc_set_timing(host, MMC_TIMING_MMC_DDR52);
> >> > +
> >> >         return err;
> >> >  }
> >> >
> >> > --
> >> > 2.9.0
> >> >
> >>
> >> We had other reports for similar problems. The following change fix
> >> those issues, have you tried this out?
> >>
> >> [PATCH] mmc: core: Restore parts of the polling policy when switch to HS/HS DDR
> >> https://patchwork.kernel.org/patch/9515239/
> >
> > I did the test with next and the behavior is the same.
> >
> > mmc0: Invalid UHS-I mode selected
> > mmc0: switch to bus width 8 ddr failed
> > mmc0: error -110 whilst initialising MMC card
> >
> > It seems the root cause is to perform mmc_set_timing before mmc_switch_status.
> 
> Okay, I see! This sounds a bit weird.
> 
> As you know, the CMD6 has been a problematic historically, mostly
> because of busy detection issues. We have now tried to make the code
> more robust in __mmc_switch() and its friends.
> That said, before considering to apply your fix, I would really like
> us to investigate this a bit more, to make sure we find the correct
> solution and of course to avoid regressions for other cases.
> 
> Recently reported issues [1] that was observed for sdhci-esdc-imx,
> which has been fixed now, can be summarized in these two issues:
> 
> *) Only 3.3V I/O voltage DDR mode was supported by the SoC. Still the
> mmc core tried to set 1.8V, which caused errors when switching to HS
> DDR mode.
> -> To fix this, we invented MMC_CAP_3_3V_DDR [2] and a corresponding
> DT binding ("mmc-ddr-3_3v"). Hosts/SoCs, that supports only 3.3V DDR
> mode, should set this.
> 
> **). Changing host's timings couldn't be done while the card was busy,
> because of internal limitations by the sdhci-esdhc-imx controller. The
> consequence was that the following CMD13 command (to get the switch
> status), returned the error code -110, perhaps similar to your case.
> ->To fix this, we decided to move the update of the host's timing, to
> after we verified the card isn't being busy [3].
> 
>
> From your description to the problem you encounter, I would recommend
> the following debug steps to try to understand what really goes on.
> 1.
> Check if the 3.3V DDR issue is applicable for your case as well, and
> fix it if it is.

There is a regulator driven by the sdhci controller to manage 3.3V and
1.8V I/O voltage.

> 
> 2.
> Both sdhci-esdhc-imx and sdhci-of-at91, don't have
> MMC_CAP_WAIT_WHILE_BUSY set. However, both sdhci variants are using
> the ->card_busy() host ops (assigned to sdhci_card_busy()), which
> triggers __mmc_switch() to call mmc_poll_for_busy() when it switches
> to HS DDR mode (CMD6). Could it be that sdhci_card_busy() isn't
> working properly for sdhci-of-at91? This could lead to that that
> mmc_poll_for_busy() believes the card isn't busy, while it actually
> is.
> 
> To check whether theory 2 stands, I would explore these debug alternatives.
> *) Remove the assignment of ->card_busy() in sdhci.c, which makes
> mmc_poll_for_busy() to use CMD13 polling instead. If this works, it
> would be useful to know how many times a CMD13 is sent to find out
> when card moves out of busy state.

It doesn't work.

> **) While using ->card_busy(), I would just add some simple debug
> prints in mmc_poll_for_busy() to prints its return values.

No error returned. I exit the function after the while loop.

I continue the investigation to figure out why calling mmc_set_timing before
mmc_switch_status causes an issue.

Regards

Ludovic

> Kind regards
> Uffe
> 
> [1]
> https://patchwork.kernel.org/patch/9514583
> [2]
> https://www.spinics.net/lists/linux-mmc/msg41967.html
> [3]
> https://patchwork.kernel.org/patch/9515239

Re: [RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Ulf Hansson]

[...]

>> >>
>> >> We had other reports for similar problems. The following change fix
>> >> those issues, have you tried this out?
>> >>
>> >> [PATCH] mmc: core: Restore parts of the polling policy when switch to HS/HS DDR
>> >> https://patchwork.kernel.org/patch/9515239/
>> >
>> > I did the test with next and the behavior is the same.
>> >
>> > mmc0: Invalid UHS-I mode selected
>> > mmc0: switch to bus width 8 ddr failed
>> > mmc0: error -110 whilst initialising MMC card
>> >
>> > It seems the root cause is to perform mmc_set_timing before mmc_switch_status.
>>
>> Okay, I see! This sounds a bit weird.
>>
>> As you know, the CMD6 has been a problematic historically, mostly
>> because of busy detection issues. We have now tried to make the code
>> more robust in __mmc_switch() and its friends.
>> That said, before considering to apply your fix, I would really like
>> us to investigate this a bit more, to make sure we find the correct
>> solution and of course to avoid regressions for other cases.
>>
>> Recently reported issues [1] that was observed for sdhci-esdc-imx,
>> which has been fixed now, can be summarized in these two issues:
>>
>> *) Only 3.3V I/O voltage DDR mode was supported by the SoC. Still the
>> mmc core tried to set 1.8V, which caused errors when switching to HS
>> DDR mode.
>> -> To fix this, we invented MMC_CAP_3_3V_DDR [2] and a corresponding
>> DT binding ("mmc-ddr-3_3v"). Hosts/SoCs, that supports only 3.3V DDR
>> mode, should set this.
>>
>> **). Changing host's timings couldn't be done while the card was busy,
>> because of internal limitations by the sdhci-esdhc-imx controller. The
>> consequence was that the following CMD13 command (to get the switch
>> status), returned the error code -110, perhaps similar to your case.
>> ->To fix this, we decided to move the update of the host's timing, to
>> after we verified the card isn't being busy [3].
>>
>>
>> From your description to the problem you encounter, I would recommend
>> the following debug steps to try to understand what really goes on.
>> 1.
>> Check if the 3.3V DDR issue is applicable for your case as well, and
>> fix it if it is.
>
> There is a regulator driven by the sdhci controller to manage 3.3V and
> 1.8V I/O voltage.
>
>>
>> 2.
>> Both sdhci-esdhc-imx and sdhci-of-at91, don't have
>> MMC_CAP_WAIT_WHILE_BUSY set. However, both sdhci variants are using
>> the ->card_busy() host ops (assigned to sdhci_card_busy()), which
>> triggers __mmc_switch() to call mmc_poll_for_busy() when it switches
>> to HS DDR mode (CMD6). Could it be that sdhci_card_busy() isn't
>> working properly for sdhci-of-at91? This could lead to that that
>> mmc_poll_for_busy() believes the card isn't busy, while it actually
>> is.
>>
>> To check whether theory 2 stands, I would explore these debug alternatives.
>> *) Remove the assignment of ->card_busy() in sdhci.c, which makes
>> mmc_poll_for_busy() to use CMD13 polling instead. If this works, it
>> would be useful to know how many times a CMD13 is sent to find out
>> when card moves out of busy state.
>
> It doesn't work.

Okay. So what kind of error do you get when sending the CMD13 to poll? -110?

>
>> **) While using ->card_busy(), I would just add some simple debug
>> prints in mmc_poll_for_busy() to prints its return values.
>
> No error returned. I exit the function after the while loop.

If I understand correctly, the ->card_busy() callbacks immediately
reports the eMMC card as *not* being busy, right?

>
> I continue the investigation to figure out why calling mmc_set_timing before
> mmc_switch_status causes an issue.

Great!

Please tell if you need some further help with some more ideas.

[...]

Kind regards
Uffe

Re: [RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Ludovic Desroches]

On Wed, Mar 22, 2017 at 12:18:00PM +0100, Ulf Hansson wrote:
> [...]
> 
> >> >>
> >> >> We had other reports for similar problems. The following change fix
> >> >> those issues, have you tried this out?
> >> >>
> >> >> [PATCH] mmc: core: Restore parts of the polling policy when switch to HS/HS DDR
> >> >> https://patchwork.kernel.org/patch/9515239/
> >> >
> >> > I did the test with next and the behavior is the same.
> >> >
> >> > mmc0: Invalid UHS-I mode selected
> >> > mmc0: switch to bus width 8 ddr failed
> >> > mmc0: error -110 whilst initialising MMC card
> >> >
> >> > It seems the root cause is to perform mmc_set_timing before mmc_switch_status.
> >>
> >> Okay, I see! This sounds a bit weird.
> >>
> >> As you know, the CMD6 has been a problematic historically, mostly
> >> because of busy detection issues. We have now tried to make the code
> >> more robust in __mmc_switch() and its friends.
> >> That said, before considering to apply your fix, I would really like
> >> us to investigate this a bit more, to make sure we find the correct
> >> solution and of course to avoid regressions for other cases.
> >>
> >> Recently reported issues [1] that was observed for sdhci-esdc-imx,
> >> which has been fixed now, can be summarized in these two issues:
> >>
> >> *) Only 3.3V I/O voltage DDR mode was supported by the SoC. Still the
> >> mmc core tried to set 1.8V, which caused errors when switching to HS
> >> DDR mode.
> >> -> To fix this, we invented MMC_CAP_3_3V_DDR [2] and a corresponding
> >> DT binding ("mmc-ddr-3_3v"). Hosts/SoCs, that supports only 3.3V DDR
> >> mode, should set this.
> >>
> >> **). Changing host's timings couldn't be done while the card was busy,
> >> because of internal limitations by the sdhci-esdhc-imx controller. The
> >> consequence was that the following CMD13 command (to get the switch
> >> status), returned the error code -110, perhaps similar to your case.
> >> ->To fix this, we decided to move the update of the host's timing, to
> >> after we verified the card isn't being busy [3].
> >>
> >>
> >> From your description to the problem you encounter, I would recommend
> >> the following debug steps to try to understand what really goes on.
> >> 1.
> >> Check if the 3.3V DDR issue is applicable for your case as well, and
> >> fix it if it is.
> >
> > There is a regulator driven by the sdhci controller to manage 3.3V and
> > 1.8V I/O voltage.
> >
> >>
> >> 2.
> >> Both sdhci-esdhc-imx and sdhci-of-at91, don't have
> >> MMC_CAP_WAIT_WHILE_BUSY set. However, both sdhci variants are using
> >> the ->card_busy() host ops (assigned to sdhci_card_busy()), which
> >> triggers __mmc_switch() to call mmc_poll_for_busy() when it switches
> >> to HS DDR mode (CMD6). Could it be that sdhci_card_busy() isn't
> >> working properly for sdhci-of-at91? This could lead to that that
> >> mmc_poll_for_busy() believes the card isn't busy, while it actually
> >> is.
> >>
> >> To check whether theory 2 stands, I would explore these debug alternatives.
> >> *) Remove the assignment of ->card_busy() in sdhci.c, which makes
> >> mmc_poll_for_busy() to use CMD13 polling instead. If this works, it
> >> would be useful to know how many times a CMD13 is sent to find out
> >> when card moves out of busy state.
> >
> > It doesn't work.
> 
> Okay. So what kind of error do you get when sending the CMD13 to poll? -110?

No error when I poll after CMD6. Here is a log with CMD13 to perform the
polling:

mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 1
mmc0: starting CMD8 arg 00000000 flags 000000b5
mmc0:     blksz 512 blocks 1 flags 00000200 tsac 400 ms nsac 1000
mmc0: sdhci: IRQ status 0x00000001
mmc0: sdhci: IRQ status 0x00000002
mmc0: req done (CMD8): 0: 00000900 00000000 00000000 00000000
mmc0:     512 bytes transferred: 0
=== mmc_select_hs_ddr: l.1072 ===
--- __mmc_switch ---
__mmc_switch: mmc_wait_for_cmd
mmc0: starting CMD6 arg 03b70601 flags 0000049d
mmc0: sdhci: IRQ status 0x00000001
mmc0: sdhci: IRQ status 0x00000002
mmc0: req done (CMD6): 0: 00000800 00000000 00000000 00000000
__mmc_switch: mmc_poll_for_busy
mmc0: starting CMD13 arg 00010000 flags 00000195
mmc0: sdhci: IRQ status 0x00000001
mmc0: req done (CMD13): 0: 00000900 00000000 00000000 00000000
mmc_poll_for_busy: l.512
__mmc_switch: mmc_set_timing
mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 8
__mmc_switch: mmc_switch_status
mmc0: starting CMD13 arg 00010000 flags 00000195
mmc0: sdhci: IRQ status 0x00038000
mmc0: req failed (CMD13): -110, retrying...
mmc0: sdhci: IRQ status 0x00038000
mmc0: req failed (CMD13): -110, retrying...
mmc0: sdhci: IRQ status 0x00038000
mmc0: req failed (CMD13): -110, retrying...
mmc0: sdhci: IRQ status 0x00038000
mmc0: req done (CMD13): -110: 00000000 00000000 00000000 00000000
mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 1
mmc0: Invalid UHS-I mode selected
mmc0: switch to bus width 8 ddr failed
mmc0: error -110 whilst initialising MMC card
mmc0: clock 0Hz busmode 2 powermode 0 cs 0 Vdd 0 width 1 timing 0


> 
> >
> >> **) While using ->card_busy(), I would just add some simple debug
> >> prints in mmc_poll_for_busy() to prints its return values.
> >
> > No error returned. I exit the function after the while loop.
> 
> If I understand correctly, the ->card_busy() callbacks immediately
> reports the eMMC card as *not* being busy, right?

Yes, with sdhci_card_busy() this time:

=== mmc_select_hs_ddr: l.1072 ===                                                                       
--- __mmc_switch ---
__mmc_switch: mmc_wait_for_cmd
mmc0: starting CMD6 arg 03b70601 flags 0000049d
mmc0: sdhci: IRQ status 0x00000001
mmc0: sdhci: IRQ status 0x00000002
mmc0: req done (CMD6): 0: 00000800 00000000 00000000 00000000
__mmc_switch: mmc_poll_for_busy
mmc_poll_for_busy: ops->card_busy
mmc_poll_for_busy: l.513
__mmc_switch: mmc_set_timing
mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 8
__mmc_switch: mmc_switch_status
mmc0: starting CMD13 arg 00010000 flags 00000195
mmc0: sdhci: IRQ status 0x00038000
mmc0: req failed (CMD13): -110, retrying...
mmc0: sdhci: IRQ status 0x00038000
mmc0: req failed (CMD13): -110, retrying...
mmc0: sdhci: IRQ status 0x00038000
mmc0: req failed (CMD13): -110, retrying...
mmc0: sdhci: IRQ status 0x00038000
mmc0: req done (CMD13): -110: 00000000 00000000 00000000 00000000
mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 1
mmc0: Invalid UHS-I mode selected
mmc0: switch to bus width 8 ddr failed
mmc0: error -110 whilst initialising MMC card


> 
> >
> > I continue the investigation to figure out why calling mmc_set_timing before
> > mmc_switch_status causes an issue.
> 
> Great!
> 
> Please tell if you need some further help with some more ideas.

Ok thanks.

To compare, if I put mmc_set_timing after mmc_switch_status:

mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 1
mmc0: starting CMD8 arg 00000000 flags 000000b5
mmc0:     blksz 512 blocks 1 flags 00000200 tsac 400 ms nsac 1000
mmc0: sdhci: IRQ status 0x00000001             
mmc0: sdhci: IRQ status 0x00000002
mmc0: req done (CMD8): 0: 00000900 00000000 00000000 00000000
mmc0:     512 bytes transferred: 0             
=== mmc_select_hs_ddr: l.1072 === 
--- __mmc_switch ---                                                 
__mmc_switch: mmc_wait_for_cmd                 
mmc0: starting CMD6 arg 03b70601 flags 0000049d                                                   
mmc0: sdhci: IRQ status 0x00000001                                                                      
mmc0: sdhci: IRQ status 0x00000002             
mmc0: req done (CMD6): 0: 00000800 00000000 00000000 00000000
__mmc_switch: mmc_poll_for_busy                              
mmc_poll_for_busy: ops->card_busy              
mmc_poll_for_busy: l.513          
__mmc_switch: mmc_switch_status
mmc0: starting CMD13 arg 00010000 flags 00000195
mmc0: sdhci: IRQ status 0x00000001
mmc0: req done (CMD13): 0: 00000900 00000000 00000000 00000000
__mmc_switch: mmc_set_timing
mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 8
--- __mmc_switch ---
__mmc_switch: mmc_wait_for_cmd
mmc0: starting CMD6 arg 03a10101 flags 0000049d
mmc0: sdhci: IRQ status 0x00000001
mmc0: sdhci: IRQ status 0x00000002
mmc0: req done (CMD6): 0: 00000800 00000000 00000000 00000000
__mmc_switch: mmc_poll_for_busy
mmc_poll_for_busy: ops->card_busy
mmc_poll_for_busy: l.513
__mmc_switch: mmc_switch_status
mmc0: starting CMD13 arg 00010000 flags 00000195
mmc0: sdhci: IRQ status 0x00000001
mmc0: req done (CMD13): 0: 00000900 00000000 00000000 00000000
mmc0: new DDR MMC card at address 0001

Regards

Ludovic

Re: [RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Ludovic Desroches]

On Wed, Mar 22, 2017 at 05:17:38PM +0100, Ludovic Desroches wrote:
> On Wed, Mar 22, 2017 at 12:18:00PM +0100, Ulf Hansson wrote:
> > [...]
> > 
> > >> >>
> > >> >> We had other reports for similar problems. The following change fix
> > >> >> those issues, have you tried this out?
> > >> >>
> > >> >> [PATCH] mmc: core: Restore parts of the polling policy when switch to HS/HS DDR
> > >> >> https://patchwork.kernel.org/patch/9515239/
> > >> >
> > >> > I did the test with next and the behavior is the same.
> > >> >
> > >> > mmc0: Invalid UHS-I mode selected
> > >> > mmc0: switch to bus width 8 ddr failed
> > >> > mmc0: error -110 whilst initialising MMC card
> > >> >
> > >> > It seems the root cause is to perform mmc_set_timing before mmc_switch_status.
> > >>
> > >> Okay, I see! This sounds a bit weird.
> > >>
> > >> As you know, the CMD6 has been a problematic historically, mostly
> > >> because of busy detection issues. We have now tried to make the code
> > >> more robust in __mmc_switch() and its friends.
> > >> That said, before considering to apply your fix, I would really like
> > >> us to investigate this a bit more, to make sure we find the correct
> > >> solution and of course to avoid regressions for other cases.
> > >>
> > >> Recently reported issues [1] that was observed for sdhci-esdc-imx,
> > >> which has been fixed now, can be summarized in these two issues:
> > >>
> > >> *) Only 3.3V I/O voltage DDR mode was supported by the SoC. Still the
> > >> mmc core tried to set 1.8V, which caused errors when switching to HS
> > >> DDR mode.
> > >> -> To fix this, we invented MMC_CAP_3_3V_DDR [2] and a corresponding
> > >> DT binding ("mmc-ddr-3_3v"). Hosts/SoCs, that supports only 3.3V DDR
> > >> mode, should set this.
> > >>
> > >> **). Changing host's timings couldn't be done while the card was busy,
> > >> because of internal limitations by the sdhci-esdhc-imx controller. The
> > >> consequence was that the following CMD13 command (to get the switch
> > >> status), returned the error code -110, perhaps similar to your case.
> > >> ->To fix this, we decided to move the update of the host's timing, to
> > >> after we verified the card isn't being busy [3].
> > >>
> > >>
> > >> From your description to the problem you encounter, I would recommend
> > >> the following debug steps to try to understand what really goes on.
> > >> 1.
> > >> Check if the 3.3V DDR issue is applicable for your case as well, and
> > >> fix it if it is.
> > >
> > > There is a regulator driven by the sdhci controller to manage 3.3V and
> > > 1.8V I/O voltage.
> > >
> > >>
> > >> 2.
> > >> Both sdhci-esdhc-imx and sdhci-of-at91, don't have
> > >> MMC_CAP_WAIT_WHILE_BUSY set. However, both sdhci variants are using
> > >> the ->card_busy() host ops (assigned to sdhci_card_busy()), which
> > >> triggers __mmc_switch() to call mmc_poll_for_busy() when it switches
> > >> to HS DDR mode (CMD6). Could it be that sdhci_card_busy() isn't
> > >> working properly for sdhci-of-at91? This could lead to that that
> > >> mmc_poll_for_busy() believes the card isn't busy, while it actually
> > >> is.
> > >>
> > >> To check whether theory 2 stands, I would explore these debug alternatives.
> > >> *) Remove the assignment of ->card_busy() in sdhci.c, which makes
> > >> mmc_poll_for_busy() to use CMD13 polling instead. If this works, it
> > >> would be useful to know how many times a CMD13 is sent to find out
> > >> when card moves out of busy state.
> > >
> > > It doesn't work.
> > 
> > Okay. So what kind of error do you get when sending the CMD13 to poll? -110?
> 
> No error when I poll after CMD6. Here is a log with CMD13 to perform the
> polling:
> 
> mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 1
> mmc0: starting CMD8 arg 00000000 flags 000000b5
> mmc0:     blksz 512 blocks 1 flags 00000200 tsac 400 ms nsac 1000
> mmc0: sdhci: IRQ status 0x00000001
> mmc0: sdhci: IRQ status 0x00000002
> mmc0: req done (CMD8): 0: 00000900 00000000 00000000 00000000
> mmc0:     512 bytes transferred: 0
> === mmc_select_hs_ddr: l.1072 ===
> --- __mmc_switch ---
> __mmc_switch: mmc_wait_for_cmd
> mmc0: starting CMD6 arg 03b70601 flags 0000049d
> mmc0: sdhci: IRQ status 0x00000001
> mmc0: sdhci: IRQ status 0x00000002
> mmc0: req done (CMD6): 0: 00000800 00000000 00000000 00000000
> __mmc_switch: mmc_poll_for_busy
> mmc0: starting CMD13 arg 00010000 flags 00000195
> mmc0: sdhci: IRQ status 0x00000001
> mmc0: req done (CMD13): 0: 00000900 00000000 00000000 00000000
> mmc_poll_for_busy: l.512
> __mmc_switch: mmc_set_timing
> mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 8
> __mmc_switch: mmc_switch_status
> mmc0: starting CMD13 arg 00010000 flags 00000195
> mmc0: sdhci: IRQ status 0x00038000
> mmc0: req failed (CMD13): -110, retrying...
> mmc0: sdhci: IRQ status 0x00038000
> mmc0: req failed (CMD13): -110, retrying...
> mmc0: sdhci: IRQ status 0x00038000
> mmc0: req failed (CMD13): -110, retrying...
> mmc0: sdhci: IRQ status 0x00038000
> mmc0: req done (CMD13): -110: 00000000 00000000 00000000 00000000
> mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 1
> mmc0: Invalid UHS-I mode selected
> mmc0: switch to bus width 8 ddr failed
> mmc0: error -110 whilst initialising MMC card
> mmc0: clock 0Hz busmode 2 powermode 0 cs 0 Vdd 0 width 1 timing 0
> 
> 
> > 
> > >
> > >> **) While using ->card_busy(), I would just add some simple debug
> > >> prints in mmc_poll_for_busy() to prints its return values.
> > >
> > > No error returned. I exit the function after the while loop.
> > 
> > If I understand correctly, the ->card_busy() callbacks immediately
> > reports the eMMC card as *not* being busy, right?
> 
> Yes, with sdhci_card_busy() this time:
> 
> === mmc_select_hs_ddr: l.1072 ===                                                                       
> --- __mmc_switch ---
> __mmc_switch: mmc_wait_for_cmd
> mmc0: starting CMD6 arg 03b70601 flags 0000049d
> mmc0: sdhci: IRQ status 0x00000001
> mmc0: sdhci: IRQ status 0x00000002
> mmc0: req done (CMD6): 0: 00000800 00000000 00000000 00000000
> __mmc_switch: mmc_poll_for_busy
> mmc_poll_for_busy: ops->card_busy
> mmc_poll_for_busy: l.513
> __mmc_switch: mmc_set_timing
> mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 8
> __mmc_switch: mmc_switch_status
> mmc0: starting CMD13 arg 00010000 flags 00000195
> mmc0: sdhci: IRQ status 0x00038000
> mmc0: req failed (CMD13): -110, retrying...
> mmc0: sdhci: IRQ status 0x00038000
> mmc0: req failed (CMD13): -110, retrying...
> mmc0: sdhci: IRQ status 0x00038000
> mmc0: req failed (CMD13): -110, retrying...
> mmc0: sdhci: IRQ status 0x00038000
> mmc0: req done (CMD13): -110: 00000000 00000000 00000000 00000000
> mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 1
> mmc0: Invalid UHS-I mode selected
> mmc0: switch to bus width 8 ddr failed
> mmc0: error -110 whilst initialising MMC card
> 
> 
> > 
> > >
> > > I continue the investigation to figure out why calling mmc_set_timing before
> > > mmc_switch_status causes an issue.
> > 
> > Great!
> > 
> > Please tell if you need some further help with some more ideas.
> 
> Ok thanks.
> 
> To compare, if I put mmc_set_timing after mmc_switch_status:

I think I have found the root cause with the help of the hardware guy
but there is still some block magic.

sdhci_set_uhs_signaling configures the host with SDHCI_CTRL_UHS_DDR50
when we need MMC_TIMING_MMC_DDR52 or MMC_TIMING_MMC_DDR52.

In my case, I have to configure another register to indicate we want to use
MMC_DDR52. It seems we are the only one to do this. I am wondering how it is
managed by other controllers.

It seems this was the root cause. If I configure the other register, it
works but I don't understand how it could work in the past.

The explanation I get from the hardware guy is that the MMC_DDR52
timings are totally different from the UHS_DDR50 ones but the MMC_HS timings
may work with the MMC_DDR52 ones.
Before the CMD13 was sent with MMC_HS timings, now with MMC_DDR52 ones.
It should explain the CMD13 issue but why next steps passed? The next CMD13 is
triggered by the mmc_switch to enable HPI and it works as we can see in
these logs:

> 
> mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 1
> mmc0: starting CMD8 arg 00000000 flags 000000b5
> mmc0:     blksz 512 blocks 1 flags 00000200 tsac 400 ms nsac 1000
> mmc0: sdhci: IRQ status 0x00000001             
> mmc0: sdhci: IRQ status 0x00000002
> mmc0: req done (CMD8): 0: 00000900 00000000 00000000 00000000
> mmc0:     512 bytes transferred: 0             
> === mmc_select_hs_ddr: l.1072 === 
> --- __mmc_switch ---                                                 
> __mmc_switch: mmc_wait_for_cmd                 
> mmc0: starting CMD6 arg 03b70601 flags 0000049d                                                   
> mmc0: sdhci: IRQ status 0x00000001                                                                      
> mmc0: sdhci: IRQ status 0x00000002             
> mmc0: req done (CMD6): 0: 00000800 00000000 00000000 00000000
> __mmc_switch: mmc_poll_for_busy                              
> mmc_poll_for_busy: ops->card_busy              
> mmc_poll_for_busy: l.513          
> __mmc_switch: mmc_switch_status
> mmc0: starting CMD13 arg 00010000 flags 00000195
> mmc0: sdhci: IRQ status 0x00000001
> mmc0: req done (CMD13): 0: 00000900 00000000 00000000 00000000
> __mmc_switch: mmc_set_timing
> mmc0: clock 52000000Hz busmode 2 powermode 2 cs 0 Vdd 21 width 8 timing 8
> --- __mmc_switch ---
> __mmc_switch: mmc_wait_for_cmd
> mmc0: starting CMD6 arg 03a10101 flags 0000049d
> mmc0: sdhci: IRQ status 0x00000001
> mmc0: sdhci: IRQ status 0x00000002
> mmc0: req done (CMD6): 0: 00000800 00000000 00000000 00000000
> __mmc_switch: mmc_poll_for_busy
> mmc_poll_for_busy: ops->card_busy
> mmc_poll_for_busy: l.513
> __mmc_switch: mmc_switch_status
> mmc0: starting CMD13 arg 00010000 flags 00000195
> mmc0: sdhci: IRQ status 0x00000001
> mmc0: req done (CMD13): 0: 00000900 00000000 00000000 00000000
> mmc0: new DDR MMC card at address 0001

Regards

Ludovic

Re: [RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Nicolas Ferre]

Le 15/03/2017 à 12:48, Nicolas Ferre a écrit :
> Le 10/03/2017 à 15:21, Ludovic Desroches a écrit :
>> From: Ludovic Desroches <ludovic.desroches@microchip.com>
>>
>> The commit e173f8911f09 mmc: core: Update CMD13 polling policy when
>> switch to HS DDR mode in addition to fix the management of CRC error,
>> changes the place where the DDR52 timing is set.
>>
>> Before this commit, the sequence was:
>> - set width to 8 with MMC_HS timing
>> - send the switch command
>> - check the status
>> - set width to 8 with MMC_DDR52 timing
>> - send the switch command
>> - check the status
>> Now:
>> - set width to 8 with MMC_HS timing
>> - send the switch command
>> - set width to 8 with MMC_DDR52 timing
>> - check the status
>>
>> It may lead to get an error when checking the status with some devices.
>>
>> Signed-off-by: Ludovic Desroches <ludovic.desroches@microchip.com>
> 
> Tested-by: Nicolas Ferre <nicolas.ferre@microchip.com>
> 
> On sama5d2 Xplained (eMMC on sdhci).
> 
> Note that without this patch the system is unable to boot. Even if it
> was present on 4.10 but we didn't spot it, I see now this as a regression.

Thorsten,

I believe that Ludovic found the root cause of this issue that we were
experiencing on our platform.

He investigated with the help of Ulf and it is now solved by his patch
"[PATCH] mmc: sdhci-of-at91: fix MMC_DDR_52 timing selection" already
integrated in Linus' tree last Friday.

As far as we are concerned, you can remove the mention of this
regression from your report
https://www.mail-archive.com/linux-kernel@vger.kernel.org/msg1368368.html

Thanks a lot for maintaining this useful tool!

Best regards,

> We would also need to add the tags:
> Cc: stable <stable@vger.kernel.org> #4.10+
> Fixes: e173f8911f09 ("mmc: core: Update CMD13 polling policy when switch
> to HS DDR mode")
> 
> 
> Best regards,
> 
>> ---
>>  drivers/mmc/core/mmc.c | 5 ++++-
>>  1 file changed, 4 insertions(+), 1 deletion(-)
>>
>> diff --git a/drivers/mmc/core/mmc.c b/drivers/mmc/core/mmc.c
>> index 0fccca0..b837148 100644
>> --- a/drivers/mmc/core/mmc.c
>> +++ b/drivers/mmc/core/mmc.c
>> @@ -1062,7 +1062,7 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>>  			   EXT_CSD_BUS_WIDTH,
>>  			   ext_csd_bits,
>>  			   card->ext_csd.generic_cmd6_time,
>> -			   MMC_TIMING_MMC_DDR52,
>> +			   0,
>>  			   true, true, true);
>>  	if (err) {
>>  		pr_err("%s: switch to bus width %d ddr failed\n",
>> @@ -1106,6 +1106,9 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>>  	if (err)
>>  		err = __mmc_set_signal_voltage(host, MMC_SIGNAL_VOLTAGE_330);
>>  
>> +	if (!err)
>> +		mmc_set_timing(host, MMC_TIMING_MMC_DDR52);
>> +
>>  	return err;
>>  }
>>  
>>
> 
> 


-- 
Nicolas Ferre

[RFC PATCH] mmc: core: HS DDR switch, don't change timing before checking status

[Nicolas Ferre]

Le 15/03/2017 ? 12:48, Nicolas Ferre a ?crit :
> Le 10/03/2017 ? 15:21, Ludovic Desroches a ?crit :
>> From: Ludovic Desroches <ludovic.desroches@microchip.com>
>>
>> The commit e173f8911f09 mmc: core: Update CMD13 polling policy when
>> switch to HS DDR mode in addition to fix the management of CRC error,
>> changes the place where the DDR52 timing is set.
>>
>> Before this commit, the sequence was:
>> - set width to 8 with MMC_HS timing
>> - send the switch command
>> - check the status
>> - set width to 8 with MMC_DDR52 timing
>> - send the switch command
>> - check the status
>> Now:
>> - set width to 8 with MMC_HS timing
>> - send the switch command
>> - set width to 8 with MMC_DDR52 timing
>> - check the status
>>
>> It may lead to get an error when checking the status with some devices.
>>
>> Signed-off-by: Ludovic Desroches <ludovic.desroches@microchip.com>
> 
> Tested-by: Nicolas Ferre <nicolas.ferre@microchip.com>
> 
> On sama5d2 Xplained (eMMC on sdhci).
> 
> Note that without this patch the system is unable to boot. Even if it
> was present on 4.10 but we didn't spot it, I see now this as a regression.

Thorsten,

I believe that Ludovic found the root cause of this issue that we were
experiencing on our platform.

He investigated with the help of Ulf and it is now solved by his patch
"[PATCH] mmc: sdhci-of-at91: fix MMC_DDR_52 timing selection" already
integrated in Linus' tree last Friday.

As far as we are concerned, you can remove the mention of this
regression from your report
https://www.mail-archive.com/linux-kernel at vger.kernel.org/msg1368368.html

Thanks a lot for maintaining this useful tool!

Best regards,

> We would also need to add the tags:
> Cc: stable <stable@vger.kernel.org> #4.10+
> Fixes: e173f8911f09 ("mmc: core: Update CMD13 polling policy when switch
> to HS DDR mode")
> 
> 
> Best regards,
> 
>> ---
>>  drivers/mmc/core/mmc.c | 5 ++++-
>>  1 file changed, 4 insertions(+), 1 deletion(-)
>>
>> diff --git a/drivers/mmc/core/mmc.c b/drivers/mmc/core/mmc.c
>> index 0fccca0..b837148 100644
>> --- a/drivers/mmc/core/mmc.c
>> +++ b/drivers/mmc/core/mmc.c
>> @@ -1062,7 +1062,7 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>>  			   EXT_CSD_BUS_WIDTH,
>>  			   ext_csd_bits,
>>  			   card->ext_csd.generic_cmd6_time,
>> -			   MMC_TIMING_MMC_DDR52,
>> +			   0,
>>  			   true, true, true);
>>  	if (err) {
>>  		pr_err("%s: switch to bus width %d ddr failed\n",
>> @@ -1106,6 +1106,9 @@ static int mmc_select_hs_ddr(struct mmc_card *card)
>>  	if (err)
>>  		err = __mmc_set_signal_voltage(host, MMC_SIGNAL_VOLTAGE_330);
>>  
>> +	if (!err)
>> +		mmc_set_timing(host, MMC_TIMING_MMC_DDR52);
>> +
>>  	return err;
>>  }
>>  
>>
> 
> 


-- 
Nicolas Ferre