2019-03-12 05:37:05

by Jisheng Zhang

[permalink] [raw]
Subject: kernel 5.0 blk_clear_pm_only triggers a warning during resume

Hi,

kernel version: 5.0

I got below warning during resume:

[ 673.658888] sd 0:0:0:0: [sda] Starting disk
[ 673.658899] WARNING: CPU: 3 PID: 1039 at blk_clear_pm_only+0x2a/0x30
[ 673.658902] CPU: 3 PID: 1039 Comm: kworker/u8:49 Not tainted 5.0.0+ #1
[ 673.658902] sd 2:0:0:0: [sdb] Starting disk
[ 673.658903] Hardware name: LENOVO 4180F42/4180F42, BIOS 83ET75WW (1.45 ) 05/10/2013
[ 673.658906] Workqueue: events_unbound async_run_entry_fn
[ 673.658909] RIP: 0010:blk_clear_pm_only+0x2a/0x30
[ 673.658911] Code: b8 ff ff ff ff f0 0f c1 87 80 00 00 00 83 e8 01 78 18 74 01 c3 48 81 c7 58 05 00 00 31 c9 31 d2 be 03 00 00 00 e9 36 97 e2 ff <0f> 0b c3 0f 1f 00 48 81 c7 90 00 00 00 e9 04 01 3a 00 0f 1f 40 00
[ 673.658911] RSP: 0000:ffff8881115a7e48 EFLAGS: 00010297
[ 673.658913] RAX: 00000000ffffffff RBX: ffff888118d42800 RCX: ffff8881194c9a00
[ 673.658914] RDX: ffff888118ab1a00 RSI: 0000000000000000 RDI: ffff888117e70000
[ 673.658915] RBP: ffff888118d42f90 R08: 0000000000000004 R09: 000000000001f900
[ 673.658915] R10: 0000000045698a8e R11: 0000000000000010 R12: ffff888119421000
[ 673.658916] R13: 0000000000000000 R14: ffff88800030ea80 R15: 0ffff88811942100
[ 673.658918] FS: 0000000000000000(0000) GS:ffff88811a180000(0000) knlGS:0000000000000000
[ 673.658918] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 673.658919] CR2: 0000000000000000 CR3: 000000000200c001 CR4: 00000000000606e0
[ 673.658920] Call Trace:
[ 673.658924] ? scsi_device_resume+0x28/0x50
[ 673.658926] ? scsi_dev_type_resume+0x2b/0x80
[ 673.658927] ? async_run_entry_fn+0x2c/0xd0
[ 673.658930] ? process_one_work+0x1f0/0x3f0
[ 673.658932] ? worker_thread+0x28/0x3c0
[ 673.658933] ? process_one_work+0x3f0/0x3f0
[ 673.658935] ? kthread+0x10c/0x130
[ 673.658936] ? __kthread_create_on_node+0x150/0x150
[ 673.658938] ? ret_from_fork+0x1f/0x30
[ 673.658940] ---[ end trace ce18772de33e283e ]---


