nvme-tcp: kernel NULL pointer dereference, address: 0000000000000034

Wed Mar 15 10:48:14 PDT 2023

I'm running tests where I connect/disconnect to/from a few I/O controllers using the nvme_tcp driver. I use nvmet_tcp with a null_blk device to simulate the target. The kernel module crashes (trace below) while trying to connect over TCP. This happens on Fedora 37 and Ubuntu 22.04. I also recompiled the kernel using the latest nvme-6.4 branch and I'm still seeing the crash.

I'm not sure how to debug this further. Any suggestions?

Thanks,
Martin Belanger

Mar 15 13:30:22.954399 fedora37 kernel: nvme nvme1: failed to connect socket: -110
Mar 15 13:30:22.958393 fedora37 kernel: nvmet: creating nvm controller 2 for subsystem nqn.1988-11.com.dell:PowerSANxxx:01:20210225100113-454f73093ceb4847a7bdfc6e34ae8e28 for NQN nqn.2014-08.org.nvmexpress:uuid:f9ef75fc-1699-418f-ba45-49f9fc766e1b.
Mar 15 13:30:22.958453 fedora37 kernel: nvme nvme1: creating 12 I/O queues.
Mar 15 13:30:22.960320 fedora37 kernel: nvme nvme1: mapped 4/4/4 default/read/poll queues.
Mar 15 13:30:22.960862 fedora37 kernel: BUG: kernel NULL pointer dereference, address: 0000000000000034
Mar 15 13:30:22.960998 fedora37 kernel: #PF: supervisor read access in kernel mode
Mar 15 13:30:22.992915 fedora37 kernel: #PF: error_code(0x0000) - not-present page
Mar 15 13:30:22.994551 fedora37 kernel: PGD 0 P4D 0 
Mar 15 13:30:22.996135 fedora37 kernel: Oops: 0000 [#1] PREEMPT SMP PTI
Mar 15 13:30:22.996169 fedora37 kernel: CPU: 0 PID: 3953 Comm: pool Not tainted 6.3.0-rc1-stas+ #1
Mar 15 13:30:22.996192 fedora37 kernel: Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS VirtualBox 12/01/2006
Mar 15 13:30:22.996210 fedora37 kernel: RIP: 0010:bio_poll+0xd/0x150
Mar 15 13:30:22.996227 fedora37 kernel: Code: 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 0f 1f 44 00 00 41 56 41 55 41 54 55 53 <8b> 6f 34 48 8b 47 08 48 85 c0 0f 84 a1 00 00 00 4c 8b a8 60 03 00
Mar 15 13:30:22.996245 fedora37 kernel: RSP: 0018:ffffa561851bfae0 EFLAGS: 00010246
Mar 15 13:30:22.996266 fedora37 kernel: RAX: 0000000000000000 RBX: ffff8ff38ae60000 RCX: 0000000000000000
Mar 15 13:30:22.996311 fedora37 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
Mar 15 13:30:22.996369 fedora37 kernel: RBP: ffffa561851bfb10 R08: 0000000000000001 R09: ffff8ff38cc0e860
Mar 15 13:30:22.996410 fedora37 kernel: R10: ffff8ff3887af388 R11: 0000000000000110 R12: 0000000000000001
Mar 15 13:30:22.996430 fedora37 kernel: R13: ffff8ff38fbd9c00 R14: 0000000000000400 R15: ffffa561851bfba8
Mar 15 13:30:22.996450 fedora37 kernel: FS:  00007f9aab2ff6c0(0000) GS:ffff8ff84b400000(0000) knlGS:0000000000000000
Mar 15 13:30:22.996467 fedora37 kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Mar 15 13:30:22.996484 fedora37 kernel: CR2: 0000000000000034 CR3: 000000011439e002 CR4: 00000000000706f0
Mar 15 13:30:22.996501 fedora37 kernel: Call Trace:
Mar 15 13:30:22.996518 fedora37 kernel:  <TASK>
Mar 15 13:30:22.996535 fedora37 kernel:  blk_execute_rq+0xc9/0x190
Mar 15 13:30:22.996552 fedora37 kernel:  __nvme_submit_sync_cmd+0xa5/0x160 [nvme_core]
Mar 15 13:30:22.996572 fedora37 kernel:  nvmf_connect_io_queue+0x10b/0x200 [nvme_fabrics]
Mar 15 13:30:22.996589 fedora37 kernel:  nvme_tcp_start_queue+0x1a/0x90 [nvme_tcp]
Mar 15 13:30:22.996606 fedora37 kernel:  nvme_tcp_setup_ctrl+0x410/0x7e0 [nvme_tcp]
Mar 15 13:30:22.996626 fedora37 kernel:  nvme_tcp_create_ctrl+0x34f/0x460 [nvme_tcp]
Mar 15 13:30:22.996643 fedora37 kernel:  nvmf_dev_write+0x5da/0xec0 [nvme_fabrics]
Mar 15 13:30:22.996660 fedora37 kernel:  ? selinux_file_permission+0x10b/0x150
Mar 15 13:30:22.996675 fedora37 kernel:  vfs_write+0xb9/0x3e0
Mar 15 13:30:22.996690 fedora37 kernel:  ? __fget_light+0x9d/0x100
Mar 15 13:30:22.996706 fedora37 kernel:  ksys_write+0x5b/0xd0
Mar 15 13:30:22.996721 fedora37 kernel:  do_syscall_64+0x5b/0x80
Mar 15 13:30:22.996735 fedora37 kernel:  ? ksys_write+0xb4/0xd0
Mar 15 13:30:22.996752 fedora37 kernel:  ? syscall_exit_to_user_mode+0x17/0x40
Mar 15 13:30:22.996769 fedora37 kernel:  ? do_syscall_64+0x67/0x80
Mar 15 13:30:22.996788 fedora37 kernel:  ? preempt_count_add+0x47/0xa0
Mar 15 13:30:22.996808 fedora37 kernel:  ? up_read+0x37/0x70
Mar 15 13:30:22.996823 fedora37 kernel:  ? do_user_addr_fault+0x1ef/0x710
Mar 15 13:30:22.996841 fedora37 kernel:  ? do_syscall_64+0x67/0x80
Mar 15 13:30:22.996856 fedora37 kernel:  ? exc_page_fault+0x70/0x170
Mar 15 13:30:22.996871 fedora37 kernel:  entry_SYSCALL_64_after_hwframe+0x72/0xdc
Mar 15 13:30:22.996888 fedora37 kernel: RIP: 0033:0x7f9abbf1e2bf
Mar 15 13:30:22.996964 fedora37 kernel: Code: 89 54 24 18 48 89 74 24 10 89 7c 24 08 e8 19 c3 f8 ff 48 8b 54 24 18 48 8b 74 24 10 41 89 c0 8b 7c 24 08 b8 01 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 31 44 89 c7 48 89 44 24 08 e8 6c c3 f8 ff 48
Mar 15 13:30:22.996984 fedora37 kernel: RSP: 002b:00007f9aab2fd500 EFLAGS: 00000293 ORIG_RAX: 0000000000000001
Mar 15 13:30:22.997003 fedora37 kernel: RAX: ffffffffffffffda RBX: 00007f9aa0006aa0 RCX: 00007f9abbf1e2bf
Mar 15 13:30:22.997022 fedora37 kernel: RDX: 0000000000000166 RSI: 00007f9aa0006aa0 RDI: 0000000000000010
Mar 15 13:30:22.997044 fedora37 kernel: RBP: 0000000000000010 R08: 0000000000000000 R09: 0000000000000073
Mar 15 13:30:22.997061 fedora37 kernel: R10: 0000000000000000 R11: 0000000000000293 R12: 00005595f875a370
Mar 15 13:30:22.997077 fedora37 kernel: R13: 0000000000000166 R14: 00007f9aac4a35f8 R15: 00007f9aac49502b
Mar 15 13:30:22.997097 fedora37 kernel:  </TASK>
Mar 15 13:30:22.997114 fedora37 kernel: Modules linked in: nvmet_tcp nvmet null_blk nvme_tcp nvme_fabrics nvme_core nvme_common uinput snd_seq_dummy snd_hrtimer qrtr rfkill sunrpc binfmt_misc snd_intel8x0 snd_ac97_codec ac97_bus snd_seq intel_rapl_msr intel_rapl_common snd_seq_device rapl joydev snd_pcm snd_timer pcspkr snd i2c_piix4 vboxguest soundcore loop zram vmwgfx crct10dif_pclmul crc32_pclmul crc32c_intel polyval_clmulni e1000 polyval_generic drm_ttm_helper ttm video wmi ghash_clmulni_intel sha512_ssse3 serio_raw ata_generic pata_acpi ip6_tables ip_tables fuse
Mar 15 13:30:22.997178 fedora37 kernel: CR2: 0000000000000034
Mar 15 13:30:22.997199 fedora37 kernel: ---[ end trace 0000000000000000 ]---
Mar 15 13:30:22.997218 fedora37 kernel: RIP: 0010:bio_poll+0xd/0x150
Mar 15 13:30:22.997234 fedora37 kernel: Code: 66 2e 0f 1f 84 00 00 00 00 00 0f 1f 00 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 90 0f 1f 44 00 00 41 56 41 55 41 54 55 53 <8b> 6f 34 48 8b 47 08 48 85 c0 0f 84 a1 00 00 00 4c 8b a8 60 03 00
Mar 15 13:30:22.997249 fedora37 kernel: RSP: 0018:ffffa561851bfae0 EFLAGS: 00010246
Mar 15 13:30:22.997264 fedora37 kernel: RAX: 0000000000000000 RBX: ffff8ff38ae60000 RCX: 0000000000000000
Mar 15 13:30:22.997279 fedora37 kernel: RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
Mar 15 13:30:22.997331 fedora37 kernel: RBP: ffffa561851bfb10 R08: 0000000000000001 R09: ffff8ff38cc0e860
Mar 15 13:30:22.997384 fedora37 kernel: R10: ffff8ff3887af388 R11: 0000000000000110 R12: 0000000000000001
Mar 15 13:30:22.997402 fedora37 kernel: R13: ffff8ff38fbd9c00 R14: 0000000000000400 R15: ffffa561851bfba8
Mar 15 13:30:22.997417 fedora37 kernel: FS:  00007f9aab2ff6c0(0000) GS:ffff8ff84b400000(0000) knlGS:0000000000000000
Mar 15 13:30:22.997432 fedora37 kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Mar 15 13:30:22.997445 fedora37 kernel: CR2: 0000000000000034 CR3: 000000011439e002 CR4: 00000000000706f0