1LC - extruder randomly stopping/reversing - ≤3.5.0-rc1

Exerqtor

@droftarts I haven't tried an unloaded print, I can try that later today (all though i'm quite sure it will behave just the same).

Yup, just those two boards and the jumper is soldered. Regarding canbus length it's 1000-1200mm at most, done with twisted FEP wires.

Exerqtor

@droftarts
Okey, here is the SD-dump (I just took it), the only things I've left out is the "System Volume Information" folder, the debug logs and any other sliced jobs than the one I've been using for testing. And regarding IP-address and WiFi setup that's all done in runounce.g so you will have to deploy that yourself, as i suspect you're well aware of lol.

Just as a heads up regarding testing the "air print / unloaded" i'm going to alter the jobfile so the bed temp is 30C, gonna try that now and report back.

droftarts

@Exerqtor Great, thanks. This will have to wait until tomorrow now. Don't forget to enable cold extrude with M302 P1!

Ian

Exerqtor

@droftarts
Np, do it whenever you got time Yeah i skipped changing the hotend temp just incase the powerdraw to the toolboard might be a issue, ~~still haven't had time to run it yet lol.~~

Well that's for sure a definitive answer that loaded filament wasn't the issue, now it's acting up from the first layer again. Won't extrude at all during the print. However if I pause it and manuallly try to extrude through DWC or PD it extrudes without an issue.

Here is the reports from the ongoing test without any extrusion:

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.5.0-rc.3+ (2024-02-27 13:52:47) running on Duet 3 Mini5plus WiFi (standalone mode)
Board ID: XNHXF-HR6KL-K65J0-409N2-K9W1Z-RV2MZ
Used output buffers: 10 of 40 (40 max)
=== RTOS ===
Static ram: 103264
Dynamic ram: 128568 of which 0 recycled
Never used RAM 5016, free system stack 128 words
Tasks: NETWORK(1,ready,144.4%,182) HEAT(3,nWait 6,2.6%,326) Move(4,nWait 6,1.7%,238) CanReceiv(6,nWait 1,4.8%,773) CanSender(5,nWait 7,0.0%,336) CanClock(7,delaying,0.7%,340) TMC(4,nWait 6,72.2%,68) MAIN(1,running,290.3%,595) IDLE(0,ready,80.6%,30) AIN(4,delaying,73.6%,260), total 670.9%
Owned mutexes:
=== Platform ===
Last reset 24:25:27 ago, cause: software
Last software reset at 2024-02-28 17:11, reason: User, Gcodes spinning, available RAM 11836, slot 0
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0044f000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x04
Aux0 errors 0,0,0
MCU revision 3, ADC conversions started 87927453, completed 87927453, timed out 0, errs 0
MCU temperature: min 34.4, current 46.0, max 46.4
Supply voltage: min 23.4, current 24.1, max 24.7, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 198/33, heap memory allocated/used/recyclable 2048/1764/1304, gc cycles 18673
Events: 0 queued, 0 completed
Driver 0: ok, SG min 0, read errors 0, write errors 0, ifcnt 87, reads 51758, writes 41, timeouts 0, DMA errors 0, CC errors 0
Driver 1: ok, SG min 0, read errors 0, write errors 0, ifcnt 88, reads 51757, writes 41, timeouts 1, DMA errors 0, CC errors 0, failedOp 0x51
Driver 2: ok, SG min 0, read errors 0, write errors 0, ifcnt 41, reads 51780, writes 18, timeouts 0, DMA errors 0, CC errors 0
Driver 3: ok, SG min 0, read errors 0, write errors 0, ifcnt 42, reads 51780, writes 18, timeouts 1, DMA errors 0, CC errors 0, failedOp 0x01
Driver 4: ok, SG min 0, read errors 0, write errors 0, ifcnt 42, reads 51781, writes 18, timeouts 0, DMA errors 0, CC errors 0
Driver 5: not present
Driver 6: not present
Date/time: 2024-02-29 17:37:03
Cache data hit count 4294967295
Slowest loop: 229.18ms; fastest: 0.09ms
=== Storage ===
Free file entries: 16
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 9.2ms, write time 67.1ms, max retries 0
=== Move ===
DMs created 83, segments created 38, maxWait 85780177ms, bed compensation in use: mesh, height map offset 0.000, max steps late 1, min interval 0, bad calcs 0, ebfmin 0.00, ebfmax 0.00
next step interrupt due in 13849 ticks, enabled
Moves shaped first try 1145, on retry 293, too short 345, wrong shape 6378, maybepossible 191
=== DDARing 0 ===
Scheduled moves 3966, completed 3926, hiccups 0, stepErrors 0, LaErrors 9, Underruns [0, 0, 2], CDDA state 3
=== DDARing 1 ===
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, chamber heaters -1 -1 -1 -1, ordering errs 0
Heater 0 is on, I-accum = 0.0
Heater 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 doing "G1 Z.85" 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 doing "G4 P250" in state(s) 0 0, running macro
Aux2 is idle in state(s) 0
Autopause is idle in state(s) 0
File2 is idle in state(s) 0, sync state 1
Queue2 is idle in state(s) 0
Q0 segments left 0, axes/extruders owned 0x0000807
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 sensor: no filament
=== CAN ===
Messages queued 791270, received 1781906, lost 0, errs 0, boc 0
Longest wait 6ms for reply type 6024, peak Tx sync delay 276, free buffers 26 (min 25), ts 434512/434512/0
Tx timeouts 0,0,0,0,0,0
=== Network ===
Slowest loop: 207.39ms; fastest: 0.06ms
Responder states: MQTT(0) HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 1 of 8
=== WiFi ===
Interface state: active
Module is connected to access point 
Failed messages: pending 0, notrdy 0, noresp 0
Firmware version 2.1beta7
MAC address c4:5b:be:ce:91:93
Module reset reason: Power up, Vcc 3.38, flash size 2097152, free heap 42848
WiFi IP address 192.168.10.x
Signal strength -58dBm, channel 6, mode 802.11n, reconnections 0
Clock register 00002001
Socket states: 0 0 0 0 0 0 0 0
M122 B121
Diagnostics for board 121:
Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.3+ (2024-02-26 15:24:37)
Bootloader ID: SAMC21 bootloader version 2.3 (2021-01-26b1)
All averaging filters OK
Never used RAM 3112, free system stack 71 words
Tasks: Move(3,nWait 7,0.4%,87) HEAT(2,nWait 6,32.4%,91) CanAsync(5,nWait 4,0.0%,49) CanRecv(3,nWait 1,1.2%,71) CanClock(5,nWait 1,1.8%,59) ACCEL(3,nWait 6,0.0%,53) TMC(2,nWait 6,296.3%,53) MAIN(1,running,478.3%,315) IDLE(0,ready,0.0%,27) AIN(2,delaying,428.1%,112), total 1238.6%
Owned mutexes:
Last reset 24:25:32 ago, cause: power up
Last software reset data not available
Driver 0: pos 0, 568.8 steps/mm, standstill, SG min 0, read errors 0, write errors 0, ifcnt 16, reads 921, writes 4, timeouts 6, DMA errors 0, CC errors 0, failedOp 0x6a, steps req 0 done 185963
Moves scheduled 3356, completed 3356, in progress 0, hiccups 235, segs 36, step errors 0, maxLate 0 maxPrep 894, maxOverdue 0, maxInc 0, mcErrs 0, gcmErrs 0, ebfmin 0.00 max inf
Peak sync jitter -3/9, peak Rx sync delay 221, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.6, current 24.4, max 25.2
MCU temperature: min 37.8C, current 40.9C, max 63.4C
Last sensors broadcast 0x00000012 found 2 95 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 1781927, send timeouts 0, received 791335, lost 0, errs 0, boc 0, free buffers 18, min 18, error reg 0
dup 0, oos 0/0/0/0, bm 0, wbm 0, rxMotionDelay 342, adv 35637/104588
Accelerometer: LIS3DH, status: 00
I2C bus errors 0, naks 0, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 5 to 1777us
Driver 0: ok

