subject:"Re\: \[BISECTED\] rcu_sched self\-detected stall since 3.17"

Re: [BISECTED] rcu_sched self-detected stall since 3.17

2015-12-15 Thread Oleg Nesterov

Sorry again for the huge delay.

And all I can say is that I am all confused.

On 12/01, Peter Zijlstra wrote:
>
> On Fri, Nov 20, 2015 at 03:35:38PM +, Vladimir Murzin wrote:
> > commit 743162013d40ca612b4cb53d3a200dff2d9ab26e
> > Author: NeilBrown 
> > Date:   Mon Jul 7 15:16:04 2014 +1000

That patch still looks correct to me.

> > and if I apply following diff I don't see stalls anymore.
> >
> > diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
> > index a104879..2d68cdb 100644
> > --- a/kernel/sched/wait.c
> > +++ b/kernel/sched/wait.c
> > @@ -514,9 +514,10 @@ EXPORT_SYMBOL(bit_wait);
> >
> >  __sched int bit_wait_io(void *word)
> >  {
> > +   io_schedule();
> > +
> > if (signal_pending_state(current->state, current))
> > return 1;
> > -   io_schedule();
> > return 0;
> >  }
> >  EXPORT_SYMBOL(bit_wait_io);

I can't understand why this change helps. But note that it actually removes
the signal_pending_state() check from bit_wait_io(), current->state is always
TASK_RUNNING after return from schedule(), signal_pending_state() will always
return zero.

This means that after this change wait_on_page_bit_killable() will spin in a
busy-wait loop if the caller is killed.

> The reason this is broken is that schedule() will no-op when there is a
> pending signal, while raising a signal will also issue a wakeup.

But why this is wrong? We should notice signal_pending_state() on the next
iteration.

> Thus the right thing to do is check for the signal state after,

I think this check should work on both sides. The only difference is that
you obviously can't use current->state after schedule().

I still can't understand the problem.

Oleg.

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Re: [BISECTED] rcu_sched self-detected stall since 3.17

2015-12-15 Thread Oleg Nesterov

Sorry again for the huge delay.

And all I can say is that I am all confused.

On 12/01, Peter Zijlstra wrote:
>
> On Fri, Nov 20, 2015 at 03:35:38PM +, Vladimir Murzin wrote:
> > commit 743162013d40ca612b4cb53d3a200dff2d9ab26e
> > Author: NeilBrown 
> > Date:   Mon Jul 7 15:16:04 2014 +1000

That patch still looks correct to me.

> > and if I apply following diff I don't see stalls anymore.
> >
> > diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
> > index a104879..2d68cdb 100644
> > --- a/kernel/sched/wait.c
> > +++ b/kernel/sched/wait.c
> > @@ -514,9 +514,10 @@ EXPORT_SYMBOL(bit_wait);
> >
> >  __sched int bit_wait_io(void *word)
> >  {
> > +   io_schedule();
> > +
> > if (signal_pending_state(current->state, current))
> > return 1;
> > -   io_schedule();
> > return 0;
> >  }
> >  EXPORT_SYMBOL(bit_wait_io);

I can't understand why this change helps. But note that it actually removes
the signal_pending_state() check from bit_wait_io(), current->state is always
TASK_RUNNING after return from schedule(), signal_pending_state() will always
return zero.

This means that after this change wait_on_page_bit_killable() will spin in a
busy-wait loop if the caller is killed.

> The reason this is broken is that schedule() will no-op when there is a
> pending signal, while raising a signal will also issue a wakeup.

But why this is wrong? We should notice signal_pending_state() on the next
iteration.

> Thus the right thing to do is check for the signal state after,

I think this check should work on both sides. The only difference is that
you obviously can't use current->state after schedule().

I still can't understand the problem.

Oleg.

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Re: [BISECTED] rcu_sched self-detected stall since 3.17

2015-12-02 Thread Vladimir Murzin

On 01/12/15 13:04, Peter Zijlstra wrote:
> Sorry for the delay and thanks for the reminder!
> 
> On Fri, Nov 20, 2015 at 03:35:38PM +, Vladimir Murzin wrote:
>> commit 743162013d40ca612b4cb53d3a200dff2d9ab26e
>> Author: NeilBrown 
>> Date:   Mon Jul 7 15:16:04 2014 +1000
>>
>> sched: Remove proliferation of wait_on_bit() action functions
>>
>> The only change I noticed is from (mm/filemap.c)
>>
>>  io_schedule();
>>  fatal_signal_pending(current)
>>
>> to (kernel/sched/wait.c)
>>
>>  signal_pending_state(current->state, current)
>>  io_schedule();
>>
>> and if I apply following diff I don't see stalls anymore.
>>
>> diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
>> index a104879..2d68cdb 100644
>> --- a/kernel/sched/wait.c
>> +++ b/kernel/sched/wait.c
>> @@ -514,9 +514,10 @@ EXPORT_SYMBOL(bit_wait);
>>
>>  __sched int bit_wait_io(void *word)
>>  {
>> +   io_schedule();
>> +
>> if (signal_pending_state(current->state, current))
>> return 1;
>> -   io_schedule();
>> return 0;
>>  }
>>  EXPORT_SYMBOL(bit_wait_io);
>>
>> Any ideas why it might happen and why diff above helps?
> 
> Yes, the code as presented is simply wrong. And in fact most of the code
> it replaced was of the right form (with a few exceptions which would
> indeed have been subject to the same problem you've observed.
> 
> Note how the late:
> 
>   - cifs_sb_tcon_pending_wait
>   - fscache_wait_bit_interruptible
>   - sleep_on_page_killable
>   - wait_inquiry
>   - key_wait_bit_intr
> 
> All check the signal state _after_ calling schedule().
> 
> As opposed to:
> 
>   - gfs2_journalid_wait
> 
> which follows the broken pattern.
> 
> Further notice that most expect a return of -EINTR, which also seems
> correct given that this is a signal, those that do not return -EINTR
> only check for a !0 return value so would work equally well with -EINTR.
> 
> The reason this is broken is that schedule() will no-op when there is a
> pending signal, while raising a signal will also issue a wakeup.
> 

Glad to hear confirmation on a problem. Thanks for detailed answer!

> Thus the right thing to do is check for the signal state after, that way
> you handle both cases:
> 
>  - calling schedule() with a signal pending
>  - receiving a signal while sleeping
> 
> As such, I would propose the below patch. Oleg, do you concur?
> 
> ---
> Subject: sched,wait: Fix signal handling in bit wait helpers
> 
> Vladimir reported getting RCU stall warnings and bisected it back to
> commit 743162013d40. That commit inadvertently reversed the calls to
> schedule() and signal_pending(), thereby not handling the case where the
> signal receives while we sleep.
> 
> Fixes: 743162013d40 ("sched: Remove proliferation of wait_on_bit() action 
> functions")
> Fixes: cbbce8220949 ("SCHED: add some "wait..on_bit...timeout()" interfaces.")
> Reported-by: Vladimir Murzin 
> Signed-off-by: Peter Zijlstra (Intel) 
> ---
>  kernel/sched/wait.c | 16 
>  1 file changed, 8 insertions(+), 8 deletions(-)
> 
> diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
> index 052e02672d12..f10bd873e684 100644
> --- a/kernel/sched/wait.c
> +++ b/kernel/sched/wait.c
> @@ -583,18 +583,18 @@ EXPORT_SYMBOL(wake_up_atomic_t);
>  
>  __sched int bit_wait(struct wait_bit_key *word)
>  {
> - if (signal_pending_state(current->state, current))
> - return 1;
>   schedule();
> + if (signal_pending(current))
> + return -EINTR;
>   return 0;
>  }
>  EXPORT_SYMBOL(bit_wait);
>  
>  __sched int bit_wait_io(struct wait_bit_key *word)
>  {
> - if (signal_pending_state(current->state, current))
> - return 1;
>   io_schedule();
> + if (signal_pending(current))
> + return -EINTR;
>   return 0;
>  }
>  EXPORT_SYMBOL(bit_wait_io);
> @@ -602,11 +602,11 @@ EXPORT_SYMBOL(bit_wait_io);
>  __sched int bit_wait_timeout(struct wait_bit_key *word)
>  {
>   unsigned long now = READ_ONCE(jiffies);
> - if (signal_pending_state(current->state, current))
> - return 1;
>   if (time_after_eq(now, word->timeout))
>   return -EAGAIN;
>   schedule_timeout(word->timeout - now);
> + if (signal_pending(current))
> + return -EINTR;
>   return 0;
>  }
>  EXPORT_SYMBOL_GPL(bit_wait_timeout);
> @@ -614,11 +614,11 @@ EXPORT_SYMBOL_GPL(bit_wait_timeout);
>  __sched int bit_wait_io_timeout(struct wait_bit_key *word)
>  {
>   unsigned long now = READ_ONCE(jiffies);
> - if (signal_pending_state(current->state, current))
> - return 1;
>   if (time_after_eq(now, word->timeout))
>   return -EAGAIN;
>   io_schedule_timeout(word->timeout - now);
> + if (signal_pending(current))
> + return -EINTR;
>   return 0;
>  }
>  EXPORT_SYMBOL_GPL(bit_wait_io_timeout);
> 

I run it overnight on top of 4.3 and didn't see stalls. So in case it helps

Tested-by: Vladimir Murzin 

Cheers

Re: [BISECTED] rcu_sched self-detected stall since 3.17

2015-12-02 Thread Vladimir Murzin

On 01/12/15 13:04, Peter Zijlstra wrote:
> Sorry for the delay and thanks for the reminder!
> 
> On Fri, Nov 20, 2015 at 03:35:38PM +, Vladimir Murzin wrote:
>> commit 743162013d40ca612b4cb53d3a200dff2d9ab26e
>> Author: NeilBrown 
>> Date:   Mon Jul 7 15:16:04 2014 +1000
>>
>> sched: Remove proliferation of wait_on_bit() action functions
>>
>> The only change I noticed is from (mm/filemap.c)
>>
>>  io_schedule();
>>  fatal_signal_pending(current)
>>
>> to (kernel/sched/wait.c)
>>
>>  signal_pending_state(current->state, current)
>>  io_schedule();
>>
>> and if I apply following diff I don't see stalls anymore.
>>
>> diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
>> index a104879..2d68cdb 100644
>> --- a/kernel/sched/wait.c
>> +++ b/kernel/sched/wait.c
>> @@ -514,9 +514,10 @@ EXPORT_SYMBOL(bit_wait);
>>
>>  __sched int bit_wait_io(void *word)
>>  {
>> +   io_schedule();
>> +
>> if (signal_pending_state(current->state, current))
>> return 1;
>> -   io_schedule();
>> return 0;
>>  }
>>  EXPORT_SYMBOL(bit_wait_io);
>>
>> Any ideas why it might happen and why diff above helps?
> 
> Yes, the code as presented is simply wrong. And in fact most of the code
> it replaced was of the right form (with a few exceptions which would
> indeed have been subject to the same problem you've observed.
> 
> Note how the late:
> 
>   - cifs_sb_tcon_pending_wait
>   - fscache_wait_bit_interruptible
>   - sleep_on_page_killable
>   - wait_inquiry
>   - key_wait_bit_intr
> 
> All check the signal state _after_ calling schedule().
> 
> As opposed to:
> 
>   - gfs2_journalid_wait
> 
> which follows the broken pattern.
> 
> Further notice that most expect a return of -EINTR, which also seems
> correct given that this is a signal, those that do not return -EINTR
> only check for a !0 return value so would work equally well with -EINTR.
> 
> The reason this is broken is that schedule() will no-op when there is a
> pending signal, while raising a signal will also issue a wakeup.
> 

Glad to hear confirmation on a problem. Thanks for detailed answer!

> Thus the right thing to do is check for the signal state after, that way
> you handle both cases:
> 
>  - calling schedule() with a signal pending
>  - receiving a signal while sleeping
> 
> As such, I would propose the below patch. Oleg, do you concur?
> 
> ---
> Subject: sched,wait: Fix signal handling in bit wait helpers
> 
> Vladimir reported getting RCU stall warnings and bisected it back to
> commit 743162013d40. That commit inadvertently reversed the calls to
> schedule() and signal_pending(), thereby not handling the case where the
> signal receives while we sleep.
> 
> Fixes: 743162013d40 ("sched: Remove proliferation of wait_on_bit() action 
> functions")
> Fixes: cbbce8220949 ("SCHED: add some "wait..on_bit...timeout()" interfaces.")
> Reported-by: Vladimir Murzin 
> Signed-off-by: Peter Zijlstra (Intel) 
> ---
>  kernel/sched/wait.c | 16 
>  1 file changed, 8 insertions(+), 8 deletions(-)
> 
> diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
> index 052e02672d12..f10bd873e684 100644
> --- a/kernel/sched/wait.c
> +++ b/kernel/sched/wait.c
> @@ -583,18 +583,18 @@ EXPORT_SYMBOL(wake_up_atomic_t);
>  
>  __sched int bit_wait(struct wait_bit_key *word)
>  {
> - if (signal_pending_state(current->state, current))
> - return 1;
>   schedule();
> + if (signal_pending(current))
> + return -EINTR;
>   return 0;
>  }
>  EXPORT_SYMBOL(bit_wait);
>  
>  __sched int bit_wait_io(struct wait_bit_key *word)
>  {
> - if (signal_pending_state(current->state, current))
> - return 1;
>   io_schedule();
> + if (signal_pending(current))
> + return -EINTR;
>   return 0;
>  }
>  EXPORT_SYMBOL(bit_wait_io);
> @@ -602,11 +602,11 @@ EXPORT_SYMBOL(bit_wait_io);
>  __sched int bit_wait_timeout(struct wait_bit_key *word)
>  {
>   unsigned long now = READ_ONCE(jiffies);
> - if (signal_pending_state(current->state, current))
> - return 1;
>   if (time_after_eq(now, word->timeout))
>   return -EAGAIN;
>   schedule_timeout(word->timeout - now);
> + if (signal_pending(current))
> + return -EINTR;
>   return 0;
>  }
>  EXPORT_SYMBOL_GPL(bit_wait_timeout);
> @@ -614,11 +614,11 @@ EXPORT_SYMBOL_GPL(bit_wait_timeout);
>  __sched int bit_wait_io_timeout(struct wait_bit_key *word)
>  {
>   unsigned long now = READ_ONCE(jiffies);
> - if (signal_pending_state(current->state, current))
> - return 1;
>   if (time_after_eq(now, word->timeout))
>   return -EAGAIN;
>   io_schedule_timeout(word->timeout - now);
> + if (signal_pending(current))
> + return -EINTR;
>   return 0;
>  }
>  EXPORT_SYMBOL_GPL(bit_wait_io_timeout);
> 

I run it overnight on top of 4.3 and didn't see

Re: [BISECTED] rcu_sched self-detected stall since 3.17

2015-12-01 Thread Ross Green

I too have traced a similar RCU stall all the way back to 3.17.

Seems to affect RCU preempt code as well.

I had not been able to find a sure fail way to trigger this and it
could take several days running before problem arises.

Ross
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Re: [BISECTED] rcu_sched self-detected stall since 3.17

2015-12-01 Thread Peter Zijlstra

Sorry for the delay and thanks for the reminder!

On Fri, Nov 20, 2015 at 03:35:38PM +, Vladimir Murzin wrote:
> commit 743162013d40ca612b4cb53d3a200dff2d9ab26e
> Author: NeilBrown 
> Date:   Mon Jul 7 15:16:04 2014 +1000
> 
> sched: Remove proliferation of wait_on_bit() action functions
> 
> The only change I noticed is from (mm/filemap.c)
> 
>   io_schedule();
>   fatal_signal_pending(current)
> 
> to (kernel/sched/wait.c)
> 
>   signal_pending_state(current->state, current)
>   io_schedule();
> 
> and if I apply following diff I don't see stalls anymore.
> 
> diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
> index a104879..2d68cdb 100644
> --- a/kernel/sched/wait.c
> +++ b/kernel/sched/wait.c
> @@ -514,9 +514,10 @@ EXPORT_SYMBOL(bit_wait);
> 
>  __sched int bit_wait_io(void *word)
>  {
> +   io_schedule();
> +
> if (signal_pending_state(current->state, current))
> return 1;
> -   io_schedule();
> return 0;
>  }
>  EXPORT_SYMBOL(bit_wait_io);
> 
> Any ideas why it might happen and why diff above helps?

Yes, the code as presented is simply wrong. And in fact most of the code
it replaced was of the right form (with a few exceptions which would
indeed have been subject to the same problem you've observed.

Note how the late:

  - cifs_sb_tcon_pending_wait
  - fscache_wait_bit_interruptible
  - sleep_on_page_killable
  - wait_inquiry
  - key_wait_bit_intr

All check the signal state _after_ calling schedule().

As opposed to:

  - gfs2_journalid_wait

which follows the broken pattern.

Further notice that most expect a return of -EINTR, which also seems
correct given that this is a signal, those that do not return -EINTR
only check for a !0 return value so would work equally well with -EINTR.

The reason this is broken is that schedule() will no-op when there is a
pending signal, while raising a signal will also issue a wakeup.

Thus the right thing to do is check for the signal state after, that way
you handle both cases:

 - calling schedule() with a signal pending
 - receiving a signal while sleeping

As such, I would propose the below patch. Oleg, do you concur?

---
Subject: sched,wait: Fix signal handling in bit wait helpers

Vladimir reported getting RCU stall warnings and bisected it back to
commit 743162013d40. That commit inadvertently reversed the calls to
schedule() and signal_pending(), thereby not handling the case where the
signal receives while we sleep.

Fixes: 743162013d40 ("sched: Remove proliferation of wait_on_bit() action 
functions")
Fixes: cbbce8220949 ("SCHED: add some "wait..on_bit...timeout()" interfaces.")
Reported-by: Vladimir Murzin 
Signed-off-by: Peter Zijlstra (Intel) 
---
 kernel/sched/wait.c | 16 
 1 file changed, 8 insertions(+), 8 deletions(-)

diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
index 052e02672d12..f10bd873e684 100644
--- a/kernel/sched/wait.c
+++ b/kernel/sched/wait.c
@@ -583,18 +583,18 @@ EXPORT_SYMBOL(wake_up_atomic_t);
 
 __sched int bit_wait(struct wait_bit_key *word)
 {
-   if (signal_pending_state(current->state, current))
-   return 1;
schedule();
+   if (signal_pending(current))
+   return -EINTR;
return 0;
 }
 EXPORT_SYMBOL(bit_wait);
 
 __sched int bit_wait_io(struct wait_bit_key *word)
 {
-   if (signal_pending_state(current->state, current))
-   return 1;
io_schedule();
+   if (signal_pending(current))
+   return -EINTR;
return 0;
 }
 EXPORT_SYMBOL(bit_wait_io);
@@ -602,11 +602,11 @@ EXPORT_SYMBOL(bit_wait_io);
 __sched int bit_wait_timeout(struct wait_bit_key *word)
 {
unsigned long now = READ_ONCE(jiffies);
-   if (signal_pending_state(current->state, current))
-   return 1;
if (time_after_eq(now, word->timeout))
return -EAGAIN;
schedule_timeout(word->timeout - now);
+   if (signal_pending(current))
+   return -EINTR;
return 0;
 }
 EXPORT_SYMBOL_GPL(bit_wait_timeout);
@@ -614,11 +614,11 @@ EXPORT_SYMBOL_GPL(bit_wait_timeout);
 __sched int bit_wait_io_timeout(struct wait_bit_key *word)
 {
unsigned long now = READ_ONCE(jiffies);
-   if (signal_pending_state(current->state, current))
-   return 1;
if (time_after_eq(now, word->timeout))
return -EAGAIN;
io_schedule_timeout(word->timeout - now);
+   if (signal_pending(current))
+   return -EINTR;
return 0;
 }
 EXPORT_SYMBOL_GPL(bit_wait_io_timeout);
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Re: [BISECTED] rcu_sched self-detected stall since 3.17

2015-12-01 Thread Vladimir Murzin

On 20/11/15 15:35, Vladimir Murzin wrote:
> Hi,
> 
> I've been getting rcu_sched self-detected stall on one of our test
> environment with the following (or similar) log:
> 
> Linux 4.3

Anybody looking into this? Oleg, Peter, any ideas what's happening here?

Thanks
Vladimir

> 
>> INFO: rcu_sched self-detected stall on CPU
>>  2: (2099 ticks this GP) idle=a73/141/0 softirq=277/283 
>> fqs=2092 
>>   (t=2100 jiffies g=-197 c=-198 q=230)
>> Task dump for CPU 2:
>> paranoiaR running  0   423  1 0x0003
>> [] (unwind_backtrace) from [] (show_stack+0x10/0x14)
>> [] (show_stack) from [] (rcu_dump_cpu_stacks+0xa4/0xc4)
>> [] (rcu_dump_cpu_stacks) from [] 
>> (rcu_check_callbacks+0x2dc/0x81c)
>> [] (rcu_check_callbacks) from [] 
>> (update_process_times+0x38/0x64)
>> [] (update_process_times) from [] 
>> (tick_periodic+0xa8/0xb8)
>> [] (tick_periodic) from [] 
>> (tick_handle_periodic+0x28/0x88)
>> [] (tick_handle_periodic) from [] 
>> (arch_timer_handler_virt+0x28/0x30)
>> [] (arch_timer_handler_virt) from [] 
>> (handle_percpu_devid_irq+0x6c/0x84)
>> [] (handle_percpu_devid_irq) from [] 
>> (generic_handle_irq+0x24/0x34)
>> [] (generic_handle_irq) from [] 
>> (__handle_domain_irq+0x98/0xac)
>> [] (__handle_domain_irq) from [] 
>> (gic_handle_irq+0x54/0x90)
>> [] (gic_handle_irq) from [] (__irq_svc+0x54/0x70)
>> Exception stack(0xdb007c60 to 0xdb007ca8)
>> 7c60:    0001 dc3e9a20   0001
>> 7c80: dc3e9a20 001b 0008 000b  db007cb0 c00ac8f0 c00aa96c
>> 7ca0: 600d0113 
>> [] (__irq_svc) from [] (free_pages_prepare+0x18c/0x218)
>> [] (free_pages_prepare) from [] 
>> (free_hot_cold_page+0x34/0x168)
>> [] (free_hot_cold_page) from [] 
>> (handle_mm_fault+0x7b8/0xe60)
>> [] (handle_mm_fault) from [] (do_page_fault+0x12c/0x378)
>> [] (do_page_fault) from [] (do_DataAbort+0x38/0xb4)
>> [] (do_DataAbort) from [] (__dabt_svc+0x40/0x60)
>> Exception stack(0xdb007e68 to 0xdb007eb0)
>> 7e60:   0001b2c8 0d30  0055 0051 dbb04600
>> 7e80:  db007ec8 db8ea700 db8f3080 dba43240 0001b2c8  db007eb8
>> 7ea0: c012c178 c0174ce8 200d0113 
>> [] (__dabt_svc) from [] (__clear_user_std+0x34/0x68)
>> [] (__clear_user_std) from [] (padzero+0x58/0x74)
>> [] (padzero) from [] (load_elf_binary+0x730/0x1250)
>> [] (load_elf_binary) from [] 
>> (search_binary_handler+0xa0/0x23c)
>> [] (search_binary_handler) from [] 
>> (do_execveat_common+0x444/0x5d8)
>> [] (do_execveat_common) from [] (do_execve+0x24/0x2c)
>> [] (do_execve) from [] (ret_fast_syscall+0x0/0x3c)
> 
> (I put report for Linux 3.17 under [2])
> 
> This rcu_sched self-detected stall is usually reproduced 2 or 3 times
> out of 10 runs, but sometimes even more runs go without issue.
> 
> I bisected [1] it to commit
> 
> commit 743162013d40ca612b4cb53d3a200dff2d9ab26e
> Author: NeilBrown 
> Date:   Mon Jul 7 15:16:04 2014 +1000
> 
> sched: Remove proliferation of wait_on_bit() action functions
> 
> The only change I noticed is from (mm/filemap.c)
> 
>   io_schedule();
>   fatal_signal_pending(current)
> 
> to (kernel/sched/wait.c)
> 
>   signal_pending_state(current->state, current)
>   io_schedule();
> 
> and if I apply following diff I don't see stalls anymore.
> 
> diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
> index a104879..2d68cdb 100644
> --- a/kernel/sched/wait.c
> +++ b/kernel/sched/wait.c
> @@ -514,9 +514,10 @@ EXPORT_SYMBOL(bit_wait);
> 
>  __sched int bit_wait_io(void *word)
>  {
> +   io_schedule();
> +
> if (signal_pending_state(current->state, current))
> return 1;
> -   io_schedule();
> return 0;
>  }
>  EXPORT_SYMBOL(bit_wait_io);
> 
> Any ideas why it might happen and why diff above helps?
> 
> [1] Bisect log:
> 
> I checked 4.[0-3] and 3.1[7-9] manually
> I have https://lkml.org/lkml/2015/8/26/649 for better report
> 
>> git bisect start '--no-checkout'
>> # good: [19583ca584d6f574384e17fe7613dfaeadcdc4a6] Linux 3.16
>> git bisect good 19583ca584d6f574384e17fe7613dfaeadcdc4a6
>> # bad: [53ee983378ff23e8f3ff95ecf99dea7c6c221900] Merge tag 
>> 'staging-3.17-rc1' of 
>> git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/staging
>> git bisect bad 53ee983378ff23e8f3ff95ecf99dea7c6c221900
>> # good: [2042088cd67d0064d18c52c13c69af2499907bb1] staging: comedi: 
>> ni_labpc: tidy up labpc_ai_scan_mode()
>> git bisect good 2042088cd67d0064d18c52c13c69af2499907bb1
>> # bad: [98959948a7ba33cf8c708626e0d2a1456397e1c6] Merge branch 
>> 'sched-core-for-linus' of 
>> git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
>> git bisect bad 98959948a7ba33cf8c708626e0d2a1456397e1c6
>> # good: [c9b88e9581828bb8bba06c5e7ee8ed1761172b6e] Merge tag 'trace-3.17-2' 
>> of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace
>> git bisect good c9b88e9581828bb8bba06c5e7ee8ed1761172b6e
>> # good: [5bda4f638f36ef4c4e3b1397b02affc3db94356e]

Re: [BISECTED] rcu_sched self-detected stall since 3.17

2015-12-01 Thread Ross Green

I too have traced a similar RCU stall all the way back to 3.17.

Seems to affect RCU preempt code as well.

I had not been able to find a sure fail way to trigger this and it
could take several days running before problem arises.

Ross
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Re: [BISECTED] rcu_sched self-detected stall since 3.17

2015-12-01 Thread Vladimir Murzin

On 20/11/15 15:35, Vladimir Murzin wrote:
> Hi,
> 
> I've been getting rcu_sched self-detected stall on one of our test
> environment with the following (or similar) log:
> 
> Linux 4.3

Anybody looking into this? Oleg, Peter, any ideas what's happening here?

Thanks
Vladimir

> 
>> INFO: rcu_sched self-detected stall on CPU
>>  2: (2099 ticks this GP) idle=a73/141/0 softirq=277/283 
>> fqs=2092 
>>   (t=2100 jiffies g=-197 c=-198 q=230)
>> Task dump for CPU 2:
>> paranoiaR running  0   423  1 0x0003
>> [] (unwind_backtrace) from [] (show_stack+0x10/0x14)
>> [] (show_stack) from [] (rcu_dump_cpu_stacks+0xa4/0xc4)
>> [] (rcu_dump_cpu_stacks) from [] 
>> (rcu_check_callbacks+0x2dc/0x81c)
>> [] (rcu_check_callbacks) from [] 
>> (update_process_times+0x38/0x64)
>> [] (update_process_times) from [] 
>> (tick_periodic+0xa8/0xb8)
>> [] (tick_periodic) from [] 
>> (tick_handle_periodic+0x28/0x88)
>> [] (tick_handle_periodic) from [] 
>> (arch_timer_handler_virt+0x28/0x30)
>> [] (arch_timer_handler_virt) from [] 
>> (handle_percpu_devid_irq+0x6c/0x84)
>> [] (handle_percpu_devid_irq) from [] 
>> (generic_handle_irq+0x24/0x34)
>> [] (generic_handle_irq) from [] 
>> (__handle_domain_irq+0x98/0xac)
>> [] (__handle_domain_irq) from [] 
>> (gic_handle_irq+0x54/0x90)
>> [] (gic_handle_irq) from [] (__irq_svc+0x54/0x70)
>> Exception stack(0xdb007c60 to 0xdb007ca8)
>> 7c60:    0001 dc3e9a20   0001
>> 7c80: dc3e9a20 001b 0008 000b  db007cb0 c00ac8f0 c00aa96c
>> 7ca0: 600d0113 
>> [] (__irq_svc) from [] (free_pages_prepare+0x18c/0x218)
>> [] (free_pages_prepare) from [] 
>> (free_hot_cold_page+0x34/0x168)
>> [] (free_hot_cold_page) from [] 
>> (handle_mm_fault+0x7b8/0xe60)
>> [] (handle_mm_fault) from [] (do_page_fault+0x12c/0x378)
>> [] (do_page_fault) from [] (do_DataAbort+0x38/0xb4)
>> [] (do_DataAbort) from [] (__dabt_svc+0x40/0x60)
>> Exception stack(0xdb007e68 to 0xdb007eb0)
>> 7e60:   0001b2c8 0d30  0055 0051 dbb04600
>> 7e80:  db007ec8 db8ea700 db8f3080 dba43240 0001b2c8  db007eb8
>> 7ea0: c012c178 c0174ce8 200d0113 
>> [] (__dabt_svc) from [] (__clear_user_std+0x34/0x68)
>> [] (__clear_user_std) from [] (padzero+0x58/0x74)
>> [] (padzero) from [] (load_elf_binary+0x730/0x1250)
>> [] (load_elf_binary) from [] 
>> (search_binary_handler+0xa0/0x23c)
>> [] (search_binary_handler) from [] 
>> (do_execveat_common+0x444/0x5d8)
>> [] (do_execveat_common) from [] (do_execve+0x24/0x2c)
>> [] (do_execve) from [] (ret_fast_syscall+0x0/0x3c)
> 
> (I put report for Linux 3.17 under [2])
> 
> This rcu_sched self-detected stall is usually reproduced 2 or 3 times
> out of 10 runs, but sometimes even more runs go without issue.
> 
> I bisected [1] it to commit
> 
> commit 743162013d40ca612b4cb53d3a200dff2d9ab26e
> Author: NeilBrown 
> Date:   Mon Jul 7 15:16:04 2014 +1000
> 
> sched: Remove proliferation of wait_on_bit() action functions
> 
> The only change I noticed is from (mm/filemap.c)
> 
>   io_schedule();
>   fatal_signal_pending(current)
> 
> to (kernel/sched/wait.c)
> 
>   signal_pending_state(current->state, current)
>   io_schedule();
> 
> and if I apply following diff I don't see stalls anymore.
> 
> diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
> index a104879..2d68cdb 100644
> --- a/kernel/sched/wait.c
> +++ b/kernel/sched/wait.c
> @@ -514,9 +514,10 @@ EXPORT_SYMBOL(bit_wait);
> 
>  __sched int bit_wait_io(void *word)
>  {
> +   io_schedule();
> +
> if (signal_pending_state(current->state, current))
> return 1;
> -   io_schedule();
> return 0;
>  }
>  EXPORT_SYMBOL(bit_wait_io);
> 
> Any ideas why it might happen and why diff above helps?
> 
> [1] Bisect log:
> 
> I checked 4.[0-3] and 3.1[7-9] manually
> I have https://lkml.org/lkml/2015/8/26/649 for better report
> 
>> git bisect start '--no-checkout'
>> # good: [19583ca584d6f574384e17fe7613dfaeadcdc4a6] Linux 3.16
>> git bisect good 19583ca584d6f574384e17fe7613dfaeadcdc4a6
>> # bad: [53ee983378ff23e8f3ff95ecf99dea7c6c221900] Merge tag 
>> 'staging-3.17-rc1' of 
>> git://git.kernel.org/pub/scm/linux/kernel/git/gregkh/staging
>> git bisect bad 53ee983378ff23e8f3ff95ecf99dea7c6c221900
>> # good: [2042088cd67d0064d18c52c13c69af2499907bb1] staging: comedi: 
>> ni_labpc: tidy up labpc_ai_scan_mode()
>> git bisect good 2042088cd67d0064d18c52c13c69af2499907bb1
>> # bad: [98959948a7ba33cf8c708626e0d2a1456397e1c6] Merge branch 
>> 'sched-core-for-linus' of 
>> git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
>> git bisect bad 98959948a7ba33cf8c708626e0d2a1456397e1c6
>> # good: [c9b88e9581828bb8bba06c5e7ee8ed1761172b6e] Merge tag 'trace-3.17-2' 
>> of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace
>> git bisect good c9b88e9581828bb8bba06c5e7ee8ed1761172b6e
>> # good:

Re: [BISECTED] rcu_sched self-detected stall since 3.17

2015-12-01 Thread Peter Zijlstra

Sorry for the delay and thanks for the reminder!

On Fri, Nov 20, 2015 at 03:35:38PM +, Vladimir Murzin wrote:
> commit 743162013d40ca612b4cb53d3a200dff2d9ab26e
> Author: NeilBrown 
> Date:   Mon Jul 7 15:16:04 2014 +1000
> 
> sched: Remove proliferation of wait_on_bit() action functions
> 
> The only change I noticed is from (mm/filemap.c)
> 
>   io_schedule();
>   fatal_signal_pending(current)
> 
> to (kernel/sched/wait.c)
> 
>   signal_pending_state(current->state, current)
>   io_schedule();
> 
> and if I apply following diff I don't see stalls anymore.
> 
> diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
> index a104879..2d68cdb 100644
> --- a/kernel/sched/wait.c
> +++ b/kernel/sched/wait.c
> @@ -514,9 +514,10 @@ EXPORT_SYMBOL(bit_wait);
> 
>  __sched int bit_wait_io(void *word)
>  {
> +   io_schedule();
> +
> if (signal_pending_state(current->state, current))
> return 1;
> -   io_schedule();
> return 0;
>  }
>  EXPORT_SYMBOL(bit_wait_io);
> 
> Any ideas why it might happen and why diff above helps?

Yes, the code as presented is simply wrong. And in fact most of the code
it replaced was of the right form (with a few exceptions which would
indeed have been subject to the same problem you've observed.

Note how the late:

  - cifs_sb_tcon_pending_wait
  - fscache_wait_bit_interruptible
  - sleep_on_page_killable
  - wait_inquiry
  - key_wait_bit_intr

All check the signal state _after_ calling schedule().

As opposed to:

  - gfs2_journalid_wait

which follows the broken pattern.

Further notice that most expect a return of -EINTR, which also seems
correct given that this is a signal, those that do not return -EINTR
only check for a !0 return value so would work equally well with -EINTR.

The reason this is broken is that schedule() will no-op when there is a
pending signal, while raising a signal will also issue a wakeup.

Thus the right thing to do is check for the signal state after, that way
you handle both cases:

 - calling schedule() with a signal pending
 - receiving a signal while sleeping

As such, I would propose the below patch. Oleg, do you concur?

---
Subject: sched,wait: Fix signal handling in bit wait helpers

Vladimir reported getting RCU stall warnings and bisected it back to
commit 743162013d40. That commit inadvertently reversed the calls to
schedule() and signal_pending(), thereby not handling the case where the
signal receives while we sleep.

Fixes: 743162013d40 ("sched: Remove proliferation of wait_on_bit() action 
functions")
Fixes: cbbce8220949 ("SCHED: add some "wait..on_bit...timeout()" interfaces.")
Reported-by: Vladimir Murzin 
Signed-off-by: Peter Zijlstra (Intel) 
---
 kernel/sched/wait.c | 16 
 1 file changed, 8 insertions(+), 8 deletions(-)

diff --git a/kernel/sched/wait.c b/kernel/sched/wait.c
index 052e02672d12..f10bd873e684 100644
--- a/kernel/sched/wait.c
+++ b/kernel/sched/wait.c
@@ -583,18 +583,18 @@ EXPORT_SYMBOL(wake_up_atomic_t);
 
 __sched int bit_wait(struct wait_bit_key *word)
 {
-   if (signal_pending_state(current->state, current))
-   return 1;
schedule();
+   if (signal_pending(current))
+   return -EINTR;
return 0;
 }
 EXPORT_SYMBOL(bit_wait);
 
 __sched int bit_wait_io(struct wait_bit_key *word)
 {
-   if (signal_pending_state(current->state, current))
-   return 1;
io_schedule();
+   if (signal_pending(current))
+   return -EINTR;
return 0;
 }
 EXPORT_SYMBOL(bit_wait_io);
@@ -602,11 +602,11 @@ EXPORT_SYMBOL(bit_wait_io);
 __sched int bit_wait_timeout(struct wait_bit_key *word)
 {
unsigned long now = READ_ONCE(jiffies);
-   if (signal_pending_state(current->state, current))
-   return 1;
if (time_after_eq(now, word->timeout))
return -EAGAIN;
schedule_timeout(word->timeout - now);
+   if (signal_pending(current))
+   return -EINTR;
return 0;
 }
 EXPORT_SYMBOL_GPL(bit_wait_timeout);
@@ -614,11 +614,11 @@ EXPORT_SYMBOL_GPL(bit_wait_timeout);
 __sched int bit_wait_io_timeout(struct wait_bit_key *word)
 {
unsigned long now = READ_ONCE(jiffies);
-   if (signal_pending_state(current->state, current))
-   return 1;
if (time_after_eq(now, word->timeout))
return -EAGAIN;
io_schedule_timeout(word->timeout - now);
+   if (signal_pending(current))
+   return -EINTR;
return 0;
 }
 EXPORT_SYMBOL_GPL(bit_wait_io_timeout);
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Re: [BISECTED] rcu_sched self-detected stall since 3.17

Re: [BISECTED] rcu_sched self-detected stall since 3.17

Re: [BISECTED] rcu_sched self-detected stall since 3.17

Re: [BISECTED] rcu_sched self-detected stall since 3.17

Re: [BISECTED] rcu_sched self-detected stall since 3.17

Re: [BISECTED] rcu_sched self-detected stall since 3.17

Re: [BISECTED] rcu_sched self-detected stall since 3.17

Re: [BISECTED] rcu_sched self-detected stall since 3.17

Re: [BISECTED] rcu_sched self-detected stall since 3.17

Re: [BISECTED] rcu_sched self-detected stall since 3.17

10 matches

Site Navigation

Mail list logo

Footer information