| 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: Tue, 19 Jul 2016 10:16:07 +0800
From: kernel test robot <xiaolong.ye@...el.com>
To: Peter Zijlstra <peterz@...radead.org>
Cc: 0day robot <fengguang.wu@...el.com>, Tejun Heo <tj@...nel.org>,
Oleg Nesterov <oleg@...hat.com>,
Paul McKenney <paulmck@...ux.vnet.ibm.com>,
John Stultz <john.stultz@...aro.org>,
Dmitry Shmidt <dimitrysh@...gle.com>,
LKML <linux-kernel@...r.kernel.org>, lkp@...org
Subject: [lkp] [locking/percpu] 1916a96ef1: INFO: task systemd:1 blocked for
more than 300 seconds.
FYI, we noticed the following commit:
https://github.com/0day-ci/linux Peter-Zijlstra/locking-percpu-rwsem-Optimize-readers-and-reduce-global-impact/20160715-142422
commit 1916a96ef19d77b4ff2f83711bb4233dc4d81dbf ("locking/percpu-rwsem: Introduce bias knob")
in testcase: boot
on test machine: 2 threads qemu-system-x86_64 -enable-kvm -cpu kvm64,+ssse3 with 8G memory
caused below changes:
+--------------------------------------------------+------------+------------+
| | b6b154e8c9 | 1916a96ef1 |
+--------------------------------------------------+------------+------------+
| boot_successes | 8 | 2 |
| boot_failures | 0 | 6 |
| INFO:task_blocked_for_more_than#seconds | 0 | 6 |
| RIP:native_write_msr | 0 | 6 |
| Kernel_panic-not_syncing:hung_task:blocked_tasks | 0 | 6 |
| backtrace:do_mount | 0 | 6 |
| backtrace:SyS_mount | 0 | 6 |
| backtrace:watchdog | 0 | 6 |
| RIP:native_safe_halt | 0 | 3 |
| backtrace:cpu_startup_entry | 0 | 4 |
| RIP:debug_lockdep_rcu_enabled | 0 | 1 |
+--------------------------------------------------+------------+------------+
[ 24.354302] systemd[1]: RTC configured in localtime, applying delta of 480 minutes to system time.
[ 24.362086] random: systemd urandom read with 20 bits of entropy available
[ 243.633515] random: nonblocking pool is initialized
[ 602.103247] INFO: task systemd:1 blocked for more than 300 seconds.
[ 602.105410] Not tainted 4.7.0-rc7-00002-g1916a96 #156
[ 602.110993] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 602.129267] systemd D ffff8802549dbb48 12256 1 0 0x00000000
[ 602.142361] ffff8802549dbb48 ffff8802549dbb08 0000000000000246 ffff880256dd9058
[ 602.145548] ffff880256dd9040 ffff8802549cc040 ffff8802549dc000 ffffffff85644608
[ 602.147879] 0000000000000001 0000000000000001 0000000000000001 ffff8802549dbb60
[ 602.150011] Call Trace:
[ 602.150644] [<ffffffff82ed8d19>] schedule+0x88/0x9d
[ 602.151628] [<ffffffff8113cf91>] rcu_sync_enter+0xdd/0x103
[ 602.156757] [<ffffffff81118822>] ? add_wait_queue_exclusive+0x44/0x44
[ 602.171406] [<ffffffff8111e1bf>] percpu_down_write+0x27/0xb6
[ 602.184434] [<ffffffff8111f327>] ? lock_is_held+0x4b/0x54
[ 602.189452] [<ffffffff81168eac>] cgroup_apply_control+0xa7/0x245
[ 602.191384] [<ffffffff8116955e>] rebind_subsystems+0x152/0x36a
[ 602.192860] [<ffffffff8116955e>] ? rebind_subsystems+0x152/0x36a
[ 602.194293] [<ffffffff81169cea>] cgroup_setup_root+0x175/0x27f
[ 602.195486] [<ffffffff8116a20d>] cgroup_mount+0x419/0x54d
[ 602.196640] [<ffffffff81203391>] ? alloc_pages_current+0xb4/0xd8
[ 602.198008] [<ffffffff81228672>] mount_fs+0x67/0x131
[ 602.204398] [<ffffffff812405b1>] vfs_kern_mount+0x6b/0xdb
[ 602.213446] [<ffffffff812430b3>] do_mount+0x8da/0x9e0
[ 602.221800] [<ffffffff812433d9>] SyS_mount+0x77/0x9f
[ 602.229713] [<ffffffff82edd1fc>] entry_SYSCALL_64_fastpath+0x1f/0xbd
[ 602.234219] [<ffffffff8111e949>] ? trace_hardirqs_off_caller+0x3f/0xab
[ 602.236742] 2 locks held by systemd/1:
[ 602.238016] #0: (cgroup_mutex){+.+.+.}, at: [<ffffffff81167fa6>] cgroup_lock_and_drain_offline+0x40/0x144
[ 602.241029] #1: (&cgroup_threadgroup_rwsem){++++.+}, at: [<ffffffff8111e1b7>] percpu_down_write+0x1f/0xb6
[ 602.243425] Sending NMI to all CPUs:
[ 602.246680] NMI backtrace for cpu 1
[ 602.254035] CPU: 1 PID: 21 Comm: khungtaskd Not tainted 4.7.0-rc7-00002-g1916a96 #156
[ 602.271726] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 602.281793] task: ffff8802546e8580 ti: ffff8802546ec000 task.ti: ffff8802546ec000
[ 602.285190] RIP: 0010:[<ffffffff8109b79a>] [<ffffffff8109b79a>] native_write_msr+0x6/0x2b
[ 602.288136] RSP: 0018:ffff8802546efd48 EFLAGS: 00000002
[ 602.290443] RAX: 0000000000000400 RBX: 0000000000000282 RCX: 0000000000000830
[ 602.304995] RDX: 0000000000000001 RSI: 0000000000000400 RDI: 0000000000000830
[ 602.319741] RBP: ffff8802546efd50 R08: fffffffffffffffe R09: 0000000000000003
[ 602.326094] R10: ffffffff85062870 R11: ffffffff855fca27 R12: 0000000000000001
[ 602.329129] R13: 000000000000a1f8 R14: 0000000000000002 R15: 0000000000000001
[ 602.331633] FS: 0000000000000000(0000) GS:ffff880256c00000(0000) knlGS:0000000000000000
[ 602.334517] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 602.346019] CR2: 00007ffec0cccf64 CR3: 00000002409d1000 CR4: 00000000000006e0
[ 602.358397] Stack:
[ 602.363519] ffffffff810949f0 ffff8802546efd60 ffffffff81094bbd ffff8802546efda8
[ 602.371797] ffffffff81094cca ffffffff84436e60 0000000000080000 0000000000000001
[ 602.375113] ffffffff810920d3 0000000000000004 ffff8802549cc3e0 0000000000400000
[ 602.377836] Call Trace:
[ 602.378822] [<ffffffff810949f0>] ? paravirt_write_msr+0xf/0x13
[ 602.382726] [<ffffffff81094bbd>] native_x2apic_icr_write+0x1e/0x20
[ 602.396007] [<ffffffff81094cca>] __x2apic_send_IPI_mask+0xd5/0x109
[ 602.409753] [<ffffffff810920d3>] ? irq_force_complete_move+0xd9/0xd9
[ 602.417086] [<ffffffff81094d62>] x2apic_send_IPI_mask+0x13/0x15
[ 602.419860] [<ffffffff810920ee>] nmi_raise_cpu_backtrace+0x1b/0x1d
[ 602.422123] [<ffffffff8178565d>] nmi_trigger_all_cpu_backtrace+0x8c/0xe3
[ 602.424138] [<ffffffff8109213e>] arch_trigger_all_cpu_backtrace+0x19/0x1b
[ 602.426085] [<ffffffff8117ce21>] watchdog+0x335/0x3ae
[ 602.430698] [<ffffffff8117caec>] ? rcu_read_lock+0x68/0x68
[ 602.442424] [<ffffffff810ff2eb>] kthread+0xc5/0xcd
[ 602.453028] [<ffffffff82edd42f>] ret_from_fork+0x1f/0x40
[ 602.462714] [<ffffffff810ff226>] ? cpumask_check+0x35/0x35
[ 602.465681] Code: 30 02 83 0f 21 c0 eb 1b 0f 21 c8 eb 16 0f 21 d0 eb 11 0f 21 d8 eb 0c 0f 21 f0 eb 07 0f 21 f8 eb 02 0f 0b 5d c3 89 f9 89 f0 0f 30 <8b> 05 a8 9e 38 03 85 c0 7e 1a 55 89 f0 48 89 d6 48 c1 e6 20 89
[ 602.472207] NMI backtrace for cpu 0
[ 602.488350] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.7.0-rc7-00002-g1916a96 #156
[ 602.498821] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 602.508297] task: ffffffff84028540 ti: ffffffff84000000 task.ti: ffffffff84000000
[ 602.510872] RIP: 0010:[<ffffffff8109b36a>] [<ffffffff8109b36a>] native_safe_halt+0x6/0x8
[ 602.513108] RSP: 0018:ffffffff84003ec0 EFLAGS: 00000202
[ 602.514343] RAX: ffffffff84028540 RBX: 0000000000000000 RCX: 0000000000000003
[ 602.515746] RDX: 0000000000000003 RSI: 0000000000000001 RDI: ffffffff84028540
[ 602.517043] RBP: ffffffff84003ec0 R08: 000000a4a3278f55 R09: 0000000000000000
[ 602.518262] R10: ffffffff84003e10 R11: ffff880240ec0980 R12: 0000000000000000
[ 602.523065] R13: ffffffff84000000 R14: ffffffff84000000 R15: ffffffff84004000
[ 602.531947] FS: 0000000000000000(0000) GS:ffff880256a00000(0000) knlGS:0000000000000000
[ 602.542866] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 602.551458] CR2: ffffffff830232a4 CR3: 0000000004021000 CR4: 00000000000006f0
[ 602.556053] Stack:
[ 602.557211] ffffffff84003ed0 ffffffff810794cb ffffffff84003ee0 ffffffff81079ac3
[ 602.559862] ffffffff84003ef0 ffffffff811190a0 ffffffff84003f38 ffffffff81119206
[ 602.562090] ffffffff847432e0 ffffffff84000000 0000000000000002 ffff88025fee1d80
[ 602.564050] Call Trace:
[ 602.566405] [<ffffffff810794cb>] default_idle+0x24/0x37
[ 602.575741] [<ffffffff81079ac3>] arch_cpu_idle+0xf/0x11
[ 602.585235] [<ffffffff811190a0>] default_idle_call+0x28/0x2f
[ 602.595242] [<ffffffff81119206>] cpu_startup_entry+0x15f/0x26e
[ 602.599785] [<ffffffff82ed0cfe>] rest_init+0x135/0x13b
[ 602.601405] [<ffffffff84628f33>] start_kernel+0x411/0x41e
[ 602.602868] [<ffffffff84628120>] ? early_idt_handler_array+0x120/0x120
[ 602.604375] [<ffffffff846282db>] x86_64_start_reservations+0x2f/0x31
[ 602.605703] [<ffffffff84628410>] x86_64_start_kernel+0x133/0x142
[ 602.606885] Code: 48 89 e5 0f 09 5d c3 55 48 89 e5 9c 58 5d c3 55 48 89 e5 57 9d 5d c3 55 48 89 e5 fa 5d c3 55 48 89 e5 fb 5d c3 55 48 89 e5 fb f4 <5d> c3 55 48 89 e5 f4 5d c3 55 49 89 c9 49 89 d0 8b 07 48 89 e5
[ 602.611792] Kernel panic - not syncing: hung_task: blocked tasks
[ 602.625626] CPU: 1 PID: 21 Comm: khungtaskd Not tainted 4.7.0-rc7-00002-g1916a96 #156
[ 602.625629] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 602.625659] 0000000000000000 ffff8802546efd78 ffffffff81781923 ffffffff839f08a0
[ 602.625667] ffff8802546efe08 ffff8802546efdf8 ffffffff811b7df3 0000000000000008
[ 602.625694] ffff8802546efe08 ffff8802546efda0 ffff8802546efdc8 0000000000000000
[ 602.625696] Call Trace:
[ 602.625730] [<ffffffff81781923>] dump_stack+0x82/0xb8
[ 602.625759] [<ffffffff811b7df3>] panic+0xd7/0x228
[ 602.625791] [<ffffffff8117ce2d>] watchdog+0x341/0x3ae
[ 602.625819] [<ffffffff8117caec>] ? rcu_read_lock+0x68/0x68
[ 602.625828] [<ffffffff810ff2eb>] kthread+0xc5/0xcd
[ 602.625861] [<ffffffff82edd42f>] ret_from_fork+0x1f/0x40
[ 602.625888] [<ffffffff810ff226>] ? cpumask_check+0x35/0x35
[ 602.626509] Kernel Offset: disabled
Elapsed time: 630
FYI, raw QEMU command line is:
qemu-system-x86_64 -enable-kvm -cpu kvm64,+ssse3 -kernel /pkg/linux/x86_64-allyesdebian/gcc-6/1916a96ef19d77b4ff2f83711bb4233dc4d81dbf/vmlinuz-4.7.0-rc7-00002-g1916a96 -append 'root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-lkp-wsx03-8G-2/bisect_boot-1-debian-x86_64-2015-02-07.cgz-1916a96ef19d77b4ff2f83711bb4233dc4d81dbf-20160719-28001-2xljr7-0.yaml ARCH=x86_64 kconfig=x86_64-allyesdebian branch=linux-devel/devel-catchup-201607190013 commit=1916a96ef19d77b4ff2f83711bb4233dc4d81dbf BOOT_IMAGE=/pkg/linux/x86_64-allyesdebian/gcc-6/1916a96ef19d77b4ff2f83711bb4233dc4d81dbf/vmlinuz-4.7.0-rc7-00002-g1916a96 max_uptime=600 RESULT_ROOT=/result/boot/1/vm-lkp-wsx03-8G/debian-x86_64-2015-02-07.cgz/x86_64-allyesdebian/gcc-6/1916a96ef19d77b4ff2f83711bb4233dc4d81dbf/0 LKP_SERVER=inn 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 systemd.log_level=err earlyprintk=ttyS0,115200 console=ttyS0,115200 console=tty0 vga=normal rw ip=::::vm-lkp-wsx03-8G-2::dhcp' -initrd /fs/sdc1/initrd-vm-lkp-wsx03-8G-2 -m 8704 -smp 2 -device e1000,netdev=net0 -netdev user,id=net0,hostfwd=tcp::23661-:22 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -drive file=/fs/sdc1/disk0-vm-lkp-wsx03-8G-2,media=disk,if=virtio -pidfile /dev/shm/kboot/pid-vm-lkp-wsx03-8G-2 -serial file:/dev/shm/kboot/serial-vm-lkp-wsx03-8G-2 -daemonize -display none -monitor null
Thanks,
Xiaolong
View attachment "config-4.7.0-rc7-00002-g1916a96" of type "text/plain" (153295 bytes)
Download attachment "dmesg.xz" of type "application/octet-stream" (28480 bytes)
Powered by blists - more mailing lists