The only extrusion it did by itself is the load sequence right before doing the purge lines, not even the purge lines themself yielded any movement.

dc42

@Exerqtor I see that there are some hiccups on the tool board. Does it make any difference if you use M220 S50 just before starting the print, to run it at half speed?

Exerqtor

@dc42
I can add it to the job code manually and run another test, give me a couple minutes and I'll report back.

Nah, same exact thing only does the nozzle loading sequence then nothing:

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.5.0-rc.3+ (2024-02-27 13:52:47) running on Duet 3 Mini5plus WiFi (standalone mode)
Board ID: XNHXF-HR6KL-K65J0-409N2-K9W1Z-RV2MZ
Used output buffers: 25 of 40 (40 max)
=== RTOS ===
Static ram: 103264
Dynamic ram: 128568 of which 0 recycled
Never used RAM 4992, free system stack 106 words
Tasks: NETWORK(2,nWait 7,16.2%,182) HEAT(3,nWait 6,0.0%,326) Move(4,nWait 6,0.3%,238) CanReceiv(6,nWait 1,0.1%,773) CanSender(5,nWait 7,0.0%,328) CanClock(7,delaying,0.0%,340) TMC(4,delaying,0.8%,68) MAIN(1,running,80.5%,595) IDLE(0,ready,1.1%,30) AIN(4,delaying,0.9%,260), total 100.0%
Owned mutexes: WiFi(NETWORK)
=== Platform ===
Last reset 24:48:18 ago, cause: software
Last software reset at 2024-02-28 17:11, reason: User, Gcodes spinning, available RAM 11836, slot 0
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0044f000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x04
Aux0 errors 0,0,0
MCU revision 3, ADC conversions started 89299231, completed 89299231, timed out 0, errs 0
MCU temperature: min 36.2, current 40.0, max 46.2
Supply voltage: min 23.5, current 23.7, max 24.5, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 198/33, heap memory allocated/used/recyclable 2048/1572/1112, gc cycles 18995
Events: 0 queued, 0 completed
Driver 0: ok, SG min 0, read errors 0, write errors 0, ifcnt 106, reads 6635, writes 19, timeouts 0, DMA errors 0, CC errors 0
Driver 1: ok, SG min 0, read errors 0, write errors 0, ifcnt 107, reads 6635, writes 19, timeouts 0, DMA errors 0, CC errors 0
Driver 2: standstill, SG min 0, read errors 0, write errors 0, ifcnt 48, reads 6647, writes 7, timeouts 0, DMA errors 0, CC errors 0
Driver 3: ok, SG min 0, read errors 0, write errors 0, ifcnt 49, reads 6647, writes 7, timeouts 0, DMA errors 0, CC errors 0
Driver 4: ok, SG min 0, read errors 0, write errors 0, ifcnt 50, reads 6646, writes 8, timeouts 0, DMA errors 0, CC errors 0
Driver 5: not present
Driver 6: not present
Date/time: 2024-02-29 17:59:55
Cache data hit count 4294967295
Slowest loop: 229.98ms; fastest: 0.09ms
=== Storage ===
Free file entries: 16
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 9.0ms, write time 46.1ms, max retries 0
=== Move ===
DMs created 83, segments created 39, maxWait 1072427ms, bed compensation in use: mesh, height map offset 0.000, max steps late 1, min interval 0, bad calcs 0, ebfmin 0.00, ebfmax 0.00
next step interrupt due in 18 ticks, enabled
Moves shaped first try 538, on retry 151, too short 149, wrong shape 2343, maybepossible 92
=== DDARing 0 ===
Scheduled moves 348, completed 319, hiccups 0, stepErrors 0, LaErrors 5, Underruns [0, 0, 3], CDDA state 3
=== DDARing 1 ===
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, chamber heaters -1 -1 -1 -1, ordering errs 0
Heater 0 is on, I-accum = 0.3
Heater 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) 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
SBC is idle in state(s) 0
Daemon is doing "G4 P250" in state(s) 0 0, running macro
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 3, axes/extruders owned 0x0000807
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 sensor: no filament
=== CAN ===
Messages queued 15975, received 28320, lost 0, errs 0, boc 0
Longest wait 6ms for reply type 6024, peak Tx sync delay 156, free buffers 26 (min 25), ts 6858/6858/0
Tx timeouts 0,0,0,0,0,0
=== Network ===
Slowest loop: 206.78ms; fastest: 0.06ms
Responder states: MQTT(0) HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 1 of 8
=== WiFi ===
Interface state: active
Module is connected to access point 
Failed messages: pending 0, notrdy 0, noresp 0
Firmware version 2.1beta7
MAC address c4:5b:be:ce:91:93
Module reset reason: Power up, Vcc 3.38, flash size 2097152, free heap 42676
WiFi IP address 192.168.10.x
Signal strength -52dBm, channel 6, mode 802.11n, reconnections 0
Clock register 00002001
Socket states: 0 0 0 0 0 0 0 0
M122 B121
Diagnostics for board 121:
Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.3+ (2024-02-26 15:24:37)
Bootloader ID: SAMC21 bootloader version 2.3 (2021-01-26b1)
All averaging filters OK
Never used RAM 3112, free system stack 71 words
Tasks: Move(3,nWait 7,0.1%,87) HEAT(2,nWait 6,0.4%,91) CanAsync(5,nWait 4,0.0%,49) CanRecv(3,nWait 1,0.0%,71) CanClock(5,nWait 1,0.0%,59) ACCEL(3,nWait 6,0.0%,53) TMC(2,delaying,3.4%,53) MAIN(1,running,91.1%,315) IDLE(0,ready,0.0%,27) AIN(2,delaying,5.0%,112), total 100.0%
Owned mutexes:
Last reset 24:48:22 ago, cause: power up
Last software reset data not available
Driver 0: pos 0, 568.8 steps/mm, standstill, SG min 0, read errors 0, write errors 0, ifcnt 18, reads 29151, writes 2, timeouts 0, DMA errors 0, CC errors 0, steps req 0 done 113840
Moves scheduled 3577, completed 3577, in progress 0, hiccups 110, segs 36, step errors 0, maxLate 0 maxPrep 883, maxOverdue 0, maxInc 0, mcErrs 0, gcmErrs 0, ebfmin 0.00 max inf
Peak sync jitter -2/9, peak Rx sync delay 217, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.7, current 24.5, max 24.9
MCU temperature: min 37.8C, current 42.5C, max 63.4C
Last sensors broadcast 0x00000012 found 2 8 ticks ago, 0 ordering errs, loop time 1
CAN messages queued 28289, send timeouts 0, received 15909, lost 0, errs 0, boc 0, free buffers 18, min 18, error reg 0
dup 0, oos 0/0/0/0, bm 0, wbm 0, rxMotionDelay 339, adv 35936/74646
Accelerometer: LIS3DH, status: 00
I2C bus errors 0, naks 0, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 5 to 2528us
Driver 0: ok

Those reports are taken during the first couple loops of the first layer btw.

Exerqtor

@Exerqtor
For some reason the half speed factor didn't apply, I just set in manually in DWC and ran another set of reports on the same print session (still no extruder movement):

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.5.0-rc.3+ (2024-02-27 13:52:47) running on Duet 3 Mini5plus WiFi (standalone mode)
Board ID: XNHXF-HR6KL-K65J0-409N2-K9W1Z-RV2MZ
Used output buffers: 15 of 40 (40 max)
=== RTOS ===
Static ram: 103264
Dynamic ram: 128568 of which 0 recycled
Never used RAM 4992, free system stack 106 words
Tasks: NETWORK(1,ready,17.8%,182) HEAT(3,nWait 6,0.0%,326) Move(4,nWait 6,2.2%,235) CanReceiv(6,nWait 1,0.1%,773) CanSender(5,nWait 7,0.0%,328) CanClock(7,delaying,0.0%,340) TMC(4,nWait 6,0.9%,68) MAIN(1,running,76.7%,595) IDLE(0,ready,1.4%,30) AIN(4,delaying,0.9%,260), total 100.0%
Owned mutexes:
=== Platform ===
Last reset 24:52:22 ago, cause: software
Last software reset at 2024-02-28 17:11, reason: User, Gcodes spinning, available RAM 11836, slot 0
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0044f000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x04
Aux0 errors 0,0,0
MCU revision 3, ADC conversions started 89542995, completed 89542993, timed out 0, errs 0
MCU temperature: min 39.8, current 46.0, max 46.2
Supply voltage: min 23.6, current 24.0, max 24.3, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 198/33, heap memory allocated/used/recyclable 2048/1252/792, gc cycles 19048
Events: 0 queued, 0 completed
Driver 0: ok, SG min 0, read errors 0, write errors 0, ifcnt 106, reads 12823, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 1: ok, SG min 0, read errors 0, write errors 0, ifcnt 107, reads 12823, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 2: standstill, SG min 0, read errors 0, write errors 0, ifcnt 48, reads 12824, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 3: ok, SG min 0, read errors 0, write errors 0, ifcnt 49, reads 12824, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 4: ok, SG min 0, read errors 0, write errors 0, ifcnt 50, reads 12823, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 5: not present
Driver 6: not present
Date/time: 2024-02-29 18:03:59
Cache data hit count 4294967295
Slowest loop: 36.84ms; fastest: 0.10ms
=== Storage ===
Free file entries: 16
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 8.1ms, write time 6.5ms, max retries 0
=== Move ===
DMs created 83, segments created 39, maxWait 2727ms, bed compensation in use: mesh, height map offset 0.000, max steps late 1, min interval 0, bad calcs 0, ebfmin 0.00, ebfmax 0.00
next step interrupt due in 39 ticks, enabled
Moves shaped first try 43, on retry 1, too short 33, wrong shape 1516, maybepossible 4
=== DDARing 0 ===
Scheduled moves 2067, completed 2054, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state 3
=== DDARing 1 ===
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, chamber heaters -1 -1 -1 -1, ordering errs 0
Heater 0 is on, I-accum = 0.0
Heater 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) 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
SBC is idle in state(s) 0
Daemon is doing "G4 P250" in state(s) 0 0, running macro
Aux2 is idle in state(s) 0
Autopause is idle in state(s) 0
File2 is idle in state(s) 0, sync state 1
Queue2 is idle in state(s) 0
Q0 segments left 1, axes/extruders owned 0x0000807
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 sensor: no filament
=== CAN ===
Messages queued 3885, received 5028, lost 0, errs 0, boc 0
Longest wait 6ms for reply type 6024, peak Tx sync delay 198, free buffers 26 (min 25), ts 1219/1219/0
Tx timeouts 0,0,0,0,0,0
=== Network ===
Slowest loop: 20.37ms; fastest: 0.06ms
Responder states: MQTT(0) HTTP(2) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 1 of 8
=== WiFi ===
Interface state: active
Module is connected to access point 
Failed messages: pending 0, notrdy 0, noresp 0
Firmware version 2.1beta7
MAC address c4:5b:be:ce:91:93
Module reset reason: Power up, Vcc 3.38, flash size 2097152, free heap 39588
WiFi IP address 192.168.10.x
Signal strength -54dBm, channel 6, mode 802.11n, reconnections 0
Clock register 00002001
Socket states: 0 0 0 0 0 0 0 0
M122 B121
Diagnostics for board 121:
Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.3+ (2024-02-26 15:24:37)
Bootloader ID: SAMC21 bootloader version 2.3 (2021-01-26b1)
All averaging filters OK
Never used RAM 3112, free system stack 71 words
Tasks: Move(3,nWait 7,0.1%,87) HEAT(2,nWait 6,0.4%,91) CanAsync(5,nWait 4,0.0%,49) CanRecv(3,nWait 1,0.1%,71) CanClock(5,nWait 1,0.0%,59) ACCEL(3,nWait 6,0.0%,53) TMC(2,nWait 6,3.4%,53) MAIN(1,running,91.0%,315) IDLE(0,ready,0.0%,27) AIN(2,delaying,5.0%,112), total 100.0%
Owned mutexes:
Last reset 24:52:27 ago, cause: power up
Last software reset data not available
Driver 0: pos 0, 568.8 steps/mm, standstill, SG min 0, read errors 0, write errors 0, ifcnt 18, reads 57100, writes 0, timeouts 0, DMA errors 0, CC errors 0, steps req 0 done 2550
Moves scheduled 3587, completed 3587, in progress 0, hiccups 5, segs 36, step errors 0, maxLate 0 maxPrep 514, maxOverdue 0, maxInc 0, mcErrs 0, gcmErrs 0, ebfmin 0.00 max inf
Peak sync jitter -2/9, peak Rx sync delay 213, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 24.2, current 24.4, max 24.9
MCU temperature: min 37.8C, current 41.7C, max 63.4C
Last sensors broadcast 0x00000012 found 2 116 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 5062, send timeouts 0, received 3897, lost 0, errs 0, boc 0, free buffers 18, min 18, error reg 0
dup 0, oos 0/0/0/0, bm 0, wbm 0, rxMotionDelay 329, adv 36085/104580
Accelerometer: LIS3DH, status: 00
I2C bus errors 0, naks 0, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 9 to 1722us
Driver 0: ok

I went through the whole system macro by macro in executed order another time yesterday evening and i can't for the life of it find anything that could cause the behaviour this time either.

How big is the code changes between 3.5.0-b4 and 3.5.0-rc1 in the regard to what might produce this bug? Given that everything plays nice in beta4 it seems rational to assume that the buggy code got added at that point, and is still persisting in the following release candidates.

droftarts

@Exerqtor The changes should be listed here: https://github.com/Duet3D/RepRapFirmware/wiki/Changelog-RRF-3.x-RC#reprapfirmware-350-rc1-changes-since-350-beta4
To actually do a code review, 3.5.0-beta.4 was release on the 9th June, and 3.5.0-rc.1 on 1st September, so it's looking at all the commits over a nearly 3 month period.

I'm just setting up to run the tests, which involves swapping the X axis on my printer! Don't worry, it was due an upgrade.

Ian

Exerqtor

@droftarts said in 1LC - extruder randomly stopping/reversing - ≤3.5.0-r1:

@Exerqtor The changes should be listed here: https://github.com/Duet3D/RepRapFirmware/wiki/Changelog-RRF-3.x-RC#reprapfirmware-350-rc1-changes-since-350-beta4
To actually do a code review, 3.5.0-beta.4 was release on the 9th June, and 3.5.0-rc.1 on 1st September, so it's looking at all the commits over a nearly 3 month period.

Yeah it's alot of commits/code to read through so I totally get why it's a bitch to track down.

I'll try to disable the filament sensor and see if that makes a difference just for the shits later. Thats pretty much "the only thing" I can't remember trying out this far.

I'm just setting up to run the tests, which involves swapping the X axis on my printer! Don't worry, it was due an upgrade.

Ian

It will be interesting hearing how it plays out for you!

Exerqtor

@dc42

Ok so i've tried out a couple other things too now, but it still yields the same result.

Updated the toolboards bootloader to 2.8, and reinstalled with the binaries mentioned earleir.
Commented out the filament sensor code from config.g.
Added M220 S50 to my start gcode so every extruder move is at 50% from the getgo.

Here is the reports from when it's not extruding agian (stopped at the "usual point" in layer 3) :

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.5.0-rc.3+ (2024-02-27 13:52:47) running on Duet 3 Mini5plus WiFi (standalone mode)
Board ID: XNHXF-HR6KL-K65J0-409N2-K9W1Z-RV2MZ
Used output buffers: 9 of 40 (34 max)
=== RTOS ===
Static ram: 103264
Dynamic ram: 128496 of which 0 recycled
Never used RAM 3128, free system stack 128 words
Tasks: NETWORK(2,nWait 7,17.3%,196) HEAT(3,nWait 6,0.0%,351) Move(4,nWait 6,1.5%,241) CanReceiv(6,nWait 1,0.1%,794) CanSender(5,nWait 7,0.0%,328) CanClock(7,delaying,0.0%,340) TMC(4,nWait 6,0.9%,68) MAIN(1,running,78.0%,602) IDLE(0,ready,1.4%,30) AIN(4,delaying,0.9%,260), total 100.0%
Owned mutexes: WiFi(NETWORK)
=== Platform ===
Last reset 00:17:57 ago, cause: software
Last software reset at 2024-03-01 14:10, reason: User, Gcodes spinning, available RAM 4992, 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
Aux0 errors 0,0,0
MCU revision 3, ADC conversions started 1078021, completed 1078021, timed out 0, errs 0
MCU temperature: min 35.3, current 46.0, max 46.4
Supply voltage: min 2.8, current 23.9, max 24.4, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 198/33, heap memory allocated/used/recyclable 4096/1060/600, gc cycles 148
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, read errors 0, write errors 0, ifcnt 31, reads 56674, writes 31, timeouts 0, DMA errors 0, CC errors 0
Driver 1: ok, SG min 0, read errors 0, write errors 0, ifcnt 31, reads 56673, writes 31, timeouts 0, DMA errors 0, CC errors 0
Driver 2: standstill, SG min 0, read errors 0, write errors 0, ifcnt 20, reads 56684, writes 20, timeouts 0, DMA errors 0, CC errors 0
Driver 3: standstill, SG min 0, read errors 0, write errors 0, ifcnt 21, reads 56683, writes 21, timeouts 0, DMA errors 0, CC errors 0
Driver 4: standstill, SG min 0, read errors 0, write errors 0, ifcnt 20, reads 56685, writes 20, timeouts 0, DMA errors 0, CC errors 0
Driver 5: not present
Driver 6: not present
Date/time: 2024-03-01 14:28:33
Cache data hit count 1597184571
Slowest loop: 222.42ms; fastest: 0.09ms
=== Storage ===
Free file entries: 16
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 9.5ms, write time 46.1ms, max retries 0
=== Move ===
DMs created 83, segments created 34, maxWait 210310ms, bed compensation in use: mesh, height map offset 0.000, max steps late 1, min interval 0, bad calcs 0, ebfmin 0.00, ebfmax 0.00
next step interrupt due in 16 ticks, enabled
Moves shaped first try 928, on retry 45, too short 162, wrong shape 5053, maybepossible 89
=== DDARing 0 ===
Scheduled moves 7843, completed 7803, hiccups 0, stepErrors 0, LaErrors 6, Underruns [0, 0, 0], CDDA state 3
=== DDARing 1 ===
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, chamber heaters -1 -1 -1 -1, ordering errs 0
Heater 0 is on, I-accum = 0.6
Heater 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 doing "G1 Z2.55 F21000" 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 doing "G4 P250" in state(s) 0 0, running macro
Aux2 is idle in state(s) 0
Autopause is idle in state(s) 0
File2 is idle in state(s) 0, sync state 1
Queue2 is idle in state(s) 0
Q0 segments left 1, axes/extruders owned 0x0000807
Code queue 0 is empty
Q1 segments left 0, axes/extruders owned 0x0000000
Code queue 1 is empty
=== CAN ===
Messages queued 16603, received 21779, lost 0, errs 1297, boc 0
Longest wait 5ms for reply type 6024, peak Tx sync delay 6564, free buffers 26 (min 25), ts 5390/5388/0
Tx timeouts 0,0,1,0,0,0 last cancelled message type 30 dest 127
=== Network ===
Slowest loop: 205.29ms; fastest: 0.00ms
Responder states: MQTT(0) HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 1 of 8
=== WiFi ===
Interface state: active
Module is connected to access point 
Failed messages: pending 0, notrdy 0, noresp 0
Firmware version 2.1beta7
MAC address c4:5b:be:ce:91:93
Module reset reason: Power up, Vcc 3.38, flash size 2097152, free heap 42320
WiFi IP address 192.168.10.x
Signal strength -53dBm, channel 6, mode 802.11n, reconnections 0
Clock register 00002001
Socket states: 0 0 0 0 0 0 0 0
	M122 B121
Diagnostics for board 121:
Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.3+ (2024-02-26 15:24:37)
Bootloader ID: SAMC21 bootloader version 2.8 (2023-07-25)
All averaging filters OK
Never used RAM 3244, free system stack 71 words
Tasks: Move(3,nWait 7,0.2%,91) HEAT(2,nWait 6,0.4%,99) CanAsync(5,nWait 4,0.0%,51) CanRecv(3,nWait 1,0.1%,71) CanClock(5,nWait 1,0.0%,59) ACCEL(3,nWait 6,0.0%,53) TMC(2,nWait 6,3.5%,53) MAIN(1,running,90.9%,315) IDLE(0,ready,0.0%,27) AIN(2,delaying,5.0%,112), total 100.0%
Owned mutexes:
Last reset 00:18:00 ago, cause: power up
Last software reset data not available
Driver 0: pos 0, 568.8 steps/mm, standstill, SG min 0, read errors 0, write errors 0, ifcnt 13, reads 63028, writes 1, timeouts 0, DMA errors 0, CC errors 0, steps req 0 done 433233
Moves scheduled 3059, completed 3059, in progress 0, hiccups 227, segs 32, step errors 0, maxLate 0 maxPrep 791, maxOverdue 143, maxInc 51, mcErrs 0, gcmErrs 0, ebfmin 0.00 max inf
Peak sync jitter -3/9, peak Rx sync delay 220, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.7, current 24.4, max 24.9
MCU temperature: min 37.5C, current 53.8C, max 53.8C
Last sensors broadcast 0x00000012 found 2 64 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 21153, send timeouts 0, received 16336, lost 0, errs 0, boc 0, free buffers 18, min 18, error reg 0
dup 0, oos 0/0/0/0, bm 0, wbm 0, rxMotionDelay 372, adv 35617/96411
Accelerometer: LIS3DH, status: 00
I2C bus errors 0, naks 0, contentions 0, other errors 0

dc42

@Exerqtor you said that if you pause and then extrude manually, it works. Does it work if you send a G1 command that does both movement and extrusion? What happens if you resume the print after the pause?

Exerqtor

@dc42 I haven't tried doing a G1 move and extrusion, just extrude and retract with DWC or PD. I'll test that tomorrow.

When i resume the printer after a pause it goes back to the print just like expected except it don't extrude. Pretty much pics up right where and as it did before the pause.

Exerqtor

@dc42 said in 1LC - extruder randomly stopping/reversing - ≤3.5.0-r1:

@Exerqtor you said that if you pause and then extrude manually, it works. Does it work if you send a G1 command that does both movement and extrusion? What happens if you resume the print after the pause?

Sorry for the late reply but I've been out cold with the stomach flu the whole weekend 🤮💩

Finally got around testing this today though! So I made a macro containing G1 X0.1 Y200.0 F1500.0 E15 that I ran (manually from PD) while the printer was paused after it had bugged out during the test print (printhead moves to X/Y0 when paused) and this is what happens:

The printhead moves to Y200, but don't extrude anything.
I try to manually extrude 20mm @ 5mm/s, through PD and that works.
I manually jog the printhead back too X/Y0 and try to run the "G1 macro" once more, with the same outcome ast the first time i tried.
I then manually extrude another 20mm with PD, that works.
Tries to resume the print, and it goes on like every other time with all movement and no extrusion.

Here is the reports from when it's resumed after runing the above tests:

	M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.5.0-rc.3+ (2024-02-27 13:52:47) running on Duet 3 Mini5plus WiFi (standalone mode)
Board ID: XNHXF-HR6KL-K65J0-409N2-K9W1Z-RV2MZ
Used output buffers: 19 of 40 (40 max)
=== RTOS ===
Static ram: 103264
Dynamic ram: 128512 of which 0 recycled
Never used RAM 3016, free system stack 138 words
Tasks: NETWORK(2,nWait 7,17.2%,226) HEAT(3,nWait 6,0.0%,342) Move(4,nWait 6,0.8%,238) CanReceiv(6,nWait 1,0.1%,796) CanSender(5,nWait 7,0.0%,337) CanClock(7,delaying,0.0%,340) TMC(4,nWait 6,0.9%,68) MAIN(1,running,78.7%,602) IDLE(0,ready,1.4%,30) AIN(4,delaying,0.9%,260), total 100.0%
Owned mutexes: WiFi(NETWORK)
=== Platform ===
Last reset 00:13:18 ago, cause: software
Last software reset at 2024-03-04 17:48, reason: User, Gcodes spinning, available RAM 11908, slot 0
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00489000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x04
Aux0 errors 0,0,0
MCU revision 3, ADC conversions started 799401, completed 799401, timed out 0, errs 0
MCU temperature: min 36.2, current 45.3, max 46.6
Supply voltage: min 3.0, current 24.1, max 24.8, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 198/33, heap memory allocated/used/recyclable 4096/3076/2616, gc cycles 112
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, read errors 0, write errors 0, ifcnt 33, reads 41985, writes 33, timeouts 0, DMA errors 0, CC errors 0
Driver 1: ok, SG min 0, read errors 0, write errors 0, ifcnt 33, reads 41985, writes 33, timeouts 0, DMA errors 0, CC errors 0
Driver 2: ok, SG min 0, read errors 0, write errors 0, ifcnt 21, reads 41997, writes 21, timeouts 0, DMA errors 0, CC errors 0
Driver 3: ok, SG min 0, read errors 0, write errors 0, ifcnt 22, reads 41996, writes 22, timeouts 0, DMA errors 0, CC errors 0
Driver 4: ok, SG min 0, read errors 0, write errors 0, ifcnt 21, reads 41997, writes 21, timeouts 0, DMA errors 0, CC errors 0
Driver 5: not present
Driver 6: not present
Date/time: 2024-03-04 18:01:30
Cache data hit count 1235346997
Slowest loop: 224.32ms; fastest: 0.09ms
=== Storage ===
Free file entries: 16
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 9.7ms, write time 8.2ms, max retries 0
=== Move ===
DMs created 83, segments created 38, maxWait 239837ms, bed compensation in use: mesh, height map offset 0.000, max steps late 1, min interval 0, bad calcs 0, ebfmin 0.00, ebfmax 0.00
next step interrupt due in 35 ticks, enabled
Moves shaped first try 288, on retry 48, too short 115, wrong shape 2458, maybepossible 56
=== DDARing 0 ===
Scheduled moves 3621, completed 3591, hiccups 0, stepErrors 0, LaErrors 1, Underruns [0, 0, 5], CDDA state 3
=== DDARing 1 ===
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, chamber heaters -1 -1 -1 -1, ordering errs 0
Heater 0 is on, I-accum = 0.4
Heater 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 doing "G1 X188.12 Y188.973 E.0049" 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 doing "G4 P250" in state(s) 0 0, running macro
Aux2 is idle in state(s) 0
Autopause is idle in state(s) 0
File2 is idle in state(s) 0, sync state 1
Queue2 is idle in state(s) 0
Q0 segments left 1, axes/extruders owned 0x0000807
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 sensor: no filament
=== CAN ===
Messages queued 10502, received 16605, lost 0, errs 1286, boc 0
Longest wait 6ms for reply type 6013, peak Tx sync delay 4831, free buffers 26 (min 25), ts 3995/3993/0
Tx timeouts 0,0,1,0,0,0 last cancelled message type 30 dest 127
=== Network ===
Slowest loop: 10.65ms; fastest: 0.00ms
Responder states: MQTT(0) HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0)
HTTP sessions: 1 of 8
=== WiFi ===
Interface state: active
Module is connected to access point 
Failed messages: pending 0, notrdy 0, noresp 0
Firmware version 2.1beta7
MAC address c4:5b:be:ce:91:93
Module reset reason: Power up, Vcc 3.38, flash size 2097152, free heap 42692
WiFi IP address 192.168.10.x
Signal strength -52dBm, channel 6, mode 802.11n, reconnections 0
Clock register 00002001
Socket states: 0 0 0 0 0 0 0 0
M122 B121
Diagnostics for board 121:
Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.3+ (2024-02-26 15:24:37)
Bootloader ID: SAMC21 bootloader version 2.8 (2023-07-25)
All averaging filters OK
Never used RAM 3160, free system stack 71 words
Tasks: Move(3,nWait 7,0.1%,91) HEAT(2,nWait 6,0.4%,99) CanAsync(5,nWait 4,0.0%,51) CanRecv(3,nWait 1,0.0%,71) CanClock(5,nWait 1,0.0%,59) ACCEL(3,nWait 6,0.0%,53) TMC(2,nWait 6,3.5%,53) MAIN(1,running,91.0%,315) IDLE(0,ready,0.0%,27) AIN(2,delaying,5.0%,112), total 100.0%
Owned mutexes:
Last reset 00:13:21 ago, cause: VDD brownout
Last software reset data not available
Driver 0: pos 0, 568.8 steps/mm, standstill, SG min 0, read errors 0, write errors 0, ifcnt 12, reads 7118, writes 12, timeouts 0, DMA errors 0, CC errors 0, steps req 0 done 392533
Moves scheduled 2791, completed 2791, in progress 0, hiccups 111, segs 34, step errors 0, maxLate 0 maxPrep 873, maxOverdue 96, maxInc 41, mcErrs 0, gcmErrs 0, ebfmin 0.00 max inf
Peak sync jitter -2/9, peak Rx sync delay 216, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.7, current 24.4, max 25.2
MCU temperature: min 45.1C, current 62.9C, max 62.9C
Last sensors broadcast 0x00000012 found 2 116 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 16690, send timeouts 0, received 10583, lost 0, errs 0, boc 0, free buffers 18, min 18, error reg 0
dup 0, oos 0/0/0/0, bm 0, wbm 0, rxMotionDelay 375, adv 35649/107889
Accelerometer: LIS3DH, status: 00
I2C bus errors 0, naks 3, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 4 to 1730us
Driver 0: ok

Exerqtor

@droftarts, how did your test turn out btw? If you've found the time to do so yet

droftarts

@Exerqtor sorry, it’s taken me a bit longer than expected to update my machine. Apparently linear bearings need lubricating at least once every 10 years! However, it’s back up together, the 1LC is wired up to a Hemera, just need to finish off commissioning and testing, then I can break it again trying to emulate your setup!

Ian

Exerqtor

@droftarts no need to excuse yourself! 😅 Yeah those darn rails and their demands lol.

Take your time, I still fall back to 3.5.0-b4 every time I need to get something printed. But it would be really nice to find and fix the issue before the next rc *wishfull thinking* 😇

dc42

@Exerqtor thanks for running that test.

I'm starting to think that the issue must be with the main board firmware, because the tool board only sees the extrusion movement command and has no idea whether there is axis movement as well. Have any of the tests with different firmware versions established which firmware affects the symptoms? For example, if you revert the tool board firmware back to 3.5.0-rc.1 or rc.2 (or even b4) but keep the main board firmware at rc.3+, does the symptom change? I suggest you disable your filament monitor during these tests to avoid incompatibility issues.

Exerqtor

@dc42 I haven't tried mismatching the firmware between the toolboard and main board. I can try in a little while, going backwards from rc3+ on the toolboard until b4 and report back.

Well this didn't go as planned lol.
With rc3+ on the main board and rc2, rc1 or b4 on the toolboard i get issues with my Z-probe:
On boot, from config.g:

Error in start-up file macro line 118: invalid Z probe index

Line 117: M558 K0 P8 C"^121.io2.in" H2 R0.2 F300:180 T18000 A1 S0.03                     ; Set Z probe number ,type, input pin, dive height,recovery time, feed rate, travel speed, max probes & tolerance when probing multiple times
Line 118: G31 K0 P500 X0 Y0 Z-1.170                                                      ; Set Z probe trigger value, offset and trigger height (higher Z value = nozzle closer to bed)

In a try to work around that i did some changes, and that just moved the issue:

Error in start-up file macro line 120: invalid Z probe index

Line 117: ;M558 K0 P8 C"^121.io2.in" H2 R0.2 F300:180 T18000 A1 S0.03                     ; Set Z probe number ,type, input pin, dive height,recovery time, feed rate, travel speed, max probes & tolerance when probing multiple times
Line 118: ;G31 K0 P500 X0 Y0 Z-1.170                                                      ; Set Z probe trigger value, offset and trigger height (higher Z value = nozzle closer to bed)
Line 119: M558 P8 C"^121.io2.in" H2 R0.2 F300:180 T18000 A1 S0.03                     ; Set Z probe number ,type, input pin, dive height,recovery time, feed rate, travel speed, max probes & tolerance when probing multiple times
Line 120: G31 P500 X0 Y0 Z-1.170                                                      ; Set Z probe trigger value, offset and trigger height (higher Z value = nozzle closer to bed)

Uhm, looks like it's something weird with the CAN communication running the mismatched firmwares. Look what it prints when i send M558 K0 P8 C"^121.io2.in" H2 R0.2 F300:180 T18000 A1 S0.03 in console:

CAN response timeout: board 121, req type 6060, RID 54

If I roll back the boards to rc2 I get rid of the probe issues. So i can try stepping back on the tool board fw from that point if you want me to? Or won't it have much value?

dc42

@Exerqtor I'm more interested in stepping the main board firmware back. Can you temporarily manage without using the Z probe? Alternatively, if the problem was easy to reproduce using rc2 then you can keep the tool board at rc2 and step the main board version back.

Exerqtor

@dc42 Aha ok, you said to revert the tool board firmware in the last post so I thought that was the one you wanted me to try

But yeah the problem comes just as easy in rc2 so i'll try it later today