Flaky tests when CPU is busy

While working on #4665, I discovered that several tests start failing randomly when running with to many jobs. And I also remember having rare CI fails which just went away on the next push.

This is not a big issue, you can just run the parallel tests with less jobs. But these races might hit also somewhere else.

This can be reproduced sometimes by running on a slow PC or in a VM with only 2 CPU's mapped. When the CPU is kept busy with stress-ng --cpu ncpu, the tests fail also in single threaded mode.

touchy UI tests, 100% reproducible with ncpu=16:

tests/ui-smoke/touchy-fit
UI_SMOKE_FAIL: window-fit: no window matching ("touchy" "Touchy") found

touchy UI tests, somewhat reproducible, better with ncpu=128. Looks like loading touchy_postgui.hal has a race.

tests/ui-smoke/touchy-quit
UI_SMOKE_QUIT_FAIL: GUI (pid 206) showed no window within 60s
...
touchy_postgui.hal:7: Pin 'touchy_test.mpg' does not exist

tests/ui-smoke/touchy
UI_SMOKE_FAIL: MODE_AUTO did not hold stable across 6 attempts
...
touchy_postgui.hal:7: Pin 'touchy_test.mpg' does not exist

SET_TERM_COND / SET_LINE appearing, somewhat reproducible, better with ncpu=128:

tests/motion-logger/basic
tests/motion-logger/mountaindew
tests/interp/m98m99/12-M99-endless-main-program
+SET_TERM_COND termCond=2, tolerance=0.00

tests/motion-logger/startup-gcode-abort
+SET_TERM_COND termCond=2, tolerance=0.001
+SET_LINE x=-1, y=-2, z=-3, a=0, b=0, c=0, u=0, v=0, w=0, id=2, motion_type=1, vel=4.98888, ini_maxvel=4.98888, acc=1247.22, turn=-1

hal-show changing order, does not reproduce well, once in a while, this happens only in parallel mode:

tests/hal-show
-    13  uint  IN     0x0000000000000000  conv-uint-bool.0.in <== net-conv-uint-bool.0.in
+    11  uint  IN     0x0000000000000000  conv-uint-bool.0.in <== net-conv-uint-bool.0.in

Found the first source of flakiness. Looks like SET_TERM_COND termCond=2, tolerance=0.001 should normally be shown, except you manage to be fast enough to not process this command. The following patch would fix it.

Before I fix many tests which have this part copy-paste: Is this the right way to wait for linuxcnc to be up and running? There are 57 tests having test-ui.py and at least 4 have this issue.

diff --git a/tests/motion-logger/basic/expected.builtin-startup.in b/tests/motion-logger/basic/expected.builtin-startup.in
index 2296018b31..fce76f310a 100644
--- a/tests/motion-logger/basic/expected.builtin-startup.in
+++ b/tests/motion-logger/basic/expected.builtin-startup.in
@@ -176,6 +176,7 @@ SPINDLE_OFF
 DISABLE
 JOINT_UNHOME joint=-2
 FREE
+SET_TERM_COND termCond=2, tolerance=0.001
 JOG_ABORT joint=0
 JOG_ABORT joint=1
 JOG_ABORT joint=2
diff --git a/tests/motion-logger/basic/test-ui.py b/tests/motion-logger/basic/test-ui.py
index 21da4c2bd4..8d85df15bc 100755
--- a/tests/motion-logger/basic/test-ui.py
+++ b/tests/motion-logger/basic/test-ui.py
@@ -45,6 +45,15 @@ c = linuxcnc.command()
 s = linuxcnc.stat()
 e = linuxcnc.error_channel()
 
+#
+# Wait for interpreter to be ready
+#
+
+while True:
+    s.poll()
+    time.sleep(0.1)
+    if s.interp_state == linuxcnc.INTERP_IDLE:
+        break
 
 #
 # Come out of E-stop, turn the machine on, and switch to Auto mode.

An other sometimes failing tests, does not reproduce well except sometimes with parallel tests:

tests/ui-smoke/gmoccapy
...
WARN: homing did not complete on attempt 1, retrying
WARN: STATE_ESTOP_RESET not reached on attempt 1, retrying
WARN: STATE_ESTOP_RESET not reached on attempt 2, retrying
WARN: STATE_ESTOP_RESET not reached on attempt 3, retrying
WARN: STATE_ESTOP_RESET not reached on attempt 4, retrying
WARN: STATE_ESTOP_RESET not reached on attempt 5, retrying
WARN: STATE_ESTOP_RESET not reached on attempt 6, retrying
UI_SMOKE_FAIL: STATE_ESTOP_RESET did not hold stable across 6 attempts
...

This is not a big issue, you can just run the parallel tests with less jobs. But these races might hit also somewhere else.

All these are races that need fixing. Either the base code has a race or the test has a race. Both are equally bad.

4. > This is not a big issue, you can just run the parallel tests with less jobs. But these races might hit also somewhere else.
    All these are races that need fixing. Either the base code has a race or the test has a race. Both are equally bad.

Agreed. Now with the parallel tests, you can easily detect them without running tests for weeks... :-)

Meanwhile, I found another one:

tests/linuxcncrsh
--- expected-telnet-output	2026-10-11 14:14:10.328086275 +0200
+++ telnet-output	2026-10-12 20:24:54.139307950 +0200
@@ -136,10 +136,10 @@
 MODE MDI
 ERROR OK
 SET PROBE ACK
-ERROR G38.2 move finished without making contact.
+ERROR OK
 PROBE_TRIPPED NO
 SET PROBE_CLEAR ACK
-ERROR OK
+ERROR G38.2 move finished without making contact.
 MODE MDI
 SET MODE ACK
 MODE MANUAL

With the following commands together with #4648:

JOBS=32
RUNS=32
N=8
M=4
time seq $RUNS | parallel -j $N "echo Running {} {%} RT \$(($M*({%}-1))) taskset \$(($M*({%}-1)))-\$(($M*{%}-1)) ; export RTAPI_CPU_NUMBER=\$(($M*({%}-1))) ; taskset -c \$(($M*({%}-1)))-\$(($M*{%}-1)) scripts/runtests -p -j $JOBS 2> /dev/null"

or

JOBS=32
RUNS=32
N=8
time seq $RUNS | parallel -j $N "SLEEP=\$(shuf -i 0-15 -n 1); echo Running {} sleep \$SLEEP ; sleep \$SLEEP ; scripts/runtests -p -j $JOBS 2> /dev/null"

I can now run 32 full test runs in 7 min, 64x faster than before.

tests/linuxcncrsh fails quite often, log in last comment, it is not always the same
tests/multiclick fails from time to time, log below
Otherwise, it looks quite stable with tests, task: fix load-dependent test failures #4674, only a few sporadic failures. But this is to be expected if up to 256 linuxcnc instances run on a 16 core cpu. I've seen up to 2000 tasks running. Once in a while, a timeout will hit.

--- /home/hannes/linuxcnc-src/tests/multiclick/expected	2026-10-11 14:14:10.340086643 +0200
+++ /home/hannes/linuxcnc-src/tests/multiclick/result	2026-10-12 21:52:16.692245495 +0200
@@ -97,8 +97,8 @@
 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 1 0 8 
 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 8 
 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 8 
-0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 1 0 
-0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 1 0 
+0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 
+0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 
 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 
 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 
 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0

tests/hal-show: mask the id together with its padding

task: report a probe move done only once motion has judged it

tests/multiclick, tests/mux: load the whole input before starting

hal: a stream of depth N holds N samples

After cherry-picking all from #4674 and #4663 together, I run 544 tests runs, massive parallel with the commands above. The branch is here: https://github.com/hdiethelm/linuxcnc-fork/tree/tests_parallel_v2_combined_tests

There 25 failures. Probably some due to just overload and timeouts but there might be other bugs hidden. You might find something worth investigating, so the report below.

Most failures are:
ui-smoke/gmoccapy 10x
ui-smoke/qtdragon-quit 5x

