linux-renesas-soc.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping
@ 2020-05-21  7:01 Yoshihiro Shimoda
  2020-05-21  7:01 ` [PATCH 1/3] mmc: tmio: core: Add end operation into tmio_mmc_dma_ops Yoshihiro Shimoda
                   ` (3 more replies)
  0 siblings, 4 replies; 13+ messages in thread
From: Yoshihiro Shimoda @ 2020-05-21  7:01 UTC (permalink / raw)
  To: ulf.hansson, wsa+renesas; +Cc: linux-mmc, linux-renesas-soc, Yoshihiro Shimoda

This patch series is based on mmc.git / next branch.

I guess we should add such a code into renesas_sdhi_sys_dmac and
uniphier-sd drivers too. But, for now, I fixed
renesas_sdhi_internal_dmac only.

Yoshihiro Shimoda (3):
  mmc: tmio: core: Add end operation into tmio_mmc_dma_ops
  mmc: renesas_sdhi_internal_dmac: clean up the code for dma complete
  mmc: renesas_sdhi_internal_dmac: Fix dma unmapping in error cases

 drivers/mmc/host/renesas_sdhi_internal_dmac.c | 28 +++++++++++++++++++++++----
 drivers/mmc/host/tmio_mmc.h                   |  3 +++
 drivers/mmc/host/tmio_mmc_core.c              |  8 ++++++++
 3 files changed, 35 insertions(+), 4 deletions(-)

-- 
2.7.4


^ permalink raw reply	[flat|nested] 13+ messages in thread

* [PATCH 1/3] mmc: tmio: core: Add end operation into tmio_mmc_dma_ops
  2020-05-21  7:01 [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping Yoshihiro Shimoda
@ 2020-05-21  7:01 ` Yoshihiro Shimoda
  2020-06-11 20:32   ` Wolfram Sang
  2020-05-21  7:01 ` [PATCH 2/3] mmc: renesas_sdhi_internal_dmac: clean up the code for dma complete Yoshihiro Shimoda
                   ` (2 subsequent siblings)
  3 siblings, 1 reply; 13+ messages in thread
From: Yoshihiro Shimoda @ 2020-05-21  7:01 UTC (permalink / raw)
  To: ulf.hansson, wsa+renesas; +Cc: linux-mmc, linux-renesas-soc, Yoshihiro Shimoda

Related drivers like renesas_sdhi_internal_dmac are possible
to lack dma unmaping in error cases (for example response timeout).

Since tmio_mmc_finish_request() will be always called in any case,
to fix the issue, add end operation into struct tmio_mmc_dma_ops and
call the operation in tmio_mmc_finish_request() to call dma_ummap API
by the related drivers correctly.

Signed-off-by: Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com>
---
 drivers/mmc/host/tmio_mmc.h      | 3 +++
 drivers/mmc/host/tmio_mmc_core.c | 8 ++++++++
 2 files changed, 11 insertions(+)

diff --git a/drivers/mmc/host/tmio_mmc.h b/drivers/mmc/host/tmio_mmc.h
index b4cf101..0a4f365 100644
--- a/drivers/mmc/host/tmio_mmc.h
+++ b/drivers/mmc/host/tmio_mmc.h
@@ -118,6 +118,9 @@ struct tmio_mmc_dma_ops {
 	void (*release)(struct tmio_mmc_host *host);
 	void (*abort)(struct tmio_mmc_host *host);
 	void (*dataend)(struct tmio_mmc_host *host);
+
+	/* optional */
+	void (*end)(struct tmio_mmc_host *host);	/* held host->lock */
 };
 
 struct tmio_mmc_host {
diff --git a/drivers/mmc/host/tmio_mmc_core.c b/drivers/mmc/host/tmio_mmc_core.c
index d7fde57..946fb01 100644
--- a/drivers/mmc/host/tmio_mmc_core.c
+++ b/drivers/mmc/host/tmio_mmc_core.c
@@ -57,6 +57,12 @@ static inline void tmio_mmc_start_dma(struct tmio_mmc_host *host,
 		host->dma_ops->start(host, data);
 }
 
+static inline void tmio_mmc_end_dma(struct tmio_mmc_host *host)
+{
+	if (host->dma_ops && host->dma_ops->end)
+		host->dma_ops->end(host);
+}
+
 static inline void tmio_mmc_enable_dma(struct tmio_mmc_host *host, bool enable)
 {
 	if (host->dma_ops)
@@ -797,6 +803,8 @@ static void tmio_mmc_finish_request(struct tmio_mmc_host *host)
 
 	spin_lock_irqsave(&host->lock, flags);
 
+	tmio_mmc_end_dma(host);
+
 	mrq = host->mrq;
 	if (IS_ERR_OR_NULL(mrq)) {
 		spin_unlock_irqrestore(&host->lock, flags);
-- 
2.7.4


^ permalink raw reply related	[flat|nested] 13+ messages in thread

* [PATCH 2/3] mmc: renesas_sdhi_internal_dmac: clean up the code for dma complete
  2020-05-21  7:01 [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping Yoshihiro Shimoda
  2020-05-21  7:01 ` [PATCH 1/3] mmc: tmio: core: Add end operation into tmio_mmc_dma_ops Yoshihiro Shimoda
@ 2020-05-21  7:01 ` Yoshihiro Shimoda
  2020-05-21  7:01 ` [PATCH 3/3] mmc: renesas_sdhi_internal_dmac: Fix dma unmapping in error cases Yoshihiro Shimoda
  2020-05-21  7:44 ` [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping Yoshihiro Shimoda
  3 siblings, 0 replies; 13+ messages in thread
From: Yoshihiro Shimoda @ 2020-05-21  7:01 UTC (permalink / raw)
  To: ulf.hansson, wsa+renesas; +Cc: linux-mmc, linux-renesas-soc, Yoshihiro Shimoda

To add end() operation in the future, clean the code of
renesas_sdhi_internal_dmac_complete_tasklet_fn(). No behavior change.

Signed-off-by: Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com>
---
 drivers/mmc/host/renesas_sdhi_internal_dmac.c | 18 +++++++++++++-----
 1 file changed, 13 insertions(+), 5 deletions(-)

diff --git a/drivers/mmc/host/renesas_sdhi_internal_dmac.c b/drivers/mmc/host/renesas_sdhi_internal_dmac.c
index 47ac53e..201b8ed 100644
--- a/drivers/mmc/host/renesas_sdhi_internal_dmac.c
+++ b/drivers/mmc/host/renesas_sdhi_internal_dmac.c
@@ -229,15 +229,12 @@ static void renesas_sdhi_internal_dmac_issue_tasklet_fn(unsigned long arg)
 					    DTRAN_CTRL_DM_START);
 }
 
-static void renesas_sdhi_internal_dmac_complete_tasklet_fn(unsigned long arg)
+static bool renesas_sdhi_internal_dmac_complete(struct tmio_mmc_host *host)
 {
-	struct tmio_mmc_host *host = (struct tmio_mmc_host *)arg;
 	enum dma_data_direction dir;
 
-	spin_lock_irq(&host->lock);
-
 	if (!host->data)
-		goto out;
+		return false;
 
 	if (host->data->flags & MMC_DATA_READ)
 		dir = DMA_FROM_DEVICE;
@@ -250,6 +247,17 @@ static void renesas_sdhi_internal_dmac_complete_tasklet_fn(unsigned long arg)
 	if (dir == DMA_FROM_DEVICE)
 		clear_bit(SDHI_INTERNAL_DMAC_RX_IN_USE, &global_flags);
 
+	return true;
+}
+
+static void renesas_sdhi_internal_dmac_complete_tasklet_fn(unsigned long arg)
+{
+	struct tmio_mmc_host *host = (struct tmio_mmc_host *)arg;
+
+	spin_lock_irq(&host->lock);
+	if (!renesas_sdhi_internal_dmac_complete(host))
+		goto out;
+
 	tmio_mmc_do_data_irq(host);
 out:
 	spin_unlock_irq(&host->lock);
-- 
2.7.4


^ permalink raw reply related	[flat|nested] 13+ messages in thread

* [PATCH 3/3] mmc: renesas_sdhi_internal_dmac: Fix dma unmapping in error cases
  2020-05-21  7:01 [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping Yoshihiro Shimoda
  2020-05-21  7:01 ` [PATCH 1/3] mmc: tmio: core: Add end operation into tmio_mmc_dma_ops Yoshihiro Shimoda
  2020-05-21  7:01 ` [PATCH 2/3] mmc: renesas_sdhi_internal_dmac: clean up the code for dma complete Yoshihiro Shimoda
@ 2020-05-21  7:01 ` Yoshihiro Shimoda
  2020-05-21  7:44 ` [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping Yoshihiro Shimoda
  3 siblings, 0 replies; 13+ messages in thread
From: Yoshihiro Shimoda @ 2020-05-21  7:01 UTC (permalink / raw)
  To: ulf.hansson, wsa+renesas; +Cc: linux-mmc, linux-renesas-soc, Yoshihiro Shimoda

If this controller doesn't issue interrupt for response of command,
this driver lacks to call dma_unmap_sg(). So, fix the issue by
using end() of struct tmio_mmc_dma_ops.

Reported-by: Takeshi Saito <takeshi.saito.xv@renesas.com>
Fixes: 2a68ea7896e3 ("mmc: renesas-sdhi: add support for R-Car Gen3 SDHI DMAC")
Signed-off-by: Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com>
---
 drivers/mmc/host/renesas_sdhi_internal_dmac.c | 12 ++++++++++++
 1 file changed, 12 insertions(+)

diff --git a/drivers/mmc/host/renesas_sdhi_internal_dmac.c b/drivers/mmc/host/renesas_sdhi_internal_dmac.c
index 201b8ed..32ab991 100644
--- a/drivers/mmc/host/renesas_sdhi_internal_dmac.c
+++ b/drivers/mmc/host/renesas_sdhi_internal_dmac.c
@@ -233,6 +233,9 @@ static bool renesas_sdhi_internal_dmac_complete(struct tmio_mmc_host *host)
 {
 	enum dma_data_direction dir;
 
+	if (!host->dma_on)
+		return false;
+
 	if (!host->data)
 		return false;
 
@@ -247,6 +250,8 @@ static bool renesas_sdhi_internal_dmac_complete(struct tmio_mmc_host *host)
 	if (dir == DMA_FROM_DEVICE)
 		clear_bit(SDHI_INTERNAL_DMAC_RX_IN_USE, &global_flags);
 
+	host->dma_on = false;
+
 	return true;
 }
 
@@ -263,6 +268,12 @@ static void renesas_sdhi_internal_dmac_complete_tasklet_fn(unsigned long arg)
 	spin_unlock_irq(&host->lock);
 }
 
+static void renesas_sdhi_internal_dmac_end_dma(struct tmio_mmc_host *host)
+{
+	if (host->data)
+		renesas_sdhi_internal_dmac_complete(host);
+}
+
 static void
 renesas_sdhi_internal_dmac_request_dma(struct tmio_mmc_host *host,
 				       struct tmio_mmc_data *pdata)
@@ -300,6 +311,7 @@ static const struct tmio_mmc_dma_ops renesas_sdhi_internal_dmac_dma_ops = {
 	.release = renesas_sdhi_internal_dmac_release_dma,
 	.abort = renesas_sdhi_internal_dmac_abort_dma,
 	.dataend = renesas_sdhi_internal_dmac_dataend_dma,
+	.end = renesas_sdhi_internal_dmac_end_dma,
 };
 
 /*
-- 
2.7.4


^ permalink raw reply related	[flat|nested] 13+ messages in thread

* RE: [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping
  2020-05-21  7:01 [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping Yoshihiro Shimoda
                   ` (2 preceding siblings ...)
  2020-05-21  7:01 ` [PATCH 3/3] mmc: renesas_sdhi_internal_dmac: Fix dma unmapping in error cases Yoshihiro Shimoda
@ 2020-05-21  7:44 ` Yoshihiro Shimoda
  2020-06-02 12:51   ` wsa+renesas
  3 siblings, 1 reply; 13+ messages in thread
From: Yoshihiro Shimoda @ 2020-05-21  7:44 UTC (permalink / raw)
  To: ulf.hansson, wsa+renesas; +Cc: linux-mmc, linux-renesas-soc

Hi again,

> From: Yoshihiro Shimoda, Sent: Thursday, May 21, 2020 4:01 PM
> To: ulf.hansson@linaro.org; wsa+renesas@sang-engineering.com
> Cc: linux-mmc@vger.kernel.org; linux-renesas-soc@vger.kernel.org; Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com>
> Subject: [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping
> 
> This patch series is based on mmc.git / next branch.

Note that this patch series is tested by using additional debug code [1],
because there is difficult to reproduce this issue. Before apply patch,
When I enabled CONFIG_DMA_API_DEBUG and CONFIG_DMA_API_DEBUG_SG,
I observed lacking dma unmapping on /sys/kernel/debug/dma-api/dump.
And then I confirmed the patch can fix the issue.

---
[1]
diff --git a/drivers/mmc/host/tmio_mmc.h b/drivers/mmc/host/tmio_mmc.h
index adc2bf7..1df00f6 100644
--- a/drivers/mmc/host/tmio_mmc.h
+++ b/drivers/mmc/host/tmio_mmc.h
@@ -192,6 +192,7 @@ struct tmio_mmc_host {
 	void (*hs400_complete)(struct tmio_mmc_host *host);
 
 	const struct tmio_mmc_dma_ops *dma_ops;
+	int debug;
 };
 
 struct tmio_mmc_host *tmio_mmc_host_alloc(struct platform_device *pdev,
diff --git a/drivers/mmc/host/tmio_mmc_core.c b/drivers/mmc/host/tmio_mmc_core.c
index 946fb01..f8fe905 100644
--- a/drivers/mmc/host/tmio_mmc_core.c
+++ b/drivers/mmc/host/tmio_mmc_core.c
@@ -552,7 +552,8 @@ static void tmio_mmc_cmd_irq(struct tmio_mmc_host *host, unsigned int stat)
 		cmd->resp[0] = cmd->resp[3];
 	}
 
-	if (stat & TMIO_STAT_CMDTIMEOUT)
+	host->debug++;
+	if (stat & TMIO_STAT_CMDTIMEOUT || !(host->debug & 0xff))
 		cmd->error = -ETIMEDOUT;
 	else if ((stat & TMIO_STAT_CRCFAIL && cmd->flags & MMC_RSP_CRC) ||
 		 stat & TMIO_STAT_STOPBIT_ERR ||


^ permalink raw reply related	[flat|nested] 13+ messages in thread

* Re: [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping
  2020-05-21  7:44 ` [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping Yoshihiro Shimoda
@ 2020-06-02 12:51   ` wsa+renesas
  2020-06-04  2:52     ` Yoshihiro Shimoda
  0 siblings, 1 reply; 13+ messages in thread
From: wsa+renesas @ 2020-06-02 12:51 UTC (permalink / raw)
  To: Yoshihiro Shimoda; +Cc: ulf.hansson, linux-mmc, linux-renesas-soc

[-- Attachment #1: Type: text/plain, Size: 1543 bytes --]

Hi Shimoda-san,

thanks for the patches and for providing a test case. I was not able to
reproduce the issue, though. I'll explain...

> Note that this patch series is tested by using additional debug code [1],
> because there is difficult to reproduce this issue. Before apply patch,
> When I enabled CONFIG_DMA_API_DEBUG and CONFIG_DMA_API_DEBUG_SG,
> I observed lacking dma unmapping on /sys/kernel/debug/dma-api/dump.
> And then I confirmed the patch can fix the issue.

So, I have this debug patch applied on top of mmc/next. I have the above
CONFIG_ symbols enabled. I have _not_ applied your three patches which
fix the issue. I mounted the eMMC and read a large file. I see the
injected timeouts happening:

[   94.079560] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   94.088668] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   94.097727] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   94.106768] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   94.115848] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   99.300589] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for hardware interrupt (CMD13)

But I do not see any output from the DMA debug system about a missing
unmapping. I expected that, though, because your fixes are not applied.
The testfile could even be correctly checksummed after reading, just
awfully slow, of course.

Am I missing something?

All the best,

   Wolfram


[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

^ permalink raw reply	[flat|nested] 13+ messages in thread

* RE: [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping
  2020-06-02 12:51   ` wsa+renesas
@ 2020-06-04  2:52     ` Yoshihiro Shimoda
  2020-07-06 13:16       ` Ulf Hansson
  0 siblings, 1 reply; 13+ messages in thread
From: Yoshihiro Shimoda @ 2020-06-04  2:52 UTC (permalink / raw)
  To: wsa+renesas; +Cc: ulf.hansson, linux-mmc, linux-renesas-soc

Hi Wolfram-san,

> From: wsa+renesas@sang-engineering.com, Sent: Tuesday, June 2, 2020 9:52 PM
> 
> Hi Shimoda-san,
> 
> thanks for the patches and for providing a test case. I was not able to
> reproduce the issue, though. I'll explain...

Thank you for trying to reproduce the issue!

> > Note that this patch series is tested by using additional debug code [1],
> > because there is difficult to reproduce this issue. Before apply patch,
> > When I enabled CONFIG_DMA_API_DEBUG and CONFIG_DMA_API_DEBUG_SG,
> > I observed lacking dma unmapping on /sys/kernel/debug/dma-api/dump.
> > And then I confirmed the patch can fix the issue.
> 
> So, I have this debug patch applied on top of mmc/next. I have the above
> CONFIG_ symbols enabled. I have _not_ applied your three patches which
> fix the issue. I mounted the eMMC and read a large file. I see the
> injected timeouts happening:
> 
> [   94.079560] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
> [   94.088668] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
> [   94.097727] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
> [   94.106768] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
> [   94.115848] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
> [   99.300589] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for hardware interrupt (CMD13)
> 
> But I do not see any output from the DMA debug system about a missing
> unmapping. I expected that, though, because your fixes are not applied.
> The testfile could even be correctly checksummed after reading, just
> awfully slow, of course.

I'm sorry, I should have shared my log. My test case is:
- Use dd command as background.
- Read /sys/kernel/debug/dma-api/dump while the dd command is running.
--> "ee140000.sd" lines are increased gradually.

---- Log ---
~ # dd if=/dev/mmcblk1 of=/dev/null bs=512k &
~ # grep sd /sys/kernel/debug/dma-api/dump
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 8274 P=736a8a000 N=736a8a D=740a4000 L=3000 DMA_FROM_DEVICE dma map error check not applicable
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 8603 P=736a51000 N=736a51 D=74337000 L=1000 DMA_FROM_DEVICE dma map error check not applicable
~ # [   56.797275] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for hardware interrupt (CMD13)
[   56.857055] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   56.866231] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   56.875330] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   56.884313] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   56.893334] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   61.917228] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for hardware interrupt (CMD13)
[   61.967599] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   61.976722] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   61.985726] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   61.994847] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   62.003772] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle

~ # 
~ # [   67.037259] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for hardware interrupt (CMD13)
[   67.098616] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   67.107610] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   67.116595] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   67.125591] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   67.134819] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle

~ # 
~ # grep sd /sys/kernel/debug/dma-api/dump
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 8274 P=736a8a000 N=736a8a D=740a4000 L=3000 DMA_FROM_DEVICE dma map error check not applicable
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 8603 P=736a51000 N=736a51 D=74337000 L=1000 DMA_FROM_DEVICE dma map error check not applicable
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 8807 P=737c2c000 N=737c2c D=744ce000 L=1000 DMA_FROM_DEVICE dma map error check not applicable
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 8993 P=736b80000 N=736b80 D=74642000 L=1000 DMA_FROM_DEVICE dma map error check not applicable
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 9251 P=73665f000 N=73665f D=74847000 L=1000 DMA_FROM_DEVICE dma map error check not applicable
~ # [   72.157278] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for hardware interrupt (CMD13)
[   72.217556] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   72.226595] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   72.235577] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   72.244558] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   72.253580] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   77.277235] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for hardware interrupt (CMD13)
[   77.339935] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   77.348953] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   77.358283] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   77.367271] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
[   77.376215] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle

~ # 
~ # grep sd /sys/kernel/debug/dma-api/dump
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 8274 P=736a8a000 N=736a8a D=740a4000 L=3000 DMA_FROM_DEVICE dma map error check not applicable
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 8603 P=736a51000 N=736a51 D=74337000 L=1000 DMA_FROM_DEVICE dma map error check not applicable
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 8807 P=737c2c000 N=737c2c D=744ce000 L=1000 DMA_FROM_DEVICE dma map error check not applicable
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 8993 P=736b80000 N=736b80 D=74642000 L=1000 DMA_FROM_DEVICE dma map error check not applicable
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 9251 P=73665f000 N=73665f D=74847000 L=1000 DMA_FROM_DEVICE dma map error check not applicable
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 9470 P=739af2000 N=739af2 D=749fc000 L=1000 DMA_FROM_DEVICE dma map error check not applicable
ee140000.sd renesas_sdhi_internal_dmac scather-gather idx 9794 P=736867000 N=736867 D=74c85000 L=1000 DMA_FROM_DEVICE dma map error check not applicable
----

Best regards,
Yoshihiro Shimoda


^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [PATCH 1/3] mmc: tmio: core: Add end operation into tmio_mmc_dma_ops
  2020-05-21  7:01 ` [PATCH 1/3] mmc: tmio: core: Add end operation into tmio_mmc_dma_ops Yoshihiro Shimoda
@ 2020-06-11 20:32   ` Wolfram Sang
  2020-06-12  4:18     ` Yoshihiro Shimoda
  0 siblings, 1 reply; 13+ messages in thread
From: Wolfram Sang @ 2020-06-11 20:32 UTC (permalink / raw)
  To: Yoshihiro Shimoda; +Cc: ulf.hansson, linux-mmc, linux-renesas-soc

[-- Attachment #1: Type: text/plain, Size: 1706 bytes --]

Hi,

On Thu, May 21, 2020 at 04:01:04PM +0900, Yoshihiro Shimoda wrote:
> Related drivers like renesas_sdhi_internal_dmac are possible
> to lack dma unmaping in error cases (for example response timeout).
> 
> Since tmio_mmc_finish_request() will be always called in any case,
> to fix the issue, add end operation into struct tmio_mmc_dma_ops and
> call the operation in tmio_mmc_finish_request() to call dma_ummap API
> by the related drivers correctly.
> 
> Signed-off-by: Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com>
> ---
>  drivers/mmc/host/tmio_mmc.h      | 3 +++
>  drivers/mmc/host/tmio_mmc_core.c | 8 ++++++++
>  2 files changed, 11 insertions(+)
> 
> diff --git a/drivers/mmc/host/tmio_mmc.h b/drivers/mmc/host/tmio_mmc.h
> index b4cf101..0a4f365 100644
> --- a/drivers/mmc/host/tmio_mmc.h
> +++ b/drivers/mmc/host/tmio_mmc.h
> @@ -118,6 +118,9 @@ struct tmio_mmc_dma_ops {
>  	void (*release)(struct tmio_mmc_host *host);
>  	void (*abort)(struct tmio_mmc_host *host);
>  	void (*dataend)(struct tmio_mmc_host *host);
> +
> +	/* optional */
> +	void (*end)(struct tmio_mmc_host *host);	/* held host->lock */

Okay, the good news is that I can reproduce the error case. I also get a
growing list in /sys/kernel/debug/dma-api/dump.

However, here, the list does not grow at the same rate as the fake
timeouts are injected. So, it doesn't look like the unmapping is missed
every time but only occasionally, so this seems like a race somewhere?

And if that is true, I wonder if we couldn't fix the current error paths
instead of adding another callback?

Or do you get a missed unmap for every timeout, Shimoda-san?

All the best,

   Wolfram


[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

^ permalink raw reply	[flat|nested] 13+ messages in thread

* RE: [PATCH 1/3] mmc: tmio: core: Add end operation into tmio_mmc_dma_ops
  2020-06-11 20:32   ` Wolfram Sang
@ 2020-06-12  4:18     ` Yoshihiro Shimoda
  0 siblings, 0 replies; 13+ messages in thread
From: Yoshihiro Shimoda @ 2020-06-12  4:18 UTC (permalink / raw)
  To: Wolfram Sang; +Cc: ulf.hansson, linux-mmc, linux-renesas-soc

Hi Wolfram-san,

> From: Wolfram Sang, Sent: Friday, June 12, 2020 5:33 AM
> 
> Hi,
> 
> On Thu, May 21, 2020 at 04:01:04PM +0900, Yoshihiro Shimoda wrote:
<snip>
> > diff --git a/drivers/mmc/host/tmio_mmc.h b/drivers/mmc/host/tmio_mmc.h
> > index b4cf101..0a4f365 100644
> > --- a/drivers/mmc/host/tmio_mmc.h
> > +++ b/drivers/mmc/host/tmio_mmc.h
> > @@ -118,6 +118,9 @@ struct tmio_mmc_dma_ops {
> >  	void (*release)(struct tmio_mmc_host *host);
> >  	void (*abort)(struct tmio_mmc_host *host);
> >  	void (*dataend)(struct tmio_mmc_host *host);
> > +
> > +	/* optional */
> > +	void (*end)(struct tmio_mmc_host *host);	/* held host->lock */
> 
> Okay, the good news is that I can reproduce the error case. I also get a
> growing list in /sys/kernel/debug/dma-api/dump.

Good news!

> However, here, the list does not grow at the same rate as the fake
> timeouts are injected. So, it doesn't look like the unmapping is missed
> every time but only occasionally, so this seems like a race somewhere?
> 
> And if that is true, I wonder if we couldn't fix the current error paths
> instead of adding another callback?
> 
> Or do you get a missed unmap for every timeout, Shimoda-san?

No, I got.
So, I investigate why, and then it found the injected timeout happened on CMD13
didn't cause a missed unmap because the command didn't map any buffer (host->dma_on == false).

JFYI, my debug patch and log messages are pasted below:

---
diff --git a/drivers/mmc/host/renesas_sdhi_core.c b/drivers/mmc/host/renesas_sdhi_core.c
index 15e21894bd44..8c306597a105 100644
--- a/drivers/mmc/host/renesas_sdhi_core.c
+++ b/drivers/mmc/host/renesas_sdhi_core.c
@@ -664,6 +664,12 @@ static int renesas_sdhi_wait_idle(struct tmio_mmc_host *host, u32 bit)
 
 	if (!timeout) {
 		dev_warn(&host->pdev->dev, "timeout waiting for SD bus idle\n");
+		dev_warn(&host->pdev->dev,
+			 "debug=%d timeout=%d no_dma=%d real=%d both=%d map=%d unmap=%d\n",
+			 host->debug, host->debug_timeout,
+			 host->debug_timeout_no_dma,
+			 host->debug_real_timeout, host->debug_both_timeout,
+			 host->debug_map, host->debug_unmap);
 		return -EBUSY;
 	}
 
diff --git a/drivers/mmc/host/renesas_sdhi_internal_dmac.c b/drivers/mmc/host/renesas_sdhi_internal_dmac.c
index 47ac53e91241..af16ff3b0868 100644
--- a/drivers/mmc/host/renesas_sdhi_internal_dmac.c
+++ b/drivers/mmc/host/renesas_sdhi_internal_dmac.c
@@ -208,6 +208,7 @@ renesas_sdhi_internal_dmac_start_dma(struct tmio_mmc_host *host,
 					    sg_dma_address(sg));
 
 	host->dma_on = true;
+	host->debug_map++;
 
 	return;
 
@@ -246,6 +247,7 @@ static void renesas_sdhi_internal_dmac_complete_tasklet_fn(unsigned long arg)
 
 	renesas_sdhi_internal_dmac_enable_dma(host, false);
 	dma_unmap_sg(&host->pdev->dev, host->sg_ptr, host->sg_len, dir);
+	host->debug_unmap++;
 
 	if (dir == DMA_FROM_DEVICE)
 		clear_bit(SDHI_INTERNAL_DMAC_RX_IN_USE, &global_flags);
diff --git a/drivers/mmc/host/tmio_mmc.h b/drivers/mmc/host/tmio_mmc.h
index b4cf10109162..ee950e453a26 100644
--- a/drivers/mmc/host/tmio_mmc.h
+++ b/drivers/mmc/host/tmio_mmc.h
@@ -189,6 +189,13 @@ struct tmio_mmc_host {
 	void (*hs400_complete)(struct tmio_mmc_host *host);
 
 	const struct tmio_mmc_dma_ops *dma_ops;
+	int debug;
+	int debug_timeout;
+	int debug_real_timeout;
+	int debug_both_timeout;
+	int debug_timeout_no_dma;
+	int debug_map;
+	int debug_unmap;
 };
 
 struct tmio_mmc_host *tmio_mmc_host_alloc(struct platform_device *pdev,
diff --git a/drivers/mmc/host/tmio_mmc_core.c b/drivers/mmc/host/tmio_mmc_core.c
index d7fde57c78c1..e5aebd44b0c7 100644
--- a/drivers/mmc/host/tmio_mmc_core.c
+++ b/drivers/mmc/host/tmio_mmc_core.c
@@ -546,8 +546,19 @@ static void tmio_mmc_cmd_irq(struct tmio_mmc_host *host, unsigned int stat)
 		cmd->resp[0] = cmd->resp[3];
 	}
 
-	if (stat & TMIO_STAT_CMDTIMEOUT)
+	host->debug++;
+	if (stat & TMIO_STAT_CMDTIMEOUT || !(host->debug & 0xff)) {
 		cmd->error = -ETIMEDOUT;
+		if (stat & TMIO_STAT_CMDTIMEOUT)
+			host->debug_real_timeout++;
+		if (!(host->debug & 0xff)) {
+			host->debug_timeout++;
+			if (!host->dma_on)
+				host->debug_timeout_no_dma++;
+		}
+		if (stat & TMIO_STAT_CMDTIMEOUT && !(host->debug & 0xff))
+			host->debug_both_timeout++;
+	}
 	else if ((stat & TMIO_STAT_CRCFAIL && cmd->flags & MMC_RSP_CRC) ||
 		 stat & TMIO_STAT_STOPBIT_ERR ||
 		 stat & TMIO_STAT_CMD_IDX_ERR)
@@ -797,6 +808,8 @@ static void tmio_mmc_finish_request(struct tmio_mmc_host *host)
 
 	spin_lock_irqsave(&host->lock, flags);
 
+	host->dma_on = false;
+
 	mrq = host->mrq;
 	if (IS_ERR_OR_NULL(mrq)) {
 		spin_unlock_irqrestore(&host->lock, flags);
-- 
2.17.1
---

~ # dmesg | grep mmc
[    3.674229] renesas_sdhi_internal_dmac ee100000.sd: mmc0 base at 0x00000000ee100000, max clock rate 200 MHz
[    3.742939] renesas_sdhi_internal_dmac ee140000.sd: mmc1 base at 0x00000000ee140000, max clock rate 200 MHz
[    3.822470] renesas_sdhi_internal_dmac ee160000.sd: mmc2 base at 0x00000000ee160000, max clock rate 200 MHz
[    3.922265] mmc1: new HS400 MMC card at address 0001
[    3.927919] mmcblk1: mmc1:0001 BGSD3R 29.1 GiB 
[    3.932705] mmcblk1boot0: mmc1:0001 BGSD3R partition 1 16.0 MiB
[    3.946713] mmcblk1boot1: mmc1:0001 BGSD3R partition 2 16.0 MiB
[    3.961567] mmcblk1rpmb: mmc1:0001 BGSD3R partition 3 4.00 MiB, chardev (243:0)
[    3.984810]  mmcblk1: p1
[    4.007834] mmc0: new ultra high speed SDR104 SDHC card at address aaaa
[    4.015030] mmcblk0: mmc0:aaaa SL32G 29.7 GiB 
[    4.051127]  mmcblk0: p1
~ # 
~ # cat /sys/kernel/debug/dma-api/dump | grep sd
~ # 
~ # dd if=/dev/mmcblk0 of=/dev/null bs=8k count=1k &
~ # [   86.183589] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   86.191318] renesas_sdhi_internal_dmac ee100000.sd: debug=256 timeout=1 no_dma=0 real=6 both=0 map=111 unmap=110
[   86.202819] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   86.210483] renesas_sdhi_internal_dmac ee100000.sd: debug=256 timeout=1 no_dma=0 real=6 both=0 map=111 unmap=110
[   86.221984] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   86.229650] renesas_sdhi_internal_dmac ee100000.sd: debug=256 timeout=1 no_dma=0 real=6 both=0 map=111 unmap=110
[   86.241237] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   86.248999] renesas_sdhi_internal_dmac ee100000.sd: debug=256 timeout=1 no_dma=0 real=6 both=0 map=111 unmap=110
[   86.260589] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   86.268274] renesas_sdhi_internal_dmac ee100000.sd: debug=256 timeout=1 no_dma=0 real=6 both=0 map=111 unmap=110
[   91.356599] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for hardware interrupt (CMD13)
[   91.482031] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   91.489717] renesas_sdhi_internal_dmac ee100000.sd: debug=768 timeout=3 no_dma=1 real=6 both=0 map=365 unmap=363
[   91.501336] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   91.509055] renesas_sdhi_internal_dmac ee100000.sd: debug=768 timeout=3 no_dma=1 real=6 both=0 map=365 unmap=363
[   91.520577] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   91.528313] renesas_sdhi_internal_dmac ee100000.sd: debug=768 timeout=3 no_dma=1 real=6 both=0 map=365 unmap=363
[   91.539817] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   91.547483] renesas_sdhi_internal_dmac ee100000.sd: debug=768 timeout=3 no_dma=1 real=6 both=0 map=365 unmap=363
[   91.559009] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   91.566686] renesas_sdhi_internal_dmac ee100000.sd: debug=768 timeout=3 no_dma=1 real=6 both=0 map=365 unmap=363
[   96.732560] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for hardware interrupt (CMD13)
[   96.803665] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   96.811419] renesas_sdhi_internal_dmac ee100000.sd: debug=1024 timeout=4 no_dma=1 real=12 both=0 map=489 unmap=486
[   96.823096] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   96.830760] renesas_sdhi_internal_dmac ee100000.sd: debug=1024 timeout=4 no_dma=1 real=12 both=0 map=489 unmap=486
[   96.842434] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   96.850097] renesas_sdhi_internal_dmac ee100000.sd: debug=1024 timeout=4 no_dma=1 real=12 both=0 map=489 unmap=486
[   96.861787] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   96.869488] renesas_sdhi_internal_dmac ee100000.sd: debug=1024 timeout=4 no_dma=1 real=12 both=0 map=489 unmap=486
[   96.881278] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[   96.888971] renesas_sdhi_internal_dmac ee100000.sd: debug=1024 timeout=4 no_dma=1 real=12 both=0 map=489 unmap=486
[  102.108592] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for hardware interrupt (CMD13)
[  102.207529] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  102.215309] renesas_sdhi_internal_dmac ee100000.sd: debug=1536 timeout=6 no_dma=2 real=12 both=0 map=744 unmap=740
[  102.226986] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  102.234652] renesas_sdhi_internal_dmac ee100000.sd: debug=1536 timeout=6 no_dma=2 real=12 both=0 map=744 unmap=740
[  102.246325] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  102.254052] renesas_sdhi_internal_dmac ee100000.sd: debug=1536 timeout=6 no_dma=2 real=12 both=0 map=744 unmap=740
[  102.265841] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  102.273508] renesas_sdhi_internal_dmac ee100000.sd: debug=1536 timeout=6 no_dma=2 real=12 both=0 map=744 unmap=740
[  102.285259] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  102.292944] renesas_sdhi_internal_dmac ee100000.sd: debug=1536 timeout=6 no_dma=2 real=12 both=0 map=744 unmap=740
--> This means:
 - injected timeout happened 6 times
 -- in this case, dma_on = false was observed 2 times.
 ---> So, leaking unmap happened 4 times.
 - The numbers of "map" and "unmap" also indicated that leaking unmap happened 4 times.

[  107.484619] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for hardware interrupt (CMD13)

1024+0 records in
1024+0 records out
8388608 bytes (8.0MB) copied, 21.460091 seconds, 381.7KB/s

[1]+  Done                       dd if=/dev/mmcblk0 of=/dev/null bs=8k count=1k
~ # 
~ # 
~ # cat /sys/kernel/debug/dma-api/dump | grep sd | wc
        4        64       612
--> DMA_API_DEBUG debugfs also had "4"

~ # 
~ # 
~ # 
~ # dd if=/dev/mmcblk0 of=/dev/null bs=8k count=1k &
~ # [  120.528606] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  120.536283] renesas_sdhi_internal_dmac ee100000.sd: debug=2048 timeout=8 no_dma=3 real=12 both=0 map=999 unmap=994
[  120.547958] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  120.555621] renesas_sdhi_internal_dmac ee100000.sd: debug=2048 timeout=8 no_dma=3 real=12 both=0 map=999 unmap=994
[  120.567294] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  120.574957] renesas_sdhi_internal_dmac ee100000.sd: debug=2048 timeout=8 no_dma=3 real=12 both=0 map=999 unmap=994
[  120.586702] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  120.594375] renesas_sdhi_internal_dmac ee100000.sd: debug=2048 timeout=8 no_dma=3 real=12 both=0 map=999 unmap=994
[  120.606101] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  120.613774] renesas_sdhi_internal_dmac ee100000.sd: debug=2048 timeout=8 no_dma=3 real=12 both=0 map=999 unmap=994
[  125.660558] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for hardware interrupt (CMD13)
[  125.743798] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  125.751549] renesas_sdhi_internal_dmac ee100000.sd: debug=2304 timeout=9 no_dma=3 real=18 both=0 map=1123 unmap=1117
[  125.763400] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  125.771067] renesas_sdhi_internal_dmac ee100000.sd: debug=2304 timeout=9 no_dma=3 real=18 both=0 map=1123 unmap=1117
[  125.782985] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  125.790658] renesas_sdhi_internal_dmac ee100000.sd: debug=2304 timeout=9 no_dma=3 real=18 both=0 map=1123 unmap=1117
[  125.802610] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  125.810278] renesas_sdhi_internal_dmac ee100000.sd: debug=2304 timeout=9 no_dma=3 real=18 both=0 map=1123 unmap=1117
[  125.822148] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  125.829825] renesas_sdhi_internal_dmac ee100000.sd: debug=2304 timeout=9 no_dma=3 real=18 both=0 map=1123 unmap=1117
[  131.036560] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for hardware interrupt (CMD13)
[  131.176918] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  131.184601] renesas_sdhi_internal_dmac ee100000.sd: debug=2816 timeout=11 no_dma=4 real=18 both=0 map=1377 unmap=1370
[  131.196557] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  131.204385] renesas_sdhi_internal_dmac ee100000.sd: debug=2816 timeout=11 no_dma=4 real=18 both=0 map=1377 unmap=1370
[  131.216491] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  131.224161] renesas_sdhi_internal_dmac ee100000.sd: debug=2816 timeout=11 no_dma=4 real=18 both=0 map=1377 unmap=1370
[  131.236096] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  131.243763] renesas_sdhi_internal_dmac ee100000.sd: debug=2816 timeout=11 no_dma=4 real=18 both=0 map=1377 unmap=1370
[  131.255738] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  131.263446] renesas_sdhi_internal_dmac ee100000.sd: debug=2816 timeout=11 no_dma=4 real=18 both=0 map=1377 unmap=1370
--> 7 times

[  136.412594] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for hardware interrupt (CMD13)
1024+0 records in
1024+0 records out
8388608 bytes (8.0MB) copied, 15.988695 seconds, 512.4KB/s

[1]+  Done                       dd if=/dev/mmcblk0 of=/dev/null bs=8k count=1k
~ # 
~ # 
~ # cat /sys/kernel/debug/dma-api/dump | grep sd | wc ^[[K
        7       112      1072
--> 7 times

~ # dd if=/dev/mmcblk0 of=/dev/null bs=8k count=1k &
~ # [  153.454690] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  153.462430] renesas_sdhi_internal_dmac ee100000.sd: debug=3328 timeout=13 no_dma=5 real=18 both=0 map=1632 unmap=1624
[  153.474369] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  153.482037] renesas_sdhi_internal_dmac ee100000.sd: debug=3328 timeout=13 no_dma=5 real=18 both=0 map=1632 unmap=1624
[  153.493970] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  153.501635] renesas_sdhi_internal_dmac ee100000.sd: debug=3328 timeout=13 no_dma=5 real=18 both=0 map=1632 unmap=1624
[  153.513586] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  153.521403] renesas_sdhi_internal_dmac ee100000.sd: debug=3328 timeout=13 no_dma=5 real=18 both=0 map=1632 unmap=1624
[  153.533388] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  153.541056] renesas_sdhi_internal_dmac ee100000.sd: debug=3328 timeout=13 no_dma=5 real=18 both=0 map=1632 unmap=1624
[  158.684563] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for hardware interrupt (CMD13)
[  158.773970] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  158.781827] renesas_sdhi_internal_dmac ee100000.sd: debug=3584 timeout=14 no_dma=5 real=24 both=0 map=1756 unmap=1747
[  158.793798] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  158.801524] renesas_sdhi_internal_dmac ee100000.sd: debug=3584 timeout=14 no_dma=5 real=24 both=0 map=1756 unmap=1747
[  158.813478] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  158.821146] renesas_sdhi_internal_dmac ee100000.sd: debug=3584 timeout=14 no_dma=5 real=24 both=0 map=1756 unmap=1747
[  158.833090] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  158.840824] renesas_sdhi_internal_dmac ee100000.sd: debug=3584 timeout=14 no_dma=5 real=24 both=0 map=1756 unmap=1747
[  158.852816] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  158.860488] renesas_sdhi_internal_dmac ee100000.sd: debug=3584 timeout=14 no_dma=5 real=24 both=0 map=1756 unmap=1747
[  164.060563] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for hardware interrupt (CMD13)
[  164.154898] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  164.162672] renesas_sdhi_internal_dmac ee100000.sd: debug=4096 timeout=16 no_dma=6 real=24 both=0 map=2010 unmap=2000
[  164.174607] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  164.182272] renesas_sdhi_internal_dmac ee100000.sd: debug=4096 timeout=16 no_dma=6 real=24 both=0 map=2010 unmap=2000
[  164.194273] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  164.201950] renesas_sdhi_internal_dmac ee100000.sd: debug=4096 timeout=16 no_dma=6 real=24 both=0 map=2010 unmap=2000
[  164.213979] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  164.221648] renesas_sdhi_internal_dmac ee100000.sd: debug=4096 timeout=16 no_dma=6 real=24 both=0 map=2010 unmap=2000
[  164.233625] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  164.241295] renesas_sdhi_internal_dmac ee100000.sd: debug=4096 timeout=16 no_dma=6 real=24 both=0 map=2010 unmap=2000
[  169.436561] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for hardware interrupt (CMD13)
[  169.502256] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  169.510040] renesas_sdhi_internal_dmac ee100000.sd: debug=4352 timeout=17 no_dma=6 real=30 both=0 map=2134 unmap=2123
[  169.521978] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  169.529645] renesas_sdhi_internal_dmac ee100000.sd: debug=4352 timeout=17 no_dma=6 real=30 both=0 map=2134 unmap=2123
[  169.541597] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  169.549352] renesas_sdhi_internal_dmac ee100000.sd: debug=4352 timeout=17 no_dma=6 real=30 both=0 map=2134 unmap=2123
[  169.561374] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  169.569137] renesas_sdhi_internal_dmac ee100000.sd: debug=4352 timeout=17 no_dma=6 real=30 both=0 map=2134 unmap=2123
[  169.581142] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for SD bus idle
[  169.588833] renesas_sdhi_internal_dmac ee100000.sd: debug=4352 timeout=17 no_dma=6 real=30 both=0 map=2134 unmap=2123
--> 11 times

[  174.812597] renesas_sdhi_internal_dmac ee100000.sd: timeout waiting for hardware interrupt (CMD13)
1024+0 records in
1024+0 records out
8388608 bytes (8.0MB) copied, 21.521918 seconds, 380.6KB/s

[1]+  Done                       dd if=/dev/mmcblk0 of=/dev/null bs=8k count=1k
~ # 
~ # cat /sys/kernel/debug/dma-api/dump | grep sd | wc
       11       176      1688
--> 11 times

Best regards,
Yoshihiro Shimoda


^ permalink raw reply related	[flat|nested] 13+ messages in thread

* Re: [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping
  2020-06-04  2:52     ` Yoshihiro Shimoda
@ 2020-07-06 13:16       ` Ulf Hansson
  2020-07-06 14:00         ` wsa+renesas
  0 siblings, 1 reply; 13+ messages in thread
From: Ulf Hansson @ 2020-07-06 13:16 UTC (permalink / raw)
  To: Yoshihiro Shimoda, wsa+renesas; +Cc: linux-mmc, linux-renesas-soc

On Thu, 4 Jun 2020 at 04:52, Yoshihiro Shimoda
<yoshihiro.shimoda.uh@renesas.com> wrote:
>
> Hi Wolfram-san,
>
> > From: wsa+renesas@sang-engineering.com, Sent: Tuesday, June 2, 2020 9:52 PM
> >
> > Hi Shimoda-san,
> >
> > thanks for the patches and for providing a test case. I was not able to
> > reproduce the issue, though. I'll explain...
>
> Thank you for trying to reproduce the issue!
>
> > > Note that this patch series is tested by using additional debug code [1],
> > > because there is difficult to reproduce this issue. Before apply patch,
> > > When I enabled CONFIG_DMA_API_DEBUG and CONFIG_DMA_API_DEBUG_SG,
> > > I observed lacking dma unmapping on /sys/kernel/debug/dma-api/dump.
> > > And then I confirmed the patch can fix the issue.
> >
> > So, I have this debug patch applied on top of mmc/next. I have the above
> > CONFIG_ symbols enabled. I have _not_ applied your three patches which
> > fix the issue. I mounted the eMMC and read a large file. I see the
> > injected timeouts happening:
> >
> > [   94.079560] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
> > [   94.088668] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
> > [   94.097727] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
> > [   94.106768] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
> > [   94.115848] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for SD bus idle
> > [   99.300589] renesas_sdhi_internal_dmac ee140000.sd: timeout waiting for hardware interrupt (CMD13)
> >
> > But I do not see any output from the DMA debug system about a missing
> > unmapping. I expected that, though, because your fixes are not applied.
> > The testfile could even be correctly checksummed after reading, just
> > awfully slow, of course.
>
> I'm sorry, I should have shared my log. My test case is:
> - Use dd command as background.
> - Read /sys/kernel/debug/dma-api/dump while the dd command is running.
> --> "ee140000.sd" lines are increased gradually.

[...]

Just wanted to check if this is ready to go or more tests are needed?

Kind regards
Uffe

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping
  2020-07-06 13:16       ` Ulf Hansson
@ 2020-07-06 14:00         ` wsa+renesas
  2020-07-06 14:49           ` Ulf Hansson
  0 siblings, 1 reply; 13+ messages in thread
From: wsa+renesas @ 2020-07-06 14:00 UTC (permalink / raw)
  To: Ulf Hansson; +Cc: Yoshihiro Shimoda, linux-mmc, linux-renesas-soc

[-- Attachment #1: Type: text/plain, Size: 370 bytes --]


> Just wanted to check if this is ready to go or more tests are needed?

From my tests, this patch series fixes the issue. I'd just like to avoid
the extra callback. However, my tries to do that failed so far. And now
I'll be away for two weeks.

Dunno, maybe we merge the series and if I come up with something else
that works, we can add it incrementally?


[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping
  2020-07-06 14:00         ` wsa+renesas
@ 2020-07-06 14:49           ` Ulf Hansson
  2020-07-06 14:51             ` wsa+renesas
  0 siblings, 1 reply; 13+ messages in thread
From: Ulf Hansson @ 2020-07-06 14:49 UTC (permalink / raw)
  To: wsa+renesas; +Cc: Yoshihiro Shimoda, linux-mmc, linux-renesas-soc

On Mon, 6 Jul 2020 at 16:00, wsa+renesas@sang-engineering.com
<wsa+renesas@sang-engineering.com> wrote:
>
>
> > Just wanted to check if this is ready to go or more tests are needed?
>
> From my tests, this patch series fixes the issue. I'd just like to avoid
> the extra callback. However, my tries to do that failed so far. And now
> I'll be away for two weeks.
>
> Dunno, maybe we merge the series and if I come up with something else
> that works, we can add it incrementally?

Sounds reasonable to me.

So, applied for next, thanks!

Kind regards
Uffe

^ permalink raw reply	[flat|nested] 13+ messages in thread

* Re: [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping
  2020-07-06 14:49           ` Ulf Hansson
@ 2020-07-06 14:51             ` wsa+renesas
  0 siblings, 0 replies; 13+ messages in thread
From: wsa+renesas @ 2020-07-06 14:51 UTC (permalink / raw)
  To: Ulf Hansson; +Cc: Yoshihiro Shimoda, linux-mmc, linux-renesas-soc

[-- Attachment #1: Type: text/plain, Size: 711 bytes --]

On Mon, Jul 06, 2020 at 04:49:20PM +0200, Ulf Hansson wrote:
> On Mon, 6 Jul 2020 at 16:00, wsa+renesas@sang-engineering.com
> <wsa+renesas@sang-engineering.com> wrote:
> >
> >
> > > Just wanted to check if this is ready to go or more tests are needed?
> >
> > From my tests, this patch series fixes the issue. I'd just like to avoid
> > the extra callback. However, my tries to do that failed so far. And now
> > I'll be away for two weeks.
> >
> > Dunno, maybe we merge the series and if I come up with something else
> > that works, we can add it incrementally?
> 
> Sounds reasonable to me.
> 
> So, applied for next, thanks!

Tested-by: Wolfram Sang <wsa+renesas@sang-engineering.com>


[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

^ permalink raw reply	[flat|nested] 13+ messages in thread

end of thread, other threads:[~2020-07-06 14:51 UTC | newest]

Thread overview: 13+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-05-21  7:01 [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping Yoshihiro Shimoda
2020-05-21  7:01 ` [PATCH 1/3] mmc: tmio: core: Add end operation into tmio_mmc_dma_ops Yoshihiro Shimoda
2020-06-11 20:32   ` Wolfram Sang
2020-06-12  4:18     ` Yoshihiro Shimoda
2020-05-21  7:01 ` [PATCH 2/3] mmc: renesas_sdhi_internal_dmac: clean up the code for dma complete Yoshihiro Shimoda
2020-05-21  7:01 ` [PATCH 3/3] mmc: renesas_sdhi_internal_dmac: Fix dma unmapping in error cases Yoshihiro Shimoda
2020-05-21  7:44 ` [PATCH 0/3] mmc: tmio and renesas_sdhi_internal_dmac: fix dma unmapping Yoshihiro Shimoda
2020-06-02 12:51   ` wsa+renesas
2020-06-04  2:52     ` Yoshihiro Shimoda
2020-07-06 13:16       ` Ulf Hansson
2020-07-06 14:00         ` wsa+renesas
2020-07-06 14:49           ` Ulf Hansson
2020-07-06 14:51             ` wsa+renesas

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).