Posts made by adammhaile

@chrishamm Sigh.... So I replaced my Pi 4 with a 3B+, ensured the voltage was fine (5.21V again) with no throttling events. But it just died again with literally 30 seconds to go on a 25 hour print. Please see logs and diagnostics captured right after it happened below.

Maybe I do need to replace the ribbon cable? Where can I find a replacement?

#DuetControlServer log when it stopped
Jun 20 12:11:39 Rancor DuetControlServer[397]: [info] Starting macro file M800.g on channel File
Jun 20 12:11:39 Rancor DuetControlServer[397]: [warn] Lost connection to Duet (Board is not available (no header))
Jun 20 12:11:39 Rancor DuetControlServer[397]: [info] Connection to Duet established
Jun 20 12:11:39 Rancor DuetControlServer[397]: [info] Starting macro file config.g on channel Trigger
Jun 20 12:11:39 Rancor DuetControlServer[397]: [info] Starting macro file globals.g on channel Trigger
Jun 20 12:11:40 Rancor DuetControlServer[397]: [info] Finished macro file globals.g
Jun 20 12:11:42 Rancor DuetControlServer[397]: [error] M584: Driver 1.0 does not exist
Jun 20 12:11:42 Rancor DuetControlServer[397]: Driver 1.1 does not exist
Jun 20 12:11:43 Rancor DuetControlServer[397]: [info] Starting macro file tools/t0.g on channel Trigger
Jun 20 12:11:43 Rancor DuetControlServer[397]: [info] Finished macro file tools/t0.g
Jun 20 12:11:43 Rancor DuetControlServer[397]: [info] Starting macro file tools/t1.g on channel Trigger
Jun 20 12:11:43 Rancor DuetControlServer[397]: [info] Finished macro file tools/t1.g
Jun 20 12:11:43 Rancor DuetControlServer[397]: [info] Starting macro file tools/bed.g on channel Trigger
Jun 20 12:11:43 Rancor DuetControlServer[397]: [info] Finished macro file tools/bed.g
Jun 20 12:11:43 Rancor DuetControlServer[397]: [info] Starting macro file tools/setup.g on channel Trigger
Jun 20 12:11:43 Rancor DuetControlServer[397]: [info] Starting macro file tools/revo_a_0.4/config.g on channel Trigger
Jun 20 12:11:43 Rancor DuetControlServer[397]: [warn] M307: Heater 1 predicted maximum temperature at full power is 497°C
Jun 20 12:11:43 Rancor DuetControlServer[397]: [info] Finished macro file tools/revo_a_0.4/config.g
Jun 20 12:11:43 Rancor DuetControlServer[397]: [info] Starting macro file tools/revo_b_0.4/config.g on channel Trigger
Jun 20 12:11:44 Rancor DuetControlServer[397]: [warn] M307: Heater 2 predicted maximum temperature at full power is 497°C
Jun 20 12:11:44 Rancor DuetControlServer[397]: [info] Finished macro file tools/revo_b_0.4/config.g
Jun 20 12:11:44 Rancor DuetControlServer[397]: [info] Starting macro file tools/bed_offsets.g on channel Trigger
Jun 20 12:11:44 Rancor DuetControlServer[397]: [info] Finished macro file tools/bed_offsets.g
Jun 20 12:11:45 Rancor DuetControlServer[397]: [info] Finished macro file tools/setup.g
Jun 20 12:11:45 Rancor DuetControlServer[397]: [info] Starting macro file soft_load_tool.g on channel Trigger
Jun 20 12:11:45 Rancor DuetControlServer[397]: [info] Starting macro file 0:/filaments/PLA/config.g on channel Trigger
Jun 20 12:11:45 Rancor DuetControlServer[397]: [info] Starting macro file tools/revo_a_0.4/filament.g on channel Trigger
Jun 20 12:11:45 Rancor DuetControlServer[397]: [info] Finished macro file tools/revo_a_0.4/filament.g
Jun 20 12:11:45 Rancor DuetControlServer[397]: [info] Finished macro file 0:/filaments/PLA/config.g
Jun 20 12:11:45 Rancor DuetControlServer[397]: [info] Finished macro file soft_load_tool.g
Jun 20 12:11:45 Rancor DuetControlServer[397]: [info] Finished macro file config.g

