<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=iso-8859-1">
</head>
<body>
<div>
<div>
<div>
<div id="compose-body-wrapper" dir="auto">
<div dir="auto">
<div dir="auto">Looking for any suggestions on where to look, or what to change, to gain more information on RDMA timeout erors.&nbsp;&nbsp;</div>
<div dir="auto"><br>
</div>
<div dir="auto">We have a CentOS (release 7.9.2009, kernel 3.10.0-1160.66.1.el7.x86_64)</div>
<div dir="auto">&nbsp;4 system (2 MDS + 2 OSS) zfs backed Lustre 2.12.9 server&nbsp; on AMD (EPYC 7402P).&nbsp; Each of these four has a single connection EDR card (Mellanox Technologies MT27800 Family [ConnectX-5]).</div>
<div dir="auto"><br>
</div>
<div dir="auto">The above Lustre should serve 54 linux compute node clients (heterogeneous hardware) running the same CentOS &amp; kernel over 3 EDR switches (4 cables each from center to edge switches). Hardware is a mix of Intel CPUs &amp; a few AMD, and have at
 least 5 variations of EDR and FDR single connection cards.</div>
<div dir="auto"><br>
</div>
<div dir="auto">All of these clients have been successfully utilizing a ClusterStor2000 appliance, as well as a BeeGFS (7.2.6) storage cluster over the same fabric.&nbsp; The IB network is not reporting any errors, and running at full rates to each client.&nbsp; Only
 errors appear to be at the lnet level, and start on the client side.&nbsp; The server eventually times out the client for no reponse</div>
<div dir="auto"><br>
</div>
<div dir="auto">We setup this server with the help of a very competent consultant and have had them back to help debug this problem.&nbsp; But we are having difficulty finding anything to log or look at that helps.</div>
<div dir="auto"><br>
</div>
<div dir="auto"><br>
</div>
<div dir="auto">On some nodes (mostly older nodes) an RDMA timeout occurs on the client that locks up the clients communication to one of the Lustre targets.&nbsp; We found that Bonnie++ and fio tests could cause these client lockups to one of the OSS nodes.&nbsp; Swapping
 hardware between server nodes didn't reveal any pattern, and eventually we moved an entirely new node which failed in the same manner.&nbsp; About 2/3 of the clients can be made to lockup, but no pattern in their individual hardware or network location seems to
 exist.&nbsp; &nbsp;The remaining nodes seem to work perfectly with this new Lustre storage.&nbsp; The same sort of client RDM lockup has also been generated to a MDS with a simple &quot;ls&quot; of the lustre root after mounting.</div>
<div dir="auto"><br>
</div>
<div dir="auto"><br>
</div>
<div dir="auto">Below are client and MDS&nbsp; log from that simplest of cases.</div>
<div dir="auto"><br>
</div>
<div dir="auto">&nbsp;Sep 15 10:05:56 node113 systemd: Started Session 85 of user root.</div>
<div dir="auto">Sep 15 10:06:08 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:08 node113 kernel: LNet: HW NUMA nodes: 2, HW CPU cores: 24, npartitions: 2</div>
<div dir="auto">Sep 15 10:06:09 node113 kernel: alg: No test for adler32 (adler32-zlib)</div>
<div dir="auto">Sep 15 10:06:09 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:09 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:09 node113 kernel: Lustre: Lustre: Build Version: 2.12.9</div>
<div dir="auto">Sep 15 10:06:09 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:10 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:10 node113 kernel: LNet: Using FMR for registration</div>
<div dir="auto">Sep 15 10:06:10 node113 kernel: LNet: Added LNI 10.200.200.113@o2ib [8/256/0/180]</div>
<div dir="auto">Sep 15 10:06:10 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:10 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:10 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:10 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:10 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:10 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:10 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:10 node113 kernel: Request for unknown module key 'DKMS module signing key: b4c2eda7b66318967d50ba12b9cb1</div>
<div dir="auto">8dcee995f32' err -11</div>
<div dir="auto">Sep 15 10:06:11 node113 kernel: Lustre: Mounted lz01-client</div>
<div dir="auto">Sep 15 10:06:56 node113 kernel: Lustre: 13799:0:(client.c:2169:ptlrpc_expire_one_request()) @@@ Request sent has timed</div>
<div dir="auto">out for slow reply: [sent 1663250809/real 1663250809]&nbsp; req@ffff899095d04800 x1744044838356992/t0(0) o101-&gt;lz01-MDT000</div>
<div dir="auto">0-mdc-ffff8990be2fb800@10.200.200.54@o2ib:12/10 lens 576/968 e 0 to 1 dl 1663250816 ref 2 fl Rpc:X/0/ffffffff rc 0/-1</div>
<div dir="auto">Sep 15 10:06:56 node113 kernel: Lustre: lz01-MDT0000-mdc-ffff8990be2fb800: Connection to lz01-MDT0000 (at 10.200.200.5</div>
<div dir="auto">4@o2ib) was lost; in progress operations using this service will wait for recovery to complete</div>
<div dir="auto">Sep 15 10:07:02 node113 kernel: LNetError: 13693:0:(o2iblnd_cb.c:3373:kiblnd_check_txs_locked()) Timed out tx: active_</div>
<div dir="auto">txs, 0 seconds</div>
<div dir="auto">Sep 15 10:07:02 node113 kernel: LNetError: 13693:0:(o2iblnd_cb.c:3448:kiblnd_check_conns()) Timed out RDMA with 10.200</div>
<div dir="auto">.200.54@o2ib (12): c: 4, oc: 0, rc: 8</div>
<div dir="auto">Sep 15 10:07:03 node113 kernel: Lustre: 13725:0:(client.c:2169:ptlrpc_expire_one_request()) @@@ Request sent has timed out for sent delay: [sent 1663250816/real 0]&nbsp; req@ffff899095d04c80 x1744044838357056/t0(0) o400-&gt;MGC10.200.200.54@o2ib@10.200.200.54@o2ib:26/25
 lens 224/224 e 0 to 1 dl 1663250823 ref 2 fl Rpc:XN/0/</div>
