3.2b1 Duet 3 (DCS is not started)

chrishamm

I suspect there may be a permission issue going on because we changed from root to a dedicate dsf user in the latest pre-release. My best guess how to resolve this, run

sudo rm -f /var/run/dsf/dcs.sock

and wait a few seconds.

If that doesn't help, please check the DCS log first:

sudo journalctl -u duetcontrolserver -f

and if that keeps running, check the DWS log:

sudo journalctl -u duetwebserver -f

If it doesn't help, please post the last 20 lines or so from each log dump.

Dougal1957

@chrishamm said in 3.2b1 Duet 3 (DCS is not started):

sudo journalctl -u duetcontrolserver -f

Sep 15 19:35:13 duet3 DuetControlServer[10966]:    at DuetControlServer.Model.PeriodicUpdater.Run() in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetControlServer/Model/PeriodicUpdater.cs:line 39
Sep 15 19:35:13 duet3 DuetControlServer[10966]: [info] Application has shut down
Sep 15 19:35:14 duet3 systemd[1]: duetcontrolserver.service: Succeeded.
Sep 15 19:35:19 duet3 systemd[1]: duetcontrolserver.service: Service RestartSec=5s expired, scheduling restart.
Sep 15 19:35:19 duet3 systemd[1]: duetcontrolserver.service: Scheduled restart job, restart counter is at 386.
Sep 15 19:35:19 duet3 systemd[1]: Stopped Duet Control Server.
Sep 15 19:35:19 duet3 systemd[1]: Started Duet Control Server.
Sep 15 19:35:20 duet3 DuetControlServer[10988]: Duet Control Server v3.2.0-beta1
Sep 15 19:35:20 duet3 DuetControlServer[10988]: Written by Christian Hammacher for Duet3D
Sep 15 19:35:20 duet3 DuetControlServer[10988]: Licensed under the terms of the GNU Public License Version 3
Sep 15 19:35:21 duet3 DuetControlServer[10988]: [info] Settings loaded
Sep 15 19:35:21 duet3 DuetControlServer[10988]: [info] Environment initialized
Sep 15 19:35:21 duet3 DuetControlServer[10988]: [warn] Kernel SPI buffer size is smaller than RepRapFirmware buffer size (4096 configured vs 8192 required)
Sep 15 19:35:21 duet3 DuetControlServer[10988]: [info] Connection to Duet established
Sep 15 19:35:22 duet3 DuetControlServer[10988]: [info] IPC socket created at /var/run/dsf/dcs.sock
Sep 15 19:35:22 duet3 DuetControlServer[10988]: [fatal] Abnormal program termination
Sep 15 19:35:22 duet3 DuetControlServer[10988]: [fatal] Periodic updater task faulted
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    System.UnauthorizedAccessException: Access to the path is denied.
Sep 15 19:35:22 duet3 DuetControlServer[10988]:  ---> System.IO.IOException: Permission denied
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    --- End of inner exception stack trace ---
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    at System.IO.DriveInfo.CheckStatfsResultAndThrowIfNecessary(Int32 result)
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    at System.IO.DriveInfo.get_TotalSize()
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    at DuetControlServer.Model.PeriodicUpdater.UpdateVolumes() in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetControlServer/Model/PeriodicUpdater.cs:line 144
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    at DuetControlServer.Model.PeriodicUpdater.Run() in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetControlServer/Model/PeriodicUpdater.cs:line 39
Sep 15 19:35:22 duet3 DuetControlServer[10988]: [fatal] Periodic updater task faulted
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    System.UnauthorizedAccessException: Access to the path is denied.
Sep 15 19:35:22 duet3 DuetControlServer[10988]:  ---> System.IO.IOException: Permission denied
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    --- End of inner exception stack trace ---
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    at System.IO.DriveInfo.CheckStatfsResultAndThrowIfNecessary(Int32 result)
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    at System.IO.DriveInfo.get_TotalSize()
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    at DuetControlServer.Model.PeriodicUpdater.UpdateVolumes() in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetControlServer/Model/PeriodicUpdater.cs:line 144
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    at DuetControlServer.Model.PeriodicUpdater.Run() in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetControlServer/Model/PeriodicUpdater.cs:line 39
Sep 15 19:35:22 duet3 DuetControlServer[10988]: [error] IPC#2: Failed to assign connection processor
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    System.Threading.Tasks.TaskCanceledException: A task was canceled.
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    at DuetAPI.Utility.JsonHelper.ReceiveUtf8Json(Socket socket, CancellationToken cancellationToken) in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetAPI/Utility/JsonHelper.cs:line 140
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    at DuetControlServer.IPC.Connection.ReceivePlainJson() in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetControlServer/IPC/Connection.cs:line 233
Sep 15 19:35:22 duet3 DuetControlServer[10988]:    at DuetControlServer.IPC.Server.GetConnectionProcessor(Connection conn) in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetControlServer/IPC/Server.cs:line 173
Sep 15 19:35:22 duet3 DuetControlServer[10988]: [info] Application has shut down
Sep 15 19:35:22 duet3 systemd[1]: duetcontrolserver.service: Succeeded.

