lists.openwall.net   lists  /  announce  owl-users  owl-dev  john-users  john-dev  passwdqc-users  yescrypt  popa3d-users  /  oss-security  kernel-hardening  musl  sabotage  tlsify  passwords  /  crypt-dev  xvendor  /  Bugtraq  Full-Disclosure  linux-kernel  linux-netdev  linux-ext4  linux-hardening  linux-cve-announce  PHC 
Open Source and information security mailing list archives
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Date:   Fri, 24 Mar 2017 17:57:45 +0100 (CET)
From:   Sebastian Ott <sebott@...ux.vnet.ibm.com>
To:     Steven Rostedt <rostedt@...dmis.org>
cc:     Sergey Senozhatsky <sergey.senozhatsky@...il.com>,
        Petr Mladek <pmladek@...e.com>,
        Heiko Carstens <heiko.carstens@...ibm.com>,
        linux-kernel@...r.kernel.org
Subject: Re: lockdep warning: console vs. mem hotplug

On Fri, 24 Mar 2017, Steven Rostedt wrote:
> Is there a stack trace of where the lockdep dump happened? That is
> useful too. Otherwise we don't see where the inverse happened.

Sure. Here you go.

[  132.379220] ======================================================
[  132.379220] [ INFO: possible circular locking dependency detected ]
[  132.379221] 4.11.0-rc3 #330 Not tainted
[  132.379221] -------------------------------------------------------
[  132.379222] sh/708 is trying to acquire lock:
[  132.379222]  (&(&sclp_con_lock)->rlock){-.-...}, at: [<000000000074524a>] sclp_console_write+0x4a/0x2b8
[  132.379224] 
[  132.379224] but task is already holding lock:
[  132.379224]  (&(&zone->lock)->rlock){..-...}, at: [<00000000002a65a8>] __offline_isolated_pages+0xe0/0x340
[  132.379226] 
[  132.379227] which lock already depends on the new lock.
[  132.379227] 
[  132.379227] 
[  132.379228] the existing dependency chain (in reverse order) is:
[  132.379228] 
[  132.379229] -> #2 (&(&zone->lock)->rlock){..-...}:
[  132.379230]        validate_chain.isra.22+0xb36/0xd18
[  132.379231]        __lock_acquire+0x650/0x880
[  132.379231]        lock_acquire+0x24e/0x2b0
[  132.379232]        _raw_spin_lock_irqsave+0x70/0xb8
[  132.379232]        get_page_from_freelist+0x548/0xf30
[  132.379233]        __alloc_pages_nodemask+0x1c8/0x14c0
[  132.379233]        allocate_slab+0xde/0x668
[  132.379233]        new_slab+0x94/0xa8
[  132.379234]        ___slab_alloc.constprop.66+0x556/0x578
[  132.379234]        __slab_alloc.isra.62.constprop.65+0x74/0xa8
[  132.379235]        kmem_cache_alloc+0x136/0x4b8
[  132.379235]        __debug_object_init+0xaa/0x448
[  132.379236]        debug_object_activate+0x182/0x238
[  132.379236]        mod_timer+0xe6/0x450
[  132.379236]        prandom_reseed+0x44/0x50
[  132.379237]        do_one_initcall+0xa2/0x150
[  132.379237]        kernel_init_freeable+0x228/0x2d8
[  132.379238]        kernel_init+0x2a/0x138
[  132.379238]        kernel_thread_starter+0x6/0xc
[  132.379239]        kernel_thread_starter+0x0/0xc
[  132.379239] 
[  132.379239] -> #1 (&(&base->lock)->rlock){-.-.-.}:
[  132.379241]        validate_chain.isra.22+0xb36/0xd18
[  132.379242]        __lock_acquire+0x650/0x880
[  132.379242]        lock_acquire+0x24e/0x2b0
[  132.379242]        _raw_spin_lock_irqsave+0x70/0xb8
[  132.379243]        lock_timer_base+0x78/0xa8
[  132.379243]        mod_timer+0xba/0x450
[  132.379244]        sclp_console_write+0x262/0x2b8
[  132.379244]        console_unlock+0x4a6/0x658
[  132.379245]        register_console+0x31c/0x430
[  132.379245]        sclp_console_init+0x152/0x170
[  132.379245]        console_init+0x3a/0x58
[  132.379246]        start_kernel+0x350/0x480
[  132.379246]        _stext+0x20/0x80
[  132.379246] 
[  132.379247] -> #0 (&(&sclp_con_lock)->rlock){-.-...}:
[  132.379249]        check_prev_add+0x150/0x648
[  132.379249]        validate_chain.isra.22+0xb36/0xd18
[  132.379249]        __lock_acquire+0x650/0x880
[  132.379250]        lock_acquire+0x24e/0x2b0
[  132.379250]        _raw_spin_lock_irqsave+0x70/0xb8
[  132.379251]        sclp_console_write+0x4a/0x2b8
[  132.379251]        console_unlock+0x4a6/0x658
[  132.379252]        vprintk_emit+0x33e/0x350
[  132.379252]        vprintk_default+0x44/0x58
[  132.379252]        printk+0x4e/0x58
[  132.379253]        __offline_isolated_pages+0x1a0/0x340
[  132.379253]        offline_isolated_pages_cb+0x2e/0x40
[  132.379254]        walk_system_ram_range+0x96/0xe8
[  132.379254]        __offline_pages.constprop.43+0x6da/0x918
[  132.379255]        memory_subsys_offline+0x6a/0xa0
[  132.379255]        device_offline+0x84/0xd8
[  132.379255]        store_mem_state+0xfe/0x120
[  132.379256]        kernfs_fop_write+0x126/0x1d0
[  132.379256]        __vfs_write+0x46/0x140
[  132.379257]        vfs_write+0xb8/0x1a8
[  132.379257]        SyS_write+0x66/0xc0
[  132.379257]        system_call+0xc4/0x240
[  132.379258] 
[  132.379258] other info that might help us debug this:
[  132.379258] 
[  132.379259] Chain exists of:
[  132.379259]   &(&sclp_con_lock)->rlock --> &(&base->lock)->rlock --> &(&zone->lock)->rlock
[  132.379262] 
[  132.379262]  Possible unsafe locking scenario:
[  132.379262] 
[  132.379263]        CPU0                    CPU1
[  132.379263]        ----                    ----
[  132.379264]   lock(&(&zone->lock)->rlock);
[  132.379265]                                lock(&(&base->lock)->rlock);
[  132.379266]                                lock(&(&zone->lock)->rlock);
[  132.379267]   lock(&(&sclp_con_lock)->rlock);
[  132.379268] 
[  132.379268]  *** DEADLOCK ***
[  132.379269] 
[  132.379269] 10 locks held by sh/708:
[  132.379269]  #0:  (sb_writers#4){.+.+.+}, at: [<0000000000345d4a>] vfs_write+0xa2/0x1a8
[  132.379272]  #1:  (&of->mutex){+.+.+.}, at: [<00000000003e5e60>] kernfs_fop_write+0xd8/0x1d0
[  132.379273]  #2:  (s_active#180){.+.+.+}, at: [<00000000003e5e6c>] kernfs_fop_write+0xe4/0x1d0
[  132.379275]  #3:  (device_hotplug_lock){+.+...}, at: [<000000000069bb58>] lock_device_hotplug_sysfs+0x30/0x68
[  132.379277]  #4:  (memory_add_remove_lock){+.+...}, at: [<000000000031cfe6>] mem_hotplug_begin+0x3e/0xd0
[  132.379279]  #5:  (mem_hotplug.lock){++++.+}, at: [<000000000031cfa8>] mem_hotplug_begin+0x0/0xd0
[  132.379281]  #6:  (mem_hotplug.lock#2){+.+...}, at: [<000000000031d02c>] mem_hotplug_begin+0x84/0xd0
[  132.379283]  #7:  (&dev->mutex){......}, at: [<000000000069d55c>] device_offline+0x5c/0xd8
[  132.379285]  #8:  (&(&zone->lock)->rlock){..-...}, at: [<00000000002a65a8>] __offline_isolated_pages+0xe0/0x340
[  132.379287]  #9:  (console_lock){+.+...}, at: [<00000000001bdc02>] vprintk_emit+0x332/0x350
[  132.379289] 
[  132.379289] stack backtrace:
[  132.379290] CPU: 1 PID: 708 Comm: sh Not tainted 4.11.0-rc3 #330
[  132.379290] Hardware name: IBM              2827 H66              703              (LPAR)
[  132.379290] Stack:
[  132.379291]        000000006f5ab458 000000006f5ab4e8 0000000000000003 0000000000000000
[  132.379293]        000000006f5ab588 000000006f5ab500 000000006f5ab500 0000000000000020
[  132.379294]        0000000000929180 000000000000000a 0000000000000020 000000000000000a
[  132.379296]        000000000000000c 000000006f5ab550 0000000000000000 0000000000000000
[  132.379298]        04000000016e0b18 0000000000111da2 000000006f5ab4e8 000000006f5ab540
[  132.379300] Call Trace:
[  132.379300] ([<0000000000111c86>] show_trace+0x8e/0xe0)
[  132.379301]  [<0000000000111d58>] show_stack+0x80/0xd8 
[  132.379301]  [<00000000005ff656>] dump_stack+0x96/0xd8 
[  132.379302]  [<0000000000291572>] print_circular_bug+0x2f2/0x308 
[  132.379302]  [<00000000001a6b98>] check_prev_add+0x150/0x648 
[  132.379303]  [<00000000001a7bc6>] validate_chain.isra.22+0xb36/0xd18 
[  132.379303]  [<00000000001a9240>] __lock_acquire+0x650/0x880 
[  132.379304]  [<00000000001a9bee>] lock_acquire+0x24e/0x2b0 
[  132.379304]  [<00000000008dcab0>] _raw_spin_lock_irqsave+0x70/0xb8 
[  132.379304]  [<000000000074524a>] sclp_console_write+0x4a/0x2b8 
[  132.379305]  [<00000000001bd71e>] console_unlock+0x4a6/0x658 
[  132.379305]  [<00000000001bdc0e>] vprintk_emit+0x33e/0x350 
[  132.379306]  [<00000000001bddec>] vprintk_default+0x44/0x58 
[  132.379306]  [<0000000000291c8e>] printk+0x4e/0x58 
[  132.379307]  [<00000000002a6668>] __offline_isolated_pages+0x1a0/0x340 
[  132.379307]  [<000000000031cbbe>] offline_isolated_pages_cb+0x2e/0x40 
[  132.379308]  [<0000000000147466>] walk_system_ram_range+0x96/0xe8 
[  132.379308]  [<00000000008d2bba>] __offline_pages.constprop.43+0x6da/0x918 
[  132.379309]  [<00000000006b9b2a>] memory_subsys_offline+0x6a/0xa0 
[  132.379309]  [<000000000069d584>] device_offline+0x84/0xd8 
[  132.379310]  [<00000000006ba146>] store_mem_state+0xfe/0x120 
[  132.379310]  [<00000000003e5eae>] kernfs_fop_write+0x126/0x1d0 
[  132.379311]  [<0000000000344b0e>] __vfs_write+0x46/0x140 
[  132.379311]  [<0000000000345d60>] vfs_write+0xb8/0x1a8 
[  132.379312]  [<000000000034742e>] SyS_write+0x66/0xc0 
[  132.379312]  [<00000000008dda2c>] system_call+0xc4/0x240 
[  132.379313] INFO: lockdep is turned off.




[  377.096545] ======================================================
[  377.096545] [ INFO: possible circular locking dependency detected ]
[  377.096546] 4.11.0-rc2-00238-ga722844 #120 Not tainted
[  377.096546] -------------------------------------------------------
[  377.096547] sh/848 is trying to acquire lock:
[  377.096547]  ((console_sem).lock){-.....}, at: [<00000000001a594e>] down_trylock+0x2e/0x68
[  377.096549] but task is already holding lock:
[  377.096550]  (&(&zone->lock)->rlock){..-...}, at: [<00000000002ae3da>] __offline_isolated_pages+0x302/0x370
[  377.096552] which lock already depends on the new lock.
[  377.096553] the existing dependency chain (in reverse order) is:

[  377.096554] -> #3 (&(&zone->lock)->rlock){..-...}:
[  377.096556]        validate_chain.isra.10+0xb7a/0xda8
[  377.096557]        __lock_acquire+0x62c/0x850
[  377.096557]        lock_acquire+0x254/0x2b8
[  377.096558]        _raw_spin_lock_irqsave+0x70/0xb8
[  377.096558]        get_page_from_freelist+0x4e2/0xf28
[  377.096558]        __alloc_pages_nodemask+0x1fa/0x1528
[  377.096559]        allocate_slab+0xf2/0x6c0
[  377.096559]        new_slab+0x94/0xa8
[  377.096560]        ___slab_alloc.constprop.22+0x570/0x590
[  377.096560]        __slab_alloc.isra.16.constprop.21+0x74/0xa8
[  377.096561]        kmem_cache_alloc+0x13c/0x4b0
[  377.096561]        __debug_object_init+0x5c/0x468
[  377.096561]        hrtimer_init+0x42/0x1d8
[  377.096562]        init_dl_task_timer+0x3a/0x58
[  377.096562]        __sched_fork.isra.5+0x7e/0xe8
[  377.096563]        init_idle+0x7a/0x278
[  377.096563]        fork_idle+0xa4/0xb8
[  377.096564]        idle_threads_init+0x64/0xc8
[  377.096564]        smp_init+0x2e/0x110
[  377.096565]        kernel_init_freeable+0x16c/0x2e0
[  377.096565]        kernel_init+0x2a/0x148
[  377.096565]        kernel_thread_starter+0x6/0xc
[  377.096566]        kernel_thread_starter+0x0/0xc

[  377.096567] -> #2 (&rq->lock){-.-.-.}:
[  377.096568]        validate_chain.isra.10+0xb7a/0xda8
[  377.096569]        __lock_acquire+0x62c/0x850
[  377.096569]        lock_acquire+0x254/0x2b8
[  377.096569]        _raw_spin_lock+0x60/0xa0
[  377.096570]        task_fork_fair+0x54/0x118
[  377.096570]        sched_fork+0x13e/0x2a0
[  377.096571]        copy_process+0x642/0x1e80
[  377.096571]        _do_fork+0xc2/0x6d0
[  377.096571]        kernel_thread+0x4e/0x60
[  377.096572]        rest_init+0x42/0x170
[  377.096572]        start_kernel+0x464/0x478
[  377.096572]        _stext+0x20/0x80

[  377.096573] -> #1 (&p->pi_lock){-.-.-.}:
[  377.096574]        validate_chain.isra.10+0xb7a/0xda8
[  377.096575]        __lock_acquire+0x62c/0x850
[  377.096575]        lock_acquire+0x254/0x2b8
[  377.096576]        _raw_spin_lock_irqsave+0x70/0xb8
[  377.096576]        try_to_wake_up+0x4a/0x5f8
[  377.096576]        up+0x58/0x70
[  377.096577]        __up_console_sem+0x5a/0x90
[  377.096577]        console_unlock+0x610/0x670
[  377.096578]        vprintk_emit+0x308/0x378
[  377.096578]        dev_vprintk_emit+0x1e6/0x200
[  377.096578]        dev_printk_emit+0x4e/0x60
[  377.096579]        __dev_printk+0x8e/0xb0
[  377.096579]        dev_warn+0x68/0x78
[  377.096579]        qeth_dev_portname_store+0x58/0x70
[  377.096580]        kernfs_fop_write+0x124/0x1c8
[  377.096580]        __vfs_write+0x36/0x140
[  377.096580]        vfs_write+0xb8/0x1a0
[  377.096581]        SyS_write+0x66/0xc0
[  377.096581]        system_call+0xc4/0x240

[  377.096582] -> #0 ((console_sem).lock){-.....}:
[  377.096583]        check_prev_add+0x160/0x6e8
[  377.096584]        validate_chain.isra.10+0xb7a/0xda8
[  377.096584]        __lock_acquire+0x62c/0x850
[  377.096584]        lock_acquire+0x254/0x2b8
[  377.096585]        _raw_spin_lock_irqsave+0x70/0xb8
[  377.096585]        down_trylock+0x2e/0x68
[  377.096586]        __down_trylock_console_sem+0x4a/0xc0
[  377.096586]        console_trylock+0x32/0xc8
[  377.096586]        vprintk_emit+0x2fc/0x378
[  377.096587]        vprintk_default+0x44/0x58
[  377.096587]        printk+0x4e/0x60
[  377.096587]        __offline_isolated_pages+0x168/0x370
[  377.096588]        offline_isolated_pages_cb+0x2e/0x40
[  377.096588]        walk_system_ram_range+0x92/0xf0
[  377.096589]        __offline_pages.constprop.9+0x74a/0x988
[  377.096589]        memory_subsys_offline+0x6c/0xa0
[  377.096589]        device_offline+0x84/0xe0
[  377.096590]        store_mem_state+0xfe/0x120
[  377.096590]        kernfs_fop_write+0x124/0x1c8
[  377.096590]        __vfs_write+0x36/0x140
[  377.096591]        vfs_write+0xb8/0x1a0
[  377.096591]        SyS_write+0x66/0xc0
[  377.096592]        system_call+0xc4/0x240

