| 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
| ||
|
Date: Wed, 15 Jun 2016 08:12:56 +0800
From: kernel test robot <xiaolong.ye@...el.com>
To: Trond Myklebust <trond.myklebust@...marydata.com>
Cc: lkp@...org, LKML <linux-kernel@...r.kernel.org>,
0day robot <fengguang.wu@...el.com>
Subject: [NFS] 5aaca3e48a: INFO: suspicious RCU usage. ]
FYI, we noticed the following commit:
https://github.com/0day-ci/linux Trond-Myklebust/NFS-Don-t-flush-caches-for-a-getattr-that-races-with-writeback/20160615-032846
commit 5aaca3e48a8af4a0dc5f194db9d29bb970dd445e ("NFS: Cache access checks more aggressively")
on test machine: vm-lkp-wsx03-2G: 2 threads qemu-system-x86_64 -enable-kvm -cpu host with 2G memory
caused below changes:
+------------------------------------------------------------------------------------+------------+------------+
| | b15f825456 | 5aaca3e48a |
+------------------------------------------------------------------------------------+------------+------------+
| boot_successes | 22 | 0 |
| boot_failures | 0 | 22 |
| INFO:suspicious_RCU_usage | 0 | 22 |
| BUG:sleeping_function_called_from_invalid_context_at_mm/slab.h | 0 | 22 |
| INFO:lockdep_is_turned_off | 0 | 22 |
| BUG:scheduling_while_atomic | 0 | 22 |
| BUG:sleeping_function_called_from_invalid_context_at_kernel/locking/percpu-rwsem.c | 0 | 11 |
| WARNING:at_kernel/softirq.c:#__local_bh_disable_ip | 0 | 10 |
| WARNING:at_kernel/time/timer.c:#del_timer_sync | 0 | 10 |
| backtrace:do_sys_open | 0 | 21 |
| backtrace:SyS_open | 0 | 21 |
| backtrace:SYSC_newstat | 0 | 10 |
| backtrace:SyS_newstat | 0 | 10 |
| BUG:sleeping_function_called_from_invalid_context_at_net/core/sock.c | 0 | 1 |
| Kernel_panic-not_syncing:Aiee,killing_interrupt_handler | 0 | 6 |
| backtrace:SYSC_newlstat | 0 | 6 |
| backtrace:SyS_newlstat | 0 | 6 |
+------------------------------------------------------------------------------------+------------+------------+
[ 41.505679] mount.nfs (820) used greatest stack depth: 11400 bytes left
[ 41.810842]
[ 41.811358] ===============================
[ 41.812192] [ INFO: suspicious RCU usage. ]
[ 41.813003] 4.7.0-rc3-00002-g5aaca3e #1 Not tainted
[ 41.813899] -------------------------------
[ 41.814707] include/linux/rcupdate.h:554 Illegal context switch in RCU read-side critical section!
[ 41.816588]
[ 41.816588] other info that might help us debug this:
[ 41.816588]
[ 41.818246]
[ 41.818246] rcu_scheduler_active = 1, debug_locks = 0
[ 41.819557] 2 locks held by wrapper/875:
[ 41.820326] #0: (rcu_read_lock){......}, at: [<ffffffff8122539e>] rcu_read_lock+0x0/0x68
[ 41.822256] #1: (rcu_read_lock){......}, at: [<ffffffff81358b9b>] rcu_read_lock+0x0/0x68
[ 41.824204]
[ 41.824204] stack backtrace:
[ 41.825180] CPU: 1 PID: 875 Comm: wrapper Not tainted 4.7.0-rc3-00002-g5aaca3e #1
[ 41.826594] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 41.828168] 0000000000000000 ffff88007d283a98 ffffffff817767c7 ffff88007d3c9100
[ 41.829890] 0000000000000001 ffff88007d283ac8 ffffffff8112049f ffffffff839fa873
[ 41.831597] 0000000000000184 0000000000000000 0000000002400040 ffff88007d283ad8
[ 41.833309] Call Trace:
[ 41.833870] [<ffffffff817767c7>] dump_stack+0x82/0xb8
[ 41.834791] [<ffffffff8112049f>] lockdep_rcu_suspicious+0xf7/0x100
[ 41.835865] [<ffffffff81105d1b>] rcu_preempt_sleep_check+0x45/0x47
[ 41.836938] [<ffffffff81105d39>] ___might_sleep+0x1c/0x1c4
[ 41.837921] [<ffffffff81105f56>] __might_sleep+0x75/0x7c
[ 41.838883] [<ffffffff812059a4>] slab_pre_alloc_hook+0x32/0x3f
[ 41.839926] [<ffffffff81207728>] kmem_cache_alloc_trace+0x3d/0x133
[ 41.841008] [<ffffffff8135e904>] ? nfs_alloc_fattr+0x20/0x37
[ 41.842010] [<ffffffff8135e904>] nfs_alloc_fattr+0x20/0x37
[ 41.843004] [<ffffffff813602a8>] __nfs_revalidate_inode+0xeb/0x2eb
[ 41.844088] [<ffffffff8135bb5f>] nfs_do_access+0x3ec/0x46f
[ 41.845083] [<ffffffff82d36756>] ? generic_lookup_cred+0x1a/0x1c
[ 41.846141] [<ffffffff82d3569b>] ? rpcauth_lookupcred+0x61/0x6a
[ 41.847182] [<ffffffff8135bcd9>] nfs_permission+0xbe/0x188
[ 41.848176] [<ffffffff812236e8>] __inode_permission+0x3e/0xa0
[ 41.849222] [<ffffffff81223789>] inode_permission+0x3f/0x41
[ 41.850227] [<ffffffff81225e63>] link_path_walk+0x47/0x478
[ 41.851217] [<ffffffff812263b1>] ? path_init+0x11d/0x2a4
[ 41.852182] [<ffffffff81226acd>] path_openat+0x2ba/0x750
[ 41.853157] [<ffffffff8109b030>] ? kvm_clock_read+0x25/0x2e
[ 41.854163] [<ffffffff812285c9>] do_filp_open+0x4d/0xa3
[ 41.855119] [<ffffffff8110cf3d>] ? sched_clock_cpu+0x15/0xae
[ 41.856140] [<ffffffff82ecf66d>] ? _raw_spin_unlock+0x27/0x31
[ 41.857176] [<ffffffff812341ca>] ? __alloc_fd+0x1b2/0x1c4
[ 41.858161] [<ffffffff81219127>] do_sys_open+0x72/0x102
[ 41.859119] [<ffffffff81219127>] ? do_sys_open+0x72/0x102
[ 41.860099] [<ffffffff812191d5>] SyS_open+0x1e/0x20
[ 41.861000] [<ffffffff82ecff3c>] entry_SYSCALL_64_fastpath+0x1f/0xbd
[ 41.862103] [<ffffffff8111e7e9>] ? trace_hardirqs_off_caller+0x3f/0xab
[ 41.863269] BUG: sleeping function called from invalid context at mm/slab.h:388
[ 41.864906] in_atomic(): 1, irqs_disabled(): 0, pid: 875, name: wrapper
[ 41.866026] INFO: lockdep is turned off.
[ 41.866788] CPU: 1 PID: 875 Comm: wrapper Not tainted 4.7.0-rc3-00002-g5aaca3e #1
[ 41.868181] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 41.869768] 0000000000000000 ffff88007d283ad8 ffffffff817767c7 ffff88007d3c9100
[ 41.871478] 000000000000036b ffff88007d283b00 ffffffff81105eda ffffffff839fa873
[ 41.873186] 0000000000000184 0000000000000000 ffff88007d283b28 ffffffff81105f56
[ 41.874902] Call Trace:
[ 41.875470] [<ffffffff817767c7>] dump_stack+0x82/0xb8
[ 41.876405] [<ffffffff81105eda>] ___might_sleep+0x1bd/0x1c4
[ 41.877407] [<ffffffff81105f56>] __might_sleep+0x75/0x7c
[ 41.878373] [<ffffffff812059a4>] slab_pre_alloc_hook+0x32/0x3f
[ 41.879416] [<ffffffff81207728>] kmem_cache_alloc_trace+0x3d/0x133
[ 41.880490] [<ffffffff8135e904>] ? nfs_alloc_fattr+0x20/0x37
[ 41.881499] [<ffffffff8135e904>] nfs_alloc_fattr+0x20/0x37
[ 41.882483] [<ffffffff813602a8>] __nfs_revalidate_inode+0xeb/0x2eb
[ 41.883560] [<ffffffff8135bb5f>] nfs_do_access+0x3ec/0x46f
[ 41.884543] [<ffffffff82d36756>] ? generic_lookup_cred+0x1a/0x1c
[ 41.885597] [<ffffffff82d3569b>] ? rpcauth_lookupcred+0x61/0x6a
[ 41.886641] [<ffffffff8135bcd9>] nfs_permission+0xbe/0x188
[ 41.887628] [<ffffffff812236e8>] __inode_permission+0x3e/0xa0
[ 41.888649] [<ffffffff81223789>] inode_permission+0x3f/0x41
[ 41.889653] [<ffffffff81225e63>] link_path_walk+0x47/0x478
[ 41.890638] [<ffffffff812263b1>] ? path_init+0x11d/0x2a4
[ 41.891595] [<ffffffff81226acd>] path_openat+0x2ba/0x750
[ 41.892565] [<ffffffff8109b030>] ? kvm_clock_read+0x25/0x2e
[ 41.893564] [<ffffffff812285c9>] do_filp_open+0x4d/0xa3
[ 41.894513] [<ffffffff8110cf3d>] ? sched_clock_cpu+0x15/0xae
[ 41.895520] [<ffffffff82ecf66d>] ? _raw_spin_unlock+0x27/0x31
[ 41.896535] [<ffffffff812341ca>] ? __alloc_fd+0x1b2/0x1c4
[ 41.897508] [<ffffffff81219127>] do_sys_open+0x72/0x102
[ 41.898453] [<ffffffff81219127>] ? do_sys_open+0x72/0x102
[ 41.899437] [<ffffffff812191d5>] SyS_open+0x1e/0x20
[ 41.900346] [<ffffffff82ecff3c>] entry_SYSCALL_64_fastpath+0x1f/0xbd
[ 41.901445] [<ffffffff8111e7e9>] ? trace_hardirqs_off_caller+0x3f/0xab
[ 41.902740] BUG: scheduling while atomic: wrapper/875/0x00000003
[ 41.903862] INFO: lockdep is turned off.
[ 41.904629] Modules linked in:
[ 41.905359] CPU: 1 PID: 875 Comm: wrapper Not tainted 4.7.0-rc3-00002-g5aaca3e #1
[ 41.906742] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 41.910291] 0000000000000000 ffff88007d2837d8 ffffffff817767c7 ffff88007d3c9100
[ 41.912029] 0000000000000000 ffff88007d2837f0 ffffffff81105441 ffff88009f5d8fc0
[ 41.913778] ffff88007d283850 ffffffff82ecb27d ffff88007d283820 00ffffff81121949
[ 41.915520] Call Trace:
[ 41.916094] [<ffffffff817767c7>] dump_stack+0x82/0xb8
[ 41.917032] [<ffffffff81105441>] __schedule_bug+0x61/0x70
[ 41.918009] [<ffffffff82ecb27d>] __schedule+0x6b/0x76f
[ 41.918958] [<ffffffff82d33909>] ? trace_event_raw_event_xs_tcp_data_ready+0xd4/0xd4
[ 41.920430] [<ffffffff82ecba09>] schedule+0x88/0x9d
[ 41.921336] [<ffffffff82d3392d>] rpc_wait_bit_killable+0x24/0xab
[ 41.922395] [<ffffffff82ecbf4b>] __wait_on_bit+0x4c/0x7e
[ 41.923370] [<ffffffff82ecbfef>] out_of_line_wait_on_bit+0x72/0x7d
[ 41.924457] [<ffffffff82d33909>] ? trace_event_raw_event_xs_tcp_data_ready+0xd4/0xd4
[ 41.925908] [<ffffffff81118633>] ? autoremove_wake_function+0x3a/0x3a
[ 41.927032] [<ffffffff82d2b1f3>] ? call_transmit_status+0xa4/0xa4
[ 41.928103] [<ffffffff82d3496f>] __rpc_execute+0x19b/0x41b
[ 41.929094] [<ffffffff81118479>] ? wake_up_bit+0x25/0x2a
[ 41.930075] [<ffffffff82d34ea4>] rpc_execute+0xfe/0x166
[ 41.931034] [<ffffffff82d2b948>] rpc_run_task+0x121/0x12d
[ 41.932008] [<ffffffff81373904>] nfs4_call_sync_sequence+0x55/0x73
[ 41.933095] [<ffffffff8137ae7c>] nfs4_call_sync+0x31/0x33
[ 41.934076] [<ffffffff8137d883>] _nfs4_proc_getattr+0xb6/0xc8
[ 41.935104] [<ffffffff817767f8>] ? dump_stack+0xb3/0xb8
[ 41.936061] [<ffffffff8137d8de>] nfs4_proc_getattr+0x49/0x172
[ 41.937084] [<ffffffff8137d8de>] ? nfs4_proc_getattr+0x49/0x172
[ 41.938128] [<ffffffff8135e904>] ? nfs_alloc_fattr+0x20/0x37
[ 41.939135] [<ffffffff813602e4>] __nfs_revalidate_inode+0x127/0x2eb
[ 41.940244] [<ffffffff8135bb5f>] nfs_do_access+0x3ec/0x46f
[ 41.941232] [<ffffffff82d36756>] ? generic_lookup_cred+0x1a/0x1c
[ 41.942289] [<ffffffff82d3569b>] ? rpcauth_lookupcred+0x61/0x6a
[ 41.943335] [<ffffffff8135bcd9>] nfs_permission+0xbe/0x188
[ 41.944325] [<ffffffff812236e8>] __inode_permission+0x3e/0xa0
[ 41.945351] [<ffffffff81223789>] inode_permission+0x3f/0x41
[ 41.946348] [<ffffffff81225e63>] link_path_walk+0x47/0x478
[ 41.947333] [<ffffffff812263b1>] ? path_init+0x11d/0x2a4
[ 41.948297] [<ffffffff81226acd>] path_openat+0x2ba/0x750
[ 41.949280] [<ffffffff8109b030>] ? kvm_clock_read+0x25/0x2e
[ 41.950274] [<ffffffff812285c9>] do_filp_open+0x4d/0xa3
[ 41.951195] [<ffffffff8110cf3d>] ? sched_clock_cpu+0x15/0xae
[ 41.952229] [<ffffffff82ecf66d>] ? _raw_spin_unlock+0x27/0x31
[ 41.953253] [<ffffffff812341ca>] ? __alloc_fd+0x1b2/0x1c4
[ 41.954184] [<ffffffff81219127>] do_sys_open+0x72/0x102
[ 41.955120] [<ffffffff81219127>] ? do_sys_open+0x72/0x102
[ 41.956103] [<ffffffff812191d5>] SyS_open+0x1e/0x20
[ 41.957004] [<ffffffff82ecff3c>] entry_SYSCALL_64_fastpath+0x1f/0xbd
[ 41.958075] [<ffffffff8111e7e9>] ? trace_hardirqs_off_caller+0x3f/0xab
[ 41.959358] BUG: scheduling while atomic: wrapper/875/0x7fffffff
[ 41.960456] INFO: lockdep is turned off.
[ 41.961248] Modules linked in:
[ 41.961950] CPU: 1 PID: 875 Comm: wrapper Tainted: G W 4.7.0-rc3-00002-g5aaca3e #1
[ 41.963473] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 41.965132] 0000000000000000 ffff88007d2838a8 ffffffff817767c7 ffff88007d3c9100
[ 41.966819] 0000000000000000 ffff88007d2838c0 ffffffff81105441 ffff88009f5d8fc0
[ 41.968549] ffff88007d283920 ffffffff82ecb27d ffff88007d2838f0 00ffffff81121949
[ 41.970276] Call Trace:
[ 41.970824] [<ffffffff817767c7>] dump_stack+0x82/0xb8
[ 41.971744] [<ffffffff81105441>] __schedule_bug+0x61/0x70
[ 41.985444] [<ffffffff82ecb27d>] __schedule+0x6b/0x76f
[ 41.986341] [<ffffffff82d33909>] ? trace_event_raw_event_xs_tcp_data_ready+0xd4/0xd4
[ 41.987717] [<ffffffff82ecba09>] schedule+0x88/0x9d
[ 41.988600] [<ffffffff82d3392d>] rpc_wait_bit_killable+0x24/0xab
[ 41.989626] [<ffffffff82ecbf4b>] __wait_on_bit+0x4c/0x7e
[ 41.990864] [<ffffffff82ecbfef>] out_of_line_wait_on_bit+0x72/0x7d
[ 41.992519] [<ffffffff82d33909>] ? trace_event_raw_event_xs_tcp_data_ready+0xd4/0xd4
[ 41.994727] [<ffffffff81118633>] ? autoremove_wake_function+0x3a/0x3a
[ 41.996442] [<ffffffff82d32f0b>] __rpc_wait_for_completion_task+0x2d/0x2f
[ 41.998271] [<ffffffff81373bd9>] rpc_wait_for_completion_task+0xb/0xd
[ 41.999795] [<ffffffff81374f63>] nfs4_run_open_task+0x108/0x135
[ 42.000860] [<ffffffff8137ec0f>] nfs4_do_open+0x1f5/0x6e7
[ 42.001974] [<ffffffff8137f185>] nfs4_atomic_open+0xe/0x1c
[ 42.002940] [<ffffffff8135caba>] nfs_atomic_open+0x1ce/0x33c
[ 42.003945] [<ffffffff812240a2>] lookup_open+0x2b5/0x4fb
[ 42.004904] [<ffffffff8111de21>] ? update_fast_ctr+0x1e/0x3e
[ 42.005952] [<ffffffff8111de21>] ? update_fast_ctr+0x1e/0x3e
[ 42.006936] [<ffffffff81226bcf>] path_openat+0x3bc/0x750
[ 42.007987] [<ffffffff8109b030>] ? kvm_clock_read+0x25/0x2e
[ 42.008979] [<ffffffff812285c9>] do_filp_open+0x4d/0xa3
[ 42.009894] [<ffffffff8110cf3d>] ? sched_clock_cpu+0x15/0xae
[ 42.010871] [<ffffffff82ecf66d>] ? _raw_spin_unlock+0x27/0x31
[ 42.011840] [<ffffffff812341ca>] ? __alloc_fd+0x1b2/0x1c4
[ 42.012799] [<ffffffff81219127>] do_sys_open+0x72/0x102
[ 42.013709] [<ffffffff81219127>] ? do_sys_open+0x72/0x102
[ 42.014644] [<ffffffff812191d5>] SyS_open+0x1e/0x20
[ 42.015936] [<ffffffff82ecff3c>] entry_SYSCALL_64_fastpath+0x1f/0xbd
[ 42.017596] [<ffffffff8111e7e9>] ? trace_hardirqs_off_caller+0x3f/0xab
[ 42.028359] BUG: scheduling while atomic: wrapper/879/0x00000003
[ 42.029615] INFO: lockdep is turned off.
[ 42.030374] Modules linked in:
[ 42.031067] CPU: 0 PID: 879 Comm: wrapper Tainted: G W 4.7.0-rc3-00002-g5aaca3e #1
[ 42.032615] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 42.034176] 0000000000000000 ffff88007cb8b7d8 ffffffff817767c7 ffff88007ba24dc0
[ 42.035844] 0000000000000000 ffff88007cb8b7f0 ffffffff81105441 ffff88009f3d8fc0
[ 42.037569] ffff88007cb8b850 ffffffff82ecb27d ffff88007cb8b820 00ffffff81121949
[ 42.039241] Call Trace:
[ 42.039794] [<ffffffff817767c7>] dump_stack+0x82/0xb8
[ 42.040724] [<ffffffff81105441>] __schedule_bug+0x61/0x70
[ 42.041691] [<ffffffff82ecb27d>] __schedule+0x6b/0x76f
[ 42.042640] [<ffffffff82d33909>] ? trace_event_raw_event_xs_tcp_data_ready+0xd4/0xd4
[ 42.044086] [<ffffffff82ecba09>] schedule+0x88/0x9d
[ 42.045000] [<ffffffff82d3392d>] rpc_wait_bit_killable+0x24/0xab
[ 42.046054] [<ffffffff82ecbf4b>] __wait_on_bit+0x4c/0x7e
[ 42.047017] [<ffffffff82ecbfef>] out_of_line_wait_on_bit+0x72/0x7d
[ 42.048113] [<ffffffff82d33909>] ? trace_event_raw_event_xs_tcp_data_ready+0xd4/0xd4
[ 42.049574] [<ffffffff81118633>] ? autoremove_wake_function+0x3a/0x3a
[ 42.050681] [<ffffffff82d2b1f3>] ? call_transmit_status+0xa4/0xa4
[ 42.051754] [<ffffffff82d3496f>] __rpc_execute+0x19b/0x41b
[ 42.052766] [<ffffffff81118479>] ? wake_up_bit+0x25/0x2a
[ 42.053726] [<ffffffff82d34ea4>] rpc_execute+0xfe/0x166
FYI, raw QEMU command line is:
qemu-system-x86_64 -enable-kvm -cpu host -kernel /pkg/linux/x86_64-allyesdebian/gcc-6/5aaca3e48a8af4a0dc5f194db9d29bb970dd445e/vmlinuz-4.7.0-rc3-00002-g5aaca3e -append 'root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-lkp-wsx03-2G-9/bisect_boot-1-debian-x86_64-2015-02-07.cgz-x86_64-allyesdebian-5aaca3e48a8af4a0dc5f194db9d29bb970dd445e-20160615-56778-vqa2gx-0.yaml~ ARCH=x86_64 kconfig=x86_64-allyesdebian branch=linux-devel/devel-catchup-201606150345 commit=5aaca3e48a8af4a0dc5f194db9d29bb970dd445e BOOT_IMAGE=/pkg/linux/x86_64-allyesdebian/gcc-6/5aaca3e48a8af4a0dc5f194db9d29bb970dd445e/vmlinuz-4.7.0-rc3-00002-g5aaca3e max_uptime=600 RESULT_ROOT=/result/boot/1/vm-lkp-wsx03-2G/debian-x86_64-2015-02-07.cgz/x86_64-allyesdebian/gcc-6/5aaca3e48a8af4a0dc5f194db9d29bb970dd445e/0 LKP_SERVER=inn earlyprintk=ttyS0,115200 systemd.log_level=err debug apic=debug sysrq_always_enabled rcupdate.rcu_cpu_stall_timeout=100 panic=-1 softlockup_panic=1 nmi_watchdog=panic oops=panic load_ramdisk=2 prompt_ramdisk=0 console=ttyS0,115200 console=tty0 vga=normal rw ip=::::vm-lkp-wsx03-2G-9::dhcp' -initrd /fs/sdc1/initrd-vm-lkp-wsx03-2G-9 -m 2560 -smp 2 -device e1000,netdev=net0 -netdev user,id=net0,hostfwd=tcp::23628-:22 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -drive file=/fs/sdc1/disk0-vm-lkp-wsx03-2G-9,media=disk,if=virtio -drive file=/fs/sdc1/disk1-vm-lkp-wsx03-2G-9,media=disk,if=virtio -pidfile /dev/shm/kboot/pid-vm-lkp-wsx03-2G-9 -serial file:/dev/shm/kboot/serial-vm-lkp-wsx03-2G-9 -daemonize -display none -monitor null
Thanks,
Kernel Test Robot
View attachment "config-4.7.0-rc3-00002-g5aaca3e" of type "text/plain" (153178 bytes)
Download attachment "dmesg.xz" of type "application/octet-stream" (33152 bytes)
Powered by blists - more mailing lists