2016-12-09 15:12:34

by Michal Hocko

[permalink] [raw]
Subject: WARNING: CPU: 3 PID: 1568 at kernel/sched/core.c:7738 __might_sleep+0x69/0x7e

Hi Tejun,
I am seeing the following warning during boot in my kvm testing
environment:
[ 3.549649] WARNING: CPU: 3 PID: 1568 at kernel/sched/core.c:7738 __might_sleep+0x69/0x7e
[ 3.551279] do not call blocking ops when !TASK_RUNNING; state=2 set at [<ffffffff81098621>] prepare_to_wait+0x65/0xac
[ 3.553354] Modules linked in:
[ 3.554032] CPU: 3 PID: 1568 Comm: modprobe Not tainted 4.9.0-rc8-nofstest5-next-20161209-00013-g3134766e941a #1018
[ 3.556099] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
[ 3.557330] Call Trace:
[ 3.557330] dump_stack+0x68/0x92
[ 3.557330] __warn+0xc2/0xdd
[ 3.557330] warn_slowpath_fmt+0x4b/0x53
[ 3.557330] ? prepare_to_wait+0x65/0xac
[ 3.557330] ? prepare_to_wait+0x65/0xac
[ 3.557330] __might_sleep+0x69/0x7e
[ 3.557330] do_ide_request+0x47/0x540
[ 3.557330] ? __lock_is_held+0x47/0x7a
[ 3.557330] ? hrtimer_try_to_cancel+0x15f/0x1c6
[ 3.557330] ? _raw_spin_unlock_irqrestore+0x4c/0x61
[ 3.557330] __blk_run_queue+0x31/0x3a
[ 3.557330] cfq_insert_request+0x331/0x429
[ 3.557330] __elv_add_request+0x2bb/0x346
[ 3.557330] blk_flush_plug_list+0x1da/0x21f
[ 3.557330] ? bit_wait+0x50/0x50
[ 3.557330] io_schedule_timeout+0x47/0x102
[ 3.557330] bit_wait_io+0x1b/0x5a
[ 3.557330] __wait_on_bit+0x4d/0x7b
[ 3.557330] out_of_line_wait_on_bit+0x72/0x7d
[ 3.557330] ? bit_wait+0x50/0x50
[ 3.557330] ? autoremove_wake_function+0x4e/0x4e
[ 3.557330] __wait_on_buffer+0x40/0x43
[ 3.557330] bh_submit_read+0x60/0x72
[ 3.557330] ext4_get_branch+0x91/0x115
[ 3.557330] ext4_ind_map_blocks+0x181/0xa16
[ 3.557330] ? __lock_is_held+0x47/0x7a
[ 3.557330] ? lock_acquire+0x133/0x1c7
[ 3.557330] ext4_map_blocks+0x120/0x4ca
[ 3.557330] ext4_mpage_readpages+0x2a7/0x70a
[ 3.557330] ext4_readpages+0x33/0x35
[ 3.557330] __do_page_cache_readahead+0x239/0x32a
[ 3.557330] filemap_fault+0x180/0x602
[ 3.557330] ? filemap_fault+0x180/0x602
[ 3.557330] ext4_filemap_fault+0x37/0x4b
[ 3.557330] __do_fault+0x1f/0x94
[ 3.557330] handle_mm_fault+0x946/0xfca
[ 3.557330] __do_page_fault+0x361/0x518
[ 3.557330] do_page_fault+0x42/0x5f
[ 3.557330] page_fault+0x22/0x30

At first I thought this would be related to you recent work
http://lkml.kernel.org/r/[email protected]
but that doesn't seem to be in the linux-next I am using as a base.
io_schedule_timeout is on the stack though so you might have an idea
what is going on here. That might_sleep check has been added a long ago
02e7cf8f8488 ("ide-cd,atapi: use bio for internal commands") in 2.6.31
so I am wondering what has changed since than.

Thanks!
--
Michal Hocko
SUSE Labs


2016-12-12 22:03:53

by Tejun Heo

[permalink] [raw]
Subject: Re: WARNING: CPU: 3 PID: 1568 at kernel/sched/core.c:7738 __might_sleep+0x69/0x7e

