[bug] System.NotSupportedException: Specified method is
-
While checking the log of the printer that crashes in sbc setup sometimes I found the following.
The error occured while hammering the DSF<->Duet3 SPI interface with requests via large printjob simulation and quering DSF via DWC to execute M122.
Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetWebServer[1321]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3] Route matched with {action = "DoCode", controller = "Machine"}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.IActionResult] DoCode(DuetWebServer.Singletons.ISessionStorage, Boolean) on controller DuetWebServer.Controllers.MachineController (DuetWebServer). Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetWebServer[1321]: DuetWebServer.Singletons.SessionStorage[0] Session a0b7b52e95b74569b4fcd0fc45803587 started a long-running request Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetWebServer[1321]: DuetWebServer.Controllers.MachineController[0] [DoCode] Executing code 'M122' Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetControlServer[744]: [error] HTTP: Failed to process code in stage Executed Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetControlServer[744]: System.NotSupportedException: Specified method is not supported. Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetControlServer[744]: at System.Threading.Channels.ChannelReader`1.get_Count() Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetControlServer[744]: at DuetControlServer.Codes.Pipelines.PipelineBase.Diagnostics(StringBuilder builder) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Codes/Pipelines/PipelineBase.cs:line 103 Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetControlServer[744]: at DuetControlServer.Codes.ChannelProcessor.Diagnostics(StringBuilder builder) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Codes/ChannelProcessor.cs:line 87 Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetControlServer[744]: at DuetControlServer.Codes.Processor.Diagnostics(StringBuilder builder) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Codes/Processor.cs:line 48 Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetControlServer[744]: at DuetControlServer.Codes.Handlers.MCodes.Diagnostics(Message result) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Codes/Handlers/MCodes.cs:line 1069 Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetControlServer[744]: at DuetControlServer.Codes.Handlers.MCodes.CodeExecuted(Code code) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Codes/Handlers/MCodes.cs:line 1033 Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetControlServer[744]: at DuetControlServer.Codes.Pipelines.Executed.ProcessCodeAsync(Code code) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Codes/Pipelines/Executed.cs:line 44 Jan 04 17:51:15 Meltingplot-MBL-480-vaswsq DuetControlServer[744]: at DuetControlServer.Codes.Pipelines.PipelineStackItem.<>c__DisplayClass0_0.<<-ctor>b__0>d.MoveNext() in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Codes/Pipelines/PipelineStackItem.cs:line 64 Jan 04 17:51:30 Meltingplot-MBL-480-vaswsq DuetWebServer[1321]: DuetWebServer.Singletons.SessionStorage[0] Session f0e11673864a49f68e1373ccbb7b2557 finished a long-running request Jan 04 17:51:30 Meltingplot-MBL-480-vaswsq DuetWebServer[1321]: DuetWebServer.Controllers.MachineController[0] [DoCode] DCS is not started Jan 04 17:51:30 Meltingplot-MBL-480-vaswsq DuetWebServer[1321]: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1] Executing ObjectResult, writing value of type 'System.String'. Jan 04 17:51:30 Meltingplot-MBL-480-vaswsq DuetWebServer[1321]: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2] Executed action DuetWebServer.Controllers.MachineController.DoCode (DuetWebServer) in 236398.3322ms Jan 04 17:51:30 Meltingplot-MBL-480-vaswsq DuetWebServer[1321]: Microsoft.AspNetCore.Routing.EndpointMiddleware[1] Executed endpoint 'DuetWebServer.Controllers.MachineController.DoCode (DuetWebServer)' Jan 04 17:51:30 Meltingplot-MBL-480-vaswsq DuetWebServer[1321]: Microsoft.AspNetCore.Hosting.Diagnostics[2] Request finished HTTP/1.1 POST http://192.168.172.110/machine/code text/plain;charset=UTF-8 4 - 503 - text/plain;+charset=utf-8 236402.9347ms Jan 04 17:51:38 Meltingplot-MBL-480-vaswsq DuetWebServer[1321]: DuetWebServer.Singletons.SessionStorage[0] Session f0e11673864a49f68e1373ccbb7b2557 expired
M122 at the moment DCS crashed from the eventlog
2024-01-04 17:51:15 === Diagnostics === RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.2 (2023-12-14 10:32:22) 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: 154844 Dynamic ram: 88272 of which 4072 recycled Never used RAM 95036, free system stack 119 words Tasks: SBC(2,nWait,6.6%,404) HEAT(3,nWait,0.0%,324) Move(4,nWait,42.8%,213) CanReceiv(6,nWait,0.0%,942) CanSender(5,nWait,0.0%,334) CanClock(7,delaying,0.0%,342) TMC(4,nWait,5.5%,61) MAIN(1,running,45.0%,103) IDLE(0,ready,0.0%,30), total 100.0% Owned mutexes: HTTP(MAIN) === Platform === Last reset 01:18:38 ago, cause: power up Last software reset at 2024-01-03 15:51, reason: OutOfMemory, Gcodes spinning, available RAM 428, slot 0 Software reset code 0x41c3 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00435000 BFAR 0x00000000 SP 0x2041b9a0 Task MAIN Freestk 2054 ok Stack: 2041808c 00419f61 00000103 2043229c 2043c740 0044659f 00000003 00000000 0000007c 01000003 ffffffff 00000000 00000253 2041bccc 2042bb20 204251b0 204251b0 00471301 00000000 00497caf 0000000a 00000000 00000000 00000000 00000000 00000000 004aea70 Error status: 0x00 MCU temperature: min 31.7, current 31.8, max 31.9 Supply voltage: min 24.1, current 24.1, max 24.1, under voltage events: 0, over voltage events: 0, power good: yes 12V rail voltage: min 12.0, current 12.2, max 12.6, under voltage events: 0 Heap OK, handles allocated/used 99/5, heap memory allocated/used/recyclable 2048/188/40, gc cycles 0 Events: 0 queued, 0 completed Driver 0: standstill, SG min n/a, mspos 200, reads 2920, writes 0 timeouts 0 Driver 1: standstill, SG min n/a, mspos 808, reads 2919, writes 0 timeouts 0 Driver 2: standstill, SG min n/a, mspos 744, reads 2919, writes 0 timeouts 0 Driver 3: standstill, SG min n/a, mspos 584, reads 2919, writes 0 timeouts 0 Driver 4: standstill, SG min n/a, mspos 584, reads 2920, writes 0 timeouts 0 Driver 5: standstill, SG min n/a, mspos 4, reads 2920, writes 0 timeouts 0 Date/time: 2024-01-04 17:51:14 Slowest loop: 24.27ms; fastest: 0.06ms === 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 38, maxWait 3ms, bed compensation in use: mesh, height map offset -0.015, max steps late 0, ebfmin 0.00, ebfmax 0.00 no step interrupt scheduled Moves shaped first try 78, on retry 4, too short 3, wrong shape 4601, maybepossible 0 === DDARing 0 === Scheduled moves 2252258, completed 2252233, 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 doing "G1 X560.140991 Y121.342003 E0.064190" 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 0x80000007 Code queue 0 is empty Q1 segments left 0, axes/extruders owned 0x0000000 Code queue 1 is empty === Filament sensors === check 0 clear 41551178 Extruder 0: pos 2160.00, errs: frame 0 parity 0 ovrun 0 pol 0 ovdue 0 === CAN === Messages queued 8, received 0, lost 0, errs 3722, boc 0 Longest wait 0ms for reply type 0, peak Tx sync delay 0, free buffers 50 (min 50), ts 4/0/0 Tx timeouts 0,0,4,0,0,4 last cancelled message type 30 dest 127 === SBC interface === Transfer state: 5, failed transfers: 0, checksum errors: 0 RX/TX seq numbers: 63584/63584 SPI underruns 0, overruns 0 State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x258a4 Buffer RX/TX: 2896/1136-4096, open files: 0
after DCS restarted
M122 === Diagnostics === RepRapFirmware for Duet 3 MB6HC version 3.5.0-rc.2 (2023-12-14 10:32:22) 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: 154844 Dynamic ram: 88272 of which 4072 recycled Never used RAM 95036, free system stack 119 words Tasks: SBC(2,ready,3.8%,404) HEAT(3,nWait,0.0%,324) Move(4,nWait,16.8%,213) CanReceiv(6,nWait,0.0%,942) CanSender(5,nWait,0.0%,334) CanClock(7,delaying,0.0%,342) TMC(4,nWait,6.9%,61) MAIN(2,running,72.4%,103) IDLE(0,ready,0.0%,30), total 100.0% Owned mutexes: HTTP(MAIN) === Platform === Last reset 01:30:01 ago, cause: power up Last software reset at 2024-01-03 15:51, reason: OutOfMemory, Gcodes spinning, available RAM 428, slot 0 Software reset code 0x41c3 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x00435000 BFAR 0x00000000 SP 0x2041b9a0 Task MAIN Freestk 2054 ok Stack: 2041808c 00419f61 00000103 2043229c 2043c740 0044659f 00000003 00000000 0000007c 01000003 ffffffff 00000000 00000253 2041bccc 2042bb20 204251b0 204251b0 00471301 00000000 00497caf 0000000a 00000000 00000000 00000000 00000000 00000000 004aea70 Error status: 0x00 MCU temperature: min 31.6, current 32.1, max 32.3 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 99/4, heap memory allocated/used/recyclable 2048/188/84, gc cycles 0 Events: 0 queued, 0 completed Driver 0: standstill, SG min n/a, mspos 200, reads 58753, writes 0 timeouts 0 Driver 1: standstill, SG min n/a, mspos 808, reads 58753, writes 0 timeouts 0 Driver 2: standstill, SG min n/a, mspos 744, reads 58753, writes 0 timeouts 0 Driver 3: standstill, SG min n/a, mspos 584, reads 58753, writes 0 timeouts 0 Driver 4: standstill, SG min n/a, mspos 584, reads 58752, writes 0 timeouts 0 Driver 5: standstill, SG min n/a, mspos 4, reads 58752, writes 0 timeouts 0 Date/time: 2024-01-04 18:02:38 Slowest loop: 34.87ms; fastest: 0.05ms === 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 38, maxWait 54ms, bed compensation in use: mesh, height map offset -0.015, max steps late 0, ebfmin 0.00, ebfmax 0.00 no step interrupt scheduled Moves shaped first try 36298, on retry 13009, too short 24420, wrong shape 1424794, maybepossible 4988 === DDARing 0 === Scheduled moves 4235707, completed 4235707, 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 0x80000003 Code queue 0 is empty Q1 segments left 0, axes/extruders owned 0x0000000 Code queue 1 is empty === Filament sensors === check 0 clear 46345336 Extruder 0: pos 2160.00, errs: frame 0 parity 0 ovrun 0 pol 0 ovdue 0 === CAN === Messages queued 6149, received 0, lost 0, errs 3242235, boc 0 Longest wait 0ms for reply type 0, peak Tx sync delay 0, free buffers 50 (min 50), ts 3416/0/0 Tx timeouts 0,0,3416,0,0,2733 last cancelled message type 4514 dest 127 === SBC interface === Transfer state: 5, failed transfers: 0, checksum errors: 0 RX/TX seq numbers: 2616/2616 SPI underruns 0, overruns 0 State: 5, disconnects: 0, timeouts: 0 total, 0 by SBC, IAP RAM available 0x258a4 Buffer RX/TX: 0/0-0, open files: 0 === Duet Control Server === Duet Control Server version 3.5.0-rc.2 (2023-12-18 12:42:49) 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: 8000000Hz, TfrRdy pin glitches: 0 Full transfers per second: 198.67, max time between full transfers: 64.9ms, max pin wait times: 43.0ms/33.7ms Codes per second: 741.41 Maximum length of RX/TX data transfers: 7392/3356
-
@timschneider One for @chrishamm
Ian
-
@timschneider Thanks for reporting this, it should be fixed now.
-