[v2] mmc: dw_mmc: Fix the DTO timeout overflow calculation for 32-bit systems

Message ID 20180222133418.29336-1-Evgeniy.Didin@synopsys.com
State New
Headers show
Series
  • [v2] mmc: dw_mmc: Fix the DTO timeout overflow calculation for 32-bit systems
Related show

Commit Message

Evgeniy Didin Feb. 22, 2018, 1:34 p.m.
In commit 9d9491a7da2a ("mmc: dw_mmc: Fix the DTO timeout calculation") have been made
changes which cause multiply overflow for 32-bit systems.
The broken timeout calculations caused false interrupt latency warnings
and stacktrace splat (such as below) when accessing the SD Card.

| Running :  4M-check-reassembly-tcp-cmykw2-rotatew2.out -v0 -w1
| -  Info: Finished target initialization.
| mmcblk0: error -110 transferring data, sector 320544, nr 2048, cmd response
|  0x900, card status 0x0
| mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 400000Hz, actual
| 396825HZ div = 63)
| mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 25000000Hz, actual
|  25000000HZ div = 1)
| ------------[ cut here ]------------
| softirq: huh, entered softirq 6 TASKLET 6f6a9412 with preempt_count 00000101,
| exited with 00000100?
| WARNING: CPU: 2 PID: 0 at ../lib/scatterlist.c:652 sg_miter_next+0x28/0x20c
| Modules linked in:
| CPU: 2 PID: 0 Comm: swapper/2 Not tainted 4.15.0 #57
|
| Stack Trace:
|  arc_unwind_core.constprop.1+0xd0/0xf4
|  dump_stack+0x68/0x80
|  warn_slowpath_null+0x4e/0xec
|  sg_miter_next+0x28/0x20c
|  dw_mci_read_data_pio+0x44/0x190
|  dw_mmc f000a000.mmc: Unexpected interrupt latency
|   dw_mci_interrupt+0x3ee/0x530
|  __handle_irq_event_percpu+0x56/0x150
|  handle_irq_event+0x34/0x78
|  handle_level_irq+0x8e/0x120
|  generic_handle_irq+0x1c/0x2c
|  idu_cascade_isr+0x30/0x6c
|  __handle_domain_irq+0x72/0xc8
|  ret_from_exception+0x0/0x8
|---[ end trace 2a58c9af6c25fe51 ]---

Lets cast this multiply to u64 type which prevents overflow.

Tested-by: Vineet Gupta <Vineet.Gupta1@synopsys.com>
Fixes: ARC STAR 9001306872 HSDK, sdio: board crashes when copying big files

Signed-off-by: Evgeniy Didin <Evgeniy.Didin@synopsys.com>

CC: Alexey Brodkin <abrodkin@synopsys.com>
CC: Eugeniy Paltsev <paltsev@synopsys.com>
CC: Douglas Anderson <dianders@chromium.org>
CC: Ulf Hansson <ulf.hansson@linaro.org>
CC: linux-kernel@vger.kernel.org
CC: linux-snps-arc@lists.infradead.org
Cc: <stable@vger.kernel.org> #  9d9491a7da2a mmc: dw_mmc: Fix the DTO timeout calculation
---
Changes since v1:
-uint64_t switched to u64
-changed commit message
 drivers/mmc/host/dw_mmc.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

Comments

Shawn Lin Feb. 22, 2018, 3:28 p.m. | #1
[+ Jaehoon]

On 2018/2/22 21:34, Evgeniy Didin wrote:
> In commit 9d9491a7da2a ("mmc: dw_mmc: Fix the DTO timeout calculation") have been made
> changes which cause multiply overflow for 32-bit systems.
> The broken timeout calculations caused false interrupt latency warnings
> and stacktrace splat (such as below) when accessing the SD Card.
> 
> | Running :  4M-check-reassembly-tcp-cmykw2-rotatew2.out -v0 -w1
> | -  Info: Finished target initialization.
> | mmcblk0: error -110 transferring data, sector 320544, nr 2048, cmd response
> |  0x900, card status 0x0
> | mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 400000Hz, actual
> | 396825HZ div = 63)
> | mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 25000000Hz, actual
> |  25000000HZ div = 1)
> | ------------[ cut here ]------------
> | softirq: huh, entered softirq 6 TASKLET 6f6a9412 with preempt_count 00000101,
> | exited with 00000100?
> | WARNING: CPU: 2 PID: 0 at ../lib/scatterlist.c:652 sg_miter_next+0x28/0x20c
> | Modules linked in:
> | CPU: 2 PID: 0 Comm: swapper/2 Not tainted 4.15.0 #57
> |
> | Stack Trace:
> |  arc_unwind_core.constprop.1+0xd0/0xf4
> |  dump_stack+0x68/0x80
> |  warn_slowpath_null+0x4e/0xec
> |  sg_miter_next+0x28/0x20c
> |  dw_mci_read_data_pio+0x44/0x190
> |  dw_mmc f000a000.mmc: Unexpected interrupt latency

