2022-11-11 08:51:36

by Wenchao Chen

[permalink] [raw]
Subject: [PATCH 1/1] mmc: sdhci: Fixed too many logs being printed during tuning

From: Wenchao Chen <[email protected]>

During the HS200 tuning process, too many tuning errors are printed in
the log.

Signed-off-by: Wenchao Chen <[email protected]>
---
drivers/mmc/host/sdhci.c | 4 ++++
1 file changed, 4 insertions(+)

diff --git a/drivers/mmc/host/sdhci.c b/drivers/mmc/host/sdhci.c
index fef03de85b99..a503b54305eb 100644
--- a/drivers/mmc/host/sdhci.c
+++ b/drivers/mmc/host/sdhci.c
@@ -3401,6 +3401,10 @@ static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
if (host->pending_reset)
return;

+ command = SDHCI_GET_CMD(sdhci_readw(host, SDHCI_COMMAND));
+ if (command == MMC_SEND_TUNING_BLOCK || command == MMC_SEND_TUNING_BLOCK_HS200)
+ return;
+
pr_err("%s: Got data interrupt 0x%08x even though no data operation was in progress.\n",
mmc_hostname(host->mmc), (unsigned)intmask);
sdhci_err_stats_inc(host, UNEXPECTED_IRQ);
--
2.17.1



2022-11-16 15:32:01

by Ulf Hansson

[permalink] [raw]
Subject: Re: [PATCH 1/1] mmc: sdhci: Fixed too many logs being printed during tuning

On Fri, 11 Nov 2022 at 09:42, Wenchao Chen <[email protected]> wrote:
>
> From: Wenchao Chen <[email protected]>
>
> During the HS200 tuning process, too many tuning errors are printed in
> the log.
>
> Signed-off-by: Wenchao Chen <[email protected]>
> ---
> drivers/mmc/host/sdhci.c | 4 ++++
> 1 file changed, 4 insertions(+)
>
> diff --git a/drivers/mmc/host/sdhci.c b/drivers/mmc/host/sdhci.c
> index fef03de85b99..a503b54305eb 100644
> --- a/drivers/mmc/host/sdhci.c
> +++ b/drivers/mmc/host/sdhci.c
> @@ -3401,6 +3401,10 @@ static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
> if (host->pending_reset)
> return;
>
> + command = SDHCI_GET_CMD(sdhci_readw(host, SDHCI_COMMAND));
> + if (command == MMC_SEND_TUNING_BLOCK || command == MMC_SEND_TUNING_BLOCK_HS200)
> + return;
> +

Please use mmc_op_tuning() instead of open-coding this. I also need an
ack from Adrian to apply this.

> pr_err("%s: Got data interrupt 0x%08x even though no data operation was in progress.\n",
> mmc_hostname(host->mmc), (unsigned)intmask);
> sdhci_err_stats_inc(host, UNEXPECTED_IRQ);
> --
> 2.17.1
>

Kind regards
Uffe

2022-11-16 16:19:03

by Adrian Hunter

[permalink] [raw]
Subject: Re: [PATCH 1/1] mmc: sdhci: Fixed too many logs being printed during tuning

On 11/11/22 10:42, Wenchao Chen wrote:
> From: Wenchao Chen <[email protected]>
>
> During the HS200 tuning process, too many tuning errors are printed in
> the log.
>
> Signed-off-by: Wenchao Chen <[email protected]>
> ---
> drivers/mmc/host/sdhci.c | 4 ++++
> 1 file changed, 4 insertions(+)
>
> diff --git a/drivers/mmc/host/sdhci.c b/drivers/mmc/host/sdhci.c
> index fef03de85b99..a503b54305eb 100644
> --- a/drivers/mmc/host/sdhci.c
> +++ b/drivers/mmc/host/sdhci.c
> @@ -3401,6 +3401,10 @@ static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
> if (host->pending_reset)
> return;
>
> + command = SDHCI_GET_CMD(sdhci_readw(host, SDHCI_COMMAND));
> + if (command == MMC_SEND_TUNING_BLOCK || command == MMC_SEND_TUNING_BLOCK_HS200)
> + return;

Normally we wouldn't get here even if a request got an error because
then we either reset the data circuit which should stop further
interrupts, or set host->pending_reset.

Can you elaborate on what is going wrong?

> +
> pr_err("%s: Got data interrupt 0x%08x even though no data operation was in progress.\n",
> mmc_hostname(host->mmc), (unsigned)intmask);
> sdhci_err_stats_inc(host, UNEXPECTED_IRQ);


2022-11-18 09:43:11

by Wenchao Chen

[permalink] [raw]
Subject: Re: [PATCH 1/1] mmc: sdhci: Fixed too many logs being printed during tuning

On Wed, Nov 16, 2022 at 11:21 PM Ulf Hansson <[email protected]> wrote:
>
> On Fri, 11 Nov 2022 at 09:42, Wenchao Chen <[email protected]> wrote:
> >
> > From: Wenchao Chen <[email protected]>
> >
> > During the HS200 tuning process, too many tuning errors are printed in
> > the log.
> >
> > Signed-off-by: Wenchao Chen <[email protected]>
> > ---
> > drivers/mmc/host/sdhci.c | 4 ++++
> > 1 file changed, 4 insertions(+)
> >
> > diff --git a/drivers/mmc/host/sdhci.c b/drivers/mmc/host/sdhci.c
> > index fef03de85b99..a503b54305eb 100644
> > --- a/drivers/mmc/host/sdhci.c
> > +++ b/drivers/mmc/host/sdhci.c
> > @@ -3401,6 +3401,10 @@ static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
> > if (host->pending_reset)
> > return;
> >
> > + command = SDHCI_GET_CMD(sdhci_readw(host, SDHCI_COMMAND));
> > + if (command == MMC_SEND_TUNING_BLOCK || command == MMC_SEND_TUNING_BLOCK_HS200)
> > + return;
> > +
>
> Please use mmc_op_tuning() instead of open-coding this. I also need an
> ack from Adrian to apply this.

Thank you for your review, I will update the next version.

>
> > pr_err("%s: Got data interrupt 0x%08x even though no data operation was in progress.\n",
> > mmc_hostname(host->mmc), (unsigned)intmask);
> > sdhci_err_stats_inc(host, UNEXPECTED_IRQ);
> > --
> > 2.17.1
> >
>
> Kind regards
> Uffe

2022-11-18 09:58:23

by Wenchao Chen

[permalink] [raw]
Subject: Re: [PATCH 1/1] mmc: sdhci: Fixed too many logs being printed during tuning

On Thu, Nov 17, 2022 at 12:00 AM Adrian Hunter <[email protected]> wrote:
>
> On 11/11/22 10:42, Wenchao Chen wrote:
> > From: Wenchao Chen <[email protected]>
> >
> > During the HS200 tuning process, too many tuning errors are printed in
> > the log.
> >
> > Signed-off-by: Wenchao Chen <[email protected]>
> > ---
> > drivers/mmc/host/sdhci.c | 4 ++++
> > 1 file changed, 4 insertions(+)
> >
> > diff --git a/drivers/mmc/host/sdhci.c b/drivers/mmc/host/sdhci.c
> > index fef03de85b99..a503b54305eb 100644
> > --- a/drivers/mmc/host/sdhci.c
> > +++ b/drivers/mmc/host/sdhci.c
> > @@ -3401,6 +3401,10 @@ static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
> > if (host->pending_reset)
> > return;
> >
> > + command = SDHCI_GET_CMD(sdhci_readw(host, SDHCI_COMMAND));
> > + if (command == MMC_SEND_TUNING_BLOCK || command == MMC_SEND_TUNING_BLOCK_HS200)
> > + return;
>
> Normally we wouldn't get here even if a request got an error because
> then we either reset the data circuit which should stop further
> interrupts, or set host->pending_reset.
>
> Can you elaborate on what is going wrong?
>
Hi adrian
1. In the process of tuning, not all tuning values are good, some
tuning values may cause errors, and these errors print too many logs.
Of course, we reset the cmdline or dataline on error.
2. use host->pending_reset = true
static void __sdhci_finish_mrq(struct sdhci_host *host, struct mmc_request *mrq)
{
...
if (sdhci_needs_reset(host, mrq))
host->pending_reset = true;
...
}