<div dir="auto">ffffffff rc 0/-1</div>
<div dir="auto">Sep 15 10:07:03 node113 kernel: LustreError: 166-1: MGC10.200.200.54@o2ib: Connection to MGS (at 10.200.200.54@o2ib) was lost; in progress operations using this service will fail</div>
<div dir="auto">Sep 15 10:07:09 node113 kernel: LNetError: 13693:0:(o2iblnd_cb.c:3373:kiblnd_check_txs_locked()) Timed out tx: active_txs, 0 seconds</div>
<div dir="auto">Sep 15 10:07:09 node113 kernel: LNetError: 13693:0:(o2iblnd_cb.c:3448:kiblnd_check_conns()) Timed out RDMA with 10.200.200.54@o2ib (5): c: 7, oc: 0, rc: 8</div>
<div dir="auto">Sep 15 10:07:10 node113 systemd-logind: New session 86 of user root.</div>
<div dir="auto">Sep 15 10:07:10 node113 systemd: Started Session 86 of user root.</div>
<div dir="auto">Sep 15 10:07:54 node113 systemd-logind: New session 87 of user root.</div>
<div dir="auto">Sep 15 10:07:54 node113 systemd: Started Session 87 of user root.</div>
<div dir="auto">Sep 15 10:10:34 node113 systemd-logind: Removed session 86.</div>
<div dir="auto">Sep 15 10:12:47 node113 kernel: LNetError: 13693:0:(o2iblnd_cb.c:3373:kiblnd_check_txs_locked()) Timed out tx: active_txs, 0 seconds</div>
<div dir="auto">Sep 15 10:12:47 node113 kernel: LNetError: 13693:0:(o2iblnd_cb.c:3448:kiblnd_check_conns()) Timed out RDMA with 10.200.200.54@o2ib (5): c: 7, oc: 0, rc: 8</div>
<div dir="auto">Sep 15 10:13:37 node113 systemd-logind: New session 88 of user root.</div>
<div dir="auto">Sep 15 10:13:37 node113 systemd: Started Session 88 of user root.</div>
<div dir="auto">Sep 15 10:13:42 node113 kernel: LNet: 14296:0:(api-ni.c:4175:lnet_ping()) ping 12345-10.200.200.54@o2ib: late network completion</div>
<div dir="auto">Sep 15 10:14:42 node113 kernel: LNet: 14296:0:(api-ni.c:4175:lnet_ping()) ping 12345-10.200.200.54@o2ib: late network completion</div>
<div dir="auto">Sep 15 10:14:50 node113 systemd-logind: Removed session 88.</div>
<div dir="auto">Sep 15 10:15:33 node113 kernel: LNetError: 13693:0:(o2iblnd_cb.c:3373:kiblnd_check_txs_locked()) Timed out tx: active_txs, 0 seconds</div>
<div dir="auto">Sep 15 10:15:33 node113 kernel: LNetError: 13693:0:(o2iblnd_cb.c:3448:kiblnd_check_conns()) Timed out RDMA with 10.200.200.54@o2ib (106): c: 8, oc: 0, rc: 8</div>
<div dir="auto">Sep 15 10:15:42 node113 kernel: LNet: 14296:0:(api-ni.c:4175:lnet_ping()) ping 12345-10.200.200.54@o2ib: late network completion</div>
<div dir="auto">Sep 15 10:15:53 node113 systemd-logind: New session 89 of user root.</div>
<div dir="auto">Sep 15 10:15:53 node113 systemd: Started Session 89 of user root.</div>
<div dir="auto">Sep 15 10:16:42 node113 kernel: LNet: 14296:0:(api-ni.c:4175:lnet_ping()) ping 12345-10.200.200.54@o2ib: late network completion</div>
<div dir="auto">Sep 15 10:17:42 node113 kernel: LNet: 14296:0:(api-ni.c:4175:lnet_ping()) ping 12345-10.200.200.54@o2ib: late network completion</div>
<div dir="auto">Sep 15 10:17:58 node113 systemd-logind: Removed session 89.</div>
<div dir="auto">Sep 15 10:18:42 node113 kernel: LNet: 14296:0:(api-ni.c:4175:lnet_ping()) ping 12345-10.200.200.54@o2ib: late network completion</div>
<div dir="auto">Sep 15 10:19:42 node113 kernel: LNet: 14296:0:(api-ni.c:4175:lnet_ping()) ping 12345-10.200.200.54@o2ib: late network completion</div>
<div dir="auto">Sep 15 10:19:53 node113 systemd-logind: New session 90 of user root.</div>
<div dir="auto">Sep 15 10:19:53 node113 systemd: Started Session 90 of user root.</div>
<div dir="auto">Sep 15 10:20:42 node113 kernel: LNet: 14296:0:(api-ni.c:4175:lnet_ping()) ping 12345-10.200.200.54@o2ib: late network completion</div>
<div dir="auto">Sep 15 10:21:52 node113 kernel: LustreError: 14973:0:(lmv_obd.c:1415:lmv_statfs()) lz01-MDT0000-mdc-ffff8990be2fb800: can't stat MDS #0: rc = -4</div>
<div dir="auto">Sep 15 10:21:56 node113 kernel: LustreError: 14977:0:(lmv_obd.c:1415:lmv_statfs()) lz01-MDT0000-mdc-ffff8990be2fb800: can't stat MDS #0: rc = -4</div>
<div dir="auto">Sep 15 10:22:29 node113 systemd-logind: New session 91 of user root.</div>
<div dir="auto">Sep 15 10:22:29 node113 systemd: Started Session 91 of user root.</div>
<div dir="auto">Sep 15 10:22:42 node113 kernel: LNet: 14296:0:(api-ni.c:4175:lnet_ping()) ping 12345-10.200.200.54@o2ib: late network completion</div>
<div dir="auto">Sep 15 10:22:42 node113 kernel: LNet: 14296:0:(api-ni.c:4175:lnet_ping()) Skipped 1 previous similar message</div>
<div dir="auto">Sep 15 10:22:50 node113 systemd-logind: Removed session 91.</div>
<div dir="auto">Sep 15 10:23:30 node113 systemd-logind: New session 92 of user root.</div>
<div dir="auto">Sep 15 10:23:30 node113 systemd: Started Session 92 of user root.</div>
<div dir="auto"><br>
</div>
<div dir="auto"><br>
</div>
<div dir="auto"><br>
</div>
<div dir="auto"><br>
</div>
<div dir="auto">&nbsp;Sep 15 10:01:04 storage04 systemd: Removed slice User Slice of root.</div>
<div dir="auto">Sep 15 10:06:16 storage04 kernel: Lustre: MGS: Connection restored to 5b462af8-e997-25fa-7aac-62ef6f834520 (at 10.200.200.113@o2ib)</div>
<div dir="auto">Sep 15 10:07:03 storage04 kernel: Lustre: lz01-MDT0000: Client fd07e75b-dbc1-20b1-ecbf-6f3a96a62d2a (at 10.200.200.113@o2ib) reconnecting</div>
<div dir="auto">Sep 15 10:07:10 storage04 kernel: Lustre: MGS: Client 01e3bd51-26ab-f2bb-6515-6afe3a181876 (at 10.200.200.113@o2ib) reconnecting</div>
<div dir="auto">Sep 15 10:10:01 storage04 systemd: Created slice User Slice of root.</div>
<div dir="auto">Sep 15 10:10:01 storage04 systemd: Started Session 2738 of user root.</div>
<div dir="auto">Sep 15 10:10:01 storage04 systemd: Removed slice User Slice of root.</div>
<div dir="auto">Sep 15 10:10:44 storage04 systemd: Created slice User Slice of root.</div>
<div dir="auto">Sep 15 10:10:44 storage04 systemd-logind: New session 2739 of user root.</div>
<div dir="auto">Sep 15 10:10:44 storage04 systemd: Started Session 2739 of user root.</div>
<div dir="auto">Sep 15 10:10:51 storage04 kernel: Lustre: lz01-MDT0000: haven't heard from client fd07e75b-dbc1-20b1-ecbf-6f3a96a62d2a (at 10.200.200.113@o2ib) in 228 seconds. I think it's dead, and I am evicting it. exp ffff8fc5496cd800, cur 1663251051 expire
 1663250901 last 1663250823</div>
<div dir="auto">Sep 15 10:10:51 storage04 kernel: Lustre: Skipped 1 previous similar message</div>
<div dir="auto">Sep 15 10:11:07 storage04 kernel: Lustre: MGS: haven't heard from client 01e3bd51-26ab-f2bb-6515-6afe3a181876 (at 10.200.200.113@o2ib) in 237 seconds. I think it's dead, and I am evicting it. exp ffff8fc6f0df9800, cur 1663251067 expire 1663250917
 last 1663250830</div>
<div dir="auto">Sep 15 10:12:07 storage04 systemd-logind: Removed session 2739.</div>
<div><br>
</div>
</div>
<div dir="auto"><br>
</div>
<div dir="auto" id="tmjah_g_1299">
<p>Robert E. Anderson</p>
<p>University of NH / Research Computing Center / Data Center Operations</p>
<p><br>
</p>
</div>
<br>
</div>
</div>
</div>
</div>
</body>
</html>