iio: WARNING at kernel/sched/core.c:7630: do not call blocking ops when !TASK_RUNNING

iio: WARNING at kernel/sched/core.c:7630: do not call blocking ops when !TASK_RUNNING

[Brian Norris]

Hi all,

I'm seeing the following warnings when I read from an IIO char device,
with CONFIG_DEBUG_ATOMIC_SLEEP=y. I'm testing a v4.4 kernel, but AFAICT,
nothing too relevant has changed between that and v4.7:

[   10.831289] do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffc00026b610>] prepare_to_wait_event+0xb0/0x11c
[   10.845531] ------------[ cut here ]------------
[   10.850161] WARNING: at kernel/sched/core.c:7630
[   10.858672] Modules linked in: cfg80211 nf_conntrack_ipv6 nf_defrag_ipv6 ip6table_filter ip6_tables asix usbnet mii joydev snd_seq_midi snd_seq_midi_event snd_rawmidi snd_seq snd_seq_device ppp_async ppp_generic slhc tun
[   10.878459] 
[   10.879953] CPU: 4 PID: 1844 Comm: BrowserBlocking Not tainted 4.4.14 #190
[   10.886817] Hardware name: Google Kevin (DT)
[   10.891085] task: ffffffc0e5a88000 ti: ffffffc0e2ce4000 task.ti: ffffffc0e2ce4000
[   10.898574] PC is at __might_sleep+0x64/0x90
[   10.902846] LR is at __might_sleep+0x64/0x90
[   10.907115] pc : [<ffffffc00024ed44>] lr : [<ffffffc00024ed44>] pstate: 60000145
[   10.914500] sp : ffffffc0e2ce7ba0
[   10.917813] x29: ffffffc0e2ce7ba0 x28: 0000000000000001 
[   10.923147] x27: 0000000000000000 x26: ffffffc0ed77b488 
[   10.928476] x25: ffffffc001082000 x24: 0000000000000000 
[   10.933809] x23: ffffffc0e2c49340 x22: 0000000000000000 
[   10.939139] x21: 0000000000000269 x20: ffffffc000c1314e 
[   10.944470] x19: ffffffc00114493e x18: 0000000000000000 
[   10.949798] x17: 0000000000000000 x16: ffffffc000372094 
[   10.955138] x15: 0000000000000000 x14: ffffffc0eacbb898 
[   10.960474] x13: ffffffc000c14919 x12: 0000000000000000 
[   10.965809] x11: 0000000000000000 x10: 0000000000001150 
[   10.971141] x9 : ffffffc0e2ce7920 x8 : ffffffc0e5a891b0 
[   10.976469] x7 : ffffffc000267934 x6 : ffffffc00024e7f0 
[   10.981805] x5 : 0000000000000000 x4 : 0000000000000001 
[   10.987138] x3 : 0000000000000000 x2 : cb88537fdc8ba60e 
[   10.992479] x1 : cb88537fdc8ba60e x0 : 0000000000000071 
[   10.997810] 

...

[   12.164333] ---[ end trace 45409966a9a76438 ]---
[   12.168942] Call trace:
[   12.171391] [<ffffffc00024ed44>] __might_sleep+0x64/0x90
[   12.176699] [<ffffffc000954774>] mutex_lock_nested+0x50/0x3fc
[   12.182440] [<ffffffc0007b9424>] iio_kfifo_buf_data_available+0x28/0x4c
[   12.189043] [<ffffffc0007b76ac>] iio_buffer_ready+0x60/0xe0
[   12.194608] [<ffffffc0007b7834>] iio_buffer_read_first_n_outer+0x108/0x1a8
[   12.201474] [<ffffffc000370d48>] __vfs_read+0x58/0x114
[   12.206606] [<ffffffc000371740>] vfs_read+0x94/0x118
[   12.211564] [<ffffffc0003720f8>] SyS_read+0x64/0xb4
[   12.216436] [<ffffffc000203cb4>] el0_svc_naked+0x24/0x28


Have any of you seen this kind of issue before (perhaps most IIO users
are not using CONFIG_DEBUG_ATOMIC_SLEEP)? If the WARNING is really
correct, then this problem has really been around a while. It looks like
we have a wait_event_interruptible() called, with this call chain in the
'condition' path:

  iio_buffer_ready()
    -> iio_buffer_data_available() (i.e., iio_kfifo_buf_data_available())
      -> mutex_lock()

Calling mutex_lock() means we clobber the TASK_INTERRUPTIBLE state with
TASK_RUNNING -- hence, the WARNING. Should this be using a spinlock
instead? Or is there some way to refactor this to avoid calling these
sleeping functions in the wait_event*() condition?

Regards,
Brian

Re: iio: WARNING at kernel/sched/core.c:7630: do not call blocking ops when !TASK_RUNNING

[Lars-Peter Clausen]

On 08/02/2016 03:12 AM, Brian Norris wrote:
> Hi all,
> 
> I'm seeing the following warnings when I read from an IIO char device,
> with CONFIG_DEBUG_ATOMIC_SLEEP=y. I'm testing a v4.4 kernel, but AFAICT,
> nothing too relevant has changed between that and v4.7:
[...]
> Have any of you seen this kind of issue before (perhaps most IIO users
> are not using CONFIG_DEBUG_ATOMIC_SLEEP)? If the WARNING is really
> correct, then this problem has really been around a while. It looks like
> we have a wait_event_interruptible() called, with this call chain in the
> 'condition' path:
> 
>   iio_buffer_ready()
>     -> iio_buffer_data_available() (i.e., iio_kfifo_buf_data_available())
>       -> mutex_lock()
> 
> Calling mutex_lock() means we clobber the TASK_INTERRUPTIBLE state with
> TASK_RUNNING -- hence, the WARNING. Should this be using a spinlock
> instead? Or is there some way to refactor this to avoid calling these
> sleeping functions in the wait_event*() condition?

Hi,

Yes, this is an issue, thanks for pointing this out. It has been there for a
while, my fault, sorry for that. We need a solution like pointed out in this
article (https://lwn.net/Articles/628628/).

- Lars

Re: iio: WARNING at kernel/sched/core.c:7630: do not call blocking ops when !TASK_RUNNING

[Brian Norris]

Hi Lars,

On Tue, Aug 02, 2016 at 03:06:39PM +0200, Lars-Peter Clausen wrote:
> On 08/02/2016 03:12 AM, Brian Norris wrote:
> > I'm seeing the following warnings when I read from an IIO char device,
> > with CONFIG_DEBUG_ATOMIC_SLEEP=y. I'm testing a v4.4 kernel, but AFAICT,
> > nothing too relevant has changed between that and v4.7:
> [...]
> > Have any of you seen this kind of issue before (perhaps most IIO users
> > are not using CONFIG_DEBUG_ATOMIC_SLEEP)? If the WARNING is really
> > correct, then this problem has really been around a while. It looks like
> > we have a wait_event_interruptible() called, with this call chain in the
> > 'condition' path:
> > 
> >   iio_buffer_ready()
> >     -> iio_buffer_data_available() (i.e., iio_kfifo_buf_data_available())
> >       -> mutex_lock()
> > 
> > Calling mutex_lock() means we clobber the TASK_INTERRUPTIBLE state with
> > TASK_RUNNING -- hence, the WARNING. Should this be using a spinlock
> > instead? Or is there some way to refactor this to avoid calling these
> > sleeping functions in the wait_event*() condition?
> 
> Hi,
> 
> Yes, this is an issue, thanks for pointing this out. It has been there for a
> while, my fault, sorry for that. We need a solution like pointed out in this
> article (https://lwn.net/Articles/628628/).

Ah, thanks for the pointer. I thought this problem seemed familiar, but
I couldn't find a canonical solution. The wait_woken() solution looks
like a good starting point, although it's definitely got more
boilerplate... It also requires a 'timeout'; I guess we'd want
MAX_SCHEDULE_TIMEOUT for this case?

Do you want to cook a patch, or should I?

Brian

Re: iio: WARNING at kernel/sched/core.c:7630: do not call blocking ops when !TASK_RUNNING

[Lars-Peter Clausen]

On 08/02/2016 06:57 PM, Brian Norris wrote:
> Hi Lars,
> 
> On Tue, Aug 02, 2016 at 03:06:39PM +0200, Lars-Peter Clausen wrote:
>> On 08/02/2016 03:12 AM, Brian Norris wrote:
>>> I'm seeing the following warnings when I read from an IIO char device,
>>> with CONFIG_DEBUG_ATOMIC_SLEEP=y. I'm testing a v4.4 kernel, but AFAICT,
>>> nothing too relevant has changed between that and v4.7:
>> [...]
>>> Have any of you seen this kind of issue before (perhaps most IIO users
>>> are not using CONFIG_DEBUG_ATOMIC_SLEEP)? If the WARNING is really
>>> correct, then this problem has really been around a while. It looks like
>>> we have a wait_event_interruptible() called, with this call chain in the
>>> 'condition' path:
>>>
>>>   iio_buffer_ready()
>>>     -> iio_buffer_data_available() (i.e., iio_kfifo_buf_data_available())
>>>       -> mutex_lock()
>>>
>>> Calling mutex_lock() means we clobber the TASK_INTERRUPTIBLE state with
>>> TASK_RUNNING -- hence, the WARNING. Should this be using a spinlock
>>> instead? Or is there some way to refactor this to avoid calling these
>>> sleeping functions in the wait_event*() condition?
>>
>> Hi,
>>
>> Yes, this is an issue, thanks for pointing this out. It has been there for a
>> while, my fault, sorry for that. We need a solution like pointed out in this
>> article (https://lwn.net/Articles/628628/).
> 
> Ah, thanks for the pointer. I thought this problem seemed familiar, but
> I couldn't find a canonical solution. The wait_woken() solution looks
> like a good starting point, although it's definitely got more
> boilerplate...

Yes, the boilerplate is a bit of shame. spinlock might still be an option,
but would certainly complicate things in case where we have hardware buffers
and need to ask the hardware whether data is available rather than just
checking a flag in software. And iio_buffer_flush_hwfifo() also needs to
talk to the hardware and can block.

> It also requires a 'timeout'; I guess we'd want
> MAX_SCHEDULE_TIMEOUT for this case?

Yes. MAX_SCHEDULE_TIMEOUT is a special case and means no timeout.

> 
> Do you want to cook a patch, or should I?

Go ahead.

[PATCH] iio: fix sched WARNING "do not call blocking ops when !TASK_RUNNING"

[Brian Norris]

When using CONFIG_DEBUG_ATOMIC_SLEEP, the scheduler nicely points out
that we're calling sleeping primitives within the wait_event loop, which
means we might clobber the task state:

[   10.831289] do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffc00026b610>]
[   10.845531] ------------[ cut here ]------------
[   10.850161] WARNING: at kernel/sched/core.c:7630
...
[   12.164333] ---[ end trace 45409966a9a76438 ]---
[   12.168942] Call trace:
[   12.171391] [<ffffffc00024ed44>] __might_sleep+0x64/0x90
[   12.176699] [<ffffffc000954774>] mutex_lock_nested+0x50/0x3fc
[   12.182440] [<ffffffc0007b9424>] iio_kfifo_buf_data_available+0x28/0x4c
[   12.189043] [<ffffffc0007b76ac>] iio_buffer_ready+0x60/0xe0
[   12.194608] [<ffffffc0007b7834>] iio_buffer_read_first_n_outer+0x108/0x1a8
[   12.201474] [<ffffffc000370d48>] __vfs_read+0x58/0x114
[   12.206606] [<ffffffc000371740>] vfs_read+0x94/0x118
[   12.211564] [<ffffffc0003720f8>] SyS_read+0x64/0xb4
[   12.216436] [<ffffffc000203cb4>] el0_svc_naked+0x24/0x28

To avoid this, we should (a la https://lwn.net/Articles/628628/) use the
wait_woken() function, which avoids the nested sleeping while still
handling races between waiting / wake-events.

Signed-off-by: Brian Norris <briannorris@chromium.org>
---
On Tue, Aug 02, 2016 at 07:04:07PM +0200, Lars-Peter Clausen wrote:
> On 08/02/2016 06:57 PM, Brian Norris wrote:
> > On Tue, Aug 02, 2016 at 03:06:39PM +0200, Lars-Peter Clausen wrote:
> >> On 08/02/2016 03:12 AM, Brian Norris wrote:
> >>> I'm seeing the following warnings when I read from an IIO char device,
> >>> with CONFIG_DEBUG_ATOMIC_SLEEP=y. I'm testing a v4.4 kernel, but AFAICT,
> >>> nothing too relevant has changed between that and v4.7:
[...]
> >> Yes, this is an issue, thanks for pointing this out. It has been there for a
> >> while, my fault, sorry for that. We need a solution like pointed out in this
> >> article (https://lwn.net/Articles/628628/).
[...]
> > Do you want to cook a patch, or should I?
> 
> Go ahead.

Done!

Tested on v4.4.

 drivers/iio/industrialio-buffer.c | 12 ++++++++----
 1 file changed, 8 insertions(+), 4 deletions(-)

diff --git a/drivers/iio/industrialio-buffer.c b/drivers/iio/industrialio-buffer.c
index 90462fcf5436..2ad10e0190d8 100644
--- a/drivers/iio/industrialio-buffer.c
+++ b/drivers/iio/industrialio-buffer.c
@@ -107,6 +107,7 @@ ssize_t iio_buffer_read_first_n_outer(struct file *filp, char __user *buf,
 {
 	struct iio_dev *indio_dev = filp->private_data;
 	struct iio_buffer *rb = indio_dev->buffer;
+	DEFINE_WAIT_FUNC(wait, woken_wake_function);
 	size_t datum_size;
 	size_t to_wait;
 	int ret;
@@ -132,10 +133,13 @@ ssize_t iio_buffer_read_first_n_outer(struct file *filp, char __user *buf,
 		to_wait = min_t(size_t, n / datum_size, rb->watermark);
 
 	do {
-		ret = wait_event_interruptible(rb->pollq,
-		      iio_buffer_ready(indio_dev, rb, to_wait, n / datum_size));
-		if (ret)
-			return ret;
+		add_wait_queue(&rb->pollq, &wait);
+		while (!iio_buffer_ready(indio_dev, rb, to_wait,
+					 n / datum_size)) {
+			wait_woken(&wait, TASK_INTERRUPTIBLE,
+				   MAX_SCHEDULE_TIMEOUT);
+		}
+		remove_wait_queue(&rb->pollq, &wait);
 
 		if (!indio_dev->info)
 			return -ENODEV;
-- 
2.8.1.340

Re: [PATCH] iio: fix sched WARNING "do not call blocking ops when !TASK_RUNNING"

[Lars-Peter Clausen]

On 08/04/2016 10:26 AM, Brian Norris wrote:
> When using CONFIG_DEBUG_ATOMIC_SLEEP, the scheduler nicely points out
> that we're calling sleeping primitives within the wait_event loop, which
> means we might clobber the task state:
> 
> [   10.831289] do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffc00026b610>]
> [   10.845531] ------------[ cut here ]------------
> [   10.850161] WARNING: at kernel/sched/core.c:7630
> ...
> [   12.164333] ---[ end trace 45409966a9a76438 ]---
> [   12.168942] Call trace:
> [   12.171391] [<ffffffc00024ed44>] __might_sleep+0x64/0x90
> [   12.176699] [<ffffffc000954774>] mutex_lock_nested+0x50/0x3fc
> [   12.182440] [<ffffffc0007b9424>] iio_kfifo_buf_data_available+0x28/0x4c
> [   12.189043] [<ffffffc0007b76ac>] iio_buffer_ready+0x60/0xe0
> [   12.194608] [<ffffffc0007b7834>] iio_buffer_read_first_n_outer+0x108/0x1a8
> [   12.201474] [<ffffffc000370d48>] __vfs_read+0x58/0x114
> [   12.206606] [<ffffffc000371740>] vfs_read+0x94/0x118
> [   12.211564] [<ffffffc0003720f8>] SyS_read+0x64/0xb4
> [   12.216436] [<ffffffc000203cb4>] el0_svc_naked+0x24/0x28
> 
> To avoid this, we should (a la https://lwn.net/Articles/628628/) use the
> wait_woken() function, which avoids the nested sleeping while still
> handling races between waiting / wake-events.
> 
> Signed-off-by: Brian Norris <briannorris@chromium.org>

Thanks for taking care of this. Looks good, just one thing.

>  drivers/iio/industrialio-buffer.c | 12 ++++++++----
>  1 file changed, 8 insertions(+), 4 deletions(-)
> 
> diff --git a/drivers/iio/industrialio-buffer.c b/drivers/iio/industrialio-buffer.c
> index 90462fcf5436..2ad10e0190d8 100644
> --- a/drivers/iio/industrialio-buffer.c
> +++ b/drivers/iio/industrialio-buffer.c
> @@ -107,6 +107,7 @@ ssize_t iio_buffer_read_first_n_outer(struct file *filp, char __user *buf,
>  {
>  	struct iio_dev *indio_dev = filp->private_data;
>  	struct iio_buffer *rb = indio_dev->buffer;
> +	DEFINE_WAIT_FUNC(wait, woken_wake_function);
>  	size_t datum_size;
>  	size_t to_wait;
>  	int ret;
> @@ -132,10 +133,13 @@ ssize_t iio_buffer_read_first_n_outer(struct file *filp, char __user *buf,
>  		to_wait = min_t(size_t, n / datum_size, rb->watermark);
>  
>  	do {
> -		ret = wait_event_interruptible(rb->pollq,
> -		      iio_buffer_ready(indio_dev, rb, to_wait, n / datum_size));
> -		if (ret)
> -			return ret;
> +		add_wait_queue(&rb->pollq, &wait);
> +		while (!iio_buffer_ready(indio_dev, rb, to_wait,
> +					 n / datum_size)) {
> +			wait_woken(&wait, TASK_INTERRUPTIBLE,
> +				   MAX_SCHEDULE_TIMEOUT);

We loose the ability to break out from this loop by sending a signal to the
task. This needs something like

	if (signal_pending(current)) {
		ret = -ERESTARTSYS;
		break;
	}

before the wait_woken()

And as a minor improvement I'd also move the
add_wait_queue()/remove_wait_queue() outside of the outer loop. And then
just if (!iio_buffer_ready(...)) continue; rather than having the inner
loop. This should slightly simplify the flow. Just make sure to replace the
returns in the loop with a break so remove_wait_queue() has a chance to run.


> +		}
> +		remove_wait_queue(&rb->pollq, &wait);
>  
>  		if (!indio_dev->info)
>  			return -ENODEV;
> 

Re: [PATCH] iio: fix sched WARNING "do not call blocking ops when !TASK_RUNNING"

[Brian Norris]

On Thu, Aug 04, 2016 at 10:45:39AM +0200, Lars-Peter Clausen wrote:
> > @@ -132,10 +133,13 @@ ssize_t iio_buffer_read_first_n_outer(struct file *filp, char __user *buf,
> >  		to_wait = min_t(size_t, n / datum_size, rb->watermark);
> >  
> >  	do {
> > -		ret = wait_event_interruptible(rb->pollq,
> > -		      iio_buffer_ready(indio_dev, rb, to_wait, n / datum_size));
> > -		if (ret)
> > -			return ret;
> > +		add_wait_queue(&rb->pollq, &wait);
> > +		while (!iio_buffer_ready(indio_dev, rb, to_wait,
> > +					 n / datum_size)) {
> > +			wait_woken(&wait, TASK_INTERRUPTIBLE,
> > +				   MAX_SCHEDULE_TIMEOUT);
> 
> We loose the ability to break out from this loop by sending a signal to the
> task. This needs something like
> 
> 	if (signal_pending(current)) {
> 		ret = -ERESTARTSYS;
> 		break;
> 	}
> 
> before the wait_woken()

Sounds good.

> And as a minor improvement I'd also move the
> add_wait_queue()/remove_wait_queue() outside of the outer loop.

Sure.

> And then
> just if (!iio_buffer_ready(...)) continue; rather than having the inner
> loop. This should slightly simplify the flow.

Perhaps I'm not gathering your meaning here, but wouldn't that turn this
into a spin loop, waiting for iio_buffer_ready()? i.e.:

	do {
		if (!iio_buffer_ready(...))
			continue; // we shouldn't just hammer
				  // iio_buffer_ready(), should we?

		wait_woken(...);
		...
	};

> Just make sure to replace the
> returns in the loop with a break so remove_wait_queue() has a chance to run.
> 
> 
> > +		}
> > +		remove_wait_queue(&rb->pollq, &wait);
> >  
> >  		if (!indio_dev->info)
> >  			return -ENODEV;
> > 
> 

Brian

Re: [PATCH] iio: fix sched WARNING "do not call blocking ops when !TASK_RUNNING"

[Lars-Peter Clausen]

On 08/04/2016 11:41 AM, Brian Norris wrote:
> On Thu, Aug 04, 2016 at 10:45:39AM +0200, Lars-Peter Clausen wrote:
>>> @@ -132,10 +133,13 @@ ssize_t iio_buffer_read_first_n_outer(struct file *filp, char __user *buf,
>>>  		to_wait = min_t(size_t, n / datum_size, rb->watermark);
>>>  
>>>  	do {
>>> -		ret = wait_event_interruptible(rb->pollq,
>>> -		      iio_buffer_ready(indio_dev, rb, to_wait, n / datum_size));
>>> -		if (ret)
>>> -			return ret;
>>> +		add_wait_queue(&rb->pollq, &wait);
>>> +		while (!iio_buffer_ready(indio_dev, rb, to_wait,
>>> +					 n / datum_size)) {
>>> +			wait_woken(&wait, TASK_INTERRUPTIBLE,
>>> +				   MAX_SCHEDULE_TIMEOUT);
>>
>> We loose the ability to break out from this loop by sending a signal to the
>> task. This needs something like
>>
>> 	if (signal_pending(current)) {
>> 		ret = -ERESTARTSYS;
>> 		break;
>> 	}
>>
>> before the wait_woken()
> 
> Sounds good.
> 
>> And as a minor improvement I'd also move the
>> add_wait_queue()/remove_wait_queue() outside of the outer loop.
> 
> Sure.
> 
>> And then
>> just if (!iio_buffer_ready(...)) continue; rather than having the inner
>> loop. This should slightly simplify the flow.
> 
> Perhaps I'm not gathering your meaning here, but wouldn't that turn this
> into a spin loop, waiting for iio_buffer_ready()? i.e.:
> 
> 	do {
> 		if (!iio_buffer_ready(...))
> 			continue; // we shouldn't just hammer
> 				  // iio_buffer_ready(), should we?
> 
> 		wait_woken(...);
> 		...
> 	};

Hm, right, I didn't think this through.

How about:

 	do {
		if (!indio_dev->info)
			return -ENODEV;

 		if (!iio_buffer_ready(...)) {
			if (signal_pending(current)) {
				ret = -ERESTARTSYS;
				break;
			}	
	 		wait_woken(...);
			continue;
		}
 		...
 	} while (ret == 0);

And then also drop the if (!indio_dev->info) at the beginning of the function.

Re: [PATCH] iio: fix sched WARNING "do not call blocking ops when !TASK_RUNNING"

[Brian Norris]

Hi Lars,

On Thu, Aug 04, 2016 at 12:21:08PM +0200, Lars-Peter Clausen wrote:
> And then also drop the if (!indio_dev->info) at the beginning of the function.

I was poking through the usage of this ->info field, and it looks like
it's supposed to be protected by the 'info_exist_lock' lock, but that's
not being acquired here and in at least one other location. Is this
another bug?

Brian

[PATCH v2] iio: fix sched WARNING "do not call blocking ops when !TASK_RUNNING"

[Brian Norris]

When using CONFIG_DEBUG_ATOMIC_SLEEP, the scheduler nicely points out
that we're calling sleeping primitives within the wait_event loop, which
means we might clobber the task state:

[   10.831289] do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffc00026b610>]
[   10.845531] ------------[ cut here ]------------
[   10.850161] WARNING: at kernel/sched/core.c:7630
...
[   12.164333] ---[ end trace 45409966a9a76438 ]---
[   12.168942] Call trace:
[   12.171391] [<ffffffc00024ed44>] __might_sleep+0x64/0x90
[   12.176699] [<ffffffc000954774>] mutex_lock_nested+0x50/0x3fc
[   12.182440] [<ffffffc0007b9424>] iio_kfifo_buf_data_available+0x28/0x4c
[   12.189043] [<ffffffc0007b76ac>] iio_buffer_ready+0x60/0xe0
[   12.194608] [<ffffffc0007b7834>] iio_buffer_read_first_n_outer+0x108/0x1a8
[   12.201474] [<ffffffc000370d48>] __vfs_read+0x58/0x114
[   12.206606] [<ffffffc000371740>] vfs_read+0x94/0x118
[   12.211564] [<ffffffc0003720f8>] SyS_read+0x64/0xb4
[   12.216436] [<ffffffc000203cb4>] el0_svc_naked+0x24/0x28

To avoid this, we should (a la https://lwn.net/Articles/628628/) use the
wait_woken() function, which avoids the nested sleeping while still
handling races between waiting / wake-events.

Signed-off-by: Brian Norris <briannorris@chromium.org>
---
v2:
 * Only add/remove to/from the wait queue once per call
 * Restore interruptability via explicit signal_pending() call
 * Refactor to avoid nested loop

Note that I did not remove the first (semi-redundant) test for
!indio_dev->info, so as to avoid disturbing the error codes used here.

 drivers/iio/industrialio-buffer.c | 23 +++++++++++++++++------
 1 file changed, 17 insertions(+), 6 deletions(-)

diff --git a/drivers/iio/industrialio-buffer.c b/drivers/iio/industrialio-buffer.c
index 90462fcf5436..49bf9c59f117 100644
--- a/drivers/iio/industrialio-buffer.c
+++ b/drivers/iio/industrialio-buffer.c
@@ -107,6 +107,7 @@ ssize_t iio_buffer_read_first_n_outer(struct file *filp, char __user *buf,
 {
 	struct iio_dev *indio_dev = filp->private_data;
 	struct iio_buffer *rb = indio_dev->buffer;
+	DEFINE_WAIT_FUNC(wait, woken_wake_function);
 	size_t datum_size;
 	size_t to_wait;
 	int ret;
@@ -131,19 +132,29 @@ ssize_t iio_buffer_read_first_n_outer(struct file *filp, char __user *buf,
 	else
 		to_wait = min_t(size_t, n / datum_size, rb->watermark);
 
+	add_wait_queue(&rb->pollq, &wait);
 	do {
-		ret = wait_event_interruptible(rb->pollq,
-		      iio_buffer_ready(indio_dev, rb, to_wait, n / datum_size));
-		if (ret)
-			return ret;
+		if (!indio_dev->info) {
+			ret = -ENODEV;
+			break;
+		}
 
-		if (!indio_dev->info)
-			return -ENODEV;
+		if (!iio_buffer_ready(indio_dev, rb, to_wait, n / datum_size)) {
+			if (signal_pending(current)) {
+				ret = -ERESTARTSYS;
+				break;
+			}
+
+			wait_woken(&wait, TASK_INTERRUPTIBLE,
+				   MAX_SCHEDULE_TIMEOUT);
+			continue;
+		}
 
 		ret = rb->access->read_first_n(rb, n, buf);
 		if (ret == 0 && (filp->f_flags & O_NONBLOCK))
 			ret = -EAGAIN;
 	 } while (ret == 0);
+	remove_wait_queue(&rb->pollq, &wait);
 
 	return ret;
 }
-- 
2.8.0.rc3.226.g39d4020

Re: [PATCH] iio: fix sched WARNING "do not call blocking ops when !TASK_RUNNING"

[Lars-Peter Clausen]

On 08/09/2016 12:23 AM, Brian Norris wrote:
> Hi Lars,
> 
> On Thu, Aug 04, 2016 at 12:21:08PM +0200, Lars-Peter Clausen wrote:
>> And then also drop the if (!indio_dev->info) at the beginning of the function.
> 
> I was poking through the usage of this ->info field, and it looks like
> it's supposed to be protected by the 'info_exist_lock' lock, but that's
> not being acquired here and in at least one other location. Is this
> another bug?

Good point. The way this was initially introduced was just to make sure to
break the loop when the device is unregistered and to prevent userspace from
grabbing new references to buffers for unregistered devices. There is no
chance of a race since the buffer is referenced counted independently from
the device. We just use the info field as a flag here. It does not matter
whether we see the change in the info field one loop earlier or later.

But over time this code has changed. E.g. iio_buffer_ready() now calls the
hwfifo_flush_to_buffer() callback of the device from within the info struct.
This can clearly race against unregistration of the device.

Any site that accesses the info field but is not synchronized against
unregistration needs to be protected by the info_exists_lock. The sysfs
read/write callbacks are not affected by this is device_del() is
synchronized against them and makes sure all callbacks have completed and no
new callbacks can be invoked after device_del() has completed. And we wait
for device_del() to complete before info is set to NULL.

The same is not true for the buffer file ops. Userspace retains a reference
to the open file handle and as long as the open file handle exists we have
to expect that the callbacks can be invoked. As long as we do not have a
revoke() [1] we need to handle this at the framework level.

As I said originally we did not access the info field at all in the fops
callbacks, so things were safe. This is has changed though with
hwfifo_flush_to_buffer().

We probably do not want to have the whole read() callback wrapped in the
lock, since that causes to much contention. But we need to wrap the
invocation of the hwfifo_flush_to_buffer() callback in combination with a
check if info is NULL wrapped in the lock.

Another issue is of course buffer implementations that do not properly
protect their callbacks internally. This was not an issue for pure software
buffers, since we simply kept their state in memory. But it might be an
issue for some hardware buffers where the hardware is already gone. Right
now each buffer implementation needs to make sure from their callbacks that
no resources are accessed after they have become unavailable. It might make
sense to move this to the core and make sure that the callbacks are no
longer called after the buffer has been removed, if there is sufficient
demand for this feature.

- Lars

[1] https://lwn.net/Articles/546537/

Re: [PATCH v2] iio: fix sched WARNING "do not call blocking ops when !TASK_RUNNING"

[Jonathan Cameron]

On 09/08/16 01:19, Brian Norris wrote:
> When using CONFIG_DEBUG_ATOMIC_SLEEP, the scheduler nicely points out
> that we're calling sleeping primitives within the wait_event loop, which
> means we might clobber the task state:
> 
> [   10.831289] do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffc00026b610>]
> [   10.845531] ------------[ cut here ]------------
> [   10.850161] WARNING: at kernel/sched/core.c:7630
> ...
> [   12.164333] ---[ end trace 45409966a9a76438 ]---
> [   12.168942] Call trace:
> [   12.171391] [<ffffffc00024ed44>] __might_sleep+0x64/0x90
> [   12.176699] [<ffffffc000954774>] mutex_lock_nested+0x50/0x3fc
> [   12.182440] [<ffffffc0007b9424>] iio_kfifo_buf_data_available+0x28/0x4c
> [   12.189043] [<ffffffc0007b76ac>] iio_buffer_ready+0x60/0xe0
> [   12.194608] [<ffffffc0007b7834>] iio_buffer_read_first_n_outer+0x108/0x1a8
> [   12.201474] [<ffffffc000370d48>] __vfs_read+0x58/0x114
> [   12.206606] [<ffffffc000371740>] vfs_read+0x94/0x118
> [   12.211564] [<ffffffc0003720f8>] SyS_read+0x64/0xb4
> [   12.216436] [<ffffffc000203cb4>] el0_svc_naked+0x24/0x28
> 
> To avoid this, we should (a la https://lwn.net/Articles/628628/) use the
> wait_woken() function, which avoids the nested sleeping while still
> handling races between waiting / wake-events.
> 
> Signed-off-by: Brian Norris <briannorris@chromium.org>
Looks good to me, but given Lars' involvement in the discussion I'd
like his review before applying this.

Jonathan
> ---
> v2:
>  * Only add/remove to/from the wait queue once per call
>  * Restore interruptability via explicit signal_pending() call
>  * Refactor to avoid nested loop
> 
> Note that I did not remove the first (semi-redundant) test for
> !indio_dev->info, so as to avoid disturbing the error codes used here.
> 
>  drivers/iio/industrialio-buffer.c | 23 +++++++++++++++++------
>  1 file changed, 17 insertions(+), 6 deletions(-)
> 
> diff --git a/drivers/iio/industrialio-buffer.c b/drivers/iio/industrialio-buffer.c
> index 90462fcf5436..49bf9c59f117 100644
> --- a/drivers/iio/industrialio-buffer.c
> +++ b/drivers/iio/industrialio-buffer.c
> @@ -107,6 +107,7 @@ ssize_t iio_buffer_read_first_n_outer(struct file *filp, char __user *buf,
>  {
>  	struct iio_dev *indio_dev = filp->private_data;
>  	struct iio_buffer *rb = indio_dev->buffer;
> +	DEFINE_WAIT_FUNC(wait, woken_wake_function);
>  	size_t datum_size;
>  	size_t to_wait;
>  	int ret;
> @@ -131,19 +132,29 @@ ssize_t iio_buffer_read_first_n_outer(struct file *filp, char __user *buf,
>  	else
>  		to_wait = min_t(size_t, n / datum_size, rb->watermark);
>  
> +	add_wait_queue(&rb->pollq, &wait);
>  	do {
> -		ret = wait_event_interruptible(rb->pollq,
> -		      iio_buffer_ready(indio_dev, rb, to_wait, n / datum_size));
> -		if (ret)
> -			return ret;
> +		if (!indio_dev->info) {
> +			ret = -ENODEV;
> +			break;
> +		}
>  
> -		if (!indio_dev->info)
> -			return -ENODEV;
> +		if (!iio_buffer_ready(indio_dev, rb, to_wait, n / datum_size)) {
> +			if (signal_pending(current)) {
> +				ret = -ERESTARTSYS;
> +				break;
> +			}
> +
> +			wait_woken(&wait, TASK_INTERRUPTIBLE,
> +				   MAX_SCHEDULE_TIMEOUT);
> +			continue;
> +		}
>  
>  		ret = rb->access->read_first_n(rb, n, buf);
>  		if (ret == 0 && (filp->f_flags & O_NONBLOCK))
>  			ret = -EAGAIN;
>  	 } while (ret == 0);
> +	remove_wait_queue(&rb->pollq, &wait);
>  
>  	return ret;
>  }
> 

Re: [PATCH v2] iio: fix sched WARNING "do not call blocking ops when !TASK_RUNNING"

[Lars-Peter Clausen]

On 08/15/2016 05:54 PM, Jonathan Cameron wrote:
> On 09/08/16 01:19, Brian Norris wrote:
>> When using CONFIG_DEBUG_ATOMIC_SLEEP, the scheduler nicely points out
>> that we're calling sleeping primitives within the wait_event loop, which
>> means we might clobber the task state:
>>
>> [   10.831289] do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffc00026b610>]
>> [   10.845531] ------------[ cut here ]------------
>> [   10.850161] WARNING: at kernel/sched/core.c:7630
>> ...
>> [   12.164333] ---[ end trace 45409966a9a76438 ]---
>> [   12.168942] Call trace:
>> [   12.171391] [<ffffffc00024ed44>] __might_sleep+0x64/0x90
>> [   12.176699] [<ffffffc000954774>] mutex_lock_nested+0x50/0x3fc
>> [   12.182440] [<ffffffc0007b9424>] iio_kfifo_buf_data_available+0x28/0x4c
>> [   12.189043] [<ffffffc0007b76ac>] iio_buffer_ready+0x60/0xe0
>> [   12.194608] [<ffffffc0007b7834>] iio_buffer_read_first_n_outer+0x108/0x1a8
>> [   12.201474] [<ffffffc000370d48>] __vfs_read+0x58/0x114
>> [   12.206606] [<ffffffc000371740>] vfs_read+0x94/0x118
>> [   12.211564] [<ffffffc0003720f8>] SyS_read+0x64/0xb4
>> [   12.216436] [<ffffffc000203cb4>] el0_svc_naked+0x24/0x28
>>
>> To avoid this, we should (a la https://lwn.net/Articles/628628/) use the
>> wait_woken() function, which avoids the nested sleeping while still
>> handling races between waiting / wake-events.
>>
>> Signed-off-by: Brian Norris <briannorris@chromium.org>
> Looks good to me, but given Lars' involvement in the discussion I'd
> like his review before applying this.

Looks good. Thanks Brian for fixing this.

Reviewed-by: Lars-Peter Clausen <lars@metafoo.de>

Re: [PATCH v2] iio: fix sched WARNING "do not call blocking ops when !TASK_RUNNING"

[Jonathan Cameron]

On 16/08/16 16:27, Lars-Peter Clausen wrote:
> On 08/15/2016 05:54 PM, Jonathan Cameron wrote:
>> On 09/08/16 01:19, Brian Norris wrote:
>>> When using CONFIG_DEBUG_ATOMIC_SLEEP, the scheduler nicely points out
>>> that we're calling sleeping primitives within the wait_event loop, which
>>> means we might clobber the task state:
>>>
>>> [   10.831289] do not call blocking ops when !TASK_RUNNING; state=1 set at [<ffffffc00026b610>]
>>> [   10.845531] ------------[ cut here ]------------
>>> [   10.850161] WARNING: at kernel/sched/core.c:7630
>>> ...
>>> [   12.164333] ---[ end trace 45409966a9a76438 ]---
>>> [   12.168942] Call trace:
>>> [   12.171391] [<ffffffc00024ed44>] __might_sleep+0x64/0x90
>>> [   12.176699] [<ffffffc000954774>] mutex_lock_nested+0x50/0x3fc
>>> [   12.182440] [<ffffffc0007b9424>] iio_kfifo_buf_data_available+0x28/0x4c
>>> [   12.189043] [<ffffffc0007b76ac>] iio_buffer_ready+0x60/0xe0
>>> [   12.194608] [<ffffffc0007b7834>] iio_buffer_read_first_n_outer+0x108/0x1a8
>>> [   12.201474] [<ffffffc000370d48>] __vfs_read+0x58/0x114
>>> [   12.206606] [<ffffffc000371740>] vfs_read+0x94/0x118
>>> [   12.211564] [<ffffffc0003720f8>] SyS_read+0x64/0xb4
>>> [   12.216436] [<ffffffc000203cb4>] el0_svc_naked+0x24/0x28
>>>
>>> To avoid this, we should (a la https://lwn.net/Articles/628628/) use the
>>> wait_woken() function, which avoids the nested sleeping while still
>>> handling races between waiting / wake-events.
>>>
>>> Signed-off-by: Brian Norris <briannorris@chromium.org>
>> Looks good to me, but given Lars' involvement in the discussion I'd
>> like his review before applying this.
> 
> Looks good. Thanks Brian for fixing this.
> 
> Reviewed-by: Lars-Peter Clausen <lars@metafoo.de>
I've applied to this to the fixes-togreg branch of iio.git

For now I haven't marked it for stable, purely because I'm not sure
when the first 'problem' usage was introduced.  I'm happy to explicitly
send a request for stable inclusion if anyone wants to track down
which stable trees this is applicable to.

I've very low on time today (holiday catch up) so won't get to
dig into it myself for a at least a few weeks.

Jonathan
> --
> To unsubscribe from this list: send the line "unsubscribe linux-iio" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
> 

Re: [PATCH v2] iio: fix sched WARNING "do not call blocking ops when !TASK_RUNNING"

[Lars-Peter Clausen]

On 08/21/2016 01:21 PM, Jonathan Cameron wrote:
[...]
> I've applied to this to the fixes-togreg branch of iio.git
> 
> For now I haven't marked it for stable, purely because I'm not sure
> when the first 'problem' usage was introduced.  I'm happy to explicitly
> send a request for stable inclusion if anyone wants to track down
> which stable trees this is applicable to.
> 
> I've very low on time today (holiday catch up) so won't get to
> dig into it myself for a at least a few weeks.

The issue has been around for a bit longer, but the wait_woken()
infrastructure has only available since v3.19.

Re: [PATCH v2] iio: fix sched WARNING "do not call blocking ops when !TASK_RUNNING"

[Jonathan Cameron]

On 21/08/16 13:26, Lars-Peter Clausen wrote:
> On 08/21/2016 01:21 PM, Jonathan Cameron wrote:
> [...]
>> I've applied to this to the fixes-togreg branch of iio.git
>>
>> For now I haven't marked it for stable, purely because I'm not sure
>> when the first 'problem' usage was introduced.  I'm happy to explicitly
>> send a request for stable inclusion if anyone wants to track down
>> which stable trees this is applicable to.
>>
>> I've very low on time today (holiday catch up) so won't get to
>> dig into it myself for a at least a few weeks.
> 
> The issue has been around for a bit longer, but the wait_woken()
> infrastructure has only available since v3.19.
> 
I've marked for stable and added a note about that.
Will do for now!

Jonathan