All of lore.kernel.org
 help / color / mirror / Atom feed
* About SD initialization at resume time
       [not found] <CGME20210303092222epcas2p11fbb2697a53b54dbc138d741893c9f07@epcas2p1.samsung.com>
@ 2021-03-03  9:22 ` Kiwoong Kim
  2021-03-03 11:42   ` Ulf Hansson
  0 siblings, 1 reply; 4+ messages in thread
From: Kiwoong Kim @ 2021-03-03  9:22 UTC (permalink / raw)
  To: linux-mmc, ulf.hansson

Dear all

I hope opinions from you guys.

For many users of mobile device, there is a possibility that issuing no IO request to
a SD card is rare during much of the device's lifetime.
Obviously the symptom would happen frequently among system suspend times, too.
In this situation, doing SD initialization at every system resume leads to long latency
and can make the users feel it, even when there is no IO request during the period,
when a hardware architecture requires re-initialization at resume time.
This is what had actually happened and was fixed with some code in commercial products.

Is there any way to avoid that symptom w/o any code change?
With no way, I hope to make soemthing to improve it.

Thanks.
Kiwoong Kim



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

* Re: About SD initialization at resume time
  2021-03-03  9:22 ` About SD initialization at resume time Kiwoong Kim
@ 2021-03-03 11:42   ` Ulf Hansson
  2021-03-04  7:43     ` Kiwoong Kim
  0 siblings, 1 reply; 4+ messages in thread
From: Ulf Hansson @ 2021-03-03 11:42 UTC (permalink / raw)
  To: Kiwoong Kim; +Cc: linux-mmc

On Wed, 3 Mar 2021 at 10:22, Kiwoong Kim <kwmad.kim@samsung.com> wrote:
>
> Dear all
>
> I hope opinions from you guys.
>
> For many users of mobile device, there is a possibility that issuing no IO request to
> a SD card is rare during much of the device's lifetime.

If you want to put the card into a low power state after a period of
idle, you can set MMC_CAP_AGGRESSIVE_PM for the corresponding mmc
host.

Be careful though, as you will prevent the card from doing internal
garbage collection if you power it off. It may be a good idea to
extend the idle period for this, which can be done from userspace via
sysfs.

> Obviously the symptom would happen frequently among system suspend times, too.
> In this situation, doing SD initialization at every system resume leads to long latency
> and can make the users feel it, even when there is no IO request during the period,
> when a hardware architecture requires re-initialization at resume time.

No matter if you have MMC_CAP_AGGRESSIVE_PM or not, system resume time
should not be affected. Re-initialization of the SD/eMMC cards are
deferred to be managed through runtime PM, which means that the card
will be resumed the next time there is a command/request to be sent to
the card.

Assuming there is no I/O request after the system has resumed, then a
non-removable card (host has MMC_CAP_NONREMOVABLE set), typically an
eMMC, will thus remain in low power state even after the system has
resumed.

For a removable card (typically SD cards), there is a limitation that
we need to check if the card remains inserted after the system has
resumed. Although, note that this is done in a workqueue, thus not
affecting the overall system resume time. Still, we do end up
re-initializing of removable cards, just to check that they are still
inserted, which certainly is not always a good thing to do.

> This is what had actually happened and was fixed with some code in commercial products.

The above code in the mmc core was introduced around kernel v3.11,
even if it has been fine tuned since then.

Maybe you have been using even older kernels?

>
> Is there any way to avoid that symptom w/o any code change?
> With no way, I hope to make soemthing to improve it.

Improvements can certainly be done and would be greatly appreciated.

If you want to look at optimizing the behaviour, I suggest trying to
avoid the re-initialization of removable cards during system resume.
It's not possible for all cases, but certainly for some.

If you care about system resume time of SDIO cards, there are even
more improvements that can be made.

>
> Thanks.
> Kiwoong Kim
>

Kind regards
Uffe

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

* RE: About SD initialization at resume time
  2021-03-03 11:42   ` Ulf Hansson
@ 2021-03-04  7:43     ` Kiwoong Kim
  2021-03-08 11:32       ` Ulf Hansson
  0 siblings, 1 reply; 4+ messages in thread
From: Kiwoong Kim @ 2021-03-04  7:43 UTC (permalink / raw)
  To: 'Ulf Hansson'; +Cc: linux-mmc

