[3.5beta1 SBC] printer stops while printing and can't resume

[Krohm Koala]

Hi,

I have some problems with the latest version, i run a duet 3 mini 5+ in SBC, and since the last update, i can't send a file with Prusa slicer, i have a error HTTP400, and i can't print because the printer stop somewhere during the first or second layer.

Here is my M122 during the event:

m122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.5beta1 (2022-12-23 18:25:34) running on Duet 3 Mini5plus WiFi (SBC mode)
Board ID: RBLWU-5096U-D65J0-40KMQ-K513Z-HRUJH
Used output buffers: 8 of 40 (27 max)
=== RTOS ===
Static ram: 102208
Dynamic ram: 106888 of which 204 recycled
Never used RAM 29340, free system stack 126 words
Tasks: SBC(ready,2.4%,447) HEAT(notifyWait,0.0%,346) Move(notifyWait,0.0%,284) CanReceiv(notifyWait,0.0%,941) CanSender(notifyWait,0.0%,335) CanClock(delaying,0.0%,342) TMC(notifyWait,0.7%,79) MAIN(running,95.4%,534) IDLE(ready,0.6%,30) AIN(delaying,0.8%,265), total 100.0%
Owned mutexes: HTTP(MAIN)
=== Platform ===
Last reset 00:05:16 ago, cause: software
Last software reset at 2022-12-27 14:41, reason: User, GCodes spinning, available RAM 29340, slot 2
Software reset code 0x6003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00000000 BFAR 0xe000ed38 SP 0x00000000 Task SBC Freestk 0 n/a
Error status: 0x00
Aux0 errors 0,0,0
MCU revision 3, ADC conversions started 316407, completed 316405, timed out 0, errs 0
Step timer max interval 1490
MCU temperature: min 31.2, current 36.1, max 36.1
Supply voltage: min 1.8, current 24.5, max 24.6, under voltage events: 1, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 99/19, heap memory allocated/used/recyclable 2048/656/440, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, read errors 0, write errors 2, ifcnt 17, reads 15843, writes 29, timeouts 0, DMA errors 0, CC errors 0
Driver 1: standstill, SG min 0, read errors 0, write errors 2, ifcnt 17, reads 15843, writes 29, timeouts 0, DMA errors 0, CC errors 0
Driver 2: standstill, SG min 0, read errors 0, write errors 2, ifcnt 14, reads 15845, writes 26, timeouts 0, DMA errors 0, CC errors 0
Driver 3: standstill, SG min 0, read errors 0, write errors 2, ifcnt 32, reads 15826, writes 45, timeouts 0, DMA errors 0, CC errors 0
Driver 4: standstill, SG min 0, read errors 0, write errors 2, ifcnt 32, reads 15827, writes 45, timeouts 0, DMA errors 0, CC errors 0
Driver 5: not present
Driver 6: not present
Date/time: 2022-12-27 14:46:44
Cache data hit count 539880467
Slowest loop: 96.35ms; fastest: 0.09ms
=== Storage ===
Free file entries: 10
SD card 0 not detected, interface speed: 0.0MBytes/sec
SD card longest read time 0.0ms, write time 0.0ms, max retries 0
=== Move ===
DMs created 83, segments created 9, maxWait 31997ms, bed compensation in use: mesh, comp offset 0.000
no step interrupt scheduled
=== DDARing 0 ===
Scheduled moves 139, completed 139, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 1], CDDA state -1
=== 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.2
Heater 1 is on, I-accum = 0.2
=== 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 doing "M0" in state(s) 0, sync state 1
Queue2 is idle in state(s) 0
Q0 segments left 0, axes/extruders owned 0x0000803
Code queue 0 is empty
Q1 segments left 0, axes/extruders owned 0x0000000
Code queue 1 is empty
=== Filament sensors ===
Extruder 0 sensor: ok
=== CAN ===
Messages queued 2798, received 0, lost 0, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 0, free buffers 18 (min 18), ts 1582/0/0
Tx timeouts 0,0,1581,0,0,1215 last cancelled message type 30 dest 127
=== SBC interface ===
Transfer state: 5, failed transfers: 0, checksum errors: 0
RX/TX seq numbers: 19946/19946
SPI underruns 0, overruns 0
State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x0e0a8
Buffer RX/TX: 0/0-0, open files: 0
=== Duet Control Server ===
Duet Control Server version 3.5.0-b1 (2022-12-23 20:41:36)
File2+ProcessInternally:

File /opt/dsf/sd/gcodes/PLA_0.2_Tape Cutter.gcode is selected, processing
File2:
Buffered code: M0
==> 24 bytes
Code buffer space: 4096
Configured SPI speed: 8000000Hz, TfrRdy pin glitches: 0
Full transfers per second: 64.76, max time between full transfers: 82.6ms, max pin wait times: 35.5ms/12.3ms
Codes per second: 134.84
Maximum length of RX/TX data transfers: 4380/1792

Have a nice day.

[Krohm Koala]

Downgrade solved the problem.

[chrishamm]

@Krohm-Koala Thanks, I could reproduce and fix it. The problem is PrusaSlicer because it does not send the correct content type with upload requests for POST /rr_upload (application/x-www-form-urlencoded instead of application/octet-stream). This caused the internal MVC validation to fail and the result was the error message you got.

