refs #60 Fixed plugin attempting to reopen connection while it is shu…

…tting down. Switch path now always happen (even if other path is not connected). Also attempt to switch path when connection is lost. Connection status is updated when switching path. Fixed repeated state change hen receiving multiple UA after connection is fully established. Fixed test server never timing out in certain situations, leading to never ending tests.

.gitignore

@@ -116,4 +116,5 @@ Temporary Items
 build/**
 
 # Folder with Fledge header
-C/**
+C/**
+.vscode/

include/hnzpath.h

@@ -91,7 +91,7 @@ class HNZPath {
    */
   bool isConnected() { return m_connected && isTCPConnected(); };
 
-    /**
+  /**
    * Is the TCP connection with the PA still alive according to HNZ client?
    * @return true if connected, false otherwise
    */
@@ -149,6 +149,18 @@ class HNZPath {
         "[" + m_path_name + " - " + (active ? "active" : "passive") + "]";
   };
 
+  /**
+   * Gets the state of the path
+   * @return true if active, false if passive
+   */
+  bool isActivePath() { return m_is_active_path; }
+
+  /**
+   * Gets the state of the HNZ protocol (CONNECTION, CONNECTED)
+   * @return CONNECTION if SARM/UA step is not complete, CONNECTED after that
+   */
+  int getProtocolState() { return m_protocol_state; }
+
  private:
   std::unique_ptr<HNZClient> m_hnz_client;  // HNZ Client that manage TCP connection
                                             // (receives/assembles and sends TCP frame)
