diff mbox series

[2/2] mmc: tmio: move runtime PM enablement to the driver implementations

Message ID 20190109223452.11184-3-niklas.soderlund+renesas@ragnatech.se (mailing list archive)
State New, archived
Headers show
Series mmc: tmio: improve how runtime PM is enabled | expand

Commit Message

Niklas Söderlund Jan. 9, 2019, 10:34 p.m. UTC 
Both the Renesas and Uniphier implementations perform actions which
effects runtime PM before calling into the core tmio_mmc_probe() which
enabled runtime PM. Move pm_runtime_enable() from the core and
tmio_mmc_probe() into each drivers probe() so it can be called before
any clocks or other resources are switched on.

Reported-by: Geert Uytterhoeven <geert+renesas@glider.be>
Signed-off-by: Niklas Söderlund <niklas.soderlund+renesas@ragnatech.se>
---
 drivers/mmc/host/renesas_sdhi_core.c | 6 ++++++
 drivers/mmc/host/tmio_mmc.c          | 5 +++++
 drivers/mmc/host/tmio_mmc_core.c     | 2 --
 drivers/mmc/host/uniphier-sd.c       | 3 +++
 4 files changed, 14 insertions(+), 2 deletions(-)

Comments

Wolfram Sang Jan. 10, 2019, 10:37 a.m. UTC | #1 
On Wed, Jan 09, 2019 at 11:34:52PM +0100, Niklas Söderlund wrote:
> Both the Renesas and Uniphier implementations perform actions which
> effects runtime PM before calling into the core tmio_mmc_probe() which

affect

> enabled runtime PM. Move pm_runtime_enable() from the core and
> tmio_mmc_probe() into each drivers probe() so it can be called before

tmio_mmc_host_probe(). One more time above, too.

> any clocks or other resources are switched on.

Can you add some kerneldoc to tmio_mmc_host_probe() which describes this
new requirement of pm_runtime being enabled before calling?

Rest looks good.
Geert Uytterhoeven Jan. 10, 2019, 4:23 p.m. UTC | #2 
Hi Niklas,

On Wed, Jan 9, 2019 at 11:36 PM Niklas Söderlund
<niklas.soderlund+renesas@ragnatech.se> wrote:
> Both the Renesas and Uniphier implementations perform actions which
> effects runtime PM before calling into the core tmio_mmc_probe() which
> enabled runtime PM. Move pm_runtime_enable() from the core and
> tmio_mmc_probe() into each drivers probe() so it can be called before
> any clocks or other resources are switched on.
>
> Reported-by: Geert Uytterhoeven <geert+renesas@glider.be>
> Signed-off-by: Niklas Söderlund <niklas.soderlund+renesas@ragnatech.se>

Thanks for your patch!

/sys/kernel/debug/clk/clk_summary after boot (without your patch):

ape6evm (R-Mobile APE6):

     mmc1         0    0    0    12500000    0     0  50000
        mmcif1    0    0    0    12500000    0     0  50000
     mmc0         1    1    0   100000000    0     0  50000
        mmcif0    2    2    0   100000000    0     0  50000
     sdhi2ck      0    0    0    12500000    0     0  50000
        sdhi2     0    0    0    12500000    0     0  50000
     sdhi1ck      1    1    0    12500000    0     0  50000
        sdhi1     2    2    0    12500000    0     0  50000
     sdhi0ck      1    1    0    88888888    0     0  50000
        sdhi0     1    2    0    88888888    0     0  50000

kzm9g (SH-Mobile AG5):

     sdhi2ck      1    1    0    69333333    0     0  50000
        sdhi2     2    2    0    69333333    0     0  50000
     sdhi1ck      0    0    0    69333333    0     0  50000
        sdhi1     0    0    0    69333333    0     0  50000
     sdhi0ck      1    1    0    69333333    0     0  50000
        sdhi0     1    2    0    69333333    0     0  50000

m3-n-salvator-xs (R-Car M3-N):

    .sdsrc        3    3    0   798720000    0     0  50000
       sd3        1    1    0    12480000    0     0  50000
          sdif3   1    2    0    12480000    0     0  50000
       sd2        1    1    0   199680000    0     0  50000
          sdif2   1    2    0   199680000    0     0  50000
       sd1        0    0    0   199680000    0     0  50000
          sdif1   0    0    0   199680000    0     0  50000
       sd0        1    1    0    12480000    0     0  50000
          sdif0   1    2    0    12480000    0     0  50000


/sys/kernel/debug/clk/clk_summary after boot (with your patch):

ape6evm:

     mmc1         0    0    0    12500000    0     0  50000
        mmcif1    0    0    0    12500000    0     0  50000
     mmc0         1    1    0   100000000    0     0  50000
        mmcif0    2    2    0   100000000    0     0  50000
     sdhi2ck      0    0    0    12500000    0     0  50000
        sdhi2     0    0    0    12500000    0     0  50000
     sdhi1ck      1    1    0    12500000    0     0  50000
        sdhi1     3    3    0    12500000    0     0  50000
     sdhi0ck      1    1    0    88888888    0     0  50000
        sdhi0     3    3    0    88888888    0     0  50000

kzm9g:

     sdhi2ck      1    1    0    69333333    0     0  50000
        sdhi2     3    3    0    69333333    0     0  50000
     sdhi1ck      0    0    0    69333333    0     0  50000
        sdhi1     0    0    0    69333333    0     0  50000
     sdhi0ck      1    1    0    69333333    0     0  50000
        sdhi0     3    3    0    69333333    0     0  50000

