Hi all,

from 3.6.0-beta.1 I started to have some layer shifts in the first layers of a print. These shifts happen randomly (the same gcode might shift in one print and not in the consecutive one, or just in another position). Still, I didn't find a way to replicate exactly the issue. The shift happens because the expansion boards go out of sync for about 2 seconds and the movement commands are discarded (as intended behavior from 3.6.0-beta.1).
So far, it never shifted when the bed compensation was disabled or, when enabled, it never shifted above the tapering height (5mm).
To debug, I connected a can sniffer device and analyzed the TimeSync messages. The out-of-sync happens when the field lastTimeAcknowledgeDelay is zero for more than 10 consecutive times. From my understanding, the CanClockLoop doesn't update this variable if the previous message takes more than MaxTimeSyncDelay between the call of the send function and when the ISR actually processed the TX callback.

From the plots you can see that the behavior of lastTimeAcknowledgeDelay with FW 3.5.2 and 3.6.0-beta.1 is similar, so I might never have had a shift before just because in 3.5.2 the movement commands weren't discarded.
I increased MaxTimeSyncDelay from 300 (400 usec?) to 375 (500 usec?) to see what happens: these spikes are still present but the number of zeros is reduced, so hopefully tolerant enough to never reach 10 consecutive samples.

From the plot, it looks like the normal value for lastTimeAcknowledgeDelay is around 3-5 and a cloudy distribution around 250-300. So the original threshold of 300 would make sense.
I'm wondering why there are these spikes, after one spike to about 300 or more, the spike is then repeated every 5 samples but with a linear decreasing amplitude.
I tried also to disable the input shaping but the overall distribution is similar.

Do you have any explanation for this behavior? Other processes or interrupts interfering? Do you think it would make sense to increase the MaxTimeSyncDelay threshold or is it just a patch? Do you foresee any issues arising from doing this?

Thanks in advance.

Hi all,
I am doing some motion tuning for a quite big and heavy machine. In general I noticed that having high values of jerk (about 500-600 mm/min) are good enough to travel circular paths smoothly (even tough it depends a lot on the mesh quality), but they are a bit high when printing corners, reducing a lot the effect of the input shaping and introducing lot of ringing.
Since I couldn't find a decent balance of jerks, acceleration and the Input Shaping L parameter, I modified a bit the function DDA::MatchSpeed and the command M566:

Basically my idea is to estimate the angle between two consecutive segments and if it is greater than a certain threshold I use a lower value of jerk.

I added to M566 a parameter J "junctionDeviation" which is the threshold below which an high value of jerk is used (the one set from M566 X-- Y--). For greater values, the minimum jerk multiplied by the parameter S is used.
I consider as threshold the difference between the X components of v1 and v2 in the reference frame of v1, and since v1 and v2 are unit vectors the threshold is equal to (1 - cos(alpha)).

void DDA::MatchSpeeds() noexcept
{
	// v2 needs to be expressed in the reference frame of v1
	// directionVector and next->directionVector are unit vectors

	// The rotation matrix R(-alpha) can be expressed by using the directionVector[0] and directionVector[1] which are the X and Y components of v1 in the absolute reference frame (v1_0).
	const float rotationMatrix[2][2] = {
		{ directionVector[0], directionVector[1] },
		{ -directionVector[1], directionVector[0] }
	};

	// Project v2 in the reference frame of v1 (v2_1)
	const float nextVectorProjected[2] = {
		rotationMatrix[0][0] * next->directionVector[0] + rotationMatrix[0][1] * next->directionVector[1],
		rotationMatrix[1][0] * next->directionVector[0] + rotationMatrix[1][1] * next->directionVector[1]
	};

	// Difference of X and Y components in the reference frame of v1 (v1_1 - v2_1)
	const float relativeFraction[2] = {
		fabsf(1 - nextVectorProjected[0]),
		fabsf(0 - nextVectorProjected[1])
	};

	for (size_t drive = 0; drive < MaxAxesPlusExtruders; ++drive)
	{
		if (directionVector[drive] != 0.0 || next->directionVector[drive] != 0.0)
		{
			const float totalFraction = fabsf(directionVector[drive] - next->directionVector[drive]);
			const float jerk = totalFraction * beforePrepare.targetNextSpeed;
			float allowedJerk = reprap.GetPlatform().GetInstantDv(drive);
			// if dealing with X and Y axes reduce jerk if sharp edges
			if (drive < 2 && relativeFraction[0] > reprap.GetPlatform().JunctionDeviation())
			{
				allowedJerk = ConvertSpeedFromMmPerSec(MinimumJerk * reprap.GetPlatform().MinimumJerkMultiplier());
			}
			if (jerk > allowedJerk)
			{
				beforePrepare.targetNextSpeed = allowedJerk/totalFraction;
			}
		}
	}
}