I notice that commit 388b4e6a00bb3 ("scsi: core: Avoid that system resume
triggers a kernel warning") tried to fix the warning in the same code path
perhaps, it isn't enough.

Thanks


2019-03-12 14:15:09

by Jens Axboe

[permalink] [raw]
Subject: Re: kernel 5.0 blk_clear_pm_only triggers a warning during resume

On 3/11/19 11:35 PM, Jisheng Zhang wrote:
> Hi,
>
> kernel version: 5.0
>
> I got below warning during resume:
>
> [ 673.658888] sd 0:0:0:0: [sda] Starting disk
> [ 673.658899] WARNING: CPU: 3 PID: 1039 at blk_clear_pm_only+0x2a/0x30
> [ 673.658902] CPU: 3 PID: 1039 Comm: kworker/u8:49 Not tainted 5.0.0+ #1
> [ 673.658902] sd 2:0:0:0: [sdb] Starting disk
> [ 673.658903] Hardware name: LENOVO 4180F42/4180F42, BIOS 83ET75WW (1.45 ) 05/10/2013
> [ 673.658906] Workqueue: events_unbound async_run_entry_fn
> [ 673.658909] RIP: 0010:blk_clear_pm_only+0x2a/0x30
> [ 673.658911] Code: b8 ff ff ff ff f0 0f c1 87 80 00 00 00 83 e8 01 78 18 74 01 c3 48 81 c7 58 05 00 00 31 c9 31 d2 be 03 00 00 00 e9 36 97 e2 ff <0f> 0b c3 0f 1f 00 48 81 c7 90 00 00 00 e9 04 01 3a 00 0f 1f 40 00
> [ 673.658911] RSP: 0000:ffff8881115a7e48 EFLAGS: 00010297
> [ 673.658913] RAX: 00000000ffffffff RBX: ffff888118d42800 RCX: ffff8881194c9a00
> [ 673.658914] RDX: ffff888118ab1a00 RSI: 0000000000000000 RDI: ffff888117e70000
> [ 673.658915] RBP: ffff888118d42f90 R08: 0000000000000004 R09: 000000000001f900
> [ 673.658915] R10: 0000000045698a8e R11: 0000000000000010 R12: ffff888119421000
> [ 673.658916] R13: 0000000000000000 R14: ffff88800030ea80 R15: 0ffff88811942100
> [ 673.658918] FS: 0000000000000000(0000) GS:ffff88811a180000(0000) knlGS:0000000000000000
> [ 673.658918] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [ 673.658919] CR2: 0000000000000000 CR3: 000000000200c001 CR4: 00000000000606e0
> [ 673.658920] Call Trace:
> [ 673.658924] ? scsi_device_resume+0x28/0x50
> [ 673.658926] ? scsi_dev_type_resume+0x2b/0x80
> [ 673.658927] ? async_run_entry_fn+0x2c/0xd0
> [ 673.658930] ? process_one_work+0x1f0/0x3f0
> [ 673.658932] ? worker_thread+0x28/0x3c0
> [ 673.658933] ? process_one_work+0x3f0/0x3f0
> [ 673.658935] ? kthread+0x10c/0x130
> [ 673.658936] ? __kthread_create_on_node+0x150/0x150
> [ 673.658938] ? ret_from_fork+0x1f/0x30
> [ 673.658940] ---[ end trace ce18772de33e283e ]---
>
>
> I notice that commit 388b4e6a00bb3 ("scsi: core: Avoid that system resume
> triggers a kernel warning") tried to fix the warning in the same code path
> perhaps, it isn't enough.

Adding Bart, the author of the patch you are referring to.

--
Jens Axboe


2019-03-12 14:59:08

by Bart Van Assche

[permalink] [raw]
Subject: Re: kernel 5.0 blk_clear_pm_only triggers a warning during resume

On Tue, 2019-03-12 at 05:35 +-0000, Jisheng Zhang wrote:
+AD4 I got below warning during resume:
+AD4
+AD4 +AFs 673.658888+AF0 sd 0:0:0:0: +AFs-sda+AF0 Starting disk
+AD4 +AFs 673.658899+AF0 WARNING: CPU: 3 PID: 1039 at blk+AF8-clear+AF8-pm+AF8-only+-0x2a/0x30
+AD4 +AFs 673.658902+AF0 CPU: 3 PID: 1039 Comm: kworker/u8:49 Not tainted 5.0.0+- +ACM-1
+AD4 +AFs 673.658902+AF0 sd 2:0:0:0: +AFs-sdb+AF0 Starting disk
+AD4 +AFs 673.658903+AF0 Hardware name: LENOVO 4180F42/4180F42, BIOS 83ET75WW (1.45 ) 05/10/2013
+AD4 +AFs 673.658906+AF0 Workqueue: events+AF8-unbound async+AF8-run+AF8-entry+AF8-fn
+AD4 +AFs 673.658909+AF0 RIP: 0010:blk+AF8-clear+AF8-pm+AF8-only+-0x2a/0x30
+AD4 +AFs 673.658911+AF0 Code: b8 ff ff ff ff f0 0f c1 87 80 00 00 00 83 e8 01 78 18 74 01 c3 48 81 c7 58 05 00 00 31 c9 31 d2 be 03 00 00 00 e9 36 97 e2 ff +ADw-0f+AD4 0b c3 0f 1f 00 48 81 c7 90 00 00 00 e9 04 01
+AD4 3a 00 0f 1f 40 00
+AD4 +AFs 673.658911+AF0 RSP: 0000:ffff8881115a7e48 EFLAGS: 00010297
+AD4 +AFs 673.658913+AF0 RAX: 00000000ffffffff RBX: ffff888118d42800 RCX: ffff8881194c9a00
+AD4 +AFs 673.658914+AF0 RDX: ffff888118ab1a00 RSI: 0000000000000000 RDI: ffff888117e70000
+AD4 +AFs 673.658915+AF0 RBP: ffff888118d42f90 R08: 0000000000000004 R09: 000000000001f900
+AD4 +AFs 673.658915+AF0 R10: 0000000045698a8e R11: 0000000000000010 R12: ffff888119421000
+AD4 +AFs 673.658916+AF0 R13: 0000000000000000 R14: ffff88800030ea80 R15: 0ffff88811942100
+AD4 +AFs 673.658918+AF0 FS: 0000000000000000(0000) GS:ffff88811a180000(0000) knlGS:0000000000000000
+AD4 +AFs 673.658918+AF0 CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
+AD4 +AFs 673.658919+AF0 CR2: 0000000000000000 CR3: 000000000200c001 CR4: 00000000000606e0
+AD4 +AFs 673.658920+AF0 Call Trace:
+AD4 +AFs 673.658924+AF0 ? scsi+AF8-device+AF8-resume+-0x28/0x50
+AD4 +AFs 673.658926+AF0 ? scsi+AF8-dev+AF8-type+AF8-resume+-0x2b/0x80
+AD4 +AFs 673.658927+AF0 ? async+AF8-run+AF8-entry+AF8-fn+-0x2c/0xd0
+AD4 +AFs 673.658930+AF0 ? process+AF8-one+AF8-work+-0x1f0/0x3f0
+AD4 +AFs 673.658932+AF0 ? worker+AF8-thread+-0x28/0x3c0
+AD4 +AFs 673.658933+AF0 ? process+AF8-one+AF8-work+-0x3f0/0x3f0
+AD4 +AFs 673.658935+AF0 ? kthread+-0x10c/0x130
+AD4 +AFs 673.658936+AF0 ? +AF8AXw-kthread+AF8-create+AF8-on+AF8-node+-0x150/0x150
+AD4 +AFs 673.658938+AF0 ? ret+AF8-from+AF8-fork+-0x1f/0x30
+AD4 +AFs 673.658940+AF0 ---+AFs end trace ce18772de33e283e +AF0----

Hi Jisheng,

Is this something that occurred once or is this something that you can reproduce
easily? In the latter case, can you verify whether the patch below is sufficient
to make this warning disappear?

Thanks,

Bart.

---
drivers/scsi/scsi+AF8-lib.c +AHw 6 +-+-+-+---
1 file changed, 4 insertions(+-), 2 deletions(-)

diff --git a/drivers/scsi/scsi+AF8-lib.c b/drivers/scsi/scsi+AF8-lib.c
index f3f24dfd8fd5..33e1a72d47fa 100644
--- a/drivers/scsi/scsi+AF8-lib.c
+-+-+- b/drivers/scsi/scsi+AF8-lib.c
+AEAAQA -2540,8 +-2540,10 +AEAAQA void scsi+AF8-device+AF8-resume(struct scsi+AF8-device +ACo-sdev)
+ACo device deleted during suspend)
+ACo-/
mutex+AF8-lock(+ACY-sdev-+AD4-state+AF8-mutex)+ADs
- sdev-+AD4-quiesced+AF8-by +AD0 NULL+ADs
- blk+AF8-clear+AF8-pm+AF8-only(sdev-+AD4-request+AF8-queue)+ADs
+- if (sdev-+AD4-quiesced+AF8-by) +AHs
+- sdev-+AD4-quiesced+AF8-by +AD0 NULL+ADs
+- blk+AF8-clear+AF8-pm+AF8-only(sdev-+AD4-request+AF8-queue)+ADs
+- +AH0
if (sdev-+AD4-sdev+AF8-state +AD0APQ SDEV+AF8-QUIESCE)
scsi+AF8-device+AF8-set+AF8-state(sdev, SDEV+AF8-RUNNING)+ADs
mutex+AF8-unlock(+ACY-sdev-+AD4-state+AF8-mutex)+ADs


2019-03-13 02:29:56

by Jisheng Zhang

[permalink] [raw]
Subject: Re: kernel 5.0 blk_clear_pm_only triggers a warning during resume


On Tue, 12 Mar 2019 07:58:19 -0700 Bart Van Assche wrote:

> CAUTION: Email originated externally, do not click links or open attachments unless you recognize the sender and know the content is safe.
>
>
> On Tue, 2019-03-12 at 05:35 +0000, Jisheng Zhang wrote:
> > I got below warning during resume:
> >
> > [ 673.658888] sd 0:0:0:0: [sda] Starting disk
> > [ 673.658899] WARNING: CPU: 3 PID: 1039 at blk_clear_pm_only+0x2a/0x30
> > [ 673.658902] CPU: 3 PID: 1039 Comm: kworker/u8:49 Not tainted 5.0.0+ #1
> > [ 673.658902] sd 2:0:0:0: [sdb] Starting disk
> > [ 673.658903] Hardware name: LENOVO 4180F42/4180F42, BIOS 83ET75WW (1.45 ) 05/10/2013
> > [ 673.658906] Workqueue: events_unbound async_run_entry_fn
> > [ 673.658909] RIP: 0010:blk_clear_pm_only+0x2a/0x30
> > [ 673.658911] Code: b8 ff ff ff ff f0 0f c1 87 80 00 00 00 83 e8 01 78 18 74 01 c3 48 81 c7 58 05 00 00 31 c9 31 d2 be 03 00 00 00 e9 36 97 e2 ff <0f> 0b c3 0f 1f 00 48 81 c7 90 00 00 00 e9 04 01
> > 3a 00 0f 1f 40 00
> > [ 673.658911] RSP: 0000:ffff8881115a7e48 EFLAGS: 00010297
> > [ 673.658913] RAX: 00000000ffffffff RBX: ffff888118d42800 RCX: ffff8881194c9a00
> > [ 673.658914] RDX: ffff888118ab1a00 RSI: 0000000000000000 RDI: ffff888117e70000
> > [ 673.658915] RBP: ffff888118d42f90 R08: 0000000000000004 R09: 000000000001f900
> > [ 673.658915] R10: 0000000045698a8e R11: 0000000000000010 R12: ffff888119421000
> > [ 673.658916] R13: 0000000000000000 R14: ffff88800030ea80 R15: 0ffff88811942100
> > [ 673.658918] FS: 0000000000000000(0000) GS:ffff88811a180000(0000) knlGS:0000000000000000
> > [ 673.658918] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > [ 673.658919] CR2: 0000000000000000 CR3: 000000000200c001 CR4: 00000000000606e0
> > [ 673.658920] Call Trace:
> > [ 673.658924] ? scsi_device_resume+0x28/0x50
> > [ 673.658926] ? scsi_dev_type_resume+0x2b/0x80
> > [ 673.658927] ? async_run_entry_fn+0x2c/0xd0
> > [ 673.658930] ? process_one_work+0x1f0/0x3f0
> > [ 673.658932] ? worker_thread+0x28/0x3c0
> > [ 673.658933] ? process_one_work+0x3f0/0x3f0
> > [ 673.658935] ? kthread+0x10c/0x130
> > [ 673.658936] ? __kthread_create_on_node+0x150/0x150
> > [ 673.658938] ? ret_from_fork+0x1f/0x30
> > [ 673.658940] ---[ end trace ce18772de33e283e ]---
>
> Hi Jisheng,

Hi Bart,

>
> Is this something that occurred once or is this something that you can reproduce

It's 100% reproduced on my home's laptop PC.

> easily? In the latter case, can you verify whether the patch below is sufficient
> to make this warning disappear?

Thanks for the patch. I will test it this night.

>
> Thanks,
>
> Bart.
>
> ---
> drivers/scsi/scsi_lib.c | 6 ++++--
> 1 file changed, 4 insertions(+), 2 deletions(-)
>
> diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c
> index f3f24dfd8fd5..33e1a72d47fa 100644
> --- a/drivers/scsi/scsi_lib.c
> +++ b/drivers/scsi/scsi_lib.c
> @@ -2540,8 +2540,10 @@ void scsi_device_resume(struct scsi_device *sdev)
> * device deleted during suspend)
> */
> mutex_lock(&sdev->state_mutex);
> - sdev->quiesced_by = NULL;
> - blk_clear_pm_only(sdev->request_queue);
> + if (sdev->quiesced_by) {
> + sdev->quiesced_by = NULL;
> + blk_clear_pm_only(sdev->request_queue);
> + }
> if (sdev->sdev_state == SDEV_QUIESCE)
> scsi_device_set_state(sdev, SDEV_RUNNING);
> mutex_unlock(&sdev->state_mutex);
>