m3-n-salvator-xs:

    .sdsrc        3    3    0   798720000    0     0  50000
       sd3        1    1    0    12480000    0     0  50000
          sdif3   3    3    0    12480000    0     0  50000
       sd2        1    1    0   199680000    0     0  50000
          sdif2   3    3    0   199680000    0     0  50000
       sd1        0    0    0   199680000    0     0  50000
          sdif1   0    0    0   199680000    0     0  50000
       sd0        1    1    0    12480000    0     0  50000
          sdif0   3    3    0    12480000    0     0  50000


Unfortunately the clock imbalance isn't gone.
After resume from s2ram (with your patch):

ape6evm:

     mmc1         0    0    0    12500000    0     0  50000
        mmcif1    0    0    0    12500000    0     0  50000
     mmc0         0    1    0   100000000    0     0  50000
        mmcif0    0    1    0   100000000    0     0  50000
     sdhi2ck      0    0    0    12500000    0     0  50000
        sdhi2     0    0    0    12500000    0     0  50000
     sdhi1ck      1    1    0    12500000    0     0  50000
        sdhi1     1    2    0    12500000    0     0  50000
     sdhi0ck      1    1    0    88888888    0     0  50000
        sdhi0     3    3    0    88888888    0     0  50000

kzm9g:

     sdhi2ck      1    1    0    69333333    0     0  50000
        sdhi2     1    2    0    69333333    0     0  50000
     sdhi1ck      0    0    0    69333333    0     0  50000
        sdhi1     0    0    0    69333333    0     0  50000
     sdhi0ck      1    1    0    69333333    0     0  50000
        sdhi0     3    3    0    69333333    0     0  50000

And my debug prints in genpd_st{art,op}_dev() still tell me the device
is cycled continuously after resume from s2ram:

ape6evm:

    [  761.928322] ==== a3sp/ee120000.sd: start
    [  762.017086] ==== a3sp/ee120000.sd: stop
    [  762.968418] ==== a3sp/ee120000.sd: start
    [  763.057139] ==== a3sp/ee120000.sd: stop
    [  764.008535] ==== a3sp/ee120000.sd: start
    [  764.097261] ==== a3sp/ee120000.sd: stop
    [  765.048621] ==== a3sp/ee120000.sd: start
    [  765.137359] ==== a3sp/ee120000.sd: stop
                   ...

kzm9g:

    [  403.676197] ==== a3sp/ee140000.sd: start
    [  403.764984] ==== a3sp/ee140000.sd: stop
    [  404.716462] ==== a3sp/ee140000.sd: start
    [  404.805208] ==== a3sp/ee140000.sd: stop
    [  405.756708] ==== a3sp/ee140000.sd: start
    [  405.836766] ==== a3sp/ee140000.sd: stop
                   ...

Further s2ram cycles make no difference, as before.

On R-Car M3-N, there is no such imbalance. This seems to happen
on older SH/R-Mobile SoCs only.

Gr{oetje,eeting}s,

                        Geert
Geert Uytterhoeven Jan. 11, 2019, 9:55 a.m. UTC | #3 
Hi Niklas,

On Thu, Jan 10, 2019 at 5:23 PM Geert Uytterhoeven <geert@linux-m68k.org> wrote:
> On Wed, Jan 9, 2019 at 11:36 PM Niklas Söderlund
> <niklas.soderlund+renesas@ragnatech.se> wrote:
> > Both the Renesas and Uniphier implementations perform actions which
> > effects runtime PM before calling into the core tmio_mmc_probe() which
> > enabled runtime PM. Move pm_runtime_enable() from the core and
> > tmio_mmc_probe() into each drivers probe() so it can be called before
> > any clocks or other resources are switched on.
> >
> > Reported-by: Geert Uytterhoeven <geert+renesas@glider.be>
> > Signed-off-by: Niklas Söderlund <niklas.soderlund+renesas@ragnatech.se>

> Unfortunately the clock imbalance isn't gone.
>
> And my debug prints in genpd_st{art,op}_dev() still tell me the device
> is cycled continuously after resume from s2ram:

> kzm9g:
>
>     [  403.676197] ==== a3sp/ee140000.sd: start
>     [  403.764984] ==== a3sp/ee140000.sd: stop
>     [  404.716462] ==== a3sp/ee140000.sd: start
>     [  404.805208] ==== a3sp/ee140000.sd: stop
>     [  405.756708] ==== a3sp/ee140000.sd: start
>     [  405.836766] ==== a3sp/ee140000.sd: stop
>                    ...
>
> Further s2ram cycles make no difference, as before.
>
> On R-Car M3-N, there is no such imbalance. This seems to happen
> on older SH/R-Mobile SoCs only.

As you don't have an ape6evm or kzm9g board, I've sprinkled a few
WARN(!strcmp(core->name, "sdhi2"), ...) in the clk_core_(un)prepare()
and clk_core_{dis,en}enable() functions on kzm9g. And guess what, the
clock imbalance is gone, just like the start/stop debug messages!

Likewise, on ape6evm the clock imbalance for sdhi1 disappears when
adding a similar WARN() for the sdhi1 clock!

The imbalance for mmcif0 is still there. If I change the WARN() to
check for mmcif0 instead of sdhi1, the imbalance for sdhi1 reappears.
Interestingly, there imbalance for mmcif0 now has a different form:

-                mmcif0                2        2        0   100000000
         0     0  50000
+                mmcif0                1        1        0   100000000
         0     0  50000

Before it was prepare_count = 0 / enable_count = 1 instead of 1/1.
I.e. the clock is prepared and enabled once less than before, due to
sh_mmcif_set_ios() not being reenabled during resume, cfr. the log below.

