Add ENVOY_LOG_PERIODIC

source/common/common/logger.h

@@ -1,6 +1,7 @@
 #pragma once
 
 #include <bitset>
+#include <chrono>
 #include <cstdint>
 #include <memory>
 #include <string>
@@ -430,6 +431,22 @@ template <Id id> class Loggable {
     }                                                                                              \
   } while (0)
 
+// This is to get us to pass the format check. We reference a real-world time source here.
+// I think it's not easy to mock/simulate time here as it stands today anyway.
+using t_logclock = std::chrono::steady_clock; // NOLINT
+
+#define ENVOY_LOG_PERIODIC(LEVEL, CHRONO_DURATION, ...)                                            \
+  do {                                                                                             \
+    static auto* last_hit = new std::atomic<uint64_t>();                                           \
+    auto last = last_hit->load();                                                                  \
+    const auto now = t_logclock::now().time_since_epoch().count();                                 \
+    if ((now - last) >                                                                             \
+            std::chrono::duration_cast<std::chrono::nanoseconds>(CHRONO_DURATION).count() &&       \
+        last_hit->compare_exchange_strong(last, now)) {                                            \
+      ENVOY_LOG(LEVEL, ##__VA_ARGS__);                                                             \
+    }                                                                                              \
+  } while (0)
+
 #define ENVOY_FLUSH_LOG()                                                                          \
   do {                                                                                             \
     if (Envoy::Logger::Context::useFancyLogger()) {                                                \

test/common/common/log_macros_test.cc

@@ -1,3 +1,4 @@
+#include <chrono>
 #include <functional>
 #include <iostream>
 #include <string>
@@ -15,6 +16,8 @@
 
 namespace Envoy {
 
+using namespace std::chrono_literals;
+
 class TestFilterLog : public Logger::Loggable<Logger::Id::filter> {
 public:
   void logMessage() {
@@ -148,6 +151,7 @@ TEST(Logger, SparseLogMacros) {
     void logSomethingThrice() { ENVOY_LOG_FIRST_N(error, 3, "foo4 '{}'", evaluations()++); }
     void logEverySeventh() { ENVOY_LOG_EVERY_NTH(error, 7, "foo5 '{}'", evaluations()++); }
     void logEveryPow2() { ENVOY_LOG_EVERY_POW_2(error, "foo6 '{}'", evaluations()++); }
+    void logEverySecond() { ENVOY_LOG_PERIODIC(error, 1s, "foo6 '{}'", evaluations()++); }
     std::atomic<int32_t>& evaluations() { MUTABLE_CONSTRUCT_ON_FIRST_USE(std::atomic<int32_t>); };
   };
   constexpr uint32_t kNumThreads = 100;
@@ -185,11 +189,22 @@ TEST(Logger, SparseLogMacros) {
   // We should log on 2, 4, 8, 16, 32, 64, which means we can expect to add 6 more evaluations.
   EXPECT_EQ(27, helper.evaluations());
 
+  spamCall([&helper]() { helper.logEverySecond(); }, kNumThreads);
+  // First call ought to evaluate.
+  EXPECT_EQ(28, helper.evaluations());
+
+  // We expect one log entry / second. Therefore each spamCall ought to result in one
+  // more evaluation. This depends on real time and not sim time, hopefully 1 second
+  // is enough to not introduce flakes in practice.
+  sleep(1);
+  spamCall([&helper]() { helper.logEverySecond(); }, kNumThreads);
+  EXPECT_EQ(29, helper.evaluations());
+
   spamCall([&helper]() { helper.logSomethingBelowLogLevelOnce(); }, kNumThreads);
   // Without fine-grained logging, we shouldn't observe additional argument evaluations
   // for log lines below the configured log level.
   // TODO(#12885): fancy logger shouldn't always evaluate variadic macro arguments.
-  EXPECT_EQ(::Envoy::Logger::Context::useFancyLogger() ? 28 : 27, helper.evaluations());
+  EXPECT_EQ(::Envoy::Logger::Context::useFancyLogger() ? 30 : 29, helper.evaluations());
 }
 
 TEST(RegistryTest, LoggerWithName) {