Re: [PATCH for-rc v1] RDMA/rxe: Avoid CQ polling hang triggered by CQ resize

[Zhu Yanjun <yanjun.zhu@linux.dev>]

在 2025/8/22 21:19, Daisuke Matsuda 写道:
> On 2025/08/21 12:12, Zhu Yanjun wrote:
>> 在 2025/8/19 8:15, Daisuke Matsuda 写道:
>>> On 2025/08/18 13:44, Zhu Yanjun wrote:
>>>> 在 2025/8/17 5:37, Daisuke Matsuda 写道:
>>>>> When running the test_resize_cq testcase from rdma-core, polling a
>>>>> completion queue from userspace may occasionally hang and 
>>>>> eventually fail
>>>>> with a timeout:
>>>>> =====
>>>>> ERROR: test_resize_cq (tests.test_cq.CQTest.test_resize_cq)
>>>>> Test resize CQ, start with specific value and then increase and 
>>>>> decrease
>>>>> ---------------------------------------------------------------------- 
>>>>>
>>>>> Traceback (most recent call last):
>>>>>      File "/root/deb/rdma-core/tests/test_cq.py", line 135, in 
>>>>> test_resize_cq
>>>>>        u.poll_cq(self.client.cq)
>>>>>      File "/root/deb/rdma-core/tests/utils.py", line 687, in poll_cq
>>>>>        wcs = _poll_cq(cq, count, data)
>>>>>              ^^^^^^^^^^^^^^^^^^^^^^^^^
>>>>>      File "/root/deb/rdma-core/tests/utils.py", line 669, in _poll_cq
>>>>>        raise PyverbsError(f'Got timeout on polling ({count} CQEs 
>>>>> remaining)')
>>>>> pyverbs.pyverbs_error.PyverbsError: Got timeout on polling (1 CQEs
>>>>> remaining)
>>>>> =====
>>>>>
>>>>> The issue is caused when rxe_cq_post() fails to post a CQE due to 
>>>>> the queue
>>>>> being temporarily full, and the CQE is effectively lost. To 
>>>>> mitigate this,
>>>>> add a bounded busy-wait with fallback rescheduling so that CQE 
>>>>> does not get
>>>>> lost.
>>>>>
>>>>> Signed-off-by: Daisuke Matsuda <dskmtsd@gmail.com>
>>>>> ---
>>>>>   drivers/infiniband/sw/rxe/rxe_cq.c | 27 +++++++++++++++++++++++++--
>>>>>   1 file changed, 25 insertions(+), 2 deletions(-)
>>>>>
>>>>> diff --git a/drivers/infiniband/sw/rxe/rxe_cq.c 
>>>>> b/drivers/infiniband/ sw/rxe/rxe_cq.c
>>>>> index fffd144d509e..7b0fba63204e 100644
>>>>> --- a/drivers/infiniband/sw/rxe/rxe_cq.c
>>>>> +++ b/drivers/infiniband/sw/rxe/rxe_cq.c
>>>>> @@ -84,14 +84,36 @@ int rxe_cq_resize_queue(struct rxe_cq *cq, int 
>>>>> cqe,
>>>>>   /* caller holds reference to cq */
>>>>>   int rxe_cq_post(struct rxe_cq *cq, struct rxe_cqe *cqe, int 
>>>>> solicited)
>>>>>   {
>>>>> +    unsigned long flags;
>>>>> +    u32 spin_cnt = 3000;
>>>>>       struct ib_event ev;
>>>>> -    int full;
>>>>>       void *addr;
>>>>> -    unsigned long flags;
>>>>> +    int full;
>>>>>       spin_lock_irqsave(&cq->cq_lock, flags);
>>>>>       full = queue_full(cq->queue, QUEUE_TYPE_TO_CLIENT);
>>>>> +    if (likely(!full))
>>>>> +        goto post_queue;
>>>>> +
>>>>> +    /* constant backoff until queue is ready */
>>>>> +    while (spin_cnt--) {
>>>>> +        full = queue_full(cq->queue, QUEUE_TYPE_TO_CLIENT);
>>>>> +        if (!full)
>>>>> +            goto post_queue;
>>>>> +
>>>>> +        cpu_relax();
>>>>> +    }
>>>>
>>>> The loop runs 3000 times.
>>>> Each iteration:
>>>>
>>>> Checks queue_full()
>>>> Executes cpu_relax()
>>>>
>>>> On modern CPUs, each iteration may take a few cycles, e.g., 4–10 
>>>> cycles per iteration (depends on memory/cache).
>>>>
>>>> Suppose 1 cycle = ~0.3 ns on a 3 GHz CPU, 10 cycles ≈ 3 ns
>>>> 3000 iterations × 10 cycles ≈ 30,000 cycles
>>>>
>>>> 30000 cycles * 0.3 ns = 9000 ns = 9 microseconds
>>>>
>>>> So the “critical section” while spinning is tens of microseconds, 
>>>> not milliseconds.
>>>>
>>>> I was concerned that 3000 iterations might make the spin lock 
>>>> critical section too long, but based on the analysis above, it 
>>>> appears that this is still a short-duration critical section.
>>>
>>> Thank you for the review.
>>>
>>> Assuming the two loads in queue_full() hit in the L1 cache, I 
>>> estimate each iteration could take around
>>> 15–20 cycles. Based on your calculation, the maximum total time 
>>> would be approximately 18 microseconds.
>>
>> ======================================================================
>> ERROR: test_rdmacm_async_write (tests.test_rdmacm.CMTestCase)
>> ----------------------------------------------------------------------
>> Traceback (most recent call last):
>>    File "/..../rdma-core/tests/test_rdmacm.py", line 71, in 
>> test_rdmacm_async_write
>>      self.two_nodes_rdmacm_traffic(CMAsyncConnection,
>>    File "/..../rdma-core/tests/base.py", line 447, in 
>> two_nodes_rdmacm_traffic
>>      raise Exception('Exception in active/passive side occurred')
>> Exception: Exception in active/passive side occurred
>>
>> After appying your commit, I run the following run_tests.py for 10000 
>> times.
>> The above error sometimes will appear. The frequency is very low.
>>
>> "
>> for (( i = 0; i < 10000; i++ ))
>> do
>>      rdma-core/build/bin/run_tests.py --dev rxe0
>> done
>> "
>> It is weird.
>
> I tried running test_rdmacm_async_write alone for 50000 times, but 
> could not reproduce this one.
> There have been multiple latency-related issues in RXE, so it is not 
> surprising a new one is
> uncovered by changing seemingly irrelevant part.
>
> How about applying additional change below:
> ===
> diff --git a/drivers/infiniband/sw/rxe/rxe_cq.c 
> b/drivers/infiniband/sw/rxe/rxe_cq.c
> index 7b0fba63204e..8f8d56051b8d 100644
> --- a/drivers/infiniband/sw/rxe/rxe_cq.c
> +++ b/drivers/infiniband/sw/rxe/rxe_cq.c
> @@ -102,7 +102,9 @@ int rxe_cq_post(struct rxe_cq *cq, struct rxe_cqe 
> *cqe, int solicited)
>                 if (!full)
>                         goto post_queue;
>
> +               spin_unlock_irqrestore(&cq->cq_lock, flags);
>                 cpu_relax();
> +               spin_lock_irqsave(&cq->cq_lock, flags);
>         }
>
>         /* try giving up cpu and retry */
> ===
> This makes cpu_relax() almost meaningless, but ensures the lock is 
> released in each iteration.
>
> It would be nice if you could provide the frequency and whether it 
> takes longer than usual in failure cases.
> I think that could be helpful as a starting point to find a solution.


With a clean KVM QEMU VM, after applying your commit, the same problem 
occurs every time the above script is run.

Yanjun.Zhu


>
> Thanks,
> Daisuke
>
>>
>> Yanjun.Zhu
>>
>
>
-- 
Best Regards,
Yanjun.Zhu