The biggest mystery is why adding the WARN() changes the prepare
and enable counts.
Is there a race condition? I thought the clock operations are protected
by prepare_lock and enable_lock?

/me puzzled...


mmcif0 on r8a73a4 boot:

    WARNING: CPU: 0 PID: 1 at drivers/clk/clk.c:768 clk_core_prepare+0x94/0x388
    clk_core_prepare: prepare_count++ => 1
    [<c02d9f64>] (clk_core_prepare) from [<c02dd3c8>] (clk_prepare+0x1c/0x2c)
    [<c02dd3c8>] (clk_prepare) from [<c033a46c>] (__pm_clk_add+0xc0/0x124)
    [<c033a46c>] (__pm_clk_add) from [<c02e234c>]
(cpg_mstp_attach_dev+0x100/0x14c)
    [<c02e234c>] (cpg_mstp_attach_dev) from [<c03382c0>]
(genpd_add_device.constprop.9+0x1a4/0x1fc)
    [<c03382c0>] (genpd_add_device.constprop.9) from [<c0338c58>]
(__genpd_dev_pm_attach+0xc4/0x1a8)
    [<c0338c58>] (__genpd_dev_pm_attach) from [<c032ca44>]
(dev_pm_domain_attach+0x14/0x24)
    [<c032ca44>] (dev_pm_domain_attach) from [<c03262ec>]
(platform_drv_probe+0x2c/0x94)
    [<c03262ec>] (platform_drv_probe) from [<c0324558>]
(really_probe+0x1f0/0x2c0)

    WARNING: CPU: 0 PID: 1 at drivers/clk/clk.c:768 clk_core_prepare+0x94/0x388
    clk_core_prepare: prepare_count++ => 2
    [<c02d9f64>] (clk_core_prepare) from [<c02dd3c8>] (clk_prepare+0x1c/0x2c)
    [<c02dd3c8>] (clk_prepare) from [<c039033c>] (sh_mmcif_probe+0x1e0/0x4b4)
    [<c039033c>] (sh_mmcif_probe) from [<c0326308>]
(platform_drv_probe+0x48/0x94)
    [<c0326308>] (platform_drv_probe) from [<c0324558>]
(really_probe+0x1f0/0x2c0)

    WARNING: CPU: 0 PID: 1 at drivers/clk/clk.c:911 clk_core_enable+0x1f4/0x30c
    clk_core_enable: enable_count++ => 1
    [<c02db738>] (clk_core_enable) from [<c02db868>]
(clk_core_enable_lock+0x18/0x2c)
    [<c02db868>] (clk_core_enable_lock) from [<c039034c>]
(sh_mmcif_probe+0x1f0/0x4b4)
    [<c039034c>] (sh_mmcif_probe) from [<c0326308>]
(platform_drv_probe+0x48/0x94)
    [<c0326308>] (platform_drv_probe) from [<c0324558>]
(really_probe+0x1f0/0x2c0)

    WARNING: CPU: 0 PID: 1 at drivers/clk/clk.c:911 clk_core_enable+0x1f4/0x30c
    clk_core_enable: enable_count++ => 2
    [<c02db738>] (clk_core_enable) from [<c02db868>]
(clk_core_enable_lock+0x18/0x2c)
    [<c02db868>] (clk_core_enable_lock) from [<c033aa78>]
(pm_clk_resume+0x68/0xa0)
    [<c033aa78>] (pm_clk_resume) from [<c0338e88>]
(genpd_runtime_resume+0x14c/0x1ac)
    [<c0338e88>] (genpd_runtime_resume) from [<c032e1f0>]
(__rpm_callback+0x30/0x188)
    [<c032e1f0>] (__rpm_callback) from [<c032e3b8>] (rpm_callback+0x70/0x80)
    [<c032e3b8>] (rpm_callback) from [<c032ee6c>] (rpm_resume+0x584/0x62c)
    [<c032ee6c>] (rpm_resume) from [<c032e1a4>] (__pm_runtime_resume+0x78/0x94)
    [<c032e1a4>] (__pm_runtime_resume) from [<c0390410>]
(sh_mmcif_probe+0x2b4/0x4b4)
    [<c0390410>] (sh_mmcif_probe) from [<c0326308>]
(platform_drv_probe+0x48/0x94)
    [<c0326308>] (platform_drv_probe) from [<c0324558>]
(really_probe+0x1f0/0x2c0)

    WARNING: CPU: 0 PID: 1 at drivers/clk/clk.c:768 clk_core_prepare+0x94/0x388
    clk_core_prepare: prepare_count++ => 3
    [<c02d9f64>] (clk_core_prepare) from [<c02dd3c8>] (clk_prepare+0x1c/0x2c)
    [<c02dd3c8>] (clk_prepare) from [<c038ffb4>] (sh_mmcif_set_ios+0xb8/0x260)
    [<c038ffb4>] (sh_mmcif_set_ios) from [<c037aca4>] (mmc_power_up+0x44/0xcc)
    [<c037aca4>] (mmc_power_up) from [<c037be00>] (mmc_start_host+0x4c/0x78)
    [<c037be00>] (mmc_start_host) from [<c037d080>] (mmc_add_host+0x64/0x78)
    [<c037d080>] (mmc_add_host) from [<c0390554>] (sh_mmcif_probe+0x3f8/0x4b4)
    [<c0390554>] (sh_mmcif_probe) from [<c0326308>]
(platform_drv_probe+0x48/0x94)
    [<c0326308>] (platform_drv_probe) from [<c0324558>]
(really_probe+0x1f0/0x2c0)

    WARNING: CPU: 0 PID: 1 at drivers/clk/clk.c:911 clk_core_enable+0x1f4/0x30c
    clk_core_enable: enable_count++ => 3
    [<c02db738>] (clk_core_enable) from [<c02db868>]
(clk_core_enable_lock+0x18/0x2c)
    [<c02db868>] (clk_core_enable_lock) from [<c038ffc4>]
(sh_mmcif_set_ios+0xc8/0x260)
    [<c038ffc4>] (sh_mmcif_set_ios) from [<c037aca4>] (mmc_power_up+0x44/0xcc)
    [<c037aca4>] (mmc_power_up) from [<c037be00>] (mmc_start_host+0x4c/0x78)
    [<c037be00>] (mmc_start_host) from [<c037d080>] (mmc_add_host+0x64/0x78)
    [<c037d080>] (mmc_add_host) from [<c0390554>] (sh_mmcif_probe+0x3f8/0x4b4)
    [<c0390554>] (sh_mmcif_probe) from [<c0326308>]
(platform_drv_probe+0x48/0x94)
    [<c0326308>] (platform_drv_probe) from [<c0324558>]
(really_probe+0x1f0/0x2c0)

    WARNING: CPU: 0 PID: 1 at drivers/clk/clk.c:834 clk_core_disable+0x1f0/0x304
    clk_core_disable: 3 => --enable_count
    [<c02da54c>] (clk_core_disable) from [<c02daf40>]
(clk_core_disable_lock+0x18/0x24)
    [<c02daf40>] (clk_core_disable_lock) from [<c03905ac>]
(sh_mmcif_probe+0x450/0x4b4)
    [<c03905ac>] (sh_mmcif_probe) from [<c0326308>]
(platform_drv_probe+0x48/0x94)
    [<c0326308>] (platform_drv_probe) from [<c0324558>]
(really_probe+0x1f0/0x2c0)

    WARNING: CPU: 0 PID: 1 at drivers/clk/clk.c:694
clk_core_unprepare+0x2d4/0x3c0
    clk_core_unprepare: 3 => --prepare_count
    [<c02d9de4>] (clk_core_unprepare) from [<c02dd3a4>]
(clk_unprepare+0x24/0x2c)
    [<c02dd3a4>] (clk_unprepare) from [<c03905b4>] (sh_mmcif_probe+0x458/0x4b4)
    [<c03905b4>] (sh_mmcif_probe) from [<c0326308>]
(platform_drv_probe+0x48/0x94)
    [<c0326308>] (platform_drv_probe) from [<c0324558>]
(really_probe+0x1f0/0x2c0)


=> mmcif0 prepare_count = 2, enable_count = 2

suspend:

    WARNING: CPU: 0 PID: 7 at drivers/clk/clk.c:834 clk_core_disable+0x1f0/0x304
    clk_core_disable: 2 => --enable_count
    [<c02da54c>] (clk_core_disable) from [<c02daf40>]
(clk_core_disable_lock+0x18/0x24)
    [<c02daf40>] (clk_core_disable_lock) from [<c0390134>]
(sh_mmcif_set_ios+0x238/0x260)
    [<c0390134>] (sh_mmcif_set_ios) from [<c037ad60>] (mmc_power_off+0x34/0x44)
    [<c037ad60>] (mmc_power_off) from [<c037daf0>] (_mmc_suspend+0x11c/0x24c)
    [<c037daf0>] (_mmc_suspend) from [<c037dc80>] (mmc_suspend+0x10/0x40)
    [<c037dc80>] (mmc_suspend) from [<c037c0c0>] (mmc_bus_suspend+0x28/0x40)
    [<c037c0c0>] (mmc_bus_suspend) from [<c0331930>]
(dpm_run_callback+0x194/0x344)
    [<c0331930>] (dpm_run_callback) from [<c0333090>]
(__device_suspend+0x16c/0x618)
    [<c0333090>] (__device_suspend) from [<c0333a54>] (async_suspend+0x18/0x84)
    [<c0333a54>] (async_suspend) from [<c0051284>]
(async_run_entry_fn+0x44/0x110)
    [<c0051284>] (async_run_entry_fn) from [<c00473b4>]
(process_one_work+0x3ac/0x6a4)
    [<c00473b4>] (process_one_work) from [<c0047964>]
(worker_thread+0x28c/0x40c)
    [<c0047964>] (worker_thread) from [<c004dc14>] (kthread+0x140/0x15c)

    WARNING: CPU: 0 PID: 7 at drivers/clk/clk.c:694
clk_core_unprepare+0x2d4/0x3c0
    clk_core_unprepare: 2 => --prepare_count
    [<c02d9de4>] (clk_core_unprepare) from [<c02dd3a4>]
(clk_unprepare+0x24/0x2c)
    [<c02dd3a4>] (clk_unprepare) from [<c039013c>]
(sh_mmcif_set_ios+0x240/0x260)
    [<c039013c>] (sh_mmcif_set_ios) from [<c037ad60>] (mmc_power_off+0x34/0x44)
    [<c037ad60>] (mmc_power_off) from [<c037daf0>] (_mmc_suspend+0x11c/0x24c)
    [<c037daf0>] (_mmc_suspend) from [<c037dc80>] (mmc_suspend+0x10/0x40)
    [<c037dc80>] (mmc_suspend) from [<c037c0c0>] (mmc_bus_suspend+0x28/0x40)
    [<c037c0c0>] (mmc_bus_suspend) from [<c0331930>]
(dpm_run_callback+0x194/0x344)
    [<c0331930>] (dpm_run_callback) from [<c0333090>]