Hello, Michal.

On Fri, Dec 09, 2016 at 04:12:29PM +0100, Michal Hocko wrote:
> Hi Tejun,
> I am seeing the following warning during boot in my kvm testing
> environment:
> [ 3.549649] WARNING: CPU: 3 PID: 1568 at kernel/sched/core.c:7738 __might_sleep+0x69/0x7e
> [ 3.551279] do not call blocking ops when !TASK_RUNNING; state=2 set at [<ffffffff81098621>] prepare_to_wait+0x65/0xac
> [ 3.553354] Modules linked in:
> [ 3.554032] CPU: 3 PID: 1568 Comm: modprobe Not tainted 4.9.0-rc8-nofstest5-next-20161209-00013-g3134766e941a #1018
> [ 3.556099] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
> [ 3.557330] Call Trace:
> [ 3.557330] dump_stack+0x68/0x92
> [ 3.557330] __warn+0xc2/0xdd
> [ 3.557330] warn_slowpath_fmt+0x4b/0x53
> [ 3.557330] ? prepare_to_wait+0x65/0xac
> [ 3.557330] ? prepare_to_wait+0x65/0xac
> [ 3.557330] __might_sleep+0x69/0x7e
> [ 3.557330] do_ide_request+0x47/0x540
> [ 3.557330] ? __lock_is_held+0x47/0x7a
> [ 3.557330] ? hrtimer_try_to_cancel+0x15f/0x1c6
> [ 3.557330] ? _raw_spin_unlock_irqrestore+0x4c/0x61
> [ 3.557330] __blk_run_queue+0x31/0x3a
> [ 3.557330] cfq_insert_request+0x331/0x429
> [ 3.557330] __elv_add_request+0x2bb/0x346
> [ 3.557330] blk_flush_plug_list+0x1da/0x21f
> [ 3.557330] ? bit_wait+0x50/0x50
> [ 3.557330] io_schedule_timeout+0x47/0x102
> [ 3.557330] bit_wait_io+0x1b/0x5a
> [ 3.557330] __wait_on_bit+0x4d/0x7b
> [ 3.557330] out_of_line_wait_on_bit+0x72/0x7d
> [ 3.557330] ? bit_wait+0x50/0x50
> [ 3.557330] ? autoremove_wake_function+0x4e/0x4e
> [ 3.557330] __wait_on_buffer+0x40/0x43
> [ 3.557330] bh_submit_read+0x60/0x72
> [ 3.557330] ext4_get_branch+0x91/0x115
> [ 3.557330] ext4_ind_map_blocks+0x181/0xa16
> [ 3.557330] ? __lock_is_held+0x47/0x7a
> [ 3.557330] ? lock_acquire+0x133/0x1c7
> [ 3.557330] ext4_map_blocks+0x120/0x4ca
> [ 3.557330] ext4_mpage_readpages+0x2a7/0x70a
> [ 3.557330] ext4_readpages+0x33/0x35
> [ 3.557330] __do_page_cache_readahead+0x239/0x32a
> [ 3.557330] filemap_fault+0x180/0x602
> [ 3.557330] ? filemap_fault+0x180/0x602
> [ 3.557330] ext4_filemap_fault+0x37/0x4b
> [ 3.557330] __do_fault+0x1f/0x94
> [ 3.557330] handle_mm_fault+0x946/0xfca
> [ 3.557330] __do_page_fault+0x361/0x518
> [ 3.557330] do_page_fault+0x42/0x5f
> [ 3.557330] page_fault+0x22/0x30
>
> At first I thought this would be related to you recent work
> http://lkml.kernel.org/r/[email protected]
> but that doesn't seem to be in the linux-next I am using as a base.
> io_schedule_timeout is on the stack though so you might have an idea
> what is going on here. That might_sleep check has been added a long ago
> 02e7cf8f8488 ("ide-cd,atapi: use bio for internal commands") in 2.6.31
> so I am wondering what has changed since than.

