| Message ID | 20230217194423.42553-1-athierry@redhat.com |
|---|---|
| State | New |
| Headers | show |
| Series | [v3] scsi: ufs: initialize devfreq synchronously | expand |
On 2/17/23 11:44, Adrien Thierry wrote: > During ufs initialization, devfreq initialization is asynchronous: > ufshcd_async_scan() calls ufshcd_add_lus(), which in turn initializes > devfreq for ufs. The simple ondemand governor is then loaded. If it is > built as a module, request_module() is called and throws a warning: Reviewed-by: Bart Van Assche <bvanassche@acm.org>
Adrien, > During ufs initialization, devfreq initialization is asynchronous: > ufshcd_async_scan() calls ufshcd_add_lus(), which in turn initializes > devfreq for ufs. The simple ondemand governor is then loaded. If it is > built as a module, request_module() is called and throws a warning: Applied to 6.3/scsi-staging, thanks!
Hi Stanley, On Wed, Mar 29, 2023 at 04:39:30PM +0800, Stanley Chu wrote: > Hi Adrien, > > On Sat, Feb 18, 2023 at 3:50 AM Adrien Thierry <athierry@redhat.com> wrote: > > > > During ufs initialization, devfreq initialization is asynchronous: > > ufshcd_async_scan() calls ufshcd_add_lus(), which in turn initializes > > devfreq for ufs. The simple ondemand governor is then loaded. If it is > > built as a module, request_module() is called and throws a warning: > > > > WARNING: CPU: 7 PID: 167 at kernel/kmod.c:136 __request_module+0x1e0/0x460 > > Modules linked in: crct10dif_ce llcc_qcom phy_qcom_qmp_usb ufs_qcom phy_qcom_snps_femto_v2 ufshcd_pltfrm phy_qcom_qmp_combo ufshcd_core phy_qcom_qmp_ufs qcom_wdt socinfo fuse ipv6 > > CPU: 7 PID: 167 Comm: kworker/u16:3 Not tainted 6.2.0-rc6-00009-g58706f7fb045 #1 > > Hardware name: Qualcomm SA8540P Ride (DT) > > Workqueue: events_unbound async_run_entry_fn > > pstate: 00400005 (nzcv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--) > > pc : __request_module+0x1e0/0x460 > > lr : __request_module+0x1d8/0x460 > > sp : ffff800009323b90 > > x29: ffff800009323b90 x28: 0000000000000000 x27: 0000000000000000 > > x26: ffff800009323d50 x25: ffff7b9045f57810 x24: ffff7b9045f57830 > > x23: ffffdc5a83e426e8 x22: ffffdc5ae80a9818 x21: 0000000000000001 > > x20: ffffdc5ae7502f98 x19: ffff7b9045f57800 x18: ffffffffffffffff > > x17: 312f716572667665 x16: 642f7366752e3030 x15: 0000000000000000 > > x14: 000000000000021c x13: 0000000000005400 x12: ffff7b9042ed7614 > > x11: ffff7b9042ed7600 x10: 00000000636c0890 x9 : 0000000000000038 > > x8 : ffff7b9045f2c880 x7 : ffff7b9045f57c68 x6 : 0000000000000080 > > x5 : 0000000000000000 x4 : 8000000000000000 x3 : 0000000000000000 > > x2 : 0000000000000000 x1 : ffffdc5ae5d382f0 x0 : 0000000000000001 > > Call trace: > > __request_module+0x1e0/0x460 > > try_then_request_governor+0x7c/0x100 > > devfreq_add_device+0x4b0/0x5fc > > ufshcd_async_scan+0x1d4/0x310 [ufshcd_core] > > async_run_entry_fn+0x34/0xe0 > > process_one_work+0x1d0/0x320 > > worker_thread+0x14c/0x444 > > kthread+0x10c/0x110 > > ret_from_fork+0x10/0x20 > > > > This occurs because synchronous module loading from async is not > > allowed. According to __request_module(): > > > > /* > > * We don't allow synchronous module loading from async. Module > > * init may invoke async_synchronize_full() which will end up > > * waiting for this task which already is waiting for the module > > * loading to complete, leading to a deadlock. > > */ > > > > I experienced such a deadlock on the Qualcomm QDrive3/sa8540p-ride. With > > DEVFREQ_GOV_SIMPLE_ONDEMAND=m, the boot hangs after the warning. > > > > This patch fixes both the warning and the deadlock, by moving devfreq > > initialization out of the async routine. > > > > I tested this on the sa8540p-ride by using fio to put the UFS under > > load, and printing the trace generated by > > /sys/kernel/tracing/events/ufs/ufshcd_clk_scaling events. The trace > > looks similar with and without the change. > > > > Signed-off-by: Adrien Thierry <athierry@redhat.com> > > --- > > v3: Addressed Bart's comments > > v2: Addressed Bart's comments > > > > drivers/ufs/core/ufshcd.c | 47 ++++++++++++++++++++++++++------------- > > include/ufs/ufshcd.h | 1 + > > 2 files changed, 32 insertions(+), 16 deletions(-) > > > > diff --git a/drivers/ufs/core/ufshcd.c b/drivers/ufs/core/ufshcd.c > > index 3a1c4d31e010..2c22a1367440 100644 > > --- a/drivers/ufs/core/ufshcd.c > > +++ b/drivers/ufs/core/ufshcd.c > > @@ -1357,6 +1357,13 @@ static int ufshcd_devfreq_target(struct device *dev, > > struct ufs_clk_info *clki; > > unsigned long irq_flags; > > > > + /* > > + * Skip devfreq if ufs initialization is not finished. > > + * Otherwise ufs could be in a inconsistent state. > > + */ > > + if (!smp_load_acquire(&hba->logical_unit_scan_finished)) > > + return 0; > > + > > if (!ufshcd_is_clkscaling_supported(hba)) > > return -EINVAL; > > > > @@ -8136,22 +8143,6 @@ static int ufshcd_add_lus(struct ufs_hba *hba) > > if (ret) > > goto out; > > > > - /* Initialize devfreq after UFS device is detected */ > > - if (ufshcd_is_clkscaling_supported(hba)) { > > - memcpy(&hba->clk_scaling.saved_pwr_info.info, > > - &hba->pwr_info, > > - sizeof(struct ufs_pa_layer_attr)); > > - hba->clk_scaling.saved_pwr_info.is_valid = true; > > - hba->clk_scaling.is_allowed = true; > > - > > - ret = ufshcd_devfreq_init(hba); > > - if (ret) > > - goto out; > > - > > - hba->clk_scaling.is_enabled = true; > > - ufshcd_init_clk_scaling_sysfs(hba); > > - } > > - > > ufs_bsg_probe(hba); > > ufshpb_init(hba); > > scsi_scan_host(hba->host); > > @@ -8290,6 +8281,12 @@ static void ufshcd_async_scan(void *data, async_cookie_t cookie) > > if (ret) { > > pm_runtime_put_sync(hba->dev); > > ufshcd_hba_exit(hba); > > + } else { > > + /* > > + * Make sure that when reader code sees ufs initialization has finished, > > + * all initialization steps have really been executed. > > + */ > > + smp_store_release(&hba->logical_unit_scan_finished, true); > > } > > } > > > > @@ -9896,12 +9893,30 @@ int ufshcd_init(struct ufs_hba *hba, void __iomem *mmio_base, unsigned int irq) > > */ > > ufshcd_set_ufs_dev_active(hba); > > > > + /* Initialize devfreq */ > > + if (ufshcd_is_clkscaling_supported(hba)) { > > + memcpy(&hba->clk_scaling.saved_pwr_info.info, > > + &hba->pwr_info, > > + sizeof(struct ufs_pa_layer_attr)); > > Here, hba->pwr_info is not initialized yet, so > hba->clk_scaling.saved_pwr_info will also have uninitialized values. > This is logically incorrect. > > First of all, hba->saved_pwr_info is originally designed to keep the > "scaled-up" gear. This statement breaks it. > > In addition, the incorrect hba->save_pwr_info may cause serious issues > in ufshcd_scale_gear(), as power mode changes will fail due to > incorrect "new_pwr_info". > > Could you please revert this patch first and then upload a fixed one? Thanks for pointing that out. I also realized today that the patch introduces a devfreq warning: "devfreq 1d84000.ufs: Couldn't update frequency transition information". So I'm going to post a revert and take the time to come up with an improved solution that fixes both issues. Best, Adrien
diff --git a/drivers/ufs/core/ufshcd.c b/drivers/ufs/core/ufshcd.c index 3a1c4d31e010..2c22a1367440 100644 --- a/drivers/ufs/core/ufshcd.c +++ b/drivers/ufs/core/ufshcd.c @@ -1357,6 +1357,13 @@ static int ufshcd_devfreq_target(struct device *dev, struct ufs_clk_info *clki; unsigned long irq_flags; + /* + * Skip devfreq if ufs initialization is not finished. + * Otherwise ufs could be in a inconsistent state. + */ + if (!smp_load_acquire(&hba->logical_unit_scan_finished)) + return 0; + if (!ufshcd_is_clkscaling_supported(hba)) return -EINVAL; @@ -8136,22 +8143,6 @@ static int ufshcd_add_lus(struct ufs_hba *hba) if (ret) goto out; - /* Initialize devfreq after UFS device is detected */ - if (ufshcd_is_clkscaling_supported(hba)) { - memcpy(&hba->clk_scaling.saved_pwr_info.info, - &hba->pwr_info, - sizeof(struct ufs_pa_layer_attr)); - hba->clk_scaling.saved_pwr_info.is_valid = true; - hba->clk_scaling.is_allowed = true; - - ret = ufshcd_devfreq_init(hba); - if (ret) - goto out; - - hba->clk_scaling.is_enabled = true; - ufshcd_init_clk_scaling_sysfs(hba); - } - ufs_bsg_probe(hba); ufshpb_init(hba); scsi_scan_host(hba->host); @@ -8290,6 +8281,12 @@ static void ufshcd_async_scan(void *data, async_cookie_t cookie) if (ret) { pm_runtime_put_sync(hba->dev); ufshcd_hba_exit(hba); + } else { + /* + * Make sure that when reader code sees ufs initialization has finished, + * all initialization steps have really been executed. + */ + smp_store_release(&hba->logical_unit_scan_finished, true); } } @@ -9896,12 +9893,30 @@ int ufshcd_init(struct ufs_hba *hba, void __iomem *mmio_base, unsigned int irq) */ ufshcd_set_ufs_dev_active(hba); + /* Initialize devfreq */ + if (ufshcd_is_clkscaling_supported(hba)) { + memcpy(&hba->clk_scaling.saved_pwr_info.info, + &hba->pwr_info, + sizeof(struct ufs_pa_layer_attr)); + hba->clk_scaling.saved_pwr_info.is_valid = true; + hba->clk_scaling.is_allowed = true; + + err = ufshcd_devfreq_init(hba); + if (err) + goto rpm_put_sync; + + hba->clk_scaling.is_enabled = true; + ufshcd_init_clk_scaling_sysfs(hba); + } + async_schedule(ufshcd_async_scan, hba); ufs_sysfs_add_nodes(hba->dev); device_enable_async_suspend(dev); return 0; +rpm_put_sync: + pm_runtime_put_sync(dev); free_tmf_queue: blk_mq_destroy_queue(hba->tmf_queue); blk_put_queue(hba->tmf_queue); diff --git a/include/ufs/ufshcd.h b/include/ufs/ufshcd.h index 727084cd79be..941ede501367 100644 --- a/include/ufs/ufshcd.h +++ b/include/ufs/ufshcd.h @@ -896,6 +896,7 @@ struct ufs_hba { struct completion *uic_async_done; enum ufshcd_state ufshcd_state; + bool logical_unit_scan_finished; u32 eh_flags; u32 intr_mask; u16 ee_ctrl_mask;
During ufs initialization, devfreq initialization is asynchronous: ufshcd_async_scan() calls ufshcd_add_lus(), which in turn initializes devfreq for ufs. The simple ondemand governor is then loaded. If it is built as a module, request_module() is called and throws a warning: WARNING: CPU: 7 PID: 167 at kernel/kmod.c:136 __request_module+0x1e0/0x460 Modules linked in: crct10dif_ce llcc_qcom phy_qcom_qmp_usb ufs_qcom phy_qcom_snps_femto_v2 ufshcd_pltfrm phy_qcom_qmp_combo ufshcd_core phy_qcom_qmp_ufs qcom_wdt socinfo fuse ipv6 CPU: 7 PID: 167 Comm: kworker/u16:3 Not tainted 6.2.0-rc6-00009-g58706f7fb045 #1 Hardware name: Qualcomm SA8540P Ride (DT) Workqueue: events_unbound async_run_entry_fn pstate: 00400005 (nzcv daif +PAN -UAO -TCO -DIT -SSBS BTYPE=--) pc : __request_module+0x1e0/0x460 lr : __request_module+0x1d8/0x460 sp : ffff800009323b90 x29: ffff800009323b90 x28: 0000000000000000 x27: 0000000000000000 x26: ffff800009323d50 x25: ffff7b9045f57810 x24: ffff7b9045f57830 x23: ffffdc5a83e426e8 x22: ffffdc5ae80a9818 x21: 0000000000000001 x20: ffffdc5ae7502f98 x19: ffff7b9045f57800 x18: ffffffffffffffff x17: 312f716572667665 x16: 642f7366752e3030 x15: 0000000000000000 x14: 000000000000021c x13: 0000000000005400 x12: ffff7b9042ed7614 x11: ffff7b9042ed7600 x10: 00000000636c0890 x9 : 0000000000000038 x8 : ffff7b9045f2c880 x7 : ffff7b9045f57c68 x6 : 0000000000000080 x5 : 0000000000000000 x4 : 8000000000000000 x3 : 0000000000000000 x2 : 0000000000000000 x1 : ffffdc5ae5d382f0 x0 : 0000000000000001 Call trace: __request_module+0x1e0/0x460 try_then_request_governor+0x7c/0x100 devfreq_add_device+0x4b0/0x5fc ufshcd_async_scan+0x1d4/0x310 [ufshcd_core] async_run_entry_fn+0x34/0xe0 process_one_work+0x1d0/0x320 worker_thread+0x14c/0x444 kthread+0x10c/0x110 ret_from_fork+0x10/0x20 This occurs because synchronous module loading from async is not allowed. According to __request_module(): /* * We don't allow synchronous module loading from async. Module * init may invoke async_synchronize_full() which will end up * waiting for this task which already is waiting for the module * loading to complete, leading to a deadlock. */ I experienced such a deadlock on the Qualcomm QDrive3/sa8540p-ride. With DEVFREQ_GOV_SIMPLE_ONDEMAND=m, the boot hangs after the warning. This patch fixes both the warning and the deadlock, by moving devfreq initialization out of the async routine. I tested this on the sa8540p-ride by using fio to put the UFS under load, and printing the trace generated by /sys/kernel/tracing/events/ufs/ufshcd_clk_scaling events. The trace looks similar with and without the change. Signed-off-by: Adrien Thierry <athierry@redhat.com> --- v3: Addressed Bart's comments v2: Addressed Bart's comments drivers/ufs/core/ufshcd.c | 47 ++++++++++++++++++++++++++------------- include/ufs/ufshcd.h | 1 + 2 files changed, 32 insertions(+), 16 deletions(-)