diff mbox series

[1/1] mmc: sdhci: Fixed too many logs being printed during tuning

Message ID 20221111084214.14822-2-wenchao.chen666@gmail.com
State New
Headers
Series mmc: Reduce tuning log output |

Commit Message

Wenchao Chen Nov. 11, 2022, 8:42 a.m. UTC 
  From: Wenchao Chen <wenchao.chen@unisoc.com>

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

Signed-off-by: Wenchao Chen <wenchao.chen@unisoc.com>
---
 drivers/mmc/host/sdhci.c | 4 ++++
 1 file changed, 4 insertions(+)

Comments

Ulf Hansson Nov. 16, 2022, 3:20 p.m. UTC | #1 
On Fri, 11 Nov 2022 at 09:42, Wenchao Chen <wenchao.chen666@gmail.com> wrote:
>
> From: Wenchao Chen <wenchao.chen@unisoc.com>
>
> During the HS200 tuning process, too many tuning errors are printed in
> the log.
>
> Signed-off-by: Wenchao Chen <wenchao.chen@unisoc.com>
> ---
>  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
Adrian Hunter Nov. 16, 2022, 4 p.m. UTC | #2 
On 11/11/22 10:42, Wenchao Chen wrote:
> From: Wenchao Chen <wenchao.chen@unisoc.com>
> 
> During the HS200 tuning process, too many tuning errors are printed in
> the log.
> 
> Signed-off-by: Wenchao Chen <wenchao.chen@unisoc.com>
> ---
>  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);
Wenchao Chen Nov. 18, 2022, 9:22 a.m. UTC | #3 
On Wed, Nov 16, 2022 at 11:21 PM Ulf Hansson <ulf.hansson@linaro.org> wrote:
>
> On Fri, 11 Nov 2022 at 09:42, Wenchao Chen <wenchao.chen666@gmail.com> wrote:
> >
> > From: Wenchao Chen <wenchao.chen@unisoc.com>
> >
> > During the HS200 tuning process, too many tuning errors are printed in
> > the log.
> >
> > Signed-off-by: Wenchao Chen <wenchao.chen@unisoc.com>
> > ---
> >  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
Wenchao Chen Nov. 18, 2022, 9:25 a.m. UTC | #4 
On Thu, Nov 17, 2022 at 12:00 AM Adrian Hunter <adrian.hunter@intel.com> wrote:
>
> On 11/11/22 10:42, Wenchao Chen wrote:
> > From: Wenchao Chen <wenchao.chen@unisoc.com>
> >
> > During the HS200 tuning process, too many tuning errors are printed in
> > the log.
> >
> > Signed-off-by: Wenchao Chen <wenchao.chen@unisoc.com>
> > ---
> >  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);
>
Adrian Hunter Nov. 18, 2022, 3:57 p.m. UTC | #5 
On 18/11/22 11:25, Wenchao Chen wrote:
> On Thu, Nov 17, 2022 at 12:00 AM Adrian Hunter <adrian.hunter@intel.com> wrote:
>>
>> On 11/11/22 10:42, Wenchao Chen wrote:
>>> From: Wenchao Chen <wenchao.chen@unisoc.com>
>>>
>>> During the HS200 tuning process, too many tuning errors are printed in
>>> the log.
>>>
>>> Signed-off-by: Wenchao Chen <wenchao.chen@unisoc.com>
>>> ---
>>>  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);
>>
Wenchao Chen Nov. 21, 2022, 3:11 a.m. UTC | #6 
On Fri, Nov 18, 2022 at 11:57 PM Adrian Hunter <adrian.hunter@intel.com> wrote:
>
> On 18/11/22 11:25, Wenchao Chen wrote:
> > On Thu, Nov 17, 2022 at 12:00 AM Adrian Hunter <adrian.hunter@intel.com> wrote:
> >>
> >> On 11/11/22 10:42, Wenchao Chen wrote:
> >>> From: Wenchao Chen <wenchao.chen@unisoc.com>
> >>>
> >>> During the HS200 tuning process, too many tuning errors are printed in
> >>> the log.
> >>>
> >>> Signed-off-by: Wenchao Chen <wenchao.chen@unisoc.com>
> >>> ---
> >>>  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);
> >>
>
Adrian Hunter Nov. 30, 2022, 6:18 a.m. UTC | #7 
On 21/11/22 05:11, Wenchao Chen wrote:
> On Fri, Nov 18, 2022 at 11:57 PM Adrian Hunter <adrian.hunter@intel.com> wrote:
>>
>> On 18/11/22 11:25, Wenchao Chen wrote:
>>> On Thu, Nov 17, 2022 at 12:00 AM Adrian Hunter <adrian.hunter@intel.com> wrote:
>>>>
>>>> On 11/11/22 10:42, Wenchao Chen wrote:
>>>>> From: Wenchao Chen <wenchao.chen@unisoc.com>
>>>>>
>>>>> During the HS200 tuning process, too many tuning errors are printed in
>>>>> the log.
>>>>>
>>>>> Signed-off-by: Wenchao Chen <wenchao.chen@unisoc.com>
>>>>> ---
>>>>>  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);
>>>>
>>
diff mbox series

Patch

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);