On Thu, 4 Mar 2021 at 08:43, Kiwoong Kim <kwmad.kim@xxxxxxxxxxx> 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 >
