[Lustre-discuss] Client Eviction Preceded by EHOSTUNREACH and then ENOTCONN?

Mon Jul 11 22:39:34 UTC 2011

Hi,

We are seeing intermittent client evictions from a new Lustre installation that we are testing. The errors on writes from a parallel job running on 32 client nodes, each with 16 tasks writing a single HDF5 file of ~40MB (512 tasks total). Occasionally, one nodes will be evicted from an OST, and the code running on the client will experience an IO error.

The directory with the data has a stripe count of 1, and a comparable amount is read in at the start of the job. Sometimes the evictions occur the first time a write is attempted, sometimes after a successful write. There is about 15 minutes before the first and subsequent write attempts.

The client and server errors are attached. In the server errors, XXX.XXX.118.141 refers to the client that gets evicted. In the client errors, here are the server names to match with the NIDS:
  lustre-oss-0-2: 172.25.33.248
  lustre-oss-2-0: 172.25.33.246
  lustre-oss-2-2: 172.25.32.118
I am assuming that -113 is EHOSTUNREACH and -107 is ENOTCONN, and that the error codes from errno.h are being used.

We've been experiencing similar problems for a while, and we've never seen IP traffic have a problem. But, clients will begin to have trouble communicating with the Lustre server (seen because an LNET ping will return an I/O error), and things will only recover when an LNET ping is performed from the server to the client NID.

The filesystem is in testing, so there is no other load on it, and when watching the load during writes, the OSS machines hardly notice. The servers are running version 1.8.5, and the client 1.8.4.

Any advice, or pointers to possible bugs would be appreciated.

Thanks,
Rick