I've added another work-around to overwrite the content type before affected requests are handled by DWS and it will be part of v3.5-b2.

[Krohm Koala]

@chrishamm Thanks, have you news about the part of the printer stop printing rapidly after the start of the print ?

[chrishamm]

@Krohm-Koala I cannot reproduce rapid stops after the start of a print. Your diagnostics say the last reset was caused by M999 (also sent by Emergency Stop).

If you can reproduce it repeatably without PrusaSlicer's upload feature, please consider enabling debug options and post your logs here (see here for further information). If you do, please provide your /sys files as well.

[Krohm Koala]

@chrishamm It's really weird, it says that the buffered code is M0 when it's happening, wich happens only at the end of the file... I join my /sys and the file i was printing inside it (i does that with every file)
https://mega.nz/file/TcgGxK7D#mVwvUW7C3xGIeLTdb9aDKipM4RJszVvIBlliq8GrTbI

m122
=== Diagnostics ===
RepRapFirmware for Duet 3 Mini 5+ version 3.5beta1 (2022-12-23 18:25:34) running on Duet 3 Mini5plus WiFi (SBC mode)
Board ID: RBLWU-5096U-D65J0-40KMQ-K513Z-HRUJH
Used output buffers: 10 of 40 (28 max)
=== RTOS ===
Static ram: 102208
Dynamic ram: 106888 of which 204 recycled
Never used RAM 29340, free system stack 132 words
Tasks: SBC(ready,3.2%,447) HEAT(notifyWait,0.0%,346) Move(notifyWait,1.2%,263) CanReceiv(notifyWait,0.0%,941) CanSender(notifyWait,0.0%,334) CanClock(delaying,0.0%,342) TMC(notifyWait,0.8%,79) MAIN(running,93.5%,434) IDLE(ready,0.3%,30) AIN(delaying,0.9%,263), total 100.0%
Owned mutexes: HTTP(MAIN)
=== Platform ===
Last reset 01:10:07 ago, cause: software
Last software reset at 2022-12-27 14:51, reason: User, GCodes spinning, available RAM 29340, slot 0
Software reset code 0x6003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00000000 BFAR 0xe000ed38 SP 0x00000000 Task SBC Freestk 0 n/a
Error status: 0x00
Aux0 errors 0,0,0
MCU revision 3, ADC conversions started 4207943, completed 4207942, timed out 0, errs 0
Step timer max interval 1490
MCU temperature: min 35.9, current 37.0, max 37.0
Supply voltage: min 24.1, current 24.5, max 24.6, under voltage events: 1, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 99/20, heap memory allocated/used/recyclable 2048/1676/1428, gc cycles 3
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, read errors 0, write errors 0, ifcnt 20, reads 2012, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 1: standstill, SG min 0, read errors 0, write errors 0, ifcnt 20, reads 2012, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 2: standstill, SG min 0, read errors 0, write errors 0, ifcnt 17, reads 2012, writes 1, timeouts 0, DMA errors 0, CC errors 0
Driver 3: standstill, SG min 0, read errors 0, write errors 0, ifcnt 44, reads 2012, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 4: standstill, SG min 2, read errors 0, write errors 0, ifcnt 44, reads 2012, writes 0, timeouts 0, DMA errors 0, CC errors 0
Driver 5: not present
Driver 6: not present
Date/time: 2023-01-02 16:41:44
Cache data hit count 4294967295
Slowest loop: 70.66ms; fastest: 0.10ms
=== Storage ===
Free file entries: 10
SD card 0 not detected, interface speed: 0.0MBytes/sec
SD card longest read time 0.0ms, write time 0.0ms, max retries 0
=== Move ===
DMs created 83, segments created 9, maxWait 6674ms, bed compensation in use: mesh, comp offset 0.000
no step interrupt scheduled
=== DDARing 0 ===
Scheduled moves 299, completed 299, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 1], CDDA state -1
=== 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.2
=== 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 doing "M0" 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 ===
Extruder 0 sensor: ok
=== CAN ===
Messages queued 345, received 0, lost 0, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 0, free buffers 18 (min 18), ts 192/0/0
Tx timeouts 0,0,192,0,0,153 last cancelled message type 30 dest 127
=== SBC interface ===
Transfer state: 5, failed transfers: 0, checksum errors: 0
RX/TX seq numbers: 16104/2180
SPI underruns 0, overruns 0
State: 5, disconnects: 2, timeouts: 1 total, 1 by SBC, IAP RAM available 0x0e0a8
Buffer RX/TX: 0/0-0, open files: 0
=== Duet Control Server ===
Duet Control Server version 3.5.0-b1 (2022-12-23 20:41:36)
File2+ProcessInternally:

File /opt/dsf/sd/gcodes/PLA_0.2_Tape Cutter.gcode is selected, processing
File2:
Buffered code: M0
==> 24 bytes
Code buffer space: 4096
Configured SPI speed: 8000000Hz, TfrRdy pin glitches: 0
Full transfers per second: 79.98, max time between full transfers: 42.2ms, max pin wait times: 32.5ms/13.2ms
Codes per second: 235.38
Maximum length of RX/TX data transfers: 4244/2644

[chrishamm]

@Krohm-Koala Okay, then this is apparently a duplicate of this one.

[Krohm Koala]

@chrishamm Thanks, i managed to print screen the part of the logs when it happens, but i don't see anything weird on the logs...