On Wed 2016-02-24 10:19:41, Sergey Senozhatsky wrote: > > Hello, > > Cc Rob, Frank, Grant > > On (02/24/16 00:53), Sergey Senozhatsky wrote: > [..] > > 284 [ 0.000000] per task-struct memory footprint: 2112 bytes > > 285 [ 0.000000] per task-struct memory footprint: 2112 bytes > > 286 [ 0.000000] ------------------------ > > 287 [ 0.000000] ------------------------ > > 288 [ 0.000000] | Locking API testsuite: > > 289 [ 0.000000] | Locking API testsuite: > > 290 [ 0.000000] ---------------------------------------------------------------------------- > > 291 [ 0.000000] ---------------------------------------------------------------------------- > > 292 [ 0.000000] | spin |wlock |rlock |mutex | wsem | rsem | > > 293 [ 0.000000] | spin |wlock |rlock |mutex | wsem | rsem | > > 294 [ 0.000000] -------------------------------------------------------------------------- > > 295 [ 0.000000] -------------------------------------------------------------------------- > > > > > > looking at your Kernel command line > > > > [ 0.000000] Kernel command line: root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-kbuild-yocto-i386-53/bisect_boot-1-yocto-minimal-i386.cgz-i386-randconfig-h1-02192137-34578dc67f38c02ccbe696e4099967884caa8e15-20160220-72722-vao2m5-0.yaml ARCH=i386 kconfig=i386-randconfig-h1-02192137 branch=linux-next/master commi t=34578dc67f38c02ccbe696e4099967884caa8e15 BOOT_IMAGE=/pkg/linux/i386-randconfig-h1-02192137/gcc-5/34578dc67f38c02ccbe696e4099967884caa8e15/vmlinuz-4.5.0-rc4-00295-g34578dc max_uptime=600 RESULT_ROOT=/result/boot/1/vm-kbuild-yocto-i386/yocto-minimal-i386.cgz/i386-randconfig-h1-02192137/gcc-5/34578dc67f38c02ccbe69 6e4099967884caa8e15/9 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-yo cto-i386-53::dhcp drbd.minor_count=8 > > > > > > - earlyprintk=ttyS0,115200 > > - console=ttyS0,115200 > > - console=tty0 > > > > and I see "bootconsole [earlyser0] enabled" but no "bootconsole [earlyser0] disabled" message, which > > I'd expect to see... > > > > > and you get the NMI watchdog softlockup because you have a whole bunch of > > "of_overlay_destroy: Could not find overlay #6" > "### dt-test ### of_unittest_destroy_tracked_overlays: overlay destroy failed for #6" > > messages to print. seems that somehitng just pushes them in a loop. > there are too many of them: This sounds like a reasonable explanation. It seems that of_unittest_destroy_tracked_overlays() really ended in an infinite loop. But I am still curious why the softlookup points to [ 33.497718] EIP is at vprintk_emit+0x1ea/0x600 Also there is on the stack [ 33.497741] [<c068e712>] vprintk_default+0x32/0x40 [ 33.497741] [<c068e712>] vprintk_default+0x32/0x40 [ 33.497744] [<c06fdf6e>] printk+0x11/0x13 [ 33.497744] [<c06fdf6e>] printk+0x11/0x13 [ 33.497748] [<c0df5eec>] of_unittest_overlay+0x8d1/0x900 [ 33.497748] [<c0df5eec>] of_unittest_overlay+0x8d1/0x900 [ 33.497750] [<c0df6b1f>] of_unittest+0xc04/0xc2d [ 33.497750] [<c0df6b1f>] of_unittest+0xc04/0xc2d I would expect that the soft lookup happens in console_unlock() called with IRQs disabled. It seems to me that of_unittest_overlay() is called with IRQs enabled. I want to be sure that the patch in printk() did not introduce a deadlock that is visible only under a high printk load. I guess that the softlookup was not visible before the printk patch was applied. I wonder if the patch made something worse. It was supposed to improve things but... Do I miss something, please? Best Regards, Petr -- To unsubscribe from this list: send the line "unsubscribe devicetree" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
