Fixes skupperproject#1385: Log inter-inter connection failures only on pn condition description change (skupperproject#1386)

Author: ganeshmurthy

src/server.c

@@ -1065,6 +1065,7 @@ static bool handle(qd_server_t *qd_server, pn_event_t *e, pn_connection_t *pn_co
             if (ctx && ctx->connector) { /* Outgoing connection */
                 const qd_server_config_t *config = &ctx->connector->config;
                 char conn_msg[QD_CXTR_CONN_MSG_BUF_SIZE];  // avoid holding connector lock when logging
+                char conn_msg_1[QD_CXTR_CONN_MSG_BUF_SIZE]; // this connection message does not contain the connection id
 
                 sys_mutex_lock(&ctx->connector->lock);
                 qd_increment_conn_index_lh(ctx);
@@ -1074,14 +1075,32 @@ static bool handle(qd_server_t *qd_server, pn_event_t *e, pn_connection_t *pn_co
                     qd_format_string(conn_msg, sizeof(conn_msg), "[C%"PRIu64"] Connection to %s failed: %s %s",
                                      ctx->connection_id, config->host_port, pn_condition_get_name(condition),
                                      pn_condition_get_description(condition));
+
+                    qd_format_string(conn_msg_1, sizeof(conn_msg_1), "Connection to %s failed: %s %s",
+                                     config->host_port, pn_condition_get_name(condition), pn_condition_get_description(condition));
                 } else {
                     qd_format_string(conn_msg, sizeof(conn_msg), "[C%"PRIu64"] Connection to %s failed",
                                      ctx->connection_id, config->host_port);
+                    qd_format_string(conn_msg_1, sizeof(conn_msg_1), "Connection to %s failed", config->host_port);
+                }
+                //
+                // This is a fix for https://github.com/skupperproject/skupper-router/issues/1385
+                // The router will repeatedly try to connect to the host/port specified in the connector
+                // If it is unable to connect, an error message will be logged only once and more error messages
+                // from connection failures will only be logged if the error message changes.
+                // This is done so we don't flood the log with connection failure error messages
+                // Even though we restrict the number of times the error message is displayed, the
+                // router will still keep trying to connect to the host/port specified in the connector.
+                //
+                bool log_error_message = false;
+                if (strcmp(ctx->connector->conn_msg, conn_msg_1) != 0) {
+                    strncpy(ctx->connector->conn_msg, conn_msg_1, QD_CXTR_CONN_MSG_BUF_SIZE);
+                    log_error_message = true;
                 }
-                strncpy(ctx->connector->conn_msg, conn_msg, QD_CXTR_CONN_MSG_BUF_SIZE);
                 sys_mutex_unlock(&ctx->connector->lock);
-
-                qd_log(LOG_SERVER, QD_LOG_ERROR, "%s", conn_msg);
+                if (log_error_message) {
+                    qd_log(LOG_SERVER, QD_LOG_ERROR, "%s", conn_msg);
+                }
 
             } else if (ctx && ctx->listener) { /* Incoming connection */
                 if (condition && pn_condition_is_set(condition)) {

tests/system_tests_sasl_plain.py

@@ -148,20 +148,27 @@ def test_inter_router_sasl_fail(self):
 
         # There was no inter-router connection established.
         self.assertFalse(passed)
-
         qd_manager = QdManager(address=self.routers[1].addresses[0])
-        logs = qd_manager.get_log()
 
-        sasl_failed = False
-        file_open_failed = False
-        for log in logs:
-            if log[0] == 'SERVER' and log[1] == "error" and "amqp:unauthorized-access Authentication failed [mech=PLAIN]" in log[2]:
-                sasl_failed = True
-            if log[0] == "CONN_MGR" and log[1] == "error" and "Unable to open password file" in log[2] and "error: No such file or directory" in log[2]:
-                file_open_failed = True
+        def check_sasl_failed():
+            logs = qd_manager.get_log()
+            sasl_failed = False
+            for log in logs:
+                if log[0] == 'SERVER' and log[1] == "error" and "amqp:unauthorized-access Authentication failed [mech=PLAIN]" in log[2]:
+                    sasl_failed = True
+                    break
+            self.assertTrue(sasl_failed)
+
+        def check_file_open_failed():
+            logs = qd_manager.get_log()
+            file_open_failed = False
+            for log in logs:
+                if log[0] == "CONN_MGR" and log[1] == "error" and "Unable to open password file" in log[2] and "error: No such file or directory" in log[2]:
+                    file_open_failed = True
+            self.assertTrue(file_open_failed)
 
-        self.assertTrue(sasl_failed)
-        self.assertTrue(file_open_failed)
+        retry_assertion(check_sasl_failed, delay=2)
+        retry_assertion(check_file_open_failed, delay=2)
 
 
 class RouterTestPlainSaslFailureUsingLiteral(RouterTestPlainSaslCommon):
@@ -244,14 +251,16 @@ def test_inter_router_sasl_fail(self):
 
         # There was no inter-router connection established.
         self.assertFalse(passed)
-        logs = qd_manager.get_log()
-
-        sasl_failed = False
-        for log in logs:
-            if log[0] == 'SERVER' and log[1] == "error" and "amqp:unauthorized-access Authentication failed [mech=PLAIN]" in log[2]:
-                sasl_failed = True
 
-        self.assertTrue(sasl_failed)
+        def check_sasl_failed():
+            logs = qd_manager.get_log()
+            sasl_failed = False
+            for log in logs:
+                if log[0] == 'SERVER' and log[1] == "error" and "amqp:unauthorized-access Authentication failed [mech=PLAIN]" in log[2]:
+                    sasl_failed = True
+                    break
+            self.assertTrue(sasl_failed)
+        retry_assertion(check_sasl_failed, delay=2)
 
 
 class RouterTestPlainSasl(RouterTestPlainSaslCommon):