| 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
| ||
|
Date: Mon, 13 Nov 2017 03:14:39 +0800
From: kernel test robot <fengguang.wu@...el.com>
To: Denys Zagorui <dzagorui@...co.com>
Cc: gregkh@...uxfoundation.org, jslaby@...e.com,
linux-serial@...r.kernel.org, linux-kernel@...r.kernel.org,
lkp@...org
Subject: [serial] b5c545ac2f: WARNING:inconsistent_lock_state
FYI, we noticed the following commit (built with gcc-6):
commit: b5c545ac2fe9cea8e5799955640f79db393c1198 ("serial: 8250: convert to threaded IRQ")
url: https://github.com/0day-ci/linux/commits/Denys-Zagorui/serial-8250-convert-to-threaded-IRQ/20171112-140607
base: https://git.kernel.org/cgit/linux/kernel/git/gregkh/tty.git tty-testing
in testcase: trinity
with following parameters:
runtime: 300s
test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/
on test machine: qemu-system-x86_64 -enable-kvm -cpu kvm64,+ssse3 -m 1G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+-------------------------------------------------+------------+------------+
| | 9ce99a3a92 | b5c545ac2f |
+-------------------------------------------------+------------+------------+
| boot_successes | 4 | 0 |
| boot_failures | 1 | 8 |
| BUG:kernel_hang_in_test_stage | 1 | |
| WARNING:inconsistent_lock_state | 0 | 8 |
| inconsistent{IN-HARDIRQ-W}->{HARDIRQ-ON-W}usage | 0 | 3 |
| inconsistent{HARDIRQ-ON-W}->{IN-HARDIRQ-W}usage | 0 | 5 |
| RIP:__do_softirq | 0 | 1 |
| RIP:lock_acquire | 0 | 1 |
| calltrace:irq_exit | 0 | 3 |
| RIP:e1000_watchdog | 0 | 3 |
| RIP:_raw_spin_unlock_irq | 0 | 1 |
| RIP:__slab_alloc | 0 | 1 |
+-------------------------------------------------+------------+------------+
[ 400.767768] WARNING: inconsistent lock state
[ 400.767770] 4.14.0-rc4-00096-gb5c545ac2 #5 Not tainted
[ 400.767772] --------------------------------
[ 400.768030] inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
[ 400.768287] systemd-journal/2162 [HC1[1]:SC1[1]:HE0:SE0] takes:
[ 400.768289] (&port_lock_key){?.+.}, at: [<ffffffffa06d678b>] serial8250_console_write+0x91/0x1f4
[ 400.768318] {HARDIRQ-ON-W} state was registered at:
[ 400.768320] __lock_acquire+0x3a4/0x822
[ 400.768322] lock_acquire+0x142/0x1dd
[ 400.768323] _raw_spin_lock+0x34/0x6a
[ 400.768906] serial8250_handle_irq+0x25/0xbc
[ 400.768929] serial8250_default_handle_irq+0x28/0x3a
[ 400.768931] serial8250_interrupt+0x3e/0xa8
[ 400.768933] irq_thread_fn+0x1d/0x34
[ 400.768935] irq_thread+0xe6/0x19c
[ 400.768936] kthread+0x172/0x17a
[ 400.768938] ret_from_fork+0x2a/0x40
[ 400.768960] irq event stamp: 181597
[ 400.768963] hardirqs last enabled at (181596): [<ffffffffa0dc382d>] _raw_spin_unlock_irq+0x2c/0x3d
[ 400.768966] hardirqs last disabled at (181597): [<ffffffffa0dc5ab8>] apic_timer_interrupt+0x98/0xb0
[ 400.768969] softirqs last enabled at (181562): [<ffffffffa0dc7fd6>] __do_softirq+0x376/0x45f
[ 400.768971] softirqs last disabled at (181585): [<ffffffffa00a59e5>] irq_exit+0x5d/0xb4
[ 400.768993]
[ 400.768995] other info that might help us debug this:
[ 400.768997] Possible unsafe locking scenario:
[ 400.768998]
[ 400.769000] CPU0
[ 400.769001] ----
[ 400.769003] lock(&port_lock_key);
[ 400.769028] <Interrupt>
[ 400.769029] lock(&port_lock_key);
[ 400.769033]
[ 400.769035] *** DEADLOCK ***
[ 400.769036]
[ 400.769058] 2 locks held by systemd-journal/2162:
[ 400.769059] #0: (&p->lock){+.+.}, at: [<ffffffffa0231d06>] seq_read+0x3c/0x333
[ 400.769067] #1: (console_lock){+.+.}, at: [<ffffffffa00ff67c>] vprintk_emit+0x264/0x2c2
[ 400.769095]
[ 400.769096] stack backtrace:
[ 400.769099] CPU: 0 PID: 2162 Comm: systemd-journal Not tainted 4.14.0-rc4-00096-gb5c545ac2 #5
[ 400.769122] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 400.769124] Call Trace:
[ 400.769125] <IRQ>
[ 400.769127] dump_stack+0x86/0xc0
[ 400.769129] print_usage_bug+0x247/0x256
[ 400.769131] ? check_usage_backwards+0x106/0x106
[ 400.769133] mark_lock+0x345/0x504
[ 400.769155] __lock_acquire+0x343/0x822
[ 400.769157] lock_acquire+0x142/0x1dd
[ 400.769159] ? serial8250_console_write+0x91/0x1f4
[ 400.769161] _raw_spin_lock_irqsave+0x4d/0x88
[ 400.769163] ? serial8250_console_write+0x91/0x1f4
[ 400.769165] serial8250_console_write+0x91/0x1f4
[ 400.769187] ? console_unlock+0x1f7/0x4d6
[ 400.769189] univ8250_console_write+0x21/0x23
[ 400.769191] console_unlock+0x3fe/0x4d6
[ 400.769193] vprintk_emit+0x26d/0x2c2
[ 400.769195] vprintk_default+0x1d/0x1f
[ 400.769196] vprintk_func+0x57/0x59
[ 400.769198] printk+0x43/0x4b
[ 400.769221] hrtimer_interrupt+0x194/0x1a3
[ 400.769223] smp_apic_timer_interrupt+0x12f/0x2a9
[ 400.769225] apic_timer_interrupt+0x9d/0xb0
[ 400.769227] RIP: 0010:_raw_spin_unlock_irq+0x33/0x3d
[ 400.769229] RSP: 0018:ffff8a1a35003e70 EFLAGS: 00000206 ORIG_RAX: ffffffffffffff10
[ 400.769255] RAX: ffff8a1a3df4c040 RBX: ffff8a1a351d2a00 RCX: ffff8a1a35003dd8
[ 400.769257] RDX: 0000000000000002 RSI: ffff8a1a3df4c928 RDI: ffff8a1a3df4c040
[ 400.769260] RBP: ffff8a1a35003e78 R08: 0000006d323b831d R09: 0000000000000000
[ 400.769262] R10: 0000000000000001 R11: 0000000000000000 R12: 00000000ffffffff
[ 400.769285] R13: 00000000ffffffff R14: ffffffffa1405188 R15: 0000000000000001
[ 400.769287] run_timer_softirq+0x80/0x89
[ 400.769289] ? _raw_spin_unlock_irq+0x33/0x3d
[ 400.769291] run_timer_softirq+0x8f/0x98
[ 400.769293] __do_softirq+0x1d1/0x45f
[ 400.769294] irq_exit+0x5d/0xb4
[ 400.769317] smp_apic_timer_interrupt+0x1f0/0x2a9
[ 400.769319] apic_timer_interrupt+0x9d/0xb0
[ 400.769320] </IRQ>
[ 400.769322] RIP: 0010:__slab_alloc+0x73/0x84
[ 400.769324] RSP: 0018:ffffafd24044fd10 EFLAGS: 00000282 ORIG_RAX: ffffffffffffff10
[ 400.769349] RAX: ffff8a1a3df4c040 RBX: 0000000000000282 RCX: ffffafd24044fcb8
[ 400.769352] RDX: ffffffffa0071b03 RSI: ffff8a1a3df4c928 RDI: 0000000000000282
[ 400.769354] RBP: ffffafd24044fd40 R08: 0000006d3168b9e5 R09: 0000000000000001
[ 400.769357] R10: ffffafd24044fd10 R11: ffff8a1a3df4c040 R12: ffff8a1a3be75698
[ 400.769359] R13: 00000000ffffffff R14: 0000000000000000 R15: ffff8a1a34c04300
[ 400.769381] ? save_stack_trace+0x1b/0x1d
[ 400.769383] ? kvmalloc_node+0x4d/0x73
[ 400.769385] __kmalloc_node+0xe9/0x35d
[ 400.769387] ? kvmalloc_node+0x4d/0x73
[ 400.769389] kvmalloc_node+0x4d/0x73
[ 400.769390] seq_buf_alloc+0x16/0x18
[ 400.769392] seq_read+0xc7/0x333
[ 400.769414] ? __seccomp_filter+0x3c/0x3d5
[ 400.769416] __vfs_read+0x26/0x10b
[ 400.769418] vfs_read+0xba/0x146
[ 400.769419] SyS_read+0x51/0x8e
[ 400.769421] do_syscall_64+0x69/0x15f
[ 400.769423] entry_SYSCALL64_slow_path+0x25/0x25
[ 400.769425] RIP: 0033:0x7ff8a51df060
[ 400.769447] RSP: 002b:00007ffc0cee8778 EFLAGS: 00000246 ORIG_RAX: 0000000000000000
[ 400.769452] RAX: ffffffffffffffda RBX: 000055f171bc3200 RCX: 00007ff8a51df060
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,
lkp
View attachment "config-4.14.0-rc4-00096-gb5c545ac2" of type "text/plain" (119003 bytes)
View attachment "job-script" of type "text/plain" (3967 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (20684 bytes)
View attachment "trinity" of type "text/plain" (9641 bytes)
Powered by blists - more mailing lists