2019-03-14 02:23:00

by Jisheng Zhang

[permalink] [raw]
Subject: Re: kernel 5.0 blk_clear_pm_only triggers a warning during resume

On Wed, 13 Mar 2019 10:18:41 +0800 Jisheng Zhang wrote:

> On Tue, 12 Mar 2019 07:58:19 -0700 Bart Van Assche wrote:
>
> > CAUTION: Email originated externally, do not click links or open attachments unless you recognize the sender and know the content is safe.
> >
> >
> > On Tue, 2019-03-12 at 05:35 +0000, Jisheng Zhang wrote:
> > > I got below warning during resume:
> > >
> > > [ 673.658888] sd 0:0:0:0: [sda] Starting disk
> > > [ 673.658899] WARNING: CPU: 3 PID: 1039 at blk_clear_pm_only+0x2a/0x30
> > > [ 673.658902] CPU: 3 PID: 1039 Comm: kworker/u8:49 Not tainted 5.0.0+ #1
> > > [ 673.658902] sd 2:0:0:0: [sdb] Starting disk
> > > [ 673.658903] Hardware name: LENOVO 4180F42/4180F42, BIOS 83ET75WW (1.45 ) 05/10/2013
> > > [ 673.658906] Workqueue: events_unbound async_run_entry_fn
> > > [ 673.658909] RIP: 0010:blk_clear_pm_only+0x2a/0x30
> > > [ 673.658911] Code: b8 ff ff ff ff f0 0f c1 87 80 00 00 00 83 e8 01 78 18 74 01 c3 48 81 c7 58 05 00 00 31 c9 31 d2 be 03 00 00 00 e9 36 97 e2 ff <0f> 0b c3 0f 1f 00 48 81 c7 90 00 00 00 e9 04 01
> > > 3a 00 0f 1f 40 00
> > > [ 673.658911] RSP: 0000:ffff8881115a7e48 EFLAGS: 00010297
> > > [ 673.658913] RAX: 00000000ffffffff RBX: ffff888118d42800 RCX: ffff8881194c9a00
> > > [ 673.658914] RDX: ffff888118ab1a00 RSI: 0000000000000000 RDI: ffff888117e70000
> > > [ 673.658915] RBP: ffff888118d42f90 R08: 0000000000000004 R09: 000000000001f900
> > > [ 673.658915] R10: 0000000045698a8e R11: 0000000000000010 R12: ffff888119421000
> > > [ 673.658916] R13: 0000000000000000 R14: ffff88800030ea80 R15: 0ffff88811942100
> > > [ 673.658918] FS: 0000000000000000(0000) GS:ffff88811a180000(0000) knlGS:0000000000000000
> > > [ 673.658918] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> > > [ 673.658919] CR2: 0000000000000000 CR3: 000000000200c001 CR4: 00000000000606e0
> > > [ 673.658920] Call Trace:
> > > [ 673.658924] ? scsi_device_resume+0x28/0x50
> > > [ 673.658926] ? scsi_dev_type_resume+0x2b/0x80
> > > [ 673.658927] ? async_run_entry_fn+0x2c/0xd0
> > > [ 673.658930] ? process_one_work+0x1f0/0x3f0
> > > [ 673.658932] ? worker_thread+0x28/0x3c0
> > > [ 673.658933] ? process_one_work+0x3f0/0x3f0
> > > [ 673.658935] ? kthread+0x10c/0x130
> > > [ 673.658936] ? __kthread_create_on_node+0x150/0x150
> > > [ 673.658938] ? ret_from_fork+0x1f/0x30
> > > [ 673.658940] ---[ end trace ce18772de33e283e ]---
> >
> > Hi Jisheng,
>
> Hi Bart,
>
> >
> > Is this something that occurred once or is this something that you can reproduce
>
> It's 100% reproduced on my home's laptop PC.
>
> > easily? In the latter case, can you verify whether the patch below is sufficient
> > to make this warning disappear?
>
> Thanks for the patch. I will test it this night.

