* 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@vger.kernel.org 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@vger.kernel.org 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 a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox