Failure listing connections, can't get controllers

[barakda]

Sometimes the next error in spdk appears on CI nightly run

the last run build - http://161.156.165.47:8080/job/ceph-nvmeof_atom_nightly_multiIBMCloudServers_m1/88/consoleText

Console log:

Jun 14 03:04:04 ceph-nvme-vm10 bash[3022446]: 2024-06-14T00:04:04.434+0000 7f35adc24640 0 ms_deliver_dispatch: unhandled message 0x557ac035d880 nvmeofgwmap magic: 0 from mon.1 v2:10.243.64.5:3300/0
Jun 14 03:04:05 ceph-nvme-vm10 bash[3022446]: 2024-06-14T00:04:05.899+0000 7f35adc24640 0 ms_deliver_dispatch: unhandled message 0x557ac035da40 nvmeofgwmap magic: 0 from mon.1 v2:10.243.64.5:3300/0
Jun 14 03:04:08 ceph-nvme-vm10 bash[3022446]: 2024-06-14T00:04:08.014+0000 7f35adc24640 0 ms_deliver_dispatch: unhandled message 0x557ac035dc00 nvmeofgwmap magic: 0 from mon.1 v2:10.243.64.5:3300/0
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: 2024-06-14T00:04:10.445+0000 7f35adc24640 0 ms_deliver_dispatch: unhandled message 0x557abfae76c0 nvmeofgwmap magic: 0 from mon.1 v2:10.243.64.5:3300/0
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: [14-Jun-2024 00:04:10] ERROR grpc.py:1936: Failure listing connections, can't get controllers
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: Traceback (most recent call last):
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: File "/src/control/grpc.py", line 1932, in list_connections_safe
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: ctrl_ret = rpc_nvmf.nvmf_subsystem_get_controllers(self.spdk_rpc_client, nqn=request.subsystem)
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: File "/usr/local/lib/python3.9/site-packages/spdk/rpc/nvmf.py", line 619, in nvmf_subsystem_get_controllers
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: return client.call('nvmf_subsystem_get_controllers', params)
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: File "/usr/local/lib/python3.9/site-packages/spdk/rpc/client.py", line 205, in call
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: raise JSONRPCException(msg)
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: spdk.rpc.client.JSONRPCException: request:
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: {
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: "nqn": "nqn.2016-06.io.spdk:cnode1",
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: "method": "nvmf_subsystem_get_controllers",
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: "req_id": 1303
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: }
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: Got JSON-RPC error response
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: response:
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: {
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: "code": -32603,
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: "message": "Internal error"
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: }
Jun 14 03:04:10 ceph-nvme-vm10 bash[3022446]: [14-Jun-2024 00:04:10] ERROR prometheus.py:201: Exporter failed to fetch connection info for nqn.2016-06.io.spdk:cnode1: Failure listing connections, can't get controllers: Internal error
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: [14-Jun-2024 00:04:11] ERROR grpc.py:1936: Failure listing connections, can't get controllers
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: Traceback (most recent call last):
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: File "/src/control/grpc.py", line 1932, in list_connections_safe
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: ctrl_ret = rpc_nvmf.nvmf_subsystem_get_controllers(self.spdk_rpc_client, nqn=request.subsystem)
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: File "/usr/local/lib/python3.9/site-packages/spdk/rpc/nvmf.py", line 619, in nvmf_subsystem_get_controllers
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: return client.call('nvmf_subsystem_get_controllers', params)
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: File "/usr/local/lib/python3.9/site-packages/spdk/rpc/client.py", line 205, in call
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: raise JSONRPCException(msg)
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: spdk.rpc.client.JSONRPCException: request:
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: {
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: "nqn": "nqn.2016-06.io.spdk:cnode2",
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: "method": "nvmf_subsystem_get_controllers",
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: "req_id": 1305
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: }
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: Got JSON-RPC error response
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: response:
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: {
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: "code": -32603,
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: "message": "Internal error"
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: }
Jun 14 03:04:11 ceph-nvme-vm10 bash[3022446]: [14-Jun-2024 00:04:11] ERROR prometheus.py:201: Exporter failed to fetch connection info for nqn.2016-06.io.spdk:cnode2: Failure listing connections, can't get controllers: Internal error
Jun 14 03:04:12 ceph-nvme-vm10 bash[3022446]: 2024-06-14T00:04:12.566+0000 7f35adc24640 0 ms_deliver_dispatch: unhandled message 0x557abfae7880 nvmeofgwmap magic: 0 from mon.1 v2:10.243.64.5:3300/0
Jun 14 03:04:12 ceph-nvme-vm10 bash[3022446]: 2024-06-14T00:04:12.566+0000 7f35adc24640 0 ms_deliver_dispatch: unhandled message 0x557abfae7a40 nvmeofgwmap magic: 0 from mon.1 v2:10.243.64.5:3300/0
Jun 14 03:04:14 ceph-nvme-vm10 bash[3022446]: [14-Jun-2024 00:04:14] INFO grpc.py:826: Received request to set ana states [nqn: "nqn.2016-06.io.spdk:cnode1"
Jun 14 03:04:14 ceph-nvme-vm10 bash[3022446]: states {
Jun 14 03:04:14 ceph-nvme-vm10 bash[3022446]: grp_id: 1
Jun 14 03:04:14 ceph-nvme-vm10 bash[3022446]: state: INACCESSIBLE
Jun 14 03:04:14 ceph-nvme-vm10 bash[3022446]: }
Jun 14 03:04:14 ceph-nvme-vm10 bash[3022446]: , nqn: "nqn.2016-06.io.spdk:cnode2"
Jun 14 03:04:14 ceph-nvme-vm10 bash[3022446]: states {
Jun 14 03:04:14 ceph-nvme-vm10 bash[3022446]: grp_id: 1
Jun 14 03:04:14 ceph-nvme-vm10 bash[3022446]: state: INACCESSIBLE