Of course the code is not optimised, but it was just a first test to see if the idea could work.
I have done a couple of prints with a bit extreme setting (M566 X600 Y600 J0.01 S1) and I noticed a good improvement in print quality. Corners don't induce much ringing, so the input shaping can play a role there, and circular motions are done without too much scattering.

I'd like to have some feedback from this approach, especially if you see weird/dangerous edge cases that I didn't think about, in the code implementation and/or in the machine behaviour.

Thank you in advance to all of you!

now I'm doing some tests increasing StepTimer::MinSyncInterval from 2000 to 4000. I noticed it was already increased some years ago, it might be the same issue, I am also running on a SAME70.

Thanks @droftarts.
Update note: I got a resync also with MaxTimeSyncDelay = 375.

@dc42 yes, I logged that message right after the expansion boards got out of sync and the print shifted. I was also able to sniff the CAN messages of another print that failed in the same way and that's where I noticed 'lastTimeAcknowledgeDelay' being equal to zero for more than 10 times consecutively. That's how I started to test higher values for MaxTimeSyncDelay (initially 375), but I didn't know how far I could go.

@dc42 I still have one:

All averaging filters OK Never used RAM 164992, free system stack 172 words 
Tasks: Move(3,nWait 7,0.0%,126) TMC(2,delaying,1.4%,51) HEAT(2,nWait 6,0.1%,89) CanAsync(5,nWait 4,0.0%,66) CanRecv(3,nWait 1,0.1%,73) CanClock(5,nWait 1,0.0%,63) LED(2,delaying,0.0%,123) ACCEL(3,nWait 6,0.0%,87) MAIN(1,running,97.4%,319) IDLE(0,ready,0.0%,29) AIN(2,delaying,1.0%,259), total 100.0% 
Owned mutexes: 
Last reset 02:15:02 ago, cause: power up 
Last software reset data not available 
Moves scheduled 37920, hiccups 0 (0.00/0.00ms), segs 37, step errors 0 (types 0x0), maxLate 0 maxPrep 62, ebfmin 0.00 max 0.00 
Peak sync jitter -3/41, peak Rx sync delay 187, resyncs 1/0, no timer interrupt scheduled, next step interrupt due in 4247606105 ticks, disabled 
VIN voltage: min 24.2, current 24.4, max 24.5 
MCU temperature: min 51.7C, current 58.0C, max 60.5C 
Driver 0: pos 12510580, 2056.0 steps/mm, standstill, SG min 0, read errors 0, write errors 0, ifcnt 25, reads 53750, writes 25, timeouts 0, DMA errors 0, CC errors 0 Last sensors broadcast 0x3fe0000000 found 9 225 ticks ago, 0 ordering errs, loop time 0 
CAN messages queued 192060, send timeouts 0, received 305253, lost 0, ignored 16, errs 0, boc 0, free buffers 22, min 22, error reg 0 dup 0, oos 0/0/0/0, bm 0, wbm 0, rxMotionDelay 299, adv 35157/37138 
Accelerometer: ADXL345, status: 00 I2C bus errors 0, naks 0, contentions 0, other errors 0 

@dc42 great, thanks!

@dc42 with CanClockIntervalMillis = 200 the number of high acknowledge delays depends on how many clashes with other transmissions we have, and since it seems to happen quite random, the comparison with CanClockIntervalMillis = 199 is difficult to do. I tried to analyse 10 minutes in idle state with different configurations of CanClockIntervalMillis and MaxTimeSyncDelay.
I think I will run some prints with CanClockIntervalMillis = 199 and MaxTimeSyncDelay = 500, to see if the resync issue still occurs. From the analysys below it seems to be the one with less number of zeros and less high delays.
Do you think this is something relevant to include in the next release?