I think we tested SD cards but the main reason we missed
this is that we don't use pio mode since dw_mmc decides
the transfer mode via HCON register but we don't have one
platform at hand then to do that. Given the data-transfer-over
interrupt should come after the data hit the RAM, so pio mode
could probably consume more time than IDMAC.

> |   dw_mci_interrupt+0x3ee/0x530
> |  __handle_irq_event_percpu+0x56/0x150
> |  handle_irq_event+0x34/0x78
> |  handle_level_irq+0x8e/0x120
> |  generic_handle_irq+0x1c/0x2c
> |  idu_cascade_isr+0x30/0x6c
> |  __handle_domain_irq+0x72/0xc8
> |  ret_from_exception+0x0/0x8
> |---[ end trace 2a58c9af6c25fe51 ]---
> 
> Lets cast this multiply to u64 type which prevents overflow.
> 
> Tested-by: Vineet Gupta <Vineet.Gupta1@synopsys.com>
> Fixes: ARC STAR 9001306872 HSDK, sdio: board crashes when copying big files
> 
> Signed-off-by: Evgeniy Didin <Evgeniy.Didin@synopsys.com>
> 
> CC: Alexey Brodkin <abrodkin@synopsys.com>
> CC: Eugeniy Paltsev <paltsev@synopsys.com>
> CC: Douglas Anderson <dianders@chromium.org>
> CC: Ulf Hansson <ulf.hansson@linaro.org>
> CC: linux-kernel@vger.kernel.org
> CC: linux-snps-arc@lists.infradead.org
> Cc: <stable@vger.kernel.org> #  9d9491a7da2a mmc: dw_mmc: Fix the DTO timeout calculation

The fix looks good to me, but the tags should be improved a bit:

Fixes: 9d9491a7da2a ("mmc: dw_mmc: Fix the DTO timeout calculation")
Cc: <stable@vger.kernel.org>

Otherwise,
Reviewed-by: Shawn Lin <shawn.lin@rock-chips.com>

BTW, would you mind cooking another patch for fixing cto_ms case?