(__device_suspend+0x16c/0x618)
    [<c0333090>] (__device_suspend) from [<c0333a54>] (async_suspend+0x18/0x84)
    [<c0333a54>] (async_suspend) from [<c0051284>]
(async_run_entry_fn+0x44/0x110)
    [<c0051284>] (async_run_entry_fn) from [<c00473b4>]
(process_one_work+0x3ac/0x6a4)
    [<c00473b4>] (process_one_work) from [<c0047964>]
(worker_thread+0x28c/0x40c)
    [<c0047964>] (worker_thread) from [<c004dc14>] (kthread+0x140/0x15c)

    WARNING: CPU: 0 PID: 562 at drivers/clk/clk.c:834
clk_core_disable+0x1f0/0x304
    clk_core_disable: 1 => --enable_count
    [<c02da54c>] (clk_core_disable) from [<c02daf40>]
(clk_core_disable_lock+0x18/0x24)
    [<c02daf40>] (clk_core_disable_lock) from [<c033a9fc>]
(pm_clk_suspend+0x64/0x78)
    [<c033a9fc>] (pm_clk_suspend) from [<c03384cc>]
(genpd_finish_suspend+0xac/0x118)
    [<c03384cc>] (genpd_finish_suspend) from [<c0331930>]
(dpm_run_callback+0x194/0x344)
    [<c0331930>] (dpm_run_callback) from [<c0334500>]
(__device_suspend_noirq+0x108/0x280)
    [<c0334500>] (__device_suspend_noirq) from [<c033499c>]
(dpm_noirq_suspend_devices+0x324/0x494)
    [<c033499c>] (dpm_noirq_suspend_devices) from [<c0334b20>]
(dpm_suspend_noirq+0x14/0x30)
    [<c0334b20>] (dpm_suspend_noirq) from [<c008e400>]
(suspend_devices_and_enter+0x614/0xcb0)
    [<c008e400>] (suspend_devices_and_enter) from [<c008f420>]
(pm_suspend+0x984/0xa14)
    [<c008f420>] (pm_suspend) from [<c008cc0c>] (state_store+0x9c/0xcc)
    [<c008cc0c>] (state_store) from [<c01e4100>] (kernfs_fop_write+0x154/0x1cc)
    [<c01e4100>] (kernfs_fop_write) from [<c016a21c>] (__vfs_write+0x28/0x178)
    [<c016a21c>] (__vfs_write) from [<c016a4fc>] (vfs_write+0xb8/0x14c)
    [<c016a4fc>] (vfs_write) from [<c016a6c0>] (ksys_write+0x4c/0x9c)
    [<c016a6c0>] (ksys_write) from [<c000a000>] (ret_fast_syscall+0x0/0x28)


resume

    WARNING: CPU: 0 PID: 562 at drivers/clk/clk.c:911
clk_core_enable+0x1f4/0x30c
    clk_core_enable: enable_count++ => 1
    [<c02db738>] (clk_core_enable) from [<c02db868>]
(clk_core_enable_lock+0x18/0x2c)
    [<c02db868>] (clk_core_enable_lock) from [<c033aa78>]
(pm_clk_resume+0x68/0xa0)
    [<c033aa78>] (pm_clk_resume) from [<c0338784>]
(genpd_resume_noirq+0xc0/0xd8)
    [<c0338784>] (genpd_resume_noirq) from [<c0331930>]
(dpm_run_callback+0x194/0x344)
    [<c0331930>] (dpm_run_callback) from [<c0333e94>]
(device_resume_noirq+0x144/0x1b4)
    [<c0333e94>] (device_resume_noirq) from [<c03341fc>]
(dpm_noirq_resume_devices+0x2f8/0x488)
    [<c03341fc>] (dpm_noirq_resume_devices) from [<c0334394>]
(dpm_resume_noirq+0x8/0x10)
    [<c0334394>] (dpm_resume_noirq) from [<c008e810>]
(suspend_devices_and_enter+0xa24/0xcb0)
    [<c008e810>] (suspend_devices_and_enter) from [<c008f420>]
(pm_suspend+0x984/0xa14)
    [<c008f420>] (pm_suspend) from [<c008cc0c>] (state_store+0x9c/0xcc)
    [<c008cc0c>] (state_store) from [<c01e4100>] (kernfs_fop_write+0x154/0x1cc)
    [<c01e4100>] (kernfs_fop_write) from [<c016a21c>] (__vfs_write+0x28/0x178)
    [<c016a21c>] (__vfs_write) from [<c016a4fc>] (vfs_write+0xb8/0x14c)
    [<c016a4fc>] (vfs_write) from [<c016a6c0>] (ksys_write+0x4c/0x9c)
    [<c016a6c0>] (ksys_write) from [<c000a000>] (ret_fast_syscall+0x0/0x28)

=> mmcif0 prepare_count = 1, enable_count = 1


2nd suspend:

    WARNING: CPU: 0 PID: 636 at drivers/clk/clk.c:834
clk_core_disable+0x1f0/0x304
    clk_core_disable: 1 => --enable_count
    [<c02da54c>] (clk_core_disable) from [<c02daf40>]
(clk_core_disable_lock+0x18/0x24)
    [<c02daf40>] (clk_core_disable_lock) from [<c033a9fc>]
(pm_clk_suspend+0x64/0x78)
    [<c033a9fc>] (pm_clk_suspend) from [<c03384cc>]
(genpd_finish_suspend+0xac/0x118)
    [<c03384cc>] (genpd_finish_suspend) from [<c0331930>]
(dpm_run_callback+0x194/0x344)
    [<c0331930>] (dpm_run_callback) from [<c0334500>]
(__device_suspend_noirq+0x108/0x280)
    [<c0334500>] (__device_suspend_noirq) from [<c033499c>]
(dpm_noirq_suspend_devices+0x324/0x494)
    [<c033499c>] (dpm_noirq_suspend_devices) from [<c0334b20>]
(dpm_suspend_noirq+0x14/0x30)
    [<c0334b20>] (dpm_suspend_noirq) from [<c008e400>]
(suspend_devices_and_enter+0x614/0xcb0)
    [<c008e400>] (suspend_devices_and_enter) from [<c008f420>]
(pm_suspend+0x984/0xa14)
    [<c008f420>] (pm_suspend) from [<c008cc0c>] (state_store+0x9c/0xcc)
    [<c008cc0c>] (state_store) from [<c01e4100>] (kernfs_fop_write+0x154/0x1cc)
    [<c01e4100>] (kernfs_fop_write) from [<c016a21c>] (__vfs_write+0x28/0x178)
    [<c016a21c>] (__vfs_write) from [<c016a4fc>] (vfs_write+0xb8/0x14c)
    [<c016a4fc>] (vfs_write) from [<c016a6c0>] (ksys_write+0x4c/0x9c)
    [<c016a6c0>] (ksys_write) from [<c000a000>] (ret_fast_syscall+0x0/0x28)


2nd resume:

    WARNING: CPU: 0 PID: 636 at drivers/clk/clk.c:911
clk_core_enable+0x1f4/0x30c
    clk_core_enable: enable_count++ => 1
    [<c02db738>] (clk_core_enable) from [<c02db868>]
(clk_core_enable_lock+0x18/0x2c)
    [<c02db868>] (clk_core_enable_lock) from [<c033aa78>]
(pm_clk_resume+0x68/0xa0)
    [<c033aa78>] (pm_clk_resume) from [<c0338784>]
(genpd_resume_noirq+0xc0/0xd8)
    [<c0338784>] (genpd_resume_noirq) from [<c0331930>]
(dpm_run_callback+0x194/0x344)
    [<c0331930>] (dpm_run_callback) from [<c0333e94>]
(device_resume_noirq+0x144/0x1b4)
    [<c0333e94>] (device_resume_noirq) from [<c03341fc>]
(dpm_noirq_resume_devices+0x2f8/0x488)
    [<c03341fc>] (dpm_noirq_resume_devices) from [<c0334394>]
(dpm_resume_noirq+0x8/0x10)
    [<c0334394>] (dpm_resume_noirq) from [<c008e810>]
(suspend_devices_and_enter+0xa24/0xcb0)
    [<c008e810>] (suspend_devices_and_enter) from [<c008f420>]
(pm_suspend+0x984/0xa14)
    [<c008f420>] (pm_suspend) from [<c008cc0c>] (state_store+0x9c/0xcc)
    [<c008cc0c>] (state_store) from [<c01e4100>] (kernfs_fop_write+0x154/0x1cc)
    [<c01e4100>] (kernfs_fop_write) from [<c016a21c>] (__vfs_write+0x28/0x178)
    [<c016a21c>] (__vfs_write) from [<c016a4fc>] (vfs_write+0xb8/0x14c)
    [<c016a4fc>] (vfs_write) from [<c016a6c0>] (ksys_write+0x4c/0x9c)
    [<c016a6c0>] (ksys_write) from [<c000a000>] (ret_fast_syscall+0x0/0x28)

=> mmcif0 prepare_count = 1, enable_count = 1

Gr{oetje,eeting}s,

                        Geert

--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- geert@linux-m68k.org

In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
                                -- Linus Torvalds
Niklas Söderlund April 10, 2019, 9:45 p.m. UTC | #4 
Hi Geert,

Thanks for your feedback. Sorry for following up a tad late on this 
getting hold of and getting started with the APE6 took some time (thanks 
again for your help in that area too!).

On 2019-01-10 17:23:46 +0100, Geert Uytterhoeven wrote:
> Hi Niklas,
> 
> On Wed, Jan 9, 2019 at 11:36 PM Niklas Söderlund
> <niklas.soderlund+renesas@ragnatech.se> wrote:
> > Both the Renesas and Uniphier implementations perform actions which
> > effects runtime PM before calling into the core tmio_mmc_probe() which
> > enabled runtime PM. Move pm_runtime_enable() from the core and
> > tmio_mmc_probe() into each drivers probe() so it can be called before
> > any clocks or other resources are switched on.
> >
> > Reported-by: Geert Uytterhoeven <geert+renesas@glider.be>
> > Signed-off-by: Niklas Söderlund <niklas.soderlund+renesas@ragnatech.se>
> 
> Thanks for your patch!
> 
> /sys/kernel/debug/clk/clk_summary after boot (without your patch):
> 
> ape6evm (R-Mobile APE6):
> 
>      mmc1         0    0    0    12500000    0     0  50000
>         mmcif1    0    0    0    12500000    0     0  50000
>      mmc0         1    1    0   100000000    0     0  50000
>         mmcif0    2    2    0   100000000    0     0  50000
>      sdhi2ck      0    0    0    12500000    0     0  50000
>         sdhi2     0    0    0    12500000    0     0  50000
>      sdhi1ck      1    1    0    12500000    0     0  50000
>         sdhi1     2    2    0    12500000    0     0  50000
>      sdhi0ck      1    1    0    88888888    0     0  50000
>         sdhi0     1    2    0    88888888    0     0  50000
> 
> kzm9g (SH-Mobile AG5):
> 
>      sdhi2ck      1    1    0    69333333    0     0  50000
>         sdhi2     2    2    0    69333333    0     0  50000
>      sdhi1ck      0    0    0    69333333    0     0  50000
>         sdhi1     0    0    0    69333333    0     0  50000
>      sdhi0ck      1    1    0    69333333    0     0  50000
>         sdhi0     1    2    0    69333333    0     0  50000
> 
> m3-n-salvator-xs (R-Car M3-N):
> 
>     .sdsrc        3    3    0   798720000    0     0  50000
>        sd3        1    1    0    12480000    0     0  50000
>           sdif3   1    2    0    12480000    0     0  50000
>        sd2        1    1    0   199680000    0     0  50000
>           sdif2   1    2    0   199680000    0     0  50000
>        sd1        0    0    0   199680000    0     0  50000
>           sdif1   0    0    0   199680000    0     0  50000
>        sd0        1    1    0    12480000    0     0  50000
>           sdif0   1    2    0    12480000    0     0  50000
> 
> 
> /sys/kernel/debug/clk/clk_summary after boot (with your patch):
> 
> ape6evm:
> 
>      mmc1         0    0    0    12500000    0     0  50000
>         mmcif1    0    0    0    12500000    0     0  50000
>      mmc0         1    1    0   100000000    0     0  50000
>         mmcif0    2    2    0   100000000    0     0  50000
>      sdhi2ck      0    0    0    12500000    0     0  50000
>         sdhi2     0    0    0    12500000    0     0  50000
>      sdhi1ck      1    1    0    12500000    0     0  50000
>         sdhi1     3    3    0    12500000    0     0  50000
>      sdhi0ck      1    1    0    88888888    0     0  50000
>         sdhi0     3    3    0    88888888    0     0  50000
> 
> kzm9g:
> 
>      sdhi2ck      1    1    0    69333333    0     0  50000
>         sdhi2     3    3    0    69333333    0     0  50000
>      sdhi1ck      0    0    0    69333333    0     0  50000
>         sdhi1     0    0    0    69333333    0     0  50000
>      sdhi0ck      1    1    0    69333333    0     0  50000
>         sdhi0     3    3    0    69333333    0     0  50000
> 
> m3-n-salvator-xs:
> 
>     .sdsrc        3    3    0   798720000    0     0  50000
>        sd3        1    1    0    12480000    0     0  50000
>           sdif3   3    3    0    12480000    0     0  50000
>        sd2        1    1    0   199680000    0     0  50000
>           sdif2   3    3    0   199680000    0     0  50000
>        sd1        0    0    0   199680000    0     0  50000
>           sdif1   0    0    0   199680000    0     0  50000
>        sd0        1    1    0    12480000    0     0  50000
>           sdif0   3    3    0    12480000    0     0  50000
> 
> 
> Unfortunately the clock imbalance isn't gone.
> After resume from s2ram (with your patch):
> 
> ape6evm:
> 
>      mmc1         0    0    0    12500000    0     0  50000
>         mmcif1    0    0    0    12500000    0     0  50000
>      mmc0         0    1    0   100000000    0     0  50000
>         mmcif0    0    1    0   100000000    0     0  50000

These clocks are handled by the sh_mmcif driver and I observe the same 
thing. I suspect however that this is the correct behavior as the driver 
uses dev_pm_qos_expose_latency_limit() and trying to use the mmc changes 
this to 1/1 and it seems to work fine.

My knowledge in this area of PM is not good so I might be wrong but I'm 
not trying to deal with this clock in this patch.

>      sdhi2ck      0    0    0    12500000    0     0  50000
>         sdhi2     0    0    0    12500000    0     0  50000
>      sdhi1ck      1    1    0    12500000    0     0  50000
>         sdhi1     1    2    0    12500000    0     0  50000
>      sdhi0ck      1    1    0    88888888    0     0  50000
>         sdhi0     3    3    0    88888888    0     0  50000

I can not reproduce this with this patch on top of v4.20 which the 
original patch was based on nor on today's mmc/next. For me clocks are 
the same as before suspending. I do however get this result if I run on 
ether base without this patch.

> 
> kzm9g:
> 
>      sdhi2ck      1    1    0    69333333    0     0  50000
>         sdhi2     1    2    0    69333333    0     0  50000
>      sdhi1ck      0    0    0    69333333    0     0  50000
>         sdhi1     0    0    0    69333333    0     0  50000
>      sdhi0ck      1    1    0    69333333    0     0  50000
>         sdhi0     3    3    0    69333333    0     0  50000
> 
> And my debug prints in genpd_st{art,op}_dev() still tell me the device
> is cycled continuously after resume from s2ram:
> 
> ape6evm:
> 
>     [  761.928322] ==== a3sp/ee120000.sd: start
>     [  762.017086] ==== a3sp/ee120000.sd: stop
>     [  762.968418] ==== a3sp/ee120000.sd: start
>     [  763.057139] ==== a3sp/ee120000.sd: stop
>     [  764.008535] ==== a3sp/ee120000.sd: start
>     [  764.097261] ==== a3sp/ee120000.sd: stop
>     [  765.048621] ==== a3sp/ee120000.sd: start
>     [  765.137359] ==== a3sp/ee120000.sd: stop
>                    ...

I tried the same on my end and I can observe the start and stop as I 
expected and can't observe this ping-pong.

> 
> kzm9g:
> 
>     [  403.676197] ==== a3sp/ee140000.sd: start
>     [  403.764984] ==== a3sp/ee140000.sd: stop
>     [  404.716462] ==== a3sp/ee140000.sd: start
>     [  404.805208] ==== a3sp/ee140000.sd: stop
>     [  405.756708] ==== a3sp/ee140000.sd: start
>     [  405.836766] ==== a3sp/ee140000.sd: stop
>                    ...
> 
> Further s2ram cycles make no difference, as before.
> 
> On R-Car M3-N, there is no such imbalance. This seems to happen
> on older SH/R-Mobile SoCs only.

I will send out a v2 of 2/2 addressing Wolframs comments, I would 
appreciate if you could test that as well as I'm not able to reproduce 
the same issue as you. I'm using the same configuration you sent me when 
you helped me to get started with the APE6EVM.
diff mbox series

Patch

diff --git a/drivers/mmc/host/renesas_sdhi_core.c b/drivers/mmc/host/renesas_sdhi_core.c
index 31a351a20dc02aab..ab07f9d1f7909412 100644
--- a/drivers/mmc/host/renesas_sdhi_core.c
+++ b/drivers/mmc/host/renesas_sdhi_core.c
@@ -755,6 +755,8 @@  int renesas_sdhi_probe(struct platform_device *pdev,
 	/* All SDHI have SDIO status bits which must be 1 */
 	mmc_data->flags |= TMIO_MMC_SDIO_STATUS_SETBITS;
 
+	pm_runtime_enable(&pdev->dev);
+
 	ret = renesas_sdhi_clk_enable(host);
 	if (ret)
 		goto efree;
@@ -833,6 +835,8 @@  int renesas_sdhi_probe(struct platform_device *pdev,
 efree:
 	tmio_mmc_host_free(host);
 
+	pm_runtime_disable(&pdev->dev);
+
 	return ret;
 }
 EXPORT_SYMBOL_GPL(renesas_sdhi_probe);
@@ -844,6 +848,8 @@  int renesas_sdhi_remove(struct platform_device *pdev)
 	tmio_mmc_host_remove(host);
 	renesas_sdhi_clk_disable(host);
 
+	pm_runtime_disable(&pdev->dev);
+
 	return 0;
 }
 EXPORT_SYMBOL_GPL(renesas_sdhi_remove);
diff --git a/drivers/mmc/host/tmio_mmc.c b/drivers/mmc/host/tmio_mmc.c
index 93e83ad25976e756..8539e10784b40961 100644
--- a/drivers/mmc/host/tmio_mmc.c
+++ b/drivers/mmc/host/tmio_mmc.c
@@ -172,6 +172,8 @@  static int tmio_mmc_probe(struct platform_device *pdev)
 	host->mmc->f_max = pdata->hclk;
 	host->mmc->f_min = pdata->hclk / 512;
 
+	pm_runtime_enable(&pdev->dev);
+
 	ret = tmio_mmc_host_probe(host);
 	if (ret)
 		goto host_free;
@@ -191,6 +193,7 @@  static int tmio_mmc_probe(struct platform_device *pdev)
 	tmio_mmc_host_remove(host);
 host_free:
 	tmio_mmc_host_free(host);
+	pm_runtime_disable(&pdev->dev);
 cell_disable:
 	if (cell->disable)
 		cell->disable(pdev);
@@ -207,6 +210,8 @@  static int tmio_mmc_remove(struct platform_device *pdev)
 	if (cell->disable)
 		cell->disable(pdev);
 
+	pm_runtime_disable(&pdev->dev);
+
 	return 0;
 }
 
diff --git a/drivers/mmc/host/tmio_mmc_core.c b/drivers/mmc/host/tmio_mmc_core.c
index 7323a5935fff786f..efc0ca83c001b948 100644
--- a/drivers/mmc/host/tmio_mmc_core.c
+++ b/drivers/mmc/host/tmio_mmc_core.c
@@ -1253,7 +1253,6 @@  int tmio_mmc_host_probe(struct tmio_mmc_host *_host)
 	pm_runtime_set_active(&pdev->dev);
 	pm_runtime_set_autosuspend_delay(&pdev->dev, 50);
 	pm_runtime_use_autosuspend(&pdev->dev);
-	pm_runtime_enable(&pdev->dev);
 
 	ret = mmc_add_host(mmc);
 	if (ret)
@@ -1289,7 +1288,6 @@  void tmio_mmc_host_remove(struct tmio_mmc_host *host)
 
 	pm_runtime_dont_use_autosuspend(&pdev->dev);
 	pm_runtime_put_sync(&pdev->dev);
-	pm_runtime_disable(&pdev->dev);
 }
 EXPORT_SYMBOL_GPL(tmio_mmc_host_remove);
 
diff --git a/drivers/mmc/host/uniphier-sd.c b/drivers/mmc/host/uniphier-sd.c
index 91a2be41edf6196b..49aad9a79c18d24a 100644
--- a/drivers/mmc/host/uniphier-sd.c
+++ b/drivers/mmc/host/uniphier-sd.c
@@ -631,6 +631,7 @@  static int uniphier_sd_probe(struct platform_device *pdev)
 	host->clk_disable = uniphier_sd_clk_disable;
 	host->set_clock = uniphier_sd_set_clock;
 
+	pm_runtime_enable(&pdev->dev);
 	ret = uniphier_sd_clk_enable(host);
 	if (ret)
 		goto free_host;
@@ -652,6 +653,7 @@  static int uniphier_sd_probe(struct platform_device *pdev)
 
 free_host:
 	tmio_mmc_host_free(host);
+	pm_runtime_disable(&pdev->dev);
 
 	return ret;
 }
@@ -662,6 +664,7 @@  static int uniphier_sd_remove(struct platform_device *pdev)
 
 	tmio_mmc_host_remove(host);
 	uniphier_sd_clk_disable(host);
+	pm_runtime_disable(&pdev->dev);
 
 	return 0;
 }