3.6.0-beta.1 Breaking Homing Sequence

gloomyandy

@Charlie If you run M122 and post the output it may provide information that will allow Andy to see if the mcu reset or not (and why).

Charlie

@gloomyandy @AndyE3D I was under the (potentially incorrect) assumption that if the MCU reset, it would not be reflected in the M122 (since it restarted and reset). With that being said, here's the response to M111:

M111 P4 S1
Debugging enabled for modules: Move(4 - 0xffffffff)
Debugging disabled for modules: Platform(0) Network(1) Webserver(2) Gcodes(3) Heat(5) Kinematics(6) InputShaping(7) unused(8) PrintMonitor(9) Storage(10) PortControl(11) DuetExpansion(12) FilamentSensors(13) WiFi(14) Display(15) SbcInterface(16) CAN(17) Expansion(18)

Here's the M122 after sending M111 P4 S1, but before the move command:

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.6.0-beta.1 (2024-09-24 10:07:51) running on Duet 3 MB6HC v1.01 (SBC mode)
Board ID: 08DJM-956L2-G43S8-6J9DG-3S46T-KV2LF
Used output buffers: 2 of 40 (23 max)
=== RTOS ===
Static ram: 136444
Dynamic ram: 96212 of which 4652 recycled
Never used RAM 90476, free system stack 156 words
Tasks: SBC(2,nWait 7,0.9%,795) HEAT(3,nWait 6,0.0%,325) Move(4,nWait 6,0.0%,211) TMC(5,nWait 6,11.3%,283) CanReceiv(6,nWait 1,0.0%,794) CanSender(5,nWait 7,0.0%,334) CanClock(7,delaying,0.0%,348) MAIN(2,running,87.8%,101) IDLE(0,ready,0.0%,29) USBD(3,blocked,0.0%,134), total 100.0%
Owned mutexes: USB(MAIN)
=== Platform ===
Last reset 00:13:55 ago, cause: power up
Last software reset at 2024-11-06 20:54, reason: AssertionFailed, Gcodes spinning, available RAM 90560, slot 1
Software reset code 0x0123 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0x00000000 SP 0x20415a34 Task MAIN Freestk 2233 ok
Stack: 00000001 00000000 0049941d 20426970 00000000 204207e8 20426970 ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff
Error status: 0x00
Aux0 errors 0,0,0
MCU temperature: min 51.7, current 52.7, max 52.9
Supply voltage: min 26.4, current 26.5, max 26.5, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.0, current 12.1, max 12.1, under voltage events: 0
Heap OK, handles allocated/used 99/4, heap memory allocated/used/recyclable 2048/88/8, gc cycles 0
Events: 0 queued, 0 completed
Date/time: 2024-11-07 12:46:12
Slowest loop: 2.24ms; fastest: 0.07ms
USB interrupts 161
=== Storage ===
Free file entries: 20
SD card 0 not detected, interface speed: 37.5MBytes/sec
SD card longest read time 0.0ms, write time 0.0ms, max retries 0
=== Move ===
Segments created 38, maxWait 0ms, bed comp in use: none, height map offset 0.000, hiccups added 0 (0.00/0.00ms), max steps late 0, ebfmin 0.00, ebfmax 0.00
Pos req/act/dcf: 26080.00/26080/0.00 1920.00/1920/0.00 2036.00/2036/0.00
no step interrupt scheduled
Driver 0: standstill, SG min n/a, mspos 8, reads 11116, writes 0 timeouts 0
Driver 1: standstill, SG min n/a, mspos 8, reads 11116, writes 0 timeouts 0
Driver 2: standstill, SG min n/a, mspos 520, reads 11117, writes 0 timeouts 0
Driver 3: standstill, SG min n/a, mspos 520, reads 11116, writes 0 timeouts 0
Driver 4: standstill, SG min n/a, mspos 520, reads 11116, writes 0 timeouts 0
Driver 5: standstill, SG min n/a, mspos 520, reads 11116, writes 0 timeouts 0
Phase step loop runtime (us): min=0, max=25, frequency (Hz): min=6410, max=10563
=== DDARing 0 ===
Scheduled moves 12, completed 12, LaErrors 0, Underruns [0, 0, 0]
=== DDARing 1 ===
Scheduled moves 0, completed 0, LaErrors 0, Underruns [0, 0, 0]
=== Heat ===
Bed heaters 0 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters -1 -1 -1 -1 -1 -1 -1 -1, ordering erHeater 1 is on, I-accum = 0.0
=== GCodes ===
Movement locks held by null, null
HTTP* is idle in state(s) 0
Telnet is idle in state(s) 0
File is idle in state(s) 0
USB is ready with "M122" 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
SBC is idle in state(s) 0
Daemon is idle in state(s) 0
Aux2 is idle in state(s) 0
Autopause is idle in state(s) 0
File2 is idle in state(s) 0
Queue2 is idle in state(s) 0
Q0 segments left 0, axes/extruders owned 0x80000007
Code queue 0 is empty
Q1 segments left 0, axes/extruders owned 0x0000000
Code queue 1 is empty
=== Filament sensors ===
check 0 clear 0
Extruder 0: no data received, errs: frame 0 parity 0 ovrun 0 pol 0 ovdue 0
=== CAN ===
Messages queued 1329, received 3024, lost 0, ignored 0, errs 0, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 6, free buffers 50 (min 50), ts 738/738/0
Tx timeouts 0,0,0,0,0,0
=== SBC interface ===
Transfer state: 5, failed transfers: 0, checksum errors: 0
RX/TX seq numbers: 31603/31603
SPI underruns 0, overruns 0
State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x27f90
Buffer RX/TX: 0/0-0, open files: 0
ok