Sep 15 19:36:39 duet3 DuetWebServer[443]:       Executed action DuetWebServer.Controllers.WebSocketController.Get (DuetWebServer) in 17.4835ms
Sep 15 19:36:39 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
Sep 15 19:36:39 duet3 DuetWebServer[443]:       Executed endpoint 'DuetWebServer.Controllers.WebSocketController.Get (DuetWebServer)'
Sep 15 19:36:39 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
Sep 15 19:36:39 duet3 DuetWebServer[443]:       Request finished in 18.1791ms 101
Sep 15 19:36:40 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
Sep 15 19:36:40 duet3 DuetWebServer[443]:       Request starting HTTP/1.1 GET http://duet3/rr_connect?password=reprap&time=2020-9-15T19%3A36%3A40 application/json
Sep 15 19:36:40 duet3 DuetWebServer[443]: info: DuetWebServer.Middleware.CustomEndpointMiddleware[0]
Sep 15 19:36:40 duet3 DuetWebServer[443]:       No endpoint found for GET request via /rr_connect
Sep 15 19:36:40 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
Sep 15 19:36:40 duet3 DuetWebServer[443]:       Request finished in 0.6246ms 404
Sep 15 19:36:40 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
Sep 15 19:36:40 duet3 DuetWebServer[443]:       Request starting HTTP/1.1 GET http://duet3/machine
Sep 15 19:36:40 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
Sep 15 19:36:40 duet3 DuetWebServer[443]:       Executing endpoint 'DuetWebServer.Controllers.WebSocketController.Get (DuetWebServer)'
Sep 15 19:36:40 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
Sep 15 19:36:40 duet3 DuetWebServer[443]:       Route matched with {action = "Get", controller = "WebSocket"}. Executing controller action with signature System.Threading.Tasks.Task Get() on controller DuetWebServer.Controllers.WebSocketController (DuetWebServer).
Sep 15 19:36:40 duet3 DuetWebServer[443]: fail: DuetWebServer.Controllers.WebSocketController[0]
Sep 15 19:36:40 duet3 DuetWebServer[443]:       [WebSocketController] DCS is not started
Sep 15 19:36:40 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
Sep 15 19:36:40 duet3 DuetWebServer[443]:       Executed action DuetWebServer.Controllers.WebSocketController.Get (DuetWebServer) in 24.4179ms
Sep 15 19:36:40 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
Sep 15 19:36:40 duet3 DuetWebServer[443]:       Executed endpoint 'DuetWebServer.Controllers.WebSocketController.Get (DuetWebServer)'
Sep 15 19:36:40 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
Sep 15 19:36:40 duet3 DuetWebServer[443]:       Request finished in 25.1331ms 101
Sep 15 19:36:41 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
Sep 15 19:36:41 duet3 DuetWebServer[443]:       Request starting HTTP/1.1 GET http://duet3/rr_connect?password=reprap&time=2020-9-15T19%3A36%3A41 application/json
Sep 15 19:36:41 duet3 DuetWebServer[443]: info: DuetWebServer.Middleware.CustomEndpointMiddleware[0]
Sep 15 19:36:41 duet3 DuetWebServer[443]:       No endpoint found for GET request via /rr_connect
Sep 15 19:36:41 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
Sep 15 19:36:41 duet3 DuetWebServer[443]:       Request finished in 0.5723ms 404
Sep 15 19:36:41 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
Sep 15 19:36:41 duet3 DuetWebServer[443]:       Request starting HTTP/1.1 GET http://duet3/machine
Sep 15 19:36:41 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
Sep 15 19:36:41 duet3 DuetWebServer[443]:       Executing endpoint 'DuetWebServer.Controllers.WebSocketController.Get (DuetWebServer)'
Sep 15 19:36:41 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
Sep 15 19:36:41 duet3 DuetWebServer[443]:       Route matched with {action = "Get", controller = "WebSocket"}. Executing controller action with signature System.Threading.Tasks.Task Get() on controller DuetWebServer.Controllers.WebSocketController (DuetWebServer).
Sep 15 19:36:41 duet3 DuetWebServer[443]: fail: DuetWebServer.Controllers.WebSocketController[0]
Sep 15 19:36:41 duet3 DuetWebServer[443]:       [WebSocketController] DCS is not started
Sep 15 19:36:41 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
Sep 15 19:36:41 duet3 DuetWebServer[443]:       Executed action DuetWebServer.Controllers.WebSocketController.Get (DuetWebServer) in 20.2086ms
Sep 15 19:36:41 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
Sep 15 19:36:41 duet3 DuetWebServer[443]:       Executed endpoint 'DuetWebServer.Controllers.WebSocketController.Get (DuetWebServer)'
Sep 15 19:36:41 duet3 DuetWebServer[443]: info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
Sep 15 19:36:41 duet3 DuetWebServer[443]:       Request finished in 20.8581ms 101
^C

