feat!: rework logging as macros, with rate limiting and a trace level

CLAUDE.md

@@ -15,6 +15,10 @@
 - Mixed signed/unsigned comparison: `static_cast` when non-negativity is evident at the call site (a length, a count); `std::cmp_*` only when a side can actually be negative (an error-signalling `-1`, a difference).
 - Log level by failure, not blame: failure of an intended operation → `Error`, even if externally caused; deliberate skips (traffic not handled by design) → `Debug`. If Error volume becomes a problem, rate-limit — don't downgrade.
 
+## Commits
+
+- Breaking changes get `!` in the type (`feat!:`, `refactor!:`): anything that makes an existing config file, command line, or deployment stop working as it did.
+
 ## Build
 
 ```sh

README.md

@@ -202,7 +202,7 @@ On RouterOS, setting the container's environment variables is usually easier tha
 `config.toml` contains optional top-level settings plus at least one reflector entry. Entries are tables under `reflectors`, keyed by name (`[reflectors.<name>]`) — the name is the label used in logs — each describing one `source_if` → `target_if` bridge that enables any combination of the protocols. The top-level settings are `log_level` and `debug_memory`:
 
 ```toml
-log_level = "info"               # optional; one of debug | info | warning | error (default: info)
+log_level = "info"               # optional; one of trace | debug | info | warn | error | off (default: info)
 debug_memory = false             # optional; periodically log RSS + heap arena stats for footprint debugging (default false)
 
 [reflectors.tv]

config.toml

@@ -1,4 +1,4 @@
-# log_level = "info"  # debug | info | warning | error
+# log_level = "info"  # trace | debug | info | warn | error | off
 # debug_memory = false  # periodically log RSS + heap arena stats for footprint debugging
 
 # A single device: bridge its Wake-on-LAN, mDNS, and SSDP. The one mac is the device's NIC MAC —

src/main.cpp

@@ -92,7 +92,7 @@ int Run(int argc, char* argv[]) {
 
     reflector::Logger logger("main");
     if (argc > 2) {
-        logger.Error("Usage: {} [config.toml]", argv[0]);
+        NFL_LOG_ERROR(logger, "Usage: {} [config.toml]", argv[0]);
         return 2;
     }
 
@@ -102,7 +102,7 @@ int Run(int argc, char* argv[]) {
     if (argc == 2) {
         auto contents = reflector::Config::ReadFileToString(argv[1]);
         if (!contents) {
-            logger.Error("Cannot read configuration file: {}", contents.error());
+            NFL_LOG_ERROR(logger, "Cannot read configuration file: {}", contents.error());
             return 1;
         }
         file_contents = *std::move(contents);
@@ -113,14 +113,14 @@ int Run(int argc, char* argv[]) {
         file_contents ? std::optional<std::string_view>{*file_contents} : std::nullopt;
     auto config = reflector::Config::Load(toml_text, env_vars);
     if (!config) {
-        logger.Error("Invalid configuration: {}", config.error());
+        NFL_LOG_ERROR(logger, "Invalid configuration: {}", config.error());
         return 1;
     }
 
-    logger.Info("Setting minimum log level to {}", config->MinLogLevel());
+    NFL_LOG_INFO(logger, "Setting minimum log level to {}", config->MinLogLevel());
     reflector::Logger::SetMinLevel(config->MinLogLevel());
 
-    logger.Debug("Config: {}", *config);
+    NFL_LOG_DEBUG(logger, "Config: {}", *config);
 
     reflector::Application app;
     if (!app.Configure(*config)) {

src/reflector/CMakeLists.txt

@@ -12,6 +12,7 @@ add_library(reflector STATIC
     ${CMAKE_CURRENT_SOURCE_DIR}/interface.cpp
     ${CMAKE_CURRENT_SOURCE_DIR}/interface_address.cpp
     ${CMAKE_CURRENT_SOURCE_DIR}/ip_address.cpp
+    ${CMAKE_CURRENT_SOURCE_DIR}/logger.cpp
     ${CMAKE_CURRENT_SOURCE_DIR}/mac_address.cpp
     ${CMAKE_CURRENT_SOURCE_DIR}/mdns_message.cpp
     ${CMAKE_CURRENT_SOURCE_DIR}/memory_report.cpp

src/reflector/application.cpp

@@ -76,7 +76,7 @@ void Application::StartMonitor() {
     // Address-change refresh is best-effort: if the monitor can't start (it logs the cause),
     // carry on without it rather than failing the daemon.
     if (!address_monitor_->Start(CreateDelegate<&Application::OnInterfacesChanged>(this))) {
-        GetLogger().Warning("Address monitor unavailable; source addresses will not refresh on interface changes");
+        NFL_LOG_WARN(GetLogger(), "Address monitor unavailable; source addresses will not refresh on interface changes");
     }
 }
 
@@ -111,20 +111,20 @@ bool Application::ConfigureReflectors(const std::vector<ConfigType>& configs, st
     for (const auto& config : configs) {
         auto* source_socket = GetOrCreateSocket(config.source_if);
         if (source_socket == nullptr) {
-            GetLogger().Error("Cannot configure {} reflector \"{}\": socket on interface \"{}\" is invalid",
+            NFL_LOG_ERROR(GetLogger(), "Cannot configure {} reflector \"{}\": socket on interface \"{}\" is invalid",
                 protocol, config.name, config.source_if);
             return false;
         }
         auto* target_socket = GetOrCreateSocket(config.target_if);
         if (target_socket == nullptr) {
-            GetLogger().Error("Cannot configure {} reflector \"{}\": socket on interface \"{}\" is invalid",
+            NFL_LOG_ERROR(GetLogger(), "Cannot configure {} reflector \"{}\": socket on interface \"{}\" is invalid",
                 protocol, config.name, config.target_if);
             return false;
         }
 
         auto reflector = std::make_unique<ReflectorType>(packet_dispatcher_, *source_socket, *target_socket, config);
         if (!reflector->IsValid()) {
-            GetLogger().Error("Cannot configure {} reflector \"{}\": setup failed", protocol, config.name);
+            NFL_LOG_ERROR(GetLogger(), "Cannot configure {} reflector \"{}\": setup failed", protocol, config.name);
             return false;
         }
         reflectors_.push_back(std::move(reflector));
@@ -139,7 +139,7 @@ bool Application::Configure(const Config& config) {
         reconcile_timer_.Start(
             RECONCILE_BACKSTOP_INTERVAL, CreateDelegate<&Application::OnReconcileTick>(this));
         if (config.DebugMemory()) {
-            GetLogger().Info("Memory diagnostics enabled; reporting RSS/heap every {}s",
+            NFL_LOG_INFO(GetLogger(), "Memory diagnostics enabled; reporting RSS/heap every {}s",
                 MEMORY_REPORT_INTERVAL.count());
             LogMemoryReport();  // a baseline at startup, then every interval via the timer
             memory_timer_.emplace(*dispatcher_);
@@ -246,7 +246,7 @@ void Application::NotifyReflectors() noexcept {
 int Application::PrepareSignalWakeup() {
     int fds[2];
     if (::pipe(fds) != 0) {
-        GetLogger().Warning("Cannot create signal wakeup pipe: {}; shutdown bounded by the poll interval",
+        NFL_LOG_WARN(GetLogger(), "Cannot create signal wakeup pipe: {}; shutdown bounded by the poll interval",
             Error::FromErrno());
         return -1;
     }
@@ -258,7 +258,7 @@ int Application::PrepareSignalWakeup() {
     // the daemon never execs (like every other fd here), so there is nothing to leak across an exec.
     for (const int fd : {wakeup_read_.Get(), wakeup_write_.Get()}) {
         if (!SetNonBlocking(fd)) {
-            GetLogger().Warning("Cannot configure signal wakeup pipe: {}; shutdown bounded by the poll interval",
+            NFL_LOG_WARN(GetLogger(), "Cannot configure signal wakeup pipe: {}; shutdown bounded by the poll interval",
                 Error::FromErrno());
             wakeup_read_.Reset();
             wakeup_write_.Reset();
@@ -268,7 +268,7 @@ int Application::PrepareSignalWakeup() {
 
     wakeup_reg_ = dispatcher_->Register(wakeup_read_.Get(), CreateDelegate<&Application::OnWakeup>(this));
     if (!wakeup_reg_.IsValid()) {
-        GetLogger().Warning("Cannot register the signal wakeup pipe; shutdown bounded by the poll interval");
+        NFL_LOG_WARN(GetLogger(), "Cannot register the signal wakeup pipe; shutdown bounded by the poll interval");
         wakeup_read_.Reset();
         wakeup_write_.Reset();
         return -1;

src/reflector/config/config.cpp

@@ -29,11 +29,14 @@ std::string_view ToStringView(const toml::key& key) {
 
 std::expected<LogLevel, Error> LogLevelFromString(std::string_view s) {
     const auto lower = AsciiToLower(s);
+    if (lower == "trace") return LogLevel::Trace;
     if (lower == "debug") return LogLevel::Debug;
     if (lower == "info") return LogLevel::Info;
-    if (lower == "warning") return LogLevel::Warning;
+    if (lower == "warn") return LogLevel::Warn;
     if (lower == "error") return LogLevel::Error;
-    return std::unexpected(Error{"log_level must be one of: debug, info, warning, error; got \"{}\"", s});
+    if (lower == "off") return LogLevel::Off;
+    return std::unexpected(
+        Error{"log_level must be one of: trace, debug, info, warn, error, off; got \"{}\"", s});
 }
 
 std::expected<AddressFamily, Error> AddressFamilyFromString(std::string_view section, std::string_view s) {

src/reflector/default_address_monitor.cpp

@@ -83,7 +83,7 @@ DefaultAddressMonitor DefaultAddressMonitor::ForTesting(Dispatcher& dispatcher,
 
 bool DefaultAddressMonitor::Start(const OnInterfacesChanged& on_change) noexcept {
     if (!on_change.IsValid()) {
-        GetLogger().Error("Cannot start address monitor: the change callback is not bound");
+        NFL_LOG_ERROR(GetLogger(), "Cannot start address monitor: the change callback is not bound");
         Close();
         return false;
     }
@@ -101,40 +101,40 @@ bool DefaultAddressMonitor::Open() noexcept {
 #if defined(__linux__)
     fd_.Reset(socket(AF_NETLINK, SOCK_RAW | SOCK_NONBLOCK, NETLINK_ROUTE));
     if (!fd_) {
-        GetLogger().Error("Cannot open netlink socket: {}", Error::FromErrno());
+        NFL_LOG_ERROR(GetLogger(), "Cannot open netlink socket: {}", Error::FromErrno());
         return false;
     }
 
     sockaddr_nl address{};
     address.nl_family = AF_NETLINK;
     address.nl_groups = RTMGRP_IPV4_IFADDR | RTMGRP_IPV6_IFADDR | RTMGRP_LINK;
     if (bind(fd_.Get(), reinterpret_cast<const sockaddr*>(&address), sizeof(address)) != 0) {
-        GetLogger().Error("Cannot subscribe to netlink notification groups: {}", Error::FromErrno());
+        NFL_LOG_ERROR(GetLogger(), "Cannot subscribe to netlink notification groups: {}", Error::FromErrno());
         return false;
     }
 #else
     fd_.Reset(socket(PF_ROUTE, SOCK_RAW, 0));
     if (!fd_) {
-        GetLogger().Error("Cannot open route socket: {}", Error::FromErrno());
+        NFL_LOG_ERROR(GetLogger(), "Cannot open route socket: {}", Error::FromErrno());
         return false;
     }
     if (!SetNonBlocking(fd_.Get())) {
-        GetLogger().Error("Cannot set route socket non-blocking: {}", Error::FromErrno());
+        NFL_LOG_ERROR(GetLogger(), "Cannot set route socket non-blocking: {}", Error::FromErrno());
         return false;
     }
     // Best-effort: a bigger receive queue so a routing-message burst is less likely to overflow it.
     // Kernel-clamped, and the default still works, so a failure only warns — it doesn't fail Open.
     if (setsockopt(fd_.Get(), SOL_SOCKET, SO_RCVBUF,
             &ROUTE_RECEIVE_BUFFER_BYTES, sizeof(ROUTE_RECEIVE_BUFFER_BYTES)) != 0) {
-        GetLogger().Warning("Cannot enlarge the route socket receive buffer: {}", Error::FromErrno());
+        NFL_LOG_WARN(GetLogger(), "Cannot enlarge the route socket receive buffer: {}", Error::FromErrno());
     }
 #if defined(__FreeBSD__)
     // Without SO_RERROR (FreeBSD 13+) a receive-buffer overflow is dropped silently, so the ENOBUFS
     // refresh-all recovery in OnReadable never fires and address changes are lost under pressure.
     // Enabling it surfaces the overflow as ENOBUFS on the next recv. macOS has no equivalent.
     const int rerror = 1;
     if (setsockopt(fd_.Get(), SOL_SOCKET, SO_RERROR, &rerror, sizeof(rerror)) != 0) {
-        GetLogger().Error("Cannot enable SO_RERROR on the route socket: {}", Error::FromErrno());
+        NFL_LOG_ERROR(GetLogger(), "Cannot enable SO_RERROR on the route socket: {}", Error::FromErrno());
         return false;
     }
 #endif
@@ -146,10 +146,10 @@ bool DefaultAddressMonitor::Open() noexcept {
 bool DefaultAddressMonitor::Watch() noexcept {
     registration_ = dispatcher_->Register(fd_.Get(), CreateDelegate<&DefaultAddressMonitor::OnReadable>(this));
     if (!registration_.IsValid()) {
-        GetLogger().Error("Cannot register the address-notification socket with the dispatcher");
+        NFL_LOG_ERROR(GetLogger(), "Cannot register the address-notification socket with the dispatcher");
         return false;
     }
-    GetLogger().Debug("Watching for interface address changes on fd {}", fd_.Get());
+    NFL_LOG_DEBUG(GetLogger(), "Watching for interface address changes on fd {}", fd_.Get());
     return true;
 }
 
@@ -192,7 +192,7 @@ void DefaultAddressMonitor::OnReadable(int /*fd*/) noexcept {
                 overflowed = true;
                 continue;
             }
-            GetLogger().Error("Cannot read address notifications: {}", Error::FromErrno());
+            NFL_LOG_ERROR(GetLogger(), "Cannot read address notifications: {}", Error::FromErrno());
             break;
         }
         if (received == 0) {
@@ -201,7 +201,7 @@ void DefaultAddressMonitor::OnReadable(int /*fd*/) noexcept {
         // A local process can unicast a netlink datagram to this socket (user-to-user needs no
         // privilege), spoofing an address change; drop anything whose source isn't the kernel.
         if (verify_sender_ && !detail::NetlinkSenderIsKernel(src, addrlen)) {
-            GetLogger().Debug("Dropping an address notification from a non-kernel sender");
+            NFL_LOG_TRACE(GetLogger(), "Dropping an address notification from a non-kernel sender");
             continue;
         }
         // Once overflowed we'll emit a single refresh-all, so keep draining the socket but stop
@@ -213,9 +213,9 @@ void DefaultAddressMonitor::OnReadable(int /*fd*/) noexcept {
     }
 
     if (overflowed) {
-        GetLogger().Warning("Address notifications overflowed; refreshing all interfaces");
+        NFL_LOG_WARN(GetLogger(), "Address notifications overflowed; refreshing all interfaces");
     } else if (changed.overflowed) {
-        GetLogger().Debug("More than {} interfaces changed in one drain; refreshing all",
+        NFL_LOG_DEBUG(GetLogger(), "More than {} interfaces changed in one drain; refreshing all",
             MAX_CHANGED_INTERFACES);
     } else if (changed.count == 0) {
         return;  // the drain carried nothing we track, so there is nothing to tell anyone

src/reflector/default_packet_dispatcher.cpp

@@ -25,14 +25,14 @@ DefaultPacketDispatcher::DefaultPacketDispatcher(Dispatcher& dispatcher)
 
 DefaultPacketDispatcher::~DefaultPacketDispatcher() noexcept {
     if (!registrations_.empty()) {
-        GetLogger().Error("Destroying packet dispatcher with {} registration(s) still active", registrations_.size());
+        NFL_LOG_ERROR(GetLogger(), "Destroying packet dispatcher with {} registration(s) still active", registrations_.size());
     }
 }
 
 PacketDispatcher::Registration DefaultPacketDispatcher::Register(
     LinkSocket& socket, const PacketFilter& filter, const PacketCallback& callback) {
     if (!socket.IsValid()) {
-        GetLogger().Error("Cannot register packet callback: capture socket is invalid");
+        NFL_LOG_ERROR(GetLogger(), "Cannot register packet callback: capture socket is invalid");
         return {};
     }
 
@@ -42,7 +42,7 @@ PacketDispatcher::Registration DefaultPacketDispatcher::Register(
         // First subscriber for this socket: start watching its fd through the Dispatcher.
         auto dispatcher_reg = dispatcher_->Register(fd, CreateDelegate<&DefaultPacketDispatcher::OnReadable>(this));
         if (!dispatcher_reg.IsValid()) {
-            GetLogger().Error("Cannot register packet callback: dispatcher registration failed for fd {}", fd);
+            NFL_LOG_ERROR(GetLogger(), "Cannot register packet callback: dispatcher registration failed for fd {}", fd);
             return {};
         }
         source = capture_sources_.emplace(
@@ -53,7 +53,7 @@ PacketDispatcher::Registration DefaultPacketDispatcher::Register(
     // capture source's count.
     const auto id = static_cast<RegistrationId>(next_registration_id_++);
     registrations_.emplace_back(id, &source->second, callback, filter);
-    GetLogger().Debug("Registered packet callback {} for fd {}", std::to_underlying(id), fd);
+    NFL_LOG_TRACE(GetLogger(), "Registered packet callback {} for fd {}", std::to_underlying(id), fd);
     return MakeRegistration(id);
 }
 
@@ -62,10 +62,10 @@ bool DefaultPacketDispatcher::Unregister(RegistrationId id) noexcept {
         return r.id == id && r.enabled;
     });
     if (it == registrations_.end()) {
-        GetLogger().Warning("Cannot unregister packet callback {}: not found", std::to_underlying(id));
+        NFL_LOG_WARN(GetLogger(), "Cannot unregister packet callback {}: not found", std::to_underlying(id));
         return false;
     }
-    GetLogger().Debug("Unregistered packet callback {}", std::to_underlying(id));
+    NFL_LOG_TRACE(GetLogger(), "Unregistered packet callback {}", std::to_underlying(id));
     if (dispatching_) {
         it->enabled = false;  // DrainReadableFd is walking; defer the erase + teardown to its sweep
         return true;
@@ -83,7 +83,7 @@ bool DefaultPacketDispatcher::Unregister(RegistrationId id) noexcept {
 void DefaultPacketDispatcher::OnReadable(int fd) noexcept {
     const auto it = capture_sources_.find(fd);
     if (it == capture_sources_.end()) {
-        GetLogger().Warning("Readable callback for unknown capture fd {}", fd);
+        NFL_LOG_WARN(GetLogger(), "Readable callback for unknown capture fd {}", fd);
         return;
     }
     // Reported after the drain, not from inside it: the sweep may have dropped this capture
@@ -101,10 +101,11 @@ bool DefaultPacketDispatcher::DrainReadableFd(LinkSocket& socket) noexcept {
     dispatching_ = true;
     bool failed = false;
 
+    size_t packet_count = 0;
 #if defined(__linux__)
-    for (size_t packet_count = 0; packet_count < MAX_PACKETS_PER_READ_EVENT; ++packet_count) {
+    for (; packet_count < MAX_PACKETS_PER_READ_EVENT; ++packet_count) {
 #else
-    for (size_t packet_count = 0; packet_count < MAX_PACKETS_PER_READ_EVENT || socket.HasBufferedData(); ++packet_count) {
+    for (; packet_count < MAX_PACKETS_PER_READ_EVENT || socket.HasBufferedData(); ++packet_count) {
 #endif
         const auto packet = socket.Receive();
         if (!packet) {
@@ -126,6 +127,8 @@ bool DefaultPacketDispatcher::DrainReadableFd(LinkSocket& socket) noexcept {
         DispatchPacket(socket, *packet);
     }
 
+    NFL_LOG_TRACE(GetLogger(), "Drained {} frame(s)", packet_count);
+
     dispatching_ = false;
     Sweep();
     return !failed;
@@ -137,12 +140,18 @@ void DefaultPacketDispatcher::DispatchPacket(const LinkSocket& socket, const Pac
     // so index by position and re-fetch each iteration, never holding an iterator across the callback.
     // Removal is deferred to the sweep, so the walk never shifts and needs no restart. A callback that
     // Registers appends a higher entry this loop still reaches, dispatching it for the current packet.
+    size_t matched = 0;
     for (size_t idx = 0; idx < registrations_.size(); ++idx) {
         const auto& entry = registrations_[idx];
         if (entry.enabled && entry.capture_source->socket == &socket && entry.filter.Matches(packet)) {
+            ++matched;
             entry.callback(packet);
         }
     }
+    if (matched == 0) {
+        NFL_LOG_TRACE(GetLogger(), "No registration matched {} -> {}", packet.header.source,
+            packet.header.dest);
+    }
 }
 
 void DefaultPacketDispatcher::Sweep() noexcept {