Details
-
Bug
-
Resolution: Unresolved
-
Minor
-
None
-
None
-
None
-
3
-
9223372036854775807
Description
While testing a patch I observed the following. It causes client I/O to pause for 3 minutes.
Client sends OST_WRITE: 00000100:00100000:18.0:1747414833.706272:0:23387:0:(client.c:1739:ptlrpc_send_new_req()) Sending RPC req@0000000082a49555 pname:cluuid:pid:xid:nid:opc:job ptlrpcd_04_02:374cc1c6-8429-4b07-8b62-e2126738e254:23387:1832221755976640:16@kfi:4: 00000100:00000200:18.0:1747414833.707643:0:321:0:(events.c:64:request_out_callback()) @@@ type 5, status 0 req@0000000082a49555 x1832221755976640/t0(0) o4->lustre-OST0000-osc-ffff914438ce6000@16@kfi:6/4 lens 488/448 e 0 to 0 dl 1747414986 ref 3 fl Rpc:r/0/ffffffff rc 0/-1 job:'' Server starts handling: 00000100:00100000:16.0:1747414833.741533:0:2453229:0:(service.c:2398:ptlrpc_server_handle_req_in()) got req x1832221755976640 00000100:00100000:17.0:1747414833.744217:0:2451940:0:(service.c:2570:ptlrpc_server_handle_request()) Handling RPC req@0000000034418825 pname:cluuid+ref:pid:xid:nid:opc:job ll_ost_io05_000:374cc1c6-8429-4b07-8b62-e2126738e254+95:23387:x1832221755976640:12345-1@kfi:4: Client disconnect, reconnect, and resend: 00000100:00080000:3.0:1747414833.769865:0:23370:0:(import.c:83:import_set_state_nolock()) 00000000ff08514c lustre-OST0000_UUID: changing import state from FULL to DISCONN 00000100:00080000:1.0:1747414833.813929:0:15920:0:(import.c:83:import_set_state_nolock()) 00000000ff08514c lustre-OST0000_UUID: changing import state from DISCONN to CONNECTING 00000100:00080000:10.0:1747414833.847275:0:23368:0:(import.c:83:import_set_state_nolock()) 00000000ff08514c lustre-OST0000_UUID: changing import state from CONNECTING to RECOVER 00000100:00080000:10.0:1747414833.847314:0:23368:0:(client.c:3036:ptlrpc_resend_req()) @@@ going to resend req@0000000082a49555 x1832221755976640/t0(0) o4->lustre-OST0000-osc-ffff914438ce6000@16@kfi:6/4 lens 488/448 e 0 to 0 dl 1747414986 ref 2 fl Rpc:eQr/0/ffffffff rc 0/-1 job:'' 00000100:00080000:10.0:1747414833.847317:0:23368:0:(import.c:83:import_set_state_nolock()) 00000000ff08514c lustre-OST0000_UUID: changing import state from RECOVER to FULL Server sees duplicate request and discards: 00000100:00080000:16.0:1747414833.847115:0:2453103:0:(service.c:2100:ptlrpc_server_request_add()) @@@ Found duplicate req in processing req@00000000f987a5ed x1832221755976640/t0(0) o4->374cc1c6-8429-4b07-8b62-e2126738e254@1@kfi:640/0 lens 488/0 e 0 to 0 dl 1747414920 ref 1 fl New:/2/ffffffff rc 0/-1 job:'' 00000100:00080000:16.0:1747414833.847118:0:2453103:0:(service.c:2101:ptlrpc_server_request_add()) @@@ Request being processed req@0000000034418825 x1832221755976640/t0(0) o4->374cc1c6-8429-4b07-8b62-e2126738e254@1@kfi:640/0 lens 488/448 e 0 to 0 dl 1747414920 ref 2 fl Interpret:/0/0 rc 0/0 job:'' Server fails bulk write because of reconnect: 00010000:00020000:17.0:1747414834.797193:0:2451940:0:(ldlm_lib.c:3601:target_bulk_io()) @@@ Reconnect on bulk WRITE req@0000000034418825 x1832221755976640/t0(0) o4->374cc1c6-8429-4b07-8b62-e2126738e254@1@kfi:640/0 lens 488/448 e 0 to 0 dl 1747414920 ref 1 fl Interpret:/0/0 rc 0/0 job:'' 00000100:00020000:17.0:1747414960.685895:0:2552251:0:(events.c:484:server_bulk_callback()) event #1832221755976640/682655eea2bc0 type 5, status -110, desc 0000000048604b68/ffff9a131da21800 Client now waits full timeout period for reply: 00000100:00000400:19.0F:1747415040.929986:0:23387:0:(client.c:2310:ptlrpc_expire_one_request()) @@@ Request sent has timed out for slow reply: [sent 1747414833/real 1747414833] req@0000000082a49555 x1832221755976640/t0(0) o4->lustre-OST0000-osc-ffff914438ce6000@16@kfi:6/4 lens 488/448 e 2 to 1 dl 1747415040 ref 2 fl Rpc:XQr/2/ffffffff rc -11/-1 job:''
The BRW resend gets new match bits (struct ptlrpc_request::rq_mbits and struct ptlrpc_request::rq_rep_mbits) but not a new xid. So server sees it as a duplicate and discards. Existing RPCs should have the reply match bits updated so replies for the old request will match the new reply buffer on the client. However, BRW rpcs are special in that they are completely dropped by the server upon client reconnect. In this case we actually want the server to process the "duplicate" request. Thus, it seems the duplicate checking should be skipped for BRW RPCs.