is this enough chris it just seems to be cycling

Doug

chrishamm

Thanks, it's indeed a permission issue - not sure why this problem didn't show up during our internal tests though. You need to change the service file /usr/lib/systemd/system/duetcontrolserver.service in order to fix it to

[Unit]
Description=Duet Control Server

[Service]
ExecStart=/opt/dsf/bin/DuetControlServer
TimeoutStopSec=15
Restart=always
RestartSec=5
Type=simple
User=dsf
Group=dsf
UMask=0002
CapabilityBoundingSet=CAP_SYS_PTRACE CAP_DAC_READ_SEARCH
AmbientCapabilities=CAP_SYS_PTRACE CAP_DAC_READ_SEARCH

[Install]
WantedBy=basic.target

Note the new permission CAP_DAC_READ_SEARCH. I'll update the DCS package again tomorrow.

Dougal1957

@chrishamm said in 3.2b1 Duet 3 (DCS is not started):

Thanks, it's indeed a permission issue - not sure why this problem didn't show up during our internal tests though. You need to change the service file /usr/lib/systemd/system/duetcontrolserver.service in order to fix it to
[Unit]
Description=Duet Control Server

[Service]
ExecStart=/opt/dsf/bin/DuetControlServer
TimeoutStopSec=15
Restart=always
RestartSec=5
Type=simple
User=dsf
Group=dsf
UMask=0002
CapabilityBoundingSet=CAP_SYS_PTRACE CAP_DAC_READ_SEARCH
AmbientCapabilities=CAP_SYS_PTRACE CAP_DAC_READ_SEARCH

[Install]
WantedBy=basic.target
Note the new permission CAP_DAC_READ_SEARCH. I'll update the DCS package again tomorrow.

Chris can you put that in simple layman's terms please How do I do that?

bcrazycramer

@chrishamm said in 3.2b1 Duet 3 (DCS is not started):

/usr/lib/systemd/system/duetcontrolserver.service

Thank you! That fixed it.

chrishamm

@Dougal1957 Sure thing, run

sudo curl https://pkg.duet3d.com/duetcontrolserver.service -o /usr/lib/systemd/system/duetcontrolserver.service
sudo systemctl daemon-reload

Dougal1957

