Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1598049 > unrolled thread

Re: srcu: BUG in __synchronize_srcu

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: srcu: BUG in __synchronize_srcu Andrey Konovalov <andreyknvl@google.com> - 2017-03-10 20:40 +0100
    Re: srcu: BUG in __synchronize_srcu Dmitry Vyukov <dvyukov@google.com> - 2017-03-10 20:50 +0100
    Re: srcu: BUG in __synchronize_srcu "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2017-03-10 23:30 +0100
      Re: srcu: BUG in __synchronize_srcu Mathieu Desnoyers <mathieu.desnoyers@efficios.com> - 2017-03-11 15:30 +0100
        Re: srcu: BUG in __synchronize_srcu "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2017-03-11 21:10 +0100
      Re: srcu: BUG in __synchronize_srcu Lance Roy <ldr709@gmail.com> - 2017-03-14 08:50 +0100
        Re: srcu: BUG in __synchronize_srcu "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2017-03-14 17:30 +0100
          Re: srcu: BUG in __synchronize_srcu Dmitry Vyukov <dvyukov@google.com> - 2017-03-27 14:40 +0200
            Re: srcu: BUG in __synchronize_srcu "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2017-03-27 16:20 +0200
              Re: srcu: BUG in __synchronize_srcu Dmitry Vyukov <dvyukov@google.com> - 2017-03-27 17:00 +0200

#1598049 — Re: srcu: BUG in __synchronize_srcu

On Fri, Mar 10, 2017 at 8:28 PM, Andrey Konovalov <andreyknvl@google.com> wrote:
> Hi,
>
> I've got the following error report while fuzzing the kernel with
> syzkaller on an arm64 board.

This also happened on x86 a few times during fuzzing, however it
wasn't reproducible.

