From mboxrd@z Thu Jan 1 00:00:00 1970 Content-Type: multipart/mixed; boundary="===============8259290791703229118==" MIME-Version: 1.0 From: JD Zheng Subject: Re: [SPDK] nvmf_tgt *ERROR*: Data buffer split over multiple RDMA Memory Regions Date: Wed, 31 Jul 2019 15:13:03 -0700 Message-ID: In-Reply-To: b8f51f34-2242-9df7-ff44-4a313c599dcb@broadcom.com List-ID: To: spdk@lists.01.org --===============8259290791703229118== Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: quoted-printable Hi Seth, After I enabled debug and ran nvmf_tgt with -L rdma, I got some logs like: rdma.c: 746:nvmf_rdma_resources_create: *DEBUG*: Command Array: = 0x2000084bf000 Length: 40000 LKey: e601 rdma.c: 749:nvmf_rdma_resources_create: *DEBUG*: Completion Array: = 0x200008621000 Length: 10000 LKey: e701 rdma.c: 753:nvmf_rdma_resources_create: *DEBUG*: In Capsule Data Array: = 0x200018600000 Length: 1000000 LKey: e801 rdma.c: 746:nvmf_rdma_resources_create: *DEBUG*: Command Array: = 0x20000847e000 Length: 40000 LKey: e701 rdma.c: 749:nvmf_rdma_resources_create: *DEBUG*: Completion Array: = 0x20000846d000 Length: 10000 LKey: e801 rdma.c: 753:nvmf_rdma_resources_create: *DEBUG*: In Capsule Data Array: = 0x200019800000 Length: 1000000 LKey: e901 rdma.c: 746:nvmf_rdma_resources_create: *DEBUG*: Command Array: = 0x200016ebb000 Length: 40000 LKey: e801 rdma.c: 749:nvmf_rdma_resources_create: *DEBUG*: Completion Array: = 0x20000845c000 Length: 10000 LKey: e901 rdma.c: 753:nvmf_rdma_resources_create: *DEBUG*: In Capsule Data Array: = 0x20001aa00000 Length: 1000000 LKey: ea01 rdma.c: 746:nvmf_rdma_resources_create: *DEBUG*: Command Array: = 0x200016e7a000 Length: 40000 LKey: e901 rdma.c: 749:nvmf_rdma_resources_create: *DEBUG*: Completion Array: = 0x20000844b000 Length: 10000 LKey: ea01 rdma.c: 753:nvmf_rdma_resources_create: *DEBUG*: In Capsule Data Array: = 0x20001bc00000 Length: 1000000 LKey: eb01 ... Is this you are look for as memory regions registered for NIC? I attached the complete log. Thanks, JD On 7/30/19 5:28 PM, JD Zheng wrote: > Hi Seth, > = > Thanks for the prompt reply! > = > Please find answers inline. > = > JD > = > On 7/30/19 5:01 PM, Howell, Seth wrote: >> Hi JD, >> >> Thanks for the report. I want to ask a few questions to start getting = >> to the bottom of this. Since this issue doesn't currently reproduce on = >> our per-patch or nightly tests, I would like to understand what's = >> unique about your setup so that we can replicate it in a per patch = >> test to prevent future regressions. > I am running it on aarch64 platform. I tried x86 platform and I can see = > same buffer alignment in memory pool but can't run the real test to = > reproduce it due to other missing pieces. > = >> >> What options are you passing when you create the rdma transport? Are = >> you creating it over RPC or in a configuration file? > I am using conf file. Pls let me know if you'd like to look into conf fil= e. > = >> >> Are you using the current DPDK submodule as your environment = >> abstraction layer? > No. Our project uses specific version of DPDK, which is v18.11. I did = > quick test using latest and DPDK submodule on x86, and the buffer = > alignment is the same, i.e. 64B aligned. > = >> >> I notice that your error log is printing from = >> spdk_nvmf_transport_poll_group_create, which value exactly are you = >> printing out? > Here is patch to add dbg print. Pls note that SPDK version is v19.04 > = > @@ -215,6 +222,7 @@ spdk_nvmf_transport_poll_group_create(st > =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 SPDK_NOTICELOG("Unable to reserve t= he = > full number of buffers for the pg buffer cache.\n"); > =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2= =A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 break; > =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 } > +=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 SPDK_ERRLOG("%= p %d(%d)\n", buf, = > group->buf_cache_count, group->buf_cache_size); > =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 STAILQ_I= NSERT_HEAD(&group->buf_cache, buf, link); > =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0 group->b= uf_cache_count++; > =C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0=C2=A0= =C2=A0=C2=A0=C2=A0 } > = >> >> Can you run your target with the -L rdma option to get a dump of the = >> memory regions registered with the NIC? > Let me test and get back to you soon. > = >> >> We made a couple of changes to this code when dynamic memory = >> allocations were added to DPDK. There were some safeguards that we = >> added to try and make sure this case wouldn't hit, so I'd like to make = >> sure you are running on the latest DPDK submodule as well as the = >> latest SPDK to narrow down where we need to look. > Unfortunately I can't easily update DPDK because other team maintains it = > internally. But if it can be repro and fixed in latest, I will try to = > pull in the fix. > = >> >> Thanks, >> >> Seth >> >> -----Original Message----- >> From: SPDK [mailto:spdk-bounces(a)lists.01.org] On Behalf Of JD Zheng = >> via SPDK >> Sent: Wednesday, July 31, 2019 3:00 AM >> To: spdk(a)lists.01.org >> Cc: JD Zheng >> Subject: [SPDK] nvmf_tgt *ERROR*: Data buffer split over multiple RDMA = >> Memory Regions >> >> Hello, >> >> When I run nvmf_tgt over RDMA using latest SPDK code, I occasionally = >> ran into this errors: >> "rdma.c:1505:nvmf_rdma_fill_buffers: *ERROR*: Data buffer split over = >> multiple RDMA Memory Regions" >> >> After digging into the code, I found that nvmf_rdma_fill_buffers() = >> calls=C2=A0spdk_mem_map_translate() to check if a data buffer sit on 2 2= MB = >> pages, and if it is the case, it reports this error. >> >> The following commit added change to use data buffer start address to = >> calculate the size between buffer start address and 2MB boundary. The = >> caller=C2=A0nvmf_rdma_fill_buffers() uses the size to compare with IO Un= it = >> size (which is 8KB in my conf) to determine if the buffer passes 2MB = >> boundary. >> >> commit 37b7a308941b996f0e69049358a6119ed90d70a2 >> Author: Darek Stojaczyk >> Date: =C2=A0 Tue Nov 13 17:43:46 2018 +0100 >> >> =C2=A0 =C2=A0 =C2=A0 memory: fix contiguous memory calculation for unali= gned buffers >> >> In nvmf_tgt, the buffers are pre-allocated as a memory pool and new = >> request will use free buffer from that pool and the buffer start = >> address is passed to=C2=A0nvmf_rdma_fill_buffers(). But I found that the= se = >> buffers are not 2MB aligned and not IOUnitSize aligned (8KB in my = >> case) either, instead, they are 64Byte aligned so that some buffers = >> will fail the checking and leads to this problem. >> >> The corresponding code snippets are as following: >> spdk_nvmf_transport_create() >> { >> ... >> =C2=A0 =C2=A0 =C2=A0 transport->data_buf_pool =3D pdk_mempool_create(spd= k_mempool_name, >> =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0opts->num_shared_buffers, >> =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0opts->io_unit_size + = >> NVMF_DATA_BUFFER_ALIGNMENT, >> =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0SPDK_MEMPOOL_DEFAULT_CACHE_= SIZE, >> =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0SPDK_ENV_SOCKET_ID_ANY); ... >> } >> >> Also some debug print I added shows the start address of the buffers: >> transport.c: 218:spdk_nvmf_transport_poll_group_create: *ERROR*: >> 0x200019258800 0(32) >> transport.c: 218:spdk_nvmf_transport_poll_group_create: *ERROR*: >> 0x2000192557c0 1(32) >> transport.c: 218:spdk_nvmf_transport_poll_group_create: *ERROR*: >> 0x200019252780 2(32) >> transport.c: 218:spdk_nvmf_transport_poll_group_create: *ERROR*: >> 0x20001924f740 3(32) >> transport.c: 218:spdk_nvmf_transport_poll_group_create: *ERROR*: >> 0x20001924c700 4(32) >> transport.c: 218:spdk_nvmf_transport_poll_group_create: *ERROR*: >> 0x2000192496c0 5(32) >> transport.c: 218:spdk_nvmf_transport_poll_group_create: *ERROR*: >> 0x200019246680 6(32) >> transport.c: 218:spdk_nvmf_transport_poll_group_create: *ERROR*: >> 0x200019243640 7(32) >> transport.c: 218:spdk_nvmf_transport_poll_group_create: *ERROR*: >> 0x200019240600 8(32) >> transport.c: 218:spdk_nvmf_transport_poll_group_create: *ERROR*: >> 0x20001923d5c0 9(32) >> ... >> >> It looks like either the buffer allocation has alignment issue or the = >> checking is not correct. >> >> Please advice how to fix this problem. >> >> Thanks, >> JD Zheng >> _______________________________________________ >> SPDK mailing list >> SPDK(a)lists.01.org >> https://lists.01.org/mailman/listinfo/spdk >> --===============8259290791703229118==--