run nvmf-fio never stop after the specified runtime

Open gaowayne opened this issue 2 years ago • 1 comments

I setup enviroment with softroce rxe, ib_send_bw works fine. then I specifiy 5 senconds run as below

./nvmf-fio --filename=nvmf-rdma://192.168.122.33:4420/nvmet-always-rdma/1 --randread --iodepth=32 --ioqueues=4 --runtime=5

I can see below log for a long time, but never print summary and even never stop. it should stop after 5 seconds run.

  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_rdma_cm_event 363 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_rdma_cq_event 169 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_rdma_cq_event_handler 130 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_queue_pollfds 403 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_queue_handle_event 97 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_rdma_cm_event 363 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_rdma_cq_event 169 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_rdma_cq_event_handler 130 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_queue_pollfds 403 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_queue_handle_event 97 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_rdma_cm_event 363 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_rdma_cq_event 169 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_rdma_cq_event_handler 130 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_queue_pollfds 403 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_queue_handle_event 97 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_rdma_cm_event 363 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_rdma_cq_event 169 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_rdma_cq_event_handler 130 
  nvmf-ys-rdma-0 Sat Feb 25 14:55:42 2023[trace]nvmf_queue_pollfds 403

Feb 25 '23 07:02 gaowayne

I found nvme connect kernel way works fine. only libnvmf has some problem dmesg log:

[2æœˆ25 11:33] nvmet: creating nvm controller 1 for subsystem nvmet-always-rdma for NQN nqn.2014-08.org.nvmexpress:libnvmf:uuid:44f3e7b5-5076-3652-8f9c-33d4e5afac0.
[  +0.000746] rdma_rxe: rxe_invalidate_mr: mr->type (3) is wrong type
[  +0.000006] rdma_rxe: qp#19 moved to error state
[  +4.182244] nvmet: ctrl 1 keep-alive timer (4 seconds) expired!
[  +0.000006] nvmet: ctrl 1 fatal error occurred!
[2æœˆ25 14:52] nvmet: creating nvm controller 1 for subsystem nvmet-always-rdma for NQN nqn.2014-08.org.nvmexpress:libnvmf:uuid:792ec550-4d59-69a3-f011-7a6524f1d099.
[  +0.000023] rdma_rxe: rxe_invalidate_mr: mr->type (3) is wrong type
[  +0.000007] rdma_rxe: qp#21 moved to error state
[  +4.247734] nvmet: ctrl 1 keep-alive timer (4 seconds) expired!
[  +0.000006] nvmet: ctrl 1 fatal error occurred!
[2æœˆ25 14:54] nvmet: creating nvm controller 1 for subsystem nvmet-always-rdma for NQN nqn.2014-08.org.nvmexpress:libnvmf:uuid:ce17dd9a-f648-af2-2053-bb20cef1f579.
[  +0.000008] rdma_rxe: rxe_invalidate_mr: mr->type (3) is wrong type
[  +0.000002] rdma_rxe: qp#23 moved to error state
[  +4.159211] nvmet: ctrl 1 keep-alive timer (4 seconds) expired!
[  +0.000006] nvmet: ctrl 1 fatal error occurred!
[2æœˆ25 15:00] nvmet: creating nvm controller 1 for subsystem nvmet-always-rdma for NQN nqn.2014-08.org.nvmexpress:libnvmf:uuid:e41b067-2d1d-81ae-796a-9fc0f1f8de1.
[  +0.000008] rdma_rxe: rxe_invalidate_mr: mr->type (3) is wrong type
[  +0.000002] rdma_rxe: qp#25 moved to error state
[  +4.255911] nvmet: ctrl 1 keep-alive timer (4 seconds) expired!
[  +0.000006] nvmet: ctrl 1 fatal error occurred!
[2æœˆ25 15:01] nvmet: creating nvm controller 1 for subsystem nvmet-always-rdma for NQN nqn.2014-08.org.nvmexpress:libnvmf:uuid:f685f71c-b99a-cc2d-17fe-abea6236f49.
[  +0.000072] rdma_rxe: rxe_invalidate_mr: mr->type (3) is wrong type
[  +0.000003] rdma_rxe: qp#27 moved to error state
[  +4.162285] nvmet: ctrl 1 keep-alive timer (4 seconds) expired!
[  +0.000005] nvmet: ctrl 1 fatal error occurred!
[2æœˆ25 15:13] nvme nvme1: rdma connection establishment failed (-110)
[2æœˆ25 15:14] nvme nvme1: rdma connection establishment failed (-110)

nvme connect works fine with below log

[2æœˆ25 15:15] nvmet: creating discovery controller 1 for subsystem nqn.2014-08.org.nvmexpress.discovery for NQN nqn.2014-08.org.nvmexpress:uuid:7c248d94-40e7-4403-93b7-c906f8435c83.
[  +0.000212] nvme nvme1: new ctrl: NQN "nqn.2014-08.org.nvmexpress.discovery", addr 192.168.1.10:4420
[  +0.000133] nvme nvme1: Removing ctrl: NQN "nqn.2014-08.org.nvmexpress.discovery"
[  +0.115747] nvmet: creating nvm controller 1 for subsystem nvmet-always-rdma for NQN nqn.2014-08.org.nvmexpress:uuid:7c248d94-40e7-4403-93b7-c906f8435c83.
[  +0.006324] nvme nvme1: creating 8 I/O queues.
[  +0.082501] nvme nvme1: mapped 8/0/0 default/read/poll queues.
[  +0.002350] nvme nvme1: new ctrl: NQN "nvmet-always-rdma", addr 192.168.1.10:4420

Feb 25 '23 07:02 gaowayne