[  377.096592] other info that might help us debug this:

[  377.096593] Chain exists of:
[  377.096593]   (console_sem).lock --> &rq->lock --> &(&zone->lock)->rlock

[  377.096595]  Possible unsafe locking scenario:

[  377.096596]        CPU0                    CPU1
[  377.096596]        ----                    ----
[  377.096597]   lock(&(&zone->lock)->rlock);
[  377.096598]                                lock(&rq->lock);
[  377.096599]                                lock(&(&zone->lock)->rlock);
[  377.096600]   lock((console_sem).lock);

[  377.096601]  *** DEADLOCK ***

[  377.096601] 9 locks held by sh/848:
[  377.096602]  #0:  (sb_writers#5){.+.+.+}, at: [<000000000034f9c2>] vfs_write+0xa2/0x1a0
[  377.096604]  #1:  (&of->mutex){+.+.+.}, at: [<00000000003f1afe>] kernfs_fop_write+0xd6/0x1c8
[  377.096605]  #2:  (s_active#51){.+.+.+}, at: [<00000000003f1b0a>] kernfs_fop_write+0xe2/0x1c8
[  377.096607]  #3:  (device_hotplug_lock){+.+.+.}, at: [<00000000006adb70>] lock_device_hotplug_sysfs+0x30/0x70
[  377.096609]  #4:  (memory_add_remove_lock){+.+.+.}, at: [<0000000000328e16>] mem_hotplug_begin+0x3e/0xd0
[  377.096610]  #5:  (mem_hotplug.lock){++++++}, at: [<0000000000328dd8>] mem_hotplug_begin+0x0/0xd0
[  377.096612]  #6:  (mem_hotplug.lock#2){+.+.+.}, at: [<0000000000328e5c>] mem_hotplug_begin+0x84/0xd0
[  377.096614]  #7:  (&dev->mutex){......}, at: [<00000000006af41c>] device_offline+0x5c/0xe0
[  377.096615]  #8:  (&(&zone->lock)->rlock){..-...}, at: [<00000000002ae3da>] __offline_isolated_pages+0x302/0x370

