Investigate intermittent CI fail on homing

[BsAtHome]

(from #4270) the mdi test fails sometime, have you also noticed this? I had it happen on #4280 merge build and here, not sure what's it about, was it happening before too, or is something new?

@grandixximo You may be referring to the non-homed state failure that happens. There still seems to be a RT-to-non-RT or non-RT-to-RT timing/race issue in the homing code. That I've seen happen several times.

The linuxcncrsh test fails on it once in a while. One of the joints fails to home and then the checked for output is off. Probably when the CI machines are busy and the race or timing gets hit. There are other tests that use linuxcncrsh and all would be prone to the same intermittent problem if they use homing.

[grandixximo]

I looked at the two recent halui/mdi failures (the master build and the three21 PR) and I think they may be a different issue from the homing race.

The failure lines were:

• timeout waiting for halui to report mode is-auto
• timeout waiting for task mode to get to 3 (it's 2)

That test does not home: its halui.ini has NO_FORCE_HOMING=1 and no homing moves configured, so the homing race probably does not apply there. The "it's 2" case looks like halui ran an MDI command and task never got switched back to AUTO afterwards, so maybe the mode-restore or an NML command/status round trip stalls when the CI machines are busy. It could be the same timing umbrella, but the mechanism seems different from homing.

Perhaps it is worth tracking the mdi mode-switch timeouts as a separate item. There is some history here too: d69d170 already bumped these timeouts once.

[BsAtHome]

But that is the whole point. The pure timeout strategy is problematic because you can't be sure it holds the promise you are looking for. Normally this type of problem exists because of RT/non-RT asynchronicity. We need to look at the sync-points and how we check (that is why the heartbeat was fixed).

[BsAtHome]

The problem in halui/mdi seems to be:

11.588: timeout waiting for task mode to get to  2 (it's 1)

The message pops up when EMC_TASK_STAT::mode does not change from EMC_TASK_MODE::MANUAL to EMC_TASK_MODE::AUTO.

The problem may be in

linuxcnc/src/emc/task/emctask.cc

Lines 392 to 402 in d5c3687

	EMC_TASK_MODE determineMode()
	{
	if (emcStatus->motion.traj.mode == EMC_TRAJ_MODE::FREE) {
	return EMC_TASK_MODE::MANUAL;
	}
	if (emcStatus->motion.traj.mode == EMC_TRAJ_MODE::TELEOP) {
	return EMC_TASK_MODE::MANUAL;
	}
	// for EMC_TRAJ_MODE::COORD
	return mdiOrAuto;
	}

because it prevents the mode from moving forward if some conditions are not met.

This is called from

linuxcnc/src/emc/task/emctask.cc

Lines 688 to 691 in d5c3687

	int emcTaskUpdate(EMC_TASK_STAT * stat)
	{
	stat->mode = determineMode();
	EMC_TASK_STATE oldstate = stat->state;

The question we should ask is what the value of the emcStatus->motion.traj.mode is at the time of failure. My guess is that the task mode gets stuck through the value there in the trajectory mode.

[grandixximo]

@BsAtHome I think your traj.mode guess was right, and I found the mechanism underneath it.

determineMode() only reports f(traj.mode, mdiOrAuto); the drop happens in motion. set_operating_mode() in control.c honors a mode transition only if INPOS is true in the one servo cycle that processes the request, otherwise it erases the request (coordinating/teleoperating cleared; a failed free exit even forces coordinating back to 1). Task echoes EMC_TASK_SET_MODE when it is read and flips mdiOrAuto immediately, so the writer sees success while traj.mode stays behind, permanently. That would explain why the failures are wedges that no timeout can outlast, and why they only appear under load: the INPOS window right after a move is timing sensitive.

I opened #4284 with a small fix: keep the request pending so the transition completes when motion comes to rest. A deterministic repro (requesting MANUAL mid-MDI-move) wedges task mode at AUTO on master and converges with the fix. halui, linuxcncrsh, mdi-queue and abort runtests pass, plus 60/60 loaded halui/mdi iterations locally.

On the NML side I could not find a race: the command channel is a proper queue with a shared serial counter and an OS semaphore for local writers, so commands are not lost or overwritten there.