But intmask = 0x00200000
static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
{
...
if (!host->data) {
struct mmc_command *data_cmd = host->data_cmd;

if (data_cmd && (data_cmd->flags & MMC_RSP_BUSY)) {
if (intmask & SDHCI_INT_DATA_TIMEOUT) { //#define
SDHCI_INT_DATA_TIMEOUT 0x00100000
host->data_cmd = NULL;
data_cmd->error = -ETIMEDOUT;
sdhci_err_stats_inc(host, CMD_TIMEOUT);
__sdhci_finish_mrq(host, data_cmd->mrq);//<=
return;
}
if (intmask & SDHCI_INT_DATA_END) { //#define SDHCI_INT_DATA_END 0x00000002

host->data_cmd = NULL;
/*
* Some cards handle busy-end interrupt
* before the command completed, so make
* sure we do things in the proper order.
*/
if (host->cmd == data_cmd)
return;

__sdhci_finish_mrq(host, data_cmd->mrq);//<=
return;
}
}
...
if (host->pending_reset)
return;

pr_err("%s: Got data interrupt 0x%08x even though no data operation
was in progress.\n",
mmc_hostname(host->mmc), (unsigned)intmask);
sdhci_err_stats_inc(host, UNEXPECTED_IRQ);
sdhci_dumpregs(host);

return;
}
...
}

> > +
> > pr_err("%s: Got data interrupt 0x%08x even though no data operation was in progress.\n",
> > mmc_hostname(host->mmc), (unsigned)intmask);
> > sdhci_err_stats_inc(host, UNEXPECTED_IRQ);
>

2022-11-18 16:09:03

by Adrian Hunter

[permalink] [raw]
Subject: Re: [PATCH 1/1] mmc: sdhci: Fixed too many logs being printed during tuning

