[3.5.0-rc.3] M122 causing Lost connection to Duet (Timeout

timschneider

Duet MB6HC in SBC mode with 3.5.0-rc.3.

When sending M122 it sometimes triggers a bug, which is causing a Error: A task was canceled or StuckInSpinLoop, Gcodes spinning - don't know what's first.

How to reproduce:
Send consecutive M122 until the connection is pending ( it is sometimes triggered with the first M122, sometimes it takes 10 - 15 times)

Output of M122

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.3 (2024-01-24 17:58:49) running on Duet 3 MB6HC v1.02 or later (SBC mode)
Board ID: 08DJM-9P63L-DJ3T8-6JKD4-3SJ6K-9A77A
Used output buffers: 1 of 40 (17 max)
=== RTOS ===
Static ram: 155184
Dynamic ram: 87932 of which 4800 recycled
Never used RAM 95220, free system stack 204 words
Tasks:=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.3 (2024-01-24 17:58:49) running on Duet 3 MB6HC v1.02 or later (SBC mode)
Board ID: 08DJM-9P63L-DJ3T8-6JKD4-3SJ6K-9A77A
Used output buffers: 1 of 40 (17 max)
=== RTOS ===
Static ram: 155184
Dynamic ram: 87932 of which 4776 recycled
Never used RAM 95244, free system stack 204 words
Tasks:=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.3 (2024-01-24 17:58:49) running on Duet 3 MB6HC v1.02 or later (SBC mode)
Board ID: 08DJM-9P63L-DJ3T8-6JKD4-3SJ6K-9A77A
Used output buffers: 1 of 40 (17 max)
=== RTOS ===
Static ram: 155184
Dynamic ram: 87932 of which 4776 recycled
Never used RAM 95244, free system stack 204 words
Tasks: SBC(2,ready,1.0%,404) HEAT(3,nWait 1,0.0%,325) Move(4,nWait 6,0.0%,336) CanReceiv(6,nWait 1,0.0%,940) CanSender(5,nWait 7,0.0%,334) CanClock(7,delaying,0.0%,338) TMC(4,nWait 6,8.5%,56) MAIN(2,running,88.6%,103) IDLE(0,ready,1.9%,30), total 100.0%
Owned mutexes: HTTP(MAIN)
=== Platform ===
Last reset 00:00:18 ago, cause: software
Last software reset at 2024-01-30 12:07, reason: StuckInSpinLoop, Gcodes spinning, available RAM 95244, slot 0
Software reset code 0x4083 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0040080f BFAR 0x00000000 SP 0x2041b8a0 Task TMC Freestk 4294961987 ok
Stack: 0000000d 00000000 2042fdd0 20419480 ffffffff 0041a123 0041a13a 210f0000 00000002 004a830c 20434300 20425cd0 20439a18 20439a4c 00000003 00000002 00000002 0010e48f 20439a94 00000194 2042fdd0 00000000 43425320 722c3228 74696157 0000003a 00000000
Error status: 0x00
MCU temperature: min 30.6, current 32.4, max 32.4
Supply voltage: min 24.0, current 24.1, max 24.2, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 11.9, current 12.3, max 12.7, under voltage events: 0
Heap OK, handles allocated/used 99/4, heap memory allocated/used/recyclable 2048/104/0, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min n/a, mspos 8, reads 38483, writes 22 timeouts 0
Driver 1: standstill, SG min n/a, mspos 8, reads 38483, writes 22 timeouts 0
Driver 2: standstill, SG min n/a, mspos 8, reads 38484, writes 21 timeouts 0
Driver 3: standstill, SG min n/a, mspos 8, reads 38484, writes 21 timeouts 0
Driver 4: standstill, SG min n/a, mspos 8, reads 38484, writes 21 timeouts 0
Driver 5: standstill, SG min n/a, mspos 4, reads 38486, writes 19 timeouts 0
Date/time: 2024-01-30 12:08:36
Slowest loop: 2.01ms; 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 ===
DMs created 125, segments created 0, maxWait 0ms, bed compensation in use: none, height map offset 0.000, max steps late 0, ebfmin 0.00, ebfmax 0.00
no step interrupt scheduled
Moves shaped first try 0, on retry 0, too short 0, wrong shape 0, maybepossible 0
=== DDARing 0 ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], 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 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters -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 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 0, axes/extruders owned 0x0000000
Code queue 0 is empty
Q1 segments left 0, axes/extruders owned 0x0000000
Code queue 1 is empty
=== Filament sensors ===
check 0 clear 151859
Extruder 0: pos 2160.00, errs: frame 0 parity 0 ovrun 0 pol 0 ovdue 0
=== CAN ===
Messages queued 166, received 0, lost 0, errs 87988, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 0, free buffers 50 (min 50), ts 94/0/0
Tx timeouts 0,0,93,0,0,71 last cancelled message type 4514 dest 127
=== SBC interface ===
Transfer state: 5, failed transfers: 0, checksum errors: 0
RX/TX seq numbers: 42990/748
SPI underruns 0, overruns 0
State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x255cc
Buffer RX/TX: 0/0-0, open files: 0
=== Duet Control Server ===
Duet Control Server version 3.5.0-rc.3 (2024-01-26 12:37:35)
Failed to deserialize the following properties:
- MoveSegmentation -> Int32 from 2.0
Daemon:
>> Doing macro daemon.g, started by system
Code buffer space: 4096
Configured SPI speed: 4000000Hz, TfrRdy pin glitches: 4
Full transfers per second: 37.23, max time between full transfers: 50.7ms, max pin wait times: 36.8ms/0.9ms
Codes per second: 1.48
Maximum length of RX/TX data transfers: 7228/892

