[3.4.5] CAN connection drops mid-print (OoM error)

Diamondback

Hello,

I have a weird CAN issue now: It appears the connection between my 6HC and my Mini5+ drops mid print.
I have 2 heaters, 4 extruder motors and the bed heater connected to the Mini and when I print something, it works for a while and then suddenly the bed temp reports 2000°C, the heating of the bed stops and the extruder stops working.

Funnily enough, I can still execute an M122 for the Mini. Here's the results:
Main board

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.4.5 (2022-11-30 19:35:23) running on Duet 3 MB6HC v1.02 or later (standalone mode)
Board ID: 08DJM-9P63L-DJ3T0-6J1F4-3S06S-9A1V9
Used output buffers: 3 of 40 (31 max)
=== RTOS ===
Static ram: 152760
Dynamic ram: 105472 of which 0 recycled
Never used RAM 88552, free system stack 132 words
Tasks: NETWORK(ready,31.8%,220) ETHERNET(notifyWait,0.1%,401) ACCEL(notifyWait,0.0%,348) HEAT(notifyWait,0.0%,322) Move(notifyWait,1.8%,245) CanReceiv(notifyWait,0.0%,774) CanSender(notifyWait,0.0%,328) CanClock(delaying,0.0%,339) TMC(notifyWait,8.7%,57) MAIN(running,57.5%,925) IDLE(ready,0.0%,30), total 100.0%
Owned mutexes:
=== Platform ===
Last reset 00:47:53 ago, cause: software
Last software reset at 2023-01-01 13:11, reason: User, GCodes spinning, available RAM 87832, slot 1
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0x00000000 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x00
Step timer max interval 553
MCU temperature: min 40.4, current 44.0, max 44.1
Supply voltage: min 23.6, current 23.7, max 23.9, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.2, current 12.3, max 12.5, under voltage events: 0
Heap OK, handles allocated/used 99/40, heap memory allocated/used/recyclable 2048/828/168, gc cycles 6
Events: 0 queued, 0 completed
Driver 0: ok, SG min 0, mspos 646, reads 50235, writes 21 timeouts 0
Driver 1: ok, SG min 0, mspos 438, reads 50235, writes 21 timeouts 0
Driver 2: ok, SG min 0, mspos 775, reads 50235, writes 21 timeouts 0
Driver 3: ok, SG min 0, mspos 579, reads 50235, writes 21 timeouts 0
Driver 4: standstill, SG min 0, mspos 264, reads 50227, writes 29 timeouts 0
Driver 5: ok, SG min 0, mspos 870, reads 50236, writes 21 timeouts 0
Date/time: 2023-01-01 13:59:15
Slowest loop: 88.39ms; fastest: 0.04ms
=== Storage ===
Free file entries: 9
SD card 0 detected, interface speed: 25.0MBytes/sec
SD card longest read time 2.9ms, write time 14.0ms, max retries 0
=== Move ===
DMs created 125, segments created 43, maxWait 389935ms, bed compensation in use: mesh, comp offset 0.000
=== MainDDARing ===
Scheduled moves 72401, completed 72372, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 1], CDDA state 3
=== AuxDDARing ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== Heat ===
Bed heaters 0 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
Heater 2 is on, I-accum = 0.3
=== GCodes ===
Segments left: 1
Movement lock held by null
HTTP is idle in state(s) 0
Telnet is idle in state(s) 0
File is doing "G1 X-2.88 Y-15.689 E.2533" in state(s) 0
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
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
Code queue is empty
=== CAN ===
Messages queued 94604, received 46198, lost 0, boc 0
Longest wait 1ms for reply type 6018, peak Tx sync delay 59128, free buffers 50 (min 36), ts 14367/14363/0
Tx timeouts 8,0,3,0,0,1 last cancelled message type 51 dest 100
=== Network ===
Slowest loop: 637.81ms; fastest: 0.03ms
Responder states: HTTP(4) HTTP(0) HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0) Telnet(0)
HTTP sessions: 2 of 8
= Ethernet =
State: active
Error counts: 0 0 0 0 0 0
Socket states: 5 3 2 2 2 0 0 0
= WiFi =
Network state is disabled
WiFi module is disabled
Failed messages: pending 2779096485, notready 2779096485, noresp 2779096485
Socket states: 0 0 0 0 0 0 0 0
=== Multicast handler ===
Responder is inactive, messages received 0, responses 0

Slave board

M122 B100
Diagnostics for board 100:
RepRapFirmware for Duet 3 Mini 5+ version 3.4.5 (2022-11-30 19:41:16) running on Duet 3 Mini5plus Ethernet
Last reset 00:17:01 ago, cause: software
Driver 0: position 0, 80.0 steps/mm,, SG min 0, read errors 0, write errors 1, ifcnt 85, reads 27271, writes 9, timeouts 0, DMA errors 0, CC errors 0
Driver 1: position 0, 80.0 steps/mm,, SG min 0, read errors 0, write errors 1, ifcnt 95, reads 27271, writes 9, timeouts 0, DMA errors 0, CC errors 0
Driver 2: position 0, 4000.0 steps/mm,, SG min 0, read errors 0, write errors 1, ifcnt 86, reads 27271, writes 9, timeouts 0, DMA errors 0, CC errors 0
Driver 3: position 0, 80.0 steps/mm,, SG min 0, read errors 0, write errors 1, ifcnt 92, reads 27271, writes 9, timeouts 0, DMA errors 0, CC errors 0
Driver 4: position 0, 80.0 steps/mm,, SG min 0, read errors 0, write errors 1, ifcnt 73, reads 27272, writes 9, timeouts 0, DMA errors 0, CC errors 0
Driver 5: position 0, 80.0 steps/mm,, SG min 0, read errors 0, write errors 1, ifcnt 73, reads 27272, writes 9, timeouts 0, DMA errors 0, CC errors 0
Driver 6: position 0, 80.0 steps/mm,, SG min 0, read errors 0, write errors 1, ifcnt 73, reads 27272, writes 9, timeouts 0, DMA errors 0, CC errors 0
VIN: 23.6V, MCU temperature: min 35.1C, current 35.6C, max 35.8C
Peak sync jitter -395/392, peak Rx sync delay 201, resyncs 0/0, next step interrupt due in 650535385 ticks, enabled

Nothing else relevant in the console, no heater fault being triggered either despite the bed reporting 2000°C (sounds like a safety issue?)

Yesterday a multi-hour print worked fine, today it failed two times within half an hour of printing or so (at different times during the same print)

After a reset the connection works correctly again.

Diamondback

Update: After the print "finished" (I left it running with no extruder actually turning...), the post print script tries to turn off the heaters and fans and stuff and this comes back: (these are two part cooling fans on the slave board and the bed heater)

Error: M106: Board 100 doesn't have fan 5
Error: M106: Board 100 doesn't have fan 7
Error: Board 100 does not have heater 0

Diamondback