freq199_thr300
Percentage of zeros: 0.50%
Percentage of values between 1 and 10: 96.60%
Percentage of values between 11 and 100: 1.13%
Percentage of values between 101 and 200: 1.10%
Percentage of values greater than 200: 0.67%

freq200_thr500
Percentage of zeros: 0.00%
Percentage of values between 1 and 10: 93.77%
Percentage of values between 11 and 100: 2.30%
Percentage of values between 101 and 200: 2.10%
Percentage of values greater than 200: 1.83%

freq199_thr500
Percentage of zeros: 0.00%
Percentage of values between 1 and 10: 96.63%
Percentage of values between 11 and 100: 1.30%
Percentage of values between 101 and 200: 1.10%
Percentage of values greater than 200: 0.97%

@dc42 thanks for the suggestion!
From M122, "peak Tx sync delay" is about 480 both when the machine is idle and when is printing. This might correspond to the 600us needed to send the CANFD packet, right?
I tried with CanClockIntervalMillis = 199 and below is the (blue) plot from the CAN analyser. The interesting thing now is that the samples between ~4 and 300 are way more than before.
Then I also increased the MaxTimeSyncDelay to 500, and the number of zeros is considerably reduced, which I think is the goal to avoid resyncs.
Could this value of MaxTimeSyncDelay lead to other issues?

Hi all,
I'm just reporting a step timing error I got with beta 1:

2024-11-29 20:17:27 [warn] Error: Movement halted because a step timing error occurred (code 3). Please reset the controller.
2024-11-29 20:17:27 [warn] Error: Existing: start=159625402 length=7371, new: start=159630740, overlap=2033 time now=159629503

now I'm doing some tests increasing StepTimer::MinSyncInterval from 2000 to 4000. I noticed it was already increased some years ago, it might be the same issue, I am also running on a SAME70.

Thanks @droftarts.
Update note: I got a resync also with MaxTimeSyncDelay = 375.

Hi all,

from 3.6.0-beta.1 I started to have some layer shifts in the first layers of a print. These shifts happen randomly (the same gcode might shift in one print and not in the consecutive one, or just in another position). Still, I didn't find a way to replicate exactly the issue. The shift happens because the expansion boards go out of sync for about 2 seconds and the movement commands are discarded (as intended behavior from 3.6.0-beta.1).
So far, it never shifted when the bed compensation was disabled or, when enabled, it never shifted above the tapering height (5mm).
To debug, I connected a can sniffer device and analyzed the TimeSync messages. The out-of-sync happens when the field lastTimeAcknowledgeDelay is zero for more than 10 consecutive times. From my understanding, the CanClockLoop doesn't update this variable if the previous message takes more than MaxTimeSyncDelay between the call of the send function and when the ISR actually processed the TX callback.

From the plots you can see that the behavior of lastTimeAcknowledgeDelay with FW 3.5.2 and 3.6.0-beta.1 is similar, so I might never have had a shift before just because in 3.5.2 the movement commands weren't discarded.
I increased MaxTimeSyncDelay from 300 (400 usec?) to 375 (500 usec?) to see what happens: these spikes are still present but the number of zeros is reduced, so hopefully tolerant enough to never reach 10 consecutive samples.

From the plot, it looks like the normal value for lastTimeAcknowledgeDelay is around 3-5 and a cloudy distribution around 250-300. So the original threshold of 300 would make sense.
I'm wondering why there are these spikes, after one spike to about 300 or more, the spike is then repeated every 5 samples but with a linear decreasing amplitude.
I tried also to disable the input shaping but the overall distribution is similar.

Do you have any explanation for this behavior? Other processes or interrupts interfering? Do you think it would make sense to increase the MaxTimeSyncDelay threshold or is it just a patch? Do you foresee any issues arising from doing this?

Thanks in advance.

Hi @chrishamm, I just noticed in the Git tree that the tag 3.6.0-beta.2 is pointing to a commit in the 3.5-dev branch (72d85117). Maybe the intended commit was 4cc23ddc in the 3.6-dev branch? Both have "Tidied up M307 processing" as message.