From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by smtp.lore.kernel.org (Postfix) with ESMTP id AD8DDC433F5 for ; Fri, 15 Apr 2022 07:50:00 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1351232AbiDOHw0 (ORCPT ); Fri, 15 Apr 2022 03:52:26 -0400 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:36624 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S232094AbiDOHwZ (ORCPT ); Fri, 15 Apr 2022 03:52:25 -0400 Received: from mail-oa1-x36.google.com (mail-oa1-x36.google.com [IPv6:2001:4860:4864:20::36]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id CD17899EEE for ; Fri, 15 Apr 2022 00:49:57 -0700 (PDT) Received: by mail-oa1-x36.google.com with SMTP id 586e51a60fabf-e2afb80550so7538306fac.1 for ; Fri, 15 Apr 2022 00:49:57 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20210112; h=message-id:date:mime-version:user-agent:subject:content-language:to :references:from:in-reply-to:content-transfer-encoding; bh=AdiIhJXv5Q4CsGK7TV0G57J1pdbxyNx3KcaOKgIzc2I=; b=LcKG0g+JkHZmRcr5Th8pvymlSaHToVmgOgTZ4r2wjnwUg78Y1OgTkw7UPUAalAl4eb yQdwVJtAVvcOiUu6rnHidmS28qTw+yuFWahRWHJGttovTBr+aqEPjITja97ebwcORzV2 G1HYmql+/ocS/IZesA5yrLgnBvLMSMevF8pZHgztxCix6JPgdgRjSm4cQvy/ZGcmwlsi C3eSqSwd2pze7u8iulAYR4/4/y+FHTcIV+wEzNsjRhOtKRvGygnroX7te7e4stWTph2W SD6eMS3FoNcN7zEF+0UwEoPU56H88rlmF8BzjVNnwk2o2/i/hCzAW9BUvlic2eNihPGh rzbQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20210112; h=x-gm-message-state:message-id:date:mime-version:user-agent:subject :content-language:to:references:from:in-reply-to :content-transfer-encoding; bh=AdiIhJXv5Q4CsGK7TV0G57J1pdbxyNx3KcaOKgIzc2I=; b=lXU/uFv5u83YdDRfqRn3zz6sMA70+IgKcacBC3I4/udft1ePRvYh8YkLjIsNwD01aS dqMY3US9Oo2BmDIF6AAOp5lPHOl6eLkvVcidLkMZ6dyUrtupfEsGNFfGQnTDrvDEYjZi KxNqJq+b4R8F4Xr5qwZY/HnJH/WoKv+itq2D2z6X+MqVenQyKfLpxV6boPmyghUKE//+ EG2uCXLG7Tcykq4m88Wlo1V8wTh4BTBeFsvYool/6DdH/4xJW62kc3GLRk6H0Kqwqpa/ 9XhYd1USRoQy96pvKHDSLMdP2233Vf+1bE8XUudyYxwidbH2jrCEXV3bzt9izuU+y2Cc fHVQ== X-Gm-Message-State: AOAM530r54A0H8RsGWObHav1Y9Za9DB/uwQk7PU/lbR295B4dhCQxjdX fHglpffIaDDXavbPYu/HA2w= X-Google-Smtp-Source: ABdhPJzqQ3sWoJ1Dx+WzBxXnlUsgG+/zMj5FIZCVp07FfQqmDQAn6Cqw5FdkJMLToPednpr2v4+NXw== X-Received: by 2002:a05:6870:4290:b0:e2:b4c9:ea5a with SMTP id y16-20020a056870429000b000e2b4c9ea5amr938739oah.173.1650008996980; Fri, 15 Apr 2022 00:49:56 -0700 (PDT) Received: from ?IPV6:2603:8081:140c:1a00:447:11e9:73f1:b59c? (2603-8081-140c-1a00-0447-11e9-73f1-b59c.res6.spectrum.com. [2603:8081:140c:1a00:447:11e9:73f1:b59c]) by smtp.gmail.com with ESMTPSA id f21-20020a056830205500b005cdb59d5d34sm858550otp.81.2022.04.15.00.49.56 (version=TLS1_3 cipher=TLS_AES_128_GCM_SHA256 bits=128/128); Fri, 15 Apr 2022 00:49:56 -0700 (PDT) Message-ID: <179daa3b-3f35-524e-6b8b-b9b4901ac5d2@gmail.com> Date: Fri, 15 Apr 2022 02:49:55 -0500 MIME-Version: 1.0 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:91.0) Gecko/20100101 Thunderbird/91.7.0 Subject: Re: [PATCHv4 1/2] RDMA/rxe: Fix a dead lock problem Content-Language: en-US To: Yanjun Zhu , jgg@ziepe.ca, leon@kernel.org, linux-rdma@vger.kernel.org References: <20220415195630.279510-1-yanjun.zhu@linux.dev> <0d88246e-c29a-27c0-95c5-da73f52e6a59@linux.dev> <726e75b0-c165-92f8-c367-1a5a777bc8b1@gmail.com> <5597e6eb-1543-6895-77fc-426e0a601338@linux.dev> <72d96848-3414-b665-d800-759986540aed@gmail.com> <11ec6705-a810-6ec9-86f1-584d29b656c6@linux.dev> From: Bob Pearson In-Reply-To: Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Precedence: bulk List-ID: X-Mailing-List: linux-rdma@vger.kernel.org On 4/15/22 02:42, Yanjun Zhu wrote: > 在 2022/4/15 15:35, Bob Pearson 写道: >> On 4/15/22 02:32, Yanjun Zhu wrote: >>> >>> 在 2022/4/15 15:22, Bob Pearson 写道: >>>> On 4/15/22 01:49, Yanjun Zhu wrote: >>>>> 在 2022/4/15 14:35, Bob Pearson 写道: >>>>>> On 4/15/22 00:54, Yanjun Zhu wrote: >>>>>>> 在 2022/4/15 13:37, Bob Pearson 写道: >>>>>>>> On 4/15/22 14:56, yanjun.zhu@linux.dev wrote: >>>>>>>>> From: Zhu Yanjun >>>>>>>>> >>>>>>>>> This is a dead lock problem. >>>>>>>>> The xa_lock first is acquired in this: >>>>>>>>> >>>>>>>>> {SOFTIRQ-ON-W} state was registered at: >>>>>>>>> >>>>>>>>>       lock_acquire+0x1d2/0x5a0 >>>>>>>>>       _raw_spin_lock+0x33/0x80 >>>>>>>>>       __rxe_add_to_pool+0x183/0x230 [rdma_rxe] >>>>>>>>>       __ib_alloc_pd+0xf9/0x550 [ib_core] >>>>>>>>>       ib_mad_init_device+0x2d9/0xd20 [ib_core] >>>>>>>>>       add_client_context+0x2fa/0x450 [ib_core] >>>>>>>>>       enable_device_and_get+0x1b7/0x350 [ib_core] >>>>>>>>>       ib_register_device+0x757/0xaf0 [ib_core] >>>>>>>>>       rxe_register_device+0x2eb/0x390 [rdma_rxe] >>>>>>>>>       rxe_net_add+0x83/0xc0 [rdma_rxe] >>>>>>>>>       rxe_newlink+0x76/0x90 [rdma_rxe] >>>>>>>>>       nldev_newlink+0x245/0x3e0 [ib_core] >>>>>>>>>       rdma_nl_rcv_msg+0x2d4/0x790 [ib_core] >>>>>>>>>       rdma_nl_rcv+0x1ca/0x3f0 [ib_core] >>>>>>>>>       netlink_unicast+0x43b/0x640 >>>>>>>>>       netlink_sendmsg+0x7eb/0xc40 >>>>>>>>>       sock_sendmsg+0xe0/0x110 >>>>>>>>>       __sys_sendto+0x1d7/0x2b0 >>>>>>>>>       __x64_sys_sendto+0xdd/0x1b0 >>>>>>>>>       do_syscall_64+0x37/0x80 >>>>>>>>>       entry_SYSCALL_64_after_hwframe+0x44/0xae >>>>>>>> There is a separate xarray for each object pool. So this one is >>>>>>>> rxe->pd_pool.xa.xa_lock from rxe_alloc_pd(). >>>>>>>> >>>>>>>>> Then xa_lock is acquired in this: >>>>>>>>> >>>>>>>>> {IN-SOFTIRQ-W}: >>>>>>>>> >>>>>>>>> Call Trace: >>>>>>>>>      >>>>>>>>>       dump_stack_lvl+0x44/0x57 >>>>>>>>>       mark_lock.part.52.cold.79+0x3c/0x46 >>>>>>>>>       __lock_acquire+0x1565/0x34a0 >>>>>>>>>       lock_acquire+0x1d2/0x5a0 >>>>>>>>>       _raw_spin_lock_irqsave+0x42/0x90 >>>>>>>>>       rxe_pool_get_index+0x72/0x1d0 [rdma_rxe] >>>>>>>>>       rxe_get_av+0x168/0x2a0 [rdma_rxe] >>>>>>>>>       rxe_requester+0x75b/0x4a90 [rdma_rxe] >>>>>>>>>       rxe_do_task+0x134/0x230 [rdma_rxe] >>>>>>>>>       tasklet_action_common.isra.12+0x1f7/0x2d0 >>>>>>>>>       __do_softirq+0x1ea/0xa4c >>>>>>>>>       run_ksoftirqd+0x32/0x60 >>>>>>>>>       smpboot_thread_fn+0x503/0x860 >>>>>>>>>       kthread+0x29b/0x340 >>>>>>>>>       ret_from_fork+0x1f/0x30 >>>>>>>> And this one is rxe->ah_pool.xa.xa_lock from rxe_requester >>>>>>>> in the process of sending a UD packet from a work request >>>>>>>> which contains the index of the ah. >>>>>>>> >>>>>>>> For your story to work there needs to be an another ah_pool.xa.xa_lock somewhere. >>>>>>>> Let's assume it is there somewhere and it's from (a different) add_to_pool call >>>>>>>> then the add_to_pool_ routine should disable interrupts when it gets the lock >>>>>>>> with spin_lock_xxx. But only for AH objects. >>>>>>>> >>>>>>>> This may be old news. >>>>>>> What do you mean? Please check the call trace in the bug. >>>>>> I mean the trace you show here shows an instance of xa_lock being >>>>>> acquired from the pd pool followed by an instance of xa_lock being >>>>>> acquired from rxe_pool_get_index from the ah pool. They are different >>>>>> locks. They can't deadlock against each other. So there must be >>>>>> some other trace (not shown) that also gets xa_lock from the ah pool. >>>>> Please check the bug report mail. The link is news://nntp.lore.kernel.org:119/CAHj4cs-MT13RiEsWXUAcX_H5jEtjsebuZgSeUcfptNVuELgjYQ@mail.gmail.com >>>>> >>>>> BTW, what is the update about wr crash caused by your xarray patches? >>>>> >>>>> Zhu Yanjun >>>>> >>>>>>> Zhu Yanjun >>>>>>> >>>>>>>>>      >>>>>>>>> >>>>>>>>>     From the above, in the function __rxe_add_to_pool, >>>>>>>>> xa_lock is acquired. Then the function __rxe_add_to_pool >>>>>>>>> is interrupted by softirq. The function >>>>>>>>> rxe_pool_get_index will also acquire xa_lock. >>>>>>>>> >>>>>>>>> Finally, the dead lock appears. >>>>>>>>> >>>>>>>>> [  296.806097]        CPU0 >>>>>>>>> [  296.808550]        ---- >>>>>>>>> [  296.811003]   lock(&xa->xa_lock#15);  <----- __rxe_add_to_pool >>>>>>>>> [  296.814583]   >>>>>>>>> [  296.817209]     lock(&xa->xa_lock#15); <---- rxe_pool_get_index >>>>>>>>> [  296.820961] >>>>>>>>>                      *** DEADLOCK *** >>>>>>>>> >>>>>>>>> Fixes: 3225717f6dfa ("RDMA/rxe: Replace red-black trees by carrays") >>>>>>>>> Reported-and-tested-by: Yi Zhang >>>>>>>>> Signed-off-by: Zhu Yanjun >>>>>>>>> --- >>>>>>>>> V3->V4: xa_lock_irq locks are used. >>>>>>>>> V2->V3: __rxe_add_to_pool is between spin_lock and spin_unlock, so >>>>>>>>>             GFP_ATOMIC is used in __rxe_add_to_pool. >>>>>>>>> V1->V2: Replace GFP_KERNEL with GFP_ATOMIC >>>>>>>>> --- >>>>>>>>>      drivers/infiniband/sw/rxe/rxe_pool.c | 20 ++++++++++++++------ >>>>>>>>>      1 file changed, 14 insertions(+), 6 deletions(-) >>>>>>>>> >>>>>>>>> diff --git a/drivers/infiniband/sw/rxe/rxe_pool.c b/drivers/infiniband/sw/rxe/rxe_pool.c >>>>>>>>> index 87066d04ed18..f1f06dc7e64f 100644 >>>>>>>>> --- a/drivers/infiniband/sw/rxe/rxe_pool.c >>>>>>>>> +++ b/drivers/infiniband/sw/rxe/rxe_pool.c >>>>>>>>> @@ -106,7 +106,7 @@ void rxe_pool_init(struct rxe_dev *rxe, struct rxe_pool *pool, >>>>>>>>>            atomic_set(&pool->num_elem, 0); >>>>>>>>>      -    xa_init_flags(&pool->xa, XA_FLAGS_ALLOC); >>>>>>>>> +    xa_init_flags(&pool->xa, XA_FLAGS_ALLOC | XA_FLAGS_LOCK_IRQ); >>>>>>>>>          pool->limit.min = info->min_index; >>>>>>>>>          pool->limit.max = info->max_index; >>>>>>>>>      } >>>>>>>>> @@ -138,8 +138,10 @@ void *rxe_alloc(struct rxe_pool *pool) >>>>>>>>>          elem->obj = obj; >>>>>>>>>          kref_init(&elem->ref_cnt); >>>>>>>>>      -    err = xa_alloc_cyclic(&pool->xa, &elem->index, elem, pool->limit, >>>>>>>>> -                  &pool->next, GFP_KERNEL); >>>>>>>>> +    xa_lock_irq(&pool->xa); >>>>>>>>> +    err = __xa_alloc_cyclic(&pool->xa, &elem->index, elem, pool->limit, >>>>>>>>> +                &pool->next, GFP_KERNEL); >>>>>>>>> +    xa_unlock_irq(&pool->xa); >>>>>>>>>          if (err) >>>>>>>>>              goto err_free; >>>>>>>>>      @@ -155,6 +157,7 @@ void *rxe_alloc(struct rxe_pool *pool) >>>>>>>>>      int __rxe_add_to_pool(struct rxe_pool *pool, struct rxe_pool_elem *elem) >>>>>>>>>      { >>>>>>>>>          int err; >>>>>>>>> +    unsigned long flags; >>>>>>>>>            if (WARN_ON(pool->flags & RXE_POOL_ALLOC)) >>>>>>>>>              return -EINVAL; >>>>>>>>> @@ -166,8 +169,10 @@ int __rxe_add_to_pool(struct rxe_pool *pool, struct rxe_pool_elem *elem) >>>>>>>>>          elem->obj = (u8 *)elem - pool->elem_offset; >>>>>>>>>          kref_init(&elem->ref_cnt); >>>>>>>>>      -    err = xa_alloc_cyclic(&pool->xa, &elem->index, elem, pool->limit, >>>>>>>>> -                  &pool->next, GFP_KERNEL); >>>>>>>>> +    xa_lock_irqsave(&pool->xa, flags); >>>>>>>>> +    err = __xa_alloc_cyclic(&pool->xa, &elem->index, elem, pool->limit, >>>>>>>>> +                &pool->next, GFP_ATOMIC); >>>>>>>>> +    xa_unlock_irqrestore(&pool->xa, flags); >>>>>>>>>          if (err) >>>>>>>>>              goto err_cnt; >>>>>>>>>      @@ -200,8 +205,11 @@ static void rxe_elem_release(struct kref *kref) >>>>>>>>>      { >>>>>>>>>          struct rxe_pool_elem *elem = container_of(kref, typeof(*elem), ref_cnt); >>>>>>>>>          struct rxe_pool *pool = elem->pool; >>>>>>>>> +    unsigned long flags; >>>>>>>>>      -    xa_erase(&pool->xa, elem->index); >>>>>>>>> +    xa_lock_irqsave(&pool->xa, flags); >>>>>>>>> +    __xa_erase(&pool->xa, elem->index); >>>>>>>>> +    xa_unlock_irqrestore(&pool->xa, flags); >>>>>>>>>            if (pool->cleanup) >>>>>>>>>              pool->cleanup(elem); >>>> Here is my output. Everything passes there are no bugs or unexpected warnings in the kernel trace. >>> >>> If I understand you correctly, you mean that the bug reported by Zhang Yi does not exist? >>> >>> I can reproduce this bug with rping. >>> >>> You can not reproduce this bug. It does not mean that this bug does not exist. >>> >>> And with rping, I also found another wr NULL bug. From the mail, you can also verify this wr NULL bug. >>> >>> Let us foucus on this wr NULL bug. OK? >>> >>> Zhu Yanjun >>> >>>> >>>> bob@ubuntu-21:~/src/blktests$ sudo ./check -q srp >>>> >>>> srp/001 (Create and remove LUNs)                             [passed] >>>> >>>>       runtime  3.402s  ...  2.753s >>>> >>>> srp/002 (File I/O on top of multipath concurrently with logout and login (mq)) [passed]time  34.431s  ... >>>> >>>>       runtime  34.431s  ...  34.328s >>>> >>>> srp/003 (File I/O on top of multipath concurrently with logout and login (sq)) [not run] >>>> >>>>       legacy device mapper support is missing >>>> >>>> srp/004 (File I/O on top of multipath concurrently with logout and login (sq-on-srp/004 (File I/O on top of multipath concurrently with logout and login (sq-on-mq)) [not run] >>>> >>>>       legacy device mapper support is missing >>>> >>>> srp/005 (Direct I/O with large transfer sizes, cmd_sg_entries=255 and bs=4M) [passed] >>>> >>>>       runtime  14.332s  ...  12.919s >>>> >>>> srp/006 (Direct I/O with large transfer sizes, cmd_sg_entries=255 and bs=8M) [passed] >>>> >>>>       runtime  13.361s  ...  12.959s >>>> >>>> srp/007 (Direct I/O with large transfer sizes, cmd_sg_entries=1 and bs=4M) [passed] >>>> >>>>       runtime  14.293s  ...  12.912s >>>> >>>> srp/008 (Direct I/O with large transfer sizes, cmd_sg_entries=1 and bs=8M) [passed] >>>> >>>>       runtime  13.369s  ...  13.165s >>>> >>>> srp/009 (Buffered I/O with large transfer sizes, cmd_sg_entries=255 and bs=4M) [passed] >>>> >>>>       runtime  13.636s  ...  14.201s >>>> >>>> srp/010 (Buffered I/O with large transfer sizes, cmd_sg_entries=255 and bs=8M) [passed] >>>> >>>>       runtime  13.361s  ...  12.909s >>>> >>>> srp/011 (Block I/O on top of multipath concurrently with logout and login) [passed] >>>> >>>>       runtime  33.706s  ...  33.571s >>>> >>>> srp/012 (dm-mpath on top of multiple I/O schedulers)         [passed] >>>> >>>>       runtime  13.592s  ...  14.138s >>>> >>>> srp/013 (Direct I/O using a discontiguous buffer)            [passed] >>>> >>>>       runtime  3.230s  ...  3.513s >>>> >>>> srp/014 (Run sg_reset while I/O is ongoing)                  [passed] >>>> >>>>       runtime  33.070s  ...  33.059s >>>> >>>> srp/015 (File I/O on top of multipath concurrently with logout and login (mq) using the SoftiWARP (siw) dsrp/015 (File I/O on top of multipath concurrently with logout and login (mq) using the SoftiWARP (siw) driver) [passed].148s  ... >>> >>> you are using SoftiWARP (siw)? >> >> not me. it is just the normal behavior of the srp/015 test case. it has always done that. my rdma-core >> does support siw. > > Fine. > Let us find the root cause of wr NULL problem. > I revert xarray patches and fell back to original source code. > This wr NULL problem does not exist. > I am working on it. > > Hope we can fix this wr NULL problem very soon. I have to go to bed. But the mr == NULL bug was fixed by the last 10 rxe pool patches. I am sure it was the 8/10 patch which fixed it. I have never seen it once all the rxe_pool patches were applied. > > Zhu Yanjun > >> >>> >>>> >>>>       runtime  35.148s  ...  34.974s >>>> >>>> bob@ubuntu-21:~/src/blktests$ >>>> >>>> Bob >> >