Re: BUG: KASAN: use-after-free in bt_for_each+0x1ea/0x29f
On Wed, 2018-04-04 at 19:26 -0600, Jens Axboe wrote: > Leaving the whole trace here, but I'm having a hard time making sense of it. > It complains about a user-after-free in the inflight iteration, which is only > working on the queue, request, and on-stack mi data. None of these would be > freed. The below trace on allocation and free indicates a bio, but that isn't > used in the inflight path at all. Is it possible that kasan gets confused > here? > Not sure what to make of it so far. Hello Jens, In the many block layer tests I ran with KASAN enabled I have never seen anything like this nor have I seen anything that made me wonder about the reliability of KASAN. Maybe some code outside the block layer core corrupted a request queue data structure and triggered this weird report? Bart.
Re: BUG: KASAN: use-after-free in bt_for_each+0x1ea/0x29f
On 4/4/18 5:28 PM, Ming Lei wrote: > Hi, > > The following warning is observed once when running dbench on NVMe with > the linus tree(top commit is 642e7fd23353). > > [ 1446.882043] > == > [ 1446.886884] BUG: KASAN: use-after-free in bt_for_each+0x1ea/0x29f > [ 1446.888045] Read of size 8 at addr 880055a60a00 by task dbench/13443 > [ 1446.889660] > [ 1446.889892] CPU: 1 PID: 13443 Comm: dbench Not tainted > 4.16.0_642e7fd23353_master+ #1 > [ 1446.891007] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS > 1.10.2-2.fc27 04/01/2014 > [ 1446.892290] Call Trace: > [ 1446.892641] > [ 1446.892937] dump_stack+0xf0/0x191 > [ 1446.893600] ? dma_direct_map_page+0x6f/0x6f > [ 1446.894425] ? show_regs_print_info+0xa/0xa > [ 1446.895247] ? ext4_writepages+0x196d/0x1e6d > [ 1446.896063] ? do_writepages+0x57/0xa3 > [ 1446.896810] print_address_description+0x6e/0x23b > [ 1446.897882] ? bt_for_each+0x1ea/0x29f > [ 1446.898693] kasan_report+0x247/0x285 > [ 1446.899484] bt_for_each+0x1ea/0x29f > [ 1446.900233] ? blk_mq_tagset_busy_iter+0xa3/0xa3 > [ 1446.901190] ? generic_file_buffered_read+0x14b1/0x14b1 > [ 1446.903097] ? blk_mq_hctx_mark_pending.isra.0+0x5c/0x5c > [ 1446.904418] ? bio_free+0x64/0xaa > [ 1446.905113] ? debug_lockdep_rcu_enabled+0x26/0x52 > [ 1446.906332] ? bio_put+0x7a/0x10e > [ 1446.906811] ? debug_lockdep_rcu_enabled+0x26/0x52 > [ 1446.907527] ? blk_mq_hctx_mark_pending.isra.0+0x5c/0x5c > [ 1446.908334] blk_mq_queue_tag_busy_iter+0xd0/0xde > [ 1446.909023] blk_mq_in_flight+0xb4/0xdb > [ 1446.909619] ? blk_mq_exit_hctx+0x190/0x190 > [ 1446.910281] ? ext4_end_bio+0x25d/0x2a1 > [ 1446.911713] part_in_flight+0xc0/0x2ac > [ 1446.912470] ? ext4_put_io_end_defer+0x277/0x277 > [ 1446.913465] ? part_dec_in_flight+0x8f/0x8f > [ 1446.914375] ? __lock_acquire+0x38/0x8e5 > [ 1446.915182] ? bio_endio+0x3d9/0x41c > [ 1446.915936] ? __rcu_read_unlock+0x134/0x180 > [ 1446.916796] ? lock_acquire+0x2ba/0x32d > [ 1446.917570] ? blk_account_io_done+0xea/0x572 > [ 1446.918424] part_round_stats+0x167/0x1a3 > [ 1446.919188] ? part_round_stats_single.isra.1+0xc7/0xc7 > [ 1446.920187] blk_account_io_done+0x34d/0x572 > [ 1446.921056] ? blk_update_bidi_request+0x8f/0x8f > [ 1446.921923] ? blk_mq_run_hw_queue+0x13d/0x187 > [ 1446.922803] blk_mq_end_request+0x3f/0xbf > [ 1446.923631] nvme_complete_rq+0x305/0x348 [nvme_core] > [ 1446.924612] ? nvme_delete_ctrl_sync+0x5c/0x5c [nvme_core] > [ 1446.925696] ? nvme_pci_complete_rq+0x1f6/0x20c [nvme] > [ 1446.926673] ? kfree+0x21c/0x2ab > [ 1446.927317] ? nvme_pci_complete_rq+0x1f6/0x20c [nvme] > [ 1446.928239] __blk_mq_complete_request+0x391/0x3ee > [ 1446.928938] ? blk_mq_free_request+0x479/0x479 > [ 1446.929588] ? rcu_read_lock_bh_held+0x3a/0x3a > [ 1446.930321] ? enqueue_hrtimer+0x252/0x29a > [ 1446.930938] ? do_raw_spin_lock+0xd8/0xd8 > [ 1446.931532] ? debug_lockdep_rcu_enabled+0x26/0x52 > [ 1446.932425] blk_mq_complete_request+0x10e/0x159 > [ 1446.933341] ? hctx_lock+0xe8/0xe8 > [ 1446.933985] ? lock_contended+0x680/0x680 > [ 1446.934707] ? lock_downgrade+0x338/0x338 > [ 1446.935463] nvme_process_cq+0x26a/0x34d [nvme] > [ 1446.936297] ? nvme_init_hctx+0xa6/0xa6 [nvme] > [ 1446.937150] nvme_irq+0x23/0x51 [nvme] > [ 1446.937864] ? nvme_process_cq+0x34d/0x34d [nvme] > [ 1446.938713] __handle_irq_event_percpu+0x29d/0x568 > [ 1446.939516] ? __irq_wake_thread+0x99/0x99 > [ 1446.940241] ? rcu_user_enter+0x72/0x72 > [ 1446.940978] ? do_timer+0x25/0x25 > [ 1446.941650] ? do_raw_spin_unlock+0x146/0x179 > [ 1446.942514] ? __lock_acquire+0x38/0x8e5 > [ 1446.943305] ? debug_lockdep_rcu_enabled+0x26/0x52 > [ 1446.944242] ? lock_acquire+0x32d/0x32d > [ 1446.944995] ? lock_contended+0x680/0x680 > [ 1446.945718] handle_irq_event_percpu+0x7c/0xf7 > [ 1446.946438] ? __handle_irq_event_percpu+0x568/0x568 > [ 1446.947124] ? rcu_user_exit+0xa/0xa > [ 1446.947781] handle_irq_event+0x53/0x83 > [ 1446.948553] handle_edge_irq+0x1f2/0x279 > [ 1446.949397] handle_irq+0x1d8/0x1e9 > [ 1446.950094] do_IRQ+0x90/0x12d > [ 1446.950750] common_interrupt+0xf/0xf > [ 1446.951507] > [ 1446.951953] RIP: 0010:__blk_mq_get_tag+0x201/0x22d > [ 1446.952894] RSP: 0018:880055b467a0 EFLAGS: 0246 ORIG_RAX: > ffdc > [ 1446.954295] RAX: RBX: 88005952f648 RCX: > > [ 1446.955641] RDX: 0259 RSI: RDI: > ed000ab68d06 > [ 1446.956972] RBP: ed000ab68cf6 R08: 0007 R09: > > [ 1446.958356] R10: ed000a0ec0f2 R11: ed000a0ec0f1 R12: > 88007f113978 > [ 1446.959737] R13: 880055b46ce8 R14: dc00 R15: > 880058bf60c0 > [ 1446.961184] ? modules_open+0x5e/0x5e > [ 1446.961922] ? blk_mq_unique_tag+0xc5/0xc5 > [ 1446.962748] ? lock_acquire+0x32d/0x32d > [ 1446.963534] ? __rcu_read_unlock+0x134/0x180 > [ 1446.964393] ?