<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.  </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"> 4 system (2 MDS + 2 OSS) zfs backed Lustre 2.12.9 server  on AMD (EPYC 7402P).  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 & kernel over 3 EDR switches (4 cables each from center to edge switches). Hardware is a mix of Intel CPUs & 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.  The IB network is not reporting any errors, and running at full rates to each client.  Only
 errors appear to be at the lnet level, and start on the client side.  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.  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.  We found that Bonnie++ and fio tests could cause these client lockups to one of the OSS nodes.  Swapping
 hardware between server nodes didn't reveal any pattern, and eventually we moved an entirely new node which failed in the same manner.  About 2/3 of the clients can be made to lockup, but no pattern in their individual hardware or network location seems to
 exist.   The remaining nodes seem to work perfectly with this new Lustre storage.  The same sort of client RDM lockup has also been generated to a MDS with a simple "ls" 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  log from that simplest of cases.</div>
<div dir="auto"><br>
</div>
<div dir="auto"> 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]  req@ffff899095d04800 x1744044838356992/t0(0) o101->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]  req@ffff899095d04c80 x1744044838357056/t0(0) o400->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"> 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>