On 18/11/22 11:25, Wenchao Chen wrote:
> On Thu, Nov 17, 2022 at 12:00 AM Adrian Hunter <[email protected]> wrote:
>>
>> On 11/11/22 10:42, Wenchao Chen wrote:
>>> From: Wenchao Chen <[email protected]>
>>>
>>> During the HS200 tuning process, too many tuning errors are printed in
>>> the log.
>>>
>>> Signed-off-by: Wenchao Chen <[email protected]>
>>> ---
>>> drivers/mmc/host/sdhci.c | 4 ++++
>>> 1 file changed, 4 insertions(+)
>>>
>>> diff --git a/drivers/mmc/host/sdhci.c b/drivers/mmc/host/sdhci.c
>>> index fef03de85b99..a503b54305eb 100644
>>> --- a/drivers/mmc/host/sdhci.c
>>> +++ b/drivers/mmc/host/sdhci.c
>>> @@ -3401,6 +3401,10 @@ static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
>>> if (host->pending_reset)
>>> return;
>>>
>>> + command = SDHCI_GET_CMD(sdhci_readw(host, SDHCI_COMMAND));
>>> + if (command == MMC_SEND_TUNING_BLOCK || command == MMC_SEND_TUNING_BLOCK_HS200)
>>> + return;
>>
>> Normally we wouldn't get here even if a request got an error because
>> then we either reset the data circuit which should stop further
>> interrupts, or set host->pending_reset.
>>
>> Can you elaborate on what is going wrong?
>>
> Hi adrian
> 1. In the process of tuning, not all tuning values are good, some
> tuning values may cause errors, and these errors print too many logs.
> Of course, we reset the cmdline or dataline on error.
> 2. use host->pending_reset = true
> static void __sdhci_finish_mrq(struct sdhci_host *host, struct mmc_request *mrq)
> {
> ...
> if (sdhci_needs_reset(host, mrq))
> host->pending_reset = true;
> ...
> }
>
> But intmask = 0x00200000
> static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
> {
> ...
> if (!host->data) {
> struct mmc_command *data_cmd = host->data_cmd;
>
> if (data_cmd && (data_cmd->flags & MMC_RSP_BUSY)) {
> if (intmask & SDHCI_INT_DATA_TIMEOUT) { //#define
> SDHCI_INT_DATA_TIMEOUT 0x00100000
> host->data_cmd = NULL;
> data_cmd->error = -ETIMEDOUT;
> sdhci_err_stats_inc(host, CMD_TIMEOUT);
> __sdhci_finish_mrq(host, data_cmd->mrq);//<=
> return;
> }
> if (intmask & SDHCI_INT_DATA_END) { //#define SDHCI_INT_DATA_END 0x00000002
>
> host->data_cmd = NULL;
> /*
> * Some cards handle busy-end interrupt
> * before the command completed, so make
> * sure we do things in the proper order.
> */
> if (host->cmd == data_cmd)
> return;
>
> __sdhci_finish_mrq(host, data_cmd->mrq);//<=
> return;
> }
> }
> ...
> if (host->pending_reset)
> return;
>
> pr_err("%s: Got data interrupt 0x%08x even though no data operation
> was in progress.\n",
> mmc_hostname(host->mmc), (unsigned)intmask);
> sdhci_err_stats_inc(host, UNEXPECTED_IRQ);
> sdhci_dumpregs(host);
>
> return;
> }
> ...
> }

Not really following that I'm sorry.

Are you saying you get a data interrupt after he data circuit is reset?

>
>>> +
>>> pr_err("%s: Got data interrupt 0x%08x even though no data operation was in progress.\n",
>>> mmc_hostname(host->mmc), (unsigned)intmask);
>>> sdhci_err_stats_inc(host, UNEXPECTED_IRQ);
>>


2022-11-21 04:19:38

by Wenchao Chen

[permalink] [raw]
Subject: Re: [PATCH 1/1] mmc: sdhci: Fixed too many logs being printed during tuning

