commit 69f5a77c610efc9073a6973ba51f7378bf0929c0
author William A. Kennington III <wak@google.com> Thu Dec 09 19:00:14 2021 -0800
committer William A. Kennington III <wak@google.com> Fri Dec 10 15:29:02 2021 -0800
tree 4c0c47a8584f322c2c09e0279be0b185026e0c96
parent f8600a16f4316f85646d4ca51d24732dda27986b

ncsid: Only log errors a single time

This reduces the amount of contents in the journal when an NCSI cable
is missing or the interface is broken.

It still periodically logs repeat messages, but only once per hour
instead of potentially many times a second.

Change-Id: Ic2efad4d3dea170863a5d4cbe48668a13007045c
Signed-off-by: William A. Kennington III <wak@google.com>

subprojects/ncsid/src/ncsi_state_machine.cpp

diff --git a/subprojects/ncsid/src/ncsi_state_machine.cpp b/subprojects/ncsid/src/ncsi_state_machine.cpp
index 6486548..40e78e7 100644
--- a/subprojects/ncsid/src/ncsi_state_machine.cpp
+++ b/subprojects/ncsid/src/ncsi_state_machine.cpp
@@ -19,6 +19,8 @@
 #include "platforms/nemora/portable/ncsi_fsm.h"
 
 #include <arpa/inet.h>
+#include <fmt/format.h>
+#include <fmt/printf.h>
 #include <netinet/ether.h>
 #include <unistd.h>
 
@@ -27,11 +29,41 @@
 #include <cstdlib>
 #include <cstring>
 #include <iostream>
+#include <string>
 #include <thread>
+#include <utility>
 
 #define ETHER_NCSI 0x88f8
 
-#define CPRINTF(...) fprintf(stderr, __VA_ARGS__)
+// Only log messages a single time and drop all duplicates to prevent log spam.
+// Having duplicate messages printed has historically not been helpful in
+// debugging issues with this program.
+static void do_log(std::string&& line)
+{
+    constexpr auto line_dup_time = std::chrono::hours(1);
+    static std::chrono::steady_clock::time_point last_line_time;
+    static size_t line_rep_count = 0;
+    static std::string last_line;
+
+    auto now = std::chrono::steady_clock::now();
+    if (line != last_line || line_dup_time + last_line_time < now)
+    {
+        if (line_rep_count > 0)
+        {
+            fmt::print(stderr, "... Repeated {} times ...\n", line_rep_count);
+        }
+        fmt::print(stderr, "{}", line);
+        last_line = std::move(line);
+        last_line_time = now;
+        line_rep_count = 0;
+    }
+    else
+    {
+        line_rep_count++;
+    }
+}
+
+#define CPRINTF(...) do_log(fmt::sprintf(__VA_ARGS__))
 
 #ifdef NCSID_VERBOSE_LOGGING
 #define DEBUG_PRINTF printf
@@ -99,6 +131,11 @@
                 sizeof(echo_pattern));
 }
 
+StateMachine::~StateMachine()
+{
+    CPRINTF("[NCSI stopping]\n");
+}
+
 size_t StateMachine::poll_l2_config()
 {
     size_t len = 0;

subprojects/ncsid/src/ncsi_state_machine.h

diff --git a/subprojects/ncsid/src/ncsi_state_machine.h b/subprojects/ncsid/src/ncsi_state_machine.h
index 3d739dd..07a7b9c 100644
--- a/subprojects/ncsid/src/ncsi_state_machine.h
+++ b/subprojects/ncsid/src/ncsi_state_machine.h
@@ -44,6 +44,7 @@
 {
   public:
     StateMachine();
+    ~StateMachine();
 
     void set_sockio(net::SockIO* sock_io);