Re: [LKP] [tty] c96cf923a9: WARNING:possible_circular_locking_dependency_detected

[Jiri Slaby]

On 11. 12. 18, 10:11, kernel test robot wrote:
> FYI, we noticed the following commit (built with gcc-7):
> 
> commit: c96cf923a98d1b094df9f0cf97a83e118817e31b ("tty: Don't block on IO when ldisc change is pending")
> https://git.kernel.org/cgit/linux/kernel/git/gregkh/tty.git tty-testing
...
> [   87.209665] WARNING: possible circular locking dependency detected
> [   87.210547] 4.20.0-rc4-00057-gc96cf92 #1 Tainted: G        W        
> [   87.211449] ------------------------------------------------------
> [   87.212405] getty/519 is trying to acquire lock:
> [   87.213074] (____ptrval____) (&obj_hash[i].lock){-.-.}, at: debug_check_no_obj_freed+0xb4/0x302
> [   87.214343] 
> [   87.214343] but task is already holding lock:
> [   87.215174] (____ptrval____) (&port_lock_key){-.-.}, at: uart_shutdown+0x3a3/0x4e2

This looks sensible -- normal use case.

> [   87.216260] which lock already depends on the new lock.
> [   87.216260] 
> [   87.217421] 
> [   87.217421] the existing dependency chain (in reverse order) is:

This is during console init, so even if the report is not false
positive, the deadlock is unlikely to happen. And only triggered with
CONFIG_DEBUG_OBJECTS_FREE.

In any way, I don't see any connection between #2 and #0 below. The
stack traces are completely different -- one from start_kernel, one from
exit syscall.

I also wonder how could the commit above start causing this? Well, it
might make it happen more likely due to more of EAGAINs.

> [   87.218483] -> #2 (&port_lock_key){-.-.}:
> [   87.219282]        lock_acquire+0x28c/0x2e7
> [   87.219901]        _raw_spin_lock_irqsave+0x35/0x49
> [   87.220601]        serial8250_console_write+0x110/0x5b5
> [   87.221354]        univ8250_console_write+0x5f/0x64
> [   87.222056]        console_unlock+0x61c/0x7cf
> [   87.222680]        register_console+0x63a/0x7b0
> [   87.223345]        univ8250_console_init+0x1e/0x28
> [   87.224041]        console_init+0x3be/0x57e
> [   87.224641]        start_kernel+0x441/0x6c6
> [   87.225246]        x86_64_start_reservations+0x29/0x2b
> [   87.225979]        x86_64_start_kernel+0x6f/0x72
> [   87.226637]        secondary_startup_64+0xa4/0xb0
> [   87.227314] 
> [   87.227314] -> #1 (console_owner){-...}:
> [   87.228127]        lock_acquire+0x28c/0x2e7
> [   87.228728]        console_unlock+0x424/0x7cf
> [   87.229363]        vprintk_emit+0x22d/0x252
> [   87.229969]        vprintk_default+0x18/0x1a
> [   87.230576]        vprintk_func+0xa9/0xab
> [   87.231156]        printk+0x97/0xbe
> [   87.231659]        __debug_object_init+0x8db/0x92d
> [   87.232349]        debug_object_init+0x14/0x17
> [   87.232987]        __init_work+0x1b/0x1d
> [   87.233551]        rhashtable_init+0x53b/0x602
> [   87.234192]        rhltable_init+0xe/0x41
> [   87.234772]        test_insert_dup+0xac/0xa94
> [   87.235467]        test_rht_init+0x387/0x79c
> [   87.236222]        do_one_initcall+0x23c/0x4af
> [   87.236869]        kernel_init_freeable+0x5ec/0x69f
> [   87.237855]        kernel_init+0xc/0x100
> [   87.238470]        ret_from_fork+0x3a/0x50
> [   87.239071] 
> [   87.239071] -> #0 (&obj_hash[i].lock){-.-.}:
> [   87.239904]        __lock_acquire+0x1f78/0x22d1
> [   87.240556]        lock_acquire+0x28c/0x2e7
> [   87.241173]        _raw_spin_lock_irqsave+0x35/0x49
> [   87.241882]        debug_check_no_obj_freed+0xb4/0x302
> [   87.242620]        free_unref_page_prepare+0x33a/0x483
> [   87.243368]        free_unref_page+0x48/0x80
> [   87.243991]        __free_pages+0x2e/0x40
> [   87.244611]        free_pages+0x54/0x5a
> [   87.245188]        uart_shutdown+0x3df/0x4e2
> [   87.245817]        uart_hangup+0x123/0x280
> [   87.246406]        __tty_hangup+0x4da/0x50f
> [   87.247025]        tty_vhangup_session+0xe/0x10
> [   87.247680]        disassociate_ctty+0xeb/0x5c5
> [   87.248349]        do_exit+0xc97/0x1daf
> [   87.248920]        __x64_sys_exit_group+0x0/0x3e
> [   87.249587]        __wake_up_parent+0x0/0x52
> [   87.250211]        do_syscall_64+0x5e8/0x881
> [   87.250839]        entry_SYSCALL_64_after_hwframe+0x49/0xbe
> [   87.251637] 
> [   87.251637] other info that might help us debug this:
> [   87.251637] 
> [   87.252790] Chain exists of:
> [   87.252790]   &obj_hash[i].lock --> console_owner --> &port_lock_key
> [   87.252790] 
> [   87.254307]  Possible unsafe locking scenario:
> [   87.254307] 
> [   87.255156]        CPU0                    CPU1
> [   87.255813]        ----                    ----
> [   87.256460]   lock(&port_lock_key);
> [   87.256973]                                lock(console_owner);
> [   87.257829]                                lock(&port_lock_key);
> [   87.258680]   lock(&obj_hash[i].lock);
> [   87.259223] 
> [   87.259223]  *** DEADLOCK ***
> [   87.259223] 
> [   87.260067] 3 locks held by getty/519:
> [   87.260605]  #0: (____ptrval____) (&tty->legacy_mutex){+.+.}, at: tty_lock+0x5c/0x68
> [   87.261717]  #1: (____ptrval____) (&port->mutex){+.+.}, at: uart_hangup+0x4b/0x280
> [   87.262795]  #2: (____ptrval____) (&port_lock_key){-.-.}, at: uart_shutdown+0x3a3/0x4e2
> [   87.263974] 
> [   87.263974] stack backtrace:
> [   87.264631] CPU: 0 PID: 519 Comm: getty Tainted: G        W         4.20.0-rc4-00057-gc96cf92 #1
> [   87.265893] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
> [   87.267082] Call Trace:
> [   87.267451]  dump_stack+0x86/0xc3
> [   87.267942]  print_circular_bug+0x4a8/0x4b9
> [   87.268635]  check_prevs_add+0x466/0x109c
> [   87.269230]  ? quarantine_put+0x114/0x135
> [   87.269821]  ? quarantine_put+0x114/0x135
> [   87.270399]  ? serial_do_unlink+0x266/0x272
> [   87.271009]  ? print_circular_bug_header+0x122/0x122
> [   87.271722]  ? __kasan_slab_free+0x1e8/0x1fd
> [   87.272341]  ? __kasan_slab_free+0x153/0x1fd


thanks,
-- 
js
suse labs