better understanding rdma-cm UNREACHABLE/ETIMEDOUT scheme
Hi Sean,
We have a user space application which is made of M (clients) x N (servers) RC connectivity pattern using librdmacm. Basically, there are N nodes, each running M client process and each client connects to all N servers.
So under some unknown conditions, many of the clients connection attempts fail with RDMA_CM_EVENT_UNREACHABLE event and the status is -ETIMEDOUT. Looking on the rdma-cm kernel code, I see that the only location which generates this event is in cma_ib_handler when getting IB_CM_REQ_ERROR (or IB_CM_REP_ERROR).
Digging down into the CM, I see that the only place where IB_CM_REQ_ERROR is delivered is on cm_process_send_error which is called when the status of mad send completion is not success or flush.
Digging down into the MAD code and the CM usage of it, I see that that the mad code will issue a mac send completion handler with the IB_WC_RESP_TIMEOUT_ERR status, and that the CM code programs the number of retries set by its consumer (rdma-cm in this case) into the mad send buffer.
Running this over an M=8 and N=4setup, e.g four nodes, each running one server process and eight client processes and sampling the IB CM counters before and after the job and adding the numbers from the four nodes, we see the following
cm_tx_msgs.req = 395
cm_tx_retries.req= 270
cm_rx_msgs.req= 390
cm_tx_msgs.rep= 375
cm_tx_retries.rep= 255
cm_rx_msgs.rep= 380
cm_tx_msgs.rtu= 108
cm_rx_msgs.rtu= 103
cm_tx_msgs.mra= 540
cm_rx_msgs.mra= 270
cm_tx_retries.mra= 270
In cm_send_handler we see that the CM TX retry counter is incremented with the number of retries reported
by the MAD layer, I also see that the RDMA-CM programs the CM to do 15 retries and the CM further programs this into the MAD send buffers.
From the RTU counters its clear that at most ~100 connections got established out of 128.
One thing seen in the nodes dmesg is a message from an old patch of yours which exists in ofed1.5.3 but didn't hit (or wasn't accepted?) upstream saying "ib_cm: calculated mra timeout 67584 > 8192, decreasing used timeout_ms" does this provides any insight into the problem?
One more piece of info, is that this apps doesn't call rdma_disconnect at all, when they are done or if something goes wrong (e.g that unreachable event) they simply issue rdma_destroy_id which when I look on the rdma-cm/cm code gets to a CM function whic sends a dreq (if the ID is in the established state) and puts the ID in the timewait zone.
So it seems we're not loosing mads, also on the stack they use (that 1.5.3) the ucma backlog size is 128
but each server process gets only 32 request (8x4) so we don't think ucma dropping REQs as of no more backlog budget takes place.
Or.
--
To unsubscribe from this list: send the line "unsubscribe linux-rdma" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html
A message that is not in the archive (sent off-list or not yet received): 519B8DB3.3010500-VPRAkNaXOzVWk0Htik3J/[email protected]
Quoted 5 lines
So under some unknown conditions, many of the clients connection attempts fail with
RDMA_CM_EVENT_UNREACHABLEevent and the status is-ETIMEDOUT. Looking on the rdma-cm kernel code, I see that the only location which generates this event is incma_ib_handlerwhen gettingIB_CM_REQ_ERROR(orIB_CM_REP_ERROR).
Does the server continue to run and accept connections during the running of this test?
Quoted 9 lines
Digging down into the CM, I see that the only place where
IB_CM_REQ_ERRORis delivered is oncm_process_send_errorwhich is called when the status of mad send completion is not success or flush.Digging down into the MAD code and the CM usage of it, I see that that the mad code will issue a mac send completion handler with the
IB_WC_RESP_TIMEOUT_ERRstatus, and that the CM code programs the number of retries set by its consumer (rdma-cm in this case) into the mad send buffer.
Correct - it appears that the connection requests are timing out.
Quoted 4 lines
Running this over an M=8 and N=4setup, e.g four nodes, each running one server process and eight client processes and sampling the IB CM counters before and after the job and adding the numbers from the four nodes, we see the following
This is such a small number of nodes/clients, that it shouldn't be related to scaling. The normal timeout/retry mechanism should work fine.
Quoted 20 lines
cm_tx_msgs.req = 395
cm_tx_retries.req= 270
cm_rx_msgs.req= 390cm_tx_msgs.rep= 375
cm_tx_retries.rep= 255
cm_rx_msgs.rep= 380cm_tx_msgs.rtu= 108
cm_rx_msgs.rtu= 103cm_tx_msgs.mra= 540
cm_rx_msgs.mra= 270
cm_tx_retries.mra= 270In
cm_send_handlerwe see that the CM TX retry counter is incremented with the number of retries reported
by the MAD layer, I also see that the RDMA-CM programs the CM to do 15 retries and the CM further programs this into the MAD send buffers.
Quoted 7 lines
From the RTU counters its clear that at most ~100 connections got
established out of 128.One thing seen in the nodes dmesg is a message from an old patch of yours which exists in ofed1.5.3 but didn't hit (or wasn't accepted?) upstream saying "
ib_cm: calculated mra timeout 67584 > 8192, decreasing usedtimeout_ms" does this provides any insight into the problem?
I don't remember this patch at all. The upstream kernel will respond to duplicate CM REQs by sending an MRA, which should increase the connection timeout. This was added to handle servers which were slow to accept connection requests.
Quoted 5 lines
One more piece of info, is that this apps doesn't call
rdma_disconnectat all, when they are done or if something goes wrong (e.g that unreachable event) they simply issuerdma_destroy_idwhich when I look on the rdma-cm/cm code gets to a CM function whic sends a dreq (if the ID is in the established state) and puts the ID in the timewait zone.
Calling rdma_disconnect shouldn't matter. Destroy will send the DREQ/DREP if the user hasn't disconnected.
Quoted 4 lines
So it seems we're not loosing mads, also on the stack they use (that 1.5.3) the ucma backlog size is 128
but each server process gets only 32 request (8x4) so we don't think ucma dropping REQs as of no more backlog budget takes place.
My first guess is that the server isn't responding to new requests.
- Sean
--
To unsubscribe from this list: send the line "unsubscribe linux-rdma" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html
A message that is not in the archive (sent off-list or not yet received): 1828884A29C6694DAF28B7E6B8A823736FD29AE3-P5GAC/[email protected]
Quoted 1 line · Sean
I don't remember this patch at all.
Alex, can you please send Sean this patch
--
To unsubscribe from this list: send the line "unsubscribe linux-rdma" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html
Quoted 6 lines · Sean
Quoted 4 lines
One thing seen in the nodes dmesg is a message from an old patch of yours which exists in ofed1.5.3 but didn't hit (or wasn't accepted?) upstream saying "
ib_cm: calculated mra timeout 67584 > 8192, decreasing usedtimeout_ms" does this provides any insight into the problem?I don't remember this patch at all.
Alex sent it to you, is that something which is missing upstream or alternatively could create troubles on that ofed stack where its applied?
Quoted 1 line
My first guess is that the server isn't responding to new requests.
yep, smells like this could be the root cause here, Dina and Alex will do some tweaking of the server code to make sure there's no starvation is servicing new connection requests.
Or.
--
To unsubscribe from this list: send the line "unsubscribe linux-rdma" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html
A message that is not in the archive (sent off-list or not yet received): CAJZOPZJ44fgPtBHpu5eXSVUQb0zP7rJH1UvL2RneDCrhGVLSwQ-JsoAwUIsXosN+BqQ9rBEUg@public.gmane.org
Quoted 10 lines
Quoted 6 lines
Quoted 4 lines
One thing seen in the nodes dmesg is a message from an old patch of yours which exists in ofed1.5.3 but didn't hit (or wasn't accepted?) upstream saying "
ib_cm: calculated mra timeout 67584 > 8192, decreasing usedtimeout_ms" does this provides any insight into the problem?I don't remember this patch at all.
Alex sent it to you, is that something which is missing upstream or alternatively could create troubles on that ofed stack where its applied?
I saw the patch and recall it now. It was a fix for an SRP target and shouldn't affect your tests or cause any issues. --
To unsubscribe from this list: send the line "unsubscribe linux-rdma" in
the body of a message to [email protected]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Quoted 1 line · Sean
My first guess is that the server isn't responding to new requests. - Sean
This is where we're looking now.
Now testing on 17 server with 8 clients per server.
When disabling all RDMA traffic in the test we get 100% RDMA connection established. So at least we know this is not some fundamental issue with our setup.
Modifying our code to increasing the priority of RDMA connection handling to be higher then the RDMA traffic (CQ completions handling) we still see many UNREACHABLE events. But only after quite a few client got connected and started pushing traffic (1GB RDMA WRITEs from server to client).
We are now adding code (via the conn_attr private data) to compare timestamp between the rdma_conenct, RDMA_CM_EV_CONNECT_REQ, rdma_accept and on the client events of UNREACHABLE or CONNECTED. We'll have better understand once we see these results.
thanks,
Alex
--
To unsubscribe from this list: send the line "unsubscribe linux-rdma" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html
A message that is not in the archive (sent off-list or not yet received): 519DF00C.9010304-VPRAkNaXOzVWk0Htik3J/[email protected]
Quoted 8 lines · Alex Rosenbaum
Quoted 1 line · Sean
My first guess is that the server isn't responding to new requests. - Sean
This is where we're looking now.
Now testing on 17 server with 8 clients per server.When disabling all RDMA traffic in the test we get 100% RDMA connection established. So at least we know this is not some fundamental issue with our setup.
Quoted 8 lines
Modifying our code to increasing the priority of RDMA connection handling to be higher then the RDMA traffic (CQ completions handling) we still see many UNREACHABLE events. But only after quite a few client got connected and started pushing traffic (1GB RDMA WRITEs from server to client).
We are now adding code (via the
conn_attrprivate data) to compare timestamp between therdma_conenct,RDMA_CM_EV_CONNECT_REQ,rdma_acceptand on the client events of UNREACHABLE or CONNECTED. We'll have better understand once we see these results.thanks,
Alex
We found the peace of code that got the server to hang for so long, enough to causes the rdma_connect() to fail on the client side with retries with RDMA_CM_EVENT_UNREACHABLE(-TIMEDOUT) OK, case closed.
--
To unsubscribe from this list: send the line "unsubscribe linux-rdma" in the body of a message to [email protected] More majordomo info at http://vger.kernel.org/majordomo-info.html