> ---
> Changes since v1:
> -uint64_t switched to u64
> -changed commit message
>   drivers/mmc/host/dw_mmc.c | 2 +-
>   1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/drivers/mmc/host/dw_mmc.c b/drivers/mmc/host/dw_mmc.c
> index 0aa39975f33b..1a0b9751c67c 100644
> --- a/drivers/mmc/host/dw_mmc.c
> +++ b/drivers/mmc/host/dw_mmc.c
> @@ -1944,7 +1944,7 @@ static void dw_mci_set_drto(struct dw_mci *host)
>   	drto_div = (mci_readl(host, CLKDIV) & 0xff) * 2;
>   	if (drto_div == 0)
>   		drto_div = 1;
> -	drto_ms = DIV_ROUND_UP(MSEC_PER_SEC * drto_clks * drto_div,
> +	drto_ms = DIV_ROUND_UP((u64)MSEC_PER_SEC * drto_clks * drto_div,
>   			       host->bus_hz);
>   
>   	/* add a bit spare time */
>
Alexey Brodkin Feb. 22, 2018, 4:03 p.m. | #2
Hi Shawn,

On Thu, 2018-02-22 at 23:28 +0800, Shawn Lin wrote:

[snip]

> > > Stack Trace:
> > >  arc_unwind_core.constprop.1+0xd0/0xf4
> > >  dump_stack+0x68/0x80
> > >  warn_slowpath_null+0x4e/0xec
> > >  sg_miter_next+0x28/0x20c
> > >  dw_mci_read_data_pio+0x44/0x190
> > >  dw_mmc f000a000.mmc: Unexpected interrupt latency
> 
> I think we tested SD cards but the main reason we missed
> this is that we don't use pio mode since dw_mmc decides
> the transfer mode via HCON register but we don't have one
> platform at hand then to do that. Given the data-transfer-over
> interrupt should come after the data hit the RAM, so pio mode
> could probably consume more time than IDMAC.

That's really interesting.

I was under impression that we use internal DMA controller (AKA IDMAC)
on that platform (HSDK).

This is what we typically see in bootlog (this extract is taken from
4.15-r9):
--------------------------------->8--------------------------------
dw_mmc f000a000.mmc: 'num-slots' was deprecated.
dw_mmc f000a000.mmc: IDMAC supports 32-bit address mode.
dw_mmc f000a000.mmc: Using internal DMA controller.
dw_mmc f000a000.mmc: Version ID is 290a
dw_mmc f000a000.mmc: DW MMC controller at irq 12,32 bit host data width,16 deep fifo
--------------------------------->8--------------------------------

I'm not really sure how PIO mode (which stands for non-DMA mode) got used
given we have IDMAC in the hardware.

@ Evgeniy, could you please check why IDMAC is not used?

-Alexey
Shawn Lin Feb. 22, 2018, 4:36 p.m. | #3
On 2018/2/23 0:03, Alexey Brodkin wrote:
> Hi Shawn,
> 
> On Thu, 2018-02-22 at 23:28 +0800, Shawn Lin wrote:
> 
> [snip]
> 
>>>> Stack Trace:
>>>>   arc_unwind_core.constprop.1+0xd0/0xf4
>>>>   dump_stack+0x68/0x80
>>>>   warn_slowpath_null+0x4e/0xec
>>>>   sg_miter_next+0x28/0x20c
>>>>   dw_mci_read_data_pio+0x44/0x190
>>>>   dw_mmc f000a000.mmc: Unexpected interrupt latency
>>
>> I think we tested SD cards but the main reason we missed
>> this is that we don't use pio mode since dw_mmc decides
>> the transfer mode via HCON register but we don't have one
>> platform at hand then to do that. Given the data-transfer-over
>> interrupt should come after the data hit the RAM, so pio mode
>> could probably consume more time than IDMAC.
> 
> That's really interesting.
> 
> I was under impression that we use internal DMA controller (AKA IDMAC)
> on that platform (HSDK).
> 
> This is what we typically see in bootlog (this extract is taken from
> 4.15-r9):
> --------------------------------->8--------------------------------
> dw_mmc f000a000.mmc: 'num-slots' was deprecated.
> dw_mmc f000a000.mmc: IDMAC supports 32-bit address mode.
> dw_mmc f000a000.mmc: Using internal DMA controller.
> dw_mmc f000a000.mmc: Version ID is 290a
> dw_mmc f000a000.mmc: DW MMC controller at irq 12,32 bit host data width,16 deep fifo
> --------------------------------->8--------------------------------
> 
> I'm not really sure how PIO mode (which stands for non-DMA mode) got used
> given we have IDMAC in the hardware.

There is a DW_MCI_DMA_THRESHOLD to decides whether we use IDMA or pio
per request, since pio probably do fast than IDMA which need setup the
decriptor list if the request size is small. But that never happen for
this case as the V1 commit log said "copying file from mmc" which means
your minimal data block size is 512 anyway. So the only reasonable guess
is that just happend when initializing the card rather then copying the 
file..

> 
> @ Evgeniy, could you please check why IDMAC is not used?
> 
> -Alexey
>
Vineet Gupta Feb. 22, 2018, 5:38 p.m. | #4
On 02/22/2018 07:28 AM, Shawn Lin wrote:
>>
>> Lets cast this multiply to u64 type which prevents overflow.
>>
>> Tested-by: Vineet Gupta <Vineet.Gupta1@synopsys.com>
>> Fixes: ARC STAR 9001306872 HSDK, sdio: board crashes when copying big files
>>
>> Signed-off-by: Evgeniy Didin <Evgeniy.Didin@synopsys.com>
>>
>> CC: Alexey Brodkin <abrodkin@synopsys.com>
>> CC: Eugeniy Paltsev <paltsev@synopsys.com>
>> CC: Douglas Anderson <dianders@chromium.org>
>> CC: Ulf Hansson <ulf.hansson@linaro.org>
>> CC: linux-kernel@vger.kernel.org
>> CC: linux-snps-arc@lists.infradead.org
>> Cc: <stable@vger.kernel.org> #  9d9491a7da2a mmc: dw_mmc: Fix the DTO timeout 
>> calculation
> 
> The fix looks good to me, but the tags should be improved a bit:
> 
> Fixes: 9d9491a7da2a ("mmc: dw_mmc: Fix the DTO timeout calculation")

Ok, then perhaps use Reported-by tag to call out when/how issue was found.

Reported-by: ARC STAR 9001306872 HSDK, sdio: board crashes when copying big files

> Cc: <stable@vger.kernel.org>
> 
> Otherwise,
> Reviewed-by: Shawn Lin <shawn.lin@rock-chips.com>
Jisheng Zhang Feb. 23, 2018, 3:24 a.m. | #5
On Thu, 22 Feb 2018 16:34:18 +0300 Evgeniy Didin wrote:

> In commit 9d9491a7da2a ("mmc: dw_mmc: Fix the DTO timeout calculation") have been made
> changes which cause multiply overflow for 32-bit systems.
> The broken timeout calculations caused false interrupt latency warnings
> and stacktrace splat (such as below) when accessing the SD Card.
> 
> | Running :  4M-check-reassembly-tcp-cmykw2-rotatew2.out -v0 -w1
> | -  Info: Finished target initialization.
> | mmcblk0: error -110 transferring data, sector 320544, nr 2048, cmd response
> |  0x900, card status 0x0
> | mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 400000Hz, actual
> | 396825HZ div = 63)
> | mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 25000000Hz, actual
> |  25000000HZ div = 1)
> | ------------[ cut here ]------------
> | softirq: huh, entered softirq 6 TASKLET 6f6a9412 with preempt_count 00000101,
> | exited with 00000100?
> | WARNING: CPU: 2 PID: 0 at ../lib/scatterlist.c:652 sg_miter_next+0x28/0x20c
> | Modules linked in:
> | CPU: 2 PID: 0 Comm: swapper/2 Not tainted 4.15.0 #57
> |
> | Stack Trace:
> |  arc_unwind_core.constprop.1+0xd0/0xf4
> |  dump_stack+0x68/0x80
> |  warn_slowpath_null+0x4e/0xec
> |  sg_miter_next+0x28/0x20c
> |  dw_mci_read_data_pio+0x44/0x190
> |  dw_mmc f000a000.mmc: Unexpected interrupt latency
> |   dw_mci_interrupt+0x3ee/0x530
> |  __handle_irq_event_percpu+0x56/0x150
> |  handle_irq_event+0x34/0x78
> |  handle_level_irq+0x8e/0x120
> |  generic_handle_irq+0x1c/0x2c
> |  idu_cascade_isr+0x30/0x6c
> |  __handle_domain_irq+0x72/0xc8
> |  ret_from_exception+0x0/0x8
> |---[ end trace 2a58c9af6c25fe51 ]---
> 
> Lets cast this multiply to u64 type which prevents overflow.
> 
> Tested-by: Vineet Gupta <Vineet.Gupta1@synopsys.com>
> Fixes: ARC STAR 9001306872 HSDK, sdio: board crashes when copying big files
> 
> Signed-off-by: Evgeniy Didin <Evgeniy.Didin@synopsys.com>
> 
> CC: Alexey Brodkin <abrodkin@synopsys.com>
> CC: Eugeniy Paltsev <paltsev@synopsys.com>
> CC: Douglas Anderson <dianders@chromium.org>
> CC: Ulf Hansson <ulf.hansson@linaro.org>
> CC: linux-kernel@vger.kernel.org
> CC: linux-snps-arc@lists.infradead.org
> Cc: <stable@vger.kernel.org> #  9d9491a7da2a mmc: dw_mmc: Fix the DTO timeout calculation
> ---
> Changes since v1:
> -uint64_t switched to u64
> -changed commit message
>  drivers/mmc/host/dw_mmc.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/drivers/mmc/host/dw_mmc.c b/drivers/mmc/host/dw_mmc.c
> index 0aa39975f33b..1a0b9751c67c 100644
> --- a/drivers/mmc/host/dw_mmc.c
> +++ b/drivers/mmc/host/dw_mmc.c
> @@ -1944,7 +1944,7 @@ static void dw_mci_set_drto(struct dw_mci *host)
>  	drto_div = (mci_readl(host, CLKDIV) & 0xff) * 2;
>  	if (drto_div == 0)
>  		drto_div = 1;
> -	drto_ms = DIV_ROUND_UP(MSEC_PER_SEC * drto_clks * drto_div,
> +	drto_ms = DIV_ROUND_UP((u64)MSEC_PER_SEC * drto_clks * drto_div,
>  			       host->bus_hz);

DIV_ROUND_UP_ULL?

>  
>  	/* add a bit spare time */

Patch

diff --git a/drivers/mmc/host/dw_mmc.c b/drivers/mmc/host/dw_mmc.c
index 0aa39975f33b..1a0b9751c67c 100644
--- a/drivers/mmc/host/dw_mmc.c
+++ b/drivers/mmc/host/dw_mmc.c
@@ -1944,7 +1944,7 @@  static void dw_mci_set_drto(struct dw_mci *host)
 	drto_div = (mci_readl(host, CLKDIV) & 0xff) * 2;
 	if (drto_div == 0)
 		drto_div = 1;
-	drto_ms = DIV_ROUND_UP(MSEC_PER_SEC * drto_clks * drto_div,
+	drto_ms = DIV_ROUND_UP((u64)MSEC_PER_SEC * drto_clks * drto_div,
 			       host->bus_hz);
 
 	/* add a bit spare time */