lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Date:   Sat, 23 Feb 2019 11:33:33 +0100
From:   Dmitry Vyukov <dvyukov@...gle.com>
To:     Borislav Petkov <bp@...en8.de>
Cc:     syzbot <syzbot+111bc509cd9740d7e4aa@...kaller.appspotmail.com>,
        Dou Liyang <douly.fnst@...fujitsu.com>,
        "H. Peter Anvin" <hpa@...or.com>, konrad.wilk@...cle.com,
        Len Brown <len.brown@...el.com>,
        LKML <linux-kernel@...r.kernel.org>,
        Ingo Molnar <mingo@...hat.com>, puwen@...on.cn,
        syzkaller-bugs <syzkaller-bugs@...glegroups.com>,
        Thomas Gleixner <tglx@...utronix.de>, wang.yi59@....com.cn,
        "the arch/x86 maintainers" <x86@...nel.org>
Subject: Re: WARNING in rcu_check_gp_start_stall

On Fri, Feb 22, 2019 at 11:20 PM Borislav Petkov <bp@...en8.de> wrote:
>
> On Fri, Feb 22, 2019 at 09:10:04AM -0800, syzbot wrote:
> > Hello,
> >
> > syzbot found the following crash on:
> >
> > HEAD commit:    8a61716ff2ab Merge tag 'ceph-for-5.0-rc8' of git://github...
> > git tree:       upstream
> > console output: https://syzkaller.appspot.com/x/log.txt?x=1531dd3f400000
> > kernel config:  https://syzkaller.appspot.com/x/.config?x=7132344728e7ec3f
> > dashboard link: https://syzkaller.appspot.com/bug?extid=111bc509cd9740d7e4aa
> > compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> > syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=16d4966cc00000
> > C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=10c492d0c00000
>
> So I ran this for more than an hour in a guest here with the above
> .config but nothing happened. The compiler I used is 8.2, dunno of that
> makes the difference or I'm missing something else...

I was able to reproduce this on the first run:

# ./syz-execprog -procs=8 -repeat=0 hang
2019/02/23 10:24:31 parsed 1 programs
2019/02/23 10:24:31 executed programs: 0
2019/02/23 10:24:36 executed programs: 23
2019/02/23 10:24:41 executed programs: 71
2019/02/23 10:24:46 executed programs: 118
2019/02/23 10:24:52 executed programs: 162
2019/02/23 10:24:57 executed programs: 208
2019/02/23 10:25:02 executed programs: 258
2019/02/23 10:25:07 executed programs: 288

And on the console:

[   77.032078] sched: RT throttling activated
[  183.901866] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[  183.902595] rcu: (detected by 2, t=10502 jiffies, g=5945, q=335)
[  183.903249] rcu: All QSes seen, last rcu_preempt kthread activity
10500 (4294955649-4294945149), jiffies_till_next_fqs=1, root ->qsmask
0x0
[  183.904548] syz-executor    R  running task    56728  7574   6076 0x00000000
[  183.905300] Call Trace:
[  183.905570]  <IRQ>
[  183.905807]  sched_show_task.cold+0x273/0x2d5
[  183.906283]  ? can_nice.part.0+0x20/0x20
[  183.906708]  ? kmsg_dump_rewind_nolock+0xe4/0xe4
[  183.907205]  ? print_usage_bug+0xd0/0xd0
[  183.907629]  ? __sanitizer_cov_trace_cmp8+0x18/0x20
[  183.908149]  ? __sanitizer_cov_trace_const_cmp4+0x16/0x20
[  183.908729]  print_other_cpu_stall.cold+0x7f2/0x8bb
[  183.909260]  ? print_cpu_stall+0x170/0x170
[  183.909703]  ? add_lock_to_list.isra.0+0x450/0x450
[  183.910219]  ? find_held_lock+0x35/0x120
[  183.910643]  ? __sanitizer_cov_trace_const_cmp4+0x16/0x20
[  183.911217]  ? __sanitizer_cov_trace_const_cmp4+0x16/0x20
[  183.911791]  ? __sanitizer_cov_trace_const_cmp4+0x16/0x20
[  183.912367]  ? check_preemption_disabled+0x48/0x290
[  183.912889]  ? __this_cpu_preempt_check+0x1d/0x30
[  183.913389]  ? rcu_preempt_need_deferred_qs+0x71/0x1a0
[  183.913939]  ? do_trace_rcu_torture_read+0x10/0x10
[  183.914496]  ? __sanitizer_cov_trace_const_cmp4+0x16/0x20
[  183.915119]  ? check_preemption_disabled+0x48/0x290
[  183.915681]  ? __sanitizer_cov_trace_const_cmp4+0x16/0x20
[  183.916307]  ? check_preemption_disabled+0x48/0x290
[  183.916876]  rcu_check_callbacks+0xf36/0x1380
[  183.917381]  ? account_system_index_time+0x31a/0x5f0
[  183.917964]  ? rcutree_dead_cpu+0x10/0x10
[  183.918437]  ? trace_hardirqs_off+0xb8/0x310
[  183.918934]  ? __lock_is_held+0xb6/0x140
[  183.919392]  ? trace_hardirqs_on_caller+0x310/0x310
[  183.919966]  ? check_preemption_disabled+0x48/0x290
[  183.920536]  ? raise_softirq+0x189/0x430
[  183.920997]  ? account_system_index_time+0x33f/0x5f0
[  183.921575]  ? raise_softirq_irqoff+0x2d0/0x2d0
[  183.922110]  ? check_preemption_disabled+0x48/0x290
[  183.922679]  ? __sanitizer_cov_trace_const_cmp1+0x1a/0x20
[  183.923303]  ? hrtimer_run_queues+0x99/0x410
[  183.923806]  ? run_local_timers+0x194/0x230
[  183.924301]  ? timer_clear_idle+0x90/0x90
[  183.924777]  ? account_process_tick+0x27f/0x350
[  183.925314]  ? ktime_mono_to_any+0x3a0/0x3a0
[  183.925819]  ? __sanitizer_cov_trace_const_cmp4+0x16/0x20
[  183.926461]  update_process_times+0x32/0x80
[  183.926960]  tick_sched_handle+0xa2/0x190
[  183.927438]  tick_sched_timer+0x47/0x130
[  183.927905]  __hrtimer_run_queues+0x3a7/0x1050
[  183.928433]  ? tick_sched_do_timer+0x1b0/0x1b0
[  183.928959]  ? hrtimer_fixup_init+0x90/0x90
[  183.929450]  ? kvm_clock_read+0x18/0x30
[  183.929904]  ? __sanitizer_cov_trace_cmp4+0x16/0x20
[  183.930473]  ? ktime_get_update_offsets_now+0x3d5/0x5e0
[  183.931081]  ? do_timer+0x50/0x50
[  183.931474]  ? add_lock_to_list.isra.0+0x450/0x450
[  183.932032]  ? rcu_softirq_qs+0x20/0x20
[  183.932482]  ? __sanitizer_cov_trace_const_cmp4+0x16/0x20
[  183.933112]  hrtimer_interrupt+0x314/0x770
[  183.933600]  smp_apic_timer_interrupt+0x18d/0x760
[  183.934160]  ? trace_hardirqs_off_thunk+0x1a/0x1c
[  183.934716]  ? smp_call_function_single_interrupt+0x640/0x640
[  183.935386]  ? trace_hardirqs_off+0x310/0x310
[  183.935897]  ? task_prio+0x50/0x50
[  183.936304]  ? __sanitizer_cov_trace_const_cmp4+0x16/0x20
[  183.936932]  ? check_preemption_disabled+0x48/0x290
[  183.937504]  ? trace_hardirqs_off_thunk+0x1a/0x1c
[  183.938067]  apic_timer_interrupt+0xf/0x20
[  183.938549]  </IRQ>
[  183.938808] RIP: 0010:lock_is_held_type+0x17e/0x210
[  183.939379] Code: 00 00 00 fc ff df 41 c7 85 7c 08 00 00 00 00 00
00 48 c1 e8 03 80 3c 10 00 75 63 48 83 3d f9 65 2e 08 00 74 30 48 89
df 57 9d <0f> 1f 44 00 00 48 83 c4 08 44 89 e0 5b 41 5c 41 5d 5d c3 48
83 c4
[  183.941512] RSP: 0018:ffff88804c04f2c8 EFLAGS: 00000286 ORIG_RAX:
ffffffffffffff13
[  183.942388] RAX: 1ffffffff132607e RBX: 0000000000000286 RCX: dffffc0000000000
[  183.943208] RDX: dffffc0000000000 RSI: 0000000000000000 RDI: 0000000000000286
[  183.944032] RBP: ffff88804c04f2e8 R08: ffff88805c074000 R09: ffffed100d8a7f98
[  183.944855] R10: ffffed100d8a7f97 R11: ffff88806c53fcbb R12: 0000000000000000
[  183.945674] R13: ffff88805c074000 R14: dffffc0000000000 R15: 0000000000000008
[  183.946508]  ___might_sleep+0xd5/0x160
[  183.946956]  ? ext4_write_end+0x1090/0x1090
[  183.947452]  generic_perform_write+0x3fd/0x6a0
[  183.947978]  ? add_page_wait_queue+0x480/0x480
[  183.948504]  ? current_time+0x1b0/0x1b0
[  183.948958]  ? generic_write_check_limits+0x380/0x380
[  183.949547]  ? ext4_file_write_iter+0x28b/0x1440
[  183.950091]  __generic_file_write_iter+0x25e/0x630
[  183.950659]  ext4_file_write_iter+0x37a/0x1440
[  183.951184]  ? ext4_file_mmap+0x410/0x410
[  183.951654]  ? save_stack+0xa9/0xd0
[  183.952065]  ? save_stack+0x45/0xd0
[  183.952477]  ? __kasan_kmalloc.constprop.0+0xcf/0xe0
[  183.953053]  ? kasan_kmalloc+0x9/0x10
[  183.953485]  ? __kmalloc+0x15c/0x740
[  183.953918]  ? iter_file_splice_write+0x267/0xfc0
[  183.954466]  ? splice_direct_to_actor+0x3be/0x9d0
[  183.955015]  ? do_splice_direct+0x2c7/0x420
[  183.955504]  ? do_sendfile+0x61d/0xe60
[  183.955948]  ? __x64_sys_sendfile64+0x15a/0x240
[  183.956475]  ? do_syscall_64+0x1a3/0x800
[  183.956939]  ? entry_SYSCALL_64_after_hwframe+0x49/0xbe
[  183.957550]  ? debug_lockdep_rcu_enabled+0x71/0xa0
[  183.958115]  ? common_file_perm+0x231/0x800
[  183.958604]  ? print_usage_bug+0xd0/0xd0
[  183.959066]  do_iter_readv_writev+0x902/0xbc0
[  183.959582]  ? vfs_dedupe_file_range+0x780/0x780
[  183.960122]  ? apparmor_file_permission+0x25/0x30
[  183.960674]  ? rw_verify_area+0x118/0x360
[  183.961146]  do_iter_write+0x184/0x610
[  183.961587]  ? pipe_to_sendpage+0x390/0x390
[  183.962087]  ? rcu_read_lock_sched_held+0x110/0x130
[  183.962658]  ? __kmalloc+0x5d5/0x740
[  183.963082]  vfs_iter_write+0x77/0xb0
[  183.963515]  iter_file_splice_write+0x885/0xfc0
[  183.964044]  ? fsnotify+0x4f5/0xed0
[  183.964462]  ? page_cache_pipe_buf_steal+0x800/0x800
[  183.965046]  ? rw_verify_area+0x118/0x360
[  183.965516]  ? page_cache_pipe_buf_steal+0x800/0x800
[  183.966098]  direct_splice_actor+0x126/0x1a0
[  183.966598]  splice_direct_to_actor+0x3be/0x9d0
[  183.967125]  ? generic_pipe_buf_nosteal+0x10/0x10
[  183.967679]  ? do_splice_to+0x190/0x190
[  183.968134]  ? __sanitizer_cov_trace_const_cmp4+0x16/0x20
[  183.968762]  ? rw_verify_area+0x118/0x360
[  183.969233]  do_splice_direct+0x2c7/0x420
[  183.969709]  ? splice_direct_to_actor+0x9d0/0x9d0
[  183.970264]  ? rcu_read_lock_sched_held+0x110/0x130
[  183.970833]  ? rcu_sync_lockdep_assert+0x73/0xb0
[  183.971376]  ? __sanitizer_cov_trace_const_cmp4+0x16/0x20
[  183.972003]  ? __sb_start_write+0x1aa/0x360
[  183.972499]  do_sendfile+0x61d/0xe60
[  183.972926]  ? do_compat_pwritev64+0x1c0/0x1c0
[  183.973453]  ? __sanitizer_cov_trace_const_cmp8+0x18/0x20
[  183.974084]  ? _copy_from_user+0xdd/0x150
[  183.974561]  __x64_sys_sendfile64+0x15a/0x240
[  183.975080]  ? __ia32_sys_sendfile+0x2a0/0x2a0
[  183.975605]  ? trace_hardirqs_on_thunk+0x1a/0x1c
[  183.976151]  do_syscall_64+0x1a3/0x800
[  183.976598]  ? syscall_return_slowpath+0x5f0/0x5f0
[  183.977161]  ? prepare_exit_to_usermode+0x3b0/0x3b0
[  183.977733]  ? __switch_to_asm+0x34/0x70
[  183.978204]  ? trace_hardirqs_off_thunk+0x1a/0x1c
[  183.978758]  entry_SYSCALL_64_after_hwframe+0x49/0xbe
[  183.979348] RIP: 0033:0x457629
[  183.979714] Code: 8d b5 fb ff c3 66 2e 0f 1f 84 00 00 00 00 00 66
90 48 89 f8 48 89 f7 48 89 d6 48 89 ca 4d 89 c2 4d 89 c8 4c 8b 4c 24
08 0f 05 <48> 3d 01 f0 ff ff 0f 83 5b b5 fb ff c3 66 2e 0f 1f 84 00 00
00 00
[  183.981845] RSP: 002b:00007f435f197c88 EFLAGS: 00000246 ORIG_RAX:
0000000000000028
[  183.982718] RAX: ffffffffffffffda RBX: 000000000071bfa0 RCX: 0000000000457629
[  183.983533] RDX: 0000000020000000 RSI: 0000000000000003 RDI: 0000000000000003
[  183.984358] RBP: 0000000000000004 R08: 0000000000000000 R09: 0000000000000000
[  183.985179] R10: 00008080fffffffe R11: 0000000000000246 R12: 00007f435f1986d4
[  183.986005] R13: 00000000004abf30 R14: 00000000006eb8b8 R15: 00000000ffffffff



This is with qemu with 4 CPUs:

qemu-system-x86_64 -hda wheezy.img -net
user,host=10.0.2.10,hostfwd=tcp::10022-:22 -net nic -nographic -kernel
arch/x86/boot/bzImage -append "kvm-intel.nested=1
kvm-intel.unrestricted_guest=1 kvm-intel.ept=1
kvm-intel.flexpriority=1 kvm-intel.vpid=1
kvm-intel.emulate_invalid_guest_state=1 kvm-intel.eptad=1
kvm-intel.enable_shadow_vmcs=1 kvm-intel.pml=1
kvm-intel.enable_apicv=1 console=ttyS0 root=/dev/sda
earlyprintk=serial slub_debug=UZ vsyscall=native rodata=n oops=panic
panic_on_warn=1 panic=86400 ima_policy=tcb" -enable-kvm -pidfile
vm_pid -m 2G -smp 4 -cpu host


There is a bunch of other bug reports about hangs where reproducers
mention perf_event_open and sched_setattr.

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