aab471bb-f00a-4cf6-9954-be73915273f4.mp4

screenshot is taken from another event:
Screenshot 2024-01-30 at 12-21-13 Meltingplot-MBL-480-vaswsq.png

It is maybe connected to https://forum.duet3d.com/topic/34596/bug-system-notsupportedexception-specified-method-is

/EDIT:

output from /var/log/daemon.log

Jan 30 11:58:16 Meltingplot-MBL-480-vaswsq DuetWebServer[1366]: DuetWebServer.Controllers.MachineController[0] [DoCode] Failed to perform code System.Threading.Tasks.TaskCanceledException: A task was canceled.    at DuetAPIClient.BaseConnection.PerformCommand[T](BaseCommand command, CancellationToken cancellationToken) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetAPIClient/BaseConnection.cs:line 188    at DuetWebServer.Controllers.MachineController.DoCode(ISessionStorage sessionStorage, Boolean async) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetWebServer/Controllers/MachineController.cs:line 326

Jan 29 21:15:33 Meltingplot-MBL-480-vaswsq DuetWebServer[2957]: DuetWebServer.Controllers.MachineController[0] [DoCode] Executing code 'M122'
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetControlServer[3786]: [warn] Restarting full transfer because a bad header format code was received (0xff)
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetControlServer[3786]: [warn] Lost connection to Duet (Timeout while waiting for transfer ready pin)
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetControlServer[3786]: [info] Connection to Duet established
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetControlServer[3786]: [warn] Daemon: Aborting orphaned macro file daemon.g
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetControlServer[3786]: [info] Aborted macro file daemon.g
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetControlServer[3786]: [warn] SPI connection has been reset
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetWebServer[2957]: DuetWebServer.Singletons.SessionStorage[0] Session 9c73075b7e7f4966a5ed3890ddcb2ee3 finished a long-running request
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetControlServer[3786]: [info] Starting macro file config.g on channel Trigger
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetWebServer[2957]: DuetWebServer.Controllers.MachineController[0] [DoCode] Failed to perform code System.Threading.Tasks.TaskCanceledException: A task was canceled.    at DuetAPIClient.BaseConnection.PerformCommand[T](BaseCommand command, CancellationToken cancellationToken) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetAPIClient/BaseConnection.cs:line 188    at DuetWebServer.Controllers.MachineController.DoCode(ISessionStorage sessionStorage, Boolean async) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetWebServer/Controllers/MachineController.cs:line 326
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetWebServer[2957]: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1] Executing ObjectResult, writing value of type 'System.String'.
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetWebServer[2957]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2] Executed action DuetWebServer.Controllers.MachineController.DoCode (DuetWebServer) in 20620.4101ms
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetWebServer[2957]: Microsoft.AspNetCore.Routing.EndpointMiddleware[1] Executed endpoint 'DuetWebServer.Controllers.MachineController.DoCode (DuetWebServer)'
Jan 29 21:15:53 Meltingplot-MBL-480-vaswsq DuetWebServer[2957]: Microsoft.AspNetCore.Hosting.Diagnostics[2] Request finished HTTP/1.1 POST http://192.168.172.110/machine/code text/plain;charset=UTF-8 4 - 500 - text/plain;+charset=utf-8 20622.5019ms