And then there are rare occurrences of:
interp/g28.2/home-all-sequence 2x
ui-smoke/gmoccapy-quit 2x
linuxcncrsh 1x
threads.0 1x
kins-switch-unsolved 1x
raster 1x
tests/m62-m68-range 1x
halmodule/stream 1x

Here just the full reports:

With taskset:
32x
tests_takset_1.txt
128x
tests_takset_2.txt

With all CPU's:
128x
tests_all_cpu_1.txt

Disabling copy back to test directory, it could have an influence when you are executing parallel runtests in parallel. But it looks like it did not change much. More statistics would be needed.
Each 128 runs.
tests_takset_nocopy.txt
tests_all_cpu_nocopy.txt

tests/halmodule/stream: print the result before signalling ready

tests/ui-smoke: let a slow homing sequence finish instead of homing a…

@hdiethelm

@hdiethelm thanks for the long runs. From your report:

gmoccapy (homing restarted while X held the switch it shares with Z) and halmodule/stream: fixed in tests, task: fix load-dependent test failures #4674.
m62-m68-range: the torn status read motion: fix the split read check on the shared status structs #4672 fixes. Motion rejected M67 E7, but task read a copy with the new command echo and the old OK status, so the program went on.
g28.2/home-all-sequence: a re-home in place takes a few servo cycles and can finish between two task status reads, so task reported "did not start". Fixed in task: count a G28.2 homing run that ends between two status reads #4680.
qtdragon-quit, gmoccapy-quit and the no-window failures look like fixed timeouts under that load. kins-switch-unsolved, threads.0 and raster I haven't looked at yet. For linuxcncrsh I'd need the telnet-output diff, which isn't in the report.

touchy sim: wait for the test panel before the postgui file

tests/ui-smoke: measure the touchy window only once it is mapped

This:
*** SHMERR: Shared memory segment 0x00000064 (Emc motion key) was not removed. Removing...
indicates a crash.

22. This:
*** SHMERR: Shared memory segment 0x00000064 (Emc motion key) was not removed. Removing...
indicates a crash.

Only a halrun / linuxcnc crash. After an rtapi_app crash, halrun will cleanup shm using realtime stop.

I have to figure out a way to fail a tests if rtapi_app crashed. Right now, it looks like there is no real error.

Only a halrun / linuxcnc crash. After an rtapi_app crash, halrun will cleanup shm using realtime stop.
I have to figure out a way to fail a tests if rtapi_app crashed. Right now, it looks like there is no real error.

You are right, 0x00000064 (Emc motion key) is not removed in the realtime script. It removes only the other shm keys. However, the way it crashes in the case I am debugging just now, this key is removed due to rtapi_app crashed during unload. This is why I have more segfaults than SHMERR in the logs.

Based on the backtrace and the log, I have the suspicion that the thread function is called after the component has already been unloaded or is still running while being unloaded. Both tests segfaulting do a delay inside the component.

probe-queue-not-empty/stderr:

+ set -e
+ halcompile --install servo_delay.comp
+ linuxcnc -r test.ini
Note: realtime scheduling unavailable (sched_setscheduler SCHED_FIFO: Operation not permitted).
  Process capabilities: cap_sys_nice=no cap_ipc_lock=no.
  Falling back to POSIX non-realtime.
  Fix: 'sudo make setcap' (preferred) or 'sudo make setuid' on rtapi_app.
  Override (testing only): set LINUXCNC_FORCE_REALTIME=1.
Note: Using POSIX non-realtime
link (updating variable file): No such file or directory
probes done: 100
rtapi_app: recv_result 1 failed: Connection reset by peer
rtapi_app: failed to read from master
<commandline>:0: exit value: 255
<commandline>:0: rmmod failed, returned -1
WARNING: Deprecated: No active realtime environment found. Use "realtime start" to start one.
  A realtime environment is started automatically.
  If this appears while using halcmd: Use halrun instead.
  halcmd should only be used with an already running realtime environment.
  halrun creates a realtime environment and tears it down at exit.