Good news. The patch fix the warning. So

Tested-by: Jisheng Zhang <[email protected]>

Thanks

>
> >
> > Thanks,
> >
> > Bart.
> >
> > ---
> > drivers/scsi/scsi_lib.c | 6 ++++--
> > 1 file changed, 4 insertions(+), 2 deletions(-)
> >
> > diff --git a/drivers/scsi/scsi_lib.c b/drivers/scsi/scsi_lib.c
> > index f3f24dfd8fd5..33e1a72d47fa 100644
> > --- a/drivers/scsi/scsi_lib.c
> > +++ b/drivers/scsi/scsi_lib.c
> > @@ -2540,8 +2540,10 @@ void scsi_device_resume(struct scsi_device *sdev)
> > * device deleted during suspend)
> > */
> > mutex_lock(&sdev->state_mutex);
> > - sdev->quiesced_by = NULL;
> > - blk_clear_pm_only(sdev->request_queue);
> > + if (sdev->quiesced_by) {
> > + sdev->quiesced_by = NULL;
> > + blk_clear_pm_only(sdev->request_queue);
> > + }
> > if (sdev->sdev_state == SDEV_QUIESCE)
> > scsi_device_set_state(sdev, SDEV_RUNNING);
> > mutex_unlock(&sdev->state_mutex);
> >
>


2019-03-15 23:08:08

by Bart Van Assche

[permalink] [raw]
Subject: Re: kernel 5.0 blk_clear_pm_only triggers a warning during resume

On Thu, 2019-03-14 at 02:21 +-0000, Jisheng Zhang wrote:
+AD4 Good news. The patch fix the warning. So
+AD4
+AD4 Tested-by: Jisheng Zhang +ADw-Jisheng.Zhang+AEA-synaptics.com+AD4

Thank you for having tested my patch+ACE

Bart.