#1082888 librocfft0-tests: read kernel buffer failed on Linux 6.10

Package:
librocfft0-tests
Source:
librocfft0-tests
Description:
ROCm library for computing Fast Fourier Transforms - tests
Submitter:
Cordell Bloor
Date:
2024-09-28 09:57:01 UTC
Severity:
normal
#1082888#5
Date:
2024-09-27 18:52:05 UTC
From:
To:
Dear Maintainer,

The rocfft tests are crashing on gfx1035 after updating the kernel from
bookworm to bookworm-backports (6.1 to 6.10). This can be seen be comparing
these two nearly identical runs from before [1] and after [2] installing a new
kernel.

This is the failing test:
498s [ RUN      ] pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_single_ip_batch_4_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
558s Killed
558s dmesg: read kernel buffer failed: Operation not permitted

It seems that previously it was skipped:
162s [ RUN      ] pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_single_ip_batch_4_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
162s clients/tests/accuracy_test.h:1260: Skipped
162s Raw problem size (9 GiB) raw data too large for device

There are other tests that use much more RAM that are still skipped, even with the newer kernel:
395s [ RUN      ] pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_op_batch_4_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
395s clients/tests/accuracy_test.h:1214: Skipped
395s needed_ramgb: 96, ramgb limit: 61.

The failure therefore appears to be due to changes in the GPU memory capacity
reported for the APUs. In Linux 6.10, the driver is able to dynamically
allocate more system memory for use by the GPU.

The rocfft library queries the amount of memory available on the device and it
skips tests that would use more memory than is available. I suspect that the
allocation for this test is failing but the library attempts to use the
returned value anyway.

While there may be 61GB of memory available in theory, it might be that there
are other factors that reduce that amount. For example, allocations in host
memory might reduce the available memory for the device in APU systems like
this. While the device memory limit might be 61GB, you cannot allocate 40GB of
host memory and 40GB of device memory, as they come from the same pool.

The rocfft-test client provides the --R <gb> and --V <gb> options to explicitly
specify the host and device memory limits, respectively. That may be a good
workaround for the moment, although it would be better if rocfft-test could
query the system hardware and choose appropriate defaults.

Sincerely,
Cory Bloor

[1]: https://ci.rocm.debian.net/data/autopkgtest/unstable/amd64+gfx1035/r/rocfft/33925/log.gz
[2]: https://ci.rocm.debian.net/data/autopkgtest/unstable/amd64+gfx1035/r/rocfft/34278/log.gz

#1082888#10
Date:
2024-09-27 19:40:31 UTC
From:
To:
Hi Cory,

"Killed" sounds like something sent SIGKILL, and I suspect this was the
OOM killer, especially since you mention memory allocation below.

This isn't from the test, this is our test runner that tries to capture
dmesg before and after [3] each test, for debugging purposes. These get
exported as artifacts, and made available in our CI. This fails with
rootless podman because reading dmesg is a privileged operation by
default.

On the host, could you try

  $ sudo sysctl kernel.dmesg_restrict=0

and then run the test again. This should enable dmesg capturing by
regular users, and if it really is the OOM killer, it should be logged
there.

(In QEMU, we have root access to dmesg, so this is not a problem there.)
more actual memory is used than physically available, the OOM killer
will kill something, which would neatly fit to the "Killed" above.

You can turn off overcommitment with:

  $ sudo sysctl vm.overcommit_memory=2

Perhaps that also changes something.

Could you share the output of rocminfo with both 6.1 and 6.10?

I don't think it needs to be run in the test container, at least I don't
see why the result on bare metal should differ.

Best,
Christian

[3]: https://sources.debian.org/src/rocfft/6.1.2-1/debian/tests/upstream-binaries/#L70

#1082888#15
Date:
2024-09-27 21:34:13 UTC
From:
To:
Hi Christian,

I appreciate your help. Those were good suggestions.
Thanks for the correction.

The log output after applying both changes:

[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_67108864_single_op_batch_1_istride_1_CI_ostride_1_CI_idist_67108864_odist_67108864_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_67108864_single_op_batch_1_istride_1_CI_ostride_1_CI_idist_67108864_odist_67108864_ioffset_0_0_ooffset_0_0
(953 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_ip_batch_4_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
command1             FAIL non-zero exit status 1

The dmesg output from test after applying both changes:

[50555.651205] __vm_enough_memory: pid: 57317, comm: rocfft-test, bytes:
8592035840 not enough memory for the allocation
[50555.651226] __vm_enough_memory: pid: 57317, comm: rocfft-test, bytes:
8592035840 not enough memory for the allocation
[50555.651233] __vm_enough_memory: pid: 57317, comm: rocfft-test, bytes:
8572432384 not enough memory for the allocation
[50555.651237] __vm_enough_memory: pid: 57317, comm: rocfft-test, bytes:
8592166912 not enough memory for the allocation
[50555.651261] show_signal_msg: 11 callbacks suppressed
[50555.651263] rocfft-test[57317]: segfault at 3c0 ip 00007fab8c38937b
sp 00007faa749fe558 error 6 in
libfftw3.so.3.6.10[18937b,7fab8c224000+1c5000] likely on CPU 9 (core 4,
socket 0)
[50555.651276] Code: 2d 57 15 48 8e 06 00 c4 c1 65 5c d9 c5 e5 57 1d 3b
8e 06 00 c4 43 7d 05 d2 05 c4 e3 7d 05 db 05 c4 41 4d 5c ca c4 c1 4d 58
f2 <c4> 43 7d 19 0c 0a 01 c4 41 79 29 0a c5 55 58 cb c5 d5 5c eb 4d 8b

See attached for rocminfo logs from Debian Stable. Here's the diff:
--- nightwatch-rocminfo-6.1.txt 2024-09-27 15:30:45.713049254 -0600 +++ nightwatch-rocminfo-6.10.txt 2024-09-27 15:30:41.808929634 -0600 @@ -33,7 +33,7 @@ L1: 32768(0x8000) KB Chip ID: 0(0x0) Cacheline Size: 64(0x40) - Max Clock Freq. (MHz): 3200 + Max Clock Freq. (MHz): 4829 BDFID: 0 Internal Node ID: 0 Compute Unit: 16 @@ -45,21 +45,21 @@ Pool Info: Pool 1 Segment: GLOBAL; FLAGS: FINE GRAINED - Size: 63516508(0x3c92f5c) KB + Size: 63523720(0x3c94b88) KB Allocatable: TRUE Alloc Granule: 4KB Alloc Alignment: 4KB Accessible by all: TRUE Pool 2 Segment: GLOBAL; FLAGS: KERNARG, FINE GRAINED - Size: 63516508(0x3c92f5c) KB + Size: 63523720(0x3c94b88) KB Allocatable: TRUE Alloc Granule: 4KB Alloc Alignment: 4KB Accessible by all: TRUE Pool 3 Segment: GLOBAL; FLAGS: COARSE GRAINED - Size: 63516508(0x3c92f5c) KB + Size: 63523720(0x3c94b88) KB Allocatable: TRUE Alloc Granule: 4KB Alloc Alignment: 4KB @@ -113,7 +113,7 @@ Pool Info: Pool 1 Segment: GLOBAL; FLAGS: COARSE GRAINED - Size: 2097152(0x200000) KB + Size: 31761860(0x1e4a5c4) KB Allocatable: TRUE Alloc Granule: 4KB Alloc Alignment: 4KB I also just noticed that [2] is segfaulting, so there's clearly another issue even with the older kernel. I hadn't noticed that before. It didn't do that when rocfft 6.1.2 was first uploaded [4]. [4]: https://ci.rocm.debian.net/data/autopkgtest/unstable/amd64+gfx1035/r/rocfft/18220/log.gz
#1082888#20
Date:
2024-09-27 22:11:48 UTC
From:
To:
Am I interpreting this right that the "Killed" disappeared? If so, then the issue should be reproducible by re-enabling vm.overcommit_memory=0.

Would be nice to be certain of this.

It seems that this is non-deterministic. Some test complete, some don't. Sadly, we don't have dmesg for the older tests, but looking at the tail of the log [5] just two days after [4], we can see a

which could be related.

It looks non-deterministic because this only occurs occasionally, and at different locations in the test run. An easy way to spot this is to look at log sizes [6]; completed tests tend to have ~640KB, shorter means early abort. This one [7] crashed almost immediately.

If it's not related, things become even more complicated...

If overcommit was indeed the issue behind "Killed", then I suspect that the test malloc'ed so much such that it eventually triggered the OOM when both test and GPU consumed all physical memory, eg: with a 32GiB large test case computed on both GPU and CPU for expected/actual comparison.

Best,
Christian

[5]: https://ci.rocm.debian.net/packages/r/rocfft/unstable/amd64+gfx1035/18314/
[6]: https://ci.rocm.debian.net/packages/r/rocfft/unstable/amd64+gfx1035/
[7]: https://ci.rocm.debian.net/packages/r/rocfft/unstable/amd64+gfx1035/23638/

#1082888#25
Date:
2024-09-27 23:11:44 UTC
From:
To:
Hi Christian,

"Killed" disappeared when I ran it myself in both cases. However, it did
get further with vm.overcommit_memory=0:

[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_67108864_single_op_batch_1_istride_1_CI_ostride_1_CI_idist_67108864_odist_67108864_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_67108864_single_op_batch_1_istride_1_CI_ostride_1_CI_idist_67108864_odist_67108864_ioffset_0_0_ooffset_0_0
(881 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_ip_batch_4_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_ip_batch_4_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(76872 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_op_batch_4_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_op_batch_4_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(11141 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_ip_batch_2_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_ip_batch_2_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(5230 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_op_batch_2_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_op_batch_2_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(5429 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_op_batch_2_istride_1_CI_ostride_1_CP_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_op_batch_2_istride_1_CI_ostride_1_CP_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(6498 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_ip_batch_1_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_ip_batch_1_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(2630 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_op_batch_1_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_double_op_batch_1_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(2718 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_ip_batch_4_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_ip_batch_4_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(8447 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_op_batch_4_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_op_batch_4_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(7018 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_ip_batch_2_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_ip_batch_2_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(3510 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_ip_batch_2_istride_1_CP_ostride_1_CP_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_ip_batch_2_istride_1_CP_ostride_1_CP_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(4090 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_op_batch_2_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_op_batch_2_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(3520 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_ip_batch_1_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_ip_batch_1_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(1766 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_op_batch_1_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_134217728_single_op_batch_1_istride_1_CI_ostride_1_CI_idist_134217728_odist_134217728_ioffset_0_0_ooffset_0_0
(1771 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_ip_batch_4_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
clients/tests/accuracy_test.h:1214: Skipped
needed_ramgb: 96, ramgb limit: 61.


[  SKIPPED ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_ip_batch_4_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
(0 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_op_batch_4_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
clients/tests/accuracy_test.h:1214: Skipped
needed_ramgb: 96, ramgb limit: 61.


[  SKIPPED ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_op_batch_4_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
(0 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_op_batch_4_istride_1_CP_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
clients/tests/accuracy_test.h:1214: Skipped
needed_ramgb: 96, ramgb limit: 61.


[  SKIPPED ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_op_batch_4_istride_1_CP_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
(0 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_ip_batch_2_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_ip_batch_2_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
(67340 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_op_batch_2_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_op_batch_2_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
(11059 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_op_batch_2_istride_1_CI_ostride_1_CP_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_op_batch_2_istride_1_CI_ostride_1_CP_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
(12243 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_ip_batch_1_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_ip_batch_1_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
(5412 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_op_batch_1_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
[       OK ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_double_op_batch_1_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
(5695 ms)
[ RUN      ]
pow2_1D/accuracy_test.vs_fftw/complex_forward_len_268435456_single_ip_batch_4_istride_1_CI_ostride_1_CI_idist_268435456_odist_268435456_ioffset_0_0_ooffset_0_0
command1             FAIL non-zero exit status 1
The dmesg logs indicate the oom killer activating with
vm.overcommit_memory=0:

[  633.775419] rocfft-test invoked oom-killer:
gfp_mask=0x440dc0(GFP_KERNEL_ACCOUNT|__GFP_COMP|__GFP_ZERO), order=0,
oom_score_adj=0

I've attached the rest of the dmesg log for the test. It has more details.

Sincerely,
Cory Bloor

#1082888#30
Date:
2024-09-28 09:53:18 UTC
From:
To:
Hm, odd. The OOM killer does kill rocfft-test, from dmesg:

and I would assume that this would be logged with "Killed" again.

Regardless:

This is the red flag right there, the test believes it has 61GiB of memory available (and it's skipped because it needs 96GiB).

I'm not yet familiar with how the driver dynamically allocates memory in 6.10, but an obvious way to run into this error is to query memory parameters at test start (GPU: 32GiB, System: 61GiB) and to assume that these are static. And grepping for "ramgb", it seems that this is exactly what is happening [8].

I don't think this is necessarily a bug in rocfft's tests, as this assumption is correct for discrete GPUs.

My first guess is that on hosts with APUs, we'll need to set --R and --V in the test runner as you initially suggested, with something like 45% of system memory each.

Best,
Christian

[8]: https://sources.debian.org/src/rocfft/6.1.2-1/clients/tests/gtest_main.cpp/#L329