M122 B0
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.4.1 (2022-06-01 21:09:01) running on Duet 3 MB6HC v1.01 or later (SBC mode)
Board ID: 08DJM-9P63L-DJ3S0-7JTD0-3SN6R-TUMBA
Used output buffers: 1 of 40 (14 max)
=== RTOS ===
Static ram: 151000
Dynamic ram: 69072 of which 0 recycled
Never used RAM 127672, free system stack 180 words
Tasks: SBC(ready,0.6%,454) HEAT(notifyWait,0.0%,321) Move(notifyWait,0.0%,267) CanReceiv(notifyWait,0.0%,797) CanSender(notifyWait,0.0%,374) CanClock(delaying,0.0%,339) TMC(notifyWait,7.7%,58) MAIN(running,91.1%,1205) IDLE(ready,0.5%,30), total 100.0%
Owned mutexes: HTTP(MAIN)
=== Platform ===
Last reset 00:02:24 ago, cause: software
Last software reset at 2022-06-20 12:11, reason: OutOfMemory, GCodes spinning, available RAM 672, slot 0
Software reset code 0x41c3 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0440f000 BFAR 0x00000000 SP 0x204341b0 Task SBC Freestk 629 ok
Stack: 20435bac 00418801 00000000 204366d0 20419894 0040c457 00000006 204341f0 204341f8 0040c5a3 20434559 20434558 00000065 204341f8 204342e8 00451913 204341f8 00000065 6579616c 40240072 00000000 43300000 00000000 2043611a 00000006 00483de7 00000001
Error status: 0x00
Aux0 errors 0,0,0
Aux1 errors 0,0,0
Step timer max interval 168
MCU temperature: min 46.1, current 46.2, max 47.0
Supply voltage: min 23.8, current 23.9, max 23.9, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.0, current 12.1, max 12.1, under voltage events: 0
Heap OK, handles allocated/used 99/54, heap memory allocated/used/recyclable 2048/1028/340, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, mspos 408, reads 21308, writes 14 timeouts 0
Driver 1: standstill, SG min 0, mspos 536, reads 21308, writes 14 timeouts 0
Driver 2: standstill, SG min 0, mspos 472, reads 21309, writes 14 timeouts 0
Driver 3: standstill, SG min 0, mspos 776, reads 21304, writes 19 timeouts 0
Driver 4: standstill, SG min 0, mspos 360, reads 21304, writes 19 timeouts 0
Driver 5: standstill, SG min 0, mspos 584, reads 21304, writes 19 timeouts 0
Date/time: 2022-06-20 12:14:03
Slowest loop: 30.80ms; fastest: 0.05ms
=== Storage ===
Free file entries: 10
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 ===
DMs created 125, segments created 3, maxWait 75628ms, bed compensation in use: none, comp offset 0.000
=== MainDDARing ===
Scheduled moves 2, completed 2, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 2], CDDA state -1
=== AuxDDARing ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== Heat ===
Bed heaters 0 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
Heater 1 is on, I-accum = 0.0
=== GCodes ===
Segments left: 0
Movement lock held by null
HTTP* is doing "M122 B0" in state(s) 0
Telnet is idle in state(s) 0
File is idle in state(s) 0
USB is idle in state(s) 0
Aux is idle in state(s) 0
Trigger* is idle in state(s) 0
Queue is idle in state(s) 0
LCD is idle in state(s) 0
SBC is idle in state(s) 0
Daemon is idle in state(s) 0
Aux2 is idle in state(s) 0
Autopause is idle in state(s) 0
Code queue is empty
=== Filament sensors ===
Extruder 0 sensor: ok
Extruder 1 sensor: no filament
=== CAN ===
Messages queued 1312, received 2994, lost 0, boc 0
Longest wait 1ms for reply type 6018, peak Tx sync delay 230, free buffers 50 (min 49), ts 724/723/0
Tx timeouts 0,0,0,0,0,0
=== SBC interface ===
Transfer state: 5, failed transfers: 0, checksum errors: 0
RX/TX seq numbers: 47574/6777
SPI underruns 0, overruns 0
State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x2b880
Buffer RX/TX: 0/0-0, open files: 0
=== Duet Control Server ===
Duet Control Server v3.4.1
File /opt/dsf/sd/gcodes/DualLightSaber_T0-PLA_T1-PLA.gcode is selected, processing
File:
Executing macro M800.g, started by M800 F"layer"
> Next stack level
Suspended code: G1 X54.614 Y175.558
Suspended code: G11 ; unretract
Suspended code: M204 P800
Suspended code: ;HEIGHT:0.15
Suspended code: G1 F900
Suspended code: G1 X57.334 Y175.561 E.06804
Suspended code: G1 X57.725 Y175.6 E.00983
Suspended code: G1 X59.068 Y175.817 E.03402
Suspended code: G1 X60.269 Y175.984 E.03032
Suspended code: G1 X61.33 Y176.073 E.02664
Suspended code: G1 X62.097 Y176.092 E.01919
Suspended code: G1 X62.863 Y176.073 E.01917
Suspended code: G1 X63.928 Y175.986 E.02672
Suspended code: G1 X66.729 Y175.57 E.07083
Suspended code: G1 X69.581 Y175.557 E.07134
Suspended code: G1 X69.344 Y175.697 E.00689
Suspended code: G1 X68.524 Y176.069 E.02252
Suspended code: G1 X67.765 Y176.362 E.02034
Suspended code: G1 X66.972 Y176.624 E.02089
Suspended code: G1 X66.161 Y176.847 E.02105
Suspended code: G1 X65.388 Y177.021 E.01981
Suspended code: G1 X64.579 Y177.162 E.02053
Suspended code: G1 X63.663 Y177.272 E.02308
Suspended code: G1 X62.945 Y177.324 E.01801
Suspended code: G1 X62.166 Y177.345 E.0195
Suspended code: G1 X61.187 Y177.32 E.02449
Suspended code: G1 X60.424 Y177.262 E.01913
Suspended code: G1 X59.638 Y177.165 E.01982
Suspended code: G1 X58.806 Y177.021 E.02112
Code buffer space: 4096
Configured SPI speed: 8000000Hz, TfrRdy pin glitches: 0
Full transfers per second: 37.60, max time between full transfers: 226.0ms, max pin wait times: 108.3ms/17.1ms
Codes per second: 17.30
Maximum length of RX/TX data transfers: 3968/1592

M122 B1
Diagnostics for board 1:
Duet EXP3HC rev 1.01 or earlier firmware version 3.4.1 (2022-06-01 21:15:27)
Bootloader ID: SAME5x bootloader version 2.3 (2021-01-26b1)
All averaging filters OK
Never used RAM 158400, free system stack 167 words
Tasks: Move(notifyWait,1.5%,92) HEAT(notifyWait,0.7%,50) CanAsync(notifyWait,0.1%,64) CanRecv(notifyWait,0.7%,80) CanClock(notifyWait,0.1%,71) TMC(notifyWait,33.3%,65) MAIN(running,41.1%,344) IDLE(ready,0.0%,40) AIN(delaying,22.5%,263), total 100.0%
Last reset 25:24:51 ago, cause: power up
Last software reset data not available
Driver 0: pos -258009, 160.0 steps/mm,standstill, SG min 0, mspos 744, reads 9620, writes 29 timeouts 0, steps req 185814711 done 185537164
Driver 1: pos 257123, 160.0 steps/mm,standstill, SG min 0, mspos 744, reads 9620, writes 29 timeouts 0, steps req 232322253 done 232005820
Driver 2: pos 13558906, 397.0 steps/mm,standstill, SG min 0, mspos 776, reads 9625, writes 26 timeouts 0, steps req 22606666 done 22606666
Moves scheduled 1382523, completed 1382523, in progress 0, hiccups 193, step errors 0, maxPrep 214, maxOverdue 7319, maxInc 7313, mcErrs 0, gcmErrs 0
Peak sync jitter -5/5, peak Rx sync delay 187, resyncs 0/1, no step interrupt scheduled
VIN voltage: min 24.0, current 24.1, max 24.2
V12 voltage: min 12.1, current 12.1, max 12.2
MCU temperature: min 31.2C, current 46.9C, max 49.2C
Last sensors broadcast 0x00000004 found 1 181 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 1881188, send timeouts 0, received 2211077, lost 0, free buffers 37, min 37, error reg 110000
dup 0, oos 0/0/0/0, bm 0, wbm 0, rxMotionDelay 424, adv 34892/95319
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 1 to 576us
Driver 2: ok