>
> On linux-next commit 56b8bad5e066c23e8fa273ef5fba50bd3da2ace8 (Mar 8).
>
> A reproducer and .config are attached.
>
> The bug happens while executing the following syzkaller program in a loop.
> While it looks kvm-related, it might be that kvm just stresses the
> srcu subsystem.
>
> mmap(&(0x7f0000000000/0xfff000)=nil, (0xfff000), 0x3, 0x32,
> 0xffffffffffffffff, 0x0)
> r0 = openat$kvm(0xffffffffffffff9c,
> &(0x7f0000a05000)="2f6465762f6b766d00", 0x0, 0x0)
> ioctl$KVM_CREATE_VM(r0, 0xae01, 0x0)
>
> ------------[ cut here ]------------
> kernel BUG at kernel/rcu/srcu.c:436!
> Internal error: Oops - BUG: 0 [#1] PREEMPT SMP
> Modules linked in: meson_drm drm_kms_helper drm dwmac_generic realtek
> dwmac_meson8b stmmac_platform stmmac meson_rng rng_core meson_gxbb_wdt
> ipv6
> CPU: 3 PID: 4250 Comm: a.out Not tainted 4.11.0-rc1-next-20170308-xc2-dirty #3
> Hardware name: Hardkernel ODROID-C2 (DT)
> task: ffff800063699700 task.stack: ffff800063cfc000
> PC is at[<        none        >] __synchronize_srcu+0x3d0/0x470
> kernel/rcu/srcu.c:412
> LR is at[<        none        >] __synchronize_srcu+0x130/0x470
> kernel/rcu/srcu.c:434
> pc : [<ffff20000821a3b8>] lr : [<ffff20000821a118>] pstate: 80000145
> sp : ffff800063cffb00
> x29: ffff800063cffb00 x28: ffff80005b1d6e00
> x27: 1fffe4000156b242 x26: ffff800063cffb70
> x25: 1fffe4000156b23b x24: ffff20000ab591d8
> x23: ffff200009dbf000 x22: ffff20000ab591a0
> x21: ffff20000ab59210 x20: ffff800063cffb70
> x19: ffff20000ab59190 x18: 0000000000000a03
> x17: 0000ffff944f3950 x16: ffff20000811f818
> x15: 0000000000000000 x14: 0000000000000007
> x13: 0000000000000002 x12: 0000000000000000
> x11: 0000000000000040 x10: 1fffe400014b568c
> x9 : ffff20000ab29000 x8 : 0000000000000007
> x7 : 0000000000000001 x6 : 0000000000000000
> x5 : 0000000000000040 x4 : 0000000000000003
> x3 : ffff20000ab59208 x2 : 1fffe4000156b243
> x1 : 0000000000000000 x0 : ffff80005e71fb70
>
> Process a.out (pid: 4250, stack limit = 0xffff800063cfc000)
> Stack: (0xffff800063cffb00 to 0xffff800063d00000)
> fb00: ffff800063cffbd0 ffff20000821a480 ffff20000ab59190 1ffff0000b63adc0
> fb20: dfff200000000000 ffff20000ab59190 ffff80004b9a8a00 1ffff000097351bc
> fb40: ffff80004b9a8de0 0000000000000000 ffff800060cad328 ffff80005b1d6e00
> fb60: ffff80004b9a8a00 1ffff000097351bc ffff80004f5e7b70 ffff200008217968
> fb80: ffff800000000001 dead4ead00010001 dfff2000ffffffff ffffffffffffffff
> fba0: ffff20000ab4c4b0 0000000000000000 0000000000000000 ffff200009b0b358
> fbc0: ffff800063cffbc0 ffff800063cffbc0 ffff800063cffbf0 ffff2000083ffd20
> fbe0: ffff80005b1d6e00 0000000000000140 ffff800063cffc50 ffff2000083aedfc
> fc00: ffff80004b9a8a00 ffff80004b9a8a00 ffff80004b9a8d78 0000000000000001
> fc20: 00000000000002a6 ffff80004f406780 ffff80004b9a8aa0 ffff800063699ac8
> fc40: 1ffff0000c6d3359 ffff800063699700 ffff800063cffd20 ffff20000810caec
> fc60: ffff80004b9a8a00 ffff80004b9a8b20 ffff80004b9a8d78 0000000000000001
> fc80: ffff80005ebae2d8 ffff800063699ac8 ffff800063cffca0 ffff20000840fc08
> fca0: ffff800063cffce0 ffff20000843327c ffff80005ebae2d8 ffff80004b9a8a00
> fcc0: ffff80005ebae0f0 ffff200009de8000 ffff800063cffce0 ffff2000084332c4
> fce0: ffff800063cffd20 ffff20000810cc64 ffff80004b9a8a00 ffff80004b9a8a48
> fd00: ffff80004b9a8d78 0000000000000001 ffff800063cffd20 ffff20000810cae0
> fd20: ffff800063cffd60 ffff20000811db88 ffff800063699700 ffff800063699700
> fd40: ffff80004b9a8a00 0000000000000001 00000000000002a6 ffff80004f406780
> fd60: ffff800063cffe40 ffff20000811f694 ffff80004f406780 0000000000000000
> fd80: ffff80004f40681c 0000000000000004 1ffff00009e80d03 1ffff00009e80d02
> fda0: ffff80004f406810 ffff800063699bd0 ffff800063699700 ffff800063699700
> fdc0: ffff800063cffe80 ffff200008490868 0000000000000000 ffff80005fd45000
> fde0: ffff80006369972c ffff800063699d48 1ffff0000c6d32e5 0000000000000004
> fe00: 0000000000000123 000000000000001d 1ffff0000c6d33a9 ffff800063699700
> fe20: ffff800063cffe30 ffff200008813c5c ffff800063cffe40 ffff20000811f688
> fe40: ffff800063cffea0 ffff20000811f838 0000000000000000 000060006d24d000
> fe60: ffffffffffffffff 0000ffff944f3974 0000000000000000 0000000000000015
> fe80: 0000000000000123 000000000000005e ffff200009852000 ffff20000811f82c
> fea0: 0000000000000000 ffff200008083f70 0000000000000000 0000000000000015
> fec0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> fee0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> ff00: 000000000000005e ffffff80ffffffd0 0101010101010101 0000000000000020
> ff20: 0000000000000018 0000000056bcb768 0000000000000000 0000ffff945be000
> ff40: 0000000000413110 0000ffff944f3950 0000000000000a03 00000000004020f8
> ff60: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> ff80: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> ffa0: 0000000000000000 0000ffffc0cc99b0 0000000000401248 0000ffffc0cc99b0
> ffc0: 0000ffff944f3974 0000000000000000 0000000000000000 000000000000005e
> ffe0: 0000000000000000 0000000000000000 0403030303030100 0807060606060605
> Call trace:
> Exception stack(0xffff800063cff910 to 0xffff800063cffa40)
> f900:                                   ffff20000ab59190 0001000000000000
> f920: ffff800063cffb00 ffff20000821a3b8 0000000080000145 000000000000003d
> f940: 1fffe4000156b23b ffff800063cffb70 ffff800063cff980 0001000000000000
> f960: ffff800063cff9d0 ffff2000081da8e8 ffff800063699ec0 ffff200009df9000
> f980: ffff800063cff990 ffff20000891e1e0 ffff800063cff9d0 ffff20000891e23c
> f9a0: ffff200009dbfe18 0000000000000040 0000000000000004 0000000000000001
> f9c0: 00000000000008ac 00000000000008ac ffff80005e71fb70 0000000000000000
> f9e0: 1fffe4000156b243 ffff20000ab59208 0000000000000003 0000000000000040
> fa00: 0000000000000000 0000000000000001 0000000000000007 ffff20000ab29000
> fa20: 1fffe400014b568c 0000000000000040 0000000000000000 0000000000000002
> [<ffff20000821a3b8>] __synchronize_srcu+0x3d0/0x470 kernel/rcu/srcu.c:412
> [<ffff20000821a480>] synchronize_srcu+0x28/0x60 kernel/rcu/srcu.c:516
> [<ffff2000083ffd20>] __mmu_notifier_release+0x268/0x3e0 mm/mmu_notifier.c:102
> [<     inline     >] mmu_notifier_release ./include/linux/mmu_notifier.h:235
> [<ffff2000083aedfc>] exit_mmap+0x21c/0x288 mm/mmap.c:2941
> [<     inline     >] __mmput kernel/fork.c:881
> [<ffff20000810caec>] mmput+0xdc/0x2e0 kernel/fork.c:903
> [<     inline     >] exit_mm kernel/exit.c:557
> [<ffff20000811db88>] do_exit+0x648/0x2020 kernel/exit.c:865
> [<ffff20000811f694>] do_group_exit+0xdc/0x260 kernel/exit.c:982
> [<     inline     >] SYSC_exit_group kernel/exit.c:993
> [<ffff20000811f838>] __wake_up_parent+0x0/0x60 kernel/exit.c:991
> [<ffff200008083f70>] el0_svc_naked+0x24/0x28 arch/arm64/kernel/entry.S:813
> Code: 97feee10 35fff680 17ffff1c d503201f (d4210000)
> ---[ end trace b727e9858bfac1ff ]---
> Kernel panic - not syncing: Fatal exception

[toc] | [next] | [standalone]

#1598052

On Fri, Mar 10, 2017 at 8:29 PM, 'Andrey Konovalov' via syzkaller
<syzkaller@googlegroups.com> wrote:
> On Fri, Mar 10, 2017 at 8:28 PM, Andrey Konovalov <andreyknvl@google.com> wrote:
>> Hi,
>>
>> I've got the following error report while fuzzing the kernel with
>> syzkaller on an arm64 board.
>
> This also happened on x86 a few times during fuzzing, however it
> wasn't reproducible.


FWIW here are 2 crashes that we hit on x86_64 on
linux-next/56b8bad5e066c23e8fa273ef5fba50bd3da2ace8:

kernel BUG at kernel/rcu/srcu.c:436!
invalid opcode: 0000 [#1] SMP KASAN
Dumping ftrace buffer:
   (ftrace buffer empty)
Modules linked in:
CPU: 1 PID: 26567 Comm: syz-executor3 Not tainted 4.11.0-rc1-next-20170308+ #2
Hardware name: Google Google Compute Engine/Google Compute Engine,
BIOS Google 01/01/2011
task: ffff8801cbcba4c0 task.stack: ffff8801d1258000
RIP: 0010:__synchronize_srcu+0x695/0x7f0 kernel/rcu/srcu.c:412
RSP: 0018:ffff8801d125ea00 EFLAGS: 00010287
RAX: dffffc0000000000 RBX: ffff8801d125ea90 RCX: 0000000000000000
RDX: 1ffffffff0cf68f0 RSI: 0000000000000040 RDI: ffffffff867b4788
RBP: ffff8801d125eb40 R08: ffffffff867b4780 R09: ffffffff867b4778
R10: 0000000000000000 R11: 0000000000000000 R12: 1ffff1003a24bd46
R13: ffffffff867b4700 R14: ffffffff85680588 R15: ffff8801d125ea90
FS:  00007f55c1334700(0000) GS:ffff8801dbf00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 000000c81cbd7200 CR3: 00000001da67d000 CR4: 00000000001426e0
Call Trace:
 synchronize_srcu+0x1e/0x40 kernel/rcu/srcu.c:516
 __mmu_notifier_release+0x373/0x6c0 mm/mmu_notifier.c:102
 mmu_notifier_release include/linux/mmu_notifier.h:235 [inline]
 exit_mmap+0x3cc/0x490 mm/mmap.c:2941
 __mmput kernel/fork.c:881 [inline]
 mmput+0x22b/0x6e0 kernel/fork.c:903
 exit_mm kernel/exit.c:557 [inline]
 do_exit+0xa41/0x28f0 kernel/exit.c:865
 do_group_exit+0x149/0x420 kernel/exit.c:982
 get_signal+0x7e0/0x1820 kernel/signal.c:2318
 do_signal+0xd2/0x2190 arch/x86/kernel/signal.c:808
 exit_to_usermode_loop+0x200/0x2a0 arch/x86/entry/common.c:157
 prepare_exit_to_usermode arch/x86/entry/common.c:191 [inline]
 syscall_return_slowpath+0x4d3/0x570 arch/x86/entry/common.c:260
 entry_SYSCALL_64_fastpath+0xbc/0xbe
RIP: 0033:0x44fb79
RSP: 002b:00007f55c1333b58 EFLAGS: 00000212 ORIG_RAX: 0000000000000101
RAX: 0000000000000026 RBX: 00000000007080a8 RCX: 000000000044fb79
RDX: 0000000000000000 RSI: 000000002003a000 RDI: ffffffffffffff9c
RBP: 0000000000000331 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000212 R12: ffffffffffffff9c
R13: 000000002003a000 R14: 0000000000000000 R15: 0000000000000000
Code: e8 e1 3e f8 ff 85 c0 0f 85 9a fd ff ff be ff ff ff ff 48 c7 c7
c0 d9 12 85 e8 c8 3e f8 ff 85 c0 0f 85 81 fd ff ff e9 12 fa ff ff <0f>
0b c6 44 24 20 00 e9 e5 fc ff ff c6 44 24 20 00 41 bf 01 00
RIP: __synchronize_srcu+0x695/0x7f0 kernel/rcu/srcu.c:412 RSP: ffff8801d125ea00
---[ end trace c25c3b4c622f543d ]---


------------[ cut here ]------------
QAT: Invalid ioctl
kernel BUG at kernel/rcu/srcu.c:436!
invalid opcode: 0000 [#1] SMP KASAN
Dumping ftrace buffer:
   (ftrace buffer empty)
Modules linked in:
CPU: 0 PID: 3886 Comm: kworker/u4:10 Not tainted 4.11.0-rc1-next-20170308+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine,
BIOS Google 01/01/2011
Workqueue: events_unbound fsnotify_mark_destroy_workfn
task: ffff8801c384c880 task.stack: ffff8801d9658000
RIP: 0010:__synchronize_srcu+0x695/0x7f0 kernel/rcu/srcu.c:412
RSP: 0018:ffff8801d965f250 EFLAGS: 00010287
RAX: dffffc0000000000 RBX: ffff8801d965f2e0 RCX: 0000000000000000
RDX: 1ffffffff0cf81a8 RSI: 0000000000000040 RDI: ffffffff867c0d48
RBP: ffff8801d965f390 R08: ffffffff867c0d40 R09: ffffffff867c0d38
R10: 0000000000000006 R11: 0000000000000000 R12: 1ffff1003b2cbe50
R13: ffffffff867c0cc0 R14: ffffffff85680588 R15: ffff8801d965f2e0
FS:  0000000000000000(0000) GS:ffff8801dbe00000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000001ddbc37000 CR3: 00000001c46e2000 CR4: 00000000001406f0
Call Trace:
 synchronize_srcu+0x1e/0x40 kernel/rcu/srcu.c:516
 fsnotify_mark_destroy_list+0x19d/0x540 fs/notify/mark.c:539
 fsnotify_mark_destroy_workfn+0xe/0x10 fs/notify/mark.c:549
 process_one_work+0xbd0/0x1c10 kernel/workqueue.c:2097
 worker_thread+0x223/0x1990 kernel/workqueue.c:2231
 kthread+0x326/0x3f0 kernel/kthread.c:229
 ret_from_fork+0x31/0x40 arch/x86/entry/entry_64.S:430
Code: e8 e1 3e f8 ff 85 c0 0f 85 9a fd ff ff be ff ff ff ff 48 c7 c7
c0 d9 12 85 e8 c8 3e f8 ff 85 c0 0f 85 81 fd ff ff e9 12 fa ff ff <0f>
0b c6 44 24 20 00 e9 e5 fc ff ff c6 44 24 20 00 41 bf 01 00
RIP: __synchronize_srcu+0x695/0x7f0 kernel/rcu/srcu.c:412 RSP: ffff8801d965f250
---[ end trace 4aa6116de274db2a ]---

[toc] | [prev] | [next] | [standalone]

#1598144

On Fri, Mar 10, 2017 at 08:29:55PM +0100, Andrey Konovalov wrote:
> On Fri, Mar 10, 2017 at 8:28 PM, Andrey Konovalov <andreyknvl@google.com> wrote:
> > Hi,
> >
> > I've got the following error report while fuzzing the kernel with
> > syzkaller on an arm64 board.
> 
> This also happened on x86 a few times during fuzzing, however it
> wasn't reproducible.
> 
> >
> > On linux-next commit 56b8bad5e066c23e8fa273ef5fba50bd3da2ace8 (Mar 8).
> >
> > A reproducer and .config are attached.
> >
> > The bug happens while executing the following syzkaller program in a loop.
> > While it looks kvm-related, it might be that kvm just stresses the
> > srcu subsystem.
> >
> > mmap(&(0x7f0000000000/0xfff000)=nil, (0xfff000), 0x3, 0x32,
> > 0xffffffffffffffff, 0x0)
> > r0 = openat$kvm(0xffffffffffffff9c,
> > &(0x7f0000a05000)="2f6465762f6b766d00", 0x0, 0x0)
> > ioctl$KVM_CREATE_VM(r0, 0xae01, 0x0)
> >
> > ------------[ cut here ]------------
> > kernel BUG at kernel/rcu/srcu.c:436!

This is on v4.10, correct?

> > Internal error: Oops - BUG: 0 [#1] PREEMPT SMP
> > Modules linked in: meson_drm drm_kms_helper drm dwmac_generic realtek
> > dwmac_meson8b stmmac_platform stmmac meson_rng rng_core meson_gxbb_wdt
> > ipv6
> > CPU: 3 PID: 4250 Comm: a.out Not tainted 4.11.0-rc1-next-20170308-xc2-dirty #3
> > Hardware name: Hardkernel ODROID-C2 (DT)
> > task: ffff800063699700 task.stack: ffff800063cfc000
> > PC is at[<        none        >] __synchronize_srcu+0x3d0/0x470
> > kernel/rcu/srcu.c:412
> > LR is at[<        none        >] __synchronize_srcu+0x130/0x470
> > kernel/rcu/srcu.c:434
> > pc : [<ffff20000821a3b8>] lr : [<ffff20000821a118>] pstate: 80000145
> > sp : ffff800063cffb00
> > x29: ffff800063cffb00 x28: ffff80005b1d6e00
> > x27: 1fffe4000156b242 x26: ffff800063cffb70
> > x25: 1fffe4000156b23b x24: ffff20000ab591d8
> > x23: ffff200009dbf000 x22: ffff20000ab591a0
> > x21: ffff20000ab59210 x20: ffff800063cffb70
> > x19: ffff20000ab59190 x18: 0000000000000a03
> > x17: 0000ffff944f3950 x16: ffff20000811f818
> > x15: 0000000000000000 x14: 0000000000000007
> > x13: 0000000000000002 x12: 0000000000000000
> > x11: 0000000000000040 x10: 1fffe400014b568c
> > x9 : ffff20000ab29000 x8 : 0000000000000007
> > x7 : 0000000000000001 x6 : 0000000000000000
> > x5 : 0000000000000040 x4 : 0000000000000003
> > x3 : ffff20000ab59208 x2 : 1fffe4000156b243
> > x1 : 0000000000000000 x0 : ffff80005e71fb70
> >
> > Process a.out (pid: 4250, stack limit = 0xffff800063cfc000)
> > Stack: (0xffff800063cffb00 to 0xffff800063d00000)
> > fb00: ffff800063cffbd0 ffff20000821a480 ffff20000ab59190 1ffff0000b63adc0
> > fb20: dfff200000000000 ffff20000ab59190 ffff80004b9a8a00 1ffff000097351bc
> > fb40: ffff80004b9a8de0 0000000000000000 ffff800060cad328 ffff80005b1d6e00
> > fb60: ffff80004b9a8a00 1ffff000097351bc ffff80004f5e7b70 ffff200008217968
> > fb80: ffff800000000001 dead4ead00010001 dfff2000ffffffff ffffffffffffffff
> > fba0: ffff20000ab4c4b0 0000000000000000 0000000000000000 ffff200009b0b358
> > fbc0: ffff800063cffbc0 ffff800063cffbc0 ffff800063cffbf0 ffff2000083ffd20
> > fbe0: ffff80005b1d6e00 0000000000000140 ffff800063cffc50 ffff2000083aedfc
> > fc00: ffff80004b9a8a00 ffff80004b9a8a00 ffff80004b9a8d78 0000000000000001
> > fc20: 00000000000002a6 ffff80004f406780 ffff80004b9a8aa0 ffff800063699ac8
> > fc40: 1ffff0000c6d3359 ffff800063699700 ffff800063cffd20 ffff20000810caec
> > fc60: ffff80004b9a8a00 ffff80004b9a8b20 ffff80004b9a8d78 0000000000000001
> > fc80: ffff80005ebae2d8 ffff800063699ac8 ffff800063cffca0 ffff20000840fc08
> > fca0: ffff800063cffce0 ffff20000843327c ffff80005ebae2d8 ffff80004b9a8a00
> > fcc0: ffff80005ebae0f0 ffff200009de8000 ffff800063cffce0 ffff2000084332c4
> > fce0: ffff800063cffd20 ffff20000810cc64 ffff80004b9a8a00 ffff80004b9a8a48
> > fd00: ffff80004b9a8d78 0000000000000001 ffff800063cffd20 ffff20000810cae0
> > fd20: ffff800063cffd60 ffff20000811db88 ffff800063699700 ffff800063699700
> > fd40: ffff80004b9a8a00 0000000000000001 00000000000002a6 ffff80004f406780
> > fd60: ffff800063cffe40 ffff20000811f694 ffff80004f406780 0000000000000000
> > fd80: ffff80004f40681c 0000000000000004 1ffff00009e80d03 1ffff00009e80d02
> > fda0: ffff80004f406810 ffff800063699bd0 ffff800063699700 ffff800063699700
> > fdc0: ffff800063cffe80 ffff200008490868 0000000000000000 ffff80005fd45000
> > fde0: ffff80006369972c ffff800063699d48 1ffff0000c6d32e5 0000000000000004
> > fe00: 0000000000000123 000000000000001d 1ffff0000c6d33a9 ffff800063699700
> > fe20: ffff800063cffe30 ffff200008813c5c ffff800063cffe40 ffff20000811f688
> > fe40: ffff800063cffea0 ffff20000811f838 0000000000000000 000060006d24d000
> > fe60: ffffffffffffffff 0000ffff944f3974 0000000000000000 0000000000000015
> > fe80: 0000000000000123 000000000000005e ffff200009852000 ffff20000811f82c
> > fea0: 0000000000000000 ffff200008083f70 0000000000000000 0000000000000015
> > fec0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> > fee0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> > ff00: 000000000000005e ffffff80ffffffd0 0101010101010101 0000000000000020
> > ff20: 0000000000000018 0000000056bcb768 0000000000000000 0000ffff945be000
> > ff40: 0000000000413110 0000ffff944f3950 0000000000000a03 00000000004020f8
> > ff60: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> > ff80: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> > ffa0: 0000000000000000 0000ffffc0cc99b0 0000000000401248 0000ffffc0cc99b0
> > ffc0: 0000ffff944f3974 0000000000000000 0000000000000000 000000000000005e
> > ffe0: 0000000000000000 0000000000000000 0403030303030100 0807060606060605
> > Call trace:
> > Exception stack(0xffff800063cff910 to 0xffff800063cffa40)
> > f900:                                   ffff20000ab59190 0001000000000000
> > f920: ffff800063cffb00 ffff20000821a3b8 0000000080000145 000000000000003d
> > f940: 1fffe4000156b23b ffff800063cffb70 ffff800063cff980 0001000000000000
> > f960: ffff800063cff9d0 ffff2000081da8e8 ffff800063699ec0 ffff200009df9000
> > f980: ffff800063cff990 ffff20000891e1e0 ffff800063cff9d0 ffff20000891e23c
> > f9a0: ffff200009dbfe18 0000000000000040 0000000000000004 0000000000000001
> > f9c0: 00000000000008ac 00000000000008ac ffff80005e71fb70 0000000000000000
> > f9e0: 1fffe4000156b243 ffff20000ab59208 0000000000000003 0000000000000040
> > fa00: 0000000000000000 0000000000000001 0000000000000007 ffff20000ab29000
> > fa20: 1fffe400014b568c 0000000000000040 0000000000000000 0000000000000002
> > [<ffff20000821a3b8>] __synchronize_srcu+0x3d0/0x470 kernel/rcu/srcu.c:412
> > [<ffff20000821a480>] synchronize_srcu+0x28/0x60 kernel/rcu/srcu.c:516
> > [<ffff2000083ffd20>] __mmu_notifier_release+0x268/0x3e0 mm/mmu_notifier.c:102
> > [<     inline     >] mmu_notifier_release ./include/linux/mmu_notifier.h:235
> > [<ffff2000083aedfc>] exit_mmap+0x21c/0x288 mm/mmap.c:2941
> > [<     inline     >] __mmput kernel/fork.c:881
> > [<ffff20000810caec>] mmput+0xdc/0x2e0 kernel/fork.c:903
> > [<     inline     >] exit_mm kernel/exit.c:557
> > [<ffff20000811db88>] do_exit+0x648/0x2020 kernel/exit.c:865
> > [<ffff20000811f694>] do_group_exit+0xdc/0x260 kernel/exit.c:982
> > [<     inline     >] SYSC_exit_group kernel/exit.c:993
> > [<ffff20000811f838>] __wake_up_parent+0x0/0x60 kernel/exit.c:991
> > [<ffff200008083f70>] el0_svc_naked+0x24/0x28 arch/arm64/kernel/entry.S:813
> > Code: 97feee10 35fff680 17ffff1c d503201f (d4210000)
> > ---[ end trace b727e9858bfac1ff ]---
> > Kernel panic - not syncing: Fatal exception

So the theory is that if !sp->running, all of SRCU's queues must be empty.
So if you are holding ->queue_lock (with irqs disabled) and you see
!sp->running, and then you enqueue a callback on ->batch_check0, then
that callback must be the first in the list.  And the code preceding
the WARN_ON() you triggered does in fact check and enqueue shile holding
->queue_lock with irqs disabled.

And rcu_batch_queue() does operate FIFO as required.  (Otherwise,
srcu_barrier() would not work.)

There are only three calls to rcu_batch_queue(), and the one involved with
the WARN_ON() enqueues to ->batch_check0.  The other two enqueue to
->batch_queue.  Callbacks move from ->batch_queue to ->batch_check0 to
->batch_check1 to ->batch_done, so nothing should slip in front.

Of course, if ->running were ever set to false with any of ->batch_check0,
->batch_check1, or ->batch_done non-empty, this WARN_ON() would trigger.
But srcu_reschedule() sets it to false only if all four batches are
empty (and checks and sets under ->queue_lock()), and all other cases
where it is set to false happen at initialization time, and also clear
out the queues.  Of course, if someone raced an init_srcu_struct() with
either a call_srcu() or synchronize_srcu(), all bets are off.  Now,
mmu_notifier.c does invoke init_srcu_struct() manually, but it does
so at subsys_initcall() time.  Which -might- be after other things are
happening, so one "hail Mary" attempted fix is to remove mmu_notifier_init()
and replace the "static struct srcu_struct srcu" with:

	DEFINE_STATIC_SRCU(srcu);

But this might require changing the name -- I vaguely recall some
strangeness where the names of statically defined per-CPU variables need
to be globally unique even when static.  Easy enough to do, though.
Might need a similar change to the "srcu" instances defined in vmd.c
and kvm_host.h -- assuming that this change helps.

Another possibility is that something in SRCU is messing with either the
queues or the ->running field without holding ->queue_lock.  And that does
seem to be happening -- srcu_advance_batches() invokes rcu_batch_move()
without holding anything.  Which seems like it could cause trouble
if someone else was invoking synchronize_srcu() concurrently.  Those
particular invocations might be safe due to access only by a single
kthread/workqueue, given that all updates to ->batch_queue are protected
by ->queue_lock (aside from initialization).

But ->batch_check0 is updated by __synchronize_srcu(), though protected
by ->queue_lock, and only if ->running is false, and with both the
check and the update protected by the same ->queue_lock critical section.
If ->running is false, then the workqueue cannot be running, so it remains
to see if all other updates to ->batch_check0 are either with ->queue_lock
held and ->running false on the one hand or from the workqueue handler
on the other:

srcu_collect_new() updates with ->queue_lock held, but does not check
	->running.  It is invoked only from process_srcu(), which in
	turn is invoked only as a workqueue handler.  The work is queued
	from:

	call_srcu(), which does so with ->queue_lock held having just
		set ->running to true.

	srcu_reschedule(), which invokes it if there are non-empty
		queues.  This is invoked from __synchronize_srcu()
		in the case where it has set ->running to true
		after finding the queues empty, which should imply
		no other instances.

		It is also invoked from process_srcu(), which is
		invoked only as a workqueue handler.  (Yay
		recursive inquiry!)

srcu_advance_batches() updates without locks held.  It is invoked as
	follows:

	__synchronize_srcu() in the case where ->running was set, which
		as noted before excludes workqueue handlers.

	process_srcu() which as noted before is only invoked from
		a workqueue handler.

So an SRCU workqueue is invoked only from a workqueue handler, or from
some other task that transitioned ->running from false to true while
holding ->queuelock.  There should therefore only be one SRCU workqueue
per srcu_struct, so this should be safe.  Though I hope that it can
be simplified a bit.  :-/

So the only suggestion I have at the moment is static definition of
the "srcu" variable.  Lai, Josh, Steve, Mathieu, anything I missed?

						Thanx, Paul

[toc] | [prev] | [next] | [standalone]

#1598347

----- On Mar 10, 2017, at 5:26 PM, Paul E. McKenney paulmck@linux.vnet.ibm.com wrote:

> On Fri, Mar 10, 2017 at 08:29:55PM +0100, Andrey Konovalov wrote:
>> On Fri, Mar 10, 2017 at 8:28 PM, Andrey Konovalov <andreyknvl@google.com> wrote:
>> > Hi,
>> >
>> > I've got the following error report while fuzzing the kernel with
>> > syzkaller on an arm64 board.
>> 
>> This also happened on x86 a few times during fuzzing, however it
>> wasn't reproducible.
>> 
>> >
>> > On linux-next commit 56b8bad5e066c23e8fa273ef5fba50bd3da2ace8 (Mar 8).
>> >
>> > A reproducer and .config are attached.
>> >
>> > The bug happens while executing the following syzkaller program in a loop.
>> > While it looks kvm-related, it might be that kvm just stresses the
>> > srcu subsystem.
>> >
>> > mmap(&(0x7f0000000000/0xfff000)=nil, (0xfff000), 0x3, 0x32,
>> > 0xffffffffffffffff, 0x0)
>> > r0 = openat$kvm(0xffffffffffffff9c,
>> > &(0x7f0000a05000)="2f6465762f6b766d00", 0x0, 0x0)
>> > ioctl$KVM_CREATE_VM(r0, 0xae01, 0x0)
>> >
>> > ------------[ cut here ]------------
>> > kernel BUG at kernel/rcu/srcu.c:436!
> 
> This is on v4.10, correct?

No, as stated above, this is on linux-next as of March 8, 2017.

I'm currently looking at the diff of kernel/rcu/srcu.c between v4.10 and
next-20170310. There are a few changes there.

One of them is the introduction of the new srcu algorithm with separate
lock vs unlock counters, which simplifies read lock/unlock by removing the
sequence counter.

Another change that directly impacts __synchronize_rcu() (near the
BUG()) is bc138e7a "srcu: Allow mid-boot use of synchronize_srcu()".

Odds are that this change introduce an unforeseen scenario that
skips awaiting for completion later after boot than expected. It
might be worthwhile to review it closely once more.

Thoughts ?

Thanks,

Mathieu

> 
>> > Internal error: Oops - BUG: 0 [#1] PREEMPT SMP
>> > Modules linked in: meson_drm drm_kms_helper drm dwmac_generic realtek
>> > dwmac_meson8b stmmac_platform stmmac meson_rng rng_core meson_gxbb_wdt
>> > ipv6
>> > CPU: 3 PID: 4250 Comm: a.out Not tainted 4.11.0-rc1-next-20170308-xc2-dirty #3
>> > Hardware name: Hardkernel ODROID-C2 (DT)
>> > task: ffff800063699700 task.stack: ffff800063cfc000
>> > PC is at[<        none        >] __synchronize_srcu+0x3d0/0x470
>> > kernel/rcu/srcu.c:412
>> > LR is at[<        none        >] __synchronize_srcu+0x130/0x470
>> > kernel/rcu/srcu.c:434
>> > pc : [<ffff20000821a3b8>] lr : [<ffff20000821a118>] pstate: 80000145
>> > sp : ffff800063cffb00
>> > x29: ffff800063cffb00 x28: ffff80005b1d6e00
>> > x27: 1fffe4000156b242 x26: ffff800063cffb70
>> > x25: 1fffe4000156b23b x24: ffff20000ab591d8
>> > x23: ffff200009dbf000 x22: ffff20000ab591a0
>> > x21: ffff20000ab59210 x20: ffff800063cffb70
>> > x19: ffff20000ab59190 x18: 0000000000000a03
>> > x17: 0000ffff944f3950 x16: ffff20000811f818
>> > x15: 0000000000000000 x14: 0000000000000007
>> > x13: 0000000000000002 x12: 0000000000000000
>> > x11: 0000000000000040 x10: 1fffe400014b568c
>> > x9 : ffff20000ab29000 x8 : 0000000000000007
>> > x7 : 0000000000000001 x6 : 0000000000000000
>> > x5 : 0000000000000040 x4 : 0000000000000003
>> > x3 : ffff20000ab59208 x2 : 1fffe4000156b243
>> > x1 : 0000000000000000 x0 : ffff80005e71fb70
>> >
>> > Process a.out (pid: 4250, stack limit = 0xffff800063cfc000)
>> > Stack: (0xffff800063cffb00 to 0xffff800063d00000)
>> > fb00: ffff800063cffbd0 ffff20000821a480 ffff20000ab59190 1ffff0000b63adc0
>> > fb20: dfff200000000000 ffff20000ab59190 ffff80004b9a8a00 1ffff000097351bc
>> > fb40: ffff80004b9a8de0 0000000000000000 ffff800060cad328 ffff80005b1d6e00
>> > fb60: ffff80004b9a8a00 1ffff000097351bc ffff80004f5e7b70 ffff200008217968
>> > fb80: ffff800000000001 dead4ead00010001 dfff2000ffffffff ffffffffffffffff
>> > fba0: ffff20000ab4c4b0 0000000000000000 0000000000000000 ffff200009b0b358
>> > fbc0: ffff800063cffbc0 ffff800063cffbc0 ffff800063cffbf0 ffff2000083ffd20
>> > fbe0: ffff80005b1d6e00 0000000000000140 ffff800063cffc50 ffff2000083aedfc
>> > fc00: ffff80004b9a8a00 ffff80004b9a8a00 ffff80004b9a8d78 0000000000000001
>> > fc20: 00000000000002a6 ffff80004f406780 ffff80004b9a8aa0 ffff800063699ac8
>> > fc40: 1ffff0000c6d3359 ffff800063699700 ffff800063cffd20 ffff20000810caec
>> > fc60: ffff80004b9a8a00 ffff80004b9a8b20 ffff80004b9a8d78 0000000000000001
>> > fc80: ffff80005ebae2d8 ffff800063699ac8 ffff800063cffca0 ffff20000840fc08
>> > fca0: ffff800063cffce0 ffff20000843327c ffff80005ebae2d8 ffff80004b9a8a00
>> > fcc0: ffff80005ebae0f0 ffff200009de8000 ffff800063cffce0 ffff2000084332c4
>> > fce0: ffff800063cffd20 ffff20000810cc64 ffff80004b9a8a00 ffff80004b9a8a48
>> > fd00: ffff80004b9a8d78 0000000000000001 ffff800063cffd20 ffff20000810cae0
>> > fd20: ffff800063cffd60 ffff20000811db88 ffff800063699700 ffff800063699700
>> > fd40: ffff80004b9a8a00 0000000000000001 00000000000002a6 ffff80004f406780
>> > fd60: ffff800063cffe40 ffff20000811f694 ffff80004f406780 0000000000000000
>> > fd80: ffff80004f40681c 0000000000000004 1ffff00009e80d03 1ffff00009e80d02
>> > fda0: ffff80004f406810 ffff800063699bd0 ffff800063699700 ffff800063699700
>> > fdc0: ffff800063cffe80 ffff200008490868 0000000000000000 ffff80005fd45000
>> > fde0: ffff80006369972c ffff800063699d48 1ffff0000c6d32e5 0000000000000004
>> > fe00: 0000000000000123 000000000000001d 1ffff0000c6d33a9 ffff800063699700
>> > fe20: ffff800063cffe30 ffff200008813c5c ffff800063cffe40 ffff20000811f688
>> > fe40: ffff800063cffea0 ffff20000811f838 0000000000000000 000060006d24d000
>> > fe60: ffffffffffffffff 0000ffff944f3974 0000000000000000 0000000000000015
>> > fe80: 0000000000000123 000000000000005e ffff200009852000 ffff20000811f82c
>> > fea0: 0000000000000000 ffff200008083f70 0000000000000000 0000000000000015
>> > fec0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
>> > fee0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
>> > ff00: 000000000000005e ffffff80ffffffd0 0101010101010101 0000000000000020
>> > ff20: 0000000000000018 0000000056bcb768 0000000000000000 0000ffff945be000
>> > ff40: 0000000000413110 0000ffff944f3950 0000000000000a03 00000000004020f8
>> > ff60: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
>> > ff80: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
>> > ffa0: 0000000000000000 0000ffffc0cc99b0 0000000000401248 0000ffffc0cc99b0
>> > ffc0: 0000ffff944f3974 0000000000000000 0000000000000000 000000000000005e
>> > ffe0: 0000000000000000 0000000000000000 0403030303030100 0807060606060605
>> > Call trace:
>> > Exception stack(0xffff800063cff910 to 0xffff800063cffa40)
>> > f900:                                   ffff20000ab59190 0001000000000000
>> > f920: ffff800063cffb00 ffff20000821a3b8 0000000080000145 000000000000003d
>> > f940: 1fffe4000156b23b ffff800063cffb70 ffff800063cff980 0001000000000000
>> > f960: ffff800063cff9d0 ffff2000081da8e8 ffff800063699ec0 ffff200009df9000
>> > f980: ffff800063cff990 ffff20000891e1e0 ffff800063cff9d0 ffff20000891e23c
>> > f9a0: ffff200009dbfe18 0000000000000040 0000000000000004 0000000000000001
>> > f9c0: 00000000000008ac 00000000000008ac ffff80005e71fb70 0000000000000000
>> > f9e0: 1fffe4000156b243 ffff20000ab59208 0000000000000003 0000000000000040
>> > fa00: 0000000000000000 0000000000000001 0000000000000007 ffff20000ab29000
>> > fa20: 1fffe400014b568c 0000000000000040 0000000000000000 0000000000000002
>> > [<ffff20000821a3b8>] __synchronize_srcu+0x3d0/0x470 kernel/rcu/srcu.c:412
>> > [<ffff20000821a480>] synchronize_srcu+0x28/0x60 kernel/rcu/srcu.c:516
>> > [<ffff2000083ffd20>] __mmu_notifier_release+0x268/0x3e0 mm/mmu_notifier.c:102
>> > [<     inline     >] mmu_notifier_release ./include/linux/mmu_notifier.h:235
>> > [<ffff2000083aedfc>] exit_mmap+0x21c/0x288 mm/mmap.c:2941
>> > [<     inline     >] __mmput kernel/fork.c:881
>> > [<ffff20000810caec>] mmput+0xdc/0x2e0 kernel/fork.c:903
>> > [<     inline     >] exit_mm kernel/exit.c:557
>> > [<ffff20000811db88>] do_exit+0x648/0x2020 kernel/exit.c:865
>> > [<ffff20000811f694>] do_group_exit+0xdc/0x260 kernel/exit.c:982
>> > [<     inline     >] SYSC_exit_group kernel/exit.c:993
>> > [<ffff20000811f838>] __wake_up_parent+0x0/0x60 kernel/exit.c:991
>> > [<ffff200008083f70>] el0_svc_naked+0x24/0x28 arch/arm64/kernel/entry.S:813
>> > Code: 97feee10 35fff680 17ffff1c d503201f (d4210000)
>> > ---[ end trace b727e9858bfac1ff ]---
>> > Kernel panic - not syncing: Fatal exception
> 
> So the theory is that if !sp->running, all of SRCU's queues must be empty.
> So if you are holding ->queue_lock (with irqs disabled) and you see
> !sp->running, and then you enqueue a callback on ->batch_check0, then
> that callback must be the first in the list.  And the code preceding
> the WARN_ON() you triggered does in fact check and enqueue shile holding
> ->queue_lock with irqs disabled.
> 
> And rcu_batch_queue() does operate FIFO as required.  (Otherwise,
> srcu_barrier() would not work.)
> 
> There are only three calls to rcu_batch_queue(), and the one involved with
> the WARN_ON() enqueues to ->batch_check0.  The other two enqueue to
> ->batch_queue.  Callbacks move from ->batch_queue to ->batch_check0 to
> ->batch_check1 to ->batch_done, so nothing should slip in front.
> 
> Of course, if ->running were ever set to false with any of ->batch_check0,
> ->batch_check1, or ->batch_done non-empty, this WARN_ON() would trigger.
> But srcu_reschedule() sets it to false only if all four batches are
> empty (and checks and sets under ->queue_lock()), and all other cases
> where it is set to false happen at initialization time, and also clear
> out the queues.  Of course, if someone raced an init_srcu_struct() with
> either a call_srcu() or synchronize_srcu(), all bets are off.  Now,
> mmu_notifier.c does invoke init_srcu_struct() manually, but it does
> so at subsys_initcall() time.  Which -might- be after other things are
> happening, so one "hail Mary" attempted fix is to remove mmu_notifier_init()
> and replace the "static struct srcu_struct srcu" with:
> 
>	DEFINE_STATIC_SRCU(srcu);
> 
> But this might require changing the name -- I vaguely recall some
> strangeness where the names of statically defined per-CPU variables need
> to be globally unique even when static.  Easy enough to do, though.
> Might need a similar change to the "srcu" instances defined in vmd.c
> and kvm_host.h -- assuming that this change helps.
> 
> Another possibility is that something in SRCU is messing with either the
> queues or the ->running field without holding ->queue_lock.  And that does
> seem to be happening -- srcu_advance_batches() invokes rcu_batch_move()
> without holding anything.  Which seems like it could cause trouble
> if someone else was invoking synchronize_srcu() concurrently.  Those
> particular invocations might be safe due to access only by a single
> kthread/workqueue, given that all updates to ->batch_queue are protected
> by ->queue_lock (aside from initialization).
> 
> But ->batch_check0 is updated by __synchronize_srcu(), though protected
> by ->queue_lock, and only if ->running is false, and with both the
> check and the update protected by the same ->queue_lock critical section.
> If ->running is false, then the workqueue cannot be running, so it remains
> to see if all other updates to ->batch_check0 are either with ->queue_lock
> held and ->running false on the one hand or from the workqueue handler
> on the other:
> 
> srcu_collect_new() updates with ->queue_lock held, but does not check
>	->running.  It is invoked only from process_srcu(), which in
>	turn is invoked only as a workqueue handler.  The work is queued
>	from:
> 
>	call_srcu(), which does so with ->queue_lock held having just
>		set ->running to true.
> 
>	srcu_reschedule(), which invokes it if there are non-empty
>		queues.  This is invoked from __synchronize_srcu()
>		in the case where it has set ->running to true
>		after finding the queues empty, which should imply
>		no other instances.
> 
>		It is also invoked from process_srcu(), which is
>		invoked only as a workqueue handler.  (Yay
>		recursive inquiry!)
> 
> srcu_advance_batches() updates without locks held.  It is invoked as
>	follows:
> 
>	__synchronize_srcu() in the case where ->running was set, which
>		as noted before excludes workqueue handlers.
> 
>	process_srcu() which as noted before is only invoked from
>		a workqueue handler.
> 
> So an SRCU workqueue is invoked only from a workqueue handler, or from
> some other task that transitioned ->running from false to true while
> holding ->queuelock.  There should therefore only be one SRCU workqueue
> per srcu_struct, so this should be safe.  Though I hope that it can
> be simplified a bit.  :-/
> 
> So the only suggestion I have at the moment is static definition of
> the "srcu" variable.  Lai, Josh, Steve, Mathieu, anything I missed?
> 
> 						Thanx, Paul

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

[toc] | [prev] | [next] | [standalone]

#1598451

On Sat, Mar 11, 2017 at 02:25:14PM +0000, Mathieu Desnoyers wrote:
> ----- On Mar 10, 2017, at 5:26 PM, Paul E. McKenney paulmck@linux.vnet.ibm.com wrote:
> 
> > On Fri, Mar 10, 2017 at 08:29:55PM +0100, Andrey Konovalov wrote:
> >> On Fri, Mar 10, 2017 at 8:28 PM, Andrey Konovalov <andreyknvl@google.com> wrote:
> >> > Hi,
> >> >
> >> > I've got the following error report while fuzzing the kernel with
> >> > syzkaller on an arm64 board.
> >> 
> >> This also happened on x86 a few times during fuzzing, however it
> >> wasn't reproducible.
> >> 
> >> >
> >> > On linux-next commit 56b8bad5e066c23e8fa273ef5fba50bd3da2ace8 (Mar 8).
> >> >
> >> > A reproducer and .config are attached.
> >> >
> >> > The bug happens while executing the following syzkaller program in a loop.
> >> > While it looks kvm-related, it might be that kvm just stresses the
> >> > srcu subsystem.
> >> >
> >> > mmap(&(0x7f0000000000/0xfff000)=nil, (0xfff000), 0x3, 0x32,
> >> > 0xffffffffffffffff, 0x0)
> >> > r0 = openat$kvm(0xffffffffffffff9c,
> >> > &(0x7f0000a05000)="2f6465762f6b766d00", 0x0, 0x0)
> >> > ioctl$KVM_CREATE_VM(r0, 0xae01, 0x0)
> >> >
> >> > ------------[ cut here ]------------
> >> > kernel BUG at kernel/rcu/srcu.c:436!
> > 
> > This is on v4.10, correct?
> 
> No, as stated above, this is on linux-next as of March 8, 2017.
> 
> I'm currently looking at the diff of kernel/rcu/srcu.c between v4.10 and
> next-20170310. There are a few changes there.

OK, I must have ended up in the wrong place -- I found line 436 to be
a comment, which caused me to guess a different version.

> One of them is the introduction of the new srcu algorithm with separate
> lock vs unlock counters, which simplifies read lock/unlock by removing the
> sequence counter.
> 
> Another change that directly impacts __synchronize_rcu() (near the
> BUG()) is bc138e7a "srcu: Allow mid-boot use of synchronize_srcu()".
> 
> Odds are that this change introduce an unforeseen scenario that
> skips awaiting for completion later after boot than expected. It
> might be worthwhile to review it closely once more.

SRCU is under active development, so yes, bugs are likely.  I will take
another look.

At the very least, a READ_ONCE() on rcu_scheduler_active would be good.
And that fastpath is removed entirely in later commits not yet pushed out,
so maybe rearranging or combining commits might be helpful.  Though it
would of course still be good to identify the bug in case it is something
subtle that persists.

							Thanx, Paul

> Thoughts ?
> 
> Thanks,
> 
> Mathieu
> 
> > 
> >> > Internal error: Oops - BUG: 0 [#1] PREEMPT SMP
> >> > Modules linked in: meson_drm drm_kms_helper drm dwmac_generic realtek
> >> > dwmac_meson8b stmmac_platform stmmac meson_rng rng_core meson_gxbb_wdt
> >> > ipv6
> >> > CPU: 3 PID: 4250 Comm: a.out Not tainted 4.11.0-rc1-next-20170308-xc2-dirty #3
> >> > Hardware name: Hardkernel ODROID-C2 (DT)
> >> > task: ffff800063699700 task.stack: ffff800063cfc000
> >> > PC is at[<        none        >] __synchronize_srcu+0x3d0/0x470
> >> > kernel/rcu/srcu.c:412
> >> > LR is at[<        none        >] __synchronize_srcu+0x130/0x470
> >> > kernel/rcu/srcu.c:434
> >> > pc : [<ffff20000821a3b8>] lr : [<ffff20000821a118>] pstate: 80000145
> >> > sp : ffff800063cffb00
> >> > x29: ffff800063cffb00 x28: ffff80005b1d6e00
> >> > x27: 1fffe4000156b242 x26: ffff800063cffb70
> >> > x25: 1fffe4000156b23b x24: ffff20000ab591d8
> >> > x23: ffff200009dbf000 x22: ffff20000ab591a0
> >> > x21: ffff20000ab59210 x20: ffff800063cffb70
> >> > x19: ffff20000ab59190 x18: 0000000000000a03
> >> > x17: 0000ffff944f3950 x16: ffff20000811f818
> >> > x15: 0000000000000000 x14: 0000000000000007
> >> > x13: 0000000000000002 x12: 0000000000000000
> >> > x11: 0000000000000040 x10: 1fffe400014b568c
> >> > x9 : ffff20000ab29000 x8 : 0000000000000007
> >> > x7 : 0000000000000001 x6 : 0000000000000000
> >> > x5 : 0000000000000040 x4 : 0000000000000003
> >> > x3 : ffff20000ab59208 x2 : 1fffe4000156b243
> >> > x1 : 0000000000000000 x0 : ffff80005e71fb70
> >> >
> >> > Process a.out (pid: 4250, stack limit = 0xffff800063cfc000)
> >> > Stack: (0xffff800063cffb00 to 0xffff800063d00000)
> >> > fb00: ffff800063cffbd0 ffff20000821a480 ffff20000ab59190 1ffff0000b63adc0
> >> > fb20: dfff200000000000 ffff20000ab59190 ffff80004b9a8a00 1ffff000097351bc
> >> > fb40: ffff80004b9a8de0 0000000000000000 ffff800060cad328 ffff80005b1d6e00
> >> > fb60: ffff80004b9a8a00 1ffff000097351bc ffff80004f5e7b70 ffff200008217968
> >> > fb80: ffff800000000001 dead4ead00010001 dfff2000ffffffff ffffffffffffffff
> >> > fba0: ffff20000ab4c4b0 0000000000000000 0000000000000000 ffff200009b0b358
> >> > fbc0: ffff800063cffbc0 ffff800063cffbc0 ffff800063cffbf0 ffff2000083ffd20
> >> > fbe0: ffff80005b1d6e00 0000000000000140 ffff800063cffc50 ffff2000083aedfc
> >> > fc00: ffff80004b9a8a00 ffff80004b9a8a00 ffff80004b9a8d78 0000000000000001
> >> > fc20: 00000000000002a6 ffff80004f406780 ffff80004b9a8aa0 ffff800063699ac8
> >> > fc40: 1ffff0000c6d3359 ffff800063699700 ffff800063cffd20 ffff20000810caec
> >> > fc60: ffff80004b9a8a00 ffff80004b9a8b20 ffff80004b9a8d78 0000000000000001
> >> > fc80: ffff80005ebae2d8 ffff800063699ac8 ffff800063cffca0 ffff20000840fc08
> >> > fca0: ffff800063cffce0 ffff20000843327c ffff80005ebae2d8 ffff80004b9a8a00
> >> > fcc0: ffff80005ebae0f0 ffff200009de8000 ffff800063cffce0 ffff2000084332c4
> >> > fce0: ffff800063cffd20 ffff20000810cc64 ffff80004b9a8a00 ffff80004b9a8a48
> >> > fd00: ffff80004b9a8d78 0000000000000001 ffff800063cffd20 ffff20000810cae0
> >> > fd20: ffff800063cffd60 ffff20000811db88 ffff800063699700 ffff800063699700
> >> > fd40: ffff80004b9a8a00 0000000000000001 00000000000002a6 ffff80004f406780
> >> > fd60: ffff800063cffe40 ffff20000811f694 ffff80004f406780 0000000000000000
> >> > fd80: ffff80004f40681c 0000000000000004 1ffff00009e80d03 1ffff00009e80d02
> >> > fda0: ffff80004f406810 ffff800063699bd0 ffff800063699700 ffff800063699700
> >> > fdc0: ffff800063cffe80 ffff200008490868 0000000000000000 ffff80005fd45000
> >> > fde0: ffff80006369972c ffff800063699d48 1ffff0000c6d32e5 0000000000000004
> >> > fe00: 0000000000000123 000000000000001d 1ffff0000c6d33a9 ffff800063699700
> >> > fe20: ffff800063cffe30 ffff200008813c5c ffff800063cffe40 ffff20000811f688
> >> > fe40: ffff800063cffea0 ffff20000811f838 0000000000000000 000060006d24d000
> >> > fe60: ffffffffffffffff 0000ffff944f3974 0000000000000000 0000000000000015
> >> > fe80: 0000000000000123 000000000000005e ffff200009852000 ffff20000811f82c
> >> > fea0: 0000000000000000 ffff200008083f70 0000000000000000 0000000000000015
> >> > fec0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> >> > fee0: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> >> > ff00: 000000000000005e ffffff80ffffffd0 0101010101010101 0000000000000020
> >> > ff20: 0000000000000018 0000000056bcb768 0000000000000000 0000ffff945be000
> >> > ff40: 0000000000413110 0000ffff944f3950 0000000000000a03 00000000004020f8
> >> > ff60: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> >> > ff80: 0000000000000000 0000000000000000 0000000000000000 0000000000000000
> >> > ffa0: 0000000000000000 0000ffffc0cc99b0 0000000000401248 0000ffffc0cc99b0
> >> > ffc0: 0000ffff944f3974 0000000000000000 0000000000000000 000000000000005e
> >> > ffe0: 0000000000000000 0000000000000000 0403030303030100 0807060606060605
> >> > Call trace:
> >> > Exception stack(0xffff800063cff910 to 0xffff800063cffa40)
> >> > f900:                                   ffff20000ab59190 0001000000000000
> >> > f920: ffff800063cffb00 ffff20000821a3b8 0000000080000145 000000000000003d
> >> > f940: 1fffe4000156b23b ffff800063cffb70 ffff800063cff980 0001000000000000
> >> > f960: ffff800063cff9d0 ffff2000081da8e8 ffff800063699ec0 ffff200009df9000
> >> > f980: ffff800063cff990 ffff20000891e1e0 ffff800063cff9d0 ffff20000891e23c
> >> > f9a0: ffff200009dbfe18 0000000000000040 0000000000000004 0000000000000001
> >> > f9c0: 00000000000008ac 00000000000008ac ffff80005e71fb70 0000000000000000
> >> > f9e0: 1fffe4000156b243 ffff20000ab59208 0000000000000003 0000000000000040
> >> > fa00: 0000000000000000 0000000000000001 0000000000000007 ffff20000ab29000
> >> > fa20: 1fffe400014b568c 0000000000000040 0000000000000000 0000000000000002
> >> > [<ffff20000821a3b8>] __synchronize_srcu+0x3d0/0x470 kernel/rcu/srcu.c:412
> >> > [<ffff20000821a480>] synchronize_srcu+0x28/0x60 kernel/rcu/srcu.c:516
> >> > [<ffff2000083ffd20>] __mmu_notifier_release+0x268/0x3e0 mm/mmu_notifier.c:102
> >> > [<     inline     >] mmu_notifier_release ./include/linux/mmu_notifier.h:235
> >> > [<ffff2000083aedfc>] exit_mmap+0x21c/0x288 mm/mmap.c:2941
> >> > [<     inline     >] __mmput kernel/fork.c:881
> >> > [<ffff20000810caec>] mmput+0xdc/0x2e0 kernel/fork.c:903
> >> > [<     inline     >] exit_mm kernel/exit.c:557
> >> > [<ffff20000811db88>] do_exit+0x648/0x2020 kernel/exit.c:865
> >> > [<ffff20000811f694>] do_group_exit+0xdc/0x260 kernel/exit.c:982
> >> > [<     inline     >] SYSC_exit_group kernel/exit.c:993
> >> > [<ffff20000811f838>] __wake_up_parent+0x0/0x60 kernel/exit.c:991
> >> > [<ffff200008083f70>] el0_svc_naked+0x24/0x28 arch/arm64/kernel/entry.S:813
> >> > Code: 97feee10 35fff680 17ffff1c d503201f (d4210000)
> >> > ---[ end trace b727e9858bfac1ff ]---
> >> > Kernel panic - not syncing: Fatal exception
> > 
> > So the theory is that if !sp->running, all of SRCU's queues must be empty.
> > So if you are holding ->queue_lock (with irqs disabled) and you see
> > !sp->running, and then you enqueue a callback on ->batch_check0, then
> > that callback must be the first in the list.  And the code preceding
> > the WARN_ON() you triggered does in fact check and enqueue shile holding
> > ->queue_lock with irqs disabled.
> > 
> > And rcu_batch_queue() does operate FIFO as required.  (Otherwise,
> > srcu_barrier() would not work.)
> > 
> > There are only three calls to rcu_batch_queue(), and the one involved with
> > the WARN_ON() enqueues to ->batch_check0.  The other two enqueue to
> > ->batch_queue.  Callbacks move from ->batch_queue to ->batch_check0 to
> > ->batch_check1 to ->batch_done, so nothing should slip in front.
> > 
> > Of course, if ->running were ever set to false with any of ->batch_check0,
> > ->batch_check1, or ->batch_done non-empty, this WARN_ON() would trigger.
> > But srcu_reschedule() sets it to false only if all four batches are
> > empty (and checks and sets under ->queue_lock()), and all other cases
> > where it is set to false happen at initialization time, and also clear
> > out the queues.  Of course, if someone raced an init_srcu_struct() with
> > either a call_srcu() or synchronize_srcu(), all bets are off.  Now,
> > mmu_notifier.c does invoke init_srcu_struct() manually, but it does
> > so at subsys_initcall() time.  Which -might- be after other things are
> > happening, so one "hail Mary" attempted fix is to remove mmu_notifier_init()
> > and replace the "static struct srcu_struct srcu" with:
> > 
> >	DEFINE_STATIC_SRCU(srcu);
> > 
> > But this might require changing the name -- I vaguely recall some
> > strangeness where the names of statically defined per-CPU variables need
> > to be globally unique even when static.  Easy enough to do, though.
> > Might need a similar change to the "srcu" instances defined in vmd.c
> > and kvm_host.h -- assuming that this change helps.
> > 
> > Another possibility is that something in SRCU is messing with either the
> > queues or the ->running field without holding ->queue_lock.  And that does
> > seem to be happening -- srcu_advance_batches() invokes rcu_batch_move()
> > without holding anything.  Which seems like it could cause trouble
> > if someone else was invoking synchronize_srcu() concurrently.  Those
> > particular invocations might be safe due to access only by a single
> > kthread/workqueue, given that all updates to ->batch_queue are protected
> > by ->queue_lock (aside from initialization).
> > 
> > But ->batch_check0 is updated by __synchronize_srcu(), though protected
> > by ->queue_lock, and only if ->running is false, and with both the
> > check and the update protected by the same ->queue_lock critical section.
> > If ->running is false, then the workqueue cannot be running, so it remains
> > to see if all other updates to ->batch_check0 are either with ->queue_lock
> > held and ->running false on the one hand or from the workqueue handler
> > on the other:
> > 
> > srcu_collect_new() updates with ->queue_lock held, but does not check
> >	->running.  It is invoked only from process_srcu(), which in
> >	turn is invoked only as a workqueue handler.  The work is queued
> >	from:
> > 
> >	call_srcu(), which does so with ->queue_lock held having just
> >		set ->running to true.
> > 
> >	srcu_reschedule(), which invokes it if there are non-empty
> >		queues.  This is invoked from __synchronize_srcu()
> >		in the case where it has set ->running to true
> >		after finding the queues empty, which should imply
> >		no other instances.
> > 
> >		It is also invoked from process_srcu(), which is
> >		invoked only as a workqueue handler.  (Yay
> >		recursive inquiry!)
> > 
> > srcu_advance_batches() updates without locks held.  It is invoked as
> >	follows:
> > 
> >	__synchronize_srcu() in the case where ->running was set, which
> >		as noted before excludes workqueue handlers.
> > 
> >	process_srcu() which as noted before is only invoked from
> >		a workqueue handler.
> > 
> > So an SRCU workqueue is invoked only from a workqueue handler, or from
> > some other task that transitioned ->running from false to true while
> > holding ->queuelock.  There should therefore only be one SRCU workqueue
> > per srcu_struct, so this should be safe.  Though I hope that it can
> > be simplified a bit.  :-/
> > 
> > So the only suggestion I have at the moment is static definition of
> > the "srcu" variable.  Lai, Josh, Steve, Mathieu, anything I missed?
> > 
> > 						Thanx, Paul
> 
> -- 
> Mathieu Desnoyers
> EfficiOS Inc.
> http://www.efficios.com
> 

[toc] | [prev] | [next] | [standalone]

#1600084

I am not sure how the rcu_scheduler_active changes in __synchronize_srcu work,
but there seem to be a few problems in them. First,
"if (done && likely(!driving))" on line 453 doesn't appear to ever happen,
as driving doesn't get set to false when srcu_reschedule is called. This seems
like it could cause a race condition if another thread notices that ->running is
false, adds itself to the queue, set ->running to true, and starts on its own
grace period before the first thread acquires the lock again on line 469. Then
the first thread will then acquire the lock, set running to false, and release
the lock, resulting in an invalid state where ->running is false but the second
thread is still trying to finish its grace period.

Second, the while loop on line 455 seems to violate to rule that ->running
shouldn't be false when there are entries in the queue. If a second thread adds
itself to the queue while the first thread is driving SRCU inside that loop, and
then the first thread finishes its own grace period and quits the loop, it will
set ->running to false even though there is still a thread on the queue.

The second issue requires rcu_scheduler_active to be RCU_SCHEDULER_INIT to
occur, and as I don't what the assumptions during RCU_SCHEDULER_INIT are I don't
know if it is actually a problem, but the first issue looks like it could occur
at any time.

Thanks,
Lance

On Fri, 10 Mar 2017 14:26:09 -0800
"Paul E. McKenney" <paulmck@linux.vnet.ibm.com> wrote:
> On Fri, Mar 10, 2017 at 08:29:55PM +0100, Andrey Konovalov wrote:
> > On Fri, Mar 10, 2017 at 8:28 PM, Andrey Konovalov <andreyknvl@google.com>
> > wrote:
> > > Kernel panic - not syncing: Fatal exception
>
> So the theory is that if !sp->running, all of SRCU's queues must be empty.
> So if you are holding ->queue_lock (with irqs disabled) and you see
> !sp->running, and then you enqueue a callback on ->batch_check0, then
> that callback must be the first in the list.  And the code preceding
> the WARN_ON() you triggered does in fact check and enqueue shile holding
> ->queue_lock with irqs disabled.
>
> And rcu_batch_queue() does operate FIFO as required.  (Otherwise,
> srcu_barrier() would not work.)
>
> There are only three calls to rcu_batch_queue(), and the one involved with
> the WARN_ON() enqueues to ->batch_check0.  The other two enqueue to
> ->batch_queue.  Callbacks move from ->batch_queue to ->batch_check0 to
> ->batch_check1 to ->batch_done, so nothing should slip in front.
>
> Of course, if ->running were ever set to false with any of ->batch_check0,
> ->batch_check1, or ->batch_done non-empty, this WARN_ON() would trigger.
> But srcu_reschedule() sets it to false only if all four batches are
> empty (and checks and sets under ->queue_lock()), and all other cases
> where it is set to false happen at initialization time, and also clear
> out the queues.  Of course, if someone raced an init_srcu_struct() with
> either a call_srcu() or synchronize_srcu(), all bets are off.  Now,
> mmu_notifier.c does invoke init_srcu_struct() manually, but it does
> so at subsys_initcall() time.  Which -might- be after other things are
> happening, so one "hail Mary" attempted fix is to remove mmu_notifier_init()
> and replace the "static struct srcu_struct srcu" with:

>
> 	DEFINE_STATIC_SRCU(srcu);
>
> But this might require changing the name -- I vaguely recall some
> strangeness where the names of statically defined per-CPU variables need
> to be globally unique even when static.  Easy enough to do, though.
> Might need a similar change to the "srcu" instances defined in vmd.c
> and kvm_host.h -- assuming that this change helps.
>
> Another possibility is that something in SRCU is messing with either the
> queues or the ->running field without holding ->queue_lock.  And that does
> seem to be happening -- srcu_advance_batches() invokes rcu_batch_move()
> without holding anything.  Which seems like it could cause trouble
> if someone else was invoking synchronize_srcu() concurrently.  Those
> particular invocations might be safe due to access only by a single
> kthread/workqueue, given that all updates to ->batch_queue are protected
> by ->queue_lock (aside from initialization).
>
> But ->batch_check0 is updated by __synchronize_srcu(), though protected
> by ->queue_lock, and only if ->running is false, and with both the
> check and the update protected by the same ->queue_lock critical section.
> If ->running is false, then the workqueue cannot be running, so it remains
> to see if all other updates to ->batch_check0 are either with ->queue_lock
> held and ->running false on the one hand or from the workqueue handler
> on the other:
>
> srcu_collect_new() updates with ->queue_lock held, but does not check
> 	->running.  It is invoked only from process_srcu(), which in
> 	turn is invoked only as a workqueue handler.  The work is queued
> 	from:
>
> 	call_srcu(), which does so with ->queue_lock held having just
> 		set ->running to true.
>
> 	srcu_reschedule(), which invokes it if there are non-empty
> 		queues.  This is invoked from __synchronize_srcu()
> 		in the case where it has set ->running to true
> 		after finding the queues empty, which should imply
> 		no other instances.
>
> 		It is also invoked from process_srcu(), which is
> 		invoked only as a workqueue handler.  (Yay
> 		recursive inquiry!)
>
> srcu_advance_batches() updates without locks held.  It is invoked as
> 	follows:
>
> 	__synchronize_srcu() in the case where ->running was set, which
> 		as noted before excludes workqueue handlers.
>
> 	process_srcu() which as noted before is only invoked from
> 		a workqueue handler.
>
> So an SRCU workqueue is invoked only from a workqueue handler, or from
> some other task that transitioned ->running from false to true while
> holding ->queuelock.  There should therefore only be one SRCU workqueue
> per srcu_struct, so this should be safe.  Though I hope that it can
> be simplified a bit.  :-/
>
> So the only suggestion I have at the moment is static definition of
> the "srcu" variable.  Lai, Josh, Steve, Mathieu, anything I missed?
>
> 						Thanx, Paul
>

[toc] | [prev] | [next] | [standalone]

#1600672

On Tue, Mar 14, 2017 at 12:47:02AM -0700, Lance Roy wrote:
> I am not sure how the rcu_scheduler_active changes in __synchronize_srcu work,
> but there seem to be a few problems in them. First,
> "if (done && likely(!driving))" on line 453 doesn't appear to ever happen,
> as driving doesn't get set to false when srcu_reschedule is called. This seems
> like it could cause a race condition if another thread notices that ->running is
> false, adds itself to the queue, set ->running to true, and starts on its own
> grace period before the first thread acquires the lock again on line 469. Then
> the first thread will then acquire the lock, set running to false, and release
> the lock, resulting in an invalid state where ->running is false but the second
> thread is still trying to finish its grace period.
> 
> Second, the while loop on line 455 seems to violate to rule that ->running
> shouldn't be false when there are entries in the queue. If a second thread adds
> itself to the queue while the first thread is driving SRCU inside that loop, and
> then the first thread finishes its own grace period and quits the loop, it will
> set ->running to false even though there is still a thread on the queue.
> 
> The second issue requires rcu_scheduler_active to be RCU_SCHEDULER_INIT to
> occur, and as I don't what the assumptions during RCU_SCHEDULER_INIT are I don't
> know if it is actually a problem, but the first issue looks like it could occur
> at any time.

Thank you for looking into this!

I determined that my patch-order strategy was flawed, as it required
me to rewrite the mid-boot functionality several times.  I therefore
removed the mid-boot commits.  I will add them in later, but they will
use a rather different approach based on a grace-period sequence number
similar to that used by the expedited grace periods.

Which should also teach me to be less aggressive about pushing new code
to -next.  For a few weeks, anyway.  ;-)

							Thanx, Paul

> Thanks,
> Lance
> 
> On Fri, 10 Mar 2017 14:26:09 -0800
> "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> wrote:
> > On Fri, Mar 10, 2017 at 08:29:55PM +0100, Andrey Konovalov wrote:
> > > On Fri, Mar 10, 2017 at 8:28 PM, Andrey Konovalov <andreyknvl@google.com>
> > > wrote:
> > > > Kernel panic - not syncing: Fatal exception
> >
> > So the theory is that if !sp->running, all of SRCU's queues must be empty.
> > So if you are holding ->queue_lock (with irqs disabled) and you see
> > !sp->running, and then you enqueue a callback on ->batch_check0, then
> > that callback must be the first in the list.  And the code preceding
> > the WARN_ON() you triggered does in fact check and enqueue shile holding
> > ->queue_lock with irqs disabled.
> >
> > And rcu_batch_queue() does operate FIFO as required.  (Otherwise,
> > srcu_barrier() would not work.)
> >
> > There are only three calls to rcu_batch_queue(), and the one involved with
> > the WARN_ON() enqueues to ->batch_check0.  The other two enqueue to
> > ->batch_queue.  Callbacks move from ->batch_queue to ->batch_check0 to
> > ->batch_check1 to ->batch_done, so nothing should slip in front.
> >
> > Of course, if ->running were ever set to false with any of ->batch_check0,
> > ->batch_check1, or ->batch_done non-empty, this WARN_ON() would trigger.
> > But srcu_reschedule() sets it to false only if all four batches are
> > empty (and checks and sets under ->queue_lock()), and all other cases
> > where it is set to false happen at initialization time, and also clear
> > out the queues.  Of course, if someone raced an init_srcu_struct() with
> > either a call_srcu() or synchronize_srcu(), all bets are off.  Now,
> > mmu_notifier.c does invoke init_srcu_struct() manually, but it does
> > so at subsys_initcall() time.  Which -might- be after other things are
> > happening, so one "hail Mary" attempted fix is to remove mmu_notifier_init()
> > and replace the "static struct srcu_struct srcu" with:
> 
> >
> > 	DEFINE_STATIC_SRCU(srcu);
> >
> > But this might require changing the name -- I vaguely recall some
> > strangeness where the names of statically defined per-CPU variables need
> > to be globally unique even when static.  Easy enough to do, though.
> > Might need a similar change to the "srcu" instances defined in vmd.c
> > and kvm_host.h -- assuming that this change helps.
> >
> > Another possibility is that something in SRCU is messing with either the
> > queues or the ->running field without holding ->queue_lock.  And that does
> > seem to be happening -- srcu_advance_batches() invokes rcu_batch_move()
> > without holding anything.  Which seems like it could cause trouble
> > if someone else was invoking synchronize_srcu() concurrently.  Those
> > particular invocations might be safe due to access only by a single
> > kthread/workqueue, given that all updates to ->batch_queue are protected
> > by ->queue_lock (aside from initialization).
> >
> > But ->batch_check0 is updated by __synchronize_srcu(), though protected
> > by ->queue_lock, and only if ->running is false, and with both the
> > check and the update protected by the same ->queue_lock critical section.
> > If ->running is false, then the workqueue cannot be running, so it remains
> > to see if all other updates to ->batch_check0 are either with ->queue_lock
> > held and ->running false on the one hand or from the workqueue handler
> > on the other:
> >
> > srcu_collect_new() updates with ->queue_lock held, but does not check
> > 	->running.  It is invoked only from process_srcu(), which in
> > 	turn is invoked only as a workqueue handler.  The work is queued
> > 	from:
> >
> > 	call_srcu(), which does so with ->queue_lock held having just
> > 		set ->running to true.
> >
> > 	srcu_reschedule(), which invokes it if there are non-empty
> > 		queues.  This is invoked from __synchronize_srcu()
> > 		in the case where it has set ->running to true
> > 		after finding the queues empty, which should imply
> > 		no other instances.
> >
> > 		It is also invoked from process_srcu(), which is
> > 		invoked only as a workqueue handler.  (Yay
> > 		recursive inquiry!)
> >
> > srcu_advance_batches() updates without locks held.  It is invoked as
> > 	follows:
> >
> > 	__synchronize_srcu() in the case where ->running was set, which
> > 		as noted before excludes workqueue handlers.
> >
> > 	process_srcu() which as noted before is only invoked from
> > 		a workqueue handler.
> >
> > So an SRCU workqueue is invoked only from a workqueue handler, or from
> > some other task that transitioned ->running from false to true while
> > holding ->queuelock.  There should therefore only be one SRCU workqueue
> > per srcu_struct, so this should be safe.  Though I hope that it can
> > be simplified a bit.  :-/
> >
> > So the only suggestion I have at the moment is static definition of
> > the "srcu" variable.  Lai, Josh, Steve, Mathieu, anything I missed?
> >
> > 						Thanx, Paul
> >
> 

[toc] | [prev] | [next] | [standalone]

#1609789

On Tue, Mar 14, 2017 at 5:21 PM, Paul E. McKenney
<paulmck@linux.vnet.ibm.com> wrote:
> On Tue, Mar 14, 2017 at 12:47:02AM -0700, Lance Roy wrote:
>> I am not sure how the rcu_scheduler_active changes in __synchronize_srcu work,
>> but there seem to be a few problems in them. First,
>> "if (done && likely(!driving))" on line 453 doesn't appear to ever happen,
>> as driving doesn't get set to false when srcu_reschedule is called. This seems
>> like it could cause a race condition if another thread notices that ->running is
>> false, adds itself to the queue, set ->running to true, and starts on its own
>> grace period before the first thread acquires the lock again on line 469. Then
>> the first thread will then acquire the lock, set running to false, and release
>> the lock, resulting in an invalid state where ->running is false but the second
>> thread is still trying to finish its grace period.
>>
>> Second, the while loop on line 455 seems to violate to rule that ->running
>> shouldn't be false when there are entries in the queue. If a second thread adds
>> itself to the queue while the first thread is driving SRCU inside that loop, and
>> then the first thread finishes its own grace period and quits the loop, it will
>> set ->running to false even though there is still a thread on the queue.
>>
>> The second issue requires rcu_scheduler_active to be RCU_SCHEDULER_INIT to
>> occur, and as I don't what the assumptions during RCU_SCHEDULER_INIT are I don't
>> know if it is actually a problem, but the first issue looks like it could occur
>> at any time.
>
> Thank you for looking into this!
>
> I determined that my patch-order strategy was flawed, as it required
> me to rewrite the mid-boot functionality several times.  I therefore
> removed the mid-boot commits.  I will add them in later, but they will
> use a rather different approach based on a grace-period sequence number
> similar to that used by the expedited grace periods.
>
> Which should also teach me to be less aggressive about pushing new code
> to -next.  For a few weeks, anyway.  ;-)
>
>                                                         Thanx, Paul
>
>> Thanks,
>> Lance
>>
>> On Fri, 10 Mar 2017 14:26:09 -0800
>> "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> wrote:
>> > On Fri, Mar 10, 2017 at 08:29:55PM +0100, Andrey Konovalov wrote:
>> > > On Fri, Mar 10, 2017 at 8:28 PM, Andrey Konovalov <andreyknvl@google.com>
>> > > wrote:
>> > > > Kernel panic - not syncing: Fatal exception
>> >
>> > So the theory is that if !sp->running, all of SRCU's queues must be empty.
>> > So if you are holding ->queue_lock (with irqs disabled) and you see
>> > !sp->running, and then you enqueue a callback on ->batch_check0, then
>> > that callback must be the first in the list.  And the code preceding
>> > the WARN_ON() you triggered does in fact check and enqueue shile holding
>> > ->queue_lock with irqs disabled.
>> >
>> > And rcu_batch_queue() does operate FIFO as required.  (Otherwise,
>> > srcu_barrier() would not work.)
>> >
>> > There are only three calls to rcu_batch_queue(), and the one involved with
>> > the WARN_ON() enqueues to ->batch_check0.  The other two enqueue to
>> > ->batch_queue.  Callbacks move from ->batch_queue to ->batch_check0 to
>> > ->batch_check1 to ->batch_done, so nothing should slip in front.
>> >
>> > Of course, if ->running were ever set to false with any of ->batch_check0,
>> > ->batch_check1, or ->batch_done non-empty, this WARN_ON() would trigger.
>> > But srcu_reschedule() sets it to false only if all four batches are
>> > empty (and checks and sets under ->queue_lock()), and all other cases
>> > where it is set to false happen at initialization time, and also clear
>> > out the queues.  Of course, if someone raced an init_srcu_struct() with
>> > either a call_srcu() or synchronize_srcu(), all bets are off.  Now,
>> > mmu_notifier.c does invoke init_srcu_struct() manually, but it does
>> > so at subsys_initcall() time.  Which -might- be after other things are
>> > happening, so one "hail Mary" attempted fix is to remove mmu_notifier_init()
>> > and replace the "static struct srcu_struct srcu" with:
>>
>> >
>> >     DEFINE_STATIC_SRCU(srcu);
>> >
>> > But this might require changing the name -- I vaguely recall some
>> > strangeness where the names of statically defined per-CPU variables need
>> > to be globally unique even when static.  Easy enough to do, though.
>> > Might need a similar change to the "srcu" instances defined in vmd.c
>> > and kvm_host.h -- assuming that this change helps.
>> >
>> > Another possibility is that something in SRCU is messing with either the
>> > queues or the ->running field without holding ->queue_lock.  And that does
>> > seem to be happening -- srcu_advance_batches() invokes rcu_batch_move()
>> > without holding anything.  Which seems like it could cause trouble
>> > if someone else was invoking synchronize_srcu() concurrently.  Those
>> > particular invocations might be safe due to access only by a single
>> > kthread/workqueue, given that all updates to ->batch_queue are protected
>> > by ->queue_lock (aside from initialization).
>> >
>> > But ->batch_check0 is updated by __synchronize_srcu(), though protected
>> > by ->queue_lock, and only if ->running is false, and with both the
>> > check and the update protected by the same ->queue_lock critical section.
>> > If ->running is false, then the workqueue cannot be running, so it remains
>> > to see if all other updates to ->batch_check0 are either with ->queue_lock
>> > held and ->running false on the one hand or from the workqueue handler
>> > on the other:
>> >
>> > srcu_collect_new() updates with ->queue_lock held, but does not check
>> >     ->running.  It is invoked only from process_srcu(), which in
>> >     turn is invoked only as a workqueue handler.  The work is queued
>> >     from:
>> >
>> >     call_srcu(), which does so with ->queue_lock held having just
>> >             set ->running to true.
>> >
>> >     srcu_reschedule(), which invokes it if there are non-empty
>> >             queues.  This is invoked from __synchronize_srcu()
>> >             in the case where it has set ->running to true
>> >             after finding the queues empty, which should imply
>> >             no other instances.
>> >
>> >             It is also invoked from process_srcu(), which is
>> >             invoked only as a workqueue handler.  (Yay
>> >             recursive inquiry!)
>> >
>> > srcu_advance_batches() updates without locks held.  It is invoked as
>> >     follows:
>> >
>> >     __synchronize_srcu() in the case where ->running was set, which
>> >             as noted before excludes workqueue handlers.
>> >
>> >     process_srcu() which as noted before is only invoked from
>> >             a workqueue handler.
>> >
>> > So an SRCU workqueue is invoked only from a workqueue handler, or from
>> > some other task that transitioned ->running from false to true while
>> > holding ->queuelock.  There should therefore only be one SRCU workqueue
>> > per srcu_struct, so this should be safe.  Though I hope that it can
>> > be simplified a bit.  :-/
>> >
>> > So the only suggestion I have at the moment is static definition of
>> > the "srcu" variable.  Lai, Josh, Steve, Mathieu, anything I missed?
>> >
>> >                                             Thanx, Paul



This happened on linux-next/65b2dc38291f9f27e5ec3b804d6eb3b5f79a3ce4
and may be related.
The report says that srcu subsystem still uses the srcu object after
it has been freed. It can be a kvm fault as well.


==================================================================
BUG: KASAN: use-after-free in debug_spin_unlock
kernel/locking/spinlock_debug.c:97 [inline]
BUG: KASAN: use-after-free in do_raw_spin_unlock+0x2ea/0x320
kernel/locking/spinlock_debug.c:134
Read of size 4 at addr ffff88014158a564 by task kworker/1:1/5712

CPU: 1 PID: 5712 Comm: kworker/1:1 Not tainted 4.11.0-rc3-next-20170324+ #1
Hardware name: Google Google Compute Engine/Google Compute Engine,
BIOS Google 01/01/2011
Workqueue: events_power_efficient process_srcu
Call Trace:
 __dump_stack lib/dump_stack.c:16 [inline]
 dump_stack+0x2fb/0x40f lib/dump_stack.c:52
 print_address_description+0x7f/0x260 mm/kasan/report.c:250
 kasan_report_error mm/kasan/report.c:349 [inline]
 kasan_report.part.3+0x21f/0x310 mm/kasan/report.c:372
 kasan_report mm/kasan/report.c:392 [inline]
 __asan_report_load4_noabort+0x29/0x30 mm/kasan/report.c:392
 debug_spin_unlock kernel/locking/spinlock_debug.c:97 [inline]
 do_raw_spin_unlock+0x2ea/0x320 kernel/locking/spinlock_debug.c:134
 __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:167 [inline]
 _raw_spin_unlock_irq+0x22/0x70 kernel/locking/spinlock.c:199
 spin_unlock_irq include/linux/spinlock.h:349 [inline]
 srcu_reschedule+0x1a1/0x260 kernel/rcu/srcu.c:582
 process_srcu+0x63c/0x11c0 kernel/rcu/srcu.c:600
 process_one_work+0xac0/0x1b00 kernel/workqueue.c:2097
 worker_thread+0x1b4/0x1300 kernel/workqueue.c:2231
 kthread+0x36c/0x440 kernel/kthread.c:231
 ret_from_fork+0x31/0x40 arch/x86/entry/entry_64.S:430

Allocated by task 20961:
 save_stack_trace+0x16/0x20 arch/x86/kernel/stacktrace.c:59
 save_stack+0x43/0xd0 mm/kasan/kasan.c:515
 set_track mm/kasan/kasan.c:527 [inline]
 kasan_kmalloc+0xaa/0xd0 mm/kasan/kasan.c:619
 kmem_cache_alloc_trace+0x10b/0x670 mm/slab.c:3635
 kmalloc include/linux/slab.h:492 [inline]
 kzalloc include/linux/slab.h:665 [inline]
 kvm_arch_alloc_vm include/linux/kvm_host.h:773 [inline]
 kvm_create_vm arch/x86/kvm/../../../virt/kvm/kvm_main.c:610 [inline]
 kvm_dev_ioctl_create_vm arch/x86/kvm/../../../virt/kvm/kvm_main.c:3161 [inline]
 kvm_dev_ioctl+0x1bf/0x1460 arch/x86/kvm/../../../virt/kvm/kvm_main.c:3205
 vfs_ioctl fs/ioctl.c:45 [inline]
 do_vfs_ioctl+0x1bf/0x1780 fs/ioctl.c:685
 SYSC_ioctl fs/ioctl.c:700 [inline]
 SyS_ioctl+0x8f/0xc0 fs/ioctl.c:691
 entry_SYSCALL_64_fastpath+0x1f/0xbe

Freed by task 20960:
 save_stack_trace+0x16/0x20 arch/x86/kernel/stacktrace.c:59
 save_stack+0x43/0xd0 mm/kasan/kasan.c:515
 set_track mm/kasan/kasan.c:527 [inline]
 kasan_slab_free+0x6e/0xc0 mm/kasan/kasan.c:592
 __cache_free mm/slab.c:3511 [inline]
 kfree+0xd3/0x250 mm/slab.c:3828
 kvm_arch_free_vm include/linux/kvm_host.h:778 [inline]
 kvm_destroy_vm arch/x86/kvm/../../../virt/kvm/kvm_main.c:732 [inline]
 kvm_put_kvm+0x709/0x9a0 arch/x86/kvm/../../../virt/kvm/kvm_main.c:747
 kvm_vm_release+0x42/0x50 arch/x86/kvm/../../../virt/kvm/kvm_main.c:758
 __fput+0x332/0x800 fs/file_table.c:209
 ____fput+0x15/0x20 fs/file_table.c:245
 task_work_run+0x197/0x260 kernel/task_work.c:116
 exit_task_work include/linux/task_work.h:21 [inline]
 do_exit+0x1a53/0x27c0 kernel/exit.c:878
 do_group_exit+0x149/0x420 kernel/exit.c:982
 get_signal+0x7d8/0x1820 kernel/signal.c:2318
 do_signal+0xd2/0x2190 arch/x86/kernel/signal.c:808
 exit_to_usermode_loop+0x21c/0x2d0 arch/x86/entry/common.c:157
 prepare_exit_to_usermode arch/x86/entry/common.c:194 [inline]
 syscall_return_slowpath+0x4d3/0x570 arch/x86/entry/common.c:263
 entry_SYSCALL_64_fastpath+0xbc/0xbe

The buggy address belongs to the object at ffff880141581640
 which belongs to the cache kmalloc-65536 of size 65536
The buggy address is located 36644 bytes inside of
 65536-byte region [ffff880141581640, ffff880141591640)
The buggy address belongs to the page:
page:ffffea000464b400 count:1 mapcount:0 mapping:ffff880141581640
index:0x0 compound_mapcount: 0
flags: 0x200000000008100(slab|head)
raw: 0200000000008100 ffff880141581640 0000000000000000 0000000100000001
raw: ffffea00064b1f20 ffffea000640fa20 ffff8801db800d00
page dumped because: kasan: bad access detected

Memory state around the buggy address:
 ffff88014158a400: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
 ffff88014158a480: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
>ffff88014158a500: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
                                                       ^
 ffff88014158a580: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
 ffff88014158a600: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
==================================================================

[toc] | [prev] | [next] | [standalone]

#1609875

On Mon, Mar 27, 2017 at 02:36:35PM +0200, Dmitry Vyukov wrote:
> On Tue, Mar 14, 2017 at 5:21 PM, Paul E. McKenney
> <paulmck@linux.vnet.ibm.com> wrote:
> > On Tue, Mar 14, 2017 at 12:47:02AM -0700, Lance Roy wrote:
> >> I am not sure how the rcu_scheduler_active changes in __synchronize_srcu work,
> >> but there seem to be a few problems in them. First,
> >> "if (done && likely(!driving))" on line 453 doesn't appear to ever happen,
> >> as driving doesn't get set to false when srcu_reschedule is called. This seems
> >> like it could cause a race condition if another thread notices that ->running is
> >> false, adds itself to the queue, set ->running to true, and starts on its own
> >> grace period before the first thread acquires the lock again on line 469. Then
> >> the first thread will then acquire the lock, set running to false, and release
> >> the lock, resulting in an invalid state where ->running is false but the second
> >> thread is still trying to finish its grace period.
> >>
> >> Second, the while loop on line 455 seems to violate to rule that ->running
> >> shouldn't be false when there are entries in the queue. If a second thread adds
> >> itself to the queue while the first thread is driving SRCU inside that loop, and
> >> then the first thread finishes its own grace period and quits the loop, it will
> >> set ->running to false even though there is still a thread on the queue.
> >>
> >> The second issue requires rcu_scheduler_active to be RCU_SCHEDULER_INIT to
> >> occur, and as I don't what the assumptions during RCU_SCHEDULER_INIT are I don't
> >> know if it is actually a problem, but the first issue looks like it could occur
> >> at any time.
> >
> > Thank you for looking into this!
> >
> > I determined that my patch-order strategy was flawed, as it required
> > me to rewrite the mid-boot functionality several times.  I therefore
> > removed the mid-boot commits.  I will add them in later, but they will
> > use a rather different approach based on a grace-period sequence number
> > similar to that used by the expedited grace periods.
> >
> > Which should also teach me to be less aggressive about pushing new code
> > to -next.  For a few weeks, anyway.  ;-)
> >
> >                                                         Thanx, Paul
> >
> >> Thanks,
> >> Lance
> >>
> >> On Fri, 10 Mar 2017 14:26:09 -0800
> >> "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> wrote:
> >> > On Fri, Mar 10, 2017 at 08:29:55PM +0100, Andrey Konovalov wrote:
> >> > > On Fri, Mar 10, 2017 at 8:28 PM, Andrey Konovalov <andreyknvl@google.com>
> >> > > wrote:
> >> > > > Kernel panic - not syncing: Fatal exception
> >> >
> >> > So the theory is that if !sp->running, all of SRCU's queues must be empty.
> >> > So if you are holding ->queue_lock (with irqs disabled) and you see
> >> > !sp->running, and then you enqueue a callback on ->batch_check0, then
> >> > that callback must be the first in the list.  And the code preceding
> >> > the WARN_ON() you triggered does in fact check and enqueue shile holding
> >> > ->queue_lock with irqs disabled.
> >> >
> >> > And rcu_batch_queue() does operate FIFO as required.  (Otherwise,
> >> > srcu_barrier() would not work.)
> >> >
> >> > There are only three calls to rcu_batch_queue(), and the one involved with
> >> > the WARN_ON() enqueues to ->batch_check0.  The other two enqueue to
> >> > ->batch_queue.  Callbacks move from ->batch_queue to ->batch_check0 to
> >> > ->batch_check1 to ->batch_done, so nothing should slip in front.
> >> >
> >> > Of course, if ->running were ever set to false with any of ->batch_check0,
> >> > ->batch_check1, or ->batch_done non-empty, this WARN_ON() would trigger.
> >> > But srcu_reschedule() sets it to false only if all four batches are
> >> > empty (and checks and sets under ->queue_lock()), and all other cases
> >> > where it is set to false happen at initialization time, and also clear
> >> > out the queues.  Of course, if someone raced an init_srcu_struct() with
> >> > either a call_srcu() or synchronize_srcu(), all bets are off.  Now,
> >> > mmu_notifier.c does invoke init_srcu_struct() manually, but it does
> >> > so at subsys_initcall() time.  Which -might- be after other things are
> >> > happening, so one "hail Mary" attempted fix is to remove mmu_notifier_init()
> >> > and replace the "static struct srcu_struct srcu" with:
> >>
> >> >
> >> >     DEFINE_STATIC_SRCU(srcu);
> >> >
> >> > But this might require changing the name -- I vaguely recall some
> >> > strangeness where the names of statically defined per-CPU variables need
> >> > to be globally unique even when static.  Easy enough to do, though.
> >> > Might need a similar change to the "srcu" instances defined in vmd.c
> >> > and kvm_host.h -- assuming that this change helps.
> >> >
> >> > Another possibility is that something in SRCU is messing with either the
> >> > queues or the ->running field without holding ->queue_lock.  And that does
> >> > seem to be happening -- srcu_advance_batches() invokes rcu_batch_move()
> >> > without holding anything.  Which seems like it could cause trouble
> >> > if someone else was invoking synchronize_srcu() concurrently.  Those
> >> > particular invocations might be safe due to access only by a single
> >> > kthread/workqueue, given that all updates to ->batch_queue are protected
> >> > by ->queue_lock (aside from initialization).
> >> >
> >> > But ->batch_check0 is updated by __synchronize_srcu(), though protected
> >> > by ->queue_lock, and only if ->running is false, and with both the
> >> > check and the update protected by the same ->queue_lock critical section.
> >> > If ->running is false, then the workqueue cannot be running, so it remains
> >> > to see if all other updates to ->batch_check0 are either with ->queue_lock
> >> > held and ->running false on the one hand or from the workqueue handler
> >> > on the other:
> >> >
> >> > srcu_collect_new() updates with ->queue_lock held, but does not check
> >> >     ->running.  It is invoked only from process_srcu(), which in
> >> >     turn is invoked only as a workqueue handler.  The work is queued
> >> >     from:
> >> >
> >> >     call_srcu(), which does so with ->queue_lock held having just
> >> >             set ->running to true.
> >> >
> >> >     srcu_reschedule(), which invokes it if there are non-empty
> >> >             queues.  This is invoked from __synchronize_srcu()
> >> >             in the case where it has set ->running to true
> >> >             after finding the queues empty, which should imply
> >> >             no other instances.
> >> >
> >> >             It is also invoked from process_srcu(), which is
> >> >             invoked only as a workqueue handler.  (Yay
> >> >             recursive inquiry!)
> >> >
> >> > srcu_advance_batches() updates without locks held.  It is invoked as
> >> >     follows:
> >> >
> >> >     __synchronize_srcu() in the case where ->running was set, which
> >> >             as noted before excludes workqueue handlers.
> >> >
> >> >     process_srcu() which as noted before is only invoked from
> >> >             a workqueue handler.
> >> >
> >> > So an SRCU workqueue is invoked only from a workqueue handler, or from
> >> > some other task that transitioned ->running from false to true while
> >> > holding ->queuelock.  There should therefore only be one SRCU workqueue
> >> > per srcu_struct, so this should be safe.  Though I hope that it can
> >> > be simplified a bit.  :-/
> >> >
> >> > So the only suggestion I have at the moment is static definition of
> >> > the "srcu" variable.  Lai, Josh, Steve, Mathieu, anything I missed?
> >> >
> >> >                                             Thanx, Paul
> 
> 
> 
> This happened on linux-next/65b2dc38291f9f27e5ec3b804d6eb3b5f79a3ce4
> and may be related.
> The report says that srcu subsystem still uses the srcu object after
> it has been freed. It can be a kvm fault as well.

Hmmm...  I am not seeing a call to cleanup_srcu_struct() for the
->track_srcu field of the kvm_page_track_notifier_head structure.
Or is this structure immortal, so that it is never cleaned up?
Or am I just blind this morning?

In any case, freeing the kvm_page_track_notifier_head structure
without first invoking cleanup_srcu_struct() on its ->track_srcu
srcu_struct field could easily result in a use-after-free bug.

							Thanx, Paul

> ==================================================================
> BUG: KASAN: use-after-free in debug_spin_unlock
> kernel/locking/spinlock_debug.c:97 [inline]
> BUG: KASAN: use-after-free in do_raw_spin_unlock+0x2ea/0x320
> kernel/locking/spinlock_debug.c:134
> Read of size 4 at addr ffff88014158a564 by task kworker/1:1/5712
> 
> CPU: 1 PID: 5712 Comm: kworker/1:1 Not tainted 4.11.0-rc3-next-20170324+ #1
> Hardware name: Google Google Compute Engine/Google Compute Engine,
> BIOS Google 01/01/2011
> Workqueue: events_power_efficient process_srcu
> Call Trace:
>  __dump_stack lib/dump_stack.c:16 [inline]
>  dump_stack+0x2fb/0x40f lib/dump_stack.c:52
>  print_address_description+0x7f/0x260 mm/kasan/report.c:250
>  kasan_report_error mm/kasan/report.c:349 [inline]
>  kasan_report.part.3+0x21f/0x310 mm/kasan/report.c:372
>  kasan_report mm/kasan/report.c:392 [inline]
>  __asan_report_load4_noabort+0x29/0x30 mm/kasan/report.c:392
>  debug_spin_unlock kernel/locking/spinlock_debug.c:97 [inline]
>  do_raw_spin_unlock+0x2ea/0x320 kernel/locking/spinlock_debug.c:134
>  __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:167 [inline]
>  _raw_spin_unlock_irq+0x22/0x70 kernel/locking/spinlock.c:199
>  spin_unlock_irq include/linux/spinlock.h:349 [inline]
>  srcu_reschedule+0x1a1/0x260 kernel/rcu/srcu.c:582
>  process_srcu+0x63c/0x11c0 kernel/rcu/srcu.c:600
>  process_one_work+0xac0/0x1b00 kernel/workqueue.c:2097
>  worker_thread+0x1b4/0x1300 kernel/workqueue.c:2231
>  kthread+0x36c/0x440 kernel/kthread.c:231
>  ret_from_fork+0x31/0x40 arch/x86/entry/entry_64.S:430
> 
> Allocated by task 20961:
>  save_stack_trace+0x16/0x20 arch/x86/kernel/stacktrace.c:59
>  save_stack+0x43/0xd0 mm/kasan/kasan.c:515
>  set_track mm/kasan/kasan.c:527 [inline]
>  kasan_kmalloc+0xaa/0xd0 mm/kasan/kasan.c:619
>  kmem_cache_alloc_trace+0x10b/0x670 mm/slab.c:3635
>  kmalloc include/linux/slab.h:492 [inline]
>  kzalloc include/linux/slab.h:665 [inline]
>  kvm_arch_alloc_vm include/linux/kvm_host.h:773 [inline]
>  kvm_create_vm arch/x86/kvm/../../../virt/kvm/kvm_main.c:610 [inline]
>  kvm_dev_ioctl_create_vm arch/x86/kvm/../../../virt/kvm/kvm_main.c:3161 [inline]
>  kvm_dev_ioctl+0x1bf/0x1460 arch/x86/kvm/../../../virt/kvm/kvm_main.c:3205
>  vfs_ioctl fs/ioctl.c:45 [inline]
>  do_vfs_ioctl+0x1bf/0x1780 fs/ioctl.c:685
>  SYSC_ioctl fs/ioctl.c:700 [inline]
>  SyS_ioctl+0x8f/0xc0 fs/ioctl.c:691
>  entry_SYSCALL_64_fastpath+0x1f/0xbe
> 
> Freed by task 20960:
>  save_stack_trace+0x16/0x20 arch/x86/kernel/stacktrace.c:59
>  save_stack+0x43/0xd0 mm/kasan/kasan.c:515
>  set_track mm/kasan/kasan.c:527 [inline]
>  kasan_slab_free+0x6e/0xc0 mm/kasan/kasan.c:592
>  __cache_free mm/slab.c:3511 [inline]
>  kfree+0xd3/0x250 mm/slab.c:3828
>  kvm_arch_free_vm include/linux/kvm_host.h:778 [inline]
>  kvm_destroy_vm arch/x86/kvm/../../../virt/kvm/kvm_main.c:732 [inline]
>  kvm_put_kvm+0x709/0x9a0 arch/x86/kvm/../../../virt/kvm/kvm_main.c:747
>  kvm_vm_release+0x42/0x50 arch/x86/kvm/../../../virt/kvm/kvm_main.c:758
>  __fput+0x332/0x800 fs/file_table.c:209
>  ____fput+0x15/0x20 fs/file_table.c:245
>  task_work_run+0x197/0x260 kernel/task_work.c:116
>  exit_task_work include/linux/task_work.h:21 [inline]
>  do_exit+0x1a53/0x27c0 kernel/exit.c:878
>  do_group_exit+0x149/0x420 kernel/exit.c:982
>  get_signal+0x7d8/0x1820 kernel/signal.c:2318
>  do_signal+0xd2/0x2190 arch/x86/kernel/signal.c:808
>  exit_to_usermode_loop+0x21c/0x2d0 arch/x86/entry/common.c:157
>  prepare_exit_to_usermode arch/x86/entry/common.c:194 [inline]
>  syscall_return_slowpath+0x4d3/0x570 arch/x86/entry/common.c:263
>  entry_SYSCALL_64_fastpath+0xbc/0xbe
> 
> The buggy address belongs to the object at ffff880141581640
>  which belongs to the cache kmalloc-65536 of size 65536
> The buggy address is located 36644 bytes inside of
>  65536-byte region [ffff880141581640, ffff880141591640)
> The buggy address belongs to the page:
> page:ffffea000464b400 count:1 mapcount:0 mapping:ffff880141581640
> index:0x0 compound_mapcount: 0
> flags: 0x200000000008100(slab|head)
> raw: 0200000000008100 ffff880141581640 0000000000000000 0000000100000001
> raw: ffffea00064b1f20 ffffea000640fa20 ffff8801db800d00
> page dumped because: kasan: bad access detected
> 
> Memory state around the buggy address:
>  ffff88014158a400: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
>  ffff88014158a480: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> >ffff88014158a500: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
>                                                        ^
>  ffff88014158a580: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
>  ffff88014158a600: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
> ==================================================================
> 

[toc] | [prev] | [next] | [standalone]

#1609913

On Mon, Mar 27, 2017 at 4:16 PM, Paul E. McKenney
<paulmck@linux.vnet.ibm.com> wrote:
> On Mon, Mar 27, 2017 at 02:36:35PM +0200, Dmitry Vyukov wrote:
>> On Tue, Mar 14, 2017 at 5:21 PM, Paul E. McKenney
>> <paulmck@linux.vnet.ibm.com> wrote:
>> > On Tue, Mar 14, 2017 at 12:47:02AM -0700, Lance Roy wrote:
>> >> I am not sure how the rcu_scheduler_active changes in __synchronize_srcu work,
>> >> but there seem to be a few problems in them. First,
>> >> "if (done && likely(!driving))" on line 453 doesn't appear to ever happen,
>> >> as driving doesn't get set to false when srcu_reschedule is called. This seems
>> >> like it could cause a race condition if another thread notices that ->running is
>> >> false, adds itself to the queue, set ->running to true, and starts on its own
>> >> grace period before the first thread acquires the lock again on line 469. Then
>> >> the first thread will then acquire the lock, set running to false, and release
>> >> the lock, resulting in an invalid state where ->running is false but the second
>> >> thread is still trying to finish its grace period.
>> >>
>> >> Second, the while loop on line 455 seems to violate to rule that ->running
>> >> shouldn't be false when there are entries in the queue. If a second thread adds
>> >> itself to the queue while the first thread is driving SRCU inside that loop, and
>> >> then the first thread finishes its own grace period and quits the loop, it will
>> >> set ->running to false even though there is still a thread on the queue.
>> >>
>> >> The second issue requires rcu_scheduler_active to be RCU_SCHEDULER_INIT to
>> >> occur, and as I don't what the assumptions during RCU_SCHEDULER_INIT are I don't
>> >> know if it is actually a problem, but the first issue looks like it could occur
>> >> at any time.
>> >
>> > Thank you for looking into this!
>> >
>> > I determined that my patch-order strategy was flawed, as it required
>> > me to rewrite the mid-boot functionality several times.  I therefore
>> > removed the mid-boot commits.  I will add them in later, but they will
>> > use a rather different approach based on a grace-period sequence number
>> > similar to that used by the expedited grace periods.
>> >
>> > Which should also teach me to be less aggressive about pushing new code
>> > to -next.  For a few weeks, anyway.  ;-)
>> >
>> >                                                         Thanx, Paul
>> >
>> >> Thanks,
>> >> Lance
>> >>
>> >> On Fri, 10 Mar 2017 14:26:09 -0800
>> >> "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> wrote:
>> >> > On Fri, Mar 10, 2017 at 08:29:55PM +0100, Andrey Konovalov wrote:
>> >> > > On Fri, Mar 10, 2017 at 8:28 PM, Andrey Konovalov <andreyknvl@google.com>
>> >> > > wrote:
>> >> > > > Kernel panic - not syncing: Fatal exception
>> >> >
>> >> > So the theory is that if !sp->running, all of SRCU's queues must be empty.
>> >> > So if you are holding ->queue_lock (with irqs disabled) and you see
>> >> > !sp->running, and then you enqueue a callback on ->batch_check0, then
>> >> > that callback must be the first in the list.  And the code preceding
>> >> > the WARN_ON() you triggered does in fact check and enqueue shile holding
>> >> > ->queue_lock with irqs disabled.
>> >> >
>> >> > And rcu_batch_queue() does operate FIFO as required.  (Otherwise,
>> >> > srcu_barrier() would not work.)
>> >> >
>> >> > There are only three calls to rcu_batch_queue(), and the one involved with
>> >> > the WARN_ON() enqueues to ->batch_check0.  The other two enqueue to
>> >> > ->batch_queue.  Callbacks move from ->batch_queue to ->batch_check0 to
>> >> > ->batch_check1 to ->batch_done, so nothing should slip in front.
>> >> >
>> >> > Of course, if ->running were ever set to false with any of ->batch_check0,
>> >> > ->batch_check1, or ->batch_done non-empty, this WARN_ON() would trigger.
>> >> > But srcu_reschedule() sets it to false only if all four batches are
>> >> > empty (and checks and sets under ->queue_lock()), and all other cases
>> >> > where it is set to false happen at initialization time, and also clear
>> >> > out the queues.  Of course, if someone raced an init_srcu_struct() with
>> >> > either a call_srcu() or synchronize_srcu(), all bets are off.  Now,
>> >> > mmu_notifier.c does invoke init_srcu_struct() manually, but it does
>> >> > so at subsys_initcall() time.  Which -might- be after other things are
>> >> > happening, so one "hail Mary" attempted fix is to remove mmu_notifier_init()
>> >> > and replace the "static struct srcu_struct srcu" with:
>> >>
>> >> >
>> >> >     DEFINE_STATIC_SRCU(srcu);
>> >> >
>> >> > But this might require changing the name -- I vaguely recall some
>> >> > strangeness where the names of statically defined per-CPU variables need
>> >> > to be globally unique even when static.  Easy enough to do, though.
>> >> > Might need a similar change to the "srcu" instances defined in vmd.c
>> >> > and kvm_host.h -- assuming that this change helps.
>> >> >
>> >> > Another possibility is that something in SRCU is messing with either the
>> >> > queues or the ->running field without holding ->queue_lock.  And that does
>> >> > seem to be happening -- srcu_advance_batches() invokes rcu_batch_move()
>> >> > without holding anything.  Which seems like it could cause trouble
>> >> > if someone else was invoking synchronize_srcu() concurrently.  Those
>> >> > particular invocations might be safe due to access only by a single
>> >> > kthread/workqueue, given that all updates to ->batch_queue are protected
>> >> > by ->queue_lock (aside from initialization).
>> >> >
>> >> > But ->batch_check0 is updated by __synchronize_srcu(), though protected
>> >> > by ->queue_lock, and only if ->running is false, and with both the
>> >> > check and the update protected by the same ->queue_lock critical section.
>> >> > If ->running is false, then the workqueue cannot be running, so it remains
>> >> > to see if all other updates to ->batch_check0 are either with ->queue_lock
>> >> > held and ->running false on the one hand or from the workqueue handler
>> >> > on the other:
>> >> >
>> >> > srcu_collect_new() updates with ->queue_lock held, but does not check
>> >> >     ->running.  It is invoked only from process_srcu(), which in
>> >> >     turn is invoked only as a workqueue handler.  The work is queued
>> >> >     from:
>> >> >
>> >> >     call_srcu(), which does so with ->queue_lock held having just
>> >> >             set ->running to true.
>> >> >
>> >> >     srcu_reschedule(), which invokes it if there are non-empty
>> >> >             queues.  This is invoked from __synchronize_srcu()
>> >> >             in the case where it has set ->running to true
>> >> >             after finding the queues empty, which should imply
>> >> >             no other instances.
>> >> >
>> >> >             It is also invoked from process_srcu(), which is
>> >> >             invoked only as a workqueue handler.  (Yay
>> >> >             recursive inquiry!)
>> >> >
>> >> > srcu_advance_batches() updates without locks held.  It is invoked as
>> >> >     follows:
>> >> >
>> >> >     __synchronize_srcu() in the case where ->running was set, which
>> >> >             as noted before excludes workqueue handlers.
>> >> >
>> >> >     process_srcu() which as noted before is only invoked from
>> >> >             a workqueue handler.
>> >> >
>> >> > So an SRCU workqueue is invoked only from a workqueue handler, or from
>> >> > some other task that transitioned ->running from false to true while
>> >> > holding ->queuelock.  There should therefore only be one SRCU workqueue
>> >> > per srcu_struct, so this should be safe.  Though I hope that it can
>> >> > be simplified a bit.  :-/
>> >> >
>> >> > So the only suggestion I have at the moment is static definition of
>> >> > the "srcu" variable.  Lai, Josh, Steve, Mathieu, anything I missed?
>> >> >
>> >> >                                             Thanx, Paul
>>
>>
>>
>> This happened on linux-next/65b2dc38291f9f27e5ec3b804d6eb3b5f79a3ce4
>> and may be related.
>> The report says that srcu subsystem still uses the srcu object after
>> it has been freed. It can be a kvm fault as well.
>
> Hmmm...  I am not seeing a call to cleanup_srcu_struct() for the
> ->track_srcu field of the kvm_page_track_notifier_head structure.
> Or is this structure immortal, so that it is never cleaned up?
> Or am I just blind this morning?
>
> In any case, freeing the kvm_page_track_notifier_head structure
> without first invoking cleanup_srcu_struct() on its ->track_srcu
> srcu_struct field could easily result in a use-after-free bug.


Sent this to kvm people:
https://groups.google.com/d/msg/syzkaller/Sl0POwca6-s/QR_z6AsFCQAJ



>> ==================================================================
>> BUG: KASAN: use-after-free in debug_spin_unlock
>> kernel/locking/spinlock_debug.c:97 [inline]
>> BUG: KASAN: use-after-free in do_raw_spin_unlock+0x2ea/0x320
>> kernel/locking/spinlock_debug.c:134
>> Read of size 4 at addr ffff88014158a564 by task kworker/1:1/5712
>>
>> CPU: 1 PID: 5712 Comm: kworker/1:1 Not tainted 4.11.0-rc3-next-20170324+ #1
>> Hardware name: Google Google Compute Engine/Google Compute Engine,
>> BIOS Google 01/01/2011
>> Workqueue: events_power_efficient process_srcu
>> Call Trace:
>>  __dump_stack lib/dump_stack.c:16 [inline]
>>  dump_stack+0x2fb/0x40f lib/dump_stack.c:52
>>  print_address_description+0x7f/0x260 mm/kasan/report.c:250
>>  kasan_report_error mm/kasan/report.c:349 [inline]
>>  kasan_report.part.3+0x21f/0x310 mm/kasan/report.c:372
>>  kasan_report mm/kasan/report.c:392 [inline]
>>  __asan_report_load4_noabort+0x29/0x30 mm/kasan/report.c:392
>>  debug_spin_unlock kernel/locking/spinlock_debug.c:97 [inline]
>>  do_raw_spin_unlock+0x2ea/0x320 kernel/locking/spinlock_debug.c:134
>>  __raw_spin_unlock_irq include/linux/spinlock_api_smp.h:167 [inline]
>>  _raw_spin_unlock_irq+0x22/0x70 kernel/locking/spinlock.c:199
>>  spin_unlock_irq include/linux/spinlock.h:349 [inline]
>>  srcu_reschedule+0x1a1/0x260 kernel/rcu/srcu.c:582
>>  process_srcu+0x63c/0x11c0 kernel/rcu/srcu.c:600
>>  process_one_work+0xac0/0x1b00 kernel/workqueue.c:2097
>>  worker_thread+0x1b4/0x1300 kernel/workqueue.c:2231
>>  kthread+0x36c/0x440 kernel/kthread.c:231
>>  ret_from_fork+0x31/0x40 arch/x86/entry/entry_64.S:430
>>
>> Allocated by task 20961:
>>  save_stack_trace+0x16/0x20 arch/x86/kernel/stacktrace.c:59
>>  save_stack+0x43/0xd0 mm/kasan/kasan.c:515
>>  set_track mm/kasan/kasan.c:527 [inline]
>>  kasan_kmalloc+0xaa/0xd0 mm/kasan/kasan.c:619
>>  kmem_cache_alloc_trace+0x10b/0x670 mm/slab.c:3635
>>  kmalloc include/linux/slab.h:492 [inline]
>>  kzalloc include/linux/slab.h:665 [inline]
>>  kvm_arch_alloc_vm include/linux/kvm_host.h:773 [inline]
>>  kvm_create_vm arch/x86/kvm/../../../virt/kvm/kvm_main.c:610 [inline]
>>  kvm_dev_ioctl_create_vm arch/x86/kvm/../../../virt/kvm/kvm_main.c:3161 [inline]
>>  kvm_dev_ioctl+0x1bf/0x1460 arch/x86/kvm/../../../virt/kvm/kvm_main.c:3205
>>  vfs_ioctl fs/ioctl.c:45 [inline]
>>  do_vfs_ioctl+0x1bf/0x1780 fs/ioctl.c:685
>>  SYSC_ioctl fs/ioctl.c:700 [inline]
>>  SyS_ioctl+0x8f/0xc0 fs/ioctl.c:691
>>  entry_SYSCALL_64_fastpath+0x1f/0xbe
>>
>> Freed by task 20960:
>>  save_stack_trace+0x16/0x20 arch/x86/kernel/stacktrace.c:59
>>  save_stack+0x43/0xd0 mm/kasan/kasan.c:515
>>  set_track mm/kasan/kasan.c:527 [inline]
>>  kasan_slab_free+0x6e/0xc0 mm/kasan/kasan.c:592
>>  __cache_free mm/slab.c:3511 [inline]
>>  kfree+0xd3/0x250 mm/slab.c:3828
>>  kvm_arch_free_vm include/linux/kvm_host.h:778 [inline]
>>  kvm_destroy_vm arch/x86/kvm/../../../virt/kvm/kvm_main.c:732 [inline]
>>  kvm_put_kvm+0x709/0x9a0 arch/x86/kvm/../../../virt/kvm/kvm_main.c:747
>>  kvm_vm_release+0x42/0x50 arch/x86/kvm/../../../virt/kvm/kvm_main.c:758
>>  __fput+0x332/0x800 fs/file_table.c:209
>>  ____fput+0x15/0x20 fs/file_table.c:245
>>  task_work_run+0x197/0x260 kernel/task_work.c:116
>>  exit_task_work include/linux/task_work.h:21 [inline]
>>  do_exit+0x1a53/0x27c0 kernel/exit.c:878
>>  do_group_exit+0x149/0x420 kernel/exit.c:982
>>  get_signal+0x7d8/0x1820 kernel/signal.c:2318
>>  do_signal+0xd2/0x2190 arch/x86/kernel/signal.c:808
>>  exit_to_usermode_loop+0x21c/0x2d0 arch/x86/entry/common.c:157
>>  prepare_exit_to_usermode arch/x86/entry/common.c:194 [inline]
>>  syscall_return_slowpath+0x4d3/0x570 arch/x86/entry/common.c:263
>>  entry_SYSCALL_64_fastpath+0xbc/0xbe
>>
>> The buggy address belongs to the object at ffff880141581640
>>  which belongs to the cache kmalloc-65536 of size 65536
>> The buggy address is located 36644 bytes inside of
>>  65536-byte region [ffff880141581640, ffff880141591640)
>> The buggy address belongs to the page:
>> page:ffffea000464b400 count:1 mapcount:0 mapping:ffff880141581640
>> index:0x0 compound_mapcount: 0
>> flags: 0x200000000008100(slab|head)
>> raw: 0200000000008100 ffff880141581640 0000000000000000 0000000100000001
>> raw: ffffea00064b1f20 ffffea000640fa20 ffff8801db800d00
>> page dumped because: kasan: bad access detected
>>
>> Memory state around the buggy address:
>>  ffff88014158a400: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
>>  ffff88014158a480: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
>> >ffff88014158a500: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
>>                                                        ^
>>  ffff88014158a580: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
>>  ffff88014158a600: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
>> ==================================================================
>>
>

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web