Note: realtime scheduling unavailable (sched_setscheduler SCHED_FIFO: Operation not permitted).
  Process capabilities: cap_sys_nice=no cap_ipc_lock=no.
  Falling back to POSIX non-realtime.
  Fix: 'sudo make setcap' (preferred) or 'sudo make setuid' on rtapi_app.
  Override (testing only): set LINUXCNC_FORCE_REALTIME=1.
Note: Using POSIX non-realtime
hypot: not loaded
<commandline>:0: exit value: 255
<commandline>:0: rmmod failed, returned -1
ddt: not loaded
<commandline>:0: exit value: 255
<commandline>:0: rmmod failed, returned -1
motmod: not loaded
<commandline>:0: exit value: 255
<commandline>:0: rmmod failed, returned -1
trivkins: not loaded
<commandline>:0: exit value: 255
<commandline>:0: rmmod failed, returned -1
homemod: not loaded
<commandline>:0: exit value: 255
<commandline>:0: rmmod failed, returned -1
tpmod: not loaded
<commandline>:0: exit value: 255
<commandline>:0: rmmod failed, returned -1

Indeed, the following patch fixes all segfaults, proving the theory. Doing it this way is a bad idea thought, works only with one thread and is not 100% race save. #4630 fixes most of it but left one race condition behind: hal_data->threads_running == 0 does not guarantee that the thread is not still processing a function call, so it can race with unloading the function while it is still running.

diff --git a/src/hal/hal_lib.c b/src/hal/hal_lib.c
index 227cf6ad62..56873c2baf 100644
--- a/src/hal/hal_lib.c
+++ b/src/hal/hal_lib.c
@@ -2776,6 +2776,9 @@ int hal_stop_threads(void)
     }
 
     hal_data->threads_running = 0;
+    while(hal_data->threads_running_ack){
+        rtapi_delay(1000000);
+    }
     rtapi_print_msg(RTAPI_MSG_DBG, "HAL: threads stopped\n");
     return 0;
 }
