FYI, we noticed the below changes on
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
commit 08d78658f393fefaa2e6507ea052c6f8ef4002a2 ("panic: release stale console lock to always get the logbuf printed out")
+------------------------------------------------------------------+------------+------------+
| | 7f8306429c | 08d78658f3 |
+------------------------------------------------------------------+------------+------------+
| boot_successes | 0 | 2 |
| boot_failures | 100 | 86 |
| invoked_oom-killer:gfp_mask=0x | 100 | 86 |
| Mem-Info | 100 | 86 |
| Out_of_memory:Kill_process | 98 | 86 |
| backtrace:vmalloc | 96 | 86 |
| backtrace:init_mtdram | 94 | 84 |
| backtrace:kernel_init_freeable | 100 | 86 |
| Kernel_panic-not_syncing:Out_of_memory_and_no_killable_processes | 80 | 86 |
| backtrace:target_register_template | 1 | |
| backtrace:iscsi_target_init_module | 1 | |
| backtrace:bdi_register | 1 | |
| backtrace:init_mtd | 1 | |
| backtrace:init_nandsim | 2 | 2 |
| backtrace:ns_init_module | 2 | 2 |
| backtrace:do_sys_open | 1 | |
| backtrace:SyS_open | 1 | |
| backtrace:populate_rootfs | 2 | |
| backtrace:vfs_write | 1 | |
| backtrace:SyS_write | 1 | |
| is_trying_to_release_lock(console_lock)at | 0 | 17 |
| backtrace:__pci_register_driver | 0 | 1 |
| backtrace:vr_nor_pci_driver_init | 0 | 1 |
+------------------------------------------------------------------+------------+------------+
The OOM is common between the parent and the child commits, but the "[
BUG: bad unlock balance detected! ]" may be related to the commit.
[ 37.291597] slram: not enough parameters.
[ 37.293324] Ramix PMC551 PCI Mezzanine Ram Driver. (C) 1999,2000 Nortel Networks.
[ 37.297038] pmc551: not detected
[ 37.329718] swapper/0 invoked oom-killer: gfp_mask=0x24002c2, order=0, oom_score_adj=0
[ 37.333699] swapper/0 cpuset=/ mems_allowed=0
[ 37.347987] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.3.0-08150-g08d7865 #1
[ 37.350728] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 37.354583] 0000000000000000 ffff8800132bbb20 ffffffff8173760d ffff8800132bbcc8
[ 37.368842] ffff8800132bbb90 ffffffff811fb624 ffff8800132bbb40 0000000000000206
[ 37.372378] ffff8800132bbb60 ffffffff82e16747 ffffffff84081da0 0000000000000001
[ 37.376098] Call Trace:
[ 37.377672] [<ffffffff8173760d>] dump_stack+0x4b/0x63
[ 37.384640] [<ffffffff811fb624>] dump_header+0x57/0x1f2
[ 37.390090] [<ffffffff82e16747>] ? _raw_spin_unlock_irqrestore+0x4d/0x59
[ 37.392707] [<ffffffff811a89f8>] oom_kill_process+0x8f/0x34b
[ 37.407046] [<ffffffff811a90da>] out_of_memory+0x3d6/0x3f1
[ 37.409493] [<ffffffff811addb5>] __alloc_pages_slowpath+0x62d/0x68d
[ 37.412700] [<ffffffff811adfab>] __alloc_pages_nodemask+0x196/0x2dc
[ 37.415088] [<ffffffff811e5b51>] alloc_page_interleave+0x37/0x7a
[ 37.428457] [<ffffffff811e6193>] alloc_pages_current+0x79/0xe2
[ 37.433083] [<ffffffff811d94fa>] __vmalloc_node_range+0x168/0x22e
[ 37.435373] [<ffffffff8467c85c>] ? init_pmc551+0x5e3/0x5e3
[ 37.437547] [<ffffffff811d95ee>] __vmalloc_node+0x2e/0x30
[ 37.443649] [<ffffffff8467c898>] ? init_mtdram+0x3c/0xc4
[ 37.456796] [<ffffffff811d9776>] vmalloc+0x2a/0x2c
[ 37.467025] [<ffffffff8467c898>] init_mtdram+0x3c/0xc4
[ 37.470180] [<ffffffff8467c85c>] ? init_pmc551+0x5e3/0x5e3
[ 37.472167] [<ffffffff81002174>] do_one_initcall+0xe7/0x173
[ 37.474194] [<ffffffff84606131>] kernel_init_freeable+0x1bf/0x24c
[ 37.476341] [<ffffffff82e0b139>] ? rest_init+0x140/0x140
[ 37.493542] [<ffffffff82e0b147>] kernel_init+0xe/0xd9
[ 37.495623] [<ffffffff82e173df>] ret_from_fork+0x3f/0x70
[ 37.497707] [<ffffffff82e0b139>] ? rest_init+0x140/0x140
[ 37.515849] Mem-Info:
[ 37.517074] active_anon:20 inactive_anon:0 isolated_anon:0
[ 37.517074] active_file:235 inactive_file:0 isolated_file:0
[ 37.517074] unevictable:6975 dirty:0 writeback:0 unstable:0
[ 37.517074] slab_reclaimable:40521 slab_unreclaimable:7389
[ 37.517074] mapped:248 shmem:0 pagetables:7 bounce:0
[ 37.517074] free:695 free_pcp:108 free_cma:0
[ 37.537368] Node 0 DMA free:980kB min:128kB low:160kB high:192kB active_anon:4kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB managed:15908kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:1452kB slab_unreclaimable:9624kB kernel_stack:1056kB pagetables:8kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
[ 37.587076] lowmem_reserve[]: 0 213 213 213
[ 37.589035] Node 0 DMA32 free:1800kB min:1804kB low:2252kB high:2704kB active_anon:76kB inactive_anon:0kB active_file:940kB inactive_file:0kB unevictable:27900kB isolated(anon):0kB isolated(file):0kB present:311168kB managed:218944kB mlocked:0kB dirty:0kB writeback:0kB mapped:992kB shmem:0kB slab_reclaimable:160632kB slab_unreclaimable:19932kB kernel_stack:880kB pagetables:20kB unstable:0kB bounce:0kB free_pcp:432kB local_pcp:144kB free_cma:0kB writeback_tmp:0kB pages_scanned:27928 all_unreclaimable? yes
[ 37.619847] lowmem_reserve[]: 0 0 0 0
[ 37.626611] Node 0 DMA: 1*4kB (U) 2*8kB (UE) 0*16kB 0*32kB 1*64kB (E) 1*128kB (U) 1*256kB (U) 1*512kB (E) 0*1024kB 0*2048kB 0*4096kB = 980kB
[ 37.637092] Node 0 DMA32: 0*4kB 1*8kB (E) 2*16kB (UE) 1*32kB (E) 5*64kB (UME) 5*128kB (UME) 3*256kB (UE) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 1800kB
[ 37.647889] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
[ 37.657973] 7212 total pagecache pages
[ 37.663038] 0 pages in swap cache
[ 37.664748] Swap cache stats: add 0, delete 0, find 0/0
[ 37.670312] Free swap = 0kB
[ 37.671896] Total swap = 0kB
[ 37.676721] 81790 pages RAM
[ 37.679531] 0 pages HighMem/MovableOnly
[ 37.686236] 23077 pages reserved
[ 37.687821] 0 pages hwpoisoned
[ 37.692504] [ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name
[ 37.699413] [ 127] 0 127 1115 222 7 3 0 0 v86d
[ 37.706628] Out of memory: Kill process 127 (v86d) score 3 or sacrifice child
[ 37.727285] Killed process 127 (v86d) total-vm:4460kB, anon-rss:88kB, file-rss:800kB
[ 37.755541] v86d (127) used greatest stack depth: 13520 bytes left
[ 37.758232] swapper/0 invoked oom-killer: gfp_mask=0x24002c2, order=0, oom_score_adj=0
[ 37.758241] swapper/0 cpuset=/ mems_allowed=0
[ 37.758249] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.3.0-08150-g08d7865 #1
[ 37.758252] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 37.758263] 0000000000000000 ffff8800132bbb78 ffffffff8173760d ffff8800132bbcc8
[ 37.758268] ffff8800132bbbe8 ffffffff811fb624 ffffffff811a854c 00000001132bbbc8
[ 37.758275] 0000000000000246 ffff8800132b4850 00000000004d3341 ffff8800132bbcc8
[ 37.758276] Call Trace:
[ 37.758296] [<ffffffff8173760d>] dump_stack+0x4b/0x63
[ 37.758303] [<ffffffff811fb624>] dump_header+0x57/0x1f2
[ 37.758309] [<ffffffff811a854c>] ? rcu_read_unlock+0x5d/0x5f
[ 37.758314] [<ffffffff811a90a9>] out_of_memory+0x3a5/0x3f1
[ 37.758320] [<ffffffff811addb5>] __alloc_pages_slowpath+0x62d/0x68d
[ 37.758326] [<ffffffff811adfab>] __alloc_pages_nodemask+0x196/0x2dc
[ 37.758334] [<ffffffff811e5b51>] alloc_page_interleave+0x37/0x7a
[ 37.758339] [<ffffffff811e6193>] alloc_pages_current+0x79/0xe2
[ 37.758345] [<ffffffff811d94fa>] __vmalloc_node_range+0x168/0x22e
[ 37.758352] [<ffffffff8467c85c>] ? init_pmc551+0x5e3/0x5e3
[ 37.758356] [<ffffffff811d95ee>] __vmalloc_node+0x2e/0x30
[ 37.758359] [<ffffffff8467c898>] ? init_mtdram+0x3c/0xc4
[ 37.758363] [<ffffffff811d9776>] vmalloc+0x2a/0x2c
[ 37.758367] [<ffffffff8467c898>] init_mtdram+0x3c/0xc4
[ 37.758370] [<ffffffff8467c85c>] ? init_pmc551+0x5e3/0x5e3
[ 37.758376] [<ffffffff81002174>] do_one_initcall+0xe7/0x173
[ 37.758383] [<ffffffff84606131>] kernel_init_freeable+0x1bf/0x24c
[ 37.758396] [<ffffffff82e0b139>] ? rest_init+0x140/0x140
[ 37.758400] [<ffffffff82e0b147>] kernel_init+0xe/0xd9
[ 37.758404] [<ffffffff82e173df>] ret_from_fork+0x3f/0x70
[ 37.758408] [<ffffffff82e0b139>] ? rest_init+0x140/0x140
[ 37.758411] Mem-Info:
[ 37.758421] active_anon:10 inactive_anon:0 isolated_anon:0
[ 37.758421] active_file:17 inactive_file:0 isolated_file:0
[ 37.758421] unevictable:7189 dirty:0 writeback:0 unstable:0
[ 37.758421] slab_reclaimable:40528 slab_unreclaimable:7401
[ 37.758421] mapped:1 shmem:0 pagetables:7 bounce:0
[ 37.758421] free:722 free_pcp:115 free_cma:0
[ 37.758435] Node 0 DMA free:980kB min:128kB low:160kB high:192kB active_anon:8kB inactive_anon:0kB active_file:0kB inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB managed:15908kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:1464kB slab_unreclaimable:9644kB kernel_stack:1136kB pagetables:8kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
[ 37.758442] lowmem_reserve[]: 0 213 213 213
[ 37.758455] Node 0 DMA32 free:1908kB min:1804kB low:2252kB high:2704kB active_anon:32kB inactive_anon:0kB active_file:68kB inactive_file:0kB unevictable:28756kB isolated(anon):0kB isolated(file):0kB present:311168kB managed:218944kB mlocked:0kB dirty:0kB writeback:0kB mapped:4kB shmem:0kB slab_reclaimable:160648kB slab_unreclaimable:19960kB kernel_stack:880kB pagetables:20kB unstable:0kB bounce:0kB free_pcp:460kB local_pcp:144kB free_cma:0kB writeback_tmp:0kB pages_scanned:724 all_unreclaimable? yes
[ 37.758461] lowmem_reserve[]: 0 0 0 0
[ 37.758490] Node 0 DMA: 1*4kB (U) 4*8kB (UE) 0*16kB 0*32kB 1*64kB (E) 1*128kB (U) 1*256kB (U) 1*512kB (E) 0*1024kB 0*2048kB 0*4096kB = 996kB
[ 37.758516] Node 0 DMA32: 4*4kB (UM) 2*8kB (M) 2*16kB (UM) 2*32kB (UE) 6*64kB (UME) 5*128kB (UME) 3*256kB (UE) 0*512kB 0*1024kB 0*2048kB 0*4096kB = 1920kB
[ 37.758520] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
[ 37.758522] 7212 total pagecache pages
[ 37.758523] 0 pages in swap cache
[ 37.758526] Swap cache stats: add 0, delete 0, find 0/0
[ 37.758527] Free swap = 0kB
[ 37.758528] Total swap = 0kB
[ 37.758531] 81790 pages RAM
[ 37.758532] 0 pages HighMem/MovableOnly
[ 37.758534] 23077 pages reserved
[ 37.758535] 0 pages hwpoisoned
[ 37.758537] [ pid ] uid tgid total_vm rss nr_ptes nr_pmds swapents oom_score_adj name
[ 37.758591] Kernel panic - not syncing: Out of memory and no killable processes...
[ 37.758591]
[ 37.758595] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.3.0-08150-g08d7865 #1
[ 37.758597] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 37.758603] 0000000000000000 ffff8800132bbb68 ffffffff8173760d ffffffff83a8ed36
[ 37.758608] ffff8800132bbbe8 ffffffff811a3c59 ffff880000000008 ffff8800132bbbf8
[ 37.758614] ffff8800132bbb90 00000001132bbbc8 0000000000002ebc 0000000000001ea0
[ 37.758615] Call Trace:
[ 37.758619] [<ffffffff8173760d>] dump_stack+0x4b/0x63
[ 37.758625] [<ffffffff811a3c59>] panic+0xcc/0x213
[ 37.758630] [<ffffffff811a90b5>] out_of_memory+0x3b1/0x3f1
[ 37.758635] [<ffffffff811addb5>] __alloc_pages_slowpath+0x62d/0x68d
[ 37.758641] [<ffffffff811adfab>] __alloc_pages_nodemask+0x196/0x2dc
[ 37.758647] [<ffffffff811e5b51>] alloc_page_interleave+0x37/0x7a
[ 37.758652] [<ffffffff811e6193>] alloc_pages_current+0x79/0xe2
[ 37.758657] [<ffffffff811d94fa>] __vmalloc_node_range+0x168/0x22e
[ 37.758661] [<ffffffff8467c85c>] ? init_pmc551+0x5e3/0x5e3
[ 37.758666] [<ffffffff811d95ee>] __vmalloc_node+0x2e/0x30
[ 37.758669] [<ffffffff8467c898>] ? init_mtdram+0x3c/0xc4
[ 37.758673] [<ffffffff811d9776>] vmalloc+0x2a/0x2c
[ 37.758677] [<ffffffff8467c898>] init_mtdram+0x3c/0xc4
[ 37.758681] [<ffffffff8467c85c>] ? init_pmc551+0x5e3/0x5e3
[ 37.758685] [<ffffffff81002174>] do_one_initcall+0xe7/0x173
[ 37.758690] [<ffffffff84606131>] kernel_init_freeable+0x1bf/0x24c
[ 37.758693] [<ffffffff82e0b139>] ? rest_init+0x140/0x140
[ 37.758697] [<ffffffff82e0b147>] kernel_init+0xe/0xd9
[ 37.758701] [<ffffffff82e173df>] ret_from_fork+0x3f/0x70
[ 37.758704] [<ffffffff82e0b139>] ? rest_init+0x140/0x140
[ 37.775268] Kernel Offset: disabled
[ 38.408621]
[ 38.408623] =====================================
[ 38.408623] [ BUG: bad unlock balance detected! ]
[ 38.408627] 4.3.0-08150-g08d7865 #1 Not tainted
[ 38.408627] -------------------------------------
[ 38.408631] swapper/0/1 is trying to release lock (console_lock) at:
[ 38.408639] [<ffffffff811a3cb1>] panic+0x124/0x213
[ 38.408640] but there are no more locks to release!
[ 38.408641]
[ 38.408641] other info that might help us debug this:
[ 38.408642] 2 locks held by swapper/0/1:
[ 38.408651] #0: (oom_lock){+.+...}, at: [<ffffffff811add45>] __alloc_pages_slowpath+0x5bd/0x68d
[ 38.408656] #1: (panic_lock){......}, at: [<ffffffff811a3bd9>] panic+0x4c/0x213
[ 38.408657]
[ 38.408657] stack backtrace:
[ 38.408659] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.3.0-08150-g08d7865 #1
[ 38.408660] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
[ 38.408665] 0000000000000000 ffff8800132bba78 ffffffff8173760d ffff8800132b4040
[ 38.408668] ffff8800132bbaa0 ffffffff8111328c 00000000ffffffff ffff8800132b4040
[ 38.408670] ffffffff8406a080 ffff8800132bbb18 ffffffff8111626c ffffffff811139d1
[ 38.408671] Call Trace:
[ 38.408678] [<ffffffff8173760d>] dump_stack+0x4b/0x63
[ 38.408682] [<ffffffff8111328c>] print_unlock_imbalance_bug+0xc7/0xd0
[ 38.408685] [<ffffffff8111626c>] lock_release+0x23f/0x41a
[ 38.408686] [<ffffffff811139d1>] ? lock_acquired+0xfc/0x2cb
[ 38.408689] [<ffffffff811a3cb1>] ? panic+0x124/0x213
[ 38.408694] [<ffffffff81123f39>] console_unlock+0x3f3/0x457
[ 38.408696] [<ffffffff811a3cb1>] panic+0x124/0x213
[ 38.408699] [<ffffffff811a90b5>] out_of_memory+0x3b1/0x3f1
[ 38.408702] [<ffffffff811addb5>] __alloc_pages_slowpath+0x62d/0x68d
[ 38.408705] [<ffffffff811adfab>] __alloc_pages_nodemask+0x196/0x2dc
[ 38.408711] [<ffffffff811e5b51>] alloc_page_interleave+0x37/0x7a
[ 38.408714] [<ffffffff811e6193>] alloc_pages_current+0x79/0xe2
[ 38.408718] [<ffffffff811d94fa>] __vmalloc_node_range+0x168/0x22e
[ 38.408724] [<ffffffff8467c85c>] ? init_pmc551+0x5e3/0x5e3
[ 38.408726] [<ffffffff811d95ee>] __vmalloc_node+0x2e/0x30
[ 38.408728] [<ffffffff8467c898>] ? init_mtdram+0x3c/0xc4
[ 38.408730] [<ffffffff811d9776>] vmalloc+0x2a/0x2c
[ 38.408732] [<ffffffff8467c898>] init_mtdram+0x3c/0xc4
[ 38.408733] [<ffffffff8467c85c>] ? init_pmc551+0x5e3/0x5e3
[ 38.408738] [<ffffffff81002174>] do_one_initcall+0xe7/0x173
[ 38.408744] [<ffffffff84606131>] kernel_init_freeable+0x1bf/0x24c
[ 38.408747] [<ffffffff82e0b139>] ? rest_init+0x140/0x140
[ 38.408749] [<ffffffff82e0b147>] kernel_init+0xe/0xd9
[ 38.408752] [<ffffffff82e173df>] ret_from_fork+0x3f/0x70
[ 38.408754] [<ffffffff82e0b139>] ? rest_init+0x140/0x140
Elapsed time: 50
qemu-system-x86_64 -enable-kvm -cpu Nehalem -kernel /pkg/linux/x86_64-allyesdebian+CONFIG_DEBUG_INFO_REDUCED/gcc-5/08d78658f393fefaa2e6507ea052c6f8ef4002a2/vmlinuz-4.3.0-08150-g08d7865 -append 'root=/dev/ram0 user=lkp job=/lkp/scheduled/vm-intel12-yocto-x86_64-1/validate_boot-1-yocto-minimal-x86_64.cgz-x86_64-allyesdebian+CONFIG_DEBUG_INFO_REDUCED-08d78658f393fefaa2e6507ea052c6f8ef4002a2-20151114-93880-64kz11-0.yaml ARCH=x86_64 kconfig=x86_64-allyesdebian+CONFIG_DEBUG_INFO_REDUCED branch=linux-devel/devel-catchup-201511132213 commit=08d78658f393fefaa2e6507ea052c6f8ef4002a2 BOOT_IMAGE=/pkg/linux/x86_64-allyesdebian+CONFIG_DEBUG_INFO_REDUCED/gcc-5/08d78658f393fefaa2e6507ea052c6f8ef4002a2/vmlinuz-4.3.0-08150-g08d7865 max_uptime=600 RESULT_ROOT=/result/boot/1/vm-intel12-yocto-x86_64/yocto-minimal-x86_64.cgz/x86_64-allyesdebian+CONFIG_DEBUG_INFO_REDUCED/gcc-5/08d78658f393fefaa2e6507ea052c6f8ef4002a2/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-intel12-yocto-x86_64-1::dhcp drbd.minor_count=8' -initrd /fs/KVM/initrd-vm-intel12-yocto-x86_64-1 -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/KVM/disk0-vm-intel12-yocto-x86_64-1,media=disk,if=virtio -drive file=/fs/KVM/disk1-vm-intel12-yocto-x86_64-1,media=disk,if=virtio -pidfile /dev/shm/kboot/pid-vm-intel12-yocto-x86_64-1 -serial file:/dev/shm/kboot/serial-vm-intel12-yocto-x86_64-1 -daemonize -display none -monitor null
Thanks,
Ying Huang
On Mon, 16 Nov 2015 11:12:50 +0800 kernel test robot <[email protected]> wrote:
> FYI, we noticed the below changes on
>
> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
> commit 08d78658f393fefaa2e6507ea052c6f8ef4002a2 ("panic: release stale console lock to always get the logbuf printed out")
>
> ...
>
> [ 38.408623] =====================================
> [ 38.408623] [ BUG: bad unlock balance detected! ]
> [ 38.408627] 4.3.0-08150-g08d7865 #1 Not tainted
> [ 38.408627] -------------------------------------
> [ 38.408631] swapper/0/1 is trying to release lock (console_lock) at:
> [ 38.408639] [<ffffffff811a3cb1>] panic+0x124/0x213
> [ 38.408640] but there are no more locks to release!
> [ 38.408641]
> [ 38.408641] other info that might help us debug this:
> [ 38.408642] 2 locks held by swapper/0/1:
> [ 38.408651] #0: (oom_lock){+.+...}, at: [<ffffffff811add45>] __alloc_pages_slowpath+0x5bd/0x68d
> [ 38.408656] #1: (panic_lock){......}, at: [<ffffffff811a3bd9>] panic+0x4c/0x213
> [ 38.408657]
> [ 38.408657] stack backtrace:
> [ 38.408659] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.3.0-08150-g08d7865 #1
> [ 38.408660] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
> [ 38.408665] 0000000000000000 ffff8800132bba78 ffffffff8173760d ffff8800132b4040
> [ 38.408668] ffff8800132bbaa0 ffffffff8111328c 00000000ffffffff ffff8800132b4040
> [ 38.408670] ffffffff8406a080 ffff8800132bbb18 ffffffff8111626c ffffffff811139d1
> [ 38.408671] Call Trace:
> [ 38.408678] [<ffffffff8173760d>] dump_stack+0x4b/0x63
> [ 38.408682] [<ffffffff8111328c>] print_unlock_imbalance_bug+0xc7/0xd0
Yup, we can't have this happen.
Can we instead do this?
if (is_console_locked())
console_unlock();
It's racy, but more accurate than what we have now?
Andrew Morton <[email protected]> writes:
> On Mon, 16 Nov 2015 11:12:50 +0800 kernel test robot <[email protected]> wrote:
>
>> FYI, we noticed the below changes on
>>
>> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git master
>> commit 08d78658f393fefaa2e6507ea052c6f8ef4002a2 ("panic: release stale console lock to always get the logbuf printed out")
>>
>> ...
>>
>> [ 38.408623] =====================================
>> [ 38.408623] [ BUG: bad unlock balance detected! ]
>> [ 38.408627] 4.3.0-08150-g08d7865 #1 Not tainted
>> [ 38.408627] -------------------------------------
>> [ 38.408631] swapper/0/1 is trying to release lock (console_lock) at:
>> [ 38.408639] [<ffffffff811a3cb1>] panic+0x124/0x213
>> [ 38.408640] but there are no more locks to release!
>> [ 38.408641]
>> [ 38.408641] other info that might help us debug this:
>> [ 38.408642] 2 locks held by swapper/0/1:
>> [ 38.408651] #0: (oom_lock){+.+...}, at: [<ffffffff811add45>] __alloc_pages_slowpath+0x5bd/0x68d
>> [ 38.408656] #1: (panic_lock){......}, at: [<ffffffff811a3bd9>] panic+0x4c/0x213
>> [ 38.408657]
>> [ 38.408657] stack backtrace:
>> [ 38.408659] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.3.0-08150-g08d7865 #1
>> [ 38.408660] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS Debian-1.8.2-1 04/01/2014
>> [ 38.408665] 0000000000000000 ffff8800132bba78 ffffffff8173760d ffff8800132b4040
>> [ 38.408668] ffff8800132bbaa0 ffffffff8111328c 00000000ffffffff ffff8800132b4040
>> [ 38.408670] ffffffff8406a080 ffff8800132bbb18 ffffffff8111626c ffffffff811139d1
>> [ 38.408671] Call Trace:
>> [ 38.408678] [<ffffffff8173760d>] dump_stack+0x4b/0x63
>> [ 38.408682] [<ffffffff8111328c>] print_unlock_imbalance_bug+0xc7/0xd0
>
> Yup, we can't have this happen.
>
> Can we instead do this?
>
> if (is_console_locked())
> console_unlock();
>
> It's racy,
Well, at this point all other CPUs are supposed to be stopped by
smp_send_stop() (first by IPIs and then by NMIs).
> but more accurate than what we have now?
Yes, but it won't solve the issue - lockdep is complaining because *we*
didn't take take the lock we're trying to release. I suggest to disable
lockdep here (it is already disabled on OOPS, but if panic() is called
directly it is not -- I didn't test this case and that's what actually
happens on OOM above), please see my "[PATCH] panic: turn off locks
debug before releasing console lock".
--
Vitaly