RepRapFirmware 3.6.0-alpha.4+3 available for testing

MaxGyver

@dc42 I just had the same error as reported by @balajiramani . In my case, the error occurred during the first layer of a print job.

=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.6.0-alpha.5+1 (2024-08-31 17:51:17) running on Duet 3 MB6HC v1.01 (SBC mode)
Board ID: 0JD2M-999AL-D25S4-7J1D2-3SJ6K-T51V3
Used output buffers: 1 of 40 (18 max)
=== RTOS ===
Static ram: 135136
Dynamic ram: 96472 of which 0 recycled
Never used RAM 68768, free system stack 198 words
Tasks: SBC(2,ready,0.8%,796) HEAT(3,nWait 6,0.0%,369) Move(4,nWait 6,0.0%,333) TMC(4,nWait 6,2.8%,353) CanReceiv(6,nWait 1,0.1%,794) CanSender(5,nWait 7,0.0%,334) CanClock(7,delaying,0.0%,353) MAIN(2,running,93.9%,440) IDLE(0,ready,2.4%,29), total 100.0%
Owned mutexes: HTTP(MAIN)
=== Platform ===
Last reset 00:00:37 ago, cause: software
Last software reset at 2024-09-18 18:45, reason: User, Expansion spinning, available RAM 65064, slot 0
Software reset code 0x6012 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0x00000000 SP 0x00000000 Task SBC Freestk 0 n/a
Error status: 0x00
MCU temperature: min 33.9, current 34.3, max 34.5
Supply voltage: min 22.7, current 23.5, max 23.6, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.1, current 12.1, max 12.1, under voltage events: 0
Heap OK, handles allocated/used 99/4, heap memory allocated/used/recyclable 2048/88/40, gc cycles 0
Events: 0 queued, 0 completed
Date/time: 2024-09-18 18:46:21
Slowest loop: 25.07ms; fastest: 0.07ms
=== Storage ===
Free file entries: 20
SD card 0 not detected, interface speed: 37.5MBytes/sec
SD card longest read time 0.0ms, write time 0.0ms, max retries 0
=== Move ===
Segments created 0, maxWait 0ms, bed comp in use: none, height map offset 0.000, hiccups added 0 (0.00/0.00ms), max steps late 0, ebfmin 0.00, ebfmax 0.00
Pos req/act/dcf: 0.00/0/0.00 0.00/0/0.00 0.00/0/0.00
next step interrupt due in 297 ticks, disabled
Driver 0: standstill, SG min n/a, mspos 8, reads 8720, writes 11 timeouts 0
Driver 1: standstill, SG min n/a, mspos 8, reads 8720, writes 11 timeouts 0
Driver 2: standstill, SG min n/a, mspos 8, reads 8720, writes 11 timeouts 0
Driver 3: standstill, SG min n/a, mspos 8, reads 8720, writes 11 timeouts 0
Driver 4: standstill, SG min n/a, mspos 8, reads 8720, writes 11 timeouts 0
Driver 5: standstill, SG min n/a, mspos 8, reads 8720, writes 11 timeouts 0
Phase step loop runtime (us): min=0, max=2, frequency (Hz): min=1913, max=2089
=== DDARing 0 ===
Scheduled moves 0, completed 0, LaErrors 0, Underruns [0, 0, 0]
=== DDARing 1 ===
Scheduled moves 0, completed 0, LaErrors 0, Underruns [0, 0, 0]
=== Heat ===
Bed heaters -1 -1 -1 -1 -1 -1 -1 -1 -1 -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 doing "M122" 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
File2 is idle in state(s) 0
Queue2 is idle in state(s) 0
Q0 segments left 0, axes/extruders owned 0x80000003
Code queue 0 is empty
Q1 segments left 0, axes/extruders owned 0x0000000
Code queue 1 is empty
=== Filament sensors ===
check 0 clear 0
Extruder 0 sensor: no filament
=== CAN ===
Messages queued 252, received 2403, lost 0, ignored 0, errs 315, boc 0
Longest wait 55ms for reply type 6041, peak Tx sync delay 50472, free buffers 50 (min 49), ts 187/186/0
Tx timeouts 0,0,0,0,0,0
=== SBC interface ===
Transfer state: 5, failed transfers: 0, checksum errors: 0
RX/TX seq numbers: 1854/1854
SPI underruns 0, overruns 0
State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x2858c
Buffer RX/TX: 0/0-0, open files: 0
=== Duet Control Server ===
Duet Control Server version 3.5.2 (2024-06-12 07:09:26, 32-bit)
HTTP+Executed:
> Executing M122
Code buffer space: 4096
Configured SPI speed: 8000000Hz, TfrRdy pin glitches: 0
Full transfers per second: 60.06, max time between full transfers: 125.2ms, max pin wait times: 33.5ms/14.1ms
Codes per second: 2.94
Maximum length of RX/TX data transfers: 4476/1040

