Another 'Hang' of DWC



  • Whilst playing with sensorless homing I've started getting some odd hangs from DWC.

    After selecting to home X or Y the gantry starts to move (CoreXY), it never reaches the home point and eventually this pops up

    20/02/2020, 21:18:49 Error: G0/G1: insufficient axes homed
    20/02/2020, 21:21:07 G28 Y
    Error: Operation failed (Reason: Transport endpoint is not connected)

    But once this error is received the web page isn't responsive. Whichever axis I was trying to home has the 'whirling circle' or whatever it is and the only way to regain control is to hard reset the Duet (Duet 3 running V3 RC2 and DWC 2.07) - basically power cycle.

    The temperature etc are still updating but no 'user' interaction with the dashboard is possible. You can select menu options, I even opened config.g and saved, selected 'yes' to reset the board but this changes nothing - the dashboard remains in the previous state, you can elect to select home for the other axis but other than the whirling circle appearing for that axis nothing happens, it is not possible to issue console commands.

    I'm running this from a Raspberry Pi 4, the Pi is not overheating or throttling.



  • Could you try rebooting just the pi next time?



  • That certainly clears the problem ....

    I do not get any indication of disconnection until I reboot the Pi



  • I've not been following the development of the Pi stuff closely lately, but I believe there are two different services DuetControlServer and DuetWebServer could you try just restarting one of those and see which one resolves the problem, then you can start looking for the logfiles etc to help debug the isuse.


  • Moderator



  • Sounds identical, I see this error a lot in syslog ...

    Feb 20 21:59:39 duet3 vncserver-x11[467,root]: AgentInitCheck: agent comms failure
    Feb 20 21:59:44 duet3 vncserver-x11[467,root]: AgentInitCheck: no response from agent

    Why would I be seeing VNC server failures - ????????

    Where would I find the duet control log ... and why can't linux distro's be consistent !!!!

    Details of Duet

    DSF Version: 1.2.4.0
    Firmware: RepRapFirmware for Duet 3 MB6HC v0.6 or 1.0 3.01-RC2 (2020-02-18b1)


  • Moderator

    @Garfield Unfortunately I don't have a working Pi4+Duet 3 working setup yet, so can't help with the details. This seems to be a DSF issue, so one for @chrishamm to look at.

    Ian



  • @Garfield said in Another 'Hang' of DWC:

    Why would I be seeing VNC server failures - ????????

    its part of the stock image unless you download the lite version with no x winows (or disable with raspi-config or remove with apt)



  • DSF logs are available via:

    sudo journalctl -f

    Or, if you want JUST a particular log:

    sudo journalctl -fu duetwebserver
    sudo journalctl -fu duetcontrolserver



  • @Danal said in Another 'Hang' of DWC:

    sudo journalctl -fu duetwebserver

    No particular crash report web server

    Feb 21 10:52:18 duet3 DuetWebServer[453]: info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
    Feb 21 10:52:18 duet3 DuetWebServer[453]:       Request starting HTTP/1.1 POST http://10.100.2.225/machine/code text/plain;charset=UTF-8 5
    Feb 21 10:52:18 duet3 DuetWebServer[453]: info: Microsoft.AspNetCore.Cors.Infrastructure.CorsService[4]
    Feb 21 10:52:18 duet3 DuetWebServer[453]:       CORS policy execution successful.
    Feb 21 10:52:18 duet3 DuetWebServer[453]: info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
    Feb 21 10:52:18 duet3 DuetWebServer[453]:       Executing endpoint 'DuetWebServer.Controllers.MachineController.DoCode (DuetWebServer)'
    Feb 21 10:52:18 duet3 DuetWebServer[453]: info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
    Feb 21 10:52:18 duet3 DuetWebServer[453]:       Route matched with {action = "DoCode", controller = "Machine"}. Executing controller action with signature System.Threading.Tasks.Task`1[Microsoft.AspNetCore.Mvc.IActionResult] DoCode() on controller DuetWebServer.Controllers.MachineController (DuetWebServer).
    Feb 21 10:52:18 duet3 DuetWebServer[453]: info: DuetWebServer.Controllers.MachineController[0]
    Feb 21 10:52:18 duet3 DuetWebServer[453]:       [DoCode] Executing code 'G28 X'
    

    Nor Duet control server

    Feb 21 00:17:10 duet3 DuetControlServer[373]: [warn] heater 1 appears to be over-powered. If left on at full power, its temperature is predicted to reach 365C.
    Feb 21 00:17:11 duet3 DuetControlServer[373]: [info] Executing nested macro file config-override.g on channel Daemon
    Feb 21 00:17:11 duet3 DuetControlServer[373]: [info] Daemon: Finished macro file config-override.g
    Feb 21 00:17:11 duet3 DuetControlServer[373]: [info] Daemon: Finished system macro file config.g
    Feb 21 10:24:07 duet3 DuetControlServer[373]: [info] System time has been changed
    Feb 21 10:52:19 duet3 DuetControlServer[373]: [info] Executing nested macro file homex.g on channel HTTP
    Feb 21 10:52:49 duet3 DuetControlServer[373]: [info] Received file abort request on channel HTTP for all files
    Feb 21 10:52:49 duet3 DuetControlServer[373]: [info] Aborted macro file
    Feb 21 10:52:49 duet3 DuetControlServer[373]: [warn] HTTP: Out-of-order reply: 'G0/G1: insufficient axes homed'
    Feb 21 10:52:49 duet3 DuetControlServer[373]: [error] G0/G1: insufficient axes homed
    

    I wonder if the out of order reply is the trigger ....



  • It is certainly a symptom, but we already knew that from the DWC console.

    The "out of order" just means it came over the socket on its own, not as a sequenced response to something. We knew that also.



  • How can I assist further ? - makes sense to do so while I can reproduce the problem at will.

    Restarting the service definitely fixes the problem.

    Incidentally I did not send any 'abort' requests so I don't know why the 'Received file abort' is there.



  • I just noticed the "System Time Has Been Changed".

    For me, changing the time on the Pi will kill a print. Cause a hang or a fault.

    Do we know what is causing that?



  • @Danal said in Another 'Hang' of DWC:

    sudo journalctl -f

    I just ran again since those logs I had recently turned on, these logs are from the system that's been enabled a while (like ever since).

    -- Logs begin at Fri 2020-02-21 14:17:01 GMT. --
    Feb 21 23:17:29 duet3 DuetWebServer[442]:       G90
    Feb 21 23:17:29 duet3 DuetWebServer[442]:       M121'
    Feb 21 23:17:29 duet3 DuetWebServer[442]: info: Microsoft.AspNetCore.Mvc.Infrastructure.ContentResultExecutor[1]
    Feb 21 23:17:29 duet3 DuetWebServer[442]:       Executing ContentResult with HTTP Response ContentType of text/plain; charset=utf-8
    Feb 21 23:17:29 duet3 DuetWebServer[442]: info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
    Feb 21 23:17:29 duet3 DuetWebServer[442]:       Executed action DuetWebServer.Controllers.MachineController.DoCode (DuetWebServer) in 426.4927ms
    Feb 21 23:17:29 duet3 DuetWebServer[442]: info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
    Feb 21 23:17:29 duet3 DuetWebServer[442]:       Executed endpoint 'DuetWebServer.Controllers.MachineController.DoCode (DuetWebServer)'
    Feb 21 23:17:29 duet3 DuetWebServer[442]: info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
    Feb 21 23:17:29 duet3 DuetWebServer[442]:       Request finished in 427.1703ms 200 text/plain; charset=utf-8
    
    pi@duet3:~ $ sudo journalctl -fu duetcontrolserver
    -- Logs begin at Fri 2020-02-21 14:17:01 GMT. --
    Feb 21 23:16:15 duet3 DuetControlServer[371]: [warn] Resetting controller
    Feb 21 23:16:16 duet3 DuetControlServer[371]: [info] Connection to Duet established
    Feb 21 23:16:16 duet3 DuetControlServer[371]: [info] Executing system macro file config.g on channel Daemon
    Feb 21 23:16:16 duet3 DuetControlServer[371]: [warn] heater 1 appears to be over-powered. If left on at full power, its temperature is predicted to reach 365C.
    Feb 21 23:16:17 duet3 DuetControlServer[371]: [info] Executing nested macro file config-override.g on channel Daemon
    Feb 21 23:16:17 duet3 DuetControlServer[371]: [info] Daemon: Finished macro file config-override.g
    Feb 21 23:16:17 duet3 DuetControlServer[371]: [info] Daemon: Finished system macro file config.g
    Feb 21 23:17:29 duet3 DuetControlServer[371]: [info] Received file abort request on channel HTTP for all files
    Feb 21 23:17:29 duet3 DuetControlServer[371]: [warn] HTTP: Out-of-order reply: 'G0/G1: insufficient axes homed'
    Feb 21 23:17:29 duet3 DuetControlServer[371]: [error] G0/G1: insufficient axes homed
    
    pi@duet3:~ $ sudo journalctl -f
    -- Logs begin at Fri 2020-02-21 14:17:01 GMT. --
    Feb 21 23:19:04 duet3 sudo[28383]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
    Feb 21 23:19:09 duet3 vncserver-x11[463]: AgentInitCheck: no response from agent
    Feb 21 23:19:14 duet3 vncserver-x11[463]: AgentInitCheck: agent comms failure
    Feb 21 23:19:19 duet3 vncserver-x11[463]: AgentInitCheck: no response from agent
    Feb 21 23:19:24 duet3 vncserver-x11[463]: AgentInitCheck: agent comms failure
    Feb 21 23:19:26 duet3 sudo[28383]: pam_unix(sudo:session): session closed for user root
    Feb 21 23:19:29 duet3 vncserver-x11[463]: AgentInitCheck: no response from agent
    Feb 21 23:19:34 duet3 vncserver-x11[463]: AgentInitCheck: agent comms failure
    Feb 21 23:19:37 duet3 sudo[28480]:       pi : TTY=pts/0 ; PWD=/home/pi ; USER=root ; COMMAND=/usr/bin/journalctl -f
    Feb 21 23:19:37 duet3 sudo[28480]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
    Feb 21 23:19:39 duet3 vncserver-x11[463]: AgentInitCheck: no response from agent
    Feb 21 23:19:44 duet3 vncserver-x11[463]: AgentInitCheck: agent comms failure
    Feb 21 23:19:49 duet3 vncserver-x11[463]: AgentInitCheck: no response from agent
    

    The systemctl status says the service is running

    duetcontrolserver.service                     loaded active running   Duet Control Server                                                                     
    duetwebserver.service                          loaded active running   Duet Web Server
    

    but interaction is not possible, I persisted in pushing buttons and got an

    Error: Push(): Stack overflow

    Feb 21 23:26:58 duet3 DuetControlServer[371]: [info] Received file abort request on channel HTTP for all files
    Feb 21 23:26:58 duet3 DuetControlServer[371]: [warn] HTTP: Out-of-order reply: 'G0/G1: insufficient axes homed'
    Feb 21 23:26:58 duet3 DuetControlServer[371]: [error] G0/G1: insufficient axes homed
    Feb 21 23:26:59 duet3 DuetControlServer[371]: [info] Received file abort request on channel HTTP for all files
    Feb 21 23:26:59 duet3 DuetControlServer[371]: [warn] HTTP: Out-of-order reply: 'G0/G1: insufficient axes homed'
    Feb 21 23:26:59 duet3 DuetControlServer[371]: [error] G0/G1: insufficient axes homed
    Feb 21 23:26:59 duet3 DuetControlServer[371]: [error] Push(): stack overflow
    Feb 21 23:27:00 duet3 DuetControlServer[371]: [info] Received file abort request on channel HTTP for all files
    Feb 21 23:27:00 duet3 DuetControlServer[371]: [warn] HTTP: Out-of-order reply: 'G0/G1: insufficient axes homed'
    Feb 21 23:27:00 duet3 DuetControlServer[371]: [error] G0/G1: insufficient axes homed
    


  • The Duetcontrolserver hang / fail is still happening, it is unpredictable but occurs most during homing. The web gui still functions for some things but is useless for any kind of control once this occurs.

    Does anyone have a way to put this service into some sort of debug mode because there is nothing useful logged - it is almost as though the Pi doesn't know the service isn't working, this may be a communication failure between the web service and the control service and not actually a service failure.

    The latest logs from the latest 'crash' - absolutely useless ..... I will be removing VNC since it serves no useful purpose to have a remote access to a browser window - that I already have access to.

    pi@duet3:~ $ sudo journalctl -fu duetcontrolserver
    -- Logs begin at Sun 2020-03-08 00:17:01 GMT. --
    Mar 09 12:03:00 duet3 DuetControlServer[13318]:    DuetAPI.Commands.CodeParserException: Duplicate P parameter
    Mar 09 12:03:00 duet3 DuetControlServer[13318]:    at DuetAPI.Commands.Code.Parse(TextReader reader, Code result, Boolean& enforcingAbsolutePosition) in /home/christian/duet/DuetSoftwareFramework/src/DuetAPI/Commands/Code/Parser.cs:line 339
    Mar 09 12:03:00 duet3 DuetControlServer[13318]:    at DuetControlServer.FileExecution.BaseFile.ReadCode() in /home/christian/duet/DuetSoftwareFramework/src/DuetControlServer/FileExecution/BaseFile.cs:line 154
    Mar 09 12:03:00 duet3 DuetControlServer[13318]:    at DuetControlServer.FileExecution.MacroFile.ReadCode() in /home/christian/duet/DuetSoftwareFramework/src/DuetControlServer/FileExecution/MacroFile.cs:line 187
    Mar 09 12:03:00 duet3 DuetControlServer[13318]:    at DuetControlServer.SPI.ChannelInformation.ProcessRequests() in /home/christian/duet/DuetSoftwareFramework/src/DuetControlServer/SPI/ChannelInformation.cs:line 221
    Mar 09 12:03:00 duet3 DuetControlServer[13318]: [warn] heater 0 appears to be over-powered. If left on at full power, its temperature is predicted to reach 875C.
    Mar 09 12:03:00 duet3 DuetControlServer[13318]: [info] Executing nested macro file config-override.g on channel Daemon
    Mar 09 12:03:00 duet3 DuetControlServer[13318]: [error] G31: Cannot set a temperature coefficient without a valid heater number
    Mar 09 12:03:00 duet3 DuetControlServer[13318]: [info] Daemon: Finished macro file config-override.g
    Mar 09 12:03:00 duet3 DuetControlServer[13318]: [info] Daemon: Finished system macro file config.g
    
     ^H
    
    ^C
    pi@duet3:~ $ sudo journalctl -fu duetwebserver
    -- Logs begin at Sun 2020-03-08 00:17:01 GMT. --
    Mar 09 12:03:26 duet3 DuetWebServer[442]:    at DuetAPIClient.BaseConnection.PerformCommand[T](BaseCommand command, CancellationToken cancellationToken) in /home/christian/duet/DuetSoftwareFramework/src/DuetAPIClient/BaseConnection.cs:line 178
    Mar 09 12:03:26 duet3 DuetWebServer[442]:    at DuetWebServer.Controllers.MachineController.DoCode() in /home/christian/duet/DuetSoftwareFramework/src/DuetWebServer/Controllers/MachineController.cs:line 100
    Mar 09 12:03:26 duet3 DuetWebServer[442]: info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
    Mar 09 12:03:26 duet3 DuetWebServer[442]:       Executing ObjectResult, writing value of type 'System.String'.
    Mar 09 12:03:26 duet3 DuetWebServer[442]: info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
    Mar 09 12:03:26 duet3 DuetWebServer[442]:       Executed action DuetWebServer.Controllers.MachineController.DoCode (DuetWebServer) in 689487.1924ms
    Mar 09 12:03:26 duet3 DuetWebServer[442]: info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
    Mar 09 12:03:26 duet3 DuetWebServer[442]:       Executed endpoint 'DuetWebServer.Controllers.MachineController.DoCode (DuetWebServer)'
    Mar 09 12:03:26 duet3 DuetWebServer[442]: info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
    Mar 09 12:03:26 duet3 DuetWebServer[442]:       Request finished in 689491.1494ms 500 text/plain; charset=utf-8
    ^C
    pi@duet3:~ $ sudo journalctl -f
    -- Logs begin at Sun 2020-03-08 00:17:01 GMT. --
    Mar 09 12:06:03 duet3 vncserver-x11[463]: AgentInitCheck: agent comms failure
    Mar 09 12:06:08 duet3 vncserver-x11[463]: AgentInitCheck: no response from agent
    Mar 09 12:06:08 duet3 sudo[15679]: pam_unix(sudo:session): session closed for user root
    Mar 09 12:06:13 duet3 vncserver-x11[463]: AgentInitCheck: agent comms failure
    Mar 09 12:06:18 duet3 vncserver-x11[463]: AgentInitCheck: no response from agent
    Mar 09 12:06:23 duet3 vncserver-x11[463]: AgentInitCheck: agent comms failure
    Mar 09 12:06:28 duet3 vncserver-x11[463]: AgentInitCheck: no response from agent
    Mar 09 12:06:33 duet3 vncserver-x11[463]: AgentInitCheck: agent comms failure
    Mar 09 12:06:36 duet3 sudo[15778]:       pi : TTY=pts/0 ; PWD=/home/pi ; USER=root ; COMMAND=/usr/bin/journalctl -f
    Mar 09 12:06:36 duet3 sudo[15778]: pam_unix(sudo:session): session opened for user root by pi(uid=0)
    Mar 09 12:06:38 duet3 vncserver-x11[463]: AgentInitCheck: no response from agent
    Mar 09 12:06:43 duet3 vncserver-x11[463]: AgentInitCheck: agent comms failure
    Mar 09 12:06:48 duet3 vncserver-x11[463]: AgentInitCheck: no response from agent
    Mar 09 12:06:53 duet3 vncserver-x11[463]: AgentInitCheck: agent comms failure
    

Log in to reply