[3.6.0-beta.3] Duet 3 MB6HC + Rpi3B+ CPU Overloaded?
-
Hi again,
Just had a print stop for the title reason; I've run a M122 directly after; any ideas on what happened?
2/3/2025, 6:28:14 PM M122 === Diagnostics === RepRapFirmware for Duet 3 MB6HC version 3.6.0-beta.3 (2025-01-16 19:09:36) running on Duet 3 MB6HC v1.0 or earlier (SBC mode) Board ID: 08DJM-956L2-G43S4-6JTDA-3SS6L-1B76H Used output buffers: 1 of 40 (17 max) === RTOS === Static ram: 136892 Dynamic ram: 96688 of which 4528 recycled Never used RAM 104556, free system stack 122 words Tasks: SBC(2,ready,0.8%,791) HEAT(3,nWait 6,0.0%,323) Move(4,nWait 6,0.3%,213) TMC(4,nWait 6,3.1%,341) CanReceiv(6,nWait 1,0.0%,768) CanSender(5,nWait 7,0.0%,325) CanClock(7,delaying,0.0%,348) MAIN(2,running,95.7%,101) IDLE(0,ready,0.0%,29) USBD(3,blocked,0.0%,149), total 100.0% Owned mutexes: HTTP(MAIN) === Platform === Last reset 24:01:45 ago, cause: power up Last software reset at 2025-01-21 01:41, reason: User, Gcodes spinning, available RAM 105956, slot 2 Software reset code 0x2003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0x00000000 SP 0x00000000 Task SBC Freestk 0 n/a Error status: 0x00 MCU temperature: min 33.7, current 35.5, max 38.2 Supply voltage: min 29.3, current 29.5, max 29.6, 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/14, heap memory allocated/used/recyclable 2048/944/744, gc cycles 180 Events: 0 queued, 0 completed Date/time: 2025-02-03 18:27:44 Slowest loop: 2999.62ms; fastest: 0.05ms USB interrupts 2 === 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 58, maxWait 53088303ms, bed comp in use: mesh, height map offset 0.012, hiccups added 0/0 (0.00/0.00ms), max steps late 0, ebfmin 0.00, ebfmax 0.00 Pos req/act/dcf: 169688.00/169688/0.05 -4579.00/-4578/-0.99 500.00/500/0.00 next step interrupt due in 247 ticks, disabled Driver 0: standstill, SG min 0, mspos 142, reads 61385, writes 304 timeouts 22 Driver 1: standstill, SG min 0, mspos 870, reads 61385, writes 304 timeouts 22 Driver 2: standstill, SG min 0, mspos 152, reads 61386, writes 303 timeouts 22 Driver 3: standstill, SG min 0, mspos 200, reads 61386, writes 303 timeouts 22 Driver 4: standstill, SG min 0, mspos 920, reads 61386, writes 303 timeouts 22 Driver 5: standstill, SG min n/a, mspos 8, reads 61436, writes 253 timeouts 22 Phase step loop runtime (us): min=0, max=108, frequency (Hz): min=317, max=10416 === DDARing 0 === Scheduled moves 7842, completed 7842, LaErrors 0, Underruns [0, 0, 0] Segments left 0, axes/extruders owned 0x80000007, drives owned 0x80000007 Code queue is empty === DDARing 1 === Scheduled moves 0, completed 0, LaErrors 0, Underruns [0, 0, 0] Segments left 0, axes/extruders owned 0x00000000, drives owned 0x00000000 Code queue is empty === Heat === Bed heaters 0 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters -1 -1 -1 -1 -1 -1 -1 -1, ordering er=== 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 === CAN === Messages queued 1835964, received 1730364, lost 0, ignored 0, errs 612, boc 0 Longest wait 2ms for reply type 6031, peak Tx sync delay 32145, free buffers 50 (min 48), ts 409981/409980/0 Tx timeouts 0,0,0,0,0,0 === SBC interface === Transfer state: 5, failed transfers: 0, checksum errors: 1 RX/TX seq numbers: 47836/1297 SPI underruns 0, overruns 0 State: 5, disconnects: 13, timeouts: 13 total, 13 by SBC, IAP RAM available 0x27c70 Buffer RX/TX: 0/0-0, open files: 0 === Duet Control Server === Duet Control Server version 3.6.0-beta.3 (2025-01-17 10:25:30, 64-bit) HTTP+Executed: > Executing M122 Code buffer space: 4096 Configured SPI speed: 8000000Hz, TfrRdy pin glitches: 2 Full transfers per second: 39.19, max time between full transfers: 17903.1ms, max pin wait times: 866.3ms/92.0ms Codes per second: 7.92 Maximum length of RX/TX data transfers: 4584/1648 2/3/2025, 6:27:34 PM Warning: SPI connection has been reset 2/3/2025, 6:27:34 PM Connection to Duet established 2/3/2025, 6:27:34 PM Warning: Lost connection to Duet (Timeout while waiting for transfer ready pin) 2/3/2025, 6:27:33 PM Warning: Did not get enough CPU time during SPI transfer, your SBC may be overloaded -
@fractalengineer said in [3.6.0-beta.3] Duet 3 MB6HC + Rpi3B+ CPU Overloaded?:
State: 5, disconnects: 13, timeouts: 13 total, 13 by SBC
That doesn't look right. What kind of microSD card are you using? Can you run
vcgencmd get_throttledon the SBC (e.g. via SSH or terminal) and confirm that it outputs 0x0? Something on your SBC slows down things too much for DSF to operate normally. -
@chrishamm nop no throttling of any kind. Using one of them Transcend 64G high endurance; no more than 6 months old too barely made any time
I just run an apt update/upgrade; will see how it does
-
@fractalengineer are you running any other processes on the Pi other than DSF / standard DuetPi build?
-
@T3P3Tony nothing; just dwc and vnc.
Just had the issue occur again on beta 4 in the middle of a print:
3/1/2025, 7:40:17 AM M122 === Diagnostics === RepRapFirmware for Duet 3 MB6HC version 3.6.0-beta.4 (2025-02-11 09:51:22) running on Duet 3 MB6HC v1.0 or earlier (SBC mode) Board ID: 08DJM-956L2-G43S4-6JTDA-3SS6L-1B76H Used output buffers: 1 of 40 (17 max) === RTOS === Static ram: 137396 Dynamic ram: 96696 of which 4584 recycled Never used RAM 104276, free system stack 122 words Tasks: SBC(2,nWait 7,1.0%,821) HEAT(3,nWait 6,0.0%,323) Move(4,nWait 6,0.3%,213) TMC(4,nWait 6,3.1%,341) CanReceiv(6,nWait 1,0.0%,770) CanSender(5,nWait 7,0.0%,327) CanClock(7,delaying,0.0%,348) MAIN(1,running,95.5%,101) IDLE(0,ready,0.0%,29) USBD(3,blocked,0.0%,149), total 100.0% Owned mutexes: HTTP(MAIN) === Platform === Last reset 08:12:26 ago, cause: software Last software reset at 2025-02-28 23:27, reason: User, Gcodes spinning, available RAM 105452, slot 1 Software reset code 0x2003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0x00000000 SP 0x00000000 Task SBC Freestk 0 n/a === 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 46, maxWait 5262568ms, bed comp in use: mesh, height map offset 0.012, hiccups added 0/0 (0.00/0.00ms), max steps late 0, ebfmin 0.00, ebfmax 0.00 Pos req/act/dcf: 176745.00/176745/-0.00 -11348.00/-11348/0.00 3844.00/3844/0.00 Next step interrupt due in 95 ticks, disabled Driver 0: standstill, SG min 0, mspos 362, reads 43384, writes 926 timeouts 86 Driver 1: standstill, SG min 0, mspos 390, reads 43384, writes 926 timeouts 86 Driver 2: standstill, SG min 0, mspos 8, reads 43385, writes 925 timeouts 86 Driver 3: standstill, SG min 0, mspos 440, reads 43385, writes 925 timeouts 86 Driver 4: standstill, SG min 0, mspos 920, reads 43386, writes 925 timeouts 86 Driver 5: standstill, SG min n/a, mspos 8, reads 43420, writes 891 timeouts 86 Phase step loop runtime (us): min=0, max=114, frequency (Hz): min=499, max=25862 === DDARing 0 === Scheduled moves 231128, completed 231128, LaErrors 0, Underruns [0, 0, 0] Segments left 0, axes/extruders owned 0x80000007, drives owned 0x80000007 Code queue is empty === DDARing 1 === Scheduled moves 0, completed 0, LaErrors 0, Underruns [0, 0, 0] Segments left 0, axes/extruders owned 0x00000000, drives owned 0x00000000 Code queue is empty === Heat === Bed heaters 0 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters -1 -1 -1 -1 -1 -1 -1 -1, ordering errs 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 === CAN === Messages queued 662406, received 591115, lost 0, ignored 0, errs 394, boc 0 Longest wait 2ms for reply type 6031, peak Tx sync delay 61516, free buffers 50 (min 48), ts 140031/140030/0 Tx timeouts 0,0,0,0,0,0 === SBC interface === Transfer state: 5, failed transfers: 0, checksum errors: 0 RX/TX seq numbers: 42751/30458 SPI underruns 0, overruns 0 State: 5, disconnects: 4, timeouts: 4 total, 4 by SBC, IAP RAM available 0x27a80 Buffer RX/TX: 0/0-0, open files: 0 === Duet Control Server === Duet Control Server version 3.6.0-beta.4 (2025-02-11 12:05:38, 64-bit) HTTP+Executed: > Executing M122 Code buffer space: 4096 Configured SPI speed: 8000000Hz, TfrRdy pin glitches: 0 Full transfers per second: 39.17, max time between full transfers: 37925.2ms, max pin wait times: 1022.3ms/24.1ms Codes per second: 17.07 Maximum length of RX/TX data transfers: 4580/1448 3/1/2025, 7:26:13 AM Warning: SPI connection has been reset 3/1/2025, 7:25:14 AM Warning: SPI connection has been reset 3/1/2025, 7:24:01 AM Warning: SPI connection has been reset 3/1/2025, 7:23:53 AM Warning: SPI connection has been resetI've also checked /var/log/syslog and here's the content:
Mar 1 00:00:04 duet3 syslogd (GNU inetutils 2.4): restart Mar 1 00:20:15 duet3 -- MARK -- Mar 1 00:40:15 duet3 -- MARK -- Mar 1 01:00:15 duet3 -- MARK -- Mar 1 01:20:15 duet3 -- MARK -- Mar 1 01:40:15 duet3 -- MARK -- Mar 1 02:00:15 duet3 -- MARK -- Mar 1 02:20:15 duet3 -- MARK -- Mar 1 02:20:40 duet3 vmunix: [10856.820231] kauditd_printk_skb: 11 callbacks suppressed Mar 1 02:20:40 duet3 vmunix: [10856.820256] audit: type=1400 audit(1740766840.671:23): apparmor="STATUS" operation="profile_load" profile="unconfined" name="/opt/dsf/plugins/ObjectCancel/**" pid=86601 comm="apparmor_parser" Mar 1 02:40:15 duet3 -- MARK -- Mar 1 03:00:15 duet3 -- MARK -- Mar 1 03:20:15 duet3 -- MARK -- Mar 1 03:40:15 duet3 -- MARK -- Mar 1 04:00:15 duet3 -- MARK -- Mar 1 04:20:15 duet3 -- MARK -- Mar 1 04:40:15 duet3 -- MARK -- Mar 1 05:00:15 duet3 -- MARK -- Mar 1 05:20:15 duet3 -- MARK -- Mar 1 05:40:15 duet3 -- MARK -- Mar 1 06:00:15 duet3 -- MARK -- Mar 1 06:20:15 duet3 -- MARK -- Mar 1 06:40:15 duet3 -- MARK -- Mar 1 06:54:22 duet3 vmunix: [27278.606049] mmc1: Controller never released inhibit bit(s). Mar 1 06:54:22 duet3 vmunix: [27278.606391] brcmfmac: brcmf_sdio_read_control: read 2048 control bytes failed: -5 Mar 1 06:54:22 duet3 vmunix: [27278.606412] brcmfmac: brcmf_sdio_rxfail: abort command, terminate frame, send NAK Mar 1 07:20:15 duet3 -- MARK -- -
@fractalengineer as a test please try a fresh DuetPi bookworm build on the SD card on the pi. Don't modify it other than to setup your printer.
