Kins switch race in test kins-switch?

[BsAtHome]

@grandixximo This was seen on the package-arch trixie/arm CI test.

This didn't fail on master or other times. Restarting the failed CI "fixes" the error, so this indicates a race in the code or the test.

Running test: ./tests/kins-switch
*** ./tests/kins-switch: FAIL: test run exited with 1
************** result:
        Machine configuration file is 'test.ini'
        Starting LinuxCNC...
        linuxcnc TPMOD=tpmod HOMEMOD=homemod EMCMOT=motmod
        Found file(REL): ./sim.hal
        emc/task/emctask.cc 71: interp_error: G12.1 requires a non-negative P word
        G12.1 requires a non-negative P word
        emc/task/emctask.cc 71: interp_error: G12.1 P word does not name a kinematics type this module provides
        G12.1 P word does not name a kinematics type this module provides
        at the switch     77.6495 77.6495 -24.0301 -22.5000 45.0000 0.0000
        W ran to 10.0000, the other joints held to 0.00e+00
        *** ERROR motion.kins-type went [0, 1], not ...[0, 1, 0, 1]
        #<_kins_type> reported KINSTYPE=0.000000 KINSTYPE=1.000000 KINSTYPE=0.000000 KINSTYPE=1.000000
        refused as expected: G12.1 requires a non-negative P word
        refused as expected: G12.1 P word does not name a kinematics type this module provides
        the abort routine ran past its G13.1
        Exiting with 1 errors
        Shutting down and cleaning up LinuxCNC...
        task: 385 cycles, min=0.000002, max=0.044951, avg=0.007036, 0 latency excursions (> 10x expected cycle time of 0.010000s)
        
        !!! switchkins-type 0 is 5axiskins
        switchkins-type 0 declared: primary
        switchkins-type 1 declared: identity
        Kinematics Module emc/kinematics/5axiskins.c
          module name = 5axiskins
          coordinates = xyzbcw  Requires: [KINS]JOINTS>=6
          sparm       = NOTSPECIFIED
          default pivot-length = 250.000
        
        identityKinematicsSetup: coordinates:xyzbcw
           Joint 0 ==> Axis X
           Joint 1 ==> Axis Y
           Joint 2 ==> Axis Z
           Joint 3 ==> Axis B
           Joint 4 ==> Axis C
           Joint 5 ==> Axis W
        
        
        userkKinematicsSetup:
           emc/kinematics/userkfuncs.c <xyzbcw> max_joints=16 allow_duplicates=1
        
        LinuxCNC terminated with an error.  You can find more information in the log:
            /home/testrunner/linuxcnc_debug.txt
        and
            /home/testrunner/linuxcnc_print.txt
        as well as in the output of the shell command 'dmesg' and in the terminal
************** stderr:
        + rm -f sim.var sim.var.bak
        + linuxcnc -r test.ini
        /__w/linuxcnc/linuxcnc/tests/kins-switch/test.ini: info: [KINS]KINEMATICS=5axiskins: Unchecked
        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
        No isolated CPU's found, expect some latency or set RTAPI_CPU_NUMBER to select CPU
        link (updating variable file): No such file or directory
**************

[BsAtHome]

Are you sure it was fixed?

CI failed on the headless: https://github.com/LinuxCNC/linuxcnc/actions/runs/35321613265/job/105525149444

It also failed on the headless when I merged your fix, but I missed the importance and just restarted the CI run.