[  377.096617] stack backtrace:
[  377.096618] CPU: 0 PID: 848 Comm: sh Not tainted 4.11.0-rc2-00238-ga722844 #120
[  377.096618] Hardware name: IBM              2827 H66              703              (z/VM)
[  377.096619] Stack:
[  377.096619]        000000003ed0f450 000000003ed0f4e0 0000000000000003 0000000000000000
[  377.096620]        000000003ed0f580 000000003ed0f4f8 000000003ed0f4f8 0000000000000020
[  377.096629]        00000000009441c0 0000000000000020 000000000000000a 000000000000000a
[  377.096631]        000000000000000c 000000003ed0f548 0000000000000000 0000000000000000
[  377.096633]        04000000016fa078 0000000000112338 000000003ed0f4e0 000000003ed0f538
[  377.096635] Call Trace:
[  377.096635] ([<0000000000112212>] show_trace+0x8a/0xe0)
[  377.096636]  [<00000000001122e8>] show_stack+0x80/0xd8 
[  377.096636]  [<000000000060f5a6>] dump_stack+0x96/0xd8 
[  377.096637]  [<00000000001a9d3c>] print_circular_bug+0x314/0x340 
[  377.096637]  [<00000000001aacc0>] check_prev_add+0x160/0x6e8 
[  377.096638]  [<00000000001abdc2>] validate_chain.isra.10+0xb7a/0xda8 
[  377.096638]  [<00000000001ad7dc>] __lock_acquire+0x62c/0x850 
[  377.096639]  [<00000000001ae20c>] lock_acquire+0x254/0x2b8 
[  377.096639]  [<00000000008f63b8>] _raw_spin_lock_irqsave+0x70/0xb8 
[  377.096639]  [<00000000001a594e>] down_trylock+0x2e/0x68 
[  377.096640]  [<00000000001c1262>] __down_trylock_console_sem+0x4a/0xc0 
[  377.096641]  [<00000000001c130a>] console_trylock+0x32/0xc8 
[  377.096641]  [<00000000001c2c84>] vprintk_emit+0x2fc/0x378 
[  377.096641]  [<00000000001c2edc>] vprintk_default+0x44/0x58 
[  377.096642]  [<000000000029a24e>] printk+0x4e/0x60 
[  377.096642]  [<00000000002ae240>] __offline_isolated_pages+0x168/0x370 
[  377.096643]  [<00000000003289d6>] offline_isolated_pages_cb+0x2e/0x40 
[  377.096643]  [<00000000001492fa>] walk_system_ram_range+0x92/0xf0 
[  377.096644]  [<00000000008ec1fa>] __offline_pages.constprop.9+0x74a/0x988 
[  377.096644]  [<00000000006cc9bc>] memory_subsys_offline+0x6c/0xa0 
[  377.096645]  [<00000000006af444>] device_offline+0x84/0xe0 
[  377.096645]  [<00000000006cd0ae>] store_mem_state+0xfe/0x120 
[  377.096645]  [<00000000003f1b4c>] kernfs_fop_write+0x124/0x1c8 
[  377.096646]  [<000000000034e736>] __vfs_write+0x36/0x140 
[  377.096646]  [<000000000034f9d8>] vfs_write+0xb8/0x1a0 
[  377.096647]  [<000000000035110e>] SyS_write+0x66/0xc0 
[  377.096647]  [<00000000008f74ac>] system_call+0xc4/0x240 
[  377.096648] INFO: lockdep is turned off.

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