loconet: added timeouts for echo and reply

server/src/hardware/protocol/loconet/config.hpp

@@ -29,6 +29,9 @@ namespace LocoNet {
 
 struct Config
 {
+  static constexpr uint16_t echoTimeout = 500; //!< Wait for echo timeout in milliseconds
+  static constexpr uint16_t responseTimeout = 500; //!< Wait for response timeout in milliseconds
+
   bool fastClockSyncEnabled;
   uint8_t fastClockSyncInterval; //!< Fast clock sync interval in seconds
 

server/src/hardware/protocol/loconet/kernel.cpp

@@ -50,7 +50,9 @@ Kernel::Kernel(const Config& config, bool simulation)
   : m_ioContext{1}
   , m_simulation{simulation}
   , m_waitingForEcho{false}
+  , m_waitingForEchoTimer{m_ioContext}
   , m_waitingForResponse{false}
+  , m_waitingForResponseTimer{m_ioContext}
   , m_fastClockSyncTimer(m_ioContext)
   , m_decoderController{nullptr}
   , m_inputController{nullptr}
@@ -167,6 +169,8 @@ void Kernel::stop()
   m_ioContext.post(
     [this]()
     {
+      m_waitingForEchoTimer.cancel();
+      m_waitingForResponseTimer.cancel();
       m_fastClockSyncTimer.cancel();
       m_ioHandler->stop();
     });
@@ -186,9 +190,10 @@ void Kernel::receive(const Message& message)
     EventLoop::call([this, msg=toString(message)](){ Log::log(m_logId, LogMessage::D2002_RX_X, msg); });
 
   bool isResponse = false;
-  if(m_waitingForEcho && message == m_sendQueue[m_sentMessagePriority].front())
+  if(m_waitingForEcho && message == lastSentMessage())
   {
     m_waitingForEcho = false;
+    m_waitingForEchoTimer.cancel();
     if(!m_waitingForResponse)
     {
       m_sendQueue[m_sentMessagePriority].pop();
@@ -197,7 +202,7 @@ void Kernel::receive(const Message& message)
   }
   else if(m_waitingForResponse)
   {
-    isResponse = isValidResponse(m_sendQueue[m_sentMessagePriority].front(), message);
+    isResponse = isValidResponse(lastSentMessage(), message);
   }
 
   switch(message.opCode)
@@ -637,6 +642,7 @@ void Kernel::receive(const Message& message)
   if(m_waitingForResponse && isResponse)
   {
     m_waitingForResponse = false;
+    m_waitingForResponseTimer.cancel();
     m_sendQueue[m_sentMessagePriority].pop();
     sendNextMessage();
   }
@@ -877,8 +883,17 @@ void Kernel::sendNextMessage()
       if(m_ioHandler->send(message))
       {
         m_sentMessagePriority = static_cast<Priority>(priority);
+
         m_waitingForEcho = true;
+        m_waitingForEchoTimer.expires_after(boost::asio::chrono::milliseconds(Config::echoTimeout));
+        m_waitingForEchoTimer.async_wait(std::bind(&Kernel::waitingForEchoTimerExpired, this, std::placeholders::_1));
+
         m_waitingForResponse = hasResponse(message);
+        if(m_waitingForResponse)
+        {
+          m_waitingForResponseTimer.expires_after(boost::asio::chrono::milliseconds(Config::responseTimeout));
+          m_waitingForResponseTimer.async_wait(std::bind(&Kernel::waitingForResponseTimerExpired, this, std::placeholders::_1));
+        }
       }
       else
       {} // log message and go to error state
@@ -887,6 +902,29 @@ void Kernel::sendNextMessage()
   }
 }
 
+void Kernel::waitingForEchoTimerExpired(const boost::system::error_code& ec)
+{
+  if(ec)
+    return;
+
+  EventLoop::call(
+    [this]()
+    {
+      Log::log(m_logId, LogMessage::E2018_TIMEOUT_NO_ECHO_WITHIN_X_MS, Config::echoTimeout);
+    });
+}
+
+void Kernel::waitingForResponseTimerExpired(const boost::system::error_code& ec)
+{
+  if(ec)
+    return;
+
+  EventLoop::call(
+    [this]()
+    {
+      Log::log(m_logId, LogMessage::E2019_TIMEOUT_NO_RESPONSE_WITHIN_X_MS, Config::responseTimeout);
+    });
+}
 void Kernel::startFastClockSyncTimer()
 {
   assert(m_config.fastClockSyncInterval > 0);

server/src/hardware/protocol/loconet/kernel.hpp

@@ -125,7 +125,9 @@ class Kernel
     std::array<SendQueue, 3> m_sendQueue;
     Priority m_sentMessagePriority;
     bool m_waitingForEcho;
+    boost::asio::steady_timer m_waitingForEchoTimer;
     bool m_waitingForResponse;
+    boost::asio::steady_timer m_waitingForResponseTimer;
 
     TriState m_globalPower;
     std::function<void(bool)> m_onGlobalPowerChanged;
@@ -160,6 +162,11 @@ class Kernel
 
     void setIOHandler(std::unique_ptr<IOHandler> handler);
 
+    inline const Message& lastSentMessage() const
+    {
+      return m_sendQueue[m_sentMessagePriority].front();
+    }
+
     void send(const Message& message, Priority priority = NormalPriority);
     void send(uint16_t address, Message& message, uint8_t& slot);
     template<typename T>
@@ -169,6 +176,9 @@ class Kernel
     }
     void sendNextMessage();
 
+    void waitingForEchoTimerExpired(const boost::system::error_code& ec);
+    void waitingForResponseTimerExpired(const boost::system::error_code& ec);
+
     void startFastClockSyncTimer();
     void stopFastClockSyncTimer();
     void fastClockSyncTimerExpired(const boost::system::error_code& ec);

shared/src/traintastic/enum/logmessage.hpp

@@ -140,6 +140,8 @@ enum class LogMessage : uint32_t
   E2015_SERIAL_PORT_SET_STOP_BITS_FAILED_X = LogMessageOffset::error + 2015,
   E2016_SERIAL_PORT_SET_PARITY_FAILED_X = LogMessageOffset::error + 2016,
   E2017_SERIAL_PORT_SET_FLOW_CONTROL_FAILED_X = LogMessageOffset::error + 2017,
+  E2018_TIMEOUT_NO_ECHO_WITHIN_X_MS = LogMessageOffset::error + 2018,
+  E2019_TIMEOUT_NO_RESPONSE_WITHIN_X_MS = LogMessageOffset::error + 2019,
   E9001_X_DURING_EXECUTION_OF_X_EVENT_HANDLER = LogMessageOffset::error + 9001,
   E9999_X = LogMessageOffset::error + 9999,
 

shared/translations/en-us.txt

@@ -270,6 +270,8 @@ message:E2009=Socket receive failed (%1)
 message:E2010=Serial port open failed (%1)
 message:E2011=Socket send failed (%1)
 message:E2012=Function number already in use
+message:E2018=Timeout, no echo within %1ms
+message:E2019=Timeout, no response within %1ms
 message:E9001=%1 (During execution of %2 event handler)
 message:E9999=%1
 message:F1001=Opening TCP socket failed (%1)