Running test: ./tests/kins-switch
*** ./tests/kins-switch: FAIL: test run exited with 1
************** result:
        Machine configuration file is 'test.ini'
        Starting LinuxCNC...
        linuxcnc TPMOD=tpmod HOMEMOD=homemod EMCMOT=motmod
        Found file(REL): ./sim.hal
        task: main loop took 0.153656 seconds
        task: main loop took 0.178064 seconds
        emc/task/emctask.cc 71: interp_error: G12.1 requires a non-negative P word
        G12.1 requires a non-negative P word
        emc/task/emctask.cc 71: interp_error: G12.1 P word does not name a kinematics type this module provides
        G12.1 P word does not name a kinematics type this module provides
        at the switch     0.0000 0.0000 0.0000 0.0000 0.0000 0.0000
        *** ERROR joint 0 moved 77.649513 while only W was asked for
        *** ERROR joint 1 moved 77.649513 while only W was asked for
        *** ERROR joint 2 moved 24.030117 while only W was asked for
        *** ERROR joint 3 moved 22.500000 while only W was asked for
        *** ERROR joint 4 moved 45.000000 while only W was asked for
        W ran to 10.0000, the other joints held to 7.76e+01
        the lines after the selections reported KINSTYPE=0.000000 PIN=0.000000 | KINSTYPE=1.000000 PIN=1.000000 | KINSTYPE=0.000000 PIN=0.000000 | KINSTYPE=1.000000 PIN=1.000000
        G43.4 switched to primary with the offset, G49 cancelled both
        refused as expected: G12.1 requires a non-negative P word
        refused as expected: G12.1 P word does not name a kinematics type this module provides
        the abort routine ran past its G13.1
        Exiting with 5 errors
        Shutting down and cleaning up LinuxCNC...
        task: 475 cycles, min=0.000004, max=0.178064, avg=0.006364, 2 latency excursions (> 10x expected cycle time of 0.010000s)
        
        !!! switchkins-type 0 is 5axiskins
        switchkins-type 0 declared: primary
        switchkins-type 1 declared: identity
        Kinematics Module emc/kinematics/5axiskins.c
          module name = 5axiskins
          coordinates = xyzbcw  Requires: [KINS]JOINTS>=6
          sparm       = NOTSPECIFIED
          default pivot-length = 250.000
        
        identityKinematicsSetup: coordinates:xyzbcw
           Joint 0 ==> Axis X
           Joint 1 ==> Axis Y
           Joint 2 ==> Axis Z
           Joint 3 ==> Axis B
           Joint 4 ==> Axis C
           Joint 5 ==> Axis W
        
        
        userkKinematicsSetup:
           emc/kinematics/userkfuncs.c <xyzbcw> max_joints=16 allow_duplicates=1
        
        LinuxCNC terminated with an error.  You can find more information in the log:
            /home/runner/linuxcnc_debug.txt
        and
            /home/runner/linuxcnc_print.txt
        as well as in the output of the shell command 'dmesg' and in the terminal
************** stderr:
        + rm -f sim.var sim.var.bak
        + linuxcnc -r test.ini
        /home/runner/work/linuxcnc/linuxcnc/tests/kins-switch/test.ini: info: [KINS]KINEMATICS=5axiskins: Unchecked
        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
        No isolated CPU's found, expect some latency or set RTAPI_CPU_NUMBER to select CPU
        link (updating variable file): No such file or directory
**************

[grandixximo]

Yes, the fix holds. What fails is the test I added with it, on a race of its own.

The hold that checks the joints stay put after the program's G12.1 P1 takes its reference from the first sample that reads identity. The config's ON_ABORT routine ends in G13.1, which leaves the machine in identity at the homed zeros. When the test's first poll lands before the program's first line, as it does on the slower runners, that sample is the reference: the "at the switch 0.0000 0.0000 ..." line in your log. The program then rapids to its pose and switches at that pose, and every sample after that reads as the joints straying by the length of the program's own moves. Locally the program's first line runs before the first poll, so the reference is the program's switch and the test passes.

The lines after the selections reported KINSTYPE=... PIN=... all match in that log, so the task-side fix did its job; the five errors are the hold comparing against the wrong pose.

#4564 starts the test in identity through MDI every run and takes the reference at the change the program makes, so the ordering no longer matters. I reproduced the CI ordering locally by polling once before the program starts, same numbers, and it passes with the change.