linux-renesas-soc.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
@ 2021-05-14 15:53 Ulrich Hecht
  2021-05-19 14:25 ` Wolfram Sang
                   ` (2 more replies)
  0 siblings, 3 replies; 14+ messages in thread
From: Ulrich Hecht @ 2021-05-14 15:53 UTC (permalink / raw)
  To: linux-renesas-soc, linux-mmc; +Cc: wsa, ulf.hansson, Ulrich Hecht

The TMIO core sets a very low latency limit (100 us), but when using R-Car
SDHI hosts with SD cards, I have observed typical latencies of around 20-30
ms. This prevents runtime PM from working properly, and the devices remain
on continuously.

This patch sets the default latency limit to 100 ms to avoid that.

Signed-off-by: Ulrich Hecht <uli+renesas@fpond.eu>
---
 drivers/mmc/host/renesas_sdhi_core.c | 4 ++++
 1 file changed, 4 insertions(+)

diff --git a/drivers/mmc/host/renesas_sdhi_core.c b/drivers/mmc/host/renesas_sdhi_core.c
index 635bf31a6735..4f41616cc6bb 100644
--- a/drivers/mmc/host/renesas_sdhi_core.c
+++ b/drivers/mmc/host/renesas_sdhi_core.c
@@ -32,6 +32,7 @@
 #include <linux/pinctrl/pinctrl-state.h>
 #include <linux/platform_device.h>
 #include <linux/pm_domain.h>
+#include <linux/pm_qos.h>
 #include <linux/regulator/consumer.h>
 #include <linux/reset.h>
 #include <linux/sh_dma.h>
@@ -1147,6 +1148,9 @@ int renesas_sdhi_probe(struct platform_device *pdev,
 		host->ops.hs400_complete = renesas_sdhi_hs400_complete;
 	}
 
+	/* keep tmio_mmc_host_probe() from setting latency limit too low */
+	dev_pm_qos_expose_latency_limit(&pdev->dev, 100000);
+
 	ret = tmio_mmc_host_probe(host);
 	if (ret < 0)
 		goto edisclk;
-- 
2.20.1


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

