Hello all,
Using the kernel v6.15-rc6 and the latest blktests (git hash 613b8377e4d3), I
observe the test case nvme/063 fails with tcp transport. Kernel reported WARN in
blk_mq_unquiesce_queue and KASAN sauf in blk_mq_queue_tag_busy_iter [1]. The
failure is recreated in stable manner on my test nodes.
The test case script had a bug then this failure was not found until the bug get
fixed. I tried the kernel v6.15-rc1, and observed the same failure symptom. This
test case cannot be run with the kernel v6.14, since it does not have secure
concatenation feature.
Actions for fix will be appreciated.
[1]
[ 488.383002] [ T1083] run blktests nvme/063 at 2025-05-16 21:22:03
[ 488.470839] [ T1194] nvmet: adding nsid 1 to subsystem blktests-subsystem-1
[ 488.479069] [ T1195] nvmet: Allow non-TLS connections while TLS1.3 is enabled
[ 488.485222] [ T1198] nvmet_tcp: enabling port 0 (127.0.0.1:4420)
[ 488.607352] [ T1209] nvme nvme1: failed to connect socket: -512
[ 488.616211] [ T111] nvmet_tcp: failed to allocate queue, error -107
[ 488.623181] [ T98] nvmet: Created nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349 with DH-HMAC-CHAP.
[ 488.639788] [ T48] nvme nvme1: qid 0: authenticated with hash hmac(sha256) dhgroup ffdhe2048
[ 488.640943] [ T1209] nvme nvme1: qid 0: authenticated
[ 488.643129] [ T1209] nvme nvme1: Please enable CONFIG_NVME_MULTIPATH for full support of multi-port devices.
[ 488.707387] [ T117] nvmet: Created nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349, TLS.
[ 488.710650] [ T1209] nvme nvme1: Please enable CONFIG_NVME_MULTIPATH for full support of multi-port devices.
[ 488.711363] [ T1209] nvme nvme1: creating 4 I/O queues.
[ 488.727670] [ T1209] nvme nvme1: mapped 4/0/0 default/read/poll queues.
[ 488.730042] [ T1209] nvme nvme1: new ctrl: NQN "blktests-subsystem-1", addr 127.0.0.1:4420, hostnqn: nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349
[ 488.794602] [ T1246] nvme nvme1: resetting controller
[ 488.801319] [ T224] nvmet: Created nvm controller 2 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349 with DH-HMAC-CHAP.
[ 488.817111] [ T1247] nvme nvme1: qid 0: authenticated with hash hmac(sha256) dhgroup ffdhe2048
[ 488.817872] [ T111] nvme nvme1: qid 0: authenticated
[ 488.819541] [ T111] nvme nvme1: Please enable CONFIG_NVME_MULTIPATH for full support of multi-port devices.
[ 488.827162] [ T98] nvmet: Created nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349, TLS.
[ 488.830619] [ T111] nvme nvme1: Please enable CONFIG_NVME_MULTIPATH for full support of multi-port devices.
[ 488.831632] [ T111] nvme nvme1: creating 4 I/O queues.
[ 488.853083] [ T111] ------------[ cut here ]------------
[ 488.853350] [ T111] WARNING: CPU: 3 PID: 111 at block/blk-mq.c:330 blk_mq_unquiesce_queue+0x8f/0xb0
[ 488.853752] [ T111] Modules linked in: tls nvmet_tcp nvmet nvme_tcp nvme_fabrics nft_fib_inet nft_fib_ipv4 nft_fib_ipv6 nft_fib nft_reject_inet nf_reject_ipv4 nf_reject_ipv6 nft_reject nft_ct nft_chain_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 ip_set nf_tables qrtr sunrpc 9pnet_virtio ppdev 9pnet netfs parport_pc e1000 parport i2c_piix4 i2c_smbus pcspkr fuse loop dm_multipath nfnetlink vsock_loopback vmw_vsock_virtio_transport_common vmw_vsock_vmci_transport vsock vmw_vmci zram bochs drm_client_lib drm_shmem_helper drm_kms_helper xfs drm sym53c8xx nvme scsi_transport_spi nvme_core nvme_keyring floppy nvme_auth serio_raw ata_generic pata_acpi qemu_fw_cfg
[ 488.856850] [ T111] CPU: 3 UID: 0 PID: 111 Comm: kworker/u16:4 Not tainted 6.15.0-rc6+ #27 PREEMPT(voluntary)
[ 488.857366] [ T111] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-3.fc41 04/01/2014
[ 488.857832] [ T111] Workqueue: nvme-reset-wq nvme_reset_ctrl_work [nvme_tcp]
[ 488.858253] [ T111] RIP: 0010:blk_mq_unquiesce_queue+0x8f/0xb0
[ 488.858536] [ T111] Code: 01 48 89 de bf 09 00 00 00 e8 3d 92 fc ff 48 89 ee 4c 89 e7 e8 e2 d7 81 01 48 89 df be 01 00 00 00 5b 5d 41 5c e9 b1 fb ff ff <0f> 0b 5b 48 89 ee 4c 89 e7 5d 41 5c e9 c0 d7 81 01 e8 eb 1f 83 ff
[ 488.859493] [ T111] RSP: 0018:ffff88812090fb58 EFLAGS: 00010046
[ 488.859791] [ T111] RAX: 0000000000000000 RBX: ffff8881249b4e00 RCX: ffffffff8a6b8369
[ 488.860197] [ T111] RDX: 0000000000000000 RSI: 0000000000000004 RDI: ffff8881249b4f50
[ 488.861504] [ T111] RBP: 0000000000000246 R08: 0000000000000001 R09: ffffed1024121f59
[ 488.862741] [ T111] R10: 0000000000000003 R11: 0000000000000000 R12: ffff8881249b4f10
[ 488.864004] [ T111] R13: ffff888105178108 R14: ffff888105178348 R15: ffff888105178450
[ 488.866593] [ T111] FS: 0000000000000000(0000) GS:ffff88840f9bf000(0000) knlGS:0000000000000000
[ 488.867757] [ T111] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 488.868787] [ T111] CR2: 000056091c302598 CR3: 000000013a27a000 CR4: 00000000000006f0
[ 488.869883] [ T111] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 488.871019] [ T111] DR3: 0000000000000000 DR6: 00000000ffff07f0 DR7: 0000000000000400
[ 488.872141] [ T111] Call Trace:
[ 488.872974] [ T111] <TASK>
[ 488.873852] [ T111] blk_mq_unquiesce_tagset+0xaf/0xe0
[ 488.874869] [ T111] nvme_tcp_setup_ctrl.cold+0x6f2/0xc89 [nvme_tcp]
[ 488.876002] [ T111] ? __pfx_nvme_tcp_setup_ctrl+0x10/0x10 [nvme_tcp]
[ 488.877077] [ T111] ? _raw_spin_unlock_irqrestore+0x35/0x60
[ 488.878130] [ T111] ? nvme_change_ctrl_state+0x196/0x2e0 [nvme_core]
[ 488.879169] [ T111] nvme_reset_ctrl_work+0x1a1/0x250 [nvme_tcp]
[ 488.880128] [ T111] process_one_work+0x84f/0x1460
[ 488.882033] [ T111] ? __pfx_process_one_work+0x10/0x10
[ 488.883129] [ T111] ? assign_work+0x16c/0x240
[ 488.884118] [ T111] worker_thread+0x5ef/0xfd0
[ 488.885099] [ T111] ? __kthread_parkme+0xb4/0x200
[ 488.886073] [ T111] ? __pfx_worker_thread+0x10/0x10
[ 488.886960] [ T111] kthread+0x3b0/0x770
[ 488.887836] [ T111] ? __pfx_kthread+0x10/0x10
[ 488.888698] [ T111] ? ret_from_fork+0x17/0x70
[ 488.889579] [ T111] ? ret_from_fork+0x17/0x70
[ 488.890395] [ T111] ? _raw_spin_unlock_irq+0x24/0x50
[ 488.891199] [ T111] ? __pfx_kthread+0x10/0x10
[ 488.891979] [ T111] ret_from_fork+0x30/0x70
[ 488.892714] [ T111] ? __pfx_kthread+0x10/0x10
[ 488.893486] [ T111] ret_from_fork_asm+0x1a/0x30
[ 488.894207] [ T111] </TASK>
[ 488.894902] [ T111] irq event stamp: 3320
[ 488.895644] [ T111] hardirqs last enabled at (3319): [<ffffffff8ce969c4>] _raw_spin_unlock_irq+0x24/0x50
[ 488.896485] [ T111] hardirqs last disabled at (3320): [<ffffffff8ce77f6d>] __schedule+0x2fad/0x5fa0
[ 488.897480] [ T111] softirqs last enabled at (2838): [<ffffffff8a516d99>] __irq_exit_rcu+0x109/0x210
[ 488.899945] [ T111] softirqs last disabled at (2833): [<ffffffff8a516d99>] __irq_exit_rcu+0x109/0x210
[ 488.900981] [ T111] ---[ end trace 0000000000000000 ]---
[ 488.906709] [ T111] nvme nvme1: mapped 4/0/0 default/read/poll queues.
[ 488.926409] [ T1265] nvme nvme1: Removing ctrl: NQN "blktests-subsystem-1"
[ 489.195387] [ T67] nvmet: Created nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349 with DH-HMAC-CHAP.
[ 489.212205] [ T1247] nvme nvme1: qid 0: authenticated with hash hmac(sha384) dhgroup ffdhe3072
[ 489.214003] [ T1278] nvme nvme1: qid 0: authenticated
[ 489.216353] [ T1278] nvme nvme1: Please enable CONFIG_NVME_MULTIPATH for full support of multi-port devices.
[ 489.218537] [ T1278] nvme nvme1: failed to connect socket: -512
[ 489.226758] [ T111] nvmet_tcp: failed to allocate queue, error -107
[ 489.232297] [ T1262] nvmet: Created nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349 with DH-HMAC-CHAP.
[ 489.254966] [ T111] nvme nvme1: qid 0: authenticated with hash hmac(sha384) dhgroup ffdhe3072
[ 489.256783] [ T1278] nvme nvme1: qid 0: authenticated
[ 489.258606] [ T1278] nvme nvme1: Please enable CONFIG_NVME_MULTIPATH for full support of multi-port devices.
[ 489.309468] [ T224] nvmet: Created nvm controller 1 for subsystem blktests-subsystem-1 for NQN nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349, TLS.
[ 489.313302] [ T1278] nvme nvme1: Please enable CONFIG_NVME_MULTIPATH for full support of multi-port devices.
[ 489.315374] [ T1278] nvme nvme1: creating 4 I/O queues.
[ 489.337242] [ T1278] nvme nvme1: mapped 4/0/0 default/read/poll queues.
[ 489.341639] [ T1278] nvme nvme1: new ctrl: NQN "blktests-subsystem-1", addr 127.0.0.1:4420, hostnqn: nqn.2014-08.org.nvmexpress:uuid:0f01fb42-9f7f-4856-b0b3-51e60b8de349
[ 489.421601] [ T1317] nvme nvme1: Removing ctrl: NQN "blktests-subsystem-1"
[ 495.597732] [ T67] ==================================================================
[ 495.598765] [ T67] BUG: KASAN: slab-use-after-free in blk_mq_queue_tag_busy_iter+0x1287/0x13a0
[ 495.599885] [ T67] Read of size 4 at addr ffff888127a0c184 by task kworker/3:1H/67
[ 495.601693] [ T67] CPU: 3 UID: 0 PID: 67 Comm: kworker/3:1H Tainted: G W 6.15.0-rc6+ #27 PREEMPT(voluntary)
[ 495.601698] [ T67] Tainted: [W]=WARN
[ 495.601699] [ T67] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.3-3.fc41 04/01/2014
[ 495.601708] [ T67] Workqueue: kblockd blk_mq_timeout_work
[ 495.601715] [ T67] Call Trace:
[ 495.601718] [ T67] <TASK>
[ 495.601720] [ T67] dump_stack_lvl+0x6a/0x90
[ 495.601724] [ T67] print_report+0x174/0x554
[ 495.601733] [ T67] ? __virt_addr_valid+0x208/0x420
[ 495.601743] [ T67] ? blk_mq_queue_tag_busy_iter+0x1287/0x13a0
[ 495.601745] [ T67] kasan_report+0xae/0x170
[ 495.601751] [ T67] ? blk_mq_queue_tag_busy_iter+0x1287/0x13a0
[ 495.601754] [ T67] blk_mq_queue_tag_busy_iter+0x1287/0x13a0
[ 495.601757] [ T67] ? __pfx_blk_mq_check_expired+0x10/0x10
[ 495.601759] [ T67] ? update_load_avg+0x240/0x2170
[ 495.601767] [ T67] ? kvm_sched_clock_read+0xd/0x20
[ 495.601770] [ T67] ? sched_clock+0xc/0x30
[ 495.601775] [ T67] ? sched_clock_cpu+0x68/0x540
[ 495.601779] [ T67] ? __pfx_blk_mq_queue_tag_busy_iter+0x10/0x10
[ 495.601780] [ T67] ? __pfx_sched_clock_cpu+0x10/0x10
[ 495.601782] [ T67] ? psi_task_switch+0x2c1/0x8a0
[ 495.601784] [ T67] ? rcu_is_watching+0x11/0xb0
[ 495.601787] [ T67] ? lock_release+0x217/0x2c0
[ 495.601793] [ T67] ? rcu_is_watching+0x11/0xb0
[ 495.601795] [ T67] ? blk_mq_timeout_work+0x137/0x550
[ 495.601797] [ T67] ? rcu_is_watching+0x11/0xb0
[ 495.601799] [ T67] ? lock_release+0x217/0x2c0
[ 495.601802] [ T67] blk_mq_timeout_work+0x15f/0x550
[ 495.601804] [ T67] ? __pfx_blk_mq_timeout_work+0x10/0x10
[ 495.601807] [ T67] ? lock_acquire+0x2b2/0x310
[ 495.601809] [ T67] ? rcu_is_watching+0x11/0xb0
[ 495.601811] [ T67] ? _raw_spin_unlock_irq+0x24/0x50
[ 495.601814] [ T67] process_one_work+0x84f/0x1460
[ 495.601818] [ T67] ? __pfx_process_one_work+0x10/0x10
[ 495.601822] [ T67] ? assign_work+0x16c/0x240
[ 495.601825] [ T67] worker_thread+0x5ef/0xfd0
[ 495.601828] [ T67] ? __kthread_parkme+0xb4/0x200
[ 495.601831] [ T67] ? __pfx_worker_thread+0x10/0x10
[ 495.601833] [ T67] kthread+0x3b0/0x770
[ 495.601836] [ T67] ? __pfx_kthread+0x10/0x10
[ 495.601838] [ T67] ? ret_from_fork+0x17/0x70
[ 495.601839] [ T67] ? ret_from_fork+0x17/0x70
[ 495.601841] [ T67] ? _raw_spin_unlock_irq+0x24/0x50
[ 495.601843] [ T67] ? __pfx_kthread+0x10/0x10
[ 495.601845] [ T67] ret_from_fork+0x30/0x70
[ 495.601847] [ T67] ? __pfx_kthread+0x10/0x10
[ 495.601849] [ T67] ret_from_fork_asm+0x1a/0x30
[ 495.601853] [ T67] </TASK>
[ 495.637098] [ T67] Allocated by task 1278:
[ 495.637607] [ T67] kasan_save_stack+0x2c/0x50
[ 495.638142] [ T67] kasan_save_track+0x10/0x30
[ 495.638660] [ T67] __kasan_kmalloc+0xa6/0xb0
[ 495.639163] [ T67] 0xffffffffc17c6fce
[ 495.639630] [ T67] 0xffffffffc0ff389b
[ 495.640099] [ T67] vfs_write+0x218/0xe90
[ 495.640576] [ T67] ksys_write+0xf5/0x1c0
[ 495.641053] [ T67] do_syscall_64+0x93/0x190
[ 495.641551] [ T67] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 495.642492] [ T67] Freed by task 1278:
[ 495.642956] [ T67] kasan_save_stack+0x2c/0x50
[ 495.643464] [ T67] kasan_save_track+0x10/0x30
[ 495.643973] [ T67] kasan_save_free_info+0x37/0x60
[ 495.644495] [ T67] __kasan_slab_free+0x4b/0x70
[ 495.645004] [ T67] kfree+0x13a/0x4b0
[ 495.645456] [ T67] nvme_free_ctrl+0x3bc/0x5c0 [nvme_core]
[ 495.646041] [ T67] device_release+0x9b/0x210
[ 495.646525] [ T67] kobject_put+0x17b/0x4a0
[ 495.646994] [ T67] 0xffffffffc17c77fd
[ 495.647457] [ T67] 0xffffffffc0ff389b
[ 495.647908] [ T67] vfs_write+0x218/0xe90
[ 495.648383] [ T67] ksys_write+0xf5/0x1c0
[ 495.648848] [ T67] do_syscall_64+0x93/0x190
[ 495.649341] [ T67] entry_SYSCALL_64_after_hwframe+0x76/0x7e
[ 495.650274] [ T67] The buggy address belongs to the object at ffff888127a0c000
which belongs to the cache kmalloc-8k of size 8192
[ 495.651564] [ T67] The buggy address is located 388 bytes inside of
freed 8192-byte region [ffff888127a0c000, ffff888127a0e000)
[ 495.653224] [ T67] The buggy address belongs to the physical page:
[ 495.653849] [ T67] page: refcount:0 mapcount:0 mapping:0000000000000000 index:0x0 pfn:0x127a08
[ 495.654646] [ T67] head: order:3 mapcount:0 entire_mapcount:0 nr_pages_mapped:0 pincount:0
[ 495.655416] [ T67] flags: 0x17ffffc0000040(head|node=0|zone=2|lastcpupid=0x1fffff)
[ 495.656150] [ T67] page_type: f5(slab)
[ 495.656624] [ T67] raw: 0017ffffc0000040 ffff888100043180 ffffea0004b1d200 0000000000000006
[ 495.657407] [ T67] raw: 0000000000000000 0000000080020002 00000000f5000000 0000000000000000
[ 495.658193] [ T67] head: 0017ffffc0000040 ffff888100043180 ffffea0004b1d200 0000000000000006
[ 495.658994] [ T67] head: 0000000000000000 0000000080020002 00000000f5000000 0000000000000000
[ 495.659789] [ T67] head: 0017ffffc0000003 ffffea00049e8201 00000000ffffffff 00000000ffffffff
[ 495.660597] [ T67] head: ffffffffffffffff 0000000000000000 00000000ffffffff 0000000000000008
[ 495.661417] [ T67] page dumped because: kasan: bad access detected
[ 495.662501] [ T67] Memory state around the buggy address:
[ 495.663108] [ T67] ffff888127a0c080: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 495.663871] [ T67] ffff888127a0c100: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 495.664649] [ T67] >ffff888127a0c180: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 495.665430] [ T67] ^
[ 495.665964] [ T67] ffff888127a0c200: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 495.666747] [ T67] ffff888127a0c280: fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb fb
[ 495.667570] [ T67] ==================================================================
