Re: rcu, sched: WARNING: CPU: 30 PID: 23771 at kernel/rcu/tree_plugin.h:337 rcu_read_unlock_special+0x369/0x550()

[Sasha Levin <sasha.levin@oracle.com>]

On 01/27/2015 06:16 PM, Paul E. McKenney wrote:
> On Tue, Jan 27, 2015 at 05:08:21PM -0500, Sasha Levin wrote:
>> On 01/27/2015 05:03 PM, Paul E. McKenney wrote:
>>> On Mon, Jan 26, 2015 at 10:08:04AM +0800, Lai Jiangshan wrote:
>>>>> On 01/25/2015 05:18 AM, Paul E. McKenney wrote:
>>>>>
>>>>>>>
>>>>>>> Good point!  In my scenario, CPU 0 would not yet have switched away from
>>>>>>> Task A.  Hmmm...  Yet Sasha really does see this failure.  Will give it
>>>>>>> some more thought.
>>>>>>>
>>>>>>> Any ideas?
>>>>>
>>>>> I don't known which commit was merged from the rcu-git-tree in Sasha's test
>>>>> I try to review it.
>>> If I had to guess, it would be 1d082fd06188 (Remove local_irq_disable()
>>> in rcu_preempt_note_context_switch()), though his finding this might be
>>> more directly related to increases in trinity's levels of stress.
>>
>> Quick update from my end: I've stopped seeing this warning, but I've also stopped
>> seeing warnings for the other RCU issue I've reported (https://lkml.org/lkml/2015/1/22/676)
>> so I'm slightly unhappy about that.
> 
> Another approach would be to remove that patch and then revert 1d082fd06188.
> 
> Either way, may I have your Tested-by?

Yup, I haven't seen it so far.

>>>>> We can fallback to git-bitsect if the reviews fails.
>>> One (very unlikely) possibility is that Sasha's compiler is ignoring the
>>> barrier() in rcu_preempt_qs().
>>
>> I'm actually running the latest gcc (trunk) as well, so it's very possible that it was
>> doing something stupid.
> 
> Hmmmm...  Could you please send along the assembly output for rcu_preempt_qs()?


0000000000002b20 <rcu_preempt_qs>:
    2b20:       e8 00 00 00 00          callq  2b25 <rcu_preempt_qs+0x5>
                        2b21: R_X86_64_PC32     __fentry__-0x4
    2b25:       55                      push   %rbp
    2b26:       48 c7 c7 00 00 00 00    mov    $0x0,%rdi
                        2b29: R_X86_64_32S      .rodata
    2b2d:       48 89 e5                mov    %rsp,%rbp
    2b30:       53                      push   %rbx
    2b31:       48 83 ec 08             sub    $0x8,%rsp
    2b35:       e8 00 00 00 00          callq  2b3a <rcu_preempt_qs+0x1a>
                        2b36: R_X86_64_PC32     __this_cpu_preempt_check-0x4
    2b3a:       65 8a 05 00 00 00 00    mov    %gs:0x0(%rip),%al        # 2b41 <rcu_preempt_qs+0x21>
                        2b3d: R_X86_64_PC32     rcu_preempt_data+0x14
    2b41:       84 c0                   test   %al,%al
    2b43:       74 0b                   je     2b50 <rcu_preempt_qs+0x30>
    2b45:       48 83 c4 08             add    $0x8,%rsp
    2b49:       5b                      pop    %rbx
    2b4a:       5d                      pop    %rbp
    2b4b:       c3                      retq
    2b4c:       0f 1f 40 00             nopl   0x0(%rax)
    2b50:       48 8b 1d 00 00 00 00    mov    0x0(%rip),%rbx        # 2b57 <rcu_preempt_qs+0x37>
                        2b53: R_X86_64_PC32     __tracepoint_str+0xb4
    2b57:       48 c7 c7 00 00 00 00    mov    $0x0,%rdi
                        2b5a: R_X86_64_32S      .rodata
    2b5e:       e8 00 00 00 00          callq  2b63 <rcu_preempt_qs+0x43>
                        2b5f: R_X86_64_PC32     __this_cpu_preempt_check-0x4
    2b63:       48 8b 3d 00 00 00 00    mov    0x0(%rip),%rdi        # 2b6a <rcu_preempt_qs+0x4a>
                        2b66: R_X86_64_PC32     __tracepoint_str+0xbc
    2b6a:       65 48 8b 35 00 00 00    mov    %gs:0x0(%rip),%rsi        # 2b72 <rcu_preempt_qs+0x52>
    2b71:       00
                        2b6e: R_X86_64_PC32     rcu_preempt_data+0x4
    2b72:       48 89 da                mov    %rbx,%rdx
    2b75:       e8 66 fd ff ff          callq  28e0 <trace_rcu_grace_period>
    2b7a:       48 c7 c7 00 00 00 00    mov    $0x0,%rdi
                        2b7d: R_X86_64_32S      .rodata+0x260
    2b81:       e8 00 00 00 00          callq  2b86 <rcu_preempt_qs+0x66>
                        2b82: R_X86_64_PC32     __this_cpu_preempt_check-0x4
    2b86:       65 c6 05 00 00 00 00    movb   $0x1,%gs:0x0(%rip)        # 2b8e <rcu_preempt_qs+0x6e>
    2b8d:       01
                        2b89: R_X86_64_PC32     rcu_preempt_data+0x13
    2b8e:       65 48 8b 1c 25 00 00    mov    %gs:0x0,%rbx
    2b95:       00 00
                        2b93: R_X86_64_32S      current_task
    2b97:       48 8d bb 15 07 00 00    lea    0x715(%rbx),%rdi
    2b9e:       48 b8 00 00 00 00 00    movabs $0xdffffc0000000000,%rax
    2ba5:       fc ff df
    2ba8:       48 89 fa                mov    %rdi,%rdx
    2bab:       48 c1 ea 03             shr    $0x3,%rdx
    2baf:       0f b6 04 02             movzbl (%rdx,%rax,1),%eax
    2bb3:       48 89 fa                mov    %rdi,%rdx
    2bb6:       83 e2 07                and    $0x7,%edx
    2bb9:       38 d0                   cmp    %dl,%al
    2bbb:       7f 04                   jg     2bc1 <rcu_preempt_qs+0xa1>
    2bbd:       84 c0                   test   %al,%al
    2bbf:       75 0e                   jne    2bcf <rcu_preempt_qs+0xaf>
    2bc1:       c6 83 15 07 00 00 00    movb   $0x0,0x715(%rbx)
    2bc8:       48 83 c4 08             add    $0x8,%rsp
    2bcc:       5b                      pop    %rbx
    2bcd:       5d                      pop    %rbp
    2bce:       c3                      retq
    2bcf:       e8 00 00 00 00          callq  2bd4 <rcu_preempt_qs+0xb4>
                        2bd0: R_X86_64_PC32     __asan_report_store1_noabort-0x4
    2bd4:       eb eb                   jmp    2bc1 <rcu_preempt_qs+0xa1>
    2bd6:       66 2e 0f 1f 84 00 00    nopw   %cs:0x0(%rax,%rax,1)
    2bdd:       00 00 00


Thanks,
Sasha