FYI, we noticed the following commit (built with gcc-6):
commit: b6da31b2c07c46f2dcad1d86caa835227a16d9ff ("tty: Fix data race in tty_insert_flip_string_fixed_flag")
https://git.kernel.org/cgit/linux/kernel/git/next/linux-next.git master
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu Nehalem -smp 2 -m 512M
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+--------------------------------------------------------------------+------------+------------+
| | 638a6f4ebe | b6da31b2c0 |
+--------------------------------------------------------------------+------------+------------+
| boot_successes | 0 | 0 |
| boot_failures | 14 | 17 |
| WARNING:at_lib/debugobjects.c:#__debug_object_init | 14 | 17 |
| RIP:__debug_object_init | 14 | 17 |
| WARNING:suspicious_RCU_usage | 14 | 17 |
| lib/test_rhashtable.c:#suspicious_rcu_dereference_protected()usage | 14 | 17 |
| WARNING:possible_circular_locking_dependency_detected | 0 | 15 |
+--------------------------------------------------------------------+------------+------------+
[ 20.553647] WARNING: possible circular locking dependency detected
[ 20.554329] 4.17.0-rc3-00051-gb6da31b #1 Tainted: G W
[ 20.554980] ------------------------------------------------------
[ 20.555637] S36udev-cache/240 is trying to acquire lock:
[ 20.556191] (ptrval) (&obj_hash[i].lock){-.-.}, at: debug_object_activate+0x96/0x250
[ 20.557071]
[ 20.557071] but task is already holding lock:
[ 20.557702] (ptrval) (&(&port->lock)->rlock){-...}, at: pty_write+0x3a/0x90
[ 20.558508]
[ 20.558508] which lock already depends on the new lock.
[ 20.558508]
[ 20.559355]
[ 20.559355] the existing dependency chain (in reverse order) is:
[ 20.560095]
[ 20.560095] -> #3 (&(&port->lock)->rlock){-...}:
[ 20.560746] lock_acquire+0x1b3/0x20a
[ 20.561249] _raw_spin_lock_irqsave+0x5b/0x70
[ 20.561741] tty_port_tty_get+0x1b/0x50
[ 20.562177] tty_port_default_wakeup+0xb/0x30
[ 20.562689] serial8250_tx_chars+0x11e/0x1d0
[ 20.563190] serial8250_handle_irq+0xa7/0xd0
[ 20.563726] serial8250_default_handle_irq+0x39/0x50
[ 20.564318] serial8250_interrupt+0x45/0x110
[ 20.564826] __handle_irq_event_percpu+0x137/0x340
[ 20.565388] handle_irq_event_percpu+0x30/0x70
[ 20.565910] handle_irq_event+0x34/0x60
[ 20.566374] handle_edge_irq+0x197/0x1c0
[ 20.566840] handle_irq+0xfd/0x110
[ 20.567290] do_IRQ+0x7b/0x100
[ 20.567671] ret_from_intr+0x0/0x2f
[ 20.568095] _raw_spin_unlock_irqrestore+0x60/0x70
[ 20.568668] uart_write+0x143/0x1a0
[ 20.569087] n_tty_write+0x250/0x490
[ 20.569517] tty_write+0x1bf/0x2a0
[ 20.569909] __vfs_write+0x33/0x140
[ 20.570411] vfs_write+0xdf/0x1b0
[ 20.570795] ksys_write+0x55/0xc0
[ 20.571185] do_syscall_64+0x71/0x220
[ 20.571656] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 20.572248]
[ 20.572248] -> #2 (&port_lock_key){-...}:
[ 20.572812] lock_acquire+0x1b3/0x20a
[ 20.573261] _raw_spin_lock_irqsave+0x5b/0x70
[ 20.573771] serial8250_console_write+0xfb/0x2a0
[ 20.574319] console_unlock+0x434/0x6e0
[ 20.574772] vprintk_emit+0x53d/0x560
[ 20.575218] printk+0x52/0x6e
[ 20.575614] register_console+0x30b/0x3c0
[ 20.576073] univ8250_console_init+0x24/0x27
[ 20.576568] console_init+0x20e/0x368
[ 20.577009] start_kernel+0x44d/0x597
[ 20.577454] secondary_startup_64+0xa5/0xb0
[ 20.577940]
[ 20.577940] -> #1 (console_owner){-...}:
[ 20.578517] lock_acquire+0x1b3/0x20a
[ 20.578958] console_unlock+0x2e6/0x6e0
[ 20.579439] vprintk_emit+0x53d/0x560
[ 20.579858] printk+0x52/0x6e
[ 20.580246] __debug_object_init+0x51d/0x580
[ 20.580730] rhashtable_init+0x1fd/0x250
[ 20.581180] rhltable_init+0x10/0x20
[ 20.581609] test_insert_dup+0x58/0x718
[ 20.582050] test_rht_init+0x2d9/0x5e1
[ 20.582491] do_one_initcall+0x131/0x334
[ 20.582961] kernel_init_freeable+0x324/0x3f4
[ 20.583510] kernel_init+0xa/0x100
[ 20.583942] ret_from_fork+0x3a/0x50
[ 20.584400]
[ 20.584400] -> #0 (&obj_hash[i].lock){-.-.}:
[ 20.585056] __lock_acquire+0x5af/0x7b0
[ 20.585568] lock_acquire+0x1b3/0x20a
[ 20.586034] _raw_spin_lock_irqsave+0x5b/0x70
[ 20.586575] debug_object_activate+0x96/0x250
[ 20.587086] __queue_work+0x70/0x560
[ 20.587537] queue_work_on+0x66/0xc0
[ 20.587959] pty_write+0x65/0x90
[ 20.588347] n_tty_write+0x250/0x490
[ 20.588779] tty_write+0x1bf/0x2a0
[ 20.589178] __vfs_write+0x33/0x140
[ 20.589593] vfs_write+0xdf/0x1b0
[ 20.589999] redirected_tty_write+0x7c/0xa0
[ 20.590523] __vfs_write+0x33/0x140
[ 20.590961] vfs_write+0xdf/0x1b0
[ 20.591390] ksys_write+0x55/0xc0
[ 20.591802] do_syscall_64+0x71/0x220
[ 20.592228] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 20.592785]
[ 20.592785] other info that might help us debug this:
[ 20.592785]
[ 20.593568] Chain exists of:
[ 20.593568] &obj_hash[i].lock --> &port_lock_key --> &(&port->lock)->rlock
[ 20.593568]
[ 20.594712] Possible unsafe locking scenario:
[ 20.594712]
[ 20.595341] CPU0 CPU1
[ 20.595793] ---- ----
[ 20.596248] lock(&(&port->lock)->rlock);
[ 20.596667] lock(&port_lock_key);
[ 20.597268] lock(&(&port->lock)->rlock);
[ 20.597935] lock(&obj_hash[i].lock);
[ 20.598315]
To reproduce:
git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email
Thanks,
Xiaolong