dc42

@MaxGyver is it repeatable? If so then please post your config.g file and the GCode file.

balajiramani

@dc42 I was wondering when we might a fix for this issue? I really like the quality of the prints with 3.6 and hence don't want to downgrade, but can't start a long print because of the step timing error.

dc42

@balajiramani I'll need to either find a reproducible test case, or add some debug to get more information when this fault occurs.

balajiramani

@dc42 Understand. Let me know if I can help in any way.

OwenD

I have just had the same error about 3 hours into a 5 hour print.

22/09/2024, 1:55:16 pm 	Error: Movement halted because a step timing error occurred (code 3). Please reset the controller.

Duet 2 WiFi 3.6.0-alpha.5+1

M122 after error

M122
=== Diagnostics ===
RepRapFirmware for Duet 2 WiFi/Ethernet version 3.6.0-alpha.5+1 (2024-08-31 17:50:58) running on Duet WiFi 1.02 or later
Board ID: 08DGM-917NK-F2MS4-7J1DA-3S86T-TZTWD
Used output buffers: 7 of 26 (24 max)
=== RTOS ===
Static ram: 23360
Dynamic ram: 72224 of which 12 recycled
Never used RAM 8368, free system stack 106 words
Tasks: NETWORK(2,nWait 6,16.3%,202) ACCEL(6,nWait 5,0.0%,345) HEAT(3,nWait 5,0.1%,315) Move(4,invalid,3.3%,266) MAIN(1,running,79.8%,672) IDLE(0,ready,0.5%,29), total 100.0%
Owned mutexes:
=== Platform ===
Last reset 05:49:08 ago, cause: software
Last software reset time unknown, reason: User, Gcodes spinning, available RAM 19896, slot 1
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0xe000ed38 SP 0x00000000 Task MAIN Freestk 0 n/a
Error status: 0x08
Aux0 errors 0,2,0
MCU temperature: min 23.6, current 31.4, max 31.9
Supply voltage: min 1.1, current 24.3, max 24.6, under voltage events: 1, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 99/22, heap memory allocated/used/recyclable 2048/1704/1320, gc cycles 572
Events: 0 queued, 0 completed
Date/time: 2024-09-22 14:34:22
Slowest loop: 451.79ms; fastest: 0.13ms
I2C nak errors 0, send timeouts 0, receive timeouts 0, finishTimeouts 0, resets 0
=== Storage ===
Free file entries: 8
SD card 0 detected, interface speed: 20.0MBytes/sec
SD card longest read time 10.1ms, write time 97.4ms, max retries 0
=== Move ===
Segments created 588, maxWait 153529ms, bed comp in use: mesh, height map offset 0.000, hiccups added 276 (8.29ms), max steps late 0, ebfmin 0.00, ebfmax 0.00
Pos req/act/dcf: 6390.00/6368/0.76 14761.00/14757/0.70 40648.00/40648/0.00
no step interrupt scheduled
Driver 0: standstill, SG min n/a
Driver 1: standstill, SG min 241
Driver 2: standstill, SG min 0
Driver 3: standstill, SG min 0
Driver 4: standstill, SG min 228
Driver 5: 
Driver 6: 
Driver 7: 
Driver 8: 
Driver 9: 
Driver 10: 
Driver 11: 
=== DDARing 0 ===
Scheduled moves 1473967, completed 1473965, LaErrors 0, Underruns [9, 0, 0]
=== 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.3
=== GCodes ===
Movement locks held by null
HTTP is idle in state(s) 0
Telnet is idle in state(s) 0
File is doing "G1 X80.404 Y147.896 E.00085" 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
Daemon is doing "G4 S2" in state(s) 0 0, running macro
Autopause is idle in state(s) 0
Q0 segments left 1
Code queue 0 is empty
=== Filament sensors ===
check 79464683 clear 1287376
Extruder 0 sensor: ok
=== Network ===
Slowest loop: 117.01ms; fastest: 0.00ms
Responder states: 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.1.0
MAC address bc:dd:c2:89:a0:bb
Module reset reason: Power up, Vcc 3.38, flash size 4194304, free heap 38948
WiFi IP address 192.168.1.163
Signal strength -52dBm, channel 6, mode 802.11n, reconnections 0
Clock register 00002002
Socket states: 4 5 0 0 0 0 0 0