Fixed now thanks (one of the guys in a discord I am in suggested how I could edit it with NANO Thanks Luke

bcrazycramer

Do you know why this isn't working?

pi@duet3:~$ sudo /opt/dsf/bin/DuetWebServer
crit: Microsoft.AspNetCore.Server.Kestrel[0]
Unable to start Kestrel.
System.IO.IOException: Failed to bind to address http://[::]:80: address already in use.
---> Microsoft.AspNetCore.Connections.AddressInUseException: Address already in use
---> System.Net.Sockets.SocketException (98): Address already in use
at System.Net.Sockets.Socket.UpdateStatusAfterSocketErrorAndThrowException(SocketError error, String callerName)
at System.Net.Sockets.Socket.DoBind(EndPoint endPointSnapshot, SocketAddress socketAddress)
at System.Net.Sockets.Socket.Bind(EndPoint localEP)
at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.SocketConnectionListener.Bind()
--- End of inner exception stack trace ---
at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.SocketConnectionListener.Bind()
at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.SocketTransportFactory.BindAsync(EndPoint endpoint, CancellationToken cancellationToken)
at Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer.<>c__DisplayClass21_01.<<StartAsync>g__OnBind|0>d.MoveNext() --- End of stack trace from previous location where exception was thrown --- at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.BindEndpointAsync(ListenOptions endpoint, AddressBindContext context) --- End of inner exception stack trace --- at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.BindEndpointAsync(ListenOptions endpoint, AddressBindContext context) at Microsoft.AspNetCore.Server.Kestrel.Core.ListenOptions.BindAsync(AddressBindContext context) at Microsoft.AspNetCore.Server.Kestrel.Core.AnyIPListenOptions.BindAsync(AddressBindContext context) at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.EndpointsStrategy.BindAsync(AddressBindContext context) at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.BindAsync(IServerAddressesFeature addresses, KestrelServerOptions serverOptions, ILogger logger, Func2 createBinding)
at Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer.StartAsync[TContext](IHttpApplication1 application, CancellationToken cancellationToken) Unhandled exception. System.IO.IOException: Failed to bind to address http://[::]:80: address already in use. ---> Microsoft.AspNetCore.Connections.AddressInUseException: Address already in use ---> System.Net.Sockets.SocketException (98): Address already in use at System.Net.Sockets.Socket.UpdateStatusAfterSocketErrorAndThrowException(SocketError error, String callerName) at System.Net.Sockets.Socket.DoBind(EndPoint endPointSnapshot, SocketAddress socketAddress) at System.Net.Sockets.Socket.Bind(EndPoint localEP) at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.SocketConnectionListener.Bind() --- End of inner exception stack trace --- at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.SocketConnectionListener.Bind() at Microsoft.AspNetCore.Server.Kestrel.Transport.Sockets.SocketTransportFactory.BindAsync(EndPoint endpoint, CancellationToken cancellationToken) at Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer.<>c__DisplayClass21_01.<<StartAsync>g__OnBind|0>d.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.BindEndpointAsync(ListenOptions endpoint, AddressBindContext context)
--- End of inner exception stack trace ---
at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.BindEndpointAsync(ListenOptions endpoint, AddressBindContext context)
at Microsoft.AspNetCore.Server.Kestrel.Core.ListenOptions.BindAsync(AddressBindContext context)
at Microsoft.AspNetCore.Server.Kestrel.Core.AnyIPListenOptions.BindAsync(AddressBindContext context)
at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.EndpointsStrategy.BindAsync(AddressBindContext context)
at Microsoft.AspNetCore.Server.Kestrel.Core.Internal.AddressBinder.BindAsync(IServerAddressesFeature addresses, KestrelServerOptions serverOptions, ILogger logger, Func2 createBinding) at Microsoft.AspNetCore.Server.Kestrel.Core.KestrelServer.StartAsync[TContext](IHttpApplication1 application, CancellationToken cancellationToken)
at Microsoft.AspNetCore.Hosting.GenericWebHostService.StartAsync(CancellationToken cancellationToken)
at Microsoft.Extensions.Hosting.Internal.Host.StartAsync(CancellationToken cancellationToken)
at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.RunAsync(IHost host, CancellationToken token)
at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.RunAsync(IHost host, CancellationToken token)
at Microsoft.Extensions.Hosting.HostingAbstractionsHostExtensions.Run(IHost host)
at DuetWebServer.Program.Main(String[] args) in /home/christian/Duet3D/DuetSoftwareFramework/src/DuetWebServer/Program.cs:line 24
Aborted
pi@duet3:~$

chrishamm

@bcrazycramer It looks like there is another web server running on the same port (80). Do you have Apache or another HTTP server installed on your system? If not, try rebooting the Pi and check if that makes a difference.

PS: DWS will usually run in the background as its own service, so there should be no need to start it manually. Follow my last reply describing the usage of journalctl to figure out why DCS/DWS isn't started.

bcrazycramer

I get the same after rebooting.

I'm not using the Raspberry Pi for anything else except the Duet 3. I do have VNC enabled and SSH.

chrishamm

@bcrazycramer Please see my earlier post where I mention journalctl.

[edit]Sorry, linking posts doesn't seem to work too well[/edit]

Dougal1957

@bcrazycramer I get the same as well not that I have a clue what it means!

bcrazycramer

bcrazycramer

@chrishamm said in 3.2b1 Duet 3 (DCS is not started):

@bcrazycramer Please see my earlier post.

Which part?

Dougal1957

@bcrazycramer it was to me asking me to run the journal cads to see what was happening!

bcrazycramer

chrishamm

@bcrazycramer That's looking good. You should be able to connect to your board over HTTP.

The GitHub releases and package feeds have been updated with the latest hotfixes as promised. If you're having problems, consider running another software update.

A Former User

@chrishamm said in 3.2b1 Duet 3 (DCS is not started):

I suspect there may be a permission issue going on because we changed from root to a dedicate dsf user in the latest pre-release.

Can you explain the thinking behind changing from root to a dsf user?

As to be honest if it was working before, this seems to be a prime example of changes being made for the sake of it for diminishing returns.

As my old journeyman used to say : if it's working fuc*ing leave it alone.

Phaedrux

@CaLviNx Running things as root is generally frowned upon for security sake.

A Former User

@Phaedrux that I understand but in this instance it should be fine as people "should" have their home network secured.

My printers all connected via my own wireless "intranet" that is not connected to the outside world, so no one can get into that small network, house innternet itself is run through a Secure DDWRT equipped router which is well locked down, and I'm not the most IT tech savvy but I'm I am happy to run my printers in "Root" mode.

So to find yet another thing changed for the sake of change just trips things/people up as this instance proven