droftarts

@timschneider one for @chrishamm

Ian

timschneider

@droftarts this is maybe for @dc42 as I guess it will stop in the output of the tasks list.

the Output of M122 in the eventlog will stop with the following:

2024-02-02 13:53:06 === Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.3 (2024-01-24 17:58:49) running on Duet 3 MB6HC v1.02 or later (SBC mode)
Board ID: 08DJM-9P63L-DJ3T8-6JKD4-3SJ6K-9A77A
Used output buffers: 1 of 40 (29 max)
=== RTOS ===
Static ram: 155184
Dynamic ram: 87860 of which 4848 recycled
Never used RAM 98100, free system stack 204 words
Tasks:Connection to SBC established!

and the Tasks parts was subject to changes in the last month.

I'm not able to check if this is a problem in standalone mode right now - maybe someone else can help here?

how to reproduce it in sbc mode (also testes with 6xd and rpi 4b)

M122 < keep pressing enter to send consecutive M122 requests as fast as possible until it will stuck>

M122 of today

m122
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.3 (2024-01-24 17:58:49) running on Duet 3 MB6HC v1.02 or later (SBC mode)
Board ID: 08DJM-9P63L-DJ3T8-6JKD4-3SJ6K-9A77A
Used output buffers: 1 of 40 (17 max)
=== RTOS ===
Static ram: 155184
Dynamic ram: 87836 of which 4872 recycled
Never used RAM 98100, free system stack 204 words
Tasks:=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.3 (2024-01-24 17:58:49) running on Duet 3 MB6HC v1.02 or later (SBC mode)
Board ID: 08DJM-9P63L-DJ3T8-6JKD4-3SJ6K-9A77A
Used output buffers: 1 of 40 (17 max)
=== RTOS ===
Static ram: 155184
Dynamic ram: 87860 of which 4848 recycled
Never used RAM 98100, free system stack 204 words
Tasks: SBC(2,ready,0.8%,402) HEAT(3,nWait 1,0.0%,323) Move(4,nWait 6,0.0%,336) CanReceiv(6,nWait 1,0.0%,940) CanSender(5,nWait 7,0.0%,334) CanClock(7,delaying,0.0%,334) TMC(4,nWait 6,8.6%,56) MAIN(2,running,90.6%,103) IDLE(0,ready,0.0%,30), total 100.0%
Owned mutexes: HTTP(MAIN)
=== Platform ===
Last reset 01:31:17 ago, cause: software
Last software reset at 2024-02-02 12:19, reason: StuckInSpinLoop, Gcodes spinning, available RAM 98100, slot 2
Software reset code 0x4083 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0043580f BFAR 0x00000000 SP 0x2041b8b4 Task MAIN Freestk 1983 ok
Stack: 0041a123 0041a13a 210f0000 468cdcfa 410a5e00 b7f83718 3f4d8366 00000000 20439a4c 00000003 00000002 00000002 000013c3 20439a94 00000196 2042fdd0 00000000 43425320 722c3228 74696157 0000003a 00000000 00000000 00000000 0001571c 00001308 00000000
Error status: 0x00
MCU temperature: min 30.1, current 32.0, max 32.2
Supply voltage: min 24.0, current 24.1, max 24.2, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 11.7, current 12.2, max 13.0, under voltage events: 0
Heap OK, handles allocated/used 0/0, heap memory allocated/used/recyclable 0/0/0, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min n/a, mspos 344, reads 5335, writes 22 timeouts 0
Driver 1: standstill, SG min n/a, mspos 1016, reads 5335, writes 22 timeouts 0
Driver 2: standstill, SG min n/a, mspos 680, reads 5336, writes 21 timeouts 0
Driver 3: standstill, SG min n/a, mspos 424, reads 5336, writes 21 timeouts 0
Driver 4: standstill, SG min n/a, mspos 168, reads 5336, writes 21 timeouts 0
Driver 5: standstill, SG min n/a, mspos 4, reads 5339, writes 19 timeouts 0
Date/time: 2024-02-02 13:50:57
Slowest loop: 1.91ms; fastest: 0.09ms
=== 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 ===
DMs created 125, segments created 0, maxWait 0ms, bed compensation in use: none, height map offset 0.000, max steps late 0, ebfmin 0.00, ebfmax 0.00
no step interrupt scheduled
Moves shaped first try 0, on retry 0, too short 0, wrong shape 0, maybepossible 0
=== DDARing 0 ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], 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 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters -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
Q0 segments left 0, axes/extruders owned 0x0000000
Code queue 0 is empty
Q1 segments left 0, axes/extruders owned 0x0000000
Code queue 1 is empty
=== Filament sensors ===
check 0 clear 47911997
Extruder 0: pos 2160.00, errs: frame 0 parity 0 ovrun 0 pol 0 ovdue 0
=== CAN ===
Messages queued 49293, received 0, lost 0, errs 25951542, boc 0
Longest wait 0ms for reply type 0, peak Tx sync delay 0, free buffers 50 (min 50), ts 27387/0/0
Tx timeouts 0,0,27386,0,0,21905 last cancelled message type 30 dest 127
=== SBC interface ===
Transfer state: 5, failed transfers: 0, checksum errors: 0
RX/TX seq numbers: 39880/18235
SPI underruns 0, overruns 0
State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x255cc
Buffer RX/TX: 0/0-0, open files: 0
=== Duet Control Server ===
Duet Control Server version 3.5.0-rc.3 (2024-01-29 19:29:19)
Failed to deserialize the following properties:
- MoveSegmentation -> Int32 from 2.0
Code buffer space: 4096
Configured SPI speed: 8000000Hz, TfrRdy pin glitches: 4
Full transfers per second: 39.18, max time between full transfers: 530.4ms, max pin wait times: 36.8ms/8.8ms
Codes per second: 0.02
Maximum length of RX/TX data transfers: 7224/920

