Shadow, could you please take a look at this.
It looks like your patch https://review.whamcloud.com/47952 "LU-16011 lnet: use preallocate bulk for server" is causing 100% OOM failure for aarch64 since it landed. There was no aarch64 testing on this patch due to "Test-Parameters: trivial". This is normally OK for LNet patches, but in this case there is likely some error in memory allocation for 64KB PAGE_SIZE.
@Andreas,
this patch have passed a Oleg testing with 2Gb ram per VM. for must more memory it's limited with number work items.
Can you provide a coredump and modules to inspect ?
please don't forget, o2iblnd have a leak introduced by "babf023227 LU-13368 lnet: discard the callback" this was caused an OOM on Cray routers after o2ib reconnects. o2ib connects was in the kib_connd_waits list.
kib_connd_waits = {
next = 0xffff88826f956a18,
prev = 0xffff88851866ec18
},
crash> list 0xffff88826f956a18 | wc -l
15009
I known, this revert already created - but - did you have arm64 test with this revert ?
this patch have passed a Oleg testing with 2Gb ram per VM. for must more memory it's limited with number work items.
I don't think Oleg tests with aarch64 clients, and the OOM is not being hit on x86_64 clients.
Can you provide a coredump and modules to inspect ?
There are coredumps available, but I think they can only be downloaded directly via our VPN. green, would you be able to help Shadow get access to the coredump? The one from the most recent failure https://testing.whamcloud.com/test_sets/bcf91e7c-563a-4c7f-8137-17f785785b8b reports at the top of the vmcore-dmesg file:
https://testing.whamcloud.com/test_logs/10f980f6-5d90-426e-90a4-5e5a92cd7d91/show_text
Core file can be found in /scratch/dumps/trevis-108vm2.trevis.whamcloud.com/10.240.44.205-2022-09-07-14:53:37
btw. how much RAM in our's aarch64 VM ?
I will create an own aarch64 guests with 2G ram (soft emu bug - don't able to have more with IB card).
I was just looking at the console messages in the original test failure and it shows a more useful stack trace in brw_srpc_init():
https://testing.whamcloud.com/test_sets/f550b8a6-bef4-4010-a6ac-a2ca28ee60fe
https://testing.whamcloud.com/test_logs/bfeee1fb-bd31-4962-9f5b-660f22af465a/show_text
[ 474.320712] Kernel panic - not syncing: Out of memory: system-wide panic_on_oom is enabled [ 474.320712] [ 474.335774] CPU: 1 PID: 19827 Comm: modprobe Kdump: loaded Tainted: G OE --------- - - 4.18.0-372.16.1.el8_6.aarch64 #1 [ 474.344303] Hardware name: QEMU KVM Virtual Machine, BIOS 0.0.0 02/06/2015 [ 474.349142] Call trace: [ 474.350920] dump_backtrace+0x0/0x160 [ 474.353462] show_stack+0x28/0x38 [ 474.355839] dump_stack+0x5c/0x74 [ 474.358227] panic+0x140/0x30c [ 474.360369] out_of_memory+0x438/0x510 [ 474.363003] __alloc_pages_nodemask+0xd74/0xde8 [ 474.366230] srpc_alloc_bulk+0x130/0x5d0 [lnet_selftest] [ 474.370112] brw_srpc_init+0x2c/0x60 [lnet_selftest] [ 474.373562] srpc_add_service+0x2a4/0x740 [lnet_selftest] [ 474.377337] sfw_startup+0x23c/0x898 [lnet_selftest] [ 474.380852] lnet_selftest_init+0x5f4/0x10000 [lnet_selftest] [ 474.384850] do_one_initcall+0x58/0x1f0 [ 474.387581] do_init_module+0x64/0x238 [ 474.390197] load_module+0x13ec/0x1690 [ 474.392839] __se_sys_finit_module+0xa4/0x100 [ 474.395916] __arm64_sys_finit_module+0x28/0x38 [ 474.399093] el0_svc_handler+0xb4/0x188 [ 474.401796] el0_svc+0x8/0xc [ 474.405020] SMP: stopping secondary CPUs [ 474.410883] Starting crashdump kernel... [ 474.413584] Bye!
It looks like there was OOM hit on both aarch64 nodes (console.onyx-91vm5.log and console.onyx-91vm6.log at the same time.
how much RAM in our's aarch64 VM ?
I will create an own aarch64 guests with 2G ram (soft emu bug - don't able to have more with IB card).
There should be 3GB of RAM for the client VMs. I believe all of the the testing is with TCP and not IB on these nodes.
I pushed (untested) patch https://review.whamcloud.com/48476 with some debugging to run on aarch64 to show how large the allocation is that fails.
Andreas,
it looks I found a root cause of it. LST want a something like a "LU-10157 ptlrpc: fill md correctly." It have allocate an 64k page for transfer, but just 4k used from it.
it increase memory consumption in such small environment. Let me cook a patch and submit.
Hi Alexey and Andreas, thanks for analyzing and addressing this issue. We also found that lnet-selftest test_smoke crashs on our arm64 CI recently. Looking forwarding to the fixed patch
.
It looks I able to replicate this issue locally. I hope patch will be ready on begin of next week.
PS. lustre test-framework too bad works with different path and different arch without installing from rpm.
I had just found the same thing with my debug patch:
https://testing.whamcloud.com/test_sets/af232f05-d183-4a2f-9d3d-84b368efbc85
[ 476.508122] Lustre: 14798:0:(brw_test.c:544:brw_init_test_service()) cache_size = 20578/41157 pages (80 IOVs) [ 476.515256] Lustre: 14798:0:(brw_test.c:549:brw_init_test_service()) want 2048 work items, got 80 [ 476.522193] LNet: 14798:0:(rpc.c:148:srpc_alloc_bulk()) allocate 256 bulk pages, 4120 bytes on cpt 0 [ 476.528390] LNet: 14798:0:(rpc.c:162:srpc_alloc_bulk()) allocate bulk page 1/256 on cpt 0 [ 476.534440] LNet: 14798:0:(rpc.c:148:srpc_alloc_bulk()) allocate 256 bulk pages, 4120 bytes on cpt 0 **** repeats 70 times **** [ 477.019823] LNet: 14798:0:(rpc.c:148:srpc_alloc_bulk()) allocate 256 bulk pages, 4120 bytes on cpt 0 [ 477.047753] LNet: 14798:0:(rpc.c:162:srpc_alloc_bulk()) allocate bulk page 12/256 on cpt 0 [ 477.053733] LNet: 14798:0:(rpc.c:162:srpc_alloc_bulk()) Skipped 18442 previous similar messages [ 477.061430] LNet: 14798:0:(rpc.c:148:srpc_alloc_bulk()) allocate 256 bulk pages, 4120 bytes on cpt 0 **** repeats 68 times **** [ 478.028197] LNet: 14798:0:(rpc.c:148:srpc_alloc_bulk()) allocate 256 bulk pages, 4120 bytes on cpt 0 [ 478.110577] obd_memory max: 3765625, obd_memory current: 3440400 [ 478.114656] systemd-journal invoked oom-killer: gfp_mask=0x6200ca(GFP_HIGHUSER_MOVABLE), order=0, oom_score_adj=0
What is also unexpected is that this is preallocating a lot more than 80 bulk descriptors, about 140 in total before OOM is hit. Since 80 desc * 256 pages/desc * 64KiB/page = 1310720 KiB = 1.2 GiB is already half of RAM (20480 of 41157 pages), the OOM is happening when over 2.2 GiB 87% of RAM has been allocated by these descriptors.
So in addition to the 4KB vs. 64KB PAGE_SIZE issue, there is also a problem with the cache_size calculation in brw_init_test_service(). That appears to be twice as much RAM allocated as expected, maybe it is per-NID or per-CPT or two "services" are started, which is bad. This needs to be limited to a more reasonable amount of memory.
"Alexey Lyashkov <alexey.lyashkov@hpe.com>" uploaded a new patch: https://review.whamcloud.com/48507
Subject: LU-16140 lnet: fix lst on 64k page size.
Project: fs/lustre-release
Branch: master
Current Patch Set: 1
Commit: 93938c2e4181c0bd91b69c980537f2dfa34d5a17
>[ 476.522193] LNet: 14798:0:(rpc.c:148:srpc_alloc_bulk()) allocate 256 bulk pages, 4120 bytes on cpt 0
it's primary fail (for both - client and server parts).
bulk pages allocation should be LNET_MTU / PAGE_SIZE + 1 (for unaligned offset) not an LNET_MAX_IOV as it was before.
Andreas, can you run attached patch on the our's arm? it passed my verification with 3G ram.
Loading modules from /work/lustre/wc/LU-16140-arm-mem/lustre/lustre
detected 8 online CPUs by sysfs
libcfs will create CPU partition based on online CPUs
../lnet/lnet/lnet options: 'networks="tcp0(eth0)" lnet_peer_discovery_disabled=0 lnet_health_sensitivity=1 accept=all'
gss/krb5 is not supported
loading modules on: 'devel1'
devel1: devel1: executing load_modules_local
devel1: Loading modules from /work/lustre/wc/lustre-basic/lustre
devel1: /work/lustre/wc/lustre-basic/lustre//tests/test-framework.sh: line 693: echo: write error: Device or resource busy
devel1: /work/lustre/wc/lustre-basic/lustre//tests/test-framework.sh: line 694: echo: write error: Device or resource busy
devel1: detected 8 online CPUs by sysfs
devel1: libcfs will create CPU partition based on online CPUs
devel1: ../lnet/lnet/lnet options: 'networks="tcp0(eth0)" lnet_peer_discovery_disabled=0 lnet_health_sensitivity=1 accept=all'
devel1: ptlrpc/ptlrpc options: 'lbug_on_grant_miscount=1'
devel1: gss/krb5 is not supported
devel1: quota/lquota options: 'hash_lqs_cur_bits=3'
192.168.100.1: LNET configured
LNET configured
12345-0@lo
12345-192.168.100.1@tcp
SESSION: read/write FEATURES: 1 TIMEOUT: 300 FORCE: No
192.168.100.1@tcp are added to session
192.168.100.5@tcp are added to session
Test was added successfully
bulk_rw is running now
[LNet Rates of servers]
[R] Avg: 119 RPC/s Min: 119 RPC/s Max: 119 RPC/s
[W] Avg: 123 RPC/s Min: 123 RPC/s Max: 123 RPC/s
[LNet Bandwidth of servers]
[R] Avg: 61.79 MiB/s Min: 61.79 MiB/s Max: 61.79 MiB/s
[W] Avg: 0.01 MiB/s Min: 0.01 MiB/s Max: 0.01 MiB/s
[LNet Rates of servers]
[R] Avg: 119 RPC/s Min: 119 RPC/s Max: 119 RPC/s
[W] Avg: 120 RPC/s Min: 120 RPC/s Max: 120 RPC/s
[LNet Bandwidth of servers]
[R] Avg: 60.27 MiB/s Min: 60.27 MiB/s Max: 60.27 MiB/s
[W] Avg: 0.01 MiB/s Min: 0.01 MiB/s Max: 0.01 MiB/s
[LNet Rates of servers]
[R] Avg: 125 RPC/s Min: 125 RPC/s Max: 125 RPC/s
[W] Avg: 124 RPC/s Min: 124 RPC/s Max: 124 RPC/s
[LNet Bandwidth of servers]
[R] Avg: 61.92 MiB/s Min: 61.92 MiB/s Max: 61.92 MiB/s
[W] Avg: 0.01 MiB/s Min: 0.01 MiB/s Max: 0.01 MiB/s
[LNet Rates of servers]
[R] Avg: 122 RPC/s Min: 122 RPC/s Max: 122 RPC/s
[W] Avg: 122 RPC/s Min: 122 RPC/s Max: 122 RPC/s
[LNet Bandwidth of servers]
[R] Avg: 61.10 MiB/s Min: 61.10 MiB/s Max: 61.10 MiB/s
[W] Avg: 0.01 MiB/s Min: 0.01 MiB/s Max: 0.01 MiB/s
[LNet Rates of servers]
[R] Avg: 123 RPC/s Min: 123 RPC/s Max: 123 RPC/s
[W] Avg: 123 RPC/s Min: 123 RPC/s Max: 123 RPC/s
[LNet Bandwidth of servers]
[R] Avg: 61.66 MiB/s Min: 61.66 MiB/s Max: 61.66 MiB/s
[W] Avg: 0.01 MiB/s Min: 0.01 MiB/s Max: 0.01 MiB/s
session is ended
test-tcp.sh: строка 32: 5280 Завершено lst stat servers
pdsh@devel4: devel1: ssh exited with exit code 126
pdsh@devel4: devel1: ssh exited with exit code 126
pdsh@devel4: devel1: ssh exited with exit code 126
pdsh@devel4: devel1: ssh exited with exit code 126
pdsh@devel4: devel1: ssh exited with exit code 126
pdsh@devel4: devel1: ssh exited with exit code 126
pdsh@devel4: devel1: ssh exited with exit code 126
pdsh@devel4: devel1: ssh exited with exit code 126
pdsh@devel4: devel1: ssh exited with exit code 126
Stopping clients: devel4 /mnt/lustre (opts:-f)
Stopping clients: devel4 /mnt/lustre2 (opts:-f)
pdsh@devel4: devel1: ssh exited with exit code 1
pdsh@devel4: devel1: ssh exited with exit code 1
pdsh@devel4: devel1: ssh exited with exit code 1
pdsh@devel4: devel1: ssh exited with exit code 1
unloading modules on: 'devel1'
devel1: devel1: executing unload_modules_local
devel1: /work/lustre/wc/lustre-basic/lustre/scripts/lustre_rmmod: line 99: echo: write error: Device or resource busy
devel1: rmmod: ERROR: Module ksocklnd is in use
pdsh@devel4: devel1: ssh exited with exit code 2
~
[root@devel4 ~]# uname -r
4.18.0-348.7.1.el8_5.aarch64
[root@devel4 ~]# free -h
total used free shared buff/cache available
Mem: 2,9Gi 411Mi 2,1Gi 18Mi 390Mi 2,1Gi
Swap: 2,0Gi 0B 2,0Gi
[root@devel4 ~]#
With patch 48507, our Arm CI won't crash now. See https://testing.whamcloud.com/test_sessions/0f397625-0376-4391-948c-a3c2e8386d09
With patch 48507, our Arm CI won't crash now. See https://testing.whamcloud.com/test_sessions/0f397625-0376-4391-948c-a3c2e8386d09
It didn't crash with OOM, but it didn't pass either... Also, the v1/v2 488507 patch is crashing both aarch64 as well as x86_64, so that isn't a proper fix yet:
Failed optional test review-ldiskfs on CentOS 8.5/x86_64, SLES 15.3/x86_64 uploaded by Trevis Autotest from trevis-40vm2: https://testing.whamcloud.com/test_sessions/601a2acf-fc26-4a52-8075-1cdee24113ac ran 7 tests. 2 tests failed: sanity, lnet-selftest.
%% THIS TEST SESSION CRASHED %%Failed enforced test review-ldiskfs on CentOS 8.5/x86_64 uploaded by Onyx Autotest from onyx-120vm1: https://testing.whamcloud.com/test_sessions/5e543a27-87e0-4031-963e-3fcd5a5dfc57 ran 7 tests. 2 tests failed: sanity, lnet-selftest.
%% THIS TEST SESSION CRASHED %%Failed optional test review-ldiskfs on RHEL 8.6/x86_64 uploaded by Onyx Autotest from onyx-77vm1: https://testing.whamcloud.com/test_sessions/4ab09db6-03aa-4ed2-843d-3dcb4f4f52dc ran 7 tests. 2 tests failed: sanity, lnet-selftest.
%% THIS TEST SESSION CRASHED %%Failed enforced test review-ldiskfs-ubuntu on CentOS 8.5/x86_64, Ubuntu 20.04/x86_64 uploaded by Trevis Autotest from trevis-25vm3: https://testing.whamcloud.com/test_sessions/e4ea3a13-f65d-4a29-8582-c402ee3153e1 ran 8 tests. 2 tests failed: sanity, lnet-selftest.
%% THIS TEST SESSION CRASHED %%Failed enforced test review-ldiskfs-arm on RHEL 8.6/aarch64, RHEL 8.6/x86_64 uploaded by Onyx Autotest from onyx-91vm1: https://testing.whamcloud.com/test_sessions/deef2746-9d03-47b3-87dc-557adacc7c7e ran 8 tests. 2 tests failed: sanity, lnet-selftest.
%% THIS TEST SESSION CRASHED %%
"Andreas Dilger <adilger@whamcloud.com>" merged in patch https://review.whamcloud.com/48457/
Subject: LU-16140 lnet: revert "LU-16011 lnet: use preallocate bulk for server"
Project: fs/lustre-release
Branch: master
Current Patch Set:
Commit: 1b09fb2296993c52e5d90d99ceb43c8c54c5c7a2