10d784eae2b4 ("sched: always use blk_schedule_flush_plug in
io_schedule_out") seems related. might_sleep is complaining that it's
being called while !TASK_RUNNING. Shaohua, any ideas?

Thanks.

--
tejun

2016-12-12 22:30:57

by Cong Wang

[permalink] [raw]
Subject: Re: WARNING: CPU: 3 PID: 1568 at kernel/sched/core.c:7738 __might_sleep+0x69/0x7e

On Mon, Dec 12, 2016 at 2:03 PM, Tejun Heo <[email protected]> wrote:
> Hello, Michal.
>
> On Fri, Dec 09, 2016 at 04:12:29PM +0100, Michal Hocko wrote:
>> At first I thought this would be related to you recent work
>> http://lkml.kernel.org/r/[email protected]
>> but that doesn't seem to be in the linux-next I am using as a base.
>> io_schedule_timeout is on the stack though so you might have an idea
>> what is going on here. That might_sleep check has been added a long ago
>> 02e7cf8f8488 ("ide-cd,atapi: use bio for internal commands") in 2.6.31
>> so I am wondering what has changed since than.
>
> 10d784eae2b4 ("sched: always use blk_schedule_flush_plug in
> io_schedule_out") seems related. might_sleep is complaining that it's
> being called while !TASK_RUNNING. Shaohua, any ideas?

Yeah, it is pretty much similar to the one I fixed for networking:
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git/commit/?id=d9dc8b0f8b4ec8cdc48ad5a20a3105387138be82

But in your case, it is complicated because of the wait bits API.

2016-12-12 22:45:59

by Shaohua Li

[permalink] [raw]
Subject: Re: WARNING: CPU: 3 PID: 1568 at kernel/sched/core.c:7738 __might_sleep+0x69/0x7e

On Mon, Dec 12, 2016 at 05:03:49PM -0500, Tejun Heo wrote:
> Hello, Michal.
>
> On Fri, Dec 09, 2016 at 04:12:29PM +0100, Michal Hocko wrote:
> > Hi Tejun,
> > I am seeing the following warning during boot in my kvm testing
> > environment:
> > [ 3.549649] WARNING: CPU: 3 PID: 1568 at kernel/sched/core.c:7738 __might_sleep+0x69/0x7e
> > [ 3.551279] do not call blocking ops when !TASK_RUNNING; state=2 set at [<ffffffff81098621>] prepare_to_wait+0x65/0xac
> > [ 3.553354] Modules linked in:
> > [ 3.554032] CPU: 3 PID: 1568 Comm: modprobe Not tainted 4.9.0-rc8-nofstest5-next-20161209-00013-g3134766e941a #1018
> > [ 3.556099] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
> > [ 3.557330] Call Trace:
> > [ 3.557330] dump_stack+0x68/0x92
> > [ 3.557330] __warn+0xc2/0xdd
> > [ 3.557330] warn_slowpath_fmt+0x4b/0x53
> > [ 3.557330] ? prepare_to_wait+0x65/0xac
> > [ 3.557330] ? prepare_to_wait+0x65/0xac
> > [ 3.557330] __might_sleep+0x69/0x7e
> > [ 3.557330] do_ide_request+0x47/0x540
> > [ 3.557330] ? __lock_is_held+0x47/0x7a
> > [ 3.557330] ? hrtimer_try_to_cancel+0x15f/0x1c6
> > [ 3.557330] ? _raw_spin_unlock_irqrestore+0x4c/0x61
> > [ 3.557330] __blk_run_queue+0x31/0x3a
> > [ 3.557330] cfq_insert_request+0x331/0x429
> > [ 3.557330] __elv_add_request+0x2bb/0x346
> > [ 3.557330] blk_flush_plug_list+0x1da/0x21f
> > [ 3.557330] ? bit_wait+0x50/0x50
> > [ 3.557330] io_schedule_timeout+0x47/0x102
> > [ 3.557330] bit_wait_io+0x1b/0x5a
> > [ 3.557330] __wait_on_bit+0x4d/0x7b
> > [ 3.557330] out_of_line_wait_on_bit+0x72/0x7d
> > [ 3.557330] ? bit_wait+0x50/0x50
> > [ 3.557330] ? autoremove_wake_function+0x4e/0x4e
> > [ 3.557330] __wait_on_buffer+0x40/0x43
> > [ 3.557330] bh_submit_read+0x60/0x72
> > [ 3.557330] ext4_get_branch+0x91/0x115
> > [ 3.557330] ext4_ind_map_blocks+0x181/0xa16
> > [ 3.557330] ? __lock_is_held+0x47/0x7a
> > [ 3.557330] ? lock_acquire+0x133/0x1c7
> > [ 3.557330] ext4_map_blocks+0x120/0x4ca
> > [ 3.557330] ext4_mpage_readpages+0x2a7/0x70a
> > [ 3.557330] ext4_readpages+0x33/0x35
> > [ 3.557330] __do_page_cache_readahead+0x239/0x32a
> > [ 3.557330] filemap_fault+0x180/0x602
> > [ 3.557330] ? filemap_fault+0x180/0x602
> > [ 3.557330] ext4_filemap_fault+0x37/0x4b
> > [ 3.557330] __do_fault+0x1f/0x94
> > [ 3.557330] handle_mm_fault+0x946/0xfca
> > [ 3.557330] __do_page_fault+0x361/0x518
> > [ 3.557330] do_page_fault+0x42/0x5f
> > [ 3.557330] page_fault+0x22/0x30
> >
> > At first I thought this would be related to you recent work
> > http://lkml.kernel.org/r/[email protected]
> > but that doesn't seem to be in the linux-next I am using as a base.
> > io_schedule_timeout is on the stack though so you might have an idea
> > what is going on here. That might_sleep check has been added a long ago
> > 02e7cf8f8488 ("ide-cd,atapi: use bio for internal commands") in 2.6.31
> > so I am wondering what has changed since than.
>
> 10d784eae2b4 ("sched: always use blk_schedule_flush_plug in
> io_schedule_out") seems related. might_sleep is complaining that it's
> being called while !TASK_RUNNING. Shaohua, any ideas?

I can't see how the patch is related. Both blk_flush_plug and
blk_schedule_flush_plug can sleep. The patch should only change behavior for plug which accepts from_schedule, which IIRC only raid code uses it.

Thanks,
Shaohua

2016-12-21 10:48:02

by Michal Hocko

[permalink] [raw]
Subject: Re: WARNING: CPU: 3 PID: 1568 at kernel/sched/core.c:7738 __might_sleep+0x69/0x7e

On Mon 12-12-16 14:45:31, Shaohua Li wrote:
> On Mon, Dec 12, 2016 at 05:03:49PM -0500, Tejun Heo wrote:
> > Hello, Michal.
> >
> > On Fri, Dec 09, 2016 at 04:12:29PM +0100, Michal Hocko wrote:
> > > Hi Tejun,
> > > I am seeing the following warning during boot in my kvm testing
> > > environment:
> > > [ 3.549649] WARNING: CPU: 3 PID: 1568 at kernel/sched/core.c:7738 __might_sleep+0x69/0x7e
> > > [ 3.551279] do not call blocking ops when !TASK_RUNNING; state=2 set at [<ffffffff81098621>] prepare_to_wait+0x65/0xac
> > > [ 3.553354] Modules linked in:
> > > [ 3.554032] CPU: 3 PID: 1568 Comm: modprobe Not tainted 4.9.0-rc8-nofstest5-next-20161209-00013-g3134766e941a #1018
> > > [ 3.556099] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-20161025_171302-gandalf 04/01/2014
> > > [ 3.557330] Call Trace:
> > > [ 3.557330] dump_stack+0x68/0x92
> > > [ 3.557330] __warn+0xc2/0xdd
> > > [ 3.557330] warn_slowpath_fmt+0x4b/0x53
> > > [ 3.557330] ? prepare_to_wait+0x65/0xac
> > > [ 3.557330] ? prepare_to_wait+0x65/0xac
> > > [ 3.557330] __might_sleep+0x69/0x7e
> > > [ 3.557330] do_ide_request+0x47/0x540
> > > [ 3.557330] ? __lock_is_held+0x47/0x7a
> > > [ 3.557330] ? hrtimer_try_to_cancel+0x15f/0x1c6
> > > [ 3.557330] ? _raw_spin_unlock_irqrestore+0x4c/0x61
> > > [ 3.557330] __blk_run_queue+0x31/0x3a
> > > [ 3.557330] cfq_insert_request+0x331/0x429
> > > [ 3.557330] __elv_add_request+0x2bb/0x346
> > > [ 3.557330] blk_flush_plug_list+0x1da/0x21f
> > > [ 3.557330] ? bit_wait+0x50/0x50
> > > [ 3.557330] io_schedule_timeout+0x47/0x102
> > > [ 3.557330] bit_wait_io+0x1b/0x5a
> > > [ 3.557330] __wait_on_bit+0x4d/0x7b
> > > [ 3.557330] out_of_line_wait_on_bit+0x72/0x7d
> > > [ 3.557330] ? bit_wait+0x50/0x50
> > > [ 3.557330] ? autoremove_wake_function+0x4e/0x4e
> > > [ 3.557330] __wait_on_buffer+0x40/0x43
> > > [ 3.557330] bh_submit_read+0x60/0x72
> > > [ 3.557330] ext4_get_branch+0x91/0x115
> > > [ 3.557330] ext4_ind_map_blocks+0x181/0xa16
> > > [ 3.557330] ? __lock_is_held+0x47/0x7a
> > > [ 3.557330] ? lock_acquire+0x133/0x1c7
> > > [ 3.557330] ext4_map_blocks+0x120/0x4ca
> > > [ 3.557330] ext4_mpage_readpages+0x2a7/0x70a
> > > [ 3.557330] ext4_readpages+0x33/0x35
> > > [ 3.557330] __do_page_cache_readahead+0x239/0x32a
> > > [ 3.557330] filemap_fault+0x180/0x602
> > > [ 3.557330] ? filemap_fault+0x180/0x602
> > > [ 3.557330] ext4_filemap_fault+0x37/0x4b
> > > [ 3.557330] __do_fault+0x1f/0x94
> > > [ 3.557330] handle_mm_fault+0x946/0xfca
> > > [ 3.557330] __do_page_fault+0x361/0x518
> > > [ 3.557330] do_page_fault+0x42/0x5f
> > > [ 3.557330] page_fault+0x22/0x30
> > >
> > > At first I thought this would be related to you recent work
> > > http://lkml.kernel.org/r/[email protected]
> > > but that doesn't seem to be in the linux-next I am using as a base.
> > > io_schedule_timeout is on the stack though so you might have an idea
> > > what is going on here. That might_sleep check has been added a long ago
> > > 02e7cf8f8488 ("ide-cd,atapi: use bio for internal commands") in 2.6.31
> > > so I am wondering what has changed since than.
> >
> > 10d784eae2b4 ("sched: always use blk_schedule_flush_plug in
> > io_schedule_out") seems related. might_sleep is complaining that it's
> > being called while !TASK_RUNNING. Shaohua, any ideas?
>
> I can't see how the patch is related. Both blk_flush_plug and
> blk_schedule_flush_plug can sleep. The patch should only change
> behavior for plug which accepts from_schedule, which IIRC only raid
> code uses it.

Is there anything I could test?
--
Michal Hocko
SUSE Labs

2016-12-21 19:25:10

by Cong Wang

[permalink] [raw]
Subject: Re: WARNING: CPU: 3 PID: 1568 at kernel/sched/core.c:7738 __might_sleep+0x69/0x7e

On Wed, Dec 21, 2016 at 2:47 AM, Michal Hocko <[email protected]> wrote:
>
> Is there anything I could test?

I am working on a patchset, will send them for you to test. Meanwhile,
if you could provide me a reproducer, that would help a lot.

Thanks!

2016-12-21 20:57:18

by Michal Hocko

[permalink] [raw]
Subject: Re: WARNING: CPU: 3 PID: 1568 at kernel/sched/core.c:7738 __might_sleep+0x69/0x7e

On Wed 21-12-16 11:24:47, Cong Wang wrote:
> On Wed, Dec 21, 2016 at 2:47 AM, Michal Hocko <[email protected]> wrote:
> >
> > Is there anything I could test?
>
> I am working on a patchset, will send them for you to test. Meanwhile,
> if you could provide me a reproducer, that would help a lot.

I just boot my kvm image. Nothing really special here.
--
Michal Hocko
SUSE Labs