timschneider

ok now I'm pretty sure that this is the dead lock

				const Mutex *m = Mutex::GetMutexList();
				while (m != nullptr)
				{
					if ((const void *)m == taskDetails.pvResource)
					{
						str.catf(" %s", m->GetName());
						break;
					}
				}

as there is a

m = m->GetNext();

missing.

ww1g16

@timschneider Unsure whether or not this helps track anything down, but whilst debugging some networking issues I was having whilst using 3.5.0-rc.2 I noticed that I've got StuckInSpinLoop being reported by M122. Having not looked at the git diff between rc.2 and rc.3, I'm unsure whether the section you mention has had any changes that would also be present in rc.2. If not, disregard my comment as irrelevant.

=== Platform ===
Last reset 03:05:28 ago, cause: software
Last software reset at 2024-02-02 12:31, reason: StuckInSpinLoop, Platform spinning, available RAM 13156, slot 2
Software reset code 0x4080 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0041f80f BFAR 0xe000ed38 SP 0x200027e0 Task NETW Freestk 4294966993 ok
Stack: fffffdff 00000000 00000000 00000009 00429eed 0040c6ef 0040c71e 41000000 0040c4cd 3f317200 b5dda462 388ab355 bb360b61 3e2aaaab 20004bbc 00000000 fd93463c a5a5a5a5 a5a5a5a5 a5a5a5a5 0040da6b 20004bbc a5a5a5a5 a5a5a5a5 00410441 a5a5a5a5 0045db95
Error status: 0x04
MCU temperature: min 25.8, current 26.4, max 29.0
Supply voltage: min 24.5, current 24.6, max 25.0, under voltage events: 0, over voltage events: 0, power good: yes
Heap OK, handles allocated/used 0/0, heap memory allocated/used/recyclable 0/0/0, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min n/a
Driver 1: standstill, SG min n/a
Driver 2: standstill, SG min n/a
Driver 3: standstill, SG min n/a
Driver 4: standstill, SG min n/a
Driver 5: 
Driver 6: 
Driver 7: 
Driver 8: 
Driver 9: 
Driver 10: 
Driver 11: 
Date/time: 2024-02-02 15:36:48
Cache data hit count 4294967295
Slowest loop: 11.13ms; fastest: 0.20ms
I2C nak errors 0, send timeouts 0, receive timeouts 0, finishTimeouts 0, resets 0

Duet 2 WiFi		2WiFi	3.5.0-rc.2
Duet WiFi Server	n/a	2.1beta6
Duet Web Control	DWC	3.5.0-rc.2

T3P3Tony

@dc42 /@chrishamm

I can confirm this in SBC mode as well.

The First M122 i got had a "normal" response, the machine has been up for a while:

=== Platform ===
Last reset 47:24:53 ago, cause: power up
Last software reset at 2024-01-31 16:51, reason: User, Gcodes spinning, available RAM 94244, slot 1
Software reset code 0x6003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00400000 BFAR 0x00000000 SP 0x00000000 Task SBC Freestk 0 n/a

From the second M122 I got no response initially, then a system reset:

Note it appears to have lost two connectivity to two 1HCLs

this is the M122 response I got when i sent it after the system recovered from the reset

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.3 (2024-01-24 17:58:49) running on Duet 3 MB6HC v1.0 or earlier (SBC mode)
Board ID: 08DGM-9T66A-G63SJ-6J9D8-3SD6R-KV0HA
Used output buffers: 1 of 40 (21 max)
=== RTOS ===
Static ram: 155184
Dynamic ram: 90892 of which 2192 recycled
Never used RAM 94244, free system stack 140 words
Tasks:=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.3 (2024-01-24 17:58:49) running on Duet 3 MB6HC v1.0 or earlier (SBC mode)
Board ID: 08DGM-9T66A-G63SJ-6J9D8-3SD6R-KV0HA
Used output buffers: 1 of 40 (19 max)
Error in macro line 49 while starting up: M584: Driver 51.0 does not exist
Driver 50.0 does not exist
=== RTOS ===
Static ram: 155184
Dynamic ram: 89900 of which 2832 recycled
Never used RAM 95220, free system stack 202 words
Tasks: SBC(2,ready,1.2%,434) HEAT(3,nWait 6,0.0%,329) Move(4,nWait 6,0.0%,336) CanReceiv(6,nWait 1,0.1%,795) CanSender(5,nWait 7,0.0%,334) CanClock(7,delaying,0.0%,348) TMC(4,nWait 6,8.3%,54) MAIN(2,running,88.7%,103) IDLE(0,ready,1.7%,30), total 100.0%
Owned mutexes: HTTP(MAIN)
=== Platform ===
Last reset 00:01:09 ago, cause: software
Last software reset at 2024-02-02 16:32, reason: StuckInSpinLoop, Gcodes spinning, available RAM 94244, slot 2
Software reset code 0x4083 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0040080f BFAR 0x00000000 SP 0x2041b8b4 Task MAIN Freestk 1983 ok
Stack: 0041a123 0041a13a 210f0000 a8000000 40006ea1 99fe5fae bf600a2e 00000000 20439a4c 00000003 00000002 00000002 00000f98 20439a94 00000164 2042fdd0 00000000 43425320 722c3228 74696157 0000003a 00000000 00000000 00000000 0001630c 00000890 00000000
Error status: 0x00
MCU temperature: min 40.1, current 42.3, max 42.5
Supply voltage: min 24.1, current 24.1, max 24.2, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.1, current 12.2, max 12.2, under voltage events: 0
Heap OK, handles allocated/used 99/6, heap memory allocated/used/recyclable 2048/120/0, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min n/a, mspos 8, reads 60315, writes 11 timeouts 0
Driver 1: standstill, SG min n/a, mspos 8, reads 60316, writes 11 timeouts 0
Driver 2: standstill, SG min n/a, mspos 312, reads 60312, writes 15 timeouts 0
Driver 3: standstill, SG min n/a, mspos 272, reads 60311, writes 16 timeouts 0
Driver 4: standstill, SG min n/a, mspos 8, reads 60316, writes 11 timeouts 0
Driver 5: standstill, SG min n/a, mspos 8, reads 60316, writes 11 timeouts 0
Date/time: 2024-02-02 16:33:38
Slowest loop: 2.48ms; 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 ===
DMs created 125, segments created 0, maxWait 0ms, bed compensation in use: none, height map offset 0.000, max steps late 0, ebfmin 0.00, ebfmax 0.00
no step interrupt scheduled
Moves shaped first try 0, on retry 0, too short 0, wrong shape 0, maybepossible 0
=== DDARing 0 ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], 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 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters -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
Q0 segments left 0, axes/extruders owned 0x0000000
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 1: no data received, errs: frame 0 parity 0 ovrun 0 pol 0 ovdue 0
Extruder 2: no data received, errs: frame 0 parity 0 ovrun 0 pol 0 ovdue 0
=== CAN ===
Messages queued 666, received 5414, lost 0, errs 1, boc 0
Longest wait 2ms for reply type 6053, peak Tx sync delay 162, free buffers 50 (min 49), ts 348/347/0
Tx timeouts 0,0,0,0,0,0
=== SBC interface ===
Transfer state: 5, failed transfers: 0, checksum errors: 0
RX/TX seq numbers: 52218/5350
SPI underruns 0, overruns 0
State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x255cc
Buffer RX/TX: 0/0-0, open files: 0
=== Duet Control Server ===
Duet Control Server version 3.5.0-rc.3 (2024-01-25 13:46:00)
Code buffer space: 4096
Configured SPI speed: 8000000Hz, TfrRdy pin glitches: 0
Full transfers per second: 65.81, max time between full transfers: 53.5ms, max pin wait times: 274.9ms/4.4ms
Codes per second: 1.16
Maximum length of RX/TX data transfers: 5288/1020

Also note how the reply looks like parts of 2 M122 replies mixed together at the start.

I did it again after a full board reboot and M122 did not report at all this time:

note i have a G0 S2 in config.g and normally do not get the errors on startup about boards 50 and 51

M122 after the reset:

M122
=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.3 (2024-01-24 17:58:49) running on Duet 3 MB6HC v1.0 or earlier (SBC mode)
Board ID: 08DGM-9T66A-G63SJ-6J9D8-3SD6R-KV0HA
Used output buffers: 1 of 40 (21 max)
=== RTOS ===
Static ram: 155184
Dynamic ram: 90252 of which 2832 recycled
Never used RAM 94868, free system stack 202 words
Tasks:=== Diagnostics ===
RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.3 (2024-01-24 17:58:49) running on Duet 3 MB6HC v1.0 or earlier (SBC mode)
Board ID: 08DGM-9T66A-G63SJ-6J9D8-3SD6R-KV0HA
Used output buffers: 1 of 40 (19 max)
Error in macro line 49 while starting up: M584: Driver 51.0 does not exist
Driver 50.0 does not exist
=== RTOS ===
Static ram: 155184
Dynamic ram: 89900 of which 2832 recycled
Never used RAM 95220, free system stack 202 words
Tasks: SBC(2,ready,1.1%,430) HEAT(3,nWait 6,0.0%,323) Move(4,nWait 6,0.0%,336) CanReceiv(6,nWait 1,0.1%,795) CanSender(5,nWait 7,0.0%,334) CanClock(7,delaying,0.0%,348) TMC(4,nWait 6,8.3%,54) MAIN(2,running,90.2%,103) IDLE(0,ready,0.3%,30), total 100.0%
Owned mutexes: HTTP(MAIN)
=== Platform ===
Last reset 00:01:26 ago, cause: software
Last software reset at 2024-02-02 16:53, reason: StuckInSpinLoop, Gcodes spinning, available RAM 94868, slot 2
Software reset code 0x4083 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0044a80f BFAR 0x00000000 SP 0x2041b8b4 Task MAIN Freestk 1983 ok
Stack: 0041a123 0041a13a 210f0000 46ea6000 3feb57cd 00000000 47518684 456a6000 20439a4c 00000003 00000002 00000002 000620b8 20439a94 000001a2 2042fdd0 00000000 43425320 722c3228 74696157 0000003a 00000000 00000000 00000000 0001608c 00000b10 00000000
Error status: 0x00
MCU temperature: min 39.7, current 41.9, max 42.1
Supply voltage: min 24.1, current 24.1, max 24.2, under voltage events: 0, over voltage events: 0, power good: yes
12V rail voltage: min 12.1, current 12.2, max 12.2, under voltage events: 0
Heap OK, handles allocated/used 99/6, heap memory allocated/used/recyclable 2048/120/0, gc cycles 0
Events: 0 queued, 0 completed
Driver 0: standstill, SG min n/a, mspos 8, reads 25509, writes 11 timeouts 0
Driver 1: standstill, SG min n/a, mspos 8, reads 25509, writes 11 timeouts 0
Driver 2: standstill, SG min n/a, mspos 312, reads 25505, writes 15 timeouts 0
Driver 3: standstill, SG min n/a, mspos 272, reads 25504, writes 16 timeouts 0
Driver 4: standstill, SG min n/a, mspos 8, reads 25509, writes 11 timeouts 0
Driver 5: standstill, SG min n/a, mspos 8, reads 25509, writes 11 timeouts 0
Date/time: 2024-02-02 16:55:44
Slowest loop: 2.53ms; fastest: 0.08ms
=== 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 ===
DMs created 125, segments created 0, maxWait 0ms, bed compensation in use: none, height map offset 0.000, max steps late 0, ebfmin 0.00, ebfmax 0.00
no step interrupt scheduled
Moves shaped first try 0, on retry 0, too short 0, wrong shape 0, maybepossible 0
=== DDARing 0 ===
Scheduled moves 0, completed 0, hiccups 0, stepErrors 0, LaErrors 0, Underruns [0, 0, 0], 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 -1 -1 -1 -1 -1 -1 -1 -1, chamber heaters -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
Q0 segments left 0, axes/extruders owned 0x0000000
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 1: no data received, errs: frame 0 parity 0 ovrun 0 pol 0 ovdue 0
Extruder 2: no data received, errs: frame 0 parity 0 ovrun 0 pol 0 ovdue 0
=== CAN ===
Messages queued 817, received 6742, lost 0, errs 1, boc 0
Longest wait 3ms for reply type 6053, peak Tx sync delay 67, free buffers 50 (min 49), ts 435/434/0
Tx timeouts 0,0,0,0,0,0
=== SBC interface ===
Transfer state: 5, failed transfers: 0, checksum errors: 0
RX/TX seq numbers: 9325/5788
SPI underruns 0, overruns 0
State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x255cc
Buffer RX/TX: 0/0-0, open files: 0
=== Duet Control Server ===
Duet Control Server version 3.5.0-rc.3 (2024-01-25 13:46:00)
Code buffer space: 4096
Configured SPI speed: 8000000Hz, TfrRdy pin glitches: 0
Full transfers per second: 57.72, max time between full transfers: 297.4ms, max pin wait times: 260.4ms/15.4ms
Codes per second: 1.26
Maximum length of RX/TX data transfers: 5444/1016

timschneider

I've added corresponding issue and pull request on Github.
https://github.com/Duet3D/RepRapFirmware/pull/955

The Binary for MB6HC
Duet3Firmware_MB6HC.bin

That solved the problem for me.

timschneider opened this pull request in Duet3D/RepRapFirmware

closed Fix M122 StuckInSpinLoop, Gcodes spinning #955

T3P3Tony

@timschneider thanks for this!