EDIT:
Of interest to anyone testing , I think I've saved the print by turning off the power and recovering from power failure.

Kiolia

I don't have a way to reproduce yet, but I'm seeing intermittent issues that may be related to machine uptime and/or changes to stepper current settings via M906. Several times now, I have seen a problem where a new print underextrudes severely after 1) running a print to completion and then 2) changing at least one stepper current with M906. There's no sound of step loss or evidence of grinding. As before, this is a 6HC with E on a 3HC as a mixing extruder with 2 steppers at ratios 100% each. I'm running a 0.5 CHT nozzle, but cold pulls after these incidents reveal no debris, and each time I've cold-pulled and restarted the machine, all was fine.

I wouldn't be reporting this yet, except that today, after the issue repeated, I discovered that I was able to easily hand-feed filament through the extruder while it was tensioned, which is normally only possible on startup before the extruder has been moved -- yet this was shortly after commanding retraction moves to unload the filament and trim the end, so the E steppers must have been at least engaged at idle (set to 25%). M122, M122 B1, and checking the current settings revealed nothing obvious, but the extruder acted like its steppers were unpowered or at least significantly under-currented. I'm pushing my machine hard right now, so it's always possible something else is going on, but I wanted to document this in case it's a thing with the alpha. Also worth noting that I had never clogged this hot end/nozzle before switching to the alpha.

EDIT: I had not yet switched off the machine, but after reloading the filament and just letting everything sit while I wrote this report, I tried hand-feeding the filament again and it is significantly harder -- more what I'd expect from the idle state.

Some specifics for the prints I ran this afternoon: I ran a speedbenchy print that finished in 3:36 with no extrusion issues, allowed about 10 minutes for board and stepper temps to steadystate, re-sliced with a change only to accels (100->120k), used M906 to change E current from 1800 to 2000 (a value I've run many times -- I was testing lower current), then ran the new gcode and got the result shown. To my eye this does not look like a clog -- it's too consistent.

gloomyandy

@Kiolia What version of RRF are you using?

Kiolia

@gloomyandy 3.6.0 5+1.

Kiolia

To follow up on the strange extrusion event, I re-ran the same print with the same config settings as before today, and extrusion appeared normal again -- so it wasn't the gcode's fault. Both prints layer shifted and were cancelled at about the same point, so out of curiosity I weighed them. The first one with the extrusion issue weighed 58% of the second one. I wondered if it would be a nice round number like half, but I guess not.

dc42

All, please upgrade to 3.6.0-beta.1. If you reported any issues with 3.6.0 alpha releases, test whether they are still present in 3.6.0-beta.1; and if so start a new thread about your issue, including [3.6.0-beta.1] in the topic title.