> > This is what had actually happened and was fixed with some code in
> commercial products.
> 
> The above code in the mmc core was introduced around kernel v3.11, even if
> it has been fine tuned since then.
> 
> Maybe you have been using even older kernels?
> 
Dear Uffe

First, you give me what I want.
We've used higher versions than 3.11 but applied our own changes for some reasons.
Anyway, thanks !

That is the first problem for me on SD.
The 2nd thing is very long latency issue for a race between an IO thread and a kworker to run mmc_rescan.

There is an application to put many IO requests to a SD card right after completion of system resume.
Current MMC stack invokes mmc_rescan is invoked asynchronously for PM_POST_SUSPEND.
As reported to me, however, there could be a race between an IO thread and the kworker for mmc_rescan
especially the function of mmc_rescan is run later than expected and the application mentioned before is installed.

For a series of IO requests, mmc_rescan, particularily at __mmc_claim_host called in mmc_sd_detect,
doesn't acquire a host for longer than expected.
Below is the call stacks shown after the symptom happened and the system tried to enter into suspend again.
In this case, mmc pm notifier is called with PM_SUSPEND_PREPARE, so it waits for completion or cancelling the work for mmc_rescan.
For the latency, users can see black screen for a long time sometimes.

So I want to post a patch not to do _mmc_detect_change conditionally
because it helps remove the race and the case assumes SD card initialization is already done.
If you have your different views, please let me know.

Thanks.

--
<6>[ 3965.259816] I[0:      swapper/0:    0]    22631        0      227    3902403994884 D(2)   3  ffffffc0007ee338                0  ffffffc85678e000 *    kworker/u16:4 [__mmc_claim_host]
<6>[ 3965.259839] I[0:      swapper/0:    0] Workqueue: kmmcd mmc_rescan
<0>[ 3965.259854] I[0:      swapper/0:    0] Call trace:
<4>[ 3965.259870] I[0:      swapper/0:    0] [<ffffffc00013e674>] __switch_to+0x80/0x90
<4>[ 3965.259886] I[0:      swapper/0:    0] [<ffffffc000b137f4>] __schedule+0x530/0x76c
<4>[ 3965.259902] I[0:      swapper/0:    0] [<ffffffc000b13a9c>] schedule+0x6c/0x7c
<4>[ 3965.259919] I[0:      swapper/0:    0] [<ffffffc0007ee338>] __mmc_claim_host+0xb8/0x188
<4>[ 3965.259937] I[0:      swapper/0:    0] [<ffffffc0007eebfc>] mmc_get_card+0x24/0x38
<4>[ 3965.259956] I[0:      swapper/0:    0] [<ffffffc0007f5c44>] mmc_sd_detect+0x90/0xe8
<4>[ 3965.259973] I[0:      swapper/0:    0] [<ffffffc0007f08d8>] mmc_rescan+0xa0/0x2ec
<4>[ 3965.259991] I[0:      swapper/0:    0] [<ffffffc0001688e0>] process_one_work+0x26c/0x434
<4>[ 3965.260008] I[0:      swapper/0:    0] [<ffffffc000168dc8>] worker_thread+0x320/0x444
<4>[ 3965.260026] I[0:      swapper/0:    0] [<ffffffc00016dac0>] kthread+0xdc/0xec
..
<0>[ 3965.259854] I[0:      swapper/0:    0] Call trace:
<4>[ 3965.259870] I[0:      swapper/0:    0] [<ffffffc00013e674>] __switch_to+0x80/0x90
<4>[ 3965.259886] I[0:      swapper/0:    0] [<ffffffc000b137f4>] __schedule+0x530/0x76c
<4>[ 3965.259902] I[0:      swapper/0:    0] [<ffffffc000b13a9c>] schedule+0x6c/0x7c
<4>[ 3965.259919] I[0:      swapper/0:    0] [<ffffffc0007ee338>] __mmc_claim_host+0xb8/0x188
<4>[ 3965.259937] I[0:      swapper/0:    0] [<ffffffc0007eebfc>] mmc_get_card+0x24/0x38
<4>[ 3965.259956] I[0:      swapper/0:    0] [<ffffffc0007f5c44>] mmc_sd_detect+0x90/0xe8
<4>[ 3965.259973] I[0:      swapper/0:    0] [<ffffffc0007f08d8>] mmc_rescan+0xa0/0x2ec
<4>[ 3965.259991] I[0:      swapper/0:    0] [<ffffffc0001688e0>] process_one_work+0x26c/0x434
<4>[ 3965.260008] I[0:      swapper/0:    0] [<ffffffc000168dc8>] worker_thread+0x320/0x444
<4>[ 3965.260026] I[0:      swapper/0:    0] [<ffffffc00016dac0>] kthread+0xdc/0xec
..
<0>[ 3965.203379] I[0:      swapper/0:    0] Call trace:
<4>[ 3965.203397] I[0:      swapper/0:    0] [<ffffffc00013e674>] __switch_to+0x80/0x90
<4>[ 3965.203414] I[0:      swapper/0:    0] [<ffffffc000b137f4>] __schedule+0x530/0x76c
<4>[ 3965.203430] I[0:      swapper/0:    0] [<ffffffc000b13a9c>] schedule+0x6c/0x7c
<4>[ 3965.203448] I[0:      swapper/0:    0] [<ffffffc000b160e8>] schedule_timeout+0x28/0x214
<4>[ 3965.203464] I[0:      swapper/0:    0] [<ffffffc000b145a0>] wait_for_common+0x114/0x15c
<4>[ 3965.203482] I[0:      swapper/0:    0] [<ffffffc000b14710>] wait_for_completion+0x10/0x20
<4>[ 3965.203498] I[0:      swapper/0:    0] [<ffffffc000169990>] flush_work+0xf0/0x11c
<4>[ 3965.203516] I[0:      swapper/0:    0] [<ffffffc000169ad0>] __cancel_work_timer+0x114/0x1a0
<4>[ 3965.203533] I[0:      swapper/0:    0] [<ffffffc000169c44>] cancel_delayed_work_sync+0xc/0x1c
<4>[ 3965.203554] I[0:      swapper/0:    0] [<ffffffc0007f1000>] mmc_pm_notify+0x78/0x12c
<4>[ 3965.203573] I[0:      swapper/0:    0] [<ffffffc00016ebf4>] notifier_call_chain+0x7c/0xec
<4>[ 3965.203590] I[0:      swapper/0:    0] [<ffffffc00016ef08>] __blocking_notifier_call_chain+0x44/0x68
<4>[ 3965.203608] I[0:      swapper/0:    0] [<ffffffc00016ef3c>] blocking_notifier_call_chain+0x10/0x20
<4>[ 3965.203628] I[0:      swapper/0:    0] [<ffffffc0001964ec>] pm_notifier_call_chain+0x1c/0x44
<4>[ 3965.203644] I[0:      swapper/0:    0] [<ffffffc000197ad0>] pm_suspend+0x2e0/0x5fc
<4>[ 3965.203662] I[0:      swapper/0:    0] [<ffffffc0001961cc>] state_store+0x4c/0x8c
<4>[ 3965.203683] I[0:      swapper/0:    0] [<ffffffc0003f35ec>] kobj_attr_store+0x14/0x2c
<4>[ 3965.203703] I[0:      swapper/0:    0] [<ffffffc0002aac2c>] sysfs_kf_write+0x40/0x50
<4>[ 3965.203721] I[0:      swapper/0:    0] [<ffffffc0002aa000>] kernfs_fop_write+0xfc/0x148
<4>[ 3965.203739] I[0:      swapper/0:    0] [<ffffffc000249b4c>] vfs_write+0xb8/0x190
<4>[ 3965.203755] I[0:      swapper/0:    0] [<ffffffc000249cf0>] SyS_write+0x44/0x88


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

* Re: About SD initialization at resume time
  2021-03-04  7:43     ` Kiwoong Kim
@ 2021-03-08 11:32       ` Ulf Hansson
  0 siblings, 0 replies; 4+ messages in thread
From: Ulf Hansson @ 2021-03-08 11:32 UTC (permalink / raw)
  To: Kiwoong Kim; +Cc: linux-mmc

