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

Exerqtor

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

@Exerqtor could it be that somehow the motor current has been reduced to a low value, so that the extruder motor is capable of retracting filament but not capable of overcoming nozzle back pressure?

I have no idea where how that could happen, but it sounds like a possible cause. Weird that it wouldn't happen on 3.5.0-b4 though.

It would be helpful if you could wait for the issue to happen, then pause the print and then run some tests on the extruder:

Verify that the nozzle temperature is correct stable, and was correct when the issue first occurred. Note, if you have a Revo hot end then on early ones the temperature sensing goes wrong after a while. The good ones have blue thermistor wires, the old ones were white.

I've got the "new" 60W heater (blue thermistor wires), so that shouldn't be an issue. I haven't seen any dips / fluctuations in the temperatures either (after I got the warranty replacement for the "white wire" variant or 60w from E3D, way before these extrusion issues started). Looking at the temperature chart in DWC everything is rock solid when the issue occurres

Use M569 to check that the driver is in spread cycle mode, not stealthchop
Send M906 and M913 without parameters to check that RRF thinks it is using the correct motor current

Test extruding and retracting at slow and medium speeds, e.g. 1 to 5mm/sec.

Assuming it's not working properly try sending M906 Exxx (where xxx is the correct motor current) and M913 E100 to check whether this fixes it

I will try all thay out some time this weekend! Haven't had the time during the week.

Exerqtor

I just had time to do the testing, updated to 3.5.0-rc2 on everything, sliced one of the "doomed" models again to verify that it wasn't slicer generated (Orca Slicer 1.9.0 stable has launched since last testing), and surely it fails just like it did a month ago 🤣

Here is what you asked for @dc42, first off M122 B121 & M569 P121.0 while laying down the first layer (not paused) with everything working like it should as a "baseline":

M122 B121
Diagnostics for board 121:
Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.2 (2023-12-14 08:58:51)
Bootloader ID: SAMC21 bootloader version 2.4 (2021-12-10)
All averaging filters OK
Never used RAM 3252, free system stack 89 words
Tasks: Move(3,nWait,0.1%,75) HEAT(2,nWait,16.8%,97) CanAsync(5,nWait,0.0%,54) CanRecv(3,nWait,0.5%,77) CanClock(5,nWait,0.8%,67) ACCEL(3,nWait,0.0%,53) TMC(2,nWait,136.3%,57) MAIN(1,running,616.0%,316) IDLE(0,ready,0.0%,27) AIN(2,delaying,215.9%,114), total 986.4%
Last reset 08:07:59 ago, cause: power up
Last software reset data not available
Driver 0: pos 0, 568.8 steps/mm, ok, SG min 0, read errors 0, write errors 0, ifcnt 12, reads 24943, writes 12, timeouts 3, DMA errors 0, CC errors 0, failedOp 0x6f, steps req 0 done 106290
Moves scheduled 718, completed 716, in progress 1, hiccups 0, segs 14, step errors 0, maxLate 1 maxPrep 320, maxOverdue 1, maxInc 1, mcErrs 0, gcmErrs 0, ebfmin 0.00 max 1.00
Peak sync jitter -2/10, peak Rx sync delay 218, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.3, current 24.1, max 24.4
MCU temperature: min 37.8C, current 55.1C, max 55.1C
Last sensors broadcast 0x00000012 found 2 166 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 600447, send timeouts 0, received 264383, 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 332, adv 35999/109737
Accelerometer: LIS3DH, status: 00
Inductive sensor: not found
I2C bus errors 0, naks 6, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 4 to 1470us
Driver 0: ok

M569 P121.0
Driver 121.0 runs in reverse, active low enable, mode spreadCycle, ccr 0x00053, toff 3, tblank 0, hstart/hend/hdec 5/0/0, pos 448

And then we have M122 B121 & M569 P121.0 taken while the issue is occurring (not paused):

M122 B121
Diagnostics for board 121:
Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.2 (2023-12-14 08:58:51)
Bootloader ID: SAMC21 bootloader version 2.4 (2021-12-10)
All averaging filters OK
Never used RAM 2724, free system stack 89 words
Tasks: Move(3,nWait,0.3%,71) HEAT(2,nWait,0.4%,97) CanAsync(5,nWait,0.0%,54) CanRecv(3,nWait,0.1%,77) CanClock(5,nWait,0.0%,67) ACCEL(3,nWait,0.0%,53) TMC(2,nWait,3.1%,57) MAIN(1,running,91.2%,316) IDLE(0,ready,0.0%,27) AIN(2,delaying,4.9%,114), total 100.0%
Last reset 08:11:58 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 12, reads 53546, writes 0, timeouts 0, DMA errors 0, CC errors 0, steps req 0 done 282853
Moves scheduled 2822, completed 2822, in progress 0, hiccups 3, segs 36, step errors 0, maxLate 1 maxPrep 833, maxOverdue 3250, maxInc 3250, mcErrs 0, gcmErrs 0, ebfmin -0.96 max inf
Peak sync jitter -2/10, peak Rx sync delay 226, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.9, current 24.0, max 24.3
MCU temperature: min 37.8C, current 56.7C, max 56.9C
Last sensors broadcast 0x00000012 found 2 25 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 4935, send timeouts 0, received 5351, 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 350, adv 36140/74649
Accelerometer: LIS3DH, status: 00
Inductive sensor: not found
I2C bus errors 0, naks 0, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 9 to 1550us
Driver 0: ok

M569 P121.0
Driver 121.0 runs in reverse, active low enable, mode spreadCycle, ccr 0x00053, toff 3, tblank 0, hstart/hend/hdec 5/0/0, pos 168

~~@Exerqtor could it be that somehow the motor current has been reduced to a low value, so that the extruder motor is capable of retracting filament but not capable of overcoming nozzle back pressure?~~

It would be helpful if you could wait for the issue to happen, then pause the print and then run some tests on the extruder:

Verify that the nozzle temperature is correct stable, and was correct when the issue first occurred. Note, if you have a Revo hot end then on early ones the temperature sensing goes wrong after a while. The good ones have blue thermistor wires, the old ones were white.

Screenshot of the temperature chart during warmup, working print & failing print:
alt text
So i would say that's sufficiently stable😄

~~Use M569 to check that the driver is in spread cycle mode, not stealthchop~~

~~Answered above.~~

Send M906 and M913 without parameters to check that RRF thinks it is using the correct motor current

Before pausing while issue is occuring:

M906
Motor current (mA) - X:1750, Y:1750, Z:850, E:650, idle factor 40%

M913
Motor current % of normal - X:100, Y:100, Z:100, E:100

After pausing while issue is occuring:

M906
Motor current (mA) - X:1750, Y:1750, Z:850, E:650, idle factor 40%

M913
Motor current % of normal - X:100, Y:100, Z:100, E:100

Test extruding and retracting at slow and medium speeds, e.g. 1 to 5mm/sec.

Tried extruding 100mm @ 1mm/sec through paneldue while paused : no issues
Tried extruding 100mm @ 5mm/sec through paneldue while paused : no issues

~~Assuming it's not working properly try sending M906 Exxx (where xxx is the correct motor current) and M913 E100 to check whether this fixes it~~

So yeah, that's that 😂

Exerqtor

@dc42 I suspect that didn't give you any more clues as to whats going on? 😓

Exerqtor

@dc42
I just ran the same job file/test after installing 3.5.0-rc3 and it still fails in the same exact manner.

I was touching/feeling the filament right as it enters the PTFE tube as the print progressed, and it stopped pulling it in right about at the 0.65mm (Z-axis height) mark.

Here is a link to the file (same as my previous post just for clarity).

M122 B121 & M569 P121.0 while laying down the first layer (not paused) with everything working like it should:

M122 B121
Diagnostics for board 121:
Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.3 (2024-01-24 17:55:14)
Bootloader ID: SAMC21 bootloader version 2.4 (2021-12-10)
All averaging filters OK
Never used RAM 3072, free system stack 83 words
Tasks: Move(3,nWait 7,0.0%,79) HEAT(2,nWait 6,7.3%,99) CanAsync(5,nWait 4,0.0%,49) CanRecv(3,nWait 1,0.3%,71) CanClock(5,nWait 1,0.4%,59) ACCEL(3,nWait 6,0.0%,53) TMC(2,nWait 6,67.2%,53) MAIN(1,running,97.2%,315) IDLE(0,ready,0.0%,27) AIN(2,delaying,96.9%,112), total 269.3%
Owned mutexes:
Last reset 18:26:14 ago, cause: power up
Last software reset data not available
Driver 0: pos 0, 568.8 steps/mm, ok, SG min 0, read errors 0, write errors 0, ifcnt 13, reads 26023, writes 13, timeouts 3, DMA errors 0, CC errors 0, failedOp 0x6c, steps req 0 done 83994
Moves scheduled 517, completed 516, in progress 1, hiccups 0, segs 13, step errors 0, maxLate 1 maxPrep 304, maxOverdue 1, maxInc 1, mcErrs 0, gcmErrs 0, ebfmin 0.00 max 1.00
Peak sync jitter -3/10, peak Rx sync delay 219, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.3, current 24.1, max 24.4
MCU temperature: min 34.9C, current 55.2C, max 55.2C
Last sensors broadcast 0x00000012 found 2 98 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 1360939, send timeouts 0, received 598056, 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 330, adv 35701/74648
Accelerometer: LIS3DH, status: 00
I2C bus errors 0, naks 3, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 4 to 1445us
Driver 0: ok

M569 P121.0
Driver 121.0 runs in reverse, active low enable, mode spreadCycle, ccr 0x00053, toff 3, tblank 0, hstart/hend/hdec 5/0/0, pos 267

And then we have M122 B121 & M569 P121.0 taken while the issue is occurring (not paused):

M122 B121
Diagnostics for board 121:
Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.3 (2024-01-24 17:55:14)
Bootloader ID: SAMC21 bootloader version 2.4 (2021-12-10)
All averaging filters OK
Never used RAM 2520, free system stack 83 words
Tasks: Move(3,nWait 7,0.3%,79) HEAT(2,nWait 6,0.4%,99) 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.5%,53) MAIN(1,running,90.6%,315) IDLE(0,ready,0.0%,27) AIN(2,delaying,5.1%,112), total 100.0%
Owned mutexes:
Last reset 18:30:29 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 61284, writes 0, timeouts 0, DMA errors 0, CC errors 0, steps req 0 done 304108
Moves scheduled 2820, completed 2820, in progress 0, hiccups 3, segs 36, step errors 0, maxLate 1 maxPrep 810, maxOverdue 41, maxInc 41, mcErrs 0, gcmErrs 0, ebfmin -0.98 max inf
Peak sync jitter -1/10, peak Rx sync delay 216, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.9, current 24.1, max 24.4
MCU temperature: min 34.9C, current 57.7C, max 57.7C
Last sensors broadcast 0x00000012 found 2 10 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 5254, send timeouts 0, received 5624, 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 35800/74648
Accelerometer: LIS3DH, status: 00
I2C bus errors 0, naks 0, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 9 to 1438us
Driver 0: ok

M569 P121.0
Driver 121.0 runs in reverse, active low enable, mode spreadCycle, ccr 0x00053, toff 3, tblank 0, hstart/hend/hdec 5/0/0, pos 440

Screenshot of the temperature chart during warmup, working print & failing print (to show that the temps are stable, the drop off at the end is from when i cancelled the print) :
alt text

Before pausing while issue is occuring:

M906
Motor current (mA) - X:1750, Y:1750, Z:850, E:650, idle factor 40%

M913
Motor current % of normal - X:100, Y:100, Z:100, E:100

After pausing while issue is occuring:

M906
Motor current (mA) - X:1750, Y:1750, Z:850, E:650, idle factor 40%

M913
Motor current % of normal - X:100, Y:100, Z:100, E:100

While paused this time i tried extruding 1mm at the time until it actually started coming molten platic out of the nossle and i had to press "extrude" on PD 9-10 times before anything happened. So it's surely retracting the filament a little bit at a time.

Like i mentioned earlier i'm running 0.45mm FW retraction, and my pause.g don't contain any extruder movement at all. So all the 10mm (ish) of retracted filament has happened before i call for a pause.

dc42

@Exerqtor please test whether the new firmware binaries at https://www.dropbox.com/scl/fo/p0136wx04h8xf6ejwdnn9/h?rlkey=efrfwyb6o5tqid11gustz3uvy&dl=0 fix tihi issue.

Exerqtor

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

@Exerqtor please test whether the new firmware binaries at https://www.dropbox.com/scl/fo/p0136wx04h8xf6ejwdnn9/h?rlkey=efrfwyb6o5tqid11gustz3uvy&dl=0 fix tihi issue.

Just had time to try it, and it's still the exact same behaviour.

M122 B121 & M569 P121.0 while laying down the first layer (not paused) with everything working like it should:

M122 B121
Diagnostics for board 121:
Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.3+ (2024-02-01 12:48:48)
Bootloader ID: SAMC21 bootloader version 2.4 (2021-12-10)
All averaging filters OK
Never used RAM 3048, free system stack 83 words
Tasks: Move(3,nWait 7,0.0%,79) HEAT(2,nWait 6,0.4%,99) CanAsync(5,nWait 4,0.0%,55) 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.2%,315) IDLE(0,ready,0.0%,27) AIN(2,delaying,5.0%,112), total 100.0%
Owned mutexes:
Last reset 00:12:59 ago, cause: VDD brownout
Last software reset data not available
Driver 0: pos 0, 568.8 steps/mm, ok, SG min 0, read errors 0, write errors 0, ifcnt 13, reads 61969, writes 13, timeouts 0, DMA errors 0, CC errors 0, steps req 0 done 42336
Moves scheduled 155, completed 154, in progress 1, hiccups 3, segs 12, step errors 0, maxLate 1 maxPrep 268, maxOverdue 17, maxInc 17, mcErrs 0, gcmErrs 0, ebfmin 0.00 max 0.99
Peak sync jitter -2/8, peak Rx sync delay 216, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.3, current 24.1, max 24.4
MCU temperature: min 43.5C, current 57.6C, max 57.6C
Last sensors broadcast 0x00000012 found 2 23 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 16201, send timeouts 0, received 7328, 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 328, adv 35675/74645
Accelerometer: LIS3DH, status: 00
I2C bus errors 0, naks 3, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 2 to 1474us
Driver 0: ok

M569 P121.0
Driver 121.0 runs in reverse, active low enable, mode spreadCycle, ccr 0x00053, toff 3, tblank 0, hstart/hend/hdec 5/0/0, pos 1017

And then we have M122 B121 & M569 P121.0 taken while the issue is occurring (not paused):

M122 B121
Diagnostics for board 121:
Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.3+ (2024-02-01 12:48:48)
Bootloader ID: SAMC21 bootloader version 2.4 (2021-12-10)
All averaging filters OK
Never used RAM 2472, free system stack 83 words
Tasks: Move(3,nWait 7,0.3%,79) HEAT(2,nWait 6,0.4%,99) CanAsync(5,nWait 4,0.0%,55) 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.6%,315) IDLE(0,ready,0.0%,27) AIN(2,delaying,5.1%,112), total 100.0%
Owned mutexes:
Last reset 00:17:36 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 13, reads 7102, writes 0, timeouts 0, DMA errors 0, CC errors 0, steps req 0 done 343188
Moves scheduled 2808, completed 2808, in progress 0, hiccups 29, segs 36, step errors 0, maxLate 1 maxPrep 842, maxOverdue 1, maxInc 1, mcErrs 0, gcmErrs 0, ebfmin -0.98 max inf
Peak sync jitter -1/10, peak Rx sync delay 217, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.9, current 24.0, max 24.3
MCU temperature: min 43.5C, current 59.9C, max 60.1C
Last sensors broadcast 0x00000012 found 2 148 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 5716, send timeouts 0, received 5953, 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 357, adv 36225/109301
Accelerometer: LIS3DH, status: 00
I2C bus errors 0, naks 0, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 9 to 1416us
Driver 0: ok

M569 P121.0
Driver 121.0 runs in reverse, active low enable, mode spreadCycle, ccr 0x00053, toff 3, tblank 0, hstart/hend/hdec 5/0/0, pos 776

Screenshot of the temperature chart during warmup, working print & failing print (to show that the temps are stable, the drop off at the end is from when i cancelled the print) :
alt text

dc42

@Exerqtor are you saying that when the issue occurs, the hot end stops heating and cools down?

Last reset 00:17:36 ago, cause: VDD brownout

Looks like the 1LC lost power.

Exerqtor

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

@Exerqtor are you saying that when the issue occurs, the hot end stops heating and cools down?

No nothing happens except it stops feeding filament. The cooling down part in the temp chart is from after I've cancelled the print.

I only included the temp charts to show that the temps are stable (I've updated the "caption" for the chart images on the original posts to reflect on that now).

Last reset 00:17:36 ago, cause: VDD brownout

Looks like the 1LC lost power.

That's from the reset point is from when i rebooted the mainboard after installing 3.5.0-rc3+, I've got relays on the 24v lines controlled with PS_ON.

Exerqtor

@dc42 Got any ideas for things i can do to try helping you narrowing down whats causing this?

Needless to say it renders the machine useless.

Exerqtor

@dc42 I've looked at the commits you did to 3.5-dev yesterday, are these potential solutions for this bug?

dc42

@Exerqtor yes, possibly.

Exerqtor

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

@Exerqtor yes, possibly.

Bad news then i guess, i just installed and tested the 3.5-dev build chrisham built a couple hours ago and tried a test print. And it's the exact same behaviour as before.

M122 & M122 B121 when it was extruding as it should:

2024-02-15 16:16:01 [debug] === Diagnostics ===
2024-02-15 16:16:01 [debug] RepRapFirmware for Duet 3 Mini 5+ version 3.5.0-rc.3+2 (2024-02-15 13:14:48) running on Duet 3 Mini5plus WiFi (standalone mode)
2024-02-15 16:16:01 [debug] Board ID: XNHXF-HR6KL-K65J0-409N2-K9W1Z-RV2MZ
2024-02-15 16:16:01 [debug] Used output buffers: 1 of 40 (40 max)
2024-02-15 16:16:01 [debug] === RTOS ===
2024-02-15 16:16:01 [debug] Static ram: 103264
2024-02-15 16:16:01 [debug] Dynamic ram: 128464 of which 0 recycled
2024-02-15 16:16:01 [debug] Never used RAM 5648, free system stack 139 words
2024-02-15 16:16:01 [debug] Tasks:
2024-02-15 16:16:01 [debug]  NETWORK(1,ready,15.0%,196)
2024-02-15 16:16:01 [debug]  HEAT(3,nWait 6,0.0%,330)
2024-02-15 16:16:01 [debug]  Move(4,nWait 6,0.4%,243)
2024-02-15 16:16:01 [debug]  CanReceiv(6,nWait 1,0.1%,798)
2024-02-15 16:16:01 [debug]  CanSender(5,nWait 7,0.0%,337)
2024-02-15 16:16:01 [debug]  CanClock(7,delaying,0.0%,340)
2024-02-15 16:16:01 [debug]  TMC(4,nWait 6,0.8%,68)
2024-02-15 16:16:01 [debug]  MAIN(1,running,81.8%,577)
2024-02-15 16:16:01 [debug]  IDLE(0,ready,1.0%,30)
2024-02-15 16:16:01 [debug]  AIN(4,delaying,0.9%,260)
2024-02-15 16:16:01 [debug] , total 100.0%
Owned mutexes:
2024-02-15 16:16:01 [debug]  WiFi(NETWORK)
2024-02-15 16:16:01 [debug] === Platform ===
2024-02-15 16:16:01 [debug] Last reset 00:17:18 ago, cause: software
2024-02-15 16:16:01 [debug] Last software reset at 2024-02-15 15:58, reason: User, Gcodes spinning, available RAM 12024, slot 2
2024-02-15 16:16:01 [debug] Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00000000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
2024-02-15 16:16:01 [debug] Error status: 0x04
2024-02-15 16:16:01 [debug] Aux0 errors 0,0,0
2024-02-15 16:16:01 [debug] MCU revision 3, ADC conversions started 1039400, completed 1039398, timed out 0, errs 0
2024-02-15 16:16:01 [debug] MCU temperature: min 35.1, current 46.4, max 46.7
2024-02-15 16:16:01 [debug] Supply voltage: min 2.9, current 23.9, max 24.5, under voltage events: 0, over voltage events: 0, power good: yes
2024-02-15 16:16:01 [debug] Heap OK, handles allocated/used 198/33, heap memory allocated/used/recyclable 2048/516/56, gc cycles 249
2024-02-15 16:16:01 [debug] Events: 0 queued, 0 completed
2024-02-15 16:16:01 [debug] Driver 0: standstill, SG min 0, read errors 0, write errors 0, ifcnt 46, reads 54608, writes 46, timeouts 0, DMA errors 0, CC errors 0
2024-02-15 16:16:01 [debug] Driver 1: ok, SG min 0, read errors 0, write errors 0, ifcnt 46, reads 54608, writes 46, timeouts 0, DMA errors 0, CC errors 0
2024-02-15 16:16:01 [debug] Driver 2: ok, SG min 0, read errors 0, write errors 0, ifcnt 25, reads 54628, writes 25, timeouts 0, DMA errors 0, CC errors 0
2024-02-15 16:16:01 [debug] Driver 3: ok, SG min 0, read errors 0, write errors 0, ifcnt 24, reads 54629, writes 24, timeouts 0, DMA errors 0, CC errors 0
2024-02-15 16:16:01 [debug] Driver 4: ok, SG min 0, read errors 0, write errors 0, ifcnt 25, reads 54629, writes 25, timeouts 0, DMA errors 0, CC errors 0
2024-02-15 16:16:01 [debug] Driver 5: not present
2024-02-15 16:16:01 [debug] Driver 6: not present
2024-02-15 16:16:01 [debug] Date/time: 
2024-02-15 16:16:01 [debug] 2024-02-15 16:16:01
2024-02-15 16:16:01 [debug] Cache data hit count 1679802919
2024-02-15 16:16:01 [debug] Slowest loop: 219.43ms; fastest: 0.09ms
2024-02-15 16:16:01 [debug] === Storage ===
Free file entries: 16
2024-02-15 16:16:01 [debug] SD card 0 detected, interface speed: 22.5MBytes/sec
2024-02-15 16:16:01 [debug] SD card longest read time 7.5ms, write time 4.6ms, max retries 0
2024-02-15 16:16:01 [debug] === Move ===
DMs created 83, segments created 16, maxWait 400258ms, 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
2024-02-15 16:16:01 [debug] next step interrupt due in 19 ticks, enabled
2024-02-15 16:16:01 [debug] Moves shaped first try 68, on retry 0, too short 25, wrong shape 1411, maybepossible 4
2024-02-15 16:16:01 [debug] === DDARing 0 ===
Scheduled moves 1676, completed 1654, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 1], CDDA state 3
2024-02-15 16:16:01 [debug] === DDARing 1 ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
2024-02-15 16:16:01 [debug] === Heat ===
2024-02-15 16:16:01 [debug] Bed heaters 0 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
2024-02-15 16:16:01 [debug] Heater 0 is on, I-accum = 0.5
2024-02-15 16:16:01 [debug] Heater 1 is on, I-accum = 0.0
2024-02-15 16:16:01 [debug] === GCodes ===
2024-02-15 16:16:01 [debug] Movement locks held by null, null
2024-02-15 16:16:01 [debug] HTTP is idle in state(s) 0
2024-02-15 16:16:01 [debug] Telnet is idle in state(s) 0
2024-02-15 16:16:01 [debug] File is idle in state(s) 3
2024-02-15 16:16:01 [debug] USB is idle in state(s) 0
2024-02-15 16:16:01 [debug] Aux is idle in state(s) 0
2024-02-15 16:16:01 [debug] Trigger is idle in state(s) 0
2024-02-15 16:16:01 [debug] Queue is idle in state(s) 0
2024-02-15 16:16:01 [debug] LCD is idle in state(s) 0
2024-02-15 16:16:01 [debug] SBC is idle in state(s) 0
2024-02-15 16:16:01 [debug] Daemon is doing "G4 P250" in state(s) 0 0, running macro
2024-02-15 16:16:01 [debug] Aux2 is idle in state(s) 0
2024-02-15 16:16:01 [debug] Autopause is idle in state(s) 0
2024-02-15 16:16:01 [debug] File2 is idle in state(s) 0, sync state 1
2024-02-15 16:16:01 [debug] Queue2 is idle in state(s) 0
2024-02-15 16:16:01 [debug] Q0 segments left 4, axes/extruders owned 0x0000807
2024-02-15 16:16:01 [debug] Code queue 0 is empty
2024-02-15 16:16:01 [debug] Q1 segments left 0, axes/extruders owned 0x0000000
2024-02-15 16:16:01 [debug] Code queue 1 is empty
2024-02-15 16:16:01 [debug] === Filament sensors ===
check 0 clear 0
2024-02-15 16:16:01 [debug] Extruder 0 sensor: no filament
2024-02-15 16:16:01 [debug] === CAN ===
2024-02-15 16:16:01 [debug] Messages queued 10994, received 21506, lost 0, errs 1229, boc 0
2024-02-15 16:16:01 [debug] Longest wait 2ms for reply type 6031, peak Tx sync delay 45006, free buffers 26 (min 25), ts 5195/5193/0
2024-02-15 16:16:01 [debug] Tx timeouts 0,0,1,0,0,0 last cancelled message type 30 dest 127
2024-02-15 16:16:01 [debug] === Network ===
2024-02-15 16:16:01 [debug] Slowest loop: 13.08ms; fastest: 0.00ms
2024-02-15 16:16:01 [debug] Responder states:
2024-02-15 16:16:01 [debug]  MQTT(0)
2024-02-15 16:16:01 [debug]  HTTP(2)
2024-02-15 16:16:01 [debug]  HTTP(0)
2024-02-15 16:16:01 [debug]  HTTP(0)
2024-02-15 16:16:01 [debug]  HTTP(0)
2024-02-15 16:16:01 [debug]  FTP(0)
2024-02-15 16:16:01 [debug]  Telnet(0)
2024-02-15 16:16:01 [debug] HTTP sessions: 1 of 8
2024-02-15 16:16:01 [debug] === WiFi ===
Interface state: active
Module is connected to access point 
Failed messages: pending 0, notrdy 0, noresp 0
2024-02-15 16:16:01 [debug] Firmware version 2.1beta6
2024-02-15 16:16:01 [debug] MAC address c4:5b:be:ce:91:93
2024-02-15 16:16:01 [debug] Module reset reason: Power up, Vcc 3.38, flash size 2097152, free heap 36456
2024-02-15 16:16:01 [debug] WiFi IP address 192.168.10.x
2024-02-15 16:16:01 [debug] Signal strength -48dBm, channel 6, mode 802.11n, reconnections 0
2024-02-15 16:16:01 [debug] Clock register 00002001
2024-02-15 16:16:01 [debug] Socket states:
2024-02-15 16:16:01 [debug]  0
2024-02-15 16:16:01 [debug]  0
2024-02-15 16:16:01 [debug]  0
2024-02-15 16:16:01 [debug]  0
2024-02-15 16:16:01 [debug]  0
2024-02-15 16:16:01 [debug]  0
2024-02-15 16:16:01 [debug]  0
2024-02-15 16:16:01 [debug]  0
2024-02-15 16:16:04 [debug] Diagnostics for board 121:
2024-02-15 16:16:04 [debug] Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.3+ (2024-02-15 13:22:28)
Bootloader ID: SAMC21 bootloader version 2.4 (2021-12-10)
All averaging filters OK
2024-02-15 16:16:04 [debug] Never used RAM 3608, free system stack 87 words
Tasks: Move(3,nWait 7,0.0%,91) HEAT(2,nWait 6,0.4%,99) CanAsync(5,nWait 4,0.0%,51) CanRecv(3,nWait 1,0.0%,73) CanClock(5,nWait 1,0.0%,61) ACCEL(3,nWait 6,0.0%,53) TMC(2,nWait 6,3.4%,53) MAIN(1,running,91.2%,317) IDLE(0,ready,0.0%,27) AIN(2,delaying,4.9%,112), total 100.0%
Owned mutexes:
Last reset 00:17:21 ago, cause: power up
2024-02-15 16:16:04 [debug] Last software reset data not available
2024-02-15 16:16:04 [debug] Driver 0: pos 0, 568.8 steps/mm, ok, SG min 0, read errors 0, write errors 0, ifcnt 12, reads 61756, writes 12, timeouts 0, DMA errors 0, CC errors 0, steps req 0 done 221092
2024-02-15 16:16:04 [debug] Moves scheduled 1506, completed 1505, in progress 1, hiccups 8, segs 18, step errors 0, maxLate 0 maxPrep 296, maxOverdue 44, maxInc 44, mcErrs 0, gcmErrs 0, ebfmin 0.00 max 1.00
Peak sync jitter -2/9, peak Rx sync delay 214, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.3, current 24.1, max 24.4
MCU temperature: min 39.7C, current 55.6C, max 55.6C
2024-02-15 16:16:04 [debug] Last sensors broadcast 0x00000012 found 2 1 ticks ago, 0 ordering errs, loop time 1
CAN messages queued 21590, send timeouts 0, received 11048, 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 338, adv 35679/105203
2024-02-15 16:16:04 [debug] Accelerometer: LIS3DH, status: 00
I2C bus errors 0, naks 3, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 4 to 1481us
Driver 0: ok

M122 & M122 B121 when it had stopped extruding:

2024-02-15 16:18:11 [debug] === Diagnostics ===
2024-02-15 16:18:11 [debug] RepRapFirmware for Duet 3 Mini 5+ version 3.5.0-rc.3+2 (2024-02-15 13:14:48) running on Duet 3 Mini5plus WiFi (standalone mode)
2024-02-15 16:18:11 [debug] Board ID: XNHXF-HR6KL-K65J0-409N2-K9W1Z-RV2MZ
2024-02-15 16:18:11 [debug] Used output buffers: 1 of 40 (40 max)
2024-02-15 16:18:11 [debug] === RTOS ===
2024-02-15 16:18:11 [debug] Static ram: 103264
2024-02-15 16:18:11 [debug] Dynamic ram: 128464 of which 0 recycled
2024-02-15 16:18:11 [debug] Never used RAM 5120, free system stack 139 words
2024-02-15 16:18:11 [debug] Tasks:
2024-02-15 16:18:11 [debug]  NETWORK(1,ready,17.5%,196)
2024-02-15 16:18:11 [debug]  HEAT(3,nWait 6,0.0%,330)
2024-02-15 16:18:11 [debug]  Move(4,nWait 6,2.4%,242)
2024-02-15 16:18:11 [debug]  CanReceiv(6,nWait 1,0.1%,798)
2024-02-15 16:18:11 [debug]  CanSender(5,nWait 7,0.0%,337)
2024-02-15 16:18:11 [debug]  CanClock(7,delaying,0.0%,340)
2024-02-15 16:18:11 [debug]  TMC(4,nWait 6,0.9%,68)
2024-02-15 16:18:11 [debug]  MAIN(1,running,77.2%,577)
2024-02-15 16:18:11 [debug]  IDLE(0,ready,0.9%,30)
2024-02-15 16:18:11 [debug]  AIN(4,delaying,0.9%,260)
2024-02-15 16:18:11 [debug] , total 100.0%
Owned mutexes:
2024-02-15 16:18:11 [debug] === Platform ===
2024-02-15 16:18:11 [debug] Last reset 00:19:29 ago, cause: software
2024-02-15 16:18:11 [debug] Last software reset at 2024-02-15 15:58, reason: User, Gcodes spinning, available RAM 12024, slot 2
2024-02-15 16:18:11 [debug] Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00000000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
2024-02-15 16:18:11 [debug] Error status: 0x04
2024-02-15 16:18:11 [debug] Aux0 errors 0,0,0
2024-02-15 16:18:11 [debug] MCU revision 3, ADC conversions started 1169660, completed 1169659, timed out 0, errs 0
2024-02-15 16:18:11 [debug] MCU temperature: min 46.0, current 46.4, max 46.6
2024-02-15 16:18:11 [debug] Supply voltage: min 23.7, current 23.7, max 24.3, under voltage events: 0, over voltage events: 0, power good: yes
2024-02-15 16:18:11 [debug] Heap OK, handles allocated/used 198/33, heap memory allocated/used/recyclable 2048/708/248, gc cycles 277
2024-02-15 16:18:11 [debug] Events: 0 queued, 0 completed
2024-02-15 16:18:11 [debug] Driver 0: ok, SG min 0, read errors 0, write errors 0, ifcnt 46, reads 6852, writes 0, timeouts 0, DMA errors 0, CC errors 0
2024-02-15 16:18:11 [debug] Driver 1: ok, SG min 0, read errors 0, write errors 0, ifcnt 46, reads 6852, writes 0, timeouts 0, DMA errors 0, CC errors 0
2024-02-15 16:18:11 [debug] Driver 2: ok, SG min 0, read errors 0, write errors 0, ifcnt 25, reads 6853, writes 0, timeouts 0, DMA errors 0, CC errors 0
2024-02-15 16:18:11 [debug] Driver 3: ok, SG min 0, read errors 0, write errors 0, ifcnt 24, reads 6852, writes 0, timeouts 0, DMA errors 0, CC errors 0
2024-02-15 16:18:11 [debug] Driver 4: ok, SG min 0, read errors 0, write errors 0, ifcnt 25, reads 6853, writes 0, timeouts 0, DMA errors 0, CC errors 0
2024-02-15 16:18:11 [debug] Driver 5: not present
2024-02-15 16:18:11 [debug] Driver 6: not present
2024-02-15 16:18:11 [debug] Date/time: 
2024-02-15 16:18:11 [debug] 2024-02-15 16:18:11
2024-02-15 16:18:11 [debug] Cache data hit count 1862287218
2024-02-15 16:18:11 [debug] Slowest loop: 40.78ms; fastest: 0.14ms
2024-02-15 16:18:11 [debug] === Storage ===
Free file entries: 16
2024-02-15 16:18:11 [debug] SD card 0 detected, interface speed: 22.5MBytes/sec
2024-02-15 16:18:11 [debug] SD card longest read time 9.1ms, write time 4.8ms, max retries 0
2024-02-15 16:18:11 [debug] === Move ===
DMs created 83, segments created 38, maxWait 852ms, 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
2024-02-15 16:18:11 [debug] next step interrupt due in 26 ticks, enabled
2024-02-15 16:18:11 [debug] Moves shaped first try 267, on retry 62, too short 102, wrong shape 1241, maybepossible 57
2024-02-15 16:18:11 [debug] === DDARing 0 ===
Scheduled moves 4017, completed 3977, hiccups 0, stepErrors 0, LaErrors 2, Underruns [0, 0, 0], CDDA state 3
2024-02-15 16:18:11 [debug] === DDARing 1 ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
2024-02-15 16:18:11 [debug] === Heat ===
2024-02-15 16:18:11 [debug] Bed heaters 0 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
2024-02-15 16:18:11 [debug] Heater 0 is on, I-accum = 0.5
2024-02-15 16:18:11 [debug] Heater 1 is on, I-accum = 0.0
2024-02-15 16:18:11 [debug] === GCodes ===
2024-02-15 16:18:11 [debug] Movement locks held by null, null
2024-02-15 16:18:11 [debug] HTTP is idle in state(s) 0
2024-02-15 16:18:11 [debug] Telnet is idle in state(s) 0
2024-02-15 16:18:11 [debug] File is doing "G1 X213.608 Y214.933 E.00193" in state(s) 0
2024-02-15 16:18:11 [debug] USB is idle in state(s) 0
2024-02-15 16:18:11 [debug] Aux is idle in state(s) 0
2024-02-15 16:18:11 [debug] Trigger is idle in state(s) 0
2024-02-15 16:18:11 [debug] Queue is idle in state(s) 0
2024-02-15 16:18:11 [debug] LCD is idle in state(s) 0
2024-02-15 16:18:11 [debug] SBC is idle in state(s) 0
2024-02-15 16:18:11 [debug] Daemon is doing "G4 P250" in state(s) 0 0, running macro
2024-02-15 16:18:11 [debug] Aux2 is idle in state(s) 0
2024-02-15 16:18:11 [debug] Autopause is idle in state(s) 0
2024-02-15 16:18:11 [debug] File2 is idle in state(s) 0, sync state 1
2024-02-15 16:18:11 [debug] Queue2 is idle in state(s) 0
2024-02-15 16:18:11 [debug] Q0 segments left 1, axes/extruders owned 0x0000807
2024-02-15 16:18:11 [debug] Code queue 0 is empty
2024-02-15 16:18:11 [debug] Q1 segments left 0, axes/extruders owned 0x0000000
2024-02-15 16:18:11 [debug] Code queue 1 is empty
2024-02-15 16:18:11 [debug] === Filament sensors ===
check 0 clear 0
2024-02-15 16:18:11 [debug] Extruder 0 sensor: no filament
2024-02-15 16:18:11 [debug] === CAN ===
2024-02-15 16:18:11 [debug] Messages queued 3206, received 2701, lost 0, errs 0, boc 0
2024-02-15 16:18:11 [debug] Longest wait 6ms for reply type 6024, peak Tx sync delay 9, free buffers 26 (min 25), ts 651/651/0
2024-02-15 16:18:11 [debug] Tx timeouts 0,0,0,0,0,0
2024-02-15 16:18:11 [debug] === Network ===
2024-02-15 16:18:11 [debug] Slowest loop: 19.53ms; fastest: 0.06ms
2024-02-15 16:18:11 [debug] Responder states:
2024-02-15 16:18:11 [debug]  MQTT(0)
2024-02-15 16:18:11 [debug]  HTTP(0)
2024-02-15 16:18:11 [debug]  HTTP(0)
2024-02-15 16:18:11 [debug]  HTTP(0)
2024-02-15 16:18:11 [debug]  HTTP(0)
2024-02-15 16:18:11 [debug]  FTP(0)
2024-02-15 16:18:11 [debug]  Telnet(0)
2024-02-15 16:18:11 [debug] HTTP sessions: 1 of 8
2024-02-15 16:18:11 [debug] === WiFi ===
Interface state: active
Module is connected to access point 
Failed messages: pending 0, notrdy 0, noresp 0
2024-02-15 16:18:11 [debug] Firmware version 2.1beta6
2024-02-15 16:18:11 [debug] MAC address c4:5b:be:ce:91:93
2024-02-15 16:18:11 [debug] Module reset reason: Power up, Vcc 3.38, flash size 2097152, free heap 43160
2024-02-15 16:18:11 [debug] WiFi IP address 192.168.10.x
2024-02-15 16:18:11 [debug] Signal strength -49dBm, channel 6, mode 802.11n, reconnections 0
2024-02-15 16:18:11 [debug] Clock register 00002001
2024-02-15 16:18:11 [debug] Socket states:
2024-02-15 16:18:11 [debug]  0
2024-02-15 16:18:11 [debug]  0
2024-02-15 16:18:11 [debug]  0
2024-02-15 16:18:11 [debug]  0
2024-02-15 16:18:11 [debug]  0
2024-02-15 16:18:11 [debug]  0
2024-02-15 16:18:11 [debug]  0
2024-02-15 16:18:11 [debug]  0
2024-02-15 16:18:14 [debug] Diagnostics for board 121:
2024-02-15 16:18:14 [debug] Duet TOOL1LC rev 1.1 or later firmware version 3.5.0-rc.3+ (2024-02-15 13:22:28)
Bootloader ID: SAMC21 bootloader version 2.4 (2021-12-10)
All averaging filters OK

(Had to grab them from the debug file because DWC disconnected and i lost the console printout).

dc42

@Exerqtor thanks for testing this again. I'm puzzles that ebfmax is showing as zero in the Move section of both M122 reports. After doing some printing, it's normally close to 1.0.

Exerqtor

@dc42 No problem, yeah i have no idea what could be the cause 😓

Exerqtor

@dc42 i saw you added some more debug features for the expansionboard firmware on friday, do you have a build with that i could try to run? Or do you need to put some more things in it first?

dc42

@Exerqtor you are very welcome to try the new Duet 3 Mini TOOL1LC and files at https://www.dropbox.com/scl/fo/p0136wx04h8xf6ejwdnn9/h?rlkey=efrfwyb6o5tqid11gustz3uvy&dl=0. The changes clear up some issues I was having with debug output, caused by variables that were output even when they should not have been used in the current context. I don't think they should change the printing behaviour, but I could be wrong.

Exerqtor

@dc42 I'll try it this evening, maybe it will give some more insight into whats causing the stops (one might hope).

dc42

@Exerqtor please use the updated (this morning) main board file from there too.

Exerqtor

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

@Exerqtor please use the updated (this morning) main board file from there too.

Just had time to install and test those binaries, and the behaviour is the same (as expected), here are the treports:

Extruding as normal:

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.5.0-rc.3+ (2024-02-19 14:31:40) running on Duet 3 Mini5plus WiFi (standalone mode)
Board ID: XNHXF-HR6KL-K65J0-409N2-K9W1Z-RV2MZ
Used output buffers: 13 of 40 (38 max)
=== RTOS ===
Static ram: 103264
Dynamic ram: 128464 of which 0 recycled
Never used RAM 5696, free system stack 135 words
Tasks: NETWORK(1,ready,104.7%,234) HEAT(3,nWait 6,0.4%,326) Move(4,nWait 6,0.1%,241) CanReceiv(6,nWait 1,0.9%,771) CanSender(5,nWait 7,0.0%,337) CanClock(7,delaying,0.1%,340) TMC(4,nWait 6,14.1%,68) MAIN(1,running,76.0%,591) IDLE(0,ready,13.8%,30) AIN(4,delaying,14.6%,260), total 224.8%
Owned mutexes:
=== Platform ===
Last reset 21:57:15 ago, cause: software
Last software reset at 2024-02-19 18:20, reason: User, Gcodes spinning, available RAM 12072, 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 79036613, completed 79036613, timed out 0, errs 0
MCU temperature: min 33.2, current 40.4, max 40.4
Supply voltage: min 2.9, current 24.1, 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 2048/1668/1208, gc cycles 17303
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, read errors 0, write errors 0, ifcnt 31, reads 30953, 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 30953, writes 31, timeouts 0, DMA errors 0, CC errors 0
Driver 2: ok, SG min 0, read errors 0, write errors 0, ifcnt 20, reads 30963, writes 20, timeouts 0, DMA errors 0, CC errors 0
Driver 3: ok, SG min 0, read errors 0, write errors 0, ifcnt 20, reads 30963, writes 20, timeouts 0, DMA errors 0, CC errors 0
Driver 4: ok, SG min 0, read errors 0, write errors 0, ifcnt 21, reads 30963, writes 21, timeouts 0, DMA errors 0, CC errors 0
Driver 5: not present
Driver 6: not present
Date/time: 2024-02-20 16:18:00
Cache data hit count 4294967295
Slowest loop: 222.67ms; fastest: 0.09ms
=== Storage ===
Free file entries: 16
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 6.5ms, write time 7.6ms, max retries 0
=== Move ===
DMs created 83, segments created 14, maxWait 78892045ms, 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 42 ticks, enabled
Moves shaped first try 45, on retry 0, too short 4, wrong shape 270, maybepossible 1
=== DDARing 0 ===
Scheduled moves 466, completed 429, 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.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 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 5, 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 711746, received 1620463, lost 0, errs 1232, boc 0
Longest wait 4ms for reply type 6013, peak Tx sync delay 45480, free buffers 26 (min 25), ts 395179/395177/0
Tx timeouts 0,0,1,0,0,0 last cancelled message type 30 dest 127
=== Network ===
Slowest loop: 11.33ms; 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 42848
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-15 13:22:28)
Bootloader ID: SAMC21 bootloader version 2.4 (2021-12-10)
All averaging filters OK
Never used RAM 3728, free system stack 95 words
Tasks: Move(3,nWait 7,0.0%,91) HEAT(2,nWait 6,6.4%,99) CanAsync(5,nWait 4,0.0%,49) CanRecv(3,nWait 1,0.2%,73) CanClock(5,nWait 1,0.4%,61) ACCEL(3,nWait 6,0.0%,53) TMC(2,nWait 6,58.7%,53) MAIN(1,running,74.2%,317) IDLE(0,ready,0.0%,27) AIN(2,delaying,84.7%,112), total 224.6%
Owned mutexes:
Last reset 21:57:20 ago, cause: power up
Last software reset data not available
Driver 0: pos 0, 568.8 steps/mm, ok, SG min 0, read errors 0, write errors 0, ifcnt 12, reads 1875, writes 12, timeouts 6, DMA errors 0, CC errors 0, failedOp 0x72, steps req 0 done 60570
Moves scheduled 315, completed 314, in progress 1, hiccups 7, segs 13, step errors 0, maxLate 0 maxPrep 279, maxOverdue 35, maxInc 27, mcErrs 0, gcmErrs 0, ebfmin 0.00 max 1.00
Peak sync jitter -3/10, peak Rx sync delay 221, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.3, current 24.0, max 24.4
MCU temperature: min 38.5C, current 48.5C, max 48.5C
Last sensors broadcast 0x00000012 found 2 62 ticks ago, 0 ordering errs, loop time 1
CAN messages queued 1620552, send timeouts 0, received 711820, 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 325, adv 35688/74645
Accelerometer: LIS3DH, status: 00
I2C bus errors 0, naks 3, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 2 to 1440us
Driver 0: ok

Not extruding:

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.5.0-rc.3+ (2024-02-19 14:31:40) running on Duet 3 Mini5plus WiFi (standalone mode)
Board ID: XNHXF-HR6KL-K65J0-409N2-K9W1Z-RV2MZ
Used output buffers: 13 of 40 (39 max)
=== RTOS ===
Static ram: 103264
Dynamic ram: 128464 of which 0 recycled
Never used RAM 5120, free system stack 134 words
Tasks: NETWORK(1,ready,17.4%,234) HEAT(3,nWait 6,0.0%,326) Move(4,nWait 6,2.4%,241) CanReceiv(6,nWait 1,0.1%,771) CanSender(5,nWait 7,0.0%,337) CanClock(7,delaying,0.0%,340) TMC(4,nWait 6,0.9%,68) MAIN(1,running,77.3%,591) IDLE(0,ready,1.0%,30) AIN(4,delaying,0.9%,260), total 100.0%
Owned mutexes:
=== Platform ===
Last reset 22:01:35 ago, cause: software
Last software reset at 2024-02-19 18:20, reason: User, Gcodes spinning, available RAM 12072, 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 79296559, completed 79296558, timed out 0, errs 0
MCU temperature: min 40.2, current 46.0, max 46.6
Supply voltage: min 23.6, current 24.2, 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/484/24, gc cycles 17360
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, read errors 0, write errors 0, ifcnt 31, reads 13673, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 1: ok, SG min 0, read errors 0, write errors 0, ifcnt 31, reads 13673, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 2: ok, SG min 0, read errors 0, write errors 0, ifcnt 20, reads 13674, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 3: ok, SG min 0, read errors 0, write errors 0, ifcnt 20, reads 13674, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 4: ok, SG min 0, read errors 0, write errors 0, ifcnt 21, reads 13673, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 5: not present
Driver 6: not present
Date/time: 2024-02-20 16:22:20
Cache data hit count 4294967295
Slowest loop: 37.44ms; fastest: 0.10ms
=== Storage ===
Free file entries: 16
SD card 0 detected, interface speed: 22.5MBytes/sec
SD card longest read time 8.9ms, write time 4.5ms, max retries 0
=== Move ===
DMs created 83, segments created 38, maxWait 2730ms, 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 19 ticks, enabled
Moves shaped first try 281, on retry 62, too short 121, wrong shape 2345, maybepossible 58
=== DDARing 0 ===
Scheduled moves 3991, completed 3953, hiccups 0, stepErrors 0, LaErrors 2, 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.5
Heater 1 is on, I-accum = 0.0
=== GCodes ===
Movement locks held by File, null
HTTP is idle in state(s) 0
Telnet is idle in state(s) 0
File is doing "G11" 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 5562, received 5362, lost 0, errs 0, boc 0
Longest wait 6ms for reply type 6024, peak Tx sync delay 197, free buffers 26 (min 25), ts 1299/1299/0
Tx timeouts 0,0,0,0,0,0
=== Network ===
Slowest loop: 19.84ms; 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 -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-15 13:22:28)
Bootloader ID: SAMC21 bootloader version 2.4 (2021-12-10)
All averaging filters OK
Never used RAM 3176, free system stack 73 words
Tasks: Move(3,nWait 7,0.3%,87) HEAT(2,nWait 6,0.4%,97) CanAsync(5,nWait 4,0.0%,49) CanRecv(3,nWait 1,0.1%,73) CanClock(5,nWait 1,0.0%,61) ACCEL(3,nWait 6,0.0%,53) TMC(2,nWait 6,3.5%,53) MAIN(1,running,90.6%,317) IDLE(0,ready,0.0%,27) AIN(2,delaying,5.1%,112), total 100.0%
Owned mutexes:
Last reset 22:01:41 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 12, reads 64518, writes 0, timeouts 0, DMA errors 0, CC errors 0, steps req 0 done 324593
Moves scheduled 2815, completed 2815, in progress 0, hiccups 93, segs 36, step errors 0, maxLate 0 maxPrep 885, maxOverdue 97, maxInc 69, mcErrs 0, gcmErrs 0, ebfmin 0.00 max inf
Peak sync jitter -1/9, peak Rx sync delay 230, resyncs 0/0, no timer interrupt scheduled
VIN voltage: min 23.9, current 24.1, max 24.4
MCU temperature: min 38.5C, current 54.3C, max 54.3C
Last sensors broadcast 0x00000012 found 2 158 ticks ago, 0 ordering errs, loop time 1
CAN messages queued 5379, send timeouts 0, received 5621, 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 369, adv 36183/98932
Accelerometer: LIS3DH, status: 00
I2C bus errors 0, naks 0, contentions 0, other errors 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 9 to 1716us
Driver 0: ok

Regarding when it stops extruding, i'm 99.9% sure it is when the inner & outer walls/perimeters of layer 3/0.65mm is done and when it goes over to the other part(s) of that layer (still using the same sliced job as supplied earlinger without alterations).

dc42

@Exerqtor thanks for testing. I've tracked down a bug in the input shaping code that could result in the main board asking the tool board to apply IS to a move when it was not possible. This could be relevant to your issue. So please try the new main board firmware at https://www.dropbox.com/scl/fo/p0136wx04h8xf6ejwdnn9/h?rlkey=efrfwyb6o5tqid11gustz3uvy&dl=0.