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 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@eclists.intel.com https://eclists.intel.com/sympa/info/lkp Unsubscribe by sending email to sympa@eclists.intel.com with subject "Unsubscribe lkp"