Code 2 halts reported using 3.6.0-beta.2

[dc42]

We have reports from an OEM that RRF occasionally halts with Code 2 movement errors.

[dc42]

In 3.6.0-beta.3 additional debugging information is output when movement errors occur. This should help us to track down the cause, in particular whether is it just small errors caused by FP rounding that can be corrected or ignored.

[dc42]

Further debug information added to 3.6.0-beta.3+2

[dc42]

Report from a user, see https://forum.duet3d.com/topic/37388/3-6-0-beta-3-1-halted-mid-print:

Error: Code 2 move error: info=-0.00195, seg: s=2467229762 t=11130 d=-29.00 u=-3.1414e-3 a=9.6290e-8 f=09

M122 report:

2/3/2025, 10:48:21 AM: M32 "0:/gcodes/FloatBowlSpacer.gcode": File 0:/gcodes/FloatBowlSpacer.gcode selected for printing
2/3/2025, 10:58:54 AM: : Starting bed calibration
2/3/2025, 10:59:15 AM: : Calibrated 9 factors using 10 points, (mean, deviation) before (0.136, 0.054) after (0.000, 0.001)
2/3/2025, 10:59:15 AM: : Auto calibration successful, deviation 5.562e-4mm
2/3/2025, 10:59:45 AM: : Error: Code 2 move error: info=-0.00195, seg: s=2467229762 t=11130 d=-29.00 u=-3.1414e-3 a=9.6290e-8 f=09
2/3/2025, 11:12:03 AM: M122: === Diagnostics ===
RepRapFirmware for Duet 2 WiFi/Ethernet version 3.6.0-beta.3+3 (2025-02-03 10:56:36) running on Duet Ethernet 1.02 or later
Board ID: 08DDM-9FAM2-LW4SD-6J9F4-3S06R-9LXVW
Used output buffers: 1 of 26 (19 max)
=== RTOS ===
Static ram: 23776
Dynamic ram: 61632 of which 68 recycled
Never used RAM 33752, free system stack 76 words
Tasks: NETWORK(1,ready,26.7%,217) HEAT(3,nWait 5,0.1%,328) Move(4,invalid,0.0%,268) MAIN(1,running,73.2%,446) IDLE(0,ready,0.0%,29), total 100.0%
Owned mutexes:
=== Platform ===
Last reset 02:12:30 ago, cause: software
Last software reset at 2025-01-24 18:07, reason: User, Gcodes spinning, available RAM 34752, slot 2
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x00
Aux0 errors 0,0,0
MCU temperature: min 35.6, current 42.4, max 43.2
Supply voltage: min 11.9, current 12.2, max 12.5, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 99/4, heap memory allocated/used/recyclable 2048/240/192, gc cycles 0
Events: 0 queued, 0 completed
Date/time: 2025-02-03 11:12:00
Slowest loop: 223.59ms; fastest: 0.19ms
I2C nak errors 0, send timeouts 0, receive timeouts 0, finishTimeouts 0, resets 0
=== Storage ===
Free file entries: 9
SD card 0 detected, interface speed: 20.0MBytes/sec
SD card longest read time 12.8ms, write time 0.0ms, max retries 0
=== Move ===
Segments created 32, maxWait 7156769ms, bed comp in use: mesh, height map offset 0.000, hiccups added 0/0 (0.00ms), max steps late 0, ebfmin 0.00, ebfmax 0.00
Pos req/act/dcf: 20106.00/20169/-1.00 19626.00/19643/0.00 20292.00/20213/1.00
no step interrupt scheduled
Driver 0: standstill, SG min 0
Driver 1: standstill, SG min 0
Driver 2: standstill, SG min 0
Driver 3: standstill, SG min 0
Driver 4: standstill, SG min n/a
Driver 5:
Driver 6:
Driver 7:
Driver 8:
Driver 9:
Driver 10:
Driver 11:
=== DDARing 0 ===
Scheduled moves 2196, completed 2157, LaErrors 0, Underruns [0, 0, 0]
Segments left 1
Code queue is empty
=== Heat ===
Bed heaters 0 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
=== GCodes ===
Movement locks held by null
HTTP is idle in state(s) 0
Telnet is idle in state(s) 0
File is idle in state(s) 3
USB is idle in state(s) 0
Aux is idle in state(s) 0
Trigger is idle in state(s) 0
Queue is idle in state(s) 0
LCD is idle in state(s) 0
Daemon is idle in state(s) 0
Autopause is idle in state(s) 0
=== Network ===
Slowest loop: 19.89ms; fastest: 0.02ms
Responder states: HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 2 of 8
Interface state active, link 100Mbps full duplex
Socket states: 7 2 2 2 0 2

Edited to add a second attempt to print:
Error: Code 2 move error: info=-0.00195, seg: s=2255125801 t=11176 d=-25.00 u=-2.6995e-3 a=8.2784e-8 f=08

[dc42]

The above two reports indicate that the movement was halted because the first step in the segment was calculated to occur a tiny amount (0.00195 of a step clock) before the segment was intended to start. I have established that this can happen when the distance carried forward to the segment is almost a whole step, because of floating point rounding error. I have changed the code in RRF and D3E to allow the calculated step time to be up to 2 clocks before the start of the move, and in this case set the step time to the move start time. It is likely that other reported Code 2 halts (for which we don't have this amount of information) have the same cause.