| 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
| ||
|
Message-ID: <20180704064347.GP15716@yexl-desktop>
Date: Wed, 4 Jul 2018 14:43:47 +0800
From: kernel test robot <xiaolong.ye@...el.com>
To: "Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>
Cc: linux-kernel@...r.kernel.org, mingo@...nel.org,
jiangshanlai@...il.com, dipankar@...ibm.com,
akpm@...ux-foundation.org, mathieu.desnoyers@...icios.com,
josh@...htriplett.org, tglx@...utronix.de, peterz@...radead.org,
rostedt@...dmis.org, dhowells@...hat.com, edumazet@...gle.com,
fweisbec@...il.com, oleg@...hat.com, joel@...lfernandes.org,
"Paul E. McKenney" <paulmck@...ux.vnet.ibm.com>, lkp@...org
Subject: [lkp-robot] [rcu] e46874dd99: WARNING:suspicious_RCU_usage
FYI, we noticed the following commit (built with gcc-7):
commit: e46874dd99fa8ef78802bee8e80fe2844ae95cd1 ("[PATCH RFC tip/core/rcu 1/2] rcu: Defer reporting RCU-preempt quiescent states when disabled")
url: https://github.com/0day-ci/linux/commits/Paul-E-McKenney/RCU-consolidation-patches/20180628-045310
base: https://git.kernel.org/cgit/linux/kernel/git/paulmck/linux-rcu.git rcu/next
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu Haswell,+smep,+smap -smp 2 -m 512M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+----------------------------------------------------------------------+------------+------------+
| | bd917f682b | e46874dd99 |
+----------------------------------------------------------------------+------------+------------+
| boot_successes | 208 | 112 |
| boot_failures | 2 | 95 |
| invoked_oom-killer:gfp_mask=0x | 2 | 2 |
| Mem-Info | 2 | 2 |
| WARNING:suspicious_RCU_usage | 0 | 93 |
| include/linux/rcupdate.h:#rcu_read_lock()used_illegally_while_idle | 0 | 93 |
| WARNING:possible_circular_locking_dependency_detected | 0 | 89 |
| include/linux/cgroup.h:#suspicious_rcu_dereference_check()usage | 0 | 1 |
| include/linux/rcupdate.h:#rcu_read_unlock()used_illegally_while_idle | 0 | 4 |
| BUG:kernel_hang_in_test_stage | 0 | 1 |
| WARNING:possible_recursive_locking_detected | 0 | 1 |
+----------------------------------------------------------------------+------------+------------+
[ 112.105779] WARNING: suspicious RCU usage
[ 112.112065] 4.18.0-rc1-00121-ge46874d #1 Not tainted
[ 112.119508] -----------------------------
[ 112.125574] include/linux/rcupdate.h:631 rcu_read_lock() used illegally while idle!
[ 112.139965]
[ 112.139965] other info that might help us debug this:
[ 112.139965]
[ 112.152087]
[ 112.152087] RCU used illegally from idle CPU!
[ 112.152087] rcu_scheduler_active = 2, debug_locks = 0
[ 112.168258] RCU used illegally from extended quiescent state!
[ 112.177070] 3 locks held by grep/3278:
[ 112.182897] #0: (____ptrval____) (&rsp->gp_wq){..-.}, at: swake_up+0x16/0x46
[ 112.193916] #1: (____ptrval____) (&p->pi_lock){-.-.}, at: try_to_wake_up+0x42/0x56f
[ 112.205522] #2: (____ptrval____) (rcu_read_lock){....}, at: select_task_rq_rt+0x22/0x20c
[ 112.218160]
[ 112.218160] stack backtrace:
[ 112.224902] CPU: 0 PID: 3278 Comm: grep Not tainted 4.18.0-rc1-00121-ge46874d #1
[ 112.236302] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 112.248488] Call Trace:
[ 112.252248] dump_stack+0xfa/0x16c
[ 112.257374] lockdep_rcu_suspicious+0x166/0x176
[ 112.264109] select_task_rq_rt+0xd5/0x20c
[ 112.270034] try_to_wake_up+0x257/0x56f
[ 112.275647] wake_up_process+0x17/0x20
[ 112.281349] swake_up_locked+0x2d/0x67
[ 112.286922] swake_up+0x28/0x46
[ 112.291591] rcu_gp_kthread_wake+0x52/0x5b
[ 112.297615] rcu_report_qs_rsp+0xaa/0xb6
[ 112.303417] rcu_preempt_deferred_qs_irqrestore+0x47a/0x5eb
[ 112.311584] rcu_preempt_deferred_qs+0x5e/0x6a
[ 112.318165] rcu_eqs_enter+0x14a/0x156
[ 112.325255] rcu_user_enter+0x8e/0x97
[ 112.330797] __context_tracking_enter+0x92/0xb1
[ 112.337376] prepare_exit_to_usermode+0x149/0x155
[ 112.344317] ? async_page_fault+0x5/0x20
[ 112.350209] retint_user+0x8/0x18
[ 112.355102] RIP: 0033:0x7f2062ad8dc0
[ 112.360389] Code: 00 00 e8 d3 e3 f8 ff 48 8d 0d bc ec 0d 00 48 8d 35 45 c4 0d 00 48 8d 3d 25 87 0d 00 ba e2 00 00 00 e8 b4 e3 f8 ff 0f 1f 40 00 <41> 57 31 c0 41 56 41 55 41 54 55 89 fd 53 48 83 ec 18 83 fe 01 0f
[ 112.387996] RSP: 002b:00007ffe5cc3a488 EFLAGS: 00010246
[ 112.395645] RAX: 0000000000000001 RBX: 0000000000000004 RCX: 00007f206321c040
[ 112.405946] RDX: 00007ffe5cc3a550 RSI: 000000000000000d RDI: 00000000000000bc
[ 112.416289] RBP: 00007ffe5cc3a528 R08: 0000000000007fff R09: 000000000000000e
[ 112.426561] R10: 00007ffe5cc3a260 R11: 00007ffe5cc3a3e0 R12: 00007f2062dea730
[ 112.437191] R13: 00007ffe5cc3a550 R14: 00007f2062dea730 R15: 0000000000000000
[ 112.447785]
[ 112.447791] ======================================================
[ 112.447815] WARNING: possible circular locking dependency detected
[ 112.447818] 4.18.0-rc1-00121-ge46874d #1 Not tainted
[ 112.447821] ------------------------------------------------------
[ 112.447824] grep/3278 is trying to acquire lock:
[ 112.447847] (____ptrval____) ((console_sem).lock){-.-.}, at: down_trylock+0x16/0x4e
[ 112.447856]
[ 112.447880] but task is already holding lock:
[ 112.447882] (____ptrval____) (&p->pi_lock){-.-.}, at: try_to_wake_up+0x42/0x56f
[ 112.447911]
[ 112.447914] which lock already depends on the new lock.
[ 112.447915]
[ 112.447917]
[ 112.447920] the existing dependency chain (in reverse order) is:
[ 112.447921]
[ 112.447944] -> #1 (&p->pi_lock){-.-.}:
[ 112.447953] __lock_acquire+0x957/0xa47
[ 112.447976] lock_acquire+0xaf/0xe4
[ 112.447978] _raw_spin_lock_irqsave+0x6c/0x8e
[ 112.447981] try_to_wake_up+0x42/0x56f
[ 112.447983] wake_up_process+0x17/0x20
[ 112.447986] __up+0x58/0x62
[ 112.448009] up+0x42/0x60
[ 112.448011] __up_console_sem+0x6a/0xc9
[ 112.448014] console_unlock+0x663/0x72f
[ 112.448016] vprintk_emit+0x5cd/0x621
[ 112.448019] vprintk_default+0x1f/0x28
[ 112.448042] vprintk_func+0xbf/0xc8
[ 112.448044] printk+0x54/0x77
[ 112.448047] _warn_unseeded_randomness+0x7a/0x87
[ 112.448049] get_random_u64+0x81/0x17d
[ 112.448073] load_elf_binary+0x495/0x12f7
[ 112.448075] search_binary_handler+0xc8/0x246
[ 112.448078] __do_execve_file+0x97b/0xbb7
[ 112.448081] do_execveat_common+0x16/0x1f
[ 112.448083] do_execve+0x25/0x2e
[ 112.448106] __x64_sys_execve+0x3b/0x50
[ 112.448109] do_syscall_64+0x294/0x4fb
[ 112.448112] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 112.448113]
[ 112.448115] -> #0 ((console_sem).lock){-.-.}:
[ 112.448145] validate_chain+0xea2/0x1096
[ 112.448147] __lock_acquire+0x957/0xa47
[ 112.448170] lock_acquire+0xaf/0xe4
[ 112.448173] _raw_spin_lock_irqsave+0x6c/0x8e
[ 112.448175] down_trylock+0x16/0x4e
[ 112.448178] __down_trylock_console_sem+0x56/0xff
[ 112.448180] console_trylock+0x1c/0x7c
[ 112.448204] vprintk_emit+0x3a9/0x621
[ 112.448206] vprintk_default+0x1f/0x28
[ 112.448209] vprintk_func+0xbf/0xc8
[ 112.448211] printk+0x54/0x77
[ 112.448213] lockdep_rcu_suspicious+0x30/0x176
[ 112.448237] select_task_rq_rt+0xd5/0x20c
[ 112.448239] try_to_wake_up+0x257/0x56f
[ 112.448241] wake_up_process+0x17/0x20
[ 112.448244] swake_up_locked+0x2d/0x67
[ 112.448267] swake_up+0x28/0x46
[ 112.448269] rcu_gp_kthread_wake+0x52/0x5b
[ 112.448272] rcu_report_qs_rsp+0xaa/0xb6
[ 112.448275] rcu_preempt_deferred_qs_irqrestore+0x47a/0x5eb
[ 112.448277] rcu_preempt_deferred_qs+0x5e/0x6a
[ 112.448301] rcu_eqs_enter+0x14a/0x156
[ 112.448304] rcu_user_enter+0x8e/0x97
[ 112.448307] __context_tracking_enter+0x92/0xb1
[ 112.448309] prepare_exit_to_usermode+0x149/0x155
[ 112.448332] retint_user+0x8/0x18
[ 112.448334]
[ 112.448336] other info that might help us debug this:
[ 112.448338]
[ 112.448340] Possible unsafe locking scenario:
[ 112.448341]
[ 112.448365] CPU0 CPU1
[ 112.448367] ---- ----
[ 112.448369] lock(&p->pi_lock);
[ 112.448374] lock((console_sem).lock);
[ 112.448401] lock(&p->pi_lock);
[ 112.448406] lock((console_sem).lock);
[ 112.448432]
[ 112.448434] *** DEADLOCK ***
[ 112.448435]
[ 112.448437] 3 locks held by grep/3278:
[ 112.448439] #0: (____ptrval____) (&rsp->gp_wq){..-.}, at: swake_up+0x16/0x46
[ 112.448470] #1: (____ptrval____) (&p->pi_lock){-.-.}, at: try_to_wake_up+0x42/0x56f
[ 112.448501] #2: (____ptrval____) (rcu_read_lock){....}, at: select_task_rq_rt+0x22/0x20c
[ 112.448532]
[ 112.448534] stack backtrace:
[ 112.448559] CPU: 0 PID: 3278 Comm: grep Not tainted 4.18.0-rc1-00121-ge46874d #1
[ 112.448562] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 112.448564] Call Trace:
[ 112.448567] dump_stack+0xfa/0x16c
[ 112.448569] print_circular_bug+0x40d/0x422
[ 112.448593] check_prev_add+0x1c1/0x94a
[ 112.448595] validate_chain+0xea2/0x1096
[ 112.448598] ? validate_chain+0xea2/0x1096
[ 112.448601] __lock_acquire+0x957/0xa47
[ 112.448624] lock_acquire+0xaf/0xe4
[ 112.448626] ? down_trylock+0x16/0x4e
[ 112.448628] ? vprintk_emit+0x3a9/0x621
[ 112.448631] _raw_spin_lock_irqsave+0x6c/0x8e
[ 112.448633] ? down_trylock+0x16/0x4e
[ 112.448656] down_trylock+0x16/0x4e
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Xiaolong
View attachment "config-4.18.0-rc1-00121-ge46874d" of type "text/plain" (110286 bytes)
View attachment "job-script" of type "text/plain" (4133 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (17236 bytes)
Powered by blists - more mailing lists