On Mon, Mar 8, 2021 at 5:21 PM Rafael J. Wysocki <rafael@xxxxxxxxxx> wrote:
>
> On Sat, Mar 6, 2021 at 5:17 PM Alan Stern <stern@xxxxxxxxxxxxxxxxxxx> wrote:
> >
> > On Fri, Mar 05, 2021 at 06:54:24PM -0800, Asutosh Das (asd) wrote:
> >
> > > Now during my testing I see a weird issue sometimes (1 in 7).
> > > Scenario - bootups
> > >
> > > Issue:
> > > The supplier 'ufs_device_wlun 0:0:0:49488' goes into runtime suspend even
> > > when one/more of its consumers are in RPM_ACTIVE state.
> > >
> > > *Log:
> > > [ 10.056379][ T206] sd 0:0:0:1: [sdb] Synchronizing SCSI cache
> > > [ 10.062497][ T113] sd 0:0:0:5: [sdf] Synchronizing SCSI cache
> > > [ 10.356600][ T32] sd 0:0:0:7: [sdh] Synchronizing SCSI cache
> > > [ 10.362944][ T174] sd 0:0:0:3: [sdd] Synchronizing SCSI cache
> > > [ 10.696627][ T83] sd 0:0:0:2: [sdc] Synchronizing SCSI cache
> > > [ 10.704562][ T170] sd 0:0:0:6: [sdg] Synchronizing SCSI cache
> > > [ 10.980602][ T5] sd 0:0:0:0: [sda] Synchronizing SCSI cache
> > >
> > > /** Printing all the consumer nodes of supplier **/
> > > [ 10.987327][ T5] ufs_device_wlun 0:0:0:49488: usage-count @ suspend: 0
> > > <-- this is the usage_count
> > > [ 10.994440][ T5] ufs_rpmb_wlun 0:0:0:49476: PM state - 2
> > > [ 11.000402][ T5] scsi 0:0:0:49456: PM state - 2
> > > [ 11.005453][ T5] sd 0:0:0:0: PM state - 2
> > > [ 11.009958][ T5] sd 0:0:0:1: PM state - 2
> > > [ 11.014469][ T5] sd 0:0:0:2: PM state - 2
> > > [ 11.019072][ T5] sd 0:0:0:3: PM state - 2
> > > [ 11.023595][ T5] sd 0:0:0:4: PM state - 0 << RPM_ACTIVE
> > > [ 11.353298][ T5] sd 0:0:0:5: PM state - 2
> > > [ 11.357726][ T5] sd 0:0:0:6: PM state - 2
> > > [ 11.362155][ T5] sd 0:0:0:7: PM state - 2
> > > [ 11.366584][ T5] ufshcd-qcom 1d84000.ufshc: __ufshcd_wl_suspend - 8709
> > > [ 11.374366][ T5] ufs_device_wlun 0:0:0:49488: __ufshcd_wl_suspend -
> > > (0) has rpm_active flags
>
> Do you mean that rpm_active of the link between the consumer and the
> supplier is greater than 0 at this point and the consumer is
I mean is rpm_active of the link greater than 1 (because 1 means "no
active references to the supplier")?
> RPM_ACTIVE, but the supplier suspends successfully nevertheless?
>
> > > [ 11.383376][ T5] ufs_device_wlun 0:0:0:49488:
> > > ufshcd_wl_runtime_suspend <-- Supplier suspends fine.
> > > [ 12.977318][ T174] sd 0:0:0:4: [sde] Synchronizing SCSI cache
> > >
> > > And the the suspend of sde is stuck now:
> > > schedule+0x9c/0xe0
> > > schedule_timeout+0x40/0x128
> > > io_schedule_timeout+0x44/0x68
> > > wait_for_common_io+0x7c/0x100
> > > wait_for_completion_io+0x14/0x20
> > > blk_execute_rq+0x90/0xcc
> > > __scsi_execute+0x104/0x1c4
> > > sd_sync_cache+0xf8/0x2a0
> > > sd_suspend_common+0x74/0x11c
> > > sd_suspend_runtime+0x14/0x20
> > > scsi_runtime_suspend+0x64/0x94
> > > __rpm_callback+0x80/0x2a4
> > > rpm_suspend+0x308/0x614
> > > pm_runtime_work+0x98/0xa8
> > >
> > > I added 'DL_FLAG_RPM_ACTIVE' while creating links.
> > > if (hba->sdev_ufs_device) {
> > > link = device_link_add(&sdev->sdev_gendev,
> > > &hba->sdev_ufs_device->sdev_gendev,
> > > DL_FLAG_PM_RUNTIME|DL_FLAG_RPM_ACTIVE);
> > > I didn't expect this to resolve the issue anyway and it didn't.
> > >
> > > Another interesting point here is when I resume any of the above suspended
> > > consumers, it all goes back to normal, which is kind of expected. I tried
> > > resuming the consumer and the supplier is resumed and the supplier is
> > > suspended when all the consumers are suspended.
> > >
> > > Any pointers on this issue please?
> > >
> > > @Bart/@Alan - Do you've any pointers please?
> >
> > It's very noticeable that although you seem to have isolated a bug in
> > the power management subsystem (supplier goes into runtime suspend
> > even when one of its consumers is still active), you did not CC the
> > power management maintainer or mailing list.
> >
> > I have added the appropriate CC's.
>
> Thanks Alan!