On Thu, 4 Mar 2021 at 08:43, Kiwoong Kim <kwmad.kim@samsung.com> wrote:
>
> > > This is what had actually happened and was fixed with some code in
> > commercial products.
> >
> > The above code in the mmc core was introduced around kernel v3.11, even if
> > it has been fine tuned since then.
> >
> > Maybe you have been using even older kernels?
> >
> Dear Uffe
>
> First, you give me what I want.
> We've used higher versions than 3.11 but applied our own changes for some reasons.
> Anyway, thanks !
>
> That is the first problem for me on SD.
> The 2nd thing is very long latency issue for a race between an IO thread and a kworker to run mmc_rescan.
>
> There is an application to put many IO requests to a SD card right after completion of system resume.
> Current MMC stack invokes mmc_rescan is invoked asynchronously for PM_POST_SUSPEND.
> As reported to me, however, there could be a race between an IO thread and the kworker for mmc_rescan
> especially the function of mmc_rescan is run later than expected and the application mentioned before is installed.
>
> For a series of IO requests, mmc_rescan, particularily at __mmc_claim_host called in mmc_sd_detect,
> doesn't acquire a host for longer than expected.
> Below is the call stacks shown after the symptom happened and the system tried to enter into suspend again.
> In this case, mmc pm notifier is called with PM_SUSPEND_PREPARE, so it waits for completion or cancelling the work for mmc_rescan.
> For the latency, users can see black screen for a long time sometimes.
>
> So I want to post a patch not to do _mmc_detect_change conditionally
> because it helps remove the race and the case assumes SD card initialization is already done.
> If you have your different views, please let me know.

This is getting hard to discuss, as you are bringing up several
different things in the same email thread.

Please repost this as a separate bug-report to continue the discussion there.

Kind regards
Uffe

