[<prev] [next>] [thread-next>] [day] [month] [year] [list]
Message-ID: <1434424558.18774.198.camel@intel.com>
Date: Tue, 16 Jun 2015 11:15:58 +0800
From: Huang Ying <ying.huang@...el.com>
To: John Stultz <john.stultz@...aro.org>
Cc: LKML <linux-kernel@...r.kernel.org>, LKP ML <lkp@...org>,
Huang Ying <ying.huang@...el.com>
Subject: [lkp] [time] 78a0b9a793a: INFO: possible recursive locking detected
]
FYI, we noticed the below changes on
https://git.linaro.org/people/john.stultz/linux.git wip
commit 78a0b9a793a36f73a9a3330dec00859e15d9ad6d ("time: Do leapsecond adjustment in gettime fastpaths")
+------------------------------------------+------------+------------+
| | 4ae9e1e25d | 78a0b9a793 |
+------------------------------------------+------------+------------+
| boot_successes | 900 | 263 |
| boot_failures | 0 | 37 |
| INFO:possible_recursive_locking_detected | 0 | 37 |
| BUG:spinlock_lockup_suspected_on_CPU | 0 | 15 |
| EIP_is_at_native_apic_mem_write | 0 | 15 |
| EIP_is_at_read_seqcount_begin | 0 | 15 |
| backtrace:SYSC_adjtimex | 0 | 32 |
| backtrace:SyS_adjtimex | 0 | 32 |
| backtrace:vfs_write | 0 | 7 |
| backtrace:SyS_write | 0 | 7 |
| BUG:kernel_test_hang | 0 | 22 |
| backtrace:SYSC_clock_adjtime | 0 | 5 |
| backtrace:SyS_clock_adjtime | 0 | 5 |
| backtrace:lru_add_drain_all | 0 | 1 |
| backtrace:SyS_mlock | 0 | 2 |
| backtrace:do_group_exit | 0 | 1 |
| backtrace:SyS_exit_group | 0 | 1 |
| backtrace:cpu_startup_entry | 0 | 3 |
| backtrace:__mm_populate | 0 | 1 |
| backtrace:link_path_walk | 0 | 1 |
| backtrace:path_init | 0 | 1 |
| backtrace:do_sys_open | 0 | 1 |
| backtrace:SyS_open | 0 | 1 |
+------------------------------------------+------------+------------+
[ 23.011400] VFS: Warning: trinity-c1 using old stat() call. Recompile your binary.
[ 23.012387]
[ 23.012580] =============================================
[ 23.013218] [ INFO: possible recursive locking detected ]
[ 23.013841] 4.1.0-rc5-01505-gd6201b6 #2 Not tainted
[ 23.014419] ---------------------------------------------
[ 23.015051] trinity-c1/22948 is trying to acquire lock:
[ 23.015657] (tk_core){----..}, at: [<4107d71c>] timekeeping_get_ns+0x10/0xe8
[ 23.016564]
[ 23.016564] but task is already holding lock:
[ 23.017241] (tk_core){----..}, at: [<4107f150>] do_adjtimex+0x58/0xc2
[ 23.017380]
[ 23.017380] other info that might help us debug this:
[ 23.017380] Possible unsafe locking scenario:
[ 23.017380]
[ 23.017380] CPU0
[ 23.017380] ----
[ 23.017380] lock(tk_core);
[ 23.017380] lock(tk_core);
[ 23.017380]
[ 23.017380] *** DEADLOCK ***
[ 23.017380]
[ 23.017380] May be due to missing lock nesting notation
[ 23.017380]
[ 23.017380] 2 locks held by trinity-c1/22948:
[ 23.017380] #0: (timekeeper_lock){-.-...}, at: [<4107f144>] do_adjtimex+0x4c/0xc2
[ 23.017380] #1: (tk_core){----..}, at: [<4107f150>] do_adjtimex+0x58/0xc2
[ 23.017380]
[ 23.017380] stack backtrace:
[ 23.017380] CPU: 1 PID: 22948 Comm: trinity-c1 Not tainted 4.1.0-rc5-01505-gd6201b6 #2
[ 23.017380] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
[ 23.017380] 00000000 00000000 50211ddc 413ce68a 41c6a910 50211e50 410646c2 41551379
[ 23.017380] 41551d81 4155126c 00000000 4fc09210 41c6a910 00001f02 00000000 7803e01f
[ 23.017380] 00000000 4fc09210 00000000 00000002 4fc09238 4fc08d40 41c506f0 4fc09208
[ 23.017380] Call Trace:
[ 23.017380] [<413ce68a>] dump_stack+0x49/0x73
[ 23.017380] [<410646c2>] __lock_acquire+0xb78/0xcd3
[ 23.017380] [<4106414b>] ? __lock_acquire+0x601/0xcd3
[ 23.017380] [<41064ad9>] lock_acquire+0x5b/0x7d
[ 23.017380] [<4107d71c>] ? timekeeping_get_ns+0x10/0xe8
[ 23.017380] [<4107d5f1>] read_seqcount_begin+0x2e/0x74
[ 23.017380] [<4107d71c>] ? timekeeping_get_ns+0x10/0xe8
[ 23.017380] [<4107d71c>] timekeeping_get_ns+0x10/0xe8
[ 23.017380] [<4107f150>] ? do_adjtimex+0x58/0xc2
[ 23.017380] [<4107dabf>] __getnstimeofday64_preleap+0x29/0x5d
[ 23.017380] [<4107f158>] do_adjtimex+0x60/0xc2
[ 23.017380] [<4107aa8e>] posix_clock_realtime_adj+0xa/0xc
[ 23.017380] [<4107af8a>] SYSC_clock_adjtime+0x60/0x92
[ 23.017380] [<4107b732>] SyS_clock_adjtime+0xe/0x10
[ 23.017380] [<413d3aab>] syscall_call+0x7/0x7
[ 23.017380] [<413d0000>] ? do_wait_for_common+0x69/0xe4
[ 23.015623] BUG: spinlock lockup suspected on CPU#0, trinity-c0/22947
[ 23.015623] lock: timekeeper_lock+0x0/0x40, .magic: dead4ead, .owner: trinity-c1/22948, .owner_cpu: 1
[ 23.015623] CPU: 0 PID: 22947 Comm: trinity-c0 Not tainted 4.1.0-rc5-01505-gd6201b6 #2
[ 23.015623] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
[ 23.015623] 00000000 00000000 501f1d54 413ce68a 4fc09040 501f1d80 410674b5 41552af6
[ 23.015623] 416204c0 dead4ead 4fc09040 000059a4 00000001 416204c0 a08baba0 00000000
[ 23.015623] 501f1dac 4106760a a08baba0 00000000 4162cecd 416204c0 416204d0 501f1dc0
[ 23.015623] Call Trace:
[ 23.015623] [<413ce68a>] dump_stack+0x49/0x73
[ 23.015623] [<410674b5>] spin_dump+0x7b/0x86
[ 23.015623] [<4106760a>] do_raw_spin_lock+0xda/0x121
[ 23.015623] [<413d2fd9>] _raw_spin_lock_irqsave+0x54/0x68
[ 23.015623] [<4107e884>] update_wall_time+0x13/0x70f
[ 23.015623] [<41064eb5>] ? lock_release+0x173/0x18a
[ 23.015623] [<41082df4>] tick_periodic+0x7a/0x99
[ 23.015623] [<41082f1e>] ? tick_handle_periodic+0x1c/0x5b
[ 23.015623] [<41082f1e>] tick_handle_periodic+0x1c/0x5b
[ 23.015623] [<41021ff0>] local_apic_timer_interrupt+0x40/0x45
[ 23.015623] [<41022519>] smp_apic_timer_interrupt+0x20/0x2f
[ 23.015623] [<413d448f>] apic_timer_interrupt+0x2f/0x34
[ 23.015623] [<4107d630>] ? read_seqcount_begin+0x6d/0x74
[ 23.015623] [<4107d642>] current_kernel_time+0xb/0x3f
[ 23.015623] [<410789b7>] current_fs_time+0xb/0x19
[ 23.015623] [<410ee0c7>] file_update_time+0x20/0x9b
[ 23.015623] [<410a6c22>] __generic_file_write_iter+0x4b/0x15f
[ 23.015623] [<410a6d7a>] generic_file_write_iter+0x44/0xc5
[ 23.015623] [<410db739>] __vfs_write+0x66/0x8f
[ 23.015623] [<410dbf25>] vfs_write+0x74/0x93
[ 23.015623] [<410dc3f6>] SyS_write+0x4a/0x77
[ 23.015623] [<413d3aab>] syscall_call+0x7/0x7
[ 23.015623] [<413d0000>] ? do_wait_for_common+0x69/0xe4
[ 23.015623] sending NMI to all CPUs:
[ 23.015623] NMI backtrace for cpu 0
[ 23.015623] CPU: 0 PID: 22947 Comm: trinity-c0 Not tainted 4.1.0-rc5-01505-gd6201b6 #2
[ 23.015623] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
[ 23.015623] task: 4fc0dcc0 ti: 501f0000 task.ti: 501f0000
[ 23.015623] EIP: 0060:[<410230d6>] EFLAGS: 00000046 CPU: 0
[ 23.015623] EIP is at native_apic_mem_write+0x12/0x14
[ 23.015623] EAX: ffffb300 EBX: 00000c00 ECX: fffff000 EDX: 00000c00
[ 23.015623] ESI: 00000002 EDI: 03000000 EBP: 501f1d34 ESP: 501f1d34
[ 23.015623] DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
[ 23.015623] CR0: 8005003b CR2: 080d3000 CR3: 1016c000 CR4: 00000690
[ 23.015623] Stack:
[ 23.015623] 501f1d48 41023152 00000006 00000003 00000002 501f1d5c 41023408 416e0880
[ 23.015623] 00000001 00000000 501f1d80 41023ead 4154a50e 415701d3 000059a4 00000001
[ 23.015623] 416204c0 a08baba0 00000000 501f1dac 41067614 a08baba0 00000000 4162cecd
[ 23.015623] Call Trace:
[ 23.015623] [<41023152>] __default_send_IPI_dest_field+0x49/0x4e
[ 23.015623] [<41023408>] default_send_IPI_mask_logical+0x4c/0x70
[ 23.015623] [<41023ead>] arch_trigger_all_cpu_backtrace+0xdf/0x1c5
[ 23.015623] [<41067614>] do_raw_spin_lock+0xe4/0x121
[ 23.015623] [<413d2fd9>] _raw_spin_lock_irqsave+0x54/0x68
[ 23.015623] [<4107e884>] update_wall_time+0x13/0x70f
[ 23.015623] [<41064eb5>] ? lock_release+0x173/0x18a
[ 23.015623] [<41082df4>] tick_periodic+0x7a/0x99
[ 23.015623] [<41082f1e>] ? tick_handle_periodic+0x1c/0x5b
[ 23.015623] [<41082f1e>] tick_handle_periodic+0x1c/0x5b
[ 23.015623] [<41021ff0>] local_apic_timer_interrupt+0x40/0x45
[ 23.015623] [<41022519>] smp_apic_timer_interrupt+0x20/0x2f
[ 23.015623] [<413d448f>] apic_timer_interrupt+0x2f/0x34
[ 23.015623] [<4107d630>] ? read_seqcount_begin+0x6d/0x74
[ 23.015623] [<4107d642>] current_kernel_time+0xb/0x3f
[ 23.015623] [<410789b7>] current_fs_time+0xb/0x19
[ 23.015623] [<410ee0c7>] file_update_time+0x20/0x9b
[ 23.015623] [<410a6c22>] __generic_file_write_iter+0x4b/0x15f
[ 23.015623] [<410a6d7a>] generic_file_write_iter+0x44/0xc5
[ 23.015623] [<410db739>] __vfs_write+0x66/0x8f
[ 23.015623] [<410dbf25>] vfs_write+0x74/0x93
[ 23.015623] [<410dc3f6>] SyS_write+0x4a/0x77
[ 23.015623] [<413d3aab>] syscall_call+0x7/0x7
[ 23.015623] [<413d0000>] ? do_wait_for_common+0x69/0xe4
[ 23.015623] Code: 00 5d c3 55 89 e5 50 9d 8d 74 26 00 5d c3 55 89 e5 fa 90 8d 74 26 00 5d c3 8b 0d 38 8c 61 41 55 89 e5 8d 84 08 00 c0 ff ff 89 10 <5d> c3 55 8d 48 01 89 e5 53 89 d3 89 d8 ba 08 00 00 00 e8 c7 dd
[ 23.015623] NMI backtrace for cpu 1
[ 23.015623] CPU: 1 PID: 22948 Comm: trinity-c1 Not tainted 4.1.0-rc5-01505-gd6201b6 #2
[ 23.015623] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.7.5-20140531_083030-gandalf 04/01/2014
[ 23.015623] task: 4fc08d40 ti: 50210000 task.ti: 50210000
[ 23.015623] EIP: 0060:[<4107d630>] EFLAGS: 00000002 CPU: 1
[ 23.015623] EIP is at read_seqcount_begin+0x6d/0x74
[ 23.015623] EAX: 0000112d EBX: 00000012 ECX: 00000046 EDX: 00000001
[ 23.015623] ESI: 4200b600 EDI: 00000246 EBP: 50211e9c ESP: 50211e98
[ 23.015623] DS: 007b ES: 007b FS: 00d8 GS: 0033 SS: 0068
[ 23.015623] CR0: 8005003b CR2: 37560fff CR3: 0ff45000 CR4: 00000690
[ 23.015623] Stack:
[ 23.015623] 4200c35c 50211ecc 4107d71c 00000001 00000001 00000000 4107f150 00000000
[ 23.015623] 00000000 50211f18 50211eec 4200b600 00000246 50211ee0 4107dabf 50211f18
[ 23.015623] 4200b600 00000246 50211f04 4107f158 00000080 00000000 00000000 00000000
[ 23.015623] Call Trace:
[ 23.015623] [<4107d71c>] timekeeping_get_ns+0x10/0xe8
[ 23.015623] [<4107f150>] ? do_adjtimex+0x58/0xc2
[ 23.015623] [<4107dabf>] __getnstimeofday64_preleap+0x29/0x5d
[ 23.015623] [<4107f158>] do_adjtimex+0x60/0xc2
[ 23.015623] [<4107aa8e>] posix_clock_realtime_adj+0xa/0xc
[ 23.015623] [<4107af8a>] SYSC_clock_adjtime+0x60/0x92
[ 23.015623] [<4107b732>] SyS_clock_adjtime+0xe/0x10
[ 23.015623] [<413d3aab>] syscall_call+0x7/0x7
[ 23.015623] [<413d0000>] ? do_wait_for_common+0x69/0xe4
[ 23.015623] Code: 10 f6 c7 02 75 0e 89 d8 e8 0c f9 ff ff e8 ee 42 fe ff eb 0c e8 d4 62 fe ff 89 d8 e8 f9 f8 ff ff a1 40 c3 00 42 a8 01 74 04 f3 90 <eb> f3 8b 5d fc c9 c3 55 89 e5 57 56 53 e8 81 ff ff ff 8b 1d bc
Elapsed time: 220
qemu-system-i386 -enable-kvm -kernel /pkg/linux/i386-randconfig-ib1-05310241/gcc-4.9/d6201b60b90be3c9c344f2387073dbfb84a08d31/vmlinuz-4.1.0-rc5-01505-gd6201b6 -append 'root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-kbuild-yocto-i386-58/rand_boot-1-yocto-minimal-i386.cgz-i386-randconfig-ib1-05310241-d6201b60b90be3c9c344f2387073dbfb84a08d31-1-20150531-98583-1ppz9ur.yaml ARCH=i386 kconfig=i386-randconfig-ib1-05310241 branch=linux-devel/devel-hourly-2015053102 commit=d6201b60b90be3c9c344f2387073dbfb84a08d31 BOOT_IMAGE=/pkg/linux/i386-randconfig-ib1-05310241/gcc-4.9/d6201b60b90be3c9c344f2387073dbfb84a08d31/vmlinuz-4.1.0-rc5-01505-gd6201b6 max_uptime=600 RESULT_ROOT=/result/boot/1/vm-kbuild-yocto-i386/yocto-minimal-i386.cgz/i386-randconfig-ib1-05310241/gcc-4.9/d6201b60b90be3c9c344f2387073dbfb84a08d31/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-kbuild-yocto-i386-58::dhcp drbd.minor_count=8' -initrd /fs/sda1/initrd-vm-kbuild-yocto-i386-58 -m 320 -smp 2 -device e1000,netdev=net0 -netdev user,id=net0 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime -drive file=/fs/sda1/disk0-vm-kbuild-yocto-i386-58,media=disk,if=virtio -pidfile /dev/shm/kboot/pid-vm-kbuild-yocto-i386-58 -serial file:/dev/shm/kboot/serial-vm-kbuild-yocto-i386-58 -daemonize -display none -monitor null
Thanks,
Ying Huang
-------------------------------------
lkp@...ists.intel.com
https://eclists.intel.com/sympa/info/lkp
Unsubscribe by sending email to sympa@...ists.intel.com with subject "Unsubscribe lkp"
View attachment "config-4.1.0-rc4-00015-g78a0b9a" of type "text/plain" (78041 bytes)
View attachment ".dmesg" of type "text/plain" (88612 bytes)
Powered by blists - more mailing lists