I am using 2 initiators + 1 target using nvmet with 1 subsystem and 4 backend devices. Kernel is 4.9.6, NVME/rdma drivers are all from the vanilla kernel, I had a probelm connecting the NVME using the OFED drivers, so I removed all the mlx_compat and everything which depends on it.
Would it be possible to test with latest upstream kernel?
When I perform simultaneous writes (non direct fio) from both of the initiators to the same device (overlapping areas), I get NVMEf disconnect followed by "dump error cqe", successful reconnect, and then on one of the servers I get a WARN_ON. After this the server gets stuck and I have to power cycle it to get it back up...
The error cqes seem to indicate that a memory registration operation failed which escalated to something worse. I noticed some issues before with CX4 having problems with memory registration in the presence of network retransmissions (due to network congestion). I notified Mellanox folks on that too, CC'ing Linux-rdma for some more attention. After that, I see that ib_modify_qp failed which I've never seen before (might indicate the the device is in bad shape), and the WARN_ON is really weird given that nvme-rdma never uses IB_POLL_DIRECT.
Here are the printouts from the server that got stuck: Feb 6 09:20:13 kblock01-knode02 kernel: [59976.204216] mlx5_0:dump_cqe:262:(pid 0): dump error cqe Feb 6 09:20:13 kblock01-knode02 kernel: [59976.204219] 00000000 00000000 00000000 00000000 Feb 6 09:20:13 kblock01-knode02 kernel: [59976.204220] 00000000 00000000 00000000 00000000 Feb 6 09:20:13 kblock01-knode02 kernel: [59976.204220] 00000000 00000000 00000000 00000000 Feb 6 09:20:13 kblock01-knode02 kernel: [59976.204221] 00000000 08007806 25000129 015557d0 Feb 6 09:20:13 kblock01-knode02 kernel: [59976.204234] nvme nvme0: MEMREG for CQE 0xffff96ddd747a638 failed with status memory management operation error (6) Feb 6 09:20:13 kblock01-knode02 kernel: [59976.204375] nvme nvme0: reconnecting in 10 seconds Feb 6 09:20:13 kblock01-knode02 kernel: [59976.205512] mlx5_0:dump_cqe:262:(pid 0): dump error cqe Feb 6 09:20:13 kblock01-knode02 kernel: [59976.205514] 00000000 00000000 00000000 00000000 Feb 6 09:20:13 kblock01-knode02 kernel: [59976.205515] 00000000 00000000 00000000 00000000 Feb 6 09:20:13 kblock01-knode02 kernel: [59976.205515] 00000000 00000000 00000000 00000000 Feb 6 09:20:13 kblock01-knode02 kernel: [59976.205516] 00000000 08007806 25000126 00692bd0 Feb 6 09:20:23 kblock01-knode02 kernel: [59986.452887] nvme nvme0: Successfully reconnected Feb 6 09:20:24 kblock01-knode02 kernel: [59986.682887] mlx5_0:dump_cqe:262:(pid 0): dump error cqe Feb 6 09:20:24 kblock01-knode02 kernel: [59986.682890] 00000000 00000000 00000000 00000000 Feb 6 09:20:24 kblock01-knode02 kernel: [59986.682891] 00000000 00000000 00000000 00000000 Feb 6 09:20:24 kblock01-knode02 kernel: [59986.682892] 00000000 00000000 00000000 00000000 Feb 6 09:20:24 kblock01-knode02 kernel: [59986.682892] 00000000 08007806 25000158 04cdd7d0 ... Feb 6 09:20:24 kblock01-knode02 kernel: [59986.687737] mlx5_0:dump_cqe:262:(pid 0): dump error cqe Feb 6 09:20:24 kblock01-knode02 kernel: [59986.687739] 00000000 00000000 00000000 00000000 Feb 6 09:20:24 kblock01-knode02 kernel: [59986.687740] 00000000 00000000 00000000 00000000 Feb 6 09:20:24 kblock01-knode02 kernel: [59986.687740] 00000000 00000000 00000000 00000000 Feb 6 09:20:24 kblock01-knode02 kernel: [59986.687741] 00000000 93005204 00000155 00a385e0 Feb 6 09:20:34 kblock01-knode02 kernel: [59997.389290] nvme nvme0: Successfully reconnected Feb 6 09:21:19 kblock01-knode02 rsyslogd: -- MARK -- Feb 6 09:21:38 kblock01-knode02 kernel: [60060.927832] mlx5_0:dump_cqe:262:(pid 0): dump error cqe Feb 6 09:21:38 kblock01-knode02 kernel: [60060.927835] 00000000 00000000 00000000 00000000 Feb 6 09:21:38 kblock01-knode02 kernel: [60060.927836] 00000000 00000000 00000000 00000000 Feb 6 09:21:38 kblock01-knode02 kernel: [60060.927837] 00000000 00000000 00000000 00000000 Feb 6 09:21:38 kblock01-knode02 kernel: [60060.927837] 00000000 93005204 00000167 b44e76e0 Feb 6 09:21:38 kblock01-knode02 kernel: [60060.927846] nvme nvme0: RECV for CQE 0xffff96fe64f18750 failed with status local protection error (4) Feb 6 09:21:38 kblock01-knode02 kernel: [60060.928200] nvme nvme0: reconnecting in 10 seconds ... Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736182] mlx5_core 0000:04:00.0: wait_func:879:(pid 22709): 2ERR_QP(0x507) timeout. Will cause a leak of a command resource Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736190] ------------[ cut here ]------------ Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736211] WARNING: CPU: 18 PID: 22709 at drivers/infiniband/core/verbs.c:1963 __ib_drain_sq+0x135/0x1d0 [ib_core] Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736212] failed to drain send queue: -110 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736213] Modules linked in: nvme_rdma rdma_cm ib_cm iw_cm nvme_fabrics nvme_core ocs_fc_scst(POE) scst(OE) mptctl mptbase qla2xxx_scst(OE) scsi_transport_fc dm_multipath drbd lru_cache netconsole mst_pciconf(OE) nfsd nfs_acl auth_rpcgss ipmi_devintf lockd sunrpc grace ipt_MASQUERADE nf_nat_masquerade_ipv4 xt_nat iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack fuse binfmt_misc iTCO_wdt iTCO_vendor_support pcspkr serio_raw joydev igb i2c_i801 i2c_smbus lpc_ich mei_me mei ioatdma dca ses enclosure ipmi_ssif ipmi_si ipmi_msghandler bnx2x libcrc32c mdio mlx5_ib ib_core mlx5_core devlink ptp pps_core tpm_tis tpm_tis_core tpm ext4(E) mbcache(E) jbd2(E) isci(E) libsas(E) mpt3sas(E) scsi_transport_sas(E) raid_class(E) megaraid_sas(E) wmi(E) mgag200(E) ttm(E) drm_kms_helper(E) Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736293] drm(E) i2c_algo_bit(E) [last unloaded: nvme_core] Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736301] CPU: 18 PID: 22709 Comm: kworker/18:4 Tainted: P OE 4.9.6-KM1 #0 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736303] Hardware name: Supermicro SYS-1027R-72BRFTP5-EI007/X9DRW-7/iTPF, BIOS 3.0a 01/22/2014 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736312] Workqueue: nvme_rdma_wq nvme_rdma_reconnect_ctrl_work [nvme_rdma] Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736315] ffff96de27e6f9b8 ffffffffb537f3ff ffffffffc06a00e5 ffff96de27e6fa18 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736320] ffff96de27e6fa18 0000000000000000 ffff96de27e6fa08 ffffffffb5091a7d Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736324] 0000000300000000 000007ab00000006 0507000000000000 ffff96de27e6fad8 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736328] Call Trace: Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736341] [<ffffffffb537f3ff>] dump_stack+0x67/0x98 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736352] [<ffffffffc06a00e5>] ? __ib_drain_sq+0x135/0x1d0 [ib_core] Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736364] [<ffffffffb5091a7d>] __warn+0xfd/0x120 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736368] [<ffffffffb5091b59>] warn_slowpath_fmt+0x49/0x50 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736378] [<ffffffffc069fdb5>] ? ib_modify_qp+0x45/0x50 [ib_core] Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736388] [<ffffffffc06a00e5>] __ib_drain_sq+0x135/0x1d0 [ib_core] Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736398] [<ffffffffc069f5a0>] ? ib_create_srq+0xa0/0xa0 [ib_core] Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736408] [<ffffffffc06a01a5>] ib_drain_sq+0x25/0x30 [ib_core] Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736418] [<ffffffffc06a01c6>] ib_drain_qp+0x16/0x40 [ib_core] Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736422] [<ffffffffc0c4d25b>] nvme_rdma_stop_and_free_queue+0x2b/0x50 [nvme_rdma] Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736426] [<ffffffffc0c4d2ad>] nvme_rdma_free_io_queues+0x2d/0x40 [nvme_rdma] Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736429] [<ffffffffc0c4d884>] nvme_rdma_reconnect_ctrl_work+0x34/0x1e0 [nvme_rdma] Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736434] [<ffffffffb50ac7ce>] process_one_work+0x17e/0x4f0 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736444] [<ffffffffb50cefc5>] ? dequeue_task_fair+0x85/0x870 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736454] [<ffffffffb5799c6a>] ? schedule+0x3a/0xa0 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736456] [<ffffffffb50ad653>] worker_thread+0x153/0x660 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736464] [<ffffffffb5026b4c>] ? __switch_to+0x1dc/0x670 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736468] [<ffffffffb5799706>] ? __schedule+0x226/0x6a0 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736471] [<ffffffffb50be7c2>] ? default_wake_function+0x12/0x20 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736474] [<ffffffffb50d7636>] ? __wake_up_common+0x56/0x90 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736477] [<ffffffffb50ad500>] ? workqueue_prepare_cpu+0x80/0x80 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736480] [<ffffffffb5799c6a>] ? schedule+0x3a/0xa0 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736483] [<ffffffffb50ad500>] ? workqueue_prepare_cpu+0x80/0x80 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736487] [<ffffffffb50b237d>] kthread+0xcd/0xf0 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736492] [<ffffffffb50bc40e>] ? schedule_tail+0x1e/0xc0 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736495] [<ffffffffb50b22b0>] ? __kthread_init_worker+0x40/0x40 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736499] [<ffffffffb579ded5>] ret_from_fork+0x25/0x30 Feb 6 09:23:54 kblock01-knode02 kernel: [60196.736502] ---[ end trace eb0e5ba7dc81a687 ]--- Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176054] mlx5_core 0000:04:00.0: wait_func:879:(pid 22709): 2ERR_QP(0x507) timeout. Will cause a leak of a command resource Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176059] ------------[ cut here ]------------ Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176073] WARNING: CPU: 18 PID: 22709 at drivers/infiniband/core/verbs.c:1998 __ib_drain_rq+0x12a/0x1c0 [ib_core] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176075] failed to drain recv queue: -110 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176076] Modules linked in: nvme_rdma rdma_cm ib_cm iw_cm nvme_fabrics nvme_core ocs_fc_scst(POE) scst(OE) mptctl mptbase qla2xxx_scst(OE) scsi_transport_fc dm_multipath drbd lru_cache netconsole mst_pciconf(OE) nfsd nfs_acl auth_rpcgss ipmi_devintf lockd sunrpc grace ipt_MASQUERADE nf_nat_masquerade_ipv4 xt_nat iptable_nat nf_nat_ipv4 nf_nat nf_conntrack_ipv4 nf_defrag_ipv4 xt_state nf_conntrack fuse binfmt_misc iTCO_wdt iTCO_vendor_support pcspkr serio_raw joydev igb i2c_i801 i2c_smbus lpc_ich mei_me mei ioatdma dca ses enclosure ipmi_ssif ipmi_si ipmi_msghandler bnx2x libcrc32c mdio mlx5_ib ib_core mlx5_core devlink ptp pps_core tpm_tis tpm_tis_core tpm ext4(E) mbcache(E) jbd2(E) isci(E) libsas(E) mpt3sas(E) scsi_transport_sas(E) raid_class(E) megaraid_sas(E) wmi(E) mgag200(E) ttm(E) drm_kms_helper(E) Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176134] drm(E) i2c_algo_bit(E) [last unloaded: nvme_core] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176140] CPU: 18 PID: 22709 Comm: kworker/18:4 Tainted: P W OE 4.9.6-KM1 #0 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176141] Hardware name: Supermicro SYS-1027R-72BRFTP5-EI007/X9DRW-7/iTPF, BIOS 3.0a 01/22/2014 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176147] Workqueue: nvme_rdma_wq nvme_rdma_reconnect_ctrl_work [nvme_rdma] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176150] ffff96de27e6f9b8 ffffffffb537f3ff ffffffffc069feea ffff96de27e6fa18 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176155] ffff96de27e6fa18 0000000000000000 ffff96de27e6fa08 ffffffffb5091a7d Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176159] 0000000300000000 000007ce00000006 0507000000000000 ffff96de27e6fad8 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176163] Call Trace: Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176169] [<ffffffffb537f3ff>] dump_stack+0x67/0x98 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176180] [<ffffffffc069feea>] ? __ib_drain_rq+0x12a/0x1c0 [ib_core] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176185] [<ffffffffb5091a7d>] __warn+0xfd/0x120 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176189] [<ffffffffb5091b59>] warn_slowpath_fmt+0x49/0x50 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176199] [<ffffffffc069fdb5>] ? ib_modify_qp+0x45/0x50 [ib_core] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176216] [<ffffffffc06de770>] ? mlx5_ib_modify_qp+0x980/0xec0 [mlx5_ib] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176225] [<ffffffffc069feea>] __ib_drain_rq+0x12a/0x1c0 [ib_core] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176235] [<ffffffffc069f5a0>] ? ib_create_srq+0xa0/0xa0 [ib_core] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176246] [<ffffffffc069ffa5>] ib_drain_rq+0x25/0x30 [ib_core] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176255] [<ffffffffc06a01dc>] ib_drain_qp+0x2c/0x40 [ib_core] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176259] [<ffffffffc0c4d25b>] nvme_rdma_stop_and_free_queue+0x2b/0x50 [nvme_rdma] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176263] [<ffffffffc0c4d2ad>] nvme_rdma_free_io_queues+0x2d/0x40 [nvme_rdma] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176267] [<ffffffffc0c4d884>] nvme_rdma_reconnect_ctrl_work+0x34/0x1e0 [nvme_rdma] Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176270] [<ffffffffb50ac7ce>] process_one_work+0x17e/0x4f0 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176275] [<ffffffffb50cefc5>] ? dequeue_task_fair+0x85/0x870 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176278] [<ffffffffb5799c6a>] ? schedule+0x3a/0xa0 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176281] [<ffffffffb50ad653>] worker_thread+0x153/0x660 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176285] [<ffffffffb5026b4c>] ? __switch_to+0x1dc/0x670 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176289] [<ffffffffb5799706>] ? __schedule+0x226/0x6a0 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176291] [<ffffffffb50be7c2>] ? default_wake_function+0x12/0x20 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176294] [<ffffffffb50d7636>] ? __wake_up_common+0x56/0x90 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176297] [<ffffffffb50ad500>] ? workqueue_prepare_cpu+0x80/0x80 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176300] [<ffffffffb5799c6a>] ? schedule+0x3a/0xa0 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176302] [<ffffffffb50ad500>] ? workqueue_prepare_cpu+0x80/0x80 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176306] [<ffffffffb50b237d>] kthread+0xcd/0xf0 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176310] [<ffffffffb50bc40e>] ? schedule_tail+0x1e/0xc0 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176313] [<ffffffffb50b22b0>] ? __kthread_init_worker+0x40/0x40 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176316] [<ffffffffb579ded5>] ret_from_fork+0x25/0x30 Feb 6 09:24:55 kblock01-knode02 kernel: [60258.176318] ---[ end trace eb0e5ba7dc81a688 ]--- Feb 6 09:25:26 kblock01-knode02 udevd[9344]: worker [21322] unexpectedly returned with status 0x0100 Feb 6 09:25:26 kblock01-knode02 udevd[9344]: worker [21322] failed while handling '/devices/virtual/nvme-fabrics/ctl/nvme0/nvme0n1' Feb 6 09:25:26 kblock01-knode02 udevd[9344]: worker [21323] unexpectedly returned with status 0x0100 Feb 6 09:25:26 kblock01-knode02 udevd[9344]: worker [21323] failed while handling '/devices/virtual/nvme-fabrics/ctl/nvme0/nvme0n2' Feb 6 09:25:26 kblock01-knode02 udevd[9344]: worker [21741] unexpectedly returned with status 0x0100 Feb 6 09:25:26 kblock01-knode02 udevd[9344]: worker [21741] failed while handling '/devices/virtual/nvme-fabrics/ctl/nvme0/nvme0n3' Feb 6 09:25:57 kblock01-knode02 kernel: [60319.615916] mlx5_core 0000:04:00.0: wait_func:879:(pid 22709): 2RST_QP(0x50a) timeout. Will cause a leak of a command resource Feb 6 09:25:57 kblock01-knode02 kernel: [60319.615922] mlx5_0:destroy_qp_common:1936:(pid 22709): mlx5_ib: modify QP 0x00015e to RESET failed Feb 6 09:26:19 kblock01-knode02 udevd[9344]: worker [21740] unexpectedly returned with status 0x0100 Feb 6 09:26:19 kblock01-knode02 udevd[9344]: worker [21740] failed while handling '/devices/virtual/nvme-fabrics/ctl/nvme0/nvme0n4' _______________________________________________ Linux-nvme mailing list Linux-nvme@xxxxxxxxxxxxxxxxxxx http://lists.infradead.org/mailman/listinfo/linux-nvme
-- To unsubscribe from this list: send the line "unsubscribe linux-rdma" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