Another update (and this time interesting stuff ) @dc42
Here's a full M122 from the slave board (gathered by connecting to the slave via its own ethernet)

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.4.5 (2022-11-30 19:41:16) running on Duet 3 Mini5plus Ethernet (expansion mode)
Board ID: H1590-0296U-D65J0-40KMQ-JP03Z-RGPPB
Used output buffers: 1 of 40 (18 max)
=== RTOS ===
Static ram: 103652
Dynamic ram: 103480 of which 0 recycled
Never used RAM 33020, free system stack 159 words
Tasks: NETWORK(ready,25.7%,257) ETHERNET(notifyWait,0.0%,560) HEAT(notifyWait,0.0%,358) Move(notifyWait,0.0%,349) CanReceiv(notifyWait,0.1%,632) CanSender(notifyWait,0.0%,336) CanClock(invalid,0.0%,351) TMC(notifyWait,1.2%,72) MAIN(running,72.1%,719) IDLE(ready,0.0%,30) AIN(delaying,0.8%,263), total 100.0%
Owned mutexes:
=== Platform ===
Last reset 00:39:17 ago, cause: software
Last software reset at 2023-01-01 13:42, reason: OutOfMemory, GCodes spinning, available RAM 8, slot 0
Software reset code 0x41c3 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00000000 BFAR 0xe000ed38 SP 0x200180e8 Task CanR Freestk 775 ok
Stack: 20032e14 0001d015 00000000 20032e28 2003f630 00045659 20018120 0003ea59 00000001 2003f630 200181dc 0003f0a9 2003f250 00000002 3edc30f6 3edc30f8 44dd8000 00000000 45134000 3139b9b3 3139b081 200181dc 00000000 200181db a5a5a5a5 0001633b a5a5a5a5
Error status: 0x00
MCU revision 3, ADC conversions started 2357795, completed 2357793, timed out 0, errs 0
Step timer max interval 955
MCU temperature: min 34.9, current 35.1, max 35.8
Supply voltage: min 23.5, current 23.7, max 23.8, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 0/0, heap memory allocated/used/recyclable 0/0/0, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, read errors 0, write errors 0, ifcnt 85, reads 7473, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 1: standstill, SG min 0, read errors 0, write errors 0, ifcnt 96, reads 7472, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 2: standstill, SG min 0, read errors 0, write errors 0, ifcnt 86, reads 7472, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 3: standstill, SG min 0, read errors 0, write errors 0, ifcnt 92, reads 7472, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 4: standstill, SG min 0, read errors 0, write errors 0, ifcnt 73, reads 7472, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 5: standstill, SG min 0, read errors 0, write errors 0, ifcnt 73, reads 7471, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 6: standstill, SG min 0, read errors 0, write errors 0, ifcnt 73, reads 7471, writes 0, timeouts 0, DMA errors 0, CC errors 0
Date/time: 2023-01-01 14:22:07
Cache data hit count 4098310382
Slowest loop: 7.29ms; fastest: 0.13ms
=== Storage ===
Free file entries: 10
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 4.1ms, write time 0.0ms, max retries 0
=== Move ===
DMs created 83, segments created 65, maxWait 0ms, bed compensation in use: none, comp offset 0.000
=== MainDDARing ===
Scheduled moves 40, completed 40, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 1], CDDA state -1
=== AuxDDARing ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== Heat ===
Bed heaters -1 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
=== GCodes ===
Segments left: 0
Movement lock held by null
HTTP is idle in state(s) 0
Telnet is idle in state(s) 0
File is idle in state(s) 0
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
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
Code queue is empty
=== CAN ===
Messages queued 18923, received 76074, lost 0, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 0, free buffers 18 (min 18), ts 1/0/0
Tx timeouts 0,0,0,0,0,0
=== Network ===
Slowest loop: 6.62ms; fastest: 0.03ms
Responder states: HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 1 of 8
= Ethernet =
State: active
Error counts: 0 0 0 0 0 0
Socket states: 5 2 2 2 2 0 0 0

Note in paticular this...

Last software reset at 2023-01-01 13:42, reason: OutOfMemory, GCodes spinning, available RAM 8, slot 0

I do wonder if the M122 Bxxx needs to be extended to send over the reset reason as well to make debugging such issues easier?

Diamondback

I tried again with network disabled on the slave board (since that working seems to be a happy accident rather than a feature), but same thing happens with it disabled.

Now trying 3.5b1 build with fixed G32...

dc42

@Diamondback thanks for your reports, in particular the direct M122 showing the out of memory error.

Please can you run another print (without filament if you like) and send M122 to the slave board direct from Ethernet or USB periodically. I am interested to see whether the reported Never Used Ram gradually decreases, which would suggest a memory leak. If it does decrease gradually, then please try to establish whether it decreases by the same fixed amount (or a multiple of some amount) each time.

Diamondback

Update: Same thing happens with 3.5b1, gonna try 3.4.5 again and record the data you asked for.

Diamondback

@dc42 It does indeed go down over time, in increments of 24 bytes at once it seems. However, I can't see any linear relation to time. Sometimes it takes well above 30s to decrease again by 24 and then I can see a few 24 byte decreases over the span of just a few seconds.

Diamondback

It appears that "free system stack" also decreases somewhat over time, much much slower than the never used RAM though. It is now stuck at 120 words since some time.

Btw, here's what I have connected to the slave Mini 5: (I am printing with T1 here, which is fully controlled from the 6HC master)

4x Extruder, one of them being used in the actual print
Bed heater/temp, used in the print
Heater/temp T2
Heater/temp T3
Hotend- & partcooling fans T2
Hotend- & partcooling fans T3
"Tool-at-dock"-switch T2
"Tool-at-dock"-switch T3

Diamondback

Here's a few example M122 outputs from before and during the print:

Fresh after boot:

1.1.2023, 16:11:03	M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.4.5 (2022-11-30 19:41:16) running on Duet 3 Mini5plus Ethernet (expansion mode)
Board ID: H1590-0296U-D65J0-40KMQ-JP03Z-RGPPB
Used output buffers: 1 of 40 (18 max)
=== RTOS ===
Static ram: 103652
Dynamic ram: 104764 of which 0 recycled
Never used RAM 33296, free system stack 200 words
Tasks: NETWORK(ready,27.1%,254) ETHERNET(notifyWait,0.2%,560) HEAT(notifyWait,0.0%,358) Move(notifyWait,0.0%,363) CanReceiv(notifyWait,0.0%,654) CanSender(notifyWait,0.0%,336) CanClock(invalid,0.0%,351) TMC(notifyWait,1.2%,116) MAIN(running,70.1%,719) IDLE(ready,0.6%,30) AIN(delaying,0.8%,263), total 100.0%
Owned mutexes:
=== Platform ===
Last reset 00:00:20 ago, cause: power up
Last software reset at 2023-01-01 16:10, reason: User, GCodes spinning, available RAM 34580, slot 1
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00000000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x00
MCU revision 3, ADC conversions started 21306, completed 21305, timed out 0, errs 0
Step timer max interval 752
MCU temperature: min 32.7, current 35.1, max 35.4
Supply voltage: min 23.7, current 23.7, max 23.8, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 0/0, heap memory allocated/used/recyclable 0/0/0, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, read errors 0, write errors 0, ifcnt 11, reads 1838, writes 11, timeouts 0, DMA errors 0, CC errors 0
Driver 1: standstill, SG min 0, read errors 0, write errors 0, ifcnt 12, reads 1837, writes 12, timeouts 0, DMA errors 0, CC errors 0
Driver 2: standstill, SG min 0, read errors 0, write errors 0, ifcnt 12, reads 1836, writes 12, timeouts 0, DMA errors 0, CC errors 0
Driver 3: standstill, SG min 0, read errors 0, write errors 0, ifcnt 11, reads 1837, writes 11, timeouts 0, DMA errors 0, CC errors 0
Driver 4: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 1840, writes 9, timeouts 0, DMA errors 0, CC errors 0
Driver 5: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 1840, writes 9, timeouts 0, DMA errors 0, CC errors 0
Driver 6: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 1839, writes 9, timeouts 0, DMA errors 0, CC errors 0
Date/time: 2023-01-01 16:11:03
Cache data hit count 35445150
Slowest loop: 2.14ms; fastest: 0.13ms
=== Storage ===
Free file entries: 10
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 1.9ms, write time 0.0ms, max retries 0
=== Move ===
DMs created 83, segments created 0, maxWait 0ms, bed compensation in use: none, comp offset 0.000
=== MainDDARing ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== AuxDDARing ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== Heat ===
Bed heaters -1 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
=== GCodes ===
Segments left: 0
Movement lock held by null
HTTP is idle in state(s) 0
Telnet is idle in state(s) 0
File is idle in state(s) 0
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
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
Code queue is empty
=== CAN ===
Messages queued 420, received 212, lost 0, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 222, free buffers 18 (min 18), ts 2/1/0
Tx timeouts 0,0,0,0,0,0
=== Network ===
Slowest loop: 5.85ms; fastest: 0.03ms
Responder states: HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 1 of 8
= Ethernet =
State: active
Error counts: 0 0 0 0 0 0
Socket states: 5 2 2 2 2 0 0 0

Some time into the print:

1.1.2023, 16:30:36	M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.4.5 (2022-11-30 19:41:16) running on Duet 3 Mini5plus Ethernet (expansion mode)
Board ID: H1590-0296U-D65J0-40KMQ-JP03Z-RGPPB
Used output buffers: 1 of 40 (31 max)
=== RTOS ===
Static ram: 103652
Dynamic ram: 104764 of which 0 recycled
Never used RAM 31256, free system stack 140 words
Tasks: NETWORK(ready,28.0%,254) ETHERNET(notifyWait,0.3%,560) HEAT(notifyWait,0.0%,342) Move(notifyWait,0.0%,338) CanReceiv(notifyWait,0.1%,650) CanSender(notifyWait,0.0%,336) CanClock(invalid,0.0%,351) TMC(notifyWait,1.2%,72) MAIN(running,69.5%,637) IDLE(ready,0.0%,30) AIN(delaying,0.8%,263), total 100.0%
Owned mutexes:
=== Platform ===
Last reset 00:19:53 ago, cause: power up
Last software reset at 2023-01-01 16:10, reason: User, GCodes spinning, available RAM 34580, slot 1
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00000000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x00
MCU revision 3, ADC conversions started 1194262, completed 1194261, timed out 0, errs 0
Step timer max interval 736
MCU temperature: min 37.1, current 37.1, max 37.1
Supply voltage: min 23.5, current 23.6, max 23.6, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 0/0, heap memory allocated/used/recyclable 0/0/0, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, read errors 0, write errors 0, ifcnt 11, reads 102, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 1: ok, SG min 0, read errors 0, write errors 0, ifcnt 14, reads 103, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 2: standstill, SG min 0, read errors 0, write errors 0, ifcnt 12, reads 103, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 3: standstill, SG min 0, read errors 0, write errors 0, ifcnt 11, reads 103, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 4: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 103, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 5: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 103, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 6: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 103, writes 0, timeouts 0, DMA errors 0, CC errors 0
Date/time: 2023-01-01 16:30:43
Cache data hit count 2028212819
Slowest loop: 1.15ms; fastest: 0.13ms
=== Storage ===
Free file entries: 10
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 0.0ms, write time 0.0ms, max retries 0
=== Move ===
DMs created 83, segments created 85, maxWait 0ms, bed compensation in use: none, comp offset 0.000
=== MainDDARing ===
Scheduled moves 5124, completed 5123, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 1], CDDA state 3
=== AuxDDARing ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== Heat ===
Bed heaters -1 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
=== GCodes ===
Segments left: 0
Movement lock held by null
HTTP is idle in state(s) 0
Telnet is idle in state(s) 0
File is idle in state(s) 0
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
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
Code queue is empty
=== CAN ===
Messages queued 20, received 39, lost 0, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 0, free buffers 18 (min 18), ts 0/0/0
Tx timeouts 0,0,0,0,0,0
=== Network ===
Slowest loop: 5.47ms; fastest: 0.04ms
Responder states: HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 1 of 8
= Ethernet =
State: active
Error counts: 0 0 0 0 0 0
Socket states: 5 2 2 2 2 0 0 0

A 24 byte drop:

1.1.2023, 16:43:19	M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.4.5 (2022-11-30 19:41:16) running on Duet 3 Mini5plus Ethernet (expansion mode)
Board ID: H1590-0296U-D65J0-40KMQ-JP03Z-RGPPB
Used output buffers: 1 of 40 (32 max)
=== RTOS ===
Static ram: 103652
Dynamic ram: 104764 of which 0 recycled
Never used RAM 3008, free system stack 120 words
Tasks: NETWORK(ready,27.5%,254) ETHERNET(notifyWait,0.3%,560) HEAT(notifyWait,0.1%,342) Move(notifyWait,0.0%,338) CanReceiv(notifyWait,0.0%,638) CanSender(notifyWait,0.0%,336) CanClock(invalid,0.0%,351) TMC(notifyWait,1.2%,72) MAIN(running,70.0%,637) IDLE(ready,0.0%,30) AIN(delaying,0.8%,263), total 100.0%
Owned mutexes:
=== Platform ===
Last reset 00:32:36 ago, cause: power up
Last software reset at 2023-01-01 16:10, reason: User, GCodes spinning, available RAM 34580, slot 1
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00000000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x00
MCU revision 3, ADC conversions started 1957490, completed 1957490, timed out 0, errs 0
Step timer max interval 647
MCU temperature: min 37.8, current 38.1, max 38.2
Supply voltage: min 23.6, current 23.7, max 23.7, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 0/0, heap memory allocated/used/recyclable 0/0/0, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, read errors 0, write errors 0, ifcnt 11, reads 107, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 1: ok, SG min 0, read errors 0, write errors 0, ifcnt 14, reads 107, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 2: standstill, SG min 0, read errors 0, write errors 0, ifcnt 12, reads 107, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 3: standstill, SG min 0, read errors 0, write errors 0, ifcnt 11, reads 107, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 4: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 108, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 5: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 107, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 6: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 107, writes 0, timeouts 0, DMA errors 0, CC errors 0
Date/time: 2023-01-01 16:43:26
Cache data hit count 3316121938
Slowest loop: 1.22ms; fastest: 0.13ms
=== Storage ===
Free file entries: 10
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 0.0ms, write time 0.0ms, max retries 0
=== Move ===
DMs created 83, segments created 1262, maxWait 0ms, bed compensation in use: none, comp offset 0.000
=== MainDDARing ===
Scheduled moves 30310, completed 30309, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state 3
=== AuxDDARing ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== Heat ===
Bed heaters -1 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
=== GCodes ===
Segments left: 0
Movement lock held by null
HTTP is idle in state(s) 0
Telnet is idle in state(s) 0
File is idle in state(s) 0
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
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
Code queue is empty
=== CAN ===
Messages queued 25, received 19, lost 0, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 0, free buffers 18 (min 18), ts 0/0/0
Tx timeouts 0,0,0,0,0,0
=== Network ===
Slowest loop: 4.95ms; fastest: 0.04ms
Responder states: HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 1 of 8
= Ethernet =
State: active
Error counts: 0 0 0 0 0 0
Socket states: 5 2 2 2 2 0 0 0

To:

1.1.2023, 16:43:21	M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.4.5 (2022-11-30 19:41:16) running on Duet 3 Mini5plus Ethernet (expansion mode)
Board ID: H1590-0296U-D65J0-40KMQ-JP03Z-RGPPB
Used output buffers: 1 of 40 (32 max)
=== RTOS ===
Static ram: 103652
Dynamic ram: 104764 of which 0 recycled
Never used RAM 2984, free system stack 120 words
Tasks: NETWORK(ready,27.7%,254) ETHERNET(notifyWait,0.3%,560) HEAT(notifyWait,0.1%,342) Move(notifyWait,0.0%,338) CanReceiv(notifyWait,0.1%,638) CanSender(notifyWait,0.0%,336) CanClock(invalid,0.0%,351) TMC(notifyWait,1.2%,72) MAIN(running,69.8%,637) IDLE(ready,0.0%,30) AIN(delaying,0.8%,263), total 100.0%
Owned mutexes:
=== Platform ===
Last reset 00:32:38 ago, cause: power up
Last software reset at 2023-01-01 16:10, reason: User, GCodes spinning, available RAM 34580, slot 1
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00000000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x00
MCU revision 3, ADC conversions started 1958782, completed 1958781, timed out 0, errs 0
Step timer max interval 679
MCU temperature: min 37.8, current 38.1, max 38.2
Supply voltage: min 23.6, current 23.6, max 23.7, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 0/0, heap memory allocated/used/recyclable 0/0/0, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, read errors 0, write errors 0, ifcnt 11, reads 117, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 1: ok, SG min 0, read errors 0, write errors 0, ifcnt 14, reads 118, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 2: standstill, SG min 0, read errors 0, write errors 0, ifcnt 12, reads 118, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 3: standstill, SG min 0, read errors 0, write errors 0, ifcnt 11, reads 117, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 4: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 117, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 5: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 118, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 6: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 117, writes 0, timeouts 0, DMA errors 0, CC errors 0
Date/time: 2023-01-01 16:43:28
Cache data hit count 3318307830
Slowest loop: 1.15ms; fastest: 0.13ms
=== Storage ===
Free file entries: 10
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 0.0ms, write time 0.0ms, max retries 0
=== Move ===
DMs created 83, segments created 1263, maxWait 0ms, bed compensation in use: none, comp offset 0.000
=== MainDDARing ===
Scheduled moves 30328, completed 30326, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state 3
=== AuxDDARing ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== Heat ===
Bed heaters -1 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
=== GCodes ===
Segments left: 0
Movement lock held by null
HTTP is idle in state(s) 0
Telnet is idle in state(s) 0
File is idle in state(s) 0
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
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
Code queue is empty
=== CAN ===
Messages queued 25, received 30, lost 0, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 0, free buffers 18 (min 18), ts 0/0/0
Tx timeouts 0,0,0,0,0,0
=== Network ===
Slowest loop: 4.85ms; fastest: 0.04ms
Responder states: HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 1 of 8
= Ethernet =
State: active
Error counts: 0 0 0 0 0 0
Socket states: 5 2 2 2 2 0 0 0

Last one before it died:

1.1.2023, 16:44:24	M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.4.5 (2022-11-30 19:41:16) running on Duet 3 Mini5plus Ethernet (expansion mode)
Board ID: H1590-0296U-D65J0-40KMQ-JP03Z-RGPPB
Used output buffers: 1 of 40 (32 max)
=== RTOS ===
Static ram: 103652
Dynamic ram: 104764 of which 0 recycled
Never used RAM 344, free system stack 120 words
Tasks: NETWORK(ready,27.9%,254) ETHERNET(notifyWait,0.3%,560) HEAT(notifyWait,0.1%,342) Move(notifyWait,0.1%,338) CanReceiv(notifyWait,0.2%,638) CanSender(notifyWait,0.0%,336) CanClock(invalid,0.0%,351) TMC(notifyWait,1.2%,72) MAIN(running,69.4%,637) IDLE(ready,0.0%,30) AIN(delaying,0.8%,263), total 100.0%
Owned mutexes:
=== Platform ===
Last reset 00:33:41 ago, cause: power up
Last software reset at 2023-01-01 16:10, reason: User, GCodes spinning, available RAM 34580, slot 1
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00000000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x00
MCU revision 3, ADC conversions started 2021886, completed 2021884, timed out 0, errs 0
Step timer max interval 655
MCU temperature: min 38.1, current 38.1, max 38.2
Supply voltage: min 23.6, current 23.6, max 23.7, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 0/0, heap memory allocated/used/recyclable 0/0/0, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, read errors 0, write errors 0, ifcnt 11, reads 109, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 1: ok, SG min 0, read errors 0, write errors 0, ifcnt 14, reads 108, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 2: standstill, SG min 0, read errors 0, write errors 0, ifcnt 12, reads 108, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 3: standstill, SG min 0, read errors 0, write errors 0, ifcnt 11, reads 109, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 4: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 109, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 5: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 108, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 6: standstill, SG min 0, read errors 0, write errors 0, ifcnt 9, reads 108, writes 0, timeouts 0, DMA errors 0, CC errors 0
Date/time: 2023-01-01 16:44:31
Cache data hit count 3424759447
Slowest loop: 1.17ms; fastest: 0.13ms
=== Storage ===
Free file entries: 10
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 0.0ms, write time 0.0ms, max retries 0
=== Move ===
DMs created 83, segments created 1373, maxWait 0ms, bed compensation in use: none, comp offset 0.000
=== MainDDARing ===
Scheduled moves 32545, completed 32539, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state 3
=== AuxDDARing ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== Heat ===
Bed heaters -1 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
=== GCodes ===
Segments left: 0
Movement lock held by null
HTTP is idle in state(s) 0
Telnet is idle in state(s) 0
File is idle in state(s) 0
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
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
Code queue is empty
=== CAN ===
Messages queued 25, received 81, lost 0, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 0, free buffers 18 (min 18), ts 0/0/0
Tx timeouts 0,0,0,0,0,0
=== Network ===
Slowest loop: 4.96ms; fastest: 0.04ms
Responder states: HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 1 of 8
= Ethernet =
State: active
Error counts: 0 0 0 0 0 0
Socket states: 5 5 2 2 2 0 0 0

Diamondback

As mentioned, I did complete a 2.5h print before with this setup, so the issue does not appear to be purely related to time.

The biggest difference I see between the working and failed print is that the working one has much longer extrusion segments and the failing one probably has a lot more tiny segments and maybe also a lot more retracts and possibly more PA action as well.

dc42

@Diamondback thanks. Are any of the endstops or the Z probe connected to the Duet 3 Mini?

Diamondback

@dc42 no, I made sure that all axis endstops and the Z probe are connected to the same board as the relevant steppers (ie all on the 6HC master)

dc42

@Diamondback thanks again. I am looking for data structures that consume 24 bytes of memory, and endstops and Z probes were one candidate.

Is it possible that the reduction in memory is correlated with operation of the tool-at-dock switches? Bear in mind that there may be contact bounce when they operate.

Diamondback

@dc42 no, these switches are not operated during the print at all (and I don't have any evidence that some sort of vibration would constantly trigger them by accident).
Maybe it's 3*8 bytes instead or something like this...

dc42

@Diamondback please install the firmware at https://www.dropbox.com/sh/wmrfidzkej24mcm/AAB7AFGrfMoYqssjbVKM5rwxa?dl=0 on the Mini5+ and monitor part of a print with M122 as before. I have added new fields heap top and heap limit to the report. When it has settled down, I expect either heap top to increase by 24 byes at a time, or heap limit to decrease by 24 bytes at a time. I need to know which.

dc42

@Diamondback ~~further to my previous message, I have found and fixed a possible cause of the memory leak. Please try the firmware at https://www.dropbox.com/sh/ihw972tlfq3gmj3/AABxTz_F0RYRC3i124PL4Wvma?dl=0.~~ Cancel that, I need to make a change to the fix.

dc42

@Diamondback second attempt: new firmware with possible memory leak fix at https://www.dropbox.com/sh/ihw972tlfq3gmj3/AABxTz_F0RYRC3i124PL4Wvma?dl=0.

Diamondback

@dc42 Which particular 6HC firmware should I use in combination with this? Is your other custom build from the reset/update via CAN issue ok?

Diamondback

Trying the fixed one first before the one with more debug output. Is the never used RAM supposed to be perfectly stable? It still does go down by 24bytes at a time, however a LOT slower than before.
Only lost 72 bytes in the last 6 minutes now and only 480 since I started the print 11 minutes ago.

Diamondback

Looks like it stopped decreasing now at 28076, the print finished without issues. Now trying to print a second time without any reset.