@phaedrux Yes. Last I checked it was 5.21V and I've never seen vcgencmd return a throttled or undervoltage status.

@chrishamm said in Print randomly stops with "Lost connection to Duet":

I'm sorry to hear you're still having problems. Make sure all moving parts are properly grounded and if it happens again, please share the output of M122 after the error message. That may help explain what part is failing but since you've had issues for quite a while, I suspect there is noise either on the TfrRdy or on the MISO line. If you can, try to replace the cable between Duet and SBC as well or try to shield-wrap the ribbon cable.

I've been through all the grounding previously. I've rechecked now and it's all fully grounded.

The original post above includes M122 output after the error message.

The ribbon cable is already shield wrapped (Which itself is grounded).

Where would I find a new ribbon cable? I've looked around but cannot find the weird type that ships with the Duet.

I have an IDEX machine with a 6HC and 3HC expansion, running latest 3.4.1 RRF and DSF. Unfortunately I'm running into an issue where it just randomly stops printing. Typically on long prints, many hours in. Previously it would fail with an SPI error and I was told that 3.4.1 fixed some SPI comms issues, so I upgraded. But now I've had it still fail with slightly different errors. See below from the duetcontrolserver logs.

I'm at my wit's end here... previously it failed because I was using WiFi on a Pi4 and that brought down the SPI. That seems fixed by using ethernet instead, but now I keep getting these other comms errors. I basically cannot trust that it will ever finish a print. Especially if they are very long.

The Pi is powered from a 100W 5V MeanWell power supply that does power a couple other things but those maybe require 15-20W together. And I've been monitoring for voltage drops and the Pi has not reported any.

I'm very tempted to swap out the 4 for a 3B+ because I have another 6HC printer with that and it's always worked fine. But I'm about to pack it up for MRRF and don't really have the time at the moment.

Jun 17 08:58:57 Rancor DuetControlServer[436]: [info] Finished macro file M4201.g
Jun 17 08:58:57 Rancor DuetControlServer[436]: [info] Starting macro file M800.g on channel File
Jun 17 08:58:57 Rancor DuetControlServer[436]: [info] Finished macro file M800.g
Jun 17 08:59:04 Rancor DuetControlServer[436]: [info] Starting macro file tfree0.g on channel File
Jun 17 08:59:05 Rancor DuetControlServer[436]: [info] Starting macro file M800.g on channel File
Jun 17 08:59:05 Rancor DuetControlServer[436]: [warn] Lost connection to Duet (Board is not available (no header))
Jun 17 08:59:05 Rancor DuetControlServer[436]: [info] Connection to Duet established
Jun 17 08:59:05 Rancor DuetControlServer[436]: [info] Starting macro file config.g on channel Trigger
Jun 17 08:59:05 Rancor DuetControlServer[436]: [info] Starting macro file globals.g on channel Trigger
Jun 17 08:59:06 Rancor DuetControlServer[436]: [info] Finished macro file globals.g
Jun 17 08:59:08 Rancor DuetControlServer[436]: [error] M584: Driver 1.0 does not exist
Jun 17 08:59:08 Rancor DuetControlServer[436]: Driver 1.1 does not exist
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Starting macro file tools/t0.g on channel Trigger
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Finished macro file tools/t0.g
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Starting macro file tools/t1.g on channel Trigger
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Finished macro file tools/t1.g
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Starting macro file tools/bed.g on channel Trigger
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Finished macro file tools/bed.g
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Starting macro file tools/setup.g on channel Trigger
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Starting macro file tools/revo_a_0.4/config.g on channel Trigger
Jun 17 08:59:09 Rancor DuetControlServer[436]: [warn] M307: Heater 1 predicted maximum temperature at full power is 497°C
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Finished macro file tools/revo_a_0.4/config.g
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Starting macro file tools/revo_b_0.4/config.g on channel Trigger
Jun 17 08:59:09 Rancor DuetControlServer[436]: [warn] M307: Heater 2 predicted maximum temperature at full power is 497°C
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Finished macro file tools/revo_b_0.4/config.g
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Starting macro file tools/bed_offsets.g on channel Trigger
Jun 17 08:59:09 Rancor DuetControlServer[436]: [info] Finished macro file tools/bed_offsets.g
Jun 17 08:59:10 Rancor DuetControlServer[436]: [info] Finished macro file tools/setup.g
Jun 17 08:59:10 Rancor DuetControlServer[436]: [info] Starting macro file soft_load_tool.g on channel Trigger
Jun 17 08:59:11 Rancor DuetControlServer[436]: [info] Starting macro file 0:/filaments/PLA/config.g on channel Trigger
Jun 17 08:59:11 Rancor DuetControlServer[436]: [info] Starting macro file tools/revo_a_0.4/filament.g on channel Trigger
Jun 17 08:59:11 Rancor DuetControlServer[436]: [info] Finished macro file tools/revo_a_0.4/filament.g
Jun 17 08:59:11 Rancor DuetControlServer[436]: [info] Finished macro file 0:/filaments/PLA/config.g
Jun 17 08:59:11 Rancor DuetControlServer[436]: [info] Finished macro file soft_load_tool.g
Jun 17 08:59:11 Rancor DuetControlServer[436]: [info] Finished macro file config.g
Jun 17 09:08:46 Rancor DuetControlServer[436]: [warn] File: Aborting orphaned macro file M800.g
Jun 17 09:08:46 Rancor DuetControlServer[436]: [info] Aborted macro file M800.g
Jun 17 09:08:46 Rancor DuetControlServer[436]: [warn] File: ==> Cancelling unfinished starting code: M800 F"toolchange"
Jun 17 09:08:46 Rancor DuetControlServer[436]: [warn] File: Aborting orphaned macro file tfree0.g
Jun 17 09:08:46 Rancor DuetControlServer[436]: [info] Aborted macro file tfree0.g
Jun 17 09:08:46 Rancor DuetControlServer[436]: [warn] File: ==> Cancelling unfinished starting code: T1

Diagnostics run right after the fail:

6/17/2022, 9:10:41 AM	M122 B1
Diagnostics for board 1:
Duet EXP3HC rev 1.01 or earlier firmware version 3.4.1 (2022-06-01 21:15:27)
Bootloader ID: SAME5x bootloader version 2.3 (2021-01-26b1)
All averaging filters OK
Never used RAM 158400, free system stack 200 words
Tasks: Move(notifyWait,0.0%,160) HEAT(notifyWait,0.0%,84) CanAsync(notifyWait,0.0%,69) CanRecv(notifyWait,0.0%,82) CanClock(notifyWait,0.0%,71) TMC(notifyWait,7.4%,99) MAIN(running,91.3%,344) IDLE(ready,0.0%,40) AIN(delaying,1.3%,263), total 100.0%
Last reset 00:01:54 ago, cause: software
Last software reset data not available
Driver 0: pos 0, 160.0 steps/mm,standstill, SG min 0, mspos 472, reads 46910, writes 16 timeouts 0, steps req 0 done 0
Driver 1: pos 0, 160.0 steps/mm,standstill, SG min 0, mspos 296, reads 46911, writes 16 timeouts 0, steps req 0 done 0
Driver 2: pos 0, 397.0 steps/mm,standstill, SG min 0, mspos 408, reads 46911, writes 16 timeouts 0, steps req 0 done 0
Moves scheduled 0, completed 0, in progress 0, hiccups 0, step errors 0, maxPrep 0, maxOverdue 0, maxInc 0, mcErrs 0, gcmErrs 0
Peak sync jitter -2/2, peak Rx sync delay 174, resyncs 0/0, no step interrupt scheduled
VIN voltage: min 24.2, current 24.2, max 24.2
V12 voltage: min 12.1, current 12.1, max 12.2
MCU temperature: min 41.2C, current 41.4C, max 42.0C
Last sensors broadcast 0x00000004 found 1 148 ticks ago, 0 ordering errs, loop time 0
CAN messages queued 1023, send timeouts 101, received 116, lost 0, free buffers 37, min 37, error reg 110000
Last cancelled message type 4519 dest 0
dup 0, oos 0/0/0/0, bm 0, wbm 0, rxMotionDelay 0
=== Filament sensors ===
Interrupt 5726621 to 0us, poll 1 to 114us
Driver 2: ok

6/17/2022, 9:10:39 AM	M122 B0
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.4.1 (2022-06-01 21:09:01) running on Duet 3 MB6HC v1.01 or later (SBC mode)
Board ID: 08DJM-9P63L-DJ3S0-7JTD0-3SN6R-TUMBA
Used output buffers: 1 of 40 (14 max)
=== RTOS ===
Static ram: 151000
Dynamic ram: 68896 of which 0 recycled
Never used RAM 127920, free system stack 202 words
Tasks: SBC(resourceWait:,2.9%,466) HEAT(notifyWait,0.0%,359) Move(notifyWait,0.0%,352) CanReceiv(notifyWait,0.1%,797) CanSender(notifyWait,0.0%,374) CanClock(delaying,0.0%,348) TMC(notifyWait,7.5%,92) MAIN(running,76.1%,1231) IDLE(ready,13.4%,30), total 100.0%
Owned mutexes: HTTP(MAIN)
=== Platform ===
Last reset 00:00:09 ago, cause: software
Last software reset at 2022-06-17 09:10, reason: User, GCodes spinning, available RAM 127744, slot 2
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0x00000000 SP 0x00000000 Task SBC Freestk 0 n/a
Error status: 0x00
Aux0 errors 0,0,0
Aux1 errors 0,0,0
Step timer max interval 1628
MCU temperature: min 41.3, current 41.6, max 41.9
Supply voltage: min 23.9, current 23.9, max 23.9, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.0, current 12.1, max 12.1, under voltage events: 0
Heap OK, handles allocated/used 99/57, heap memory allocated/used/recyclable 2048/928/218, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min 0, mspos 984, reads 53081, writes 14 timeouts 0
Driver 1: standstill, SG min 0, mspos 584, reads 53082, writes 14 timeouts 0
Driver 2: standstill, SG min 0, mspos 920, reads 53082, writes 14 timeouts 0
Driver 3: standstill, SG min 0, mspos 632, reads 53082, writes 14 timeouts 0
Driver 4: standstill, SG min 0, mspos 216, reads 53082, writes 14 timeouts 0
Driver 5: standstill, SG min 0, mspos 936, reads 53082, writes 14 timeouts 0
Date/time: 2022-06-17 09:10:37
Slowest loop: 211.92ms; fastest: 0.00ms
=== Storage ===
Free file entries: 10
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 ===
DMs created 125, segments created 0, maxWait 0ms, bed compensation in use: none, comp offset 0.000
=== MainDDARing ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== AuxDDARing ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], CDDA state -1
=== Heat ===
Bed heaters 0 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters -1 -1 -1 -1, ordering errs 0
=== GCodes ===
Segments left: 0
Movement lock held by null
HTTP* is doing "M122 B0" 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 0 0, running macro
Queue is idle in state(s) 0
LCD is idle in state(s) 0
SBC is idle in state(s) 0
Daemon is idle in state(s) 0
Aux2 is idle in state(s) 0
Autopause is idle in state(s) 0
Code queue is empty
=== Filament sensors ===
Extruder 0 sensor: ok
Extruder 1 sensor: no filament
=== CAN ===
Messages queued 88, received 851, lost 0, boc 0
Longest wait 1ms for reply type 6018, peak Tx sync delay 324, free buffers 50 (min 49), ts 48/47/0
Tx timeouts 0,0,0,0,0,0
=== SBC interface ===
Transfer state: 5, failed transfers: 0, checksum errors: 0
RX/TX seq numbers: 4821/4821
SPI underruns 0, overruns 0
State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x2b858
Buffer RX/TX: 0/0-0, open files: 0
=== Duet Control Server ===
Duet Control Server v3.4.1
Trigger:
Finishing macro tools/setup.g, started by M98 P"tools/setup.g"
> Next stack level
Executing macro config.g, started by system
Suspended code: M98 P"soft_load_tool.g" S0
> Next stack level
Code buffer space: 4096
Configured SPI speed: 8000000Hz, TfrRdy pin glitches: 0
Full transfers per second: 596.70, max time between full transfers: 97.7ms, max pin wait times: 46.8ms/34.0ms
Codes per second: 11.99
Maximum length of RX/TX data transfers: 3616/540

@chrishamm said in CAN bus anomalies with 6HC and 3HC:

At least on DuetPi the pi user should have access to the dsf files as well.

Read yes, write no. And if I make a file via the pi user it seems that DWC doesn't see it. It was kind of weird... it didn't act quite right.
And yes, I did exactly what you said to make the directory and set the shell. Just thought there was no reason it couldn't be setup like that from the start

@chrishamm @dc42 @Phaedrux @T3P3Tony
Just wanted to follow up on this and let you know that, at this point, I'm quite confident we found the problem. So, thank you all for sticking with me through all the ups and downs of solving this. It's been a crazy ride for sure.
And hopefully with the patches made to the Pi image this won't be a problem for people in the future who want to use a Pi4.

@chrishamm said in CAN bus anomalies with 6HC and 3HC:

@adammhaile Thanks for the info, that's very good to know. When I build the next DuetPi image, I'll disable WiFi power saving by default.

Awesome.
Silly request while you are in there... is there any chance you would considering setting up the dsf user to have a home directory and default shell so that you can log into it?
With complex configurations, such as mine, it's extremely helpful to be able to ssh directly as that user. I currently use usermod to do this on each Duet SBC I have and then will use Visual Studio Code's remote features to directly connect to the sd directory contents over SSH. This has also allowed me to keep the entire config backed up on GitHub

@t3p3tony @chrishamm @Phaedrux @dc42
Update: I've been stress testing the machine after swapping the Pi again and tweaking some of the wiring runs to help avoid signal noise. The last 4 days I've started a 12 hour print every morning so that I could have it printing as long as possible without having to leave it running while I'm asleep.

The first 3 days went beautifully but today I got another of the same failures.
However, this time was a little different...

Previously the SBC Pi was running a dhcp server to provide an IP for a direct ethernet connected Pi running android and a touch screen DWC interface.
I ditched that when I rebuilt the DuetPi Lite image and instead installed a small WiFi/Ethernet router. So now the SBC Pi and DWC Android Pi are wired to that and I can connect to the machine over it's own WiFi access point (this is so I can get to it at MRRF ).

The advantage of this was that previously when it would fail, I would never be able to connect to the Pi over SSH which limited my ability to diagnose. But this time I could hit its ethernet connection (which, unlike the WiFi, doesn't go down when the failure occurs it would seem) via the WiFi router I added.

So that led me to digging into various system logs and eventually dmesg, where I found a stream of errors, such as these:

[31055.833034] ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
[31062.393030] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
[31064.953033] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110
[31064.953060] ieee80211 phy0: brcmf_cfg80211_get_station: GET STA INFO failed, -110
[31071.513043] ieee80211 phy0: brcmf_proto_bcdc_query_dcmd: brcmf_proto_bcdc_msg failed w/status -110

And it was those that led me to this Duet Forum post:

https://forum.duet3d.com/topic/23889/pi4-network-disconnect

Now, the crazy thing is: they were seeing exactly what I was.

• SPI comms reset
• WiFi dropping
• Print stopping midway through and DWC showing it was done
• Using a Pi 4 with a Duet 3 (mini, but still)

Fortunately, they seem to have a solution! In that post they recommended not using 5Ghz networks and disabling the wifi power management features. From further research it seems that WiFi with 5GHz is somewhat of an ongoing issue with the Pi 4 and it will sometimes just kill WiFi when it shouldn't.... Now, why that seems to affect SPI, I have no idea. But they seem to be related...

While I could disable power saving on WiFi, the 2.4GHz network part was a problem for silly reasons with my home WiFi access point.
So, for now I've switched to only using ethernet and have connected a separate USB ethernet adapter for the connection between the SBC Pi and the DWC Android Pi.

Whether or not this will also fix the problem for me... time will tell. I'll be back to long test prints tomorrow morning and let you know how it goes in a few days.
But so far this seems promising given they were seeing pretty identical symptoms. My fallback at this point is tearing a Pi 3B+ out of something else in my house and using that. I have another Duet 3 machine with a 3B+ and it's been rock solid.

@nurgelrot said in Pi4 Network Disconnect.:

Marking Solved for now. If I can figure out how

Sorry to dig up old posts, but can you confirm that the problem was gone after you did this?
I'm having the exact same problem.

@chrishamm Interesting - will keep that in mind.
Strangely the SD card speed test is exactly the same with the new Duet boards, new Pi, and new faster SD card (the one recommended above). So I'd say that test is a red herring. I'm currently seeing 150+ MB/s reads on this card from the Pi.

Will test with DCS in RAM if my current batch of tests fail to rule anything out.

@phaedrux said in CAN bus anomalies with 6HC and 3HC:

Start eliminating extras until you find the smoking gun.

Yup - working on it. Re-running the same ~12 hour print every day, changing one thing each time.

@t3p3tony @chrishamm @Phaedrux
<sigh> Got the replacements, installed them, and all seemed to be going fine... but was just running a print and it stopped again mid-print. I unfortunately wasn't even able to view the duetcontrolserver log. I could try to run journalctl but it just never returned - and this was from the Pi terminal directly. I couldn't ssh into it.
I was able get this though, which is the streaming output of the CodeLogger -t executed -q

So, I'll admit - probably not something with the actual Duet boards - though I'm completely stumped as to what it could be.
Guess maybe I'll try swapping the Pi again - the fact that even SSH locks up is suspect to me. Implies that it's not the Duet failing... I guess?

I'm running mjpg-streamer and that gcode scroll on the display above from the SBC Pi - we've previously checked that the CPU usage is still low... but could it maybe still be one of those causing it? I've got other Duet 3 SBC machines that have a camera running off the same Pi without issue.

@dc42 said in Filament sensor triggers for the wrong extruder:

@adammhaile I confirm there is a bug. When the filament-error event is constructed, the CAN address and device number parameters are swapped.
I have fixed this in the source code. The fix will be in RRF 3.5.0beta1 and also in 3.4.1 if we do that release.

Awesome. Thanks for the update!

Alright @chrishamm @Phaedrux @dc42 - had it printing since early this morning and now (8pm) it locked up while not printing... couldn't even run any commands to get diagnostics. I could talk to the Pi, but no comms with the controllers until I power cycled.
I'm going to get these boards taken out of the machine now to

@chrishamm said in CAN bus anomalies with 6HC and 3HC:

Please check if the disconnects persist with the new card. If they do, I'll be happy to share a new firmware build that tells us whether the timeout is caused by the SBC or by Reprapfirmware. We've got another trace but I cannot comment on that one yet.

Sure - been running prints off this SD all morning. So far so good - but it was pretty random before so we'll see.
And by timeouts do you mean the SPI connection reset?

I'll keep putting this through it's paces either through tomorrow morning or until it fails again - then I'll remove and packup to send back.

@chrishamm said in CAN bus anomalies with 6HC and 3HC:

is this with the new SanDisk card?

Yes. Same card recommended above.

@chrishamm @T3P3Tony I don't think I trust the M122 P104 SD card test.... I'm using the new recommended SD card I've I've tested on my desktop at over 140MB/s but when running the diagnostic speed test I get the same exact results as before.
Honestly the fact that it's the exact same speed every time makes me feel like it's a bottleneck elsewhere - likely in the diagnostics code.
Especially given that I'm consistently able to upload gcode files at ~15MB/s no problem.
Though.... maybe this is part of the problem... The 15MB/s upload is through DWC which would be direct to the Pi.
But the diagnostics SD write test is running from the 6HC control board itself - so maybe that bottleneck is the SPI bus and that's causing my problems?

Is there anywhere I could purchase a new 6HC ribbon cable? Wondering if I should replace that too - though can't find anything that I'm sure is correct.

It's late now but I will run some print tests in the morning to see if I can cause any other fails, before I pack up the boards to ship back to Filastruder.

@t3p3tony said in CAN bus anomalies with 6HC and 3HC:

when so the new SD cards arrive? Would it be too disruptive to ask you to test with one of those.

No problem - they arrive today. I can likely give it a shot tonight.

@phaedrux @chrishamm @dc42
I've got to remove these boards and send them back to Filastruder - anything else you want me to try before I do that?

@phaedrux said in CAN bus anomalies with 6HC and 3HC:

I would back up the configs and start with a fresh DuetPi image, at least for testing. If you have more customizations you wish to preserve cloning the card should be an option.

Ok, will do that for now then.