I made a shell script to launch my program in a loop in case my programm exits for any reason. While rare, the programm occasionally encounters a situation in which it has to reset. One of those situations is when it fails to connect to the KNX-Tunneling interface 10 times in a row. Then I decide to just restart the program and have everything in a known state.
Just today I had checked in on my project and found the service running, but no data being logged for 5 days.
Examining the journal I found this:
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: [E-KNX] 18.07.2019 20: 04:27.113: ID: KNXLib.KnxReceiverTunnelingMSG: A connection attempt failed because the connected party did not properly respondafter a period of time, or established connection failed because connected host has failed to respond
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: No knx-connection during main loop. Attempted reconnects so far: 10
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: [E-KNX] 18.07.2019 20: 04:27.223: ID: KNXLib.KnxReceiverTunnelingMSG: System.Net.Sockets.SocketException (0x80004005): A connection attempt failed because the connected party did not properly respondafter a period of time, or established connection failed because connected host has failed to respond
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom_nochecks_exc (System.Byte[] buf, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags flags, System.Net.EndPoint& remote_end, System.Boolean throwOnError, System.Int32& error) [0x00076] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags socketFlags, System.Net.EndPoint& remoteEP) [0x00029] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Net.EndPoint& remoteEP) [0x0000d] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.UdpClient.Receive (System.Net.IPEndPoint& remoteEP) [0x00014] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: at KNXLib.KnxReceiverTunneling.ReceiverThreadFlow () [0x00000] in <Path>\KnxLogger\knx.net\src\KNXLib\KnxReceiverTunneling.cs:42
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: [E-KNX] 18.07.2019 20: 04:27.226: ID: KNXLib.KnxReceiverTunnelingMSG: at System.Net.Sockets.Socket.ReceiveFrom_nochecks_exc (System.Byte[] buf, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags flags, System.Net.EndPoint& remote_end, System.Boolean throwOnError, System.Int32& error) [0x00076] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags socketFlags, System.Net.EndPoint& remoteEP) [0x00029] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Net.EndPoint& remoteEP) [0x0000d] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.UdpClient.Receive (System.Net.IPEndPoint& remoteEP) [0x00014] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: at KNXLib.KnxReceiverTunneling.ReceiverThreadFlow () [0x00000] in <Path>\KnxLogger\knx.net\src\KNXLib\KnxReceiverTunneling.cs:42
Jul 18 20:04:27 logger-pi KNX_Logger.sh[13144]: [DELEGATE] Disconnected.
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: 6/0/80 received data from 7.1.11 but it is not tracked.
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: Data: 0x33 0x14 (00110011 00010100)
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: [E-KNX] 18.07.2019 20: 04:32.219: ID: KNXLib.KnxReceiverTunnelingMSG: A connection attempt failed because the connected party did not properly respondafter a period of time, or established connection failed because connected host has failed to respond
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: [E-KNX] 18.07.2019 20: 04:32.226: ID: KNXLib.KnxReceiverTunnelingMSG: System.Net.Sockets.SocketException (0x80004005): A connection attempt failed because the connected party did not properly respondafter a period of time, or established connection failed because connected host has failed to respond
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom_nochecks_exc (System.Byte[] buf, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags flags, System.Net.EndPoint& remote_end, System.Boolean throwOnError, System.Int32& error) [0x00076] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags socketFlags, System.Net.EndPoint& remoteEP) [0x00029] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Net.EndPoint& remoteEP) [0x0000d] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.UdpClient.Receive (System.Net.IPEndPoint& remoteEP) [0x00014] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at KNXLib.KnxReceiverTunneling.ReceiverThreadFlow () [0x00000] in <Path>\KnxLogger\knx.net\src\KNXLib\KnxReceiverTunneling.cs:42
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: [E-KNX] 18.07.2019 20: 04:32.228: ID: KNXLib.KnxReceiverTunnelingMSG: at System.Net.Sockets.Socket.ReceiveFrom_nochecks_exc (System.Byte[] buf, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags flags, System.Net.EndPoint& remote_end, System.Boolean throwOnError, System.Int32& error) [0x00076] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags socketFlags, System.Net.EndPoint& remoteEP) [0x00029] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Net.EndPoint& remoteEP) [0x0000d] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.UdpClient.Receive (System.Net.IPEndPoint& remoteEP) [0x00014] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at KNXLib.KnxReceiverTunneling.ReceiverThreadFlow () [0x00000] in <Path>\KnxLogger\knx.net\src\KNXLib\KnxReceiverTunneling.cs:42
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: [DELEGATE] Disconnected.
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: ================================================================================
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: EXCEPTION
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: Exception time: 18.07.2019 20:04:32.608
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: Exception message: Reconnect failed 11 times in a row.
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: Exception source: KNX_Logger
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: Data:
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: Help link:
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: ================================================================================
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: Stack Trace:
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at KNX_Logger.KNX_Logger.Main (System.String[] args) [0x00574] in <Path>\KnxLogger\KNX_Logger\KNX_Logger.cs:299
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: ================================================================================
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: Disconnecting normally.
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: Shutdown complete. Exiting.
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: [E-KNX] 18.07.2019 20: 04:32.738: ID: KNXLib.KnxReceiverTunnelingMSG: A connection attempt failed because the connected party did not properly respondafter a period of time, or established connection failed because connected host has failed to respond
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: [E-KNX] 18.07.2019 20: 04:32.754: ID: KNXLib.KnxReceiverTunnelingMSG: System.Net.Sockets.SocketException (0x80004005): A connection attempt failed because the connected party did not properly respondafter a period of time, or established connection failed because connected host has failed to respond
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom_nochecks_exc (System.Byte[] buf, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags flags, System.Net.EndPoint& remote_end, System.Boolean throwOnError, System.Int32& error) [0x00076] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags socketFlags, System.Net.EndPoint& remoteEP) [0x00029] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Net.EndPoint& remoteEP) [0x0000d] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.UdpClient.Receive (System.Net.IPEndPoint& remoteEP) [0x00014] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at KNXLib.KnxReceiverTunneling.ReceiverThreadFlow () [0x00000] in <Path>\KnxLogger\knx.net\src\KNXLib\KnxReceiverTunneling.cs:42
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: [E-KNX] 18.07.2019 20: 04:32.759: ID: KNXLib.KnxReceiverTunnelingMSG: at System.Net.Sockets.Socket.ReceiveFrom_nochecks_exc (System.Byte[] buf, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags flags, System.Net.EndPoint& remote_end, System.Boolean throwOnError, System.Int32& error) [0x00076] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Int32 offset, System.Int32 size, System.Net.Sockets.SocketFlags socketFlags, System.Net.EndPoint& remoteEP) [0x00029] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Net.EndPoint& remoteEP) [0x0000d] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.UdpClient.Receive (System.Net.IPEndPoint& remoteEP) [0x00014] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at KNXLib.KnxReceiverTunneling.ReceiverThreadFlow () [0x00000] in <Path>\KnxLogger\knx.net\src\KNXLib\KnxReceiverTunneling.cs:42
After which I restarted...
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.Socket.ReceiveFrom (System.Byte[] buffer, System.Net.EndPoint& remoteEP) [0x0000d] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at System.Net.Sockets.UdpClient.Receive (System.Net.IPEndPoint& remoteEP) [0x00014] in <bd46d4d4f7964dfa9beea098499ab597>:0
Jul 18 20:04:32 logger-pi KNX_Logger.sh[13144]: at KNXLib.KnxReceiverTunneling.ReceiverThreadFlow () [0x00000] in <Path>\KnxLogger\knx.net\src\KNXLib\KnxReceiverTunneling.cs:42
Jul 24 13:29:45 logger-pi systemd[1]: Stopping Service logging data from KNX IP-Interface...
Jul 24 13:29:45 logger-pi systemd[1]: Stopped Service logging data from KNX IP-Interface.
Jul 24 13:29:45 logger-pi systemd[1]: Started Service logging data from KNX IP-Interface.
Jul 24 13:29:45 logger-pi KNX_Logger.sh[27799]: [I]Working Directory: <Path>/KNX_Logger/bin
Jul 24 13:29:45 logger-pi KNX_Logger.sh[27799]: [I]Starting KNX_Logger shell loop script
The most pressing issue is that the shell script output that runs the program in a loop never triggered, meaning the shell script hung on the program launch. and systemd told me the program was running.
I suspect some thread was at work here and didn't quit properly when the main programm returned from execution, letting the program "hang" in a state where it should've exited.