-------------- next part --------------
Jul  6 15:07:45 lustre-oss-2-2.local kernel: LustreError: 23681:0:(events.c:381:server_bulk_callback()) event type 2, status -113, desc ffff8105256b3c00 
Jul  6 15:07:45 lustre-oss-2-2.local kernel: LustreError: 24049:0:(ost_handler.c:1073:ost_brw_write()) @@@ network error on bulk GET 0(40960)  req at ffff8103e1f1dc00 x1372441561093199/t0 o4->2da500e9-f52c-3978-ce0e-be4518714347 at NET_0x20000c6ca768d_UUID:0/0 lens 464/416 e 0 to 0 dl 1309990076 ref 1 fl Interpret:/0/0 rc 0/0 
Jul  6 15:07:45 lustre-oss-2-2.local kernel: LustreError: 23667:0:(events.c:381:server_bulk_callback()) event type 2, status -113, desc ffff8101d7280000 
Jul  6 15:07:45 lustre-oss-2-2.local kernel: LustreError: 24095:0:(ost_handler.c:1073:ost_brw_write()) @@@ network error on bulk GET 0(1048576)  req at ffff810147243c00 x1372437788293191/t0 o4->d10b9ac8-f4d2-637c-c3a8-cdccfd5bf07d at NET_0x20000c6ca7662_UUID:0/0 lens 448/416 e 0 to 0 dl 1309990071 ref 1 fl Interpret:/0/0 rc 0/0 
Jul  6 15:07:45 lustre-oss-2-0.local kernel: LustreError: 24091:0:(events.c:381:server_bulk_callback()) event type 2, status -113, desc ffff81043032a000 
Jul  6 15:07:45 lustre-oss-2-0.local kernel: LustreError: 24511:0:(ost_handler.c:1073:ost_brw_write()) @@@ network error on bulk GET 0(1048576)  req at ffff8103b380f400 x1372441561093193/t0 o4->2da500e9-f52c-3978-ce0e-be4518714347 at NET_0x20000c6ca768d_UUID:0/0 lens 464/416 e 0 to 0 dl 1309990071 ref 1 fl Interpret:/0/0 rc 0/0 
Jul  6 15:07:45 lustre-oss-0-2.local kernel: LustreError: 10295:0:(events.c:381:server_bulk_callback()) event type 2, status -113, desc ffff81050cf70000 
Jul  6 15:07:45 lustre-oss-0-2.local kernel: LustreError: 10677:0:(ost_handler.c:1073:ost_brw_write()) @@@ network error on bulk GET 0(1048576)  req at ffff8105469cc800 x1372441561093196/t0 o4->2da500e9-f52c-3978-ce0e-be4518714347 at NET_0x20000c6ca768d_UUID:0/0 lens 448/416 e 0 to 0 dl 1309990072 ref 1 fl Interpret:/0/0 rc 0/0 
Jul  6 15:07:52 lustre-oss-2-2.local kernel: LustreError: 23922:0:(ldlm_lib.c:1919:target_send_reply_msg()) @@@ processing error (-16)  req at ffff810268226c00 x1372437788293751/t0 o8->d10b9ac8-f4d2-637c-c3a8-cdccfd5bf07d at NET_0x20000c6ca7662_UUID:0/0 lens 368/264 e 0 to 0 dl 1309990172 ref 1 fl Interpret:/0/0 rc -16/0 
Jul  6 15:07:52 lustre-oss-0-2.local kernel: LustreError: 29773:0:(ldlm_lib.c:1919:target_send_reply_msg()) @@@ processing error (-16)  req at ffff8101a7e73450 x1372441561093716/t0 o8->2da500e9-f52c-3978-ce0e-be4518714347 at NET_0x20000c6ca768d_UUID:0/0 lens 368/264 e 0 to 0 dl 1309990172 ref 1 fl Interpret:/0/0 rc -16/0 
Jul  6 15:07:52 lustre-oss-2-2.local kernel: LustreError: 24118:0:(ost_handler.c:1064:ost_brw_write()) @@@ Reconnect on bulk GET  req at ffff8101d5214000 x1372437788293198/t0 o4->d10b9ac8-f4d2-637c-c3a8-cdccfd5bf07d at NET_0x20000c6ca7662_UUID:0/0 lens 448/416 e 1 to 0 dl 1309990097 ref 1 fl Interpret:/0/0 rc 0/0 
Jul  6 15:07:52 lustre-oss-2-2.local kernel: LustreError: 24118:0:(ost_handler.c:1064:ost_brw_write()) Skipped 2 previous similar messages 
Jul  6 15:07:52 lustre-oss-0-2.local kernel: LustreError: 138-a: phase1-OST0009: A client on nid XXX.XXX.118.141 at tcp was evicted due to a lock blocking callback to XXX.XXX.118.141 at tcp timed out: rc -107 
Jul  6 15:07:52 lustre-oss-0-2.local kernel: LustreError: 10636:0:(ldlm_lockd.c:1174:ldlm_handle_enqueue()) ### lock on destroyed export ffff81033e03a600 ns: filter-phase1-OST0009_UUID lock: ffff81025cd00a00/0x6fe441ccea649245 lrc: 3/0,0 mode: --/PW res: 5673/0 rrc: 2 type: EXT [0->1048575] (req 0->1048575) flags: 0x0 remote: 0xc65408cd7811ce69 expref: 13 pid: 10636 timeout 0 
Jul  6 15:07:52 lustre-oss-0-2.local kernel: LustreError: 10738:0:(ost_handler.c:1060:ost_brw_write()) @@@ Eviction on bulk GET  req at ffff81017299e000 x1372441561093207/t0 o4->2da500e9-f52c-3978-ce0e-be4518714347 at NET_0x20000c6ca768d_UUID:0/0 lens 448/416 e 1 to 0 dl 1309990099 ref 1 fl Interpret:/0/0 rc 0/0 
Jul  6 15:07:57 lustre-oss-2-2.local kernel: LustreError: 23954:0:(ldlm_lib.c:1919:target_send_reply_msg()) @@@ processing error (-16)  req at ffff8101a5977c00 x1372441561093719/t0 o8->2da500e9-f52c-3978-ce0e-be4518714347 at NET_0x20000c6ca768d_UUID:0/0 lens 368/264 e 0 to 0 dl 1309990177 ref 1 fl Interpret:/0/0 rc -16/0 
Jul  6 15:07:58 lustre-oss-2-2.local kernel: LustreError: 13541:0:(ost_handler.c:1064:ost_brw_write()) @@@ Reconnect on bulk GET  req at ffff81060f5a3400 x1372441561093195/t0 o4->2da500e9-f52c-3978-ce0e-be4518714347 at NET_0x20000c6ca768d_UUID:0/0 lens 448/416 e 1 to 0 dl 1309990107 ref 1 fl Interpret:/0/0 rc 0/0 
Jul  6 15:07:58 lustre-oss-2-2.local kernel: LustreError: 13541:0:(ost_handler.c:1064:ost_brw_write()) Skipped 1 previous similar message 
Jul  6 15:09:48 lustre-oss-2-0.local kernel: LustreError: 24303:0:(ldlm_lib.c:1919:target_send_reply_msg()) @@@ processing error (-16)  req at ffff810532c01c00 x1372441561094298/t0 o8->2da500e9-f52c-3978-ce0e-be4518714347 at NET_0x20000c6ca768d_UUID:0/0 lens 368/264 e 0 to 0 dl 1309990288 ref 1 fl Interpret:/0/0 rc -16/0 
Jul  6 15:09:49 lustre-oss-2-0.local kernel: LustreError: 24467:0:(ost_handler.c:1064:ost_brw_write()) @@@ Reconnect on bulk GET  req at ffff810603c3e400 x1372441561093197/t0 o4->2da500e9-f52c-3978-ce0e-be4518714347 at NET_0x20000c6ca768d_UUID:0/0 lens 448/416 e 3 to 0 dl 1309990253 ref 1 fl Interpret:/0/0 rc 0/0 
-------------- next part --------------

-------------- next part --------------
rpwagner at ubuntu-devel:~/Projects/vl3/vlUtility/build/test$ ./CeleritasStreamClient 192.168.56.101 50000 10 704 576
Bufsize is 1216512
 Recv Size 1216512
 Remote HOST IS 192.168.56.101  Remote Port is  50000
 Local Host 192.168.56.102 : Local Port 58945
 Recv Size -16515074
TOTAL READ BW IS Mbps 10.833
rpwagner at ubuntu-devel:~/Projects/vl3/vlUtility/build/test$ 