@@ -166,7 +178,7 @@ class HNZPath {
 
   thread* m_connection_thread = nullptr; // Main thread that maintains the connection
   atomic<bool> m_is_running{true};  // If false, the connection thread will stop
-  bool m_connected = false;   // TCP Connection state with the PA
+  atomic<bool> m_connected{false};   // TCP Connection state with the PA
   int m_protocol_state;       // HNZ Protocol connection state
   bool m_is_active_path = false;
 

src/hnz.cpp

@@ -133,12 +133,16 @@ void HNZ::receive(HNZPath *hnz_path_in_use) {
     messages = hnz_path_in_use->getData();
 
     if (messages.empty() && !hnz_path_in_use->isConnected()) {
-      HnzUtility::log_warn(path +
-                                " No data available, checking connection ...");
+      HnzUtility::log_warn(path + " Connection lost, reconnecting active path and switching to other path");
+      // If connection lost, try to switch path
+      if (hnz_path_in_use->isActivePath()) m_hnz_connection->switchPath();
       // Try to reconnect, unless thread is stopping
       if (m_is_running) {
         hnz_path_in_use->disconnect();
-        hnz_path_in_use->connect();
+        // Shutdown request may happen while disconnecting, if it does cancel reconnection
+        if (m_is_running) {
+          hnz_path_in_use->connect();
+        }
       }
     } else {
       // Push each message to fledge

src/hnzconnection.cpp

@@ -220,29 +220,28 @@ void HNZConnection::m_update_quality_update_timer() {
 
 void HNZConnection::switchPath() {
   if (m_passive_path != nullptr) {
-    if (m_passive_path->isConnected()) {
-      HnzUtility::log_error("Switching active and passive path.");
+    HnzUtility::log_warn("Switching active and passive path.");
 
-      // Check the status of the passive path before switching
-      // Permute path
-      HNZPath* temp = m_active_path;
-      m_active_path = m_passive_path;
-      m_active_path->setActivePath(true);
-      temp->setActivePath(false);
-      m_passive_path = temp;
+    // Check the status of the passive path before switching
+    // Permute path
+    HNZPath* temp = m_active_path;
+    m_active_path = m_passive_path;
+    m_active_path->setActivePath(true);
+    temp->setActivePath(false);
+    m_passive_path = temp;
 
-      HnzUtility::log_error("New active path is " +
-                                 m_active_path->getName());
+    HnzUtility::log_info("New active path is " + m_active_path->getName());
 
-    } else {
-      HnzUtility::log_error(
-          "Impossible to change the path, the TCP connection on the passive "
-          "path is cut.");
+    // When switching path, update connection status accordingly
+    if (m_active_path->getProtocolState() == CONNECTED) {
+      updateConnectionStatus(ConnectionStatus::STARTED);
+    }
+    else {
+      updateConnectionStatus(ConnectionStatus::NOT_CONNECTED);
     }
   } else {
     // Redundancy isn't enable, can't switch to the other path
-    HnzUtility::log_error(
-        "Redundancy isn't enable, can't switch to the other path");
+    HnzUtility::log_warn("Redundancy isn't enabled, can't switch to the other path");
   }
 }
 

src/hnzpath.cpp

@@ -8,6 +8,9 @@
  * Author: Justin Facquet
  */
 
+#include <sstream>
+#include <iomanip>
+
 #include "hnzutility.h"
 #include "hnz.h"
 #include "hnzpath.h"
@@ -60,12 +63,15 @@ vector<unsigned char> convertPayloadToVector(unsigned char* data, int size) {
  * Helper method to convert payload into something readable for logs.
  */
 string convert_data_to_str(unsigned char* data, int len) {
-  string s = "";
+  if (data == nullptr) {
+    return "";
+  }
+  std::stringstream stream;
   for (int i = 0; i < len; i++) {
-    s += to_string(data[i]);
-    if (i < len - 1) s += " ";
+    stream << std::setfill ('0') << std::setw(2) << std::hex << static_cast<unsigned int>(data[i]);
+    if (i < len - 1) stream << " ";
   }
-  return s;
+  return stream.str();
 }
 
 void HNZPath::connect() {
@@ -96,13 +102,15 @@ void HNZPath::connect() {
       HnzUtility::log_warn(m_name_log +
                                 " Error in connection, retrying in " +
                                 to_string(RETRY_CONN_DELAY) + "s ...");
+      // If connection failed, try to switch path
+      if (m_is_active_path) m_hnz_connection->switchPath();
       this_thread::sleep_for(std::chrono::seconds(RETRY_CONN_DELAY));
     }
   }
 }
 
 void HNZPath::disconnect() {
-  HnzUtility::log_debug(m_name_log + " HNZ Connection stopping...");
+  HnzUtility::log_debug(m_name_log + " HNZ Path stopping...");
   if (m_is_active_path) {
     m_hnz_connection->updateConnectionStatus(ConnectionStatus::NOT_CONNECTED);
   }
@@ -165,8 +173,7 @@ milliseconds HNZPath::m_manageHNZProtocolConnecting(long now) {
       if (m_nbr_sarm_sent == m_max_sarm) {
         HnzUtility::log_warn(
             m_name_log + " The maximum number of SARM was reached.");
-        // If the path is the active one, switch to passive path if
-        // available
+        // If the path is the active one, switch to passive path if available
         if (m_is_active_path) m_hnz_connection->switchPath();
         m_nbr_sarm_sent = 0;
       }
@@ -410,9 +417,11 @@ void HNZPath::m_receivedSARM() {
 }
 
 void HNZPath::m_receivedUA() {
-  sarm_ARP_UA = true;
-  if (sarm_PA_received) {
-    m_go_to_connected();
+  if (m_protocol_state == CONNECTION) {
+    sarm_ARP_UA = true;
+    if (sarm_PA_received) {
+      m_go_to_connected();
+    }
   }
 }
 
@@ -679,4 +688,4 @@ void HNZPath::receivedCommandACK(string type, int addr) {
       }
     }
   }
-}
+}

tests/server/basic_hnz_server.cpp

@@ -95,13 +95,13 @@ void BasicHNZServer::sendSARMLoop() {
   }
 }
 
-bool BasicHNZServer::HNZServerIsReady() {
+bool BasicHNZServer::HNZServerIsReady(int timeout_s /*= 16*/) {
   is_running = true;
   long start = time(NULL);
   printf("[HNZ Server][%d] Waiting for initial connection...\n", m_port); fflush(stdout);
   // Wait for the server to finish starting
   while (!server->isConnected() && is_running) {
-    if (time(NULL) - start > 10) {
+    if (time(NULL) - start > timeout_s) {
       printf("[HNZ Server][%d] Connection timeout\n", m_port); fflush(stdout);
       return false;
     }
@@ -124,7 +124,7 @@ bool BasicHNZServer::HNZServerIsReady() {
   start = time(NULL);
   bool lastFrameWasEmpty = false;
   while (is_running) {
-    if (time(NULL) - start > 10) {
+    if (time(NULL) - start > timeout_s) {
       printf("[HNZ Server][%d] SARM/UA timeout\n", m_port); fflush(stdout);
       is_running = false;
       break;
@@ -137,7 +137,7 @@ bool BasicHNZServer::HNZServerIsReady() {
       start = time(NULL);
       // Wait for the server to finish starting
       while (!server->isConnected() && is_running) {
-        if (time(NULL) - start > 10) {
+        if (time(NULL) - start > timeout_s) {
           printf("[HNZ Server][%d] Reconnection timeout\n", m_port); fflush(stdout);
           return false;
         }
@@ -167,12 +167,10 @@ bool BasicHNZServer::HNZServerIsReady() {
     switch (c) {
       case UA_CODE:
         printf("[HNZ Server][%d] UA received\n", m_port); fflush(stdout);
-        start = time(NULL);
         ua_ok = true;
         break;
       case SARM_CODE:
         printf("[HNZ Server][%d] SARM received, sending UA\n", m_port); fflush(stdout);
-        start = time(NULL);
         unsigned char message[1];
         message[0] = 0x63;
         createAndSendFrame(0x07, message, sizeof(message));

tests/server/basic_hnz_server.h

@@ -19,8 +19,8 @@ class BasicHNZServer {
 
   void startHNZServer();
   void stopHNZServer();
-
-  bool HNZServerIsReady();
+  // Timeout = 16 = (5 * 3) + 1 sec = (SARM retries * SARM delay) + 1
+  bool HNZServerIsReady(int timeout_s = 16);
 
   void sendSARM();
 

tests/test_hnz.cpp

@@ -1519,6 +1519,7 @@ TEST_F(HNZTest, ReceivingMessagesTwoPath) {
 
   // Send a SARM to put hnz plugin on path A in connection state
   // and don't send UA then to switch on path B
+  debug_print("[HNZ Server] Send SARM on Path A to force switch to Path B");
   server->sendSARM();
 
   // Wait 20s
@@ -1573,6 +1574,7 @@ TEST_F(HNZTest, SendingMessagesTwoPath) {
 
   // Send a SARM to put hnz plugin on path A in connection state
   // and don't send UA then to switch on path B
+  debug_print("[HNZ Server] Send SARM on Path A to force switch to Path B");
   server->sendSARM();
 
   // Wait 30s

tests/test_utility.cpp

@@ -0,0 +1,13 @@
+#include <gtest/gtest.h>
+
+#include "hnzutility.h"
+
+TEST(HNZUtility, Logs)
+{
+    std::string text("This message is at level %s");
+    ASSERT_NO_THROW(HnzUtility::log_debug(text.c_str(), "debug"));
+    ASSERT_NO_THROW(HnzUtility::log_info(text.c_str(), "info"));
+    ASSERT_NO_THROW(HnzUtility::log_warn(text.c_str(), "warning"));
+    ASSERT_NO_THROW(HnzUtility::log_error(text.c_str(), "error"));
+    ASSERT_NO_THROW(HnzUtility::log_fatal(text.c_str(), "fatal"));
+}