@@ -3275,6 +3278,7 @@ static void thread_task(void *arg)
 
     thread = arg;
     while (1) {
+        hal_data->threads_running_ack = hal_data->threads_running;
         if (hal_data->threads_running > 0 && !thread->init_done) {
             /* special init cycle: run init_funct_list once with no
                timing measurement, re-anchor the period so the long
diff --git a/src/hal/hal_priv.h b/src/hal/hal_priv.h
index 8692aae946..a487b9021e 100644
--- a/src/hal/hal_priv.h
+++ b/src/hal/hal_priv.h
@@ -286,7 +286,8 @@ typedef struct hal_data_t {
     SHMFIELD(hal_funct_t) funct_list_ptr;   // root of linked list of functions
     SHMFIELD(hal_thread_t) thread_list_ptr; // root of linked list of threads
     long base_period;                       // timer period for realtime tasks
-    int threads_running;                    // non-zero if threads are started
+    int threads_running;                    // non-zero if threads are started (set and reset from externally)
+    int threads_running_ack;                // non-zero if threads are running (set by and reset by thread)
     SHMFIELD(hal_oldname_t) oldname_free_ptr; // list of free oldname structs
     SHMFIELD(hal_comp_t) comp_free_ptr;     // list of free component structs
     SHMFIELD(hal_pin_t) pin_free_ptr;       // list of free pin structs

tests: home one joint at a time

tests/ui-smoke: no import in the qtdragon shim's SIGUSR1 handler

tests: stale-motion-status: slow the controller only once task is up

@hdiethelm

@hdiethelm thanks, I reproduced every round 4 failure here and have a fix for each:

rtapi_app segfault at unload: as you found, halcmd stop returned while a thread was still inside a function. hal: stop returns once no thread runs a function #4694 makes stop wait for every thread, with a busy flag per thread, and tests/hal-delf-live now holds the thread inside a function across stop.
slow-controller "can't read motion status": at startup task retries that read once a second, at the same point of the 1 ms servo period each time, so with slowkins busy for most of the period all ten tries can miss. The busy wait now starts once task is up (pushed to task: do not take a motion status from before a command as current (#3650) #4666). Your print shows the time left, so 60 means the first try worked and 0 the failures.
stop-button-crazy-move "Homing not possible...": motion refuses to home a joint while another one is homing, and the test sent its three homes back to back. The tests now home one joint at a time (tests, task: fix load-dependent test failures #4674).
qtdragon-quit sip error: this one was our ui-smoke shim. Its SIGUSR1 screenshot handler imported qtpy.QtCore, and the launcher signals every second from qtvcp's start, so a signal during qtvcp's first PyQt5 import imported it a second time (tests, task: fix load-dependent test failures #4674). The command 32 timeout is the first motion command at startup under load; task retried it and went on.
gmoccapy-quit: the SIGTERM arrived in an at-fork hook while gmoccapy ran its postgui halcmd, where Python drops the exception (gmoccapy: exit on a SIGTERM lost in a fork hook at startup #4696).
tooldb/db-g10-offset: a real bug. Every db notification also sent an empty line, so task read the replies one behind and the G10 returned before the db program had saved the offset (tooldata: send each db notification as one line #4695).
Newline missing in some log messages #4689: rtapi: end an error or warning that lacks the newline #4697 adds the missing newline to errors and warnings where they are printed, as Bertho suggested.

hal: stop returns once no thread runs a function

tooldata: send each db notification as one line

gmoccapy: exit on a SIGTERM lost in a fork hook at startup

Thanks for all the fixes. The list of PR's due to what was initially just an experiment how many tests I can run as fast as possible starts being quite long... ;-)
Merged to my test branch in this order:
#4694
#4666
#4674
#4696
#4695

There was also an issue in my parallel tests not using taskset (tests_all_cpu*.txt results): All rtapi_app tasks where running on the same CPU, load at 100%. I need to fix this also for the normal parallel tests. It only occurs if you have an isolated CPU due to rtapi_app chooses this CPU to run which is fine as long you don't run 256 instances of it...

Especially stale-motion-status/slow-controller creates quite a high load on the rtapi_app task, surfacing this.

This was the reason stale-motion-status/slow-controller was still failing.
I had a few:

        USRMOT: ERROR: command 20 timeout (seq: 553)
        USRMOT: ERROR: command 1 timeout (seq: 570)
        the program did not finish

This is probably just a normal timeout, not a bug and it is gone by not running 256x rtapi_app on one CPU.

And next test round, 128 tests each, rtapi_app tasks spread over the CPU's:
I had one case of:
/home/hannes/linuxcnc-src/tests/ui-smoke/touchy-quit: *** SHMERR: Shared memory segment 0x00000064 (Emc motion key) was not removed. Removing...
Which probably is caused by the following log. However, it is not straight forward to assign console errors to test logs, it is a best guess. Looks like rtapi_app exited early but there was no segfault.
touchy-quit.txt

Otherwise, it looks good, 256 of 256 tests rounds pass, except the issue above.

I think it is time to consolidate, merge everything and then I can do another round of testing.

tests: stale-motion-status: slow the controller only once task is up

Rebased to master and merged #4701 to test branch:
256 tests rounds passed, no SHMERR nice!

tests/ui-smoke: let linuxcnc shut down before signalling its group

Navigation Menu

Repository navigation

Flaky tests when CPU is busy #4669

30 remaining items

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Flaky tests when CPU is busy #4669

Description

Activity

hdiethelm commented on Oct 11, 2026

hdiethelm commented on Oct 11, 2026

BsAtHome commented on Oct 12, 2026

hdiethelm commented on Oct 12, 2026

hdiethelm commented on Oct 12, 2026

hdiethelm commented on Oct 13, 2026

grandixximo commented on Oct 14, 2026

30 remaining items

BsAtHome commented on Oct 15, 2026

hdiethelm commented on Oct 15, 2026

hdiethelm commented on Oct 16, 2026

hdiethelm commented on Oct 16, 2026

grandixximo commented on Oct 17, 2026

hdiethelm commented on Oct 17, 2026

hdiethelm commented on Oct 18, 2026

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions