2:38 a.m.
FYI, we noticed the below changes on
https://git.kernel.org/pub/scm/linux/kernel/git/geert/renesas-drivers.git
topic/renesas-overlays
commit e9fb34ab2bd1aafaa9da3e3c0511faddb0a7542b ("of: unittest: changeset
helpers")
[ 4.316732] /testcase-data/phandle-tests/consumer-a: arguments longer than property
[ 4.318017]
[ 4.318249] =============================================
[ 4.318979] [ INFO: possible recursive locking detected ]
[ 4.319710] 4.5.0-00021-ge9fb34a #1 Not tainted
[ 4.320327] ---------------------------------------------
[ 4.321052] swapper/1 is trying to acquire lock:
[ 4.321682] (of_mutex){+.+.+.}, at: [<ffffffff81f4c276>]
of_changeset_apply+0x16/0x40
[ 4.322825]
[ 4.322825] but task is already holding lock:
[ 4.323611] (of_mutex){+.+.+.}, at: [<ffffffff835532d2>]
of_unittest+0x1ddd/0x268f
[ 4.324714]
[ 4.324714] other info that might help us debug this:
[ 4.325598] Possible unsafe locking scenario:
[ 4.325598]
[ 4.326401] CPU0
[ 4.326739] ----
[ 4.327086] lock(of_mutex);
[ 4.327528] lock(of_mutex);
[ 4.327969]
[ 4.327969] *** DEADLOCK ***
[ 4.327969]
[ 4.328770] May be due to missing lock nesting notation
[ 4.328770]
[ 4.331776] 1 lock held by swapper/1:
[ 4.332286] #0: (of_mutex){+.+.+.}, at: [<ffffffff835532d2>]
of_unittest+0x1ddd/0x268f
[ 4.333468]
[ 4.333468] stack backtrace:
[ 4.334065] CPU: 0 PID: 1 Comm: swapper Not tainted 4.5.0-00021-ge9fb34a #1
[ 4.334998] ffff880013450040 ffff880013457b10 ffffffff81781e14 ffff880013457c20
[ 4.336068] ffffffff81103a30 ffff880013457c30 0000000000000046 ffff880013457c40
[ 4.337141] 0000000000000046 ffff88001022f8a0 ffffffff83628346 ffffffff83628343
[ 4.338208] Call Trace:
[ 4.338550] [<ffffffff81781e14>] dump_stack+0x19/0x25
[ 4.339248] [<ffffffff81103a30>] validate_chain+0x1190/0x1970
[ 4.340126] [<ffffffff81109156>] __lock_acquire+0x556/0x1860
[ 4.340899] [<ffffffff81109187>] ? __lock_acquire+0x587/0x1860
[ 4.341702] [<ffffffff81f4c276>] ? of_changeset_apply+0x16/0x40
[ 4.342518] [<ffffffff8110b65a>] lock_acquire+0xaa/0x180
[ 4.343252] [<ffffffff81f4c276>] ? of_changeset_apply+0x16/0x40
[ 4.344116] [<ffffffff820e475e>] mutex_lock_nested+0x6e/0x460
[ 4.344903] [<ffffffff81f4c276>] ? of_changeset_apply+0x16/0x40
[ 4.345718] [<ffffffff835532d2>] ? of_unittest+0x1ddd/0x268f
[ 4.346498] [<ffffffff81f4c5ff>] ? of_changeset_add_property_copy+0x8f/0x100
[ 4.347458] [<ffffffff81f4c276>] of_changeset_apply+0x16/0x40
[ 4.348329] [<ffffffff835532db>] of_unittest+0x1de6/0x268f
[ 4.349092] [<ffffffff811fe816>] ? kfree+0x156/0x290
[ 4.349777] [<ffffffff8110582d>] ? trace_hardirqs_on+0xd/0x10
[ 4.350566] [<ffffffff835514f5>] ? of_unittest_overlay+0x1e6c/0x1e6c
[ 4.351438] [<ffffffff834f77cb>] do_one_initcall+0x136/0x1cb
[ 4.352219] [<ffffffff834f77cb>] ? do_one_initcall+0x136/0x1cb
[ 4.353013] [<ffffffff834f7a91>] kernel_init_freeable+0x231/0x2c7
[ 4.353852] [<ffffffff820d7ec0>] ? rest_init+0x170/0x170
[ 4.354586] [<ffffffff820d7ec9>] kernel_init+0x9/0xd0
[ 4.355288] [<ffffffff820e9e1f>] ret_from_fork+0x3f/0x70
[ 4.356014] [<ffffffff820d7ec0>] ? rest_init+0x170/0x170
[ 4.404482] input: ImExPS/2 Generic Explorer Mouse as
/devices/platform/i8042/serio1/input/input3
[ 61.130268] Writes: Total: 2 Max/Min: 0/0 Fail: 0
[ 121.130263] Writes: Total: 2 Max/Min: 0/0 Fail: 0
[ 181.130266] Writes: Total: 2 Max/Min: 0/0 Fail: 0
[ 240.365270] INFO: task swapper:1 blocked for more than 120 seconds.
[ 240.367221] Not tainted 4.5.0-00021-ge9fb34a #1
[ 240.368051] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[ 240.369327] swapper D ffff880013457cf8 0 1 0 0x00000000
[ 240.370521] ffff880013457cf8 ffff8800105da4c0 ffff880013454000 ffff880013454008
[ 240.371803] ffff880013450040 00000000ffffffff ffffffff81f4c276 ffff880013457d18
[ 240.373087] ffffffff820e2790 ffffffff833bc360 0000000000000246 ffff880013457d28
[ 240.374386] Call Trace:
[ 240.374795] [<ffffffff81f4c276>] ? of_changeset_apply+0x16/0x40
[ 240.375770] [<ffffffff820e2790>] schedule+0x40/0x100
[ 240.376604] [<ffffffff820e285f>] schedule_preempt_disabled+0xf/0x20
[ 240.377634] [<ffffffff820e4878>] mutex_lock_nested+0x188/0x460
[ 240.378621] [<ffffffff81f4c276>] ? of_changeset_apply+0x16/0x40
[ 240.379595] [<ffffffff81f4c5ff>] ? of_changeset_add_property_copy+0x8f/0x100
[ 240.380718] [<ffffffff81f4c276>] of_changeset_apply+0x16/0x40
[ 240.381660] [<ffffffff835532db>] of_unittest+0x1de6/0x268f
[ 240.382570] [<ffffffff811fe816>] ? kfree+0x156/0x290
[ 240.383380] [<ffffffff8110582d>] ? trace_hardirqs_on+0xd/0x10
[ 240.384333] [<ffffffff835514f5>] ? of_unittest_overlay+0x1e6c/0x1e6c
[ 240.385380] [<ffffffff834f77cb>] do_one_initcall+0x136/0x1cb
[ 240.386175] [<ffffffff834f77cb>] ? do_one_initcall+0x136/0x1cb
[ 240.386990] [<ffffffff834f7a91>] kernel_init_freeable+0x231/0x2c7
[ 240.387855] [<ffffffff820d7ec0>] ? rest_init+0x170/0x170
[ 240.388612] [<ffffffff820d7ec9>] kernel_init+0x9/0xd0
[ 240.389339] [<ffffffff820e9e1f>] ret_from_fork+0x3f/0x70
[ 240.390079] [<ffffffff820d7ec0>] ? rest_init+0x170/0x170
[ 240.390826] INFO: lockdep is turned off.
[ 240.391437] Sending NMI to all CPUs:
[ 240.392072] NMI backtrace for cpu 0
[ 240.392605] CPU: 0 PID: 9 Comm: khungtaskd Not tainted 4.5.0-00021-ge9fb34a #1
[ 240.393671] task: ffff880013548240 ti: ffff88001354c000 task.ti: ffff88001354c000
[ 240.394777] RIP: 0010:[<ffffffff8105d492>] [<ffffffff8105d492>]
flat_send_IPI_mask+0x82/0xf0
[ 240.396029] RSP: 0000:ffff88001354fd40 EFLAGS: 00000046
[ 240.396814] RAX: 0000000001000000 RBX: 0000000000000c00 RCX: 0000000000000000
[ 240.397864] RDX: 0000000000000c00 RSI: 0000000000000002 RDI: 0000000000000300
[ 240.398908] RBP: ffff88001354fd68 R08: 0000000000000000 R09: 0000000000000000
[ 240.399956] R10: ffff880013450320 R11: 0000000000000001 R12: 0000000000000282
[ 240.401006] R13: 0000000000000001 R14: 0000000000000002 R15: ffffffff825ec560
[ 240.402081] FS: 0000000000000000(0000) GS:ffffffff82599000(0000)
knlGS:0000000000000000
[ 240.403266] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[ 240.404135] CR2: 0000000000000000 CR3: 0000000002570000 CR4: 00000000000006f0
[ 240.405287] Stack:
[ 240.405617] ffffffff825ec560 ffffffff834f2b20 ffffffff81055de0 ffff8800134501c0
[ 240.406751] 00000000000003ff ffff88001354fd88 ffffffff81055e04 0000000000000001
[ 240.407924] ffffffff82d4f580 ffff88001354fdc8 ffffffff817890d8 0000000000000001
[ 240.409110] Call Trace:
[ 240.409520] [<ffffffff81055de0>] ?
arch_trigger_all_cpu_backtrace_handler+0x20/0x20
[ 240.410749] [<ffffffff81055e04>] nmi_raise_cpu_backtrace+0x24/0x40
[ 240.411753] [<ffffffff817890d8>] nmi_trigger_all_cpu_backtrace+0x208/0x390
[ 240.412858] [<ffffffff81055e34>] arch_trigger_all_cpu_backtrace+0x14/0x20
[ 240.413955] [<ffffffff8115b439>] watchdog+0x389/0x600
[ 240.414781] [<ffffffff8115b12c>] ? watchdog+0x7c/0x600
[ 240.415623] [<ffffffff8115b0b0>] ? hung_task_panic+0x20/0x20
[ 240.416542] [<ffffffff810e5ce0>] kthread+0x130/0x1a0
[ 240.417355] [<ffffffff810e5bb0>] ? __kthread_parkme+0x160/0x160
[ 240.418319] [<ffffffff820e9e1f>] ret_from_fork+0x3f/0x70
[ 240.419173] [<ffffffff810e5bb0>] ? __kthread_parkme+0x160/0x160
[ 240.420131] Code: c3 5f ff 80 e6 10 75 f2 44 89 e8 c1 e0 18 89 04 25 10 c3 5f ff 44 89
f2 09 da 80 cf 04 41 83 fe 02 0f 44 d3 89 14 25 00 c3 5f ff <41> f7 c4 00 02 00 00
74 1a e8 80 83 0a 00 4c 89 e7 57 9d 66 66
[ 240.423052] Kernel panic - not syncing: hung_task: blocked tasks
[ 240.424004] CPU: 0 PID: 9 Comm: khungtaskd Not tainted 4.5.0-00021-ge9fb34a #1
[ 240.425142] ffff880013450040 ffff88001354fd58 ffffffff81781e14 ffff88001354fdd8
[ 240.426383] ffffffff81189382 0000000000000008 ffff88001354fde8 ffff88001354fd80
[ 240.427624] ffff880013450320 0000000000000001 00000000000000c8 000000000000075d
[ 240.428861] Call Trace:
[ 240.429267] [<ffffffff81781e14>] dump_stack+0x19/0x25
[ 240.430089] [<ffffffff81189382>] panic+0xc7/0x2e6
[ 240.430850] [<ffffffff8115b445>] watchdog+0x395/0x600
[ 240.431663] [<ffffffff8115b12c>] ? watchdog+0x7c/0x600
[ 240.432486] [<ffffffff8115b0b0>] ? hung_task_panic+0x20/0x20
[ 240.433395] [<ffffffff810e5ce0>] kthread+0x130/0x1a0
[ 240.434200] [<ffffffff810e5bb0>] ? __kthread_parkme+0x160/0x160
[ 240.435150] [<ffffffff820e9e1f>] ret_from_fork+0x3f/0x70
[ 240.435998] [<ffffffff810e5bb0>] ? __kthread_parkme+0x160/0x160
[ 240.436949] Kernel Offset: disabled
Elapsed time: 250
FYI, raw QEMU command line is:
qemu-system-x86_64 -enable-kvm -cpu Westmere -kernel
/pkg/linux/x86_64-randconfig-v0-03180107/gcc-5/e9fb34ab2bd1aafaa9da3e3c0511faddb0a7542b/vmlinuz-4.5.0-00021-ge9fb34a
-append 'root=/dev/ram0 user=lkp
job=/lkp/scheduled/vm-kbuild-yocto-ia32-27/bisect_boot-1-yocto-minimal-i386.cgz-x86_64-randconfig-v0-03180107-e9fb34ab2bd1aafaa9da3e3c0511faddb0a7542b-20160318-82431-5l5wq9-0.yaml
ARCH=x86_64 kconfig=x86_64-randconfig-v0-03180107
branch=linux-devel/devel-spot-201603180038 commit=e9fb34ab2bd1aafaa9da3e3c0511faddb0a7542b
BOOT_IMAGE=/pkg/linux/x86_64-randconfig-v0-03180107/gcc-5/e9fb34ab2bd1aafaa9da3e3c0511faddb0a7542b/vmlinuz-4.5.0-00021-ge9fb34a
max_uptime=600
RESULT_ROOT=/result/boot/1/vm-kbuild-yocto-ia32/yocto-minimal-i386.cgz/x86_64-randconfig-v0-03180107/gcc-5/e9fb34ab2bd1aafaa9da3e3c0511faddb0a7542b/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-ia32-27::dhcp drbd.minor_count=8'
-initrd /fs/sde1/initrd-vm-kbuild-yocto-ia32-27 -m 320 -smp 1 -device e1000,netdev=net0
-netdev user,id=net0 -boot order=nc -no-reboot -watchdog i6300esb -rtc base=localtime
-drive file=/fs/sde1/disk0-vm-kbuild-yocto-ia32-27,media=disk,if=virtio -pidfile
/dev/shm/kboot/pid-vm-kbuild-yocto-ia32-27 -serial
file:/dev/shm/kboot/serial-vm-kbuild-yocto-ia32-27 -daemonize -display none -monitor null
Thanks,
Kernel Test Robot