[<prev] [next>] [day] [month] [year] [list]
Message-ID: <20181012085809.GM13396@shao2-debian>
Date: Fri, 12 Oct 2018 16:58:09 +0800
From: kernel test robot <rong.a.chen@...el.com>
To: Jens Axboe <axboe@...nel.dk>
Cc: LKML <linux-kernel@...r.kernel.org>, Jens Axboe <axboe@...com>,
Jens Axboe <axboe@...nel.dk>, lkp@...org
Subject: [LKp] [ide] ea83e583f1: WARNING:inconsistent_lock_state
FYI, we noticed the following commit (built with gcc-7):
commit: ea83e583f1d684cf93f8b33f31f3aebb43724bdc ("ide: convert to blk-mq")
https://git.kernel.org/cgit/linux/kernel/git/axboe/linux-block.git mq-conversions
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 host -smp 2 -m 4G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+---------------------------------------------------------+------------+------------+
| | 4832dd7367 | ea83e583f1 |
+---------------------------------------------------------+------------+------------+
| boot_successes | 0 | 0 |
| boot_failures | 18 | 24 |
| invoked_oom-killer:gfp_mask=0x | 3 | 6 |
| Mem-Info | 3 | 6 |
| Out_of_memory_and_no_killable_processes | 2 | 6 |
| Kernel_panic-not_syncing:System_is_deadlocked_on_memory | 2 | 6 |
| WARNING:possible_recursive_locking_detected | 16 | |
| WARNING:at_net/sched/sch_generic.c:#dev_watchdog | 1 | |
| RIP:dev_watchdog | 1 | |
| RIP:__asan_load4 | 1 | |
| WARNING:inconsistent_lock_state | 0 | 18 |
| inconsistent{HARDIRQ-ON-W}->{IN-HARDIRQ-W}usage | 0 | 18 |
| RIP:lock_release | 0 | 1 |
| RIP:lock_acquire | 0 | 2 |
| calltrace:copy_process | 0 | 7 |
| RIP:ide_output_data | 0 | 10 |
| RIP:lock_is_held_type | 0 | 1 |
| RIP:native_safe_halt | 0 | 4 |
| calltrace:irq_exit | 0 | 3 |
+---------------------------------------------------------+------------+------------+
[ 200.533480] WARNING: inconsistent lock state
[ 200.534065] 4.19.0-rc7-00021-gea83e58 #1 Not tainted
[ 200.534699] --------------------------------
[ 200.534699] inconsistent {HARDIRQ-ON-W} -> {IN-HARDIRQ-W} usage.
[ 200.534699] lock_torture_wr/127 [HC1[1]:SC0[0]:HE0:SE1] takes:
[ 200.534699] (____ptrval____) (&(&dd->lock)->rlock){?.+.}, at: dd_insert_requests+0x67/0x400
[ 200.534699] {HARDIRQ-ON-W} state was registered at:
[ 200.534699] lock_acquire+0x13b/0x2b0
[ 200.534699] _raw_spin_lock+0x2f/0x40
[ 200.534699] dd_bio_merge+0x9f/0x100
[ 200.534699] __blk_mq_sched_bio_merge+0x111/0x1f0
[ 200.534699] blk_mq_make_request+0x453/0xca0
[ 200.534699] generic_make_request+0x3a1/0x6c0
[ 200.534699] submit_bio+0xbc/0x1d0
[ 200.534699] submit_bh_wbc+0x262/0x290
[ 200.534699] block_read_full_page+0x3cd/0x630
[ 200.534699] blkdev_readpage+0x18/0x20
[ 200.534699] do_read_cache_page+0x220/0x510
[ 200.534699] read_cache_page+0x40/0x50
[ 200.534699] read_dev_sector+0x64/0x180
[ 200.534699] sgi_partition+0xca/0x490
[ 200.534699] check_partition+0x1a7/0x340
[ 200.534699] rescan_partitions+0x13c/0x4f0
[ 200.534699] __blkdev_get+0x5e7/0x990
[ 200.534699] blkdev_get+0x231/0x5a0
[ 200.534699] __device_add_disk+0x771/0x7c0
[ 200.534699] device_add_disk+0x13/0x20
[ 200.534699] virtblk_probe+0xbea/0x1050
[ 200.534699] virtio_dev_probe+0x25e/0x390
[ 200.534699] really_probe+0x2d5/0x400
[ 200.534699] driver_probe_device+0xc2/0xe0
[ 200.534699] __driver_attach+0x13a/0x140
[ 200.534699] bus_for_each_dev+0x105/0x160
[ 200.534699] driver_attach+0x2b/0x30
[ 200.534699] bus_add_driver+0x278/0x310
[ 200.534699] driver_register+0xdc/0x1d0
[ 200.534699] register_virtio_driver+0x3c/0x60
[ 200.534699] init+0x5f/0x88
[ 200.534699] do_one_initcall+0x178/0x37e
[ 200.534699] kernel_init_freeable+0x512/0x5a8
[ 200.534699] kernel_init+0x13/0x130
[ 200.534699] ret_from_fork+0x24/0x30
[ 200.534699] irq event stamp: 49456
[ 200.534699] hardirqs last enabled at (49455): [<ffffffff83f7046c>] _raw_spin_unlock_irq+0x2c/0x60
[ 200.534699] hardirqs last disabled at (49456): [<ffffffff81002026>] trace_hardirqs_off_thunk+0x1a/0x1c
[ 200.534699] softirqs last enabled at (49448): [<ffffffff84200362>] __do_softirq+0x362/0x600
[ 200.534699] softirqs last disabled at (49441): [<ffffffff810c44d9>] irq_exit+0x119/0x130
[ 200.534699]
[ 200.534699] other info that might help us debug this:
[ 200.534699] Possible unsafe locking scenario:
[ 200.534699]
[ 200.534699] CPU0
[ 200.534699] ----
[ 200.534699] lock(&(&dd->lock)->rlock);
[ 200.534699] <Interrupt>
[ 200.534699] lock(&(&dd->lock)->rlock);
[ 200.534699]
[ 200.534699] *** DEADLOCK ***
[ 200.534699]
[ 200.534699] no locks held by lock_torture_wr/127.
[ 200.534699]
[ 200.534699] stack backtrace:
[ 200.534699] CPU: 1 PID: 127 Comm: lock_torture_wr Not tainted 4.19.0-rc7-00021-gea83e58 #1
[ 200.534699] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1 04/01/2014
[ 200.534699] Call Trace:
[ 200.534699] <IRQ>
[ 200.534699] dump_stack+0x10a/0x195
[ 200.534699] print_usage_bug+0x321/0x338
[ 200.534699] mark_lock+0x8c0/0x9a0
[ 200.534699] ? check_usage_backwards+0x210/0x210
[ 200.534699] __lock_acquire+0x1205/0x27b0
[ 200.534699] ? debug_show_all_locks+0x210/0x210
[ 200.534699] ? __lock_acquire+0x5c9/0x27b0
[ 200.534699] ? debug_show_all_locks+0x210/0x210
[ 200.534699] ? __lock_acquire+0x5c9/0x27b0
[ 200.534699] lock_acquire+0x13b/0x2b0
[ 200.534699] ? debug_lockdep_rcu_enabled+0x1a/0x30
[ 200.534699] ? lock_acquire+0x13b/0x2b0
[ 200.534699] ? dd_insert_requests+0x67/0x400
[ 200.534699] _raw_spin_lock+0x2f/0x40
[ 200.534699] ? dd_insert_requests+0x67/0x400
[ 200.534699] dd_insert_requests+0x67/0x400
[ 200.534699] blk_mq_sched_insert_request+0x28b/0x340
[ 200.534699] ? blk_mq_sched_request_inserted+0x170/0x170
[ 200.534699] ? SELECT_MASK+0x70/0x70
[ 200.534699] ? check_chain_key+0x13e/0x1f0
[ 200.534699] ide_queue_sense_rq+0x99/0xc0
[ 200.534699] cdrom_newpc_intr+0xa32/0x14b0
[ 200.534699] ? idecd_open+0xe0/0xe0
[ 200.534699] ? lock_downgrade+0x3b0/0x3b0
[ 200.534699] ? del_timer+0xa4/0xd0
[ 200.534699] ? add_timer_on+0x400/0x400
[ 200.534699] ? kasan_check_read+0x11/0x20
[ 200.534699] ? do_raw_spin_unlock+0xa8/0x140
[ 200.534699] ide_intr+0x2e6/0x460
[ 200.534699] ? idecd_open+0xe0/0xe0
[ 200.534699] ? ide_requeue_and_plug+0x70/0x70
[ 200.534699] __handle_irq_event_percpu+0x7d/0x480
[ 200.534699] handle_irq_event_percpu+0x68/0xd0
[ 200.534699] ? __handle_irq_event_percpu+0x480/0x480
[ 200.534699] ? lock_acquire+0x13b/0x2b0
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,
Rong Chen
View attachment "config-4.19.0-rc7-00021-gea83e58" of type "text/plain" (124098 bytes)
View attachment "job-script" of type "text/plain" (4009 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (24636 bytes)
View attachment "trinity" of type "text/plain" (5165 bytes)
Powered by blists - more mailing lists