>
> Thanks.
>
> --
> <6>[ 3965.259816] I[0:      swapper/0:    0]    22631        0      227    3902403994884 D(2)   3  ffffffc0007ee338                0  ffffffc85678e000 *    kworker/u16:4 [__mmc_claim_host]
> <6>[ 3965.259839] I[0:      swapper/0:    0] Workqueue: kmmcd mmc_rescan
> <0>[ 3965.259854] I[0:      swapper/0:    0] Call trace:
> <4>[ 3965.259870] I[0:      swapper/0:    0] [<ffffffc00013e674>] __switch_to+0x80/0x90
> <4>[ 3965.259886] I[0:      swapper/0:    0] [<ffffffc000b137f4>] __schedule+0x530/0x76c
> <4>[ 3965.259902] I[0:      swapper/0:    0] [<ffffffc000b13a9c>] schedule+0x6c/0x7c
> <4>[ 3965.259919] I[0:      swapper/0:    0] [<ffffffc0007ee338>] __mmc_claim_host+0xb8/0x188
> <4>[ 3965.259937] I[0:      swapper/0:    0] [<ffffffc0007eebfc>] mmc_get_card+0x24/0x38
> <4>[ 3965.259956] I[0:      swapper/0:    0] [<ffffffc0007f5c44>] mmc_sd_detect+0x90/0xe8
> <4>[ 3965.259973] I[0:      swapper/0:    0] [<ffffffc0007f08d8>] mmc_rescan+0xa0/0x2ec
> <4>[ 3965.259991] I[0:      swapper/0:    0] [<ffffffc0001688e0>] process_one_work+0x26c/0x434
> <4>[ 3965.260008] I[0:      swapper/0:    0] [<ffffffc000168dc8>] worker_thread+0x320/0x444
> <4>[ 3965.260026] I[0:      swapper/0:    0] [<ffffffc00016dac0>] kthread+0xdc/0xec
> ..
> <0>[ 3965.259854] I[0:      swapper/0:    0] Call trace:
> <4>[ 3965.259870] I[0:      swapper/0:    0] [<ffffffc00013e674>] __switch_to+0x80/0x90
> <4>[ 3965.259886] I[0:      swapper/0:    0] [<ffffffc000b137f4>] __schedule+0x530/0x76c
> <4>[ 3965.259902] I[0:      swapper/0:    0] [<ffffffc000b13a9c>] schedule+0x6c/0x7c
> <4>[ 3965.259919] I[0:      swapper/0:    0] [<ffffffc0007ee338>] __mmc_claim_host+0xb8/0x188
> <4>[ 3965.259937] I[0:      swapper/0:    0] [<ffffffc0007eebfc>] mmc_get_card+0x24/0x38
> <4>[ 3965.259956] I[0:      swapper/0:    0] [<ffffffc0007f5c44>] mmc_sd_detect+0x90/0xe8
> <4>[ 3965.259973] I[0:      swapper/0:    0] [<ffffffc0007f08d8>] mmc_rescan+0xa0/0x2ec
> <4>[ 3965.259991] I[0:      swapper/0:    0] [<ffffffc0001688e0>] process_one_work+0x26c/0x434
> <4>[ 3965.260008] I[0:      swapper/0:    0] [<ffffffc000168dc8>] worker_thread+0x320/0x444
> <4>[ 3965.260026] I[0:      swapper/0:    0] [<ffffffc00016dac0>] kthread+0xdc/0xec
> ..
> <0>[ 3965.203379] I[0:      swapper/0:    0] Call trace:
> <4>[ 3965.203397] I[0:      swapper/0:    0] [<ffffffc00013e674>] __switch_to+0x80/0x90
> <4>[ 3965.203414] I[0:      swapper/0:    0] [<ffffffc000b137f4>] __schedule+0x530/0x76c
> <4>[ 3965.203430] I[0:      swapper/0:    0] [<ffffffc000b13a9c>] schedule+0x6c/0x7c
> <4>[ 3965.203448] I[0:      swapper/0:    0] [<ffffffc000b160e8>] schedule_timeout+0x28/0x214
> <4>[ 3965.203464] I[0:      swapper/0:    0] [<ffffffc000b145a0>] wait_for_common+0x114/0x15c
> <4>[ 3965.203482] I[0:      swapper/0:    0] [<ffffffc000b14710>] wait_for_completion+0x10/0x20
> <4>[ 3965.203498] I[0:      swapper/0:    0] [<ffffffc000169990>] flush_work+0xf0/0x11c
> <4>[ 3965.203516] I[0:      swapper/0:    0] [<ffffffc000169ad0>] __cancel_work_timer+0x114/0x1a0
> <4>[ 3965.203533] I[0:      swapper/0:    0] [<ffffffc000169c44>] cancel_delayed_work_sync+0xc/0x1c
> <4>[ 3965.203554] I[0:      swapper/0:    0] [<ffffffc0007f1000>] mmc_pm_notify+0x78/0x12c
> <4>[ 3965.203573] I[0:      swapper/0:    0] [<ffffffc00016ebf4>] notifier_call_chain+0x7c/0xec
> <4>[ 3965.203590] I[0:      swapper/0:    0] [<ffffffc00016ef08>] __blocking_notifier_call_chain+0x44/0x68
> <4>[ 3965.203608] I[0:      swapper/0:    0] [<ffffffc00016ef3c>] blocking_notifier_call_chain+0x10/0x20
> <4>[ 3965.203628] I[0:      swapper/0:    0] [<ffffffc0001964ec>] pm_notifier_call_chain+0x1c/0x44
> <4>[ 3965.203644] I[0:      swapper/0:    0] [<ffffffc000197ad0>] pm_suspend+0x2e0/0x5fc
> <4>[ 3965.203662] I[0:      swapper/0:    0] [<ffffffc0001961cc>] state_store+0x4c/0x8c
> <4>[ 3965.203683] I[0:      swapper/0:    0] [<ffffffc0003f35ec>] kobj_attr_store+0x14/0x2c
> <4>[ 3965.203703] I[0:      swapper/0:    0] [<ffffffc0002aac2c>] sysfs_kf_write+0x40/0x50
> <4>[ 3965.203721] I[0:      swapper/0:    0] [<ffffffc0002aa000>] kernfs_fop_write+0xfc/0x148
> <4>[ 3965.203739] I[0:      swapper/0:    0] [<ffffffc000249b4c>] vfs_write+0xb8/0x190
> <4>[ 3965.203755] I[0:      swapper/0:    0] [<ffffffc000249cf0>] SyS_write+0x44/0x88
>

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

end of thread, other threads:[~2021-03-08 11:33 UTC | newest]

Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
     [not found] <CGME20210303092222epcas2p11fbb2697a53b54dbc138d741893c9f07@epcas2p1.samsung.com>
2021-03-03  9:22 ` About SD initialization at resume time Kiwoong Kim
2021-03-03 11:42   ` Ulf Hansson
2021-03-04  7:43     ` Kiwoong Kim
2021-03-08 11:32       ` Ulf Hansson

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.