On Fri, Nov 18, 2022 at 11:57 PM Adrian Hunter <[email protected]> wrote:
>
> On 18/11/22 11:25, Wenchao Chen wrote:
> > On Thu, Nov 17, 2022 at 12:00 AM Adrian Hunter <[email protected]> wrote:
> >>
> >> On 11/11/22 10:42, Wenchao Chen wrote:
> >>> From: Wenchao Chen <[email protected]>
> >>>
> >>> During the HS200 tuning process, too many tuning errors are printed in
> >>> the log.
> >>>
> >>> Signed-off-by: Wenchao Chen <[email protected]>
> >>> ---
> >>> drivers/mmc/host/sdhci.c | 4 ++++
> >>> 1 file changed, 4 insertions(+)
> >>>
> >>> diff --git a/drivers/mmc/host/sdhci.c b/drivers/mmc/host/sdhci.c
> >>> index fef03de85b99..a503b54305eb 100644
> >>> --- a/drivers/mmc/host/sdhci.c
> >>> +++ b/drivers/mmc/host/sdhci.c
> >>> @@ -3401,6 +3401,10 @@ static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
> >>> if (host->pending_reset)
> >>> return;
> >>>
> >>> + command = SDHCI_GET_CMD(sdhci_readw(host, SDHCI_COMMAND));
> >>> + if (command == MMC_SEND_TUNING_BLOCK || command == MMC_SEND_TUNING_BLOCK_HS200)
> >>> + return;
> >>
> >> Normally we wouldn't get here even if a request got an error because
> >> then we either reset the data circuit which should stop further
> >> interrupts, or set host->pending_reset.
> >>
> >> Can you elaborate on what is going wrong?
> >>
> > Hi adrian
> > 1. In the process of tuning, not all tuning values are good, some
> > tuning values may cause errors, and these errors print too many logs.
> > Of course, we reset the cmdline or dataline on error.
> > 2. use host->pending_reset = true
> > static void __sdhci_finish_mrq(struct sdhci_host *host, struct mmc_request *mrq)
> > {
> > ...
> > if (sdhci_needs_reset(host, mrq))
> > host->pending_reset = true;
> > ...
> > }
> >
> > But intmask = 0x00200000
> > static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
> > {
> > ...
> > if (!host->data) {
> > struct mmc_command *data_cmd = host->data_cmd;
> >
> > if (data_cmd && (data_cmd->flags & MMC_RSP_BUSY)) {
> > if (intmask & SDHCI_INT_DATA_TIMEOUT) { //#define
> > SDHCI_INT_DATA_TIMEOUT 0x00100000
> > host->data_cmd = NULL;
> > data_cmd->error = -ETIMEDOUT;
> > sdhci_err_stats_inc(host, CMD_TIMEOUT);
> > __sdhci_finish_mrq(host, data_cmd->mrq);//<=
> > return;
> > }
> > if (intmask & SDHCI_INT_DATA_END) { //#define SDHCI_INT_DATA_END 0x00000002
> >
> > host->data_cmd = NULL;
> > /*
> > * Some cards handle busy-end interrupt
> > * before the command completed, so make
> > * sure we do things in the proper order.
> > */
> > if (host->cmd == data_cmd)
> > return;
> >
> > __sdhci_finish_mrq(host, data_cmd->mrq);//<=
> > return;
> > }
> > }
> > ...
> > if (host->pending_reset)
> > return;
> >
> > pr_err("%s: Got data interrupt 0x%08x even though no data operation
> > was in progress.\n",
> > mmc_hostname(host->mmc), (unsigned)intmask);
> > sdhci_err_stats_inc(host, UNEXPECTED_IRQ);
> > sdhci_dumpregs(host);
> >
> > return;
> > }
> > ...
> > }
>
> Not really following that I'm sorry.
>
> Are you saying you get a data interrupt after he data circuit is reset?
>

No. During the tuning process, sdhci_data_irq does not skip printing
because the interrupt state is 0x00200000 (DATA CRC ERROR).

> >
> >>> +
> >>> pr_err("%s: Got data interrupt 0x%08x even though no data operation was in progress.\n",
> >>> mmc_hostname(host->mmc), (unsigned)intmask);
> >>> sdhci_err_stats_inc(host, UNEXPECTED_IRQ);
> >>
>

2022-11-30 07:27:02

by Adrian Hunter

[permalink] [raw]
Subject: Re: [PATCH 1/1] mmc: sdhci: Fixed too many logs being printed during tuning

On 21/11/22 05:11, Wenchao Chen wrote:
> On Fri, Nov 18, 2022 at 11:57 PM Adrian Hunter <[email protected]> wrote:
>>
>> On 18/11/22 11:25, Wenchao Chen wrote:
>>> On Thu, Nov 17, 2022 at 12:00 AM Adrian Hunter <[email protected]> wrote:
>>>>
>>>> On 11/11/22 10:42, Wenchao Chen wrote:
>>>>> From: Wenchao Chen <[email protected]>
>>>>>
>>>>> During the HS200 tuning process, too many tuning errors are printed in
>>>>> the log.
>>>>>
>>>>> Signed-off-by: Wenchao Chen <[email protected]>
>>>>> ---
>>>>> drivers/mmc/host/sdhci.c | 4 ++++
>>>>> 1 file changed, 4 insertions(+)
>>>>>
>>>>> diff --git a/drivers/mmc/host/sdhci.c b/drivers/mmc/host/sdhci.c
>>>>> index fef03de85b99..a503b54305eb 100644
>>>>> --- a/drivers/mmc/host/sdhci.c
>>>>> +++ b/drivers/mmc/host/sdhci.c
>>>>> @@ -3401,6 +3401,10 @@ static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
>>>>> if (host->pending_reset)
>>>>> return;
>>>>>
>>>>> + command = SDHCI_GET_CMD(sdhci_readw(host, SDHCI_COMMAND));
>>>>> + if (command == MMC_SEND_TUNING_BLOCK || command == MMC_SEND_TUNING_BLOCK_HS200)
>>>>> + return;
>>>>
>>>> Normally we wouldn't get here even if a request got an error because
>>>> then we either reset the data circuit which should stop further
>>>> interrupts, or set host->pending_reset.
>>>>
>>>> Can you elaborate on what is going wrong?
>>>>
>>> Hi adrian
>>> 1. In the process of tuning, not all tuning values are good, some
>>> tuning values may cause errors, and these errors print too many logs.
>>> Of course, we reset the cmdline or dataline on error.
>>> 2. use host->pending_reset = true
>>> static void __sdhci_finish_mrq(struct sdhci_host *host, struct mmc_request *mrq)
>>> {
>>> ...
>>> if (sdhci_needs_reset(host, mrq))
>>> host->pending_reset = true;
>>> ...
>>> }
>>>
>>> But intmask = 0x00200000
>>> static void sdhci_data_irq(struct sdhci_host *host, u32 intmask)
>>> {
>>> ...
>>> if (!host->data) {
>>> struct mmc_command *data_cmd = host->data_cmd;
>>>
>>> if (data_cmd && (data_cmd->flags & MMC_RSP_BUSY)) {
>>> if (intmask & SDHCI_INT_DATA_TIMEOUT) { //#define
>>> SDHCI_INT_DATA_TIMEOUT 0x00100000
>>> host->data_cmd = NULL;
>>> data_cmd->error = -ETIMEDOUT;
>>> sdhci_err_stats_inc(host, CMD_TIMEOUT);
>>> __sdhci_finish_mrq(host, data_cmd->mrq);//<=
>>> return;
>>> }
>>> if (intmask & SDHCI_INT_DATA_END) { //#define SDHCI_INT_DATA_END 0x00000002
>>>
>>> host->data_cmd = NULL;
>>> /*
>>> * Some cards handle busy-end interrupt
>>> * before the command completed, so make
>>> * sure we do things in the proper order.
>>> */
>>> if (host->cmd == data_cmd)
>>> return;
>>>
>>> __sdhci_finish_mrq(host, data_cmd->mrq);//<=
>>> return;
>>> }
>>> }
>>> ...
>>> if (host->pending_reset)
>>> return;
>>>
>>> pr_err("%s: Got data interrupt 0x%08x even though no data operation
>>> was in progress.\n",
>>> mmc_hostname(host->mmc), (unsigned)intmask);
>>> sdhci_err_stats_inc(host, UNEXPECTED_IRQ);
>>> sdhci_dumpregs(host);
>>>
>>> return;
>>> }
>>> ...
>>> }
>>
>> Not really following that I'm sorry.
>>
>> Are you saying you get a data interrupt after he data circuit is reset?
>>
>
> No. During the tuning process, sdhci_data_irq does not skip printing
> because the interrupt state is 0x00200000 (DATA CRC ERROR).

Sorry I am still confused. Which driver is this? I was assuming
you were using mmc_send_tuning() because the only interrupt enabled
for regular SDHCI tuning is SDHCI_INT_DATA_AVAIL (0x00000020).

So are you saying you are getting status 0x00200000 even though the
mask is 0x00000020 ?

>
>>>
>>>>> +
>>>>> pr_err("%s: Got data interrupt 0x%08x even though no data operation was in progress.\n",
>>>>> mmc_hostname(host->mmc), (unsigned)intmask);
>>>>> sdhci_err_stats_inc(host, UNEXPECTED_IRQ);
>>>>
>>