gh-150114: Log the memory usage in regrtest

[vstinner]

On Linux, log the total memory usage of all Python processes. Read the private memory in /proc/pid/smaps.

• Issue: GitHub free threading CI failing with SIGTERM #150114

[vstinner]

I looked manually at logs to get minimum and maximum memory usage:

• Address sanitizer (ubuntu-24.04): min mem: 119.4 MiB, max mem: 3.2 GiB.
• Sanitizers / TSan (free-threading): min mem: 323.1 MiB, max mem: 3.4 GiB.
• Sanitizers / TSan: min mem: 105.0 MiB, max mem: 769.5 MiB.
• Sanitizers / UBSan: min mem: 47.5 MiB, max mem: 650.5 MiB.
• Ubuntu / build and test (ubuntu-24.04-arm): mem: 22.9 MiB, max mem: 608.5 MiB.
• Ubuntu / build and test (ubuntu-24.04): min mem: 22.8 MiB, max mem: 761.0 MiB.
• Ubuntu (free-threading) / build and test (ubuntu-24.04-arm): min mem: 31.6 MiB, max mem: 925.0 MiB.
• Ubuntu (free-threading) / build and test (ubuntu-24.04): min mem: 41.5 MiB, max mem: 1.1 GiB.
• WASI / build and test: min mem: 22.9 MiB, max mem: 884.9 MiB.

"Ubuntu (free-threading) / build and test (ubuntu-24.04)" uses 1.5x more memory (1.1 GiB) than
"Ubuntu / build and test (ubuntu-24.04)" (761.0 MiB), but the maximum is still 3x lower than "Address sanitizer (ubuntu-24.04)" (3.2 GiB) and "Sanitizers / TSan (free-threading)" (3.4 GiB).

[vstinner]

Oh, "Tests / Ubuntu (free-threading) / build and test (ubuntu-24.04) (pull_request)" failed with issue gh-150114:

(...)
0:10:31 load avg: 9.31 mem: 14.1 GiB running (6): test.test_concurrent_futures.test_deadlock (30.6 sec), test_capi (59.9 sec), test_free_threading (3 min 59 sec), test_profiling (43.5 sec), test.test_multiprocessing_forkserver.test_processes (1 min 1 sec), test.test_concurrent_futures.test_process_pool (1 min 50 sec)
0:11:01 load avg: 9.29 mem: 14.6 GiB running (6): test.test_concurrent_futures.test_deadlock (1 min 1 sec), test_capi (1 min 30 sec), test_free_threading (4 min 29 sec), test_profiling (1 min 14 sec), test.test_multiprocessing_forkserver.test_processes (1 min 32 sec), test.test_concurrent_futures.test_process_pool (2 min 20 sec)
make: *** wait: No child processes.  Stop.
make: *** Waiting for unfinished jobs....
make: *** wait: No child processes.  Stop.
Error: Process completed with exit code 143.

I restarted the job.

[vstinner]

Let's see how this code goes on the CI / buildbots before considering to backport this new regrtest feature to stable branches (3.13, 3.14, 3.15).

[StanFromIreland]

It doesn’t the process’s children I think, is it possible to include them?

Also, why was the sequential runner omitted?

[vstinner]

@StanFromIreland:

It doesn’t the process’s children I think, is it possible to include them?

Getting an accurate value of the memory usage on Linux is complicated. The RSS memory for example is higher than "expected":

$ ./python
>>> import test.libregrtest.utils, os
>>> test.libregrtest.utils.get_process_memory_usage(os.getpid()) / 1024**2
26.28125
>>> rc=os.system(f"grep ^VmRSS /proc/{os.getpid()}/status")
VmRSS:	   36204 kB

I reused the private memory from /proc/pid/smaps since it's used by pyperf and seems to be reliable in my experience. See this quick introduction to smaps: https://web.archive.org/web/20180907232758/https://bmaurer.blogspot.com/2006/03/memory-usage-with-smaps.html.

About child processes, you're correct that they are not included, only worker test processes and the main test process. I chose to start simple to debug the issue gh-150114. Maybe it would make sense to include them, I'm not sure. Well, it was also simpler to only read the usage of worker processes, since we can easily get their pid.

Also, why was the sequential runner omitted?

Oh, it's just that I wanted to merge a quick change to debug the issue. I wrote gh-150264 follow-up issue to also log the memory usage when tests are run sequentially.

[vstinner]

By the way, here is a "screenshot" of the new feature: it adds "mem: xxx MiB" to the output.

...
0:00:05 load avg: 53.90 mem: 185.0 MiB [ 13/505] test_patma passed
0:00:08 load avg: 50.54 mem: 184.2 MiB [ 14/505] test.test_asyncio.test_eager_task_factory passed
0:00:09 load avg: 50.54 mem: 180.3 MiB [ 15/505] test_tomllib passed
0:00:09 load avg: 50.54 mem: 168.9 MiB [ 16/505] test.test_concurrent_futures.test_future passed
0:00:10 load avg: 50.54 mem: 175.9 MiB [ 17/505] test_picklebuffer passed
0:00:11 load avg: 50.54 mem: 157.7 MiB [ 18/505] test_c_stack_unwind passed
0:00:15 load avg: 47.38 mem: 191.5 MiB [ 19/505] test.test_gdb.test_misc passed
0:00:15 load avg: 47.38 mem: 170.0 MiB [ 20/505] test_buffer passed
...