The move command:

G91
G1 H2 X10 F3000

And the M122 output after:

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.6.0-beta.1 (2024-09-24 10:07:51) running on Duet 3 MB6HC v1.01 (SBC mode)
Board ID: 08DJM-956L2-G43S8-6J9DG-3S46T-KV2LF
Used output buffers: 2 of 40 (23 max)
=== RTOS ===
Static ram: 136444
Dynamic ram: 96104 of which 4652 recycled
Never used RAM 91496, free system stack 180 words
Tasks: SBC(2,nWait 7,0.8%,791) HEAT(3,nWait 6,0.0%,335) Move(4,nWait 6,0.0%,321) TMC(5,nWait 6,11.1%,379) CanReceiv(6,nWait 1,0.0%,794) CanSender(5,nWait 7,0.0%,334) CanClock(7,delaying,0.0%,350) MAIN(2,running,88.0%,101) IDLE(0,ready,0.0%,29) USBD(3,blocked,0.0%,134), total 100.0%
Owned mutexes: USB(MAIN)
=== Platform ===
Last reset 00:00:36 ago, cause: software
Last software reset at 2024-11-07 12:49, reason: HeatTaskStuck, Gcodes spinning, available RAM 90476, slot 2
Software reset code 0x4143 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0042780f BFAR 0x00000000 SP 0x2041d3d0 Task Move Freestk 958 ok
Stack: 00000000 2041cd2c 10000000 e000e000 2041d4b8 0049a1d5 0049a9cc 61000000 204210a0 20432728 20432728 00000000 204326a0 00453cf9 001025cc 00456df5 20432728 204326a8 a5a5a5a5 a5a5a500 42576179 a5a5a5a5 a5a5a5a5 a5a5a5a5 a5a5a5a5 a5a5a5a5 a5a5a5a5
Error status: 0x00
Aux0 errors 0,0,0
MCU temperature: min 53.7, current 53.9, max 54.1
Supply voltage: min 26.4, current 26.5, max 26.5, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.1, current 12.1, max 12.1, under voltage events: 0
Heap OK, handles allocated/used 99/4, heap memory allocated/used/recyclable 2048/80/0, gc cycles 0
Events: 0 queued, 0 completed
Date/time: 2024-11-07 12:50:35
Slowest loop: 2.11ms; fastest: 0.08ms
USB interrupts 185
=== Storage ===
Free file entries: 20
SD card 0 not detected, interface speed: 37.5MBytes/sec
SD card longest read time 0.0ms, write time 0.0ms, max retries 0
=== Move ===
Segments created 0, maxWait 0ms, bed comp in use: none, height map offset 0.000, hiccups added 0 (0.00/0.00ms), max steps late 0, ebfmin 0.00, ebfmax 0.00
Pos req/act/dcf: 0.00/0/0.00 0.00/0/0.00 0.00/0/0.00
next step interrupt due in 11 ticks, disabled
Driver 0: standstill, SG min n/a, mspos 8, reads 7814, writes 0 timeouts 0
Driver 1: standstill, SG min n/a, mspos 8, reads 7814, writes 0 timeouts 0
Driver 2: standstill, SG min n/a, mspos 520, reads 7814, writes 0 timeouts 0
Driver 3: standstill, SG min n/a, mspos 520, reads 7814, writes 0 timeouts 0
Driver 4: standstill, SG min n/a, mspos 520, reads 7813, writes 0 timeouts 0
Driver 5: standstill, SG min n/a, mspos 520, reads 7814, writes 0 timeouts 0
Phase step loop runtime (us): min=0, max=26, frequency (Hz): min=6465, max=10416
=== DDARing 0 ===
Scheduled moves 0, completed 0, LaErrors 0, Underruns [0, 0, 0]
=== DDARing 1 ===
Scheduled moves 0, completed 0, LaErrors 0, Underruns [0, 0, 0]
=== Heat ===
Bed heaters 0 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters -1 -1 -1 -1 -1 -1 -1 -1, ordering erHeater 1 is on, I-accum = 0.0
=== GCodes ===
Movement locks held by null, null
HTTP is idle in state(s) 0
Telnet is idle in state(s) 0
File is idle in state(s) 0
USB is ready with "M122" 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
SBC is idle in state(s) 0
Daemon is idle in state(s) 0
Aux2 is idle in state(s) 0
Autopause is idle in state(s) 0
File2 is idle in state(s) 0
Queue2 is idle in state(s) 0
Q0 segments left 0, axes/extruders owned 0x80000003
Code queue 0 is empty
Q1 segments left 0, axes/extruders owned 0x0000000
Code queue 1 is empty
=== Filament sensors ===
check 0 clear 0
Extruder 0: no data received, errs: frame 0 parity 0 ovrun 0 pol 0 ovdue 0
=== CAN ===
Messages queued 227, received 518, lost 0, ignored 0, errs 0, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 6, free buffers 50 (min 50), ts 126/126/0
Tx timeouts 0,0,0,0,0,0
=== SBC interface ===
Transfer state: 5, failed transfers: 3, checksum errors: 6
RX/TX seq numbers: 41734/1414
SPI underruns 4, overruns 4
State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x27f90
Buffer RX/TX: 0/0-0, open files: 0
ok

gloomyandy

@Charlie when the mcu resets RRF is able to capture (and store) some information about what was going on. Rather interestingly you seem to have had two on the face of it different resets the first was this:

Last software reset at 2024-11-06 20:54, reason: AssertionFailed, Gcodes spinning, available RAM 90560, slot 1
Software reset code 0x0123 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0x00000000 SP 0x20415a34 Task MAIN Freestk 2233 ok
Stack: 00000001 00000000 0049941d 20426970 00000000 204207e8 20426970 ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff ffffffff

the second this:

Last software reset at 2024-11-07 12:49, reason: HeatTaskStuck, Gcodes spinning, available RAM 90476, slot 2
Software reset code 0x4143 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0042780f BFAR 0x00000000 SP 0x2041d3d0 Task Move Freestk 958 ok
Stack: 00000000 2041cd2c 10000000 e000e000 2041d4b8 0049a1d5 0049a9cc 61000000 204210a0 20432728 20432728 00000000 204326a0 00453cf9 001025cc 00456df5 20432728 204326a8 a5a5a5a5 a5a5a500 42576179 a5a5a5a5 a5a5a5a5 a5a5a5a5 a5a5a5a5 a5a5a5a5 a5a5a5a5

It sounds like the second reset may be the one caused by the phase stepping move with debug enabled, do you remember having any other sort of reset that may have generated the first case (looks like it was last night just before 9pm)?

Either way hopefully @AndyE3D will be able to work out what may be happening here.

Charlie

@gloomyandy Thats really good to know. I appreciate that info!

Regarding the first crash, it could've either been the first attempt at capturing the debug data, me pulling the mains power in an attempt to "reset" the board, or something to do with me trying to connect to the board over YAT.

Charlie

Also, I just want to note that for the Gcode Dictionary, for M970, .1, &.2, the "Example" code shows M917 instead of M970.

Phaedrux

@Charlie said in 3.6.0-beta.1 Breaking Homing Sequence:

Also, I just want to note that for the Gcode Dictionary, for M970, .1, &.2, the "Example" code shows M917 instead of M970.

Something for @droftarts to take a look at.

droftarts

@Charlie said in 3.6.0-beta.1 Breaking Homing Sequence:

Also, I just want to note that for the Gcode Dictionary, for M970, .1, &.2, the "Example" code shows M917 instead of M970.

Thanks, fixed!

Ian

Charlie

@droftarts Thank you!