* Re: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-05-14 15:53 [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit Ulrich Hecht
@ 2021-05-19 14:25 ` Wolfram Sang
  2021-06-02 15:40   ` Ulrich Hecht
  2021-06-30  4:44 ` Wolfram Sang
  2021-07-30 15:28 ` Wolfram Sang
  2 siblings, 1 reply; 14+ messages in thread
From: Wolfram Sang @ 2021-05-19 14:25 UTC (permalink / raw)
  To: Ulrich Hecht; +Cc: linux-renesas-soc, linux-mmc, ulf.hansson

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

Hi Uli,

On Fri, May 14, 2021 at 05:53:18PM +0200, Ulrich Hecht wrote:
> The TMIO core sets a very low latency limit (100 us), but when using R-Car
> SDHI hosts with SD cards, I have observed typical latencies of around 20-30
> ms. This prevents runtime PM from working properly, and the devices remain
> on continuously.
> 
> This patch sets the default latency limit to 100 ms to avoid that.
> 
> Signed-off-by: Ulrich Hecht <uli+renesas@fpond.eu>

Well, yes, I can confirm that this helps wrt the "always-enabled" clock.
However, when removing UHS cards, I now see this regression:

[    8.659916] mmcblk2: mmc2:0001 00000 29.8 GiB 
[    8.677304]  mmcblk2: p1
[    9.622918] mmc2: tuning execution failed: -5
[    9.627385] mmc2: card 0001 removed

It is interesting to see the "execution failed" error when *removing*
the card. Before removing, access to the card seems fine. I haven't
checked further, so I can't say yet if this is a related or seperate but
now undiscovered issue.

Thanks for the work so far!

   Wolfram

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

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

* Re: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-05-19 14:25 ` Wolfram Sang
@ 2021-06-02 15:40   ` Ulrich Hecht
  2021-06-18  8:17     ` Wolfram Sang
  0 siblings, 1 reply; 14+ messages in thread
From: Ulrich Hecht @ 2021-06-02 15:40 UTC (permalink / raw)
  To: Wolfram Sang, Ulrich Hecht; +Cc: linux-renesas-soc, linux-mmc, ulf.hansson


> On 05/19/2021 4:25 PM Wolfram Sang <wsa@kernel.org> wrote:
> On Fri, May 14, 2021 at 05:53:18PM +0200, Ulrich Hecht wrote:
> > The TMIO core sets a very low latency limit (100 us), but when using R-Car
> > SDHI hosts with SD cards, I have observed typical latencies of around 20-30
> > ms. This prevents runtime PM from working properly, and the devices remain
> > on continuously.
> > 
> > This patch sets the default latency limit to 100 ms to avoid that.
> > 
> > Signed-off-by: Ulrich Hecht <uli+renesas@fpond.eu>
> 
> Well, yes, I can confirm that this helps wrt the "always-enabled" clock.
> However, when removing UHS cards, I now see this regression:
> 
> [    8.659916] mmcblk2: mmc2:0001 00000 29.8 GiB 
> [    8.677304]  mmcblk2: p1
> [    9.622918] mmc2: tuning execution failed: -5
> [    9.627385] mmc2: card 0001 removed
> 
> It is interesting to see the "execution failed" error when *removing*
> the card. Before removing, access to the card seems fine. I haven't
> checked further, so I can't say yet if this is a related or seperate but
> now undiscovered issue.

I have traced this, and it seems to be triggered by mmc_sd_detect(), which is called by mmc_rescan() and does this:

[...]
        /*
         * Just check if our card has been removed.
         */
        err = _mmc_detect_card_removed(host);

        mmc_put_card(host->card, NULL);

        if (err) {
                mmc_sd_remove(host);
[...]

_mmc_detect_card_removed() calls mmc_sd_alive(), which tries to send a command to the SD card to see if it's still there, which in turn triggers the retune. IOW, this is expected to fail, and the error message is misleading.

CU
Uli

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

* Re: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-06-02 15:40   ` Ulrich Hecht
@ 2021-06-18  8:17     ` Wolfram Sang
  2021-06-18 10:40       ` Wolfram Sang
  0 siblings, 1 reply; 14+ messages in thread
From: Wolfram Sang @ 2021-06-18  8:17 UTC (permalink / raw)
  To: Ulrich Hecht, Yoshihiro Shimoda
  Cc: Ulrich Hecht, linux-renesas-soc, linux-mmc, ulf.hansson

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

Hi Uli,

> _mmc_detect_card_removed() calls mmc_sd_alive(), which tries to send a
> command to the SD card to see if it's still there, which in turn
> triggers the retune. IOW, this is expected to fail, and the error
> message is misleading.

This makes perfect sense to me. I disabled tuning in
_mmc_detect_card_removed() and the message is gone, of course. I'll send
a patch right away. With that sorted out, the patch works for me nicely
and we have *finally* RPM kicking in for SDHI. Looks good to me.

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

However, I'd appreciate if Shimoda-san could also test this against his
test-suite to make sure there are no other issues unearthed now that RPM
is finally suspending the device. I will also add do additional
suspend/resume tests before I say Tested-by.

Good work so far, thanks!


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

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

* Re: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-06-18  8:17     ` Wolfram Sang
@ 2021-06-18 10:40       ` Wolfram Sang
  0 siblings, 0 replies; 14+ messages in thread
From: Wolfram Sang @ 2021-06-18 10:40 UTC (permalink / raw)
  To: Ulrich Hecht, Yoshihiro Shimoda, Ulrich Hecht, linux-renesas-soc,
	linux-mmc, ulf.hansson

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


> is finally suspending the device. I will also add do additional
> suspend/resume tests before I say Tested-by.

So, I could not find a regression. I checked that RPM disables the clock
between reads and reenables them properly when needed. Also,
suspend/resume works, even when the resume happens in the middle of a
transfer. No issues with bus width etc. Looks good.

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] 14+ messages in thread

* Re: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-05-14 15:53 [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit Ulrich Hecht
  2021-05-19 14:25 ` Wolfram Sang
@ 2021-06-30  4:44 ` Wolfram Sang
  2021-07-30 15:28 ` Wolfram Sang
  2 siblings, 0 replies; 14+ messages in thread
From: Wolfram Sang @ 2021-06-30  4:44 UTC (permalink / raw)
  To: Ulrich Hecht; +Cc: linux-renesas-soc, linux-mmc, ulf.hansson

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

On Fri, May 14, 2021 at 05:53:18PM +0200, Ulrich Hecht wrote:
> The TMIO core sets a very low latency limit (100 us), but when using R-Car
> SDHI hosts with SD cards, I have observed typical latencies of around 20-30
> ms. This prevents runtime PM from working properly, and the devices remain
> on continuously.
> 
> This patch sets the default latency limit to 100 ms to avoid that.
> 
> Signed-off-by: Ulrich Hecht <uli+renesas@fpond.eu>

Ulrich is right that the tuning error is just a cosmetic problem
revealed by this patch and not really a regression. We are working on
fixing this cosmetic problem. However, this patch is good as is and we
finally have RPM working for SDHI with it. I tested RPM and
suspend/resume and all worked nicely:

Reviewed-by: Wolfram Sang <wsa+renesas@sang-engineering.com>
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] 14+ messages in thread

* Re: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-05-14 15:53 [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit Ulrich Hecht
  2021-05-19 14:25 ` Wolfram Sang
  2021-06-30  4:44 ` Wolfram Sang
@ 2021-07-30 15:28 ` Wolfram Sang
  2021-08-02  5:34   ` Yoshihiro Shimoda
  2 siblings, 1 reply; 14+ messages in thread
From: Wolfram Sang @ 2021-07-30 15:28 UTC (permalink / raw)
  To: Ulrich Hecht, Yoshihiro Shimoda; +Cc: linux-renesas-soc, linux-mmc, ulf.hansson

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

On Fri, May 14, 2021 at 05:53:18PM +0200, Ulrich Hecht wrote:
> The TMIO core sets a very low latency limit (100 us), but when using R-Car
> SDHI hosts with SD cards, I have observed typical latencies of around 20-30
> ms. This prevents runtime PM from working properly, and the devices remain
> on continuously.
> 
> This patch sets the default latency limit to 100 ms to avoid that.
> 
> Signed-off-by: Ulrich Hecht <uli+renesas@fpond.eu>

Adding Shimoda-san to CC.

Shimoda-san: can you kindly run your SDHI tests with this patch applied?
That would be very kind, thank you!

> ---
>  drivers/mmc/host/renesas_sdhi_core.c | 4 ++++
>  1 file changed, 4 insertions(+)
> 
> diff --git a/drivers/mmc/host/renesas_sdhi_core.c b/drivers/mmc/host/renesas_sdhi_core.c
> index 635bf31a6735..4f41616cc6bb 100644
> --- a/drivers/mmc/host/renesas_sdhi_core.c
> +++ b/drivers/mmc/host/renesas_sdhi_core.c
> @@ -32,6 +32,7 @@
>  #include <linux/pinctrl/pinctrl-state.h>
>  #include <linux/platform_device.h>
>  #include <linux/pm_domain.h>
> +#include <linux/pm_qos.h>
>  #include <linux/regulator/consumer.h>
>  #include <linux/reset.h>
>  #include <linux/sh_dma.h>
> @@ -1147,6 +1148,9 @@ int renesas_sdhi_probe(struct platform_device *pdev,
>  		host->ops.hs400_complete = renesas_sdhi_hs400_complete;
>  	}
>  
> +	/* keep tmio_mmc_host_probe() from setting latency limit too low */
> +	dev_pm_qos_expose_latency_limit(&pdev->dev, 100000);
> +
>  	ret = tmio_mmc_host_probe(host);
>  	if (ret < 0)
>  		goto edisclk;
> -- 
> 2.20.1
> 

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

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

* RE: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-07-30 15:28 ` Wolfram Sang
@ 2021-08-02  5:34   ` Yoshihiro Shimoda
  2021-08-02 11:18     ` Ulrich Hecht
  2021-08-02 12:53     ` Wolfram Sang
  0 siblings, 2 replies; 14+ messages in thread
From: Yoshihiro Shimoda @ 2021-08-02  5:34 UTC (permalink / raw)
  To: Wolfram Sang, Ulrich Hecht; +Cc: linux-renesas-soc, linux-mmc, ulf.hansson

Hi Wolfram-san, Ulrich-san,

> From: Wolfram Sang, Sent: Saturday, July 31, 2021 12:28 AM
> 
> On Fri, May 14, 2021 at 05:53:18PM +0200, Ulrich Hecht wrote:
> > The TMIO core sets a very low latency limit (100 us), but when using R-Car
> > SDHI hosts with SD cards, I have observed typical latencies of around 20-30
> > ms. This prevents runtime PM from working properly, and the devices remain
> > on continuously.
> >
> > This patch sets the default latency limit to 100 ms to avoid that.
> >
> > Signed-off-by: Ulrich Hecht <uli+renesas@fpond.eu>
> 
> Adding Shimoda-san to CC.
> 
> Shimoda-san: can you kindly run your SDHI tests with this patch applied?

Sure!

However, I have a question about this patch.
Would you know how to measure the latencies?
I enabled function trace of rpm and checked the log, but I could not observe
any behavior changes with and without applying this patch.

---
echo 1 > /sys/kernel/debug/tracing/events/rpm/enable
dd if=/dev/mmcblk1 of=/dev/null bs=4k count=1
cat /sys/kernel/debug/tracing/trace

# /root/trace/read.sh
# tracer: nop
#
# entries-in-buffer/entries-written: 36/36   #P:8
#
#                                _-----=> irqs-off
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| /     delay
#           TASK-PID     CPU#  ||||   TIMESTAMP  FUNCTION
#              | |         |   ||||      |         |
    kworker/4:1H-307     [004] d..1   125.845356: rpm_resume: mmc0:0001 flags-4 cnt-1  dep-0  auto-1 p-0 irq-0 child-0
    kworker/4:1H-307     [004] d..1   125.845401: rpm_resume: ee140000.mmc flags-4 cnt-1  dep-0  auto-1 p-0 irq-0 child-0
    kworker/4:1H-307     [004] d..1   125.867766: rpm_idle: ee140000.mmc flags-1 cnt-1  dep-0  auto-1 p-0 irq-0 child-0
    kworker/4:1H-307     [004] d..1   125.867774: rpm_return_int: rpm_idle+0x40/0x3d0:ee140000.mmc ret=-11
    kworker/4:1H-307     [004] d..1   125.867785: rpm_idle: soc flags-5 cnt-0  dep-1  auto-1 p-0 irq-0 child-27
    kworker/4:1H-307     [004] d..1   125.867788: rpm_return_int: rpm_idle+0x40/0x3d0:soc ret=-13
    kworker/4:1H-307     [004] d..1   125.867796: rpm_return_int: rpm_resume+0x124/0x6d8:ee140000.mmc ret=0
    kworker/4:1H-307     [004] d..1   125.867819: rpm_suspend: ee140000.mmc flags-d cnt-0  dep-0  auto-1 p-0 irq-0 child-0
    kworker/4:1H-307     [004] d..1   125.867948: rpm_return_int: rpm_suspend+0x150/0x620:ee140000.mmc ret=0
    kworker/4:1H-307     [004] d..1   125.867962: rpm_idle: mmc0:0001 flags-1 cnt-1  dep-0  auto-1 p-0 irq-0 child-0
    kworker/4:1H-307     [004] d..1   125.867965: rpm_return_int: rpm_idle+0x40/0x3d0:mmc0:0001 ret=-11
    kworker/4:1H-307     [004] d..1   125.867974: rpm_idle: mmc0 flags-5 cnt-0  dep-1  auto-1 p-0 irq-0 child-1
    kworker/4:1H-307     [004] d..1   125.867978: rpm_return_int: rpm_idle+0x40/0x3d0:mmc0 ret=-13
    kworker/4:1H-307     [004] d..1   125.867985: rpm_return_int: rpm_resume+0x124/0x6d8:mmc0:0001 ret=0
    kworker/4:1H-307     [004] d..1   125.868009: rpm_resume: ee140000.mmc flags-4 cnt-1  dep-0  auto-1 p-0 irq-0 child-0
    kworker/4:1H-307     [004] d..1   125.868013: rpm_return_int: rpm_resume+0x124/0x6d8:ee140000.mmc ret=1
    kworker/0:1H-295     [000] d..1   125.879823: rpm_suspend: ee140000.mmc flags-d cnt-0  dep-0  auto-1 p-0 irq-0 child-0
    kworker/0:1H-295     [000] d..1   125.879833: rpm_return_int: rpm_suspend+0x150/0x620:ee140000.mmc ret=0
    kworker/0:1H-295     [000] d..1   125.879843: rpm_suspend: mmc0:0001 flags-d cnt-0  dep-0  auto-1 p-0 irq-0 child-0
    kworker/0:1H-295     [000] d..1   125.879856: rpm_return_int: rpm_suspend+0x150/0x620:mmc0:0001 ret=0
    kworker/4:1H-307     [004] d..1   125.880562: rpm_resume: mmc0:0001 flags-4 cnt-1  dep-0  auto-1 p-0 irq-0 child-0
    kworker/4:1H-307     [004] d..1   125.880569: rpm_return_int: rpm_resume+0x124/0x6d8:mmc0:0001 ret=1
    kworker/4:1H-307     [004] d..1   125.880591: rpm_resume: ee140000.mmc flags-4 cnt-1  dep-0  auto-1 p-0 irq-0 child-0
    kworker/4:1H-307     [004] d..1   125.880594: rpm_return_int: rpm_resume+0x124/0x6d8:ee140000.mmc ret=1
    kworker/0:1H-295     [000] d..1   125.883242: rpm_suspend: ee140000.mmc flags-d cnt-0  dep-0  auto-1 p-0 irq-0 child-0
    kworker/0:1H-295     [000] d..1   125.883249: rpm_return_int: rpm_suspend+0x150/0x620:ee140000.mmc ret=0
    kworker/0:1H-295     [000] d..1   125.883258: rpm_suspend: mmc0:0001 flags-d cnt-0  dep-0  auto-1 p-0 irq-0 child-0
    kworker/0:1H-295     [000] d..1   125.883262: rpm_return_int: rpm_suspend+0x150/0x620:mmc0:0001 ret=0
          <idle>-0       [004] d.h2   125.928997: rpm_suspend: ee140000.mmc flags-9 cnt-0  dep-0  auto-1 p-0 irq-0 child-0
          <idle>-0       [004] d.h2   125.929015: rpm_return_int: rpm_suspend+0x150/0x620:ee140000.mmc ret=0
          <idle>-0       [004] d.h2   125.945766: rpm_suspend: ee140000.mmc flags-9 cnt-0  dep-0  auto-1 p-0 irq-0 child-0
          <idle>-0       [004] dNh2   125.945808: rpm_return_int: rpm_suspend+0x150/0x620:ee140000.mmc ret=0
     kworker/4:2-361     [004] d..1   125.945872: rpm_suspend: ee140000.mmc flags-a cnt-0  dep-0  auto-1 p-0 irq-0 child-0
     kworker/4:2-361     [004] d..1   125.945956: rpm_idle: soc flags-1 cnt-0  dep-1  auto-1 p-0 irq-0 child-26
     kworker/4:2-361     [004] d..1   125.945960: rpm_return_int: rpm_idle+0x40/0x3d0:soc ret=-13
     kworker/4:2-361     [004] d..1   125.945966: rpm_return_int: rpm_suspend+0x150/0x620:ee140000.mmc ret=0
---

Best regards,
Yoshihiro Shimoda

> That would be very kind, thank you!
> 
> > ---
> >  drivers/mmc/host/renesas_sdhi_core.c | 4 ++++
> >  1 file changed, 4 insertions(+)
> >
> > diff --git a/drivers/mmc/host/renesas_sdhi_core.c b/drivers/mmc/host/renesas_sdhi_core.c
> > index 635bf31a6735..4f41616cc6bb 100644
> > --- a/drivers/mmc/host/renesas_sdhi_core.c
> > +++ b/drivers/mmc/host/renesas_sdhi_core.c
> > @@ -32,6 +32,7 @@
> >  #include <linux/pinctrl/pinctrl-state.h>
> >  #include <linux/platform_device.h>
> >  #include <linux/pm_domain.h>
> > +#include <linux/pm_qos.h>
> >  #include <linux/regulator/consumer.h>
> >  #include <linux/reset.h>
> >  #include <linux/sh_dma.h>
> > @@ -1147,6 +1148,9 @@ int renesas_sdhi_probe(struct platform_device *pdev,
> >  		host->ops.hs400_complete = renesas_sdhi_hs400_complete;
> >  	}
> >
> > +	/* keep tmio_mmc_host_probe() from setting latency limit too low */
> > +	dev_pm_qos_expose_latency_limit(&pdev->dev, 100000);
> > +
> >  	ret = tmio_mmc_host_probe(host);
> >  	if (ret < 0)
> >  		goto edisclk;
> > --
> > 2.20.1
> >

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

* RE: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-08-02  5:34   ` Yoshihiro Shimoda
@ 2021-08-02 11:18     ` Ulrich Hecht
  2021-08-03 11:16       ` Yoshihiro Shimoda
  2021-08-02 12:53     ` Wolfram Sang
  1 sibling, 1 reply; 14+ messages in thread
From: Ulrich Hecht @ 2021-08-02 11:18 UTC (permalink / raw)
  To: Yoshihiro Shimoda, Wolfram Sang; +Cc: linux-renesas-soc, linux-mmc, ulf.hansson


> On 08/02/2021 7:34 AM Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com> wrote:
> 
>  
> Hi Wolfram-san, Ulrich-san,
> 
> > From: Wolfram Sang, Sent: Saturday, July 31, 2021 12:28 AM
> > 
> > On Fri, May 14, 2021 at 05:53:18PM +0200, Ulrich Hecht wrote:
> > > The TMIO core sets a very low latency limit (100 us), but when using R-Car
> > > SDHI hosts with SD cards, I have observed typical latencies of around 20-30
> > > ms. This prevents runtime PM from working properly, and the devices remain
> > > on continuously.
> > >
> > > This patch sets the default latency limit to 100 ms to avoid that.
> > >
> > > Signed-off-by: Ulrich Hecht <uli+renesas@fpond.eu>
> > 
> > Adding Shimoda-san to CC.
> > 
> > Shimoda-san: can you kindly run your SDHI tests with this patch applied?
> 
> Sure!
> 
> However, I have a question about this patch.
> Would you know how to measure the latencies?

IIRC I simply put a printk() in default_suspend_ok() that dumps td->suspend_latency_ns and td->resume_latency_ns.

> I enabled function trace of rpm and checked the log, but I could not observe
> any behavior changes with and without applying this patch.

So you are saying that for you, the clock is suspended as expected when removing the card, even without this patch?
If so, I wonder if there are variations between boards...

CU
Uli

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

* Re: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-08-02  5:34   ` Yoshihiro Shimoda
  2021-08-02 11:18     ` Ulrich Hecht
@ 2021-08-02 12:53     ` Wolfram Sang
  2021-08-03 11:16       ` Yoshihiro Shimoda
  1 sibling, 1 reply; 14+ messages in thread
From: Wolfram Sang @ 2021-08-02 12:53 UTC (permalink / raw)
  To: Yoshihiro Shimoda; +Cc: Ulrich Hecht, linux-renesas-soc, linux-mmc, ulf.hansson

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


> Would you know how to measure the latencies?

I didn't measure the latencies itself. I just checked 'clk_summary' in
debugfs and verified that finally clocks are disabled by RPM. Because
only with this patch, clk_enable-cnt goes to zero when SD card is
removed or eMMC has no activity.


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

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

* RE: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-08-02 12:53     ` Wolfram Sang
@ 2021-08-03 11:16       ` Yoshihiro Shimoda
  0 siblings, 0 replies; 14+ messages in thread
From: Yoshihiro Shimoda @ 2021-08-03 11:16 UTC (permalink / raw)
  To: Wolfram Sang; +Cc: Ulrich Hecht, linux-renesas-soc, linux-mmc, ulf.hansson

Hi Wolfram-san,

> From: Wolfram Sang, Sent: Monday, August 2, 2021 9:53 PM
> 
> > Would you know how to measure the latencies?
> 
> I didn't measure the latencies itself. I just checked 'clk_summary' in
> debugfs and verified that finally clocks are disabled by RPM. Because
> only with this patch, clk_enable-cnt goes to zero when SD card is
> removed or eMMC has no activity.

Thank you for your comment! Now I understood :)
So, I'll test this patch with my test environment tomorrow.

Best regards,
Yoshihiro Shimoda


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

* RE: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-08-02 11:18     ` Ulrich Hecht
@ 2021-08-03 11:16       ` Yoshihiro Shimoda
  2021-08-04  5:29         ` Yoshihiro Shimoda
  0 siblings, 1 reply; 14+ messages in thread
From: Yoshihiro Shimoda @ 2021-08-03 11:16 UTC (permalink / raw)
  To: Ulrich Hecht, Wolfram Sang; +Cc: linux-renesas-soc, linux-mmc, ulf.hansson

Hi Ulrich-san,

Thank you for your comments!

> From: Ulrich Hecht, Sent: Monday, August 2, 2021 8:18 PM
> 
> > On 08/02/2021 7:34 AM Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com> wrote:
> >
> >
> > Hi Wolfram-san, Ulrich-san,
> >
> > > From: Wolfram Sang, Sent: Saturday, July 31, 2021 12:28 AM
> > >
> > > On Fri, May 14, 2021 at 05:53:18PM +0200, Ulrich Hecht wrote:
> > > > The TMIO core sets a very low latency limit (100 us), but when using R-Car
> > > > SDHI hosts with SD cards, I have observed typical latencies of around 20-30
> > > > ms. This prevents runtime PM from working properly, and the devices remain
> > > > on continuously.
> > > >
> > > > This patch sets the default latency limit to 100 ms to avoid that.
> > > >
> > > > Signed-off-by: Ulrich Hecht <uli+renesas@fpond.eu>
> > >
> > > Adding Shimoda-san to CC.
> > >
> > > Shimoda-san: can you kindly run your SDHI tests with this patch applied?
> >
> > Sure!
> >
> > However, I have a question about this patch.
> > Would you know how to measure the latencies?
> 
> IIRC I simply put a printk() in default_suspend_ok() that dumps td->suspend_latency_ns and td->resume_latency_ns.

Thanks! I could get the latencies.

> > I enabled function trace of rpm and checked the log, but I could not observe
> > any behavior changes with and without applying this patch.
> 
> So you are saying that for you, the clock is suspended as expected when removing the card, even without this patch?
> If so, I wonder if there are variations between boards...

I'm sorry, I only observed the trace log.
As Wolfram-san mentioned on other email thread, I should check the clk_summary whether
the clock is enabled or not.

So, I'll test this patch with my test environment tomorrow.


> CU
> Uli

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

* RE: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-08-03 11:16       ` Yoshihiro Shimoda
@ 2021-08-04  5:29         ` Yoshihiro Shimoda
  2021-08-04 16:17           ` Ulrich Hecht
  0 siblings, 1 reply; 14+ messages in thread
From: Yoshihiro Shimoda @ 2021-08-04  5:29 UTC (permalink / raw)
  To: Ulrich Hecht, Wolfram Sang; +Cc: linux-renesas-soc, linux-mmc, ulf.hansson

Hi Ulrich-san again,

> From: Yoshihiro Shimoda, Sent: Tuesday, August 3, 2021 8:17 PM
> 
> So, I'll test this patch with my test environment tomorrow.

Unfortunately, this patch failed on mmc_test driver.
I'm not sure, but perhaps we have a potential issue on runtime PM with SDHI driver?

< My environment >
- H3 ES3.0 Salvator-XS
- kernel v5.14-rc2
- buildroot v2020.02.10

< How to test >
# mount -t debugfs none /sys/kernel/debug
# ./bind.sh mmc0:0001
# ./test.sh mmc0 mmc0;0001 38 38
# ./test.sh mmc0 mmc0;0001 38 38

CAUTION: The mmc_test driver will overwrite any data of the device..

< Results >
- When I tested on an eMMC, the issue happened.
-- But, when I tested on a sd card, the issue didn't happen.

- The mmc_test failed after test case 38.
-- After that, I could not recover the device even if I issued test case 45(Reset).
-- Once the test case 38 was OK, but after that, any test case failed.

- When I changed the latency value via sysfs as 100, the issue didn't happen.
# echo 100 > /sys/devices/platform/soc/ee140000.mmc/power/pm_qos_resume_latency_us

< Issue >
# ./test.sh mmc0 mmc0:0001 38 38
[   90.688971] mmc0: Starting tests of card mmc0:0001...
[   90.718703] mmc0: Test case 38. Write performance with non-blocking req 4k to 4MB...
[   90.762127] [mmc_test_rw_multiple] error
[   90.770964] mmc0: Result: ERROR (-84)
[   90.779551] mmc0: Tests completed.

< My scripts >
--- bind.sh ---
#!/bin/sh
if [ $# -ne 2 ]; then
	echo "[dev] [bind or unbind]"
	echo "dev list (for bind)"
	ls -la /sys/bus/mmc/drivers/mmcblk
	echo "dev list (for unbind)"
	ls -la /sys/bus/mmc/drivers/mmc_test
	exit
fi

if [ $2 = "bind" ]; then
	echo $1 > /sys/bus/mmc/drivers/mmcblk/unbind
	echo $1 > /sys/bus/mmc/drivers/mmc_test/bind
elif [ $2 = "unbind" ]; then
	echo $1 > /sys/bus/mmc/drivers/mmc_test/unbind
	echo $1 > /sys/bus/mmc/drivers/mmcblk/bind
fi
---------------

--- test.sh ---
#!/bin/sh

if [ $# -ne 4 ]; then
	echo "[dev base] [dev] [start] [end]"
	if [ $# -eq 2 ]; then
		echo "testlist"
		cat /sys/kernel/debug/$1/$2/testlist
	fi
	exit
fi

dev_base=$1
dev=$2
start=$3
end=$4

i=$start
while [ $i -le $end ] ; do
	echo $i > /sys/kernel/debug/$dev_base/$dev/test
	sleep 1
	i=`expr $i + 1`
done
---------------

Best regards,
Yoshihiro Shimoda


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

* RE: [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit
  2021-08-04  5:29         ` Yoshihiro Shimoda
@ 2021-08-04 16:17           ` Ulrich Hecht
  0 siblings, 0 replies; 14+ messages in thread
From: Ulrich Hecht @ 2021-08-04 16:17 UTC (permalink / raw)
  To: Yoshihiro Shimoda, Wolfram Sang; +Cc: linux-renesas-soc, linux-mmc, ulf.hansson


> On 08/04/2021 7:29 AM Yoshihiro Shimoda <yoshihiro.shimoda.uh@renesas.com> wrote:
> > From: Yoshihiro Shimoda, Sent: Tuesday, August 3, 2021 8:17 PM
> > 
> > So, I'll test this patch with my test environment tomorrow.
> 
> Unfortunately, this patch failed on mmc_test driver.

Confirmed on Salvator-XS M3-N. :/

> I'm not sure, but perhaps we have a potential issue on runtime PM with SDHI driver?

It sure feels like it.

CU
Uli

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

end of thread, other threads:[~2021-08-04 16:20 UTC | newest]

Thread overview: 14+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2021-05-14 15:53 [PATCH] mmc: renesas_sdhi: increase suspend/resume latency limit Ulrich Hecht
2021-05-19 14:25 ` Wolfram Sang
2021-06-02 15:40   ` Ulrich Hecht
2021-06-18  8:17     ` Wolfram Sang
2021-06-18 10:40       ` Wolfram Sang
2021-06-30  4:44 ` Wolfram Sang
2021-07-30 15:28 ` Wolfram Sang
2021-08-02  5:34   ` Yoshihiro Shimoda
2021-08-02 11:18     ` Ulrich Hecht
2021-08-03 11:16       ` Yoshihiro Shimoda
2021-08-04  5:29         ` Yoshihiro Shimoda
2021-08-04 16:17           ` Ulrich Hecht
2021-08-02 12:53     ` Wolfram Sang
2021-08-03 11:16       ` Yoshihiro Shimoda

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