[3.6.0-beta.4 SBC] Abnormal program termination
-
@chrishamm
I guess I've just bad luck, but today I got the following.Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [warn] Resending packet #1 (request GetObjectModel) Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [fatal] Abnormal program termination Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [fatal] Update task faulted Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: System.Text.Json.JsonReaderException: The input does not contain any JSON tokens. Expected the input to start with a valid JSON token, when isFinalBlock is true. LineNumber: 0 | BytePositionInLine: 0. Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: at System.Text.Json.ThrowHelper.ThrowJsonReaderException(Utf8JsonReader& json, ExceptionResource resource, Byte nextByte, ReadOnlySpan`1 bytes) Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: at System.Text.Json.Utf8JsonReader.Read() Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: at DuetControlServer.Model.Updater.UpdateModel(Int32 offset, Boolean last) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Model/Updater.cs:line 150 Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: at DuetControlServer.Model.Updater.Run() in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Model/Updater.cs:line 320 Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [warn] Failed to find query for object model response Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [info] Starting macro file filament-error.g on channel Autopause Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [warn] HTTP: Aborting orphaned macro file 0:/macros/meltingplot/filament-extrusion-calibration Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [info] Aborted macro file 0:/macros/meltingplot/filament-extrusion-calibration Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [warn] HTTP: ==> Cancelling unfinished starting code: M98 P"0:/macros/meltingplot/filament-extrusion-calibration" Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [warn] Daemon: Aborting orphaned macro file daemon.g Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [info] Aborted macro file daemon.g Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [warn] Autopause: Aborting orphaned macro file filament-error.g Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [info] Aborted macro file filament-error.g Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [info] Event logging stopped Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [fatal] Update task faulted Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: System.Text.Json.JsonReaderException: The input does not contain any JSON tokens. Expected the input to start with a valid JSON token, when isFinalBlock is true. LineNumber: 0 | BytePositionInLine: 0. Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: at System.Text.Json.ThrowHelper.ThrowJsonReaderException(Utf8JsonReader& json, ExceptionResource resource, Byte nextByte, ReadOnlySpan`1 bytes) Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: at System.Text.Json.Utf8JsonReader.Read() Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: at DuetControlServer.Model.Updater.UpdateModel(Int32 offset, Boolean last) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Model/Updater.cs:line 150 Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: at DuetControlServer.Model.Updater.Run() in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Model/Updater.cs:line 320 Feb 15 09:59:49 Meltingplot-MBL-480-vaswsq DuetControlServer[475]: [info] Application has shut down
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.02 or 1.02a (SBC mode) Board ID: 08DJM-9P63L-DJ3T8-6JKD4-3SJ6K-9A77A Used output buffers: 1 of 40 (36 max) === RTOS === Static ram: 137396 Dynamic ram: 103212 of which 16 recycled Never used RAM 101992, free system stack 134 words Tasks: LASER(5,nWait 7,0.2%,223) SBC(2,delaying,6.8%,648) HEAT(3,nWait 6,0.0%,327) Move(4,nWait 6,0.0%,215) TMC(4,nWait 6,3.0%,343) CanReceiv(6,nWait 1,0.0%,814) CanSender(5,nWait 7,0.0%,326) CanClock(7,delaying,0.0%,341) MAIN(2,running,85.7%,101) IDLE(0,ready,4.2%,29) USBD(3,blocked,0.0%,144), total 100.0% Owned mutexes: HTTP(MAIN) === Platform === Last reset 00:37:39 ago, cause: power up Last software reset details not available === 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 60, maxWait 400876ms, bed comp in use: mesh, height map offset 0.000, hiccups added 0/0 (0.00/0.00ms), max steps late 1, ebfmin 0.00, ebfmax 0.00 Pos req/act/dcf: 63940.00/63940/0.00 31540.00/31540/0.00 371568.00/371568/0.00 Next step interrupt due in 45 ticks, disabled Driver 0: standstill, SG min 0, mspos 8, reads 61208, writes 649 timeouts 59 Driver 1: standstill, SG min 0, mspos 8, reads 61208, writes 649 timeouts 59 Driver 2: standstill, SG min 0, mspos 8, reads 61166, writes 692 timeouts 59 Driver 3: standstill, SG min 0, mspos 568, reads 61166, writes 692 timeouts 59 Driver 4: standstill, SG min 0, mspos 824, reads 61166, writes 692 timeouts 59 Driver 5: standstill, SG min 0, mspos 604, reads 61190, writes 668 timeouts 59 Phase step loop runtime (us): min=0, max=20, frequency (Hz): min=501, max=11363 === DDARing 0 === Scheduled moves 663, completed 663, 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 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 === Filament sensors === Driver 31: pos 13724.65, errs: frame 0 parity 0 ovrun 0 pol 0 ovdue 0 === CAN === Messages queued 20969, received 36170, lost 0, ignored 0, errs 6720, boc 0 Longest wait 233ms for reply type 6041, peak Tx sync delay 46599, free buffers 50 (min 48), ts 10710/10703/0 Tx timeouts 0,0,6,0,0,0 last cancelled message type 30 dest 127 === SBC interface === Transfer state: 5, failed transfers: 0, checksum errors: 0 RX/TX seq numbers: 8066/8066 SPI underruns 0, overruns 0 State: 5, disconnects: 1, timeouts: 1 total, 1 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:02:27, 32-bit) HTTP+Executed: > Executing M122 Daemon: Buffered code: G4 P100 ; wait 100ms Buffered codes: 32 bytes total >> Doing macro daemon.g, started by system >> Number of flush requests: 1 Code buffer space: 4096 Configured SPI speed: 8000000Hz, TfrRdy pin glitches: 0 Full transfers per second: 3915.48, max time between full transfers: 878.1ms, max pin wait times: 55.6ms/50.2ms Codes per second: 20.73 Maximum length of RX/TX data transfers: 8192/408
-
undefined Phaedrux moved this topic from DSF Development
-
@timschneider Do you have any more details about this bug, i.e. what G-code triggered it? Can you easily reproduce it?
-
This post is deleted! -
Ok - so it happend while I was using the filament-error to calibrate the E-Steps and non-linear extrusion. I set the error margin almost to zero +-0.5% and so there are a lot of events generated.
The following macro can trigger the bug
Content of0:/macros/test-event-system.g
if !exists(global.ignoreMFMevents) global ignoreMFMevents = true else set global.ignoreMFMevents = true while iterations < 1000 M957 E"filament-error" D0 P4 S"tooLittleMovement - The movement is below the minimum set in the R value of M591"
Contnet of
0:/sys/filament-error.g
if exists(global.ignoreMFMevents) && global.ignoreMFMevents == true M99
Have at least one DWC session open.
Call the macro0:/macros/test-event-system.g
Result in journalctl
Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Starting macro file filament-error.g on channel Autopause Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [warn] M957: a similar event is already queued Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Received file abort request on channel Autopause for the last file Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Aborted macro file filament-error.g Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Starting macro file filament-error.g on channel Autopause Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [warn] M957: a similar event is already queued Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Received file abort request on channel Autopause for the last file Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Aborted macro file filament-error.g Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Starting macro file filament-error.g on channel Autopause Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [warn] Resending packet #1 (request GetObjectModel) Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [fatal] Abnormal program termination Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [fatal] Update task faulted Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: System.Text.Json.JsonReaderException: The input does not contain any JSON tokens. Expected the input to start with a valid JSON token, when isFinalBlock is true. LineNumber: 0 | BytePositionInLine: 0. Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: at System.Text.Json.ThrowHelper.ThrowJsonReaderException(Utf8JsonReader& json, ExceptionResource resource, Byte nextByte, ReadOnlySpan`1 bytes) Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: at System.Text.Json.Utf8JsonReader.Read() Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: at DuetControlServer.Model.Updater.UpdateModel(Int32 offset, Boolean last) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Model/Updater.cs:line 150 Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: at DuetControlServer.Model.Updater.Run() in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Model/Updater.cs:line 296 Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [warn] Resending packet #0 (request GetObjectModel) Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [warn] M957: a similar event is already queued Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [warn] Failed to find query for object model response Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Received file abort request on channel Autopause for the last file Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Aborted macro file filament-error.g Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [warn] HTTP: Aborting orphaned macro file 0:/macros/test-event-system.g Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Aborted macro file 0:/macros/test-event-system.g Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [warn] HTTP: ==> Cancelling unfinished starting code: M98 P"0:/macros/test-event-system.g" Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [warn] Daemon: Aborting orphaned macro file daemon.g Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Aborted macro file daemon.g Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Event logging stopped Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [fatal] Update task faulted Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: System.Text.Json.JsonReaderException: The input does not contain any JSON tokens. Expected the input to start with a valid JSON token, when isFinalBlock is true. LineNumber: 0 | BytePositionInLine: 0. Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: at System.Text.Json.ThrowHelper.ThrowJsonReaderException(Utf8JsonReader& json, ExceptionResource resource, Byte nextByte, ReadOnlySpan`1 bytes) Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: at System.Text.Json.Utf8JsonReader.Read() Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: at DuetControlServer.Model.Updater.UpdateModel(Int32 offset, Boolean last) in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Model/Updater.cs:line 150 Feb 20 09:33:57 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: at DuetControlServer.Model.Updater.Run() in /home/runner/work/DuetSoftwareFramework/DuetSoftwareFramework/src/DuetControlServer/Model/Updater.cs:line 296 Feb 20 09:33:58 Meltingplot-MBL-480-vaswsq DuetControlServer[405]: [info] Application has shut down Feb 20 09:33:58 Meltingplot-MBL-480-vaswsq systemd[1]: duetcontrolserver.service: Main process exited, code=exited, status=70/SOFTWARE -- Subject: Unit process exited
EDIT: at the second attempt I was not able to reproduce it! Maybe it is related to
[warn] Resending packet #1 (request GetObjectModel)
as in the first try I saw many of these warnings and after a reboot, these warmings are gone and I can't reproduce the update thread bug.