mgmt+rib: improve logging

Change-Id: I2c8470831a9f9cbd5c06681f69783c4b442420f9
diff --git a/daemon/mgmt/fib-manager.cpp b/daemon/mgmt/fib-manager.cpp
index 4de989e..470a0ef 100644
--- a/daemon/mgmt/fib-manager.cpp
+++ b/daemon/mgmt/fib-manager.cpp
@@ -65,24 +65,24 @@
   uint64_t cost = parameters.getCost();
 
   if (prefix.size() > Fib::getMaxDepth()) {
-    NFD_LOG_DEBUG("fib/add-nexthop(" << prefix << ',' << faceId << ',' << cost <<
-                  "): FAIL prefix-too-long");
+    NFD_LOG_DEBUG("add-nexthop(" << prefix << ',' << faceId << ',' << cost <<
+                  ") -> FAIL prefix-too-long");
     return done(ControlResponse(414, "FIB entry prefix cannot exceed " +
                                 std::to_string(Fib::getMaxDepth()) + " components"));
   }
 
   Face* face = m_faceTable.get(faceId);
   if (face == nullptr) {
-    NFD_LOG_DEBUG("fib/add-nexthop(" << prefix << ',' << faceId << ',' << cost <<
-                  "): FAIL unknown-faceid");
+    NFD_LOG_DEBUG("add-nexthop(" << prefix << ',' << faceId << ',' << cost <<
+                  ") -> FAIL unknown-faceid");
     return done(ControlResponse(410, "Face not found"));
   }
 
   fib::Entry* entry = m_fib.insert(prefix).first;
   m_fib.addOrUpdateNextHop(*entry, *face, cost);
 
-  NFD_LOG_TRACE("fib/add-nexthop(" << prefix << ',' << faceId << ',' << cost << "): OK");
-  return done(ControlResponse(200, "Success").setBody(parameters.wireEncode()));
+  NFD_LOG_TRACE("add-nexthop(" << prefix << ',' << faceId << ',' << cost << ") -> OK");
+  return done(ControlResponse(200, "OK").setBody(parameters.wireEncode()));
 }
 
 void
@@ -93,30 +93,30 @@
   const Name& prefix = parameters.getName();
   FaceId faceId = parameters.getFaceId();
 
-  done(ControlResponse(200, "Success").setBody(parameters.wireEncode()));
+  done(ControlResponse(200, "OK").setBody(parameters.wireEncode()));
 
   Face* face = m_faceTable.get(faceId);
   if (face == nullptr) {
-    NFD_LOG_TRACE("fib/remove-nexthop(" << prefix << ',' << faceId << "): OK no-face");
+    NFD_LOG_TRACE("remove-nexthop(" << prefix << ',' << faceId << ") -> OK no-face");
     return;
   }
 
   fib::Entry* entry = m_fib.findExactMatch(parameters.getName());
   if (entry == nullptr) {
-    NFD_LOG_TRACE("fib/remove-nexthop(" << prefix << ',' << faceId << "): OK no-entry");
+    NFD_LOG_TRACE("remove-nexthop(" << prefix << ',' << faceId << ") -> OK no-entry");
     return;
   }
 
   auto status = m_fib.removeNextHop(*entry, *face);
   switch (status) {
     case Fib::RemoveNextHopResult::NO_SUCH_NEXTHOP:
-      NFD_LOG_TRACE("fib/remove-nexthop(" << prefix << ',' << faceId << "): OK no-nexthop");
+      NFD_LOG_TRACE("remove-nexthop(" << prefix << ',' << faceId << ") -> OK no-nexthop");
       break;
     case Fib::RemoveNextHopResult::FIB_ENTRY_REMOVED:
-      NFD_LOG_TRACE("fib/remove-nexthop(" << prefix << ',' << faceId << "): OK entry-erased");
+      NFD_LOG_TRACE("remove-nexthop(" << prefix << ',' << faceId << ") -> OK entry-erased");
       break;
     case Fib::RemoveNextHopResult::NEXTHOP_REMOVED:
-      NFD_LOG_TRACE("fib/remove-nexthop(" << prefix << ',' << faceId << "): OK nexthop-removed");
+      NFD_LOG_TRACE("remove-nexthop(" << prefix << ',' << faceId << ") -> OK nexthop-removed");
       break;
   }
 }
diff --git a/daemon/mgmt/rib-manager.cpp b/daemon/mgmt/rib-manager.cpp
index ddc53cf..d9331e5 100644
--- a/daemon/mgmt/rib-manager.cpp
+++ b/daemon/mgmt/rib-manager.cpp
@@ -31,6 +31,7 @@
 #include "table/fib.hpp"
 
 #include <boost/asio/defer.hpp>
+#include <boost/lexical_cast.hpp>
 
 #include <ndn-cxx/lp/tags.hpp>
 #include <ndn-cxx/mgmt/nfd/rib-entry.hpp>
@@ -122,11 +123,11 @@
   m_nfdController.start<ndn::nfd::FaceUpdateCommand>(
     ControlParameters().setFlagBit(ndn::nfd::BIT_LOCAL_FIELDS_ENABLED, true),
     [] (const ControlParameters&) {
-      NFD_LOG_DEBUG("Local fields enabled");
+      NFD_LOG_TRACE("Local fields enabled");
     },
     [] (const ControlResponse& res) {
-      NDN_THROW(Error("Couldn't enable local fields (" + std::to_string(res.getCode()) +
-                      " " + res.getText() + ")"));
+      NDN_THROW(Error("Could not enable local fields (error " +
+                      std::to_string(res.getCode()) + ": " + res.getText() + ")"));
     });
 }
 
@@ -182,11 +183,11 @@
 {
   m_rib.beginApplyUpdate(update,
     [=] {
-      NFD_LOG_DEBUG("RIB update succeeded for " << update);
+      NFD_LOG_DEBUG(update << " -> OK");
       done(RibUpdateResult::OK);
     },
     [=] (uint32_t code, const std::string& error) {
-      NFD_LOG_DEBUG("RIB update failed for " << update << " (" << code << " " << error << ")");
+      NFD_LOG_DEBUG(update << " -> error " << code << ": " << error);
 
       // Since the FIB rejected the update, clean up invalid routes
       scheduleActiveFaceFetch(1_s);
@@ -200,10 +201,9 @@
 {
   // add FIB nexthop
   m_nfdController.start<ndn::nfd::FibAddNextHopCommand>(
-    ControlParameters().setName(Name(topPrefix).append(MGMT_MODULE_NAME))
-                       .setFaceId(0),
+    ControlParameters().setName(Name(topPrefix).append(MGMT_MODULE_NAME)).setFaceId(0),
     [=] (const ControlParameters& res) {
-      NFD_LOG_DEBUG("Successfully registered " << topPrefix << " with NFD");
+      NFD_LOG_DEBUG("Successfully registered " << topPrefix << " with the forwarder");
 
       // Routes must be inserted into the RIB so route flags can be applied
       Route route;
@@ -214,14 +214,25 @@
       m_rib.insert(topPrefix, route);
     },
     [=] (const ControlResponse& res) {
-      NDN_THROW(Error("Cannot add FIB entry " + topPrefix.toUri() + " (" +
-                      std::to_string(res.getCode()) + " " + res.getText() + ")"));
+      NDN_THROW(Error("Could not add FIB entry " + topPrefix.toUri() + " (error " +
+                      std::to_string(res.getCode()) + ": " + res.getText() + ")"));
     });
 
   // add top prefix to the dispatcher without prefix registration
   m_dispatcher.addTopPrefix(topPrefix, false);
 }
 
+static uint64_t
+getIncomingFaceId(const Interest& request)
+{
+  auto incomingFaceIdTag = request.getTag<lp::IncomingFaceIdTag>();
+  // NDNLPv2 says "application MUST be prepared to receive a packet without IncomingFaceId field",
+  // but it's fine to assert IncomingFaceId is available, because InternalFace lives inside NFD
+  // and is initialized synchronously with IncomingFaceId field enabled.
+  BOOST_ASSERT(incomingFaceIdTag != nullptr);
+  return incomingFaceIdTag->get();
+}
+
 void
 RibManager::registerEntry(const Interest& interest, ControlParameters parameters,
                           const CommandContinuation& done)
@@ -232,10 +243,12 @@
     return;
   }
 
-  setFaceForSelfRegistration(interest, parameters);
+  if (parameters.getFaceId() == 0) { // self registration
+    parameters.setFaceId(getIncomingFaceId(interest));
+  }
 
   // Respond since command is valid and authorized
-  done(ControlResponse(200, "Success").setBody(parameters.wireEncode()));
+  done(ControlResponse(200, "OK").setBody(parameters.wireEncode()));
 
   Route route;
   route.faceId = parameters.getFaceId();
@@ -256,10 +269,12 @@
 RibManager::unregisterEntry(const Interest& interest, ControlParameters parameters,
                             const CommandContinuation& done)
 {
-  setFaceForSelfRegistration(interest, parameters);
+  if (parameters.getFaceId() == 0) { // self unregistration
+    parameters.setFaceId(getIncomingFaceId(interest));
+  }
 
   // Respond since command is valid and authorized
-  done(ControlResponse(200, "Success").setBody(parameters.wireEncode()));
+  done(ControlResponse(200, "OK").setBody(parameters.wireEncode()));
 
   Route route;
   route.faceId = parameters.getFaceId();
@@ -273,37 +288,38 @@
                           const CommandContinuation& done)
 {
   const auto& announcement = parameters.getPrefixAnnouncement();
-  if (announcement.getAnnouncedName().size() > Fib::getMaxDepth()) {
+  const auto& name = announcement.getAnnouncedName();
+  if (name.size() > Fib::getMaxDepth()) {
     done(ControlResponse(414, "Route prefix cannot exceed " + std::to_string(Fib::getMaxDepth()) +
                          " components"));
     return;
   }
 
+  Route route(announcement, getIncomingFaceId(interest));
+
   // Prepare parameters for response
   ControlParameters responseParams;
-  responseParams.setFaceId(0);
-  setFaceForSelfRegistration(interest, responseParams);
-
-  Route route(announcement, responseParams.getFaceId());
-
   responseParams
-    .setName(announcement.getAnnouncedName())
+    .setName(name)
+    .setFaceId(route.faceId)
     .setOrigin(route.origin)
     .setCost(route.cost)
     .setFlags(route.flags)
     .setExpirationPeriod(time::duration_cast<time::milliseconds>(route.annExpires - time::steady_clock::now()));
 
+  NDN_LOG_TRACE("Validating announcement " << announcement);
   BOOST_ASSERT(announcement.getData());
   m_paValidator.validate(*announcement.getData(),
-    [=, name = announcement.getAnnouncedName(), route = std::move(route)] (const Data&) {
+    [=, route = std::move(route)] (const Data&) {
       // Respond since command is valid and authorized
-      done(ControlResponse(200, "Success").setBody(responseParams.wireEncode()));
+      done(ControlResponse(200, "OK").setBody(responseParams.wireEncode()));
       beginAddRoute(name, std::move(route), std::nullopt, [] (RibUpdateResult) {});
     },
-    [=] (const Data&, ndn::security::ValidationError err) {
-      done(ControlResponse(403, "Validation error: " + err.getInfo()));
-    }
-  );
+    [=] (const Data&, const ndn::security::ValidationError& err) {
+      NDN_LOG_DEBUG("announce " << name << " -> " << err);
+      done(ControlResponse(403, "Prefix announcement rejected: " +
+                           boost::lexical_cast<std::string>(err.getCode())));
+    });
 }
 
 void
@@ -330,20 +346,6 @@
   context.end();
 }
 
-void
-RibManager::setFaceForSelfRegistration(const Interest& request, ControlParameters& parameters)
-{
-  bool isSelfRegistration = (parameters.getFaceId() == 0);
-  if (isSelfRegistration) {
-    shared_ptr<lp::IncomingFaceIdTag> incomingFaceIdTag = request.getTag<lp::IncomingFaceIdTag>();
-    // NDNLPv2 says "application MUST be prepared to receive a packet without IncomingFaceId field",
-    // but it's fine to assert IncomingFaceId is available, because InternalFace lives inside NFD
-    // and is initialized synchronously with IncomingFaceId field enabled.
-    BOOST_ASSERT(incomingFaceIdTag != nullptr);
-    parameters.setFaceId(*incomingFaceIdTag);
-  }
-}
-
 ndn::mgmt::Authorization
 RibManager::makeAuthorization(const std::string&)
 {
@@ -408,16 +410,15 @@
       beginAddRoute(pa.getAnnouncedName(), route, std::nullopt,
         [=] (RibUpdateResult ribRes) {
           auto res = getSlAnnounceResultFromRibUpdateResult(ribRes);
-          NFD_LOG_INFO("slAnnounce " << pa.getAnnouncedName() << " " << faceId << ": " << res);
+          NFD_LOG_INFO("slAnnounce " << pa.getAnnouncedName() << " " << faceId << " -> " << res);
           cb(res);
         });
     },
-    [=] (const Data&, ndn::security::ValidationError err) {
+    [=] (const Data&, const ndn::security::ValidationError& err) {
       NFD_LOG_INFO("slAnnounce " << pa.getAnnouncedName() << " " << faceId <<
-                   " validation error: " << err);
+                   " -> validation error: " << err);
       cb(SlAnnounceResult::VALIDATION_FAILURE);
-    }
-  );
+    });
 }
 
 void
@@ -430,7 +431,7 @@
   Route* oldRoute = m_rib.findLongestPrefix(name, routeQuery);
 
   if (oldRoute == nullptr || !oldRoute->announcement) {
-    NFD_LOG_DEBUG("slRenew " << name << " " << faceId << ": not found");
+    NFD_LOG_DEBUG("slRenew " << name << " " << faceId << " -> not found");
     return cb(SlAnnounceResult::NOT_FOUND);
   }
   Name routeName = oldRoute->announcement->getAnnouncedName();
@@ -440,7 +441,7 @@
   beginAddRoute(routeName, route, std::nullopt,
     [=] (RibUpdateResult ribRes) {
       auto res = getSlAnnounceResultFromRibUpdateResult(ribRes);
-      NFD_LOG_INFO("slRenew " << name << " " << faceId << ": " << res << " " << routeName);
+      NFD_LOG_INFO("slRenew " << name << " " << faceId << " -> " << res << " " << routeName);
       cb(res);
     });
 }
@@ -472,18 +473,14 @@
 
   m_nfdController.fetch<ndn::nfd::FaceDataset>(
     [this] (auto&&... args) { removeInvalidFaces(std::forward<decltype(args)>(args)...); },
-    [this] (auto&&... args) { onFetchActiveFacesFailure(std::forward<decltype(args)>(args)...); });
+    [this] (uint32_t code, const std::string& reason) {
+      NFD_LOG_WARN("Failed to fetch face dataset (error " << code << ": " << reason << ")");
+      scheduleActiveFaceFetch(ACTIVE_FACE_FETCH_INTERVAL);
+    });
 }
 
 void
-RibManager::onFetchActiveFacesFailure(uint32_t code, const std::string& reason)
-{
-  NFD_LOG_DEBUG("Face Status Dataset request failure " << code << " " << reason);
-  scheduleActiveFaceFetch(ACTIVE_FACE_FETCH_INTERVAL);
-}
-
-void
-RibManager::scheduleActiveFaceFetch(const time::seconds& timeToWait)
+RibManager::scheduleActiveFaceFetch(time::seconds timeToWait)
 {
   m_activeFaceFetchEvent = getScheduler().schedule(timeToWait, [this] { fetchActiveFaces(); });
 }
@@ -507,10 +504,9 @@
 void
 RibManager::onNotification(const ndn::nfd::FaceEventNotification& notification)
 {
-  NFD_LOG_TRACE("onNotification: " << notification);
+  NFD_LOG_TRACE("Received notification " << notification);
 
   if (notification.getKind() == ndn::nfd::FACE_EVENT_DESTROYED) {
-    NFD_LOG_DEBUG("Received notification for destroyed FaceId " << notification.getFaceId());
     boost::asio::defer(getGlobalIoService(),
                        [this, id = notification.getFaceId()] { m_rib.beginRemoveFace(id); });
   }
diff --git a/daemon/mgmt/rib-manager.hpp b/daemon/mgmt/rib-manager.hpp
index 3b348a1..87de627 100644
--- a/daemon/mgmt/rib-manager.hpp
+++ b/daemon/mgmt/rib-manager.hpp
@@ -224,9 +224,6 @@
   void
   listEntries(ndn::mgmt::StatusDatasetContext& context);
 
-  void
-  setFaceForSelfRegistration(const Interest& request, ControlParameters& parameters);
-
   ndn::mgmt::Authorization
   makeAuthorization(const std::string& verb) final;
 
@@ -234,12 +231,9 @@
   void
   fetchActiveFaces();
 
-  void
-  onFetchActiveFacesFailure(uint32_t code, const std::string& reason);
-
 NFD_PUBLIC_WITH_TESTS_ELSE_PRIVATE:
   void
-  scheduleActiveFaceFetch(const time::seconds& timeToWait);
+  scheduleActiveFaceFetch(time::seconds timeToWait);
 
   void
   removeInvalidFaces(const std::vector<ndn::nfd::FaceStatus>& activeFaces);
diff --git a/daemon/rib/fib-updater.cpp b/daemon/rib/fib-updater.cpp
index 897b6fb..0b8fc0e 100644
--- a/daemon/rib/fib-updater.cpp
+++ b/daemon/rib/fib-updater.cpp
@@ -64,24 +64,23 @@
 void
 FibUpdater::computeUpdates(const RibUpdateBatch& batch)
 {
-  NFD_LOG_DEBUG("Computing updates for batch with faceID: " << batch.getFaceId());
+  NFD_LOG_TRACE("Computing updates for batch with faceid=" << batch.getFaceId());
 
   // Compute updates and add to m_fibUpdates
   for (const RibUpdate& update : batch) {
     switch (update.getAction()) {
-      case RibUpdate::REGISTER:
-        computeUpdatesForRegistration(update);
-        break;
-      case RibUpdate::UNREGISTER:
-        computeUpdatesForUnregistration(update);
-        break;
-      case RibUpdate::REMOVE_FACE:
-        computeUpdatesForUnregistration(update);
-
-        // Do not apply updates with the same face ID as the destroyed face
-        // since they will be rejected by the FIB
-        m_updatesForBatchFaceId.clear();
-        break;
+    case RibUpdate::REGISTER:
+      computeUpdatesForRegistration(update);
+      break;
+    case RibUpdate::UNREGISTER:
+      computeUpdatesForUnregistration(update);
+      break;
+    case RibUpdate::REMOVE_FACE:
+      computeUpdatesForUnregistration(update);
+      // Do not apply updates with the same face ID as the destroyed face
+      // since they will be rejected by the FIB
+      m_updatesForBatchFaceId.clear();
+      break;
     }
   }
 }
diff --git a/daemon/rib/readvertise/readvertise.cpp b/daemon/rib/readvertise/readvertise.cpp
index 164e26b..1df539d 100644
--- a/daemon/rib/readvertise/readvertise.cpp
+++ b/daemon/rib/readvertise/readvertise.cpp
@@ -68,16 +68,16 @@
 {
   std::optional<ReadvertiseAction> action = m_policy->handleNewRoute(ribRoute);
   if (!action) {
-    NFD_LOG_DEBUG("add-route " << ribRoute.entry->getName() << '(' << ribRoute.route->faceId <<
-                  ',' << ribRoute.route->origin << ") not-readvertising");
+    NFD_LOG_DEBUG("add-route " << ribRoute.entry->getName() << " face=" << ribRoute.route->faceId <<
+                  " origin=" << ribRoute.route->origin << " -> not-readvertising");
     return;
   }
 
   auto [rrIt, isNewRr] = m_rrs.emplace(action->prefix);
   if (!isNewRr && rrIt->signer != action->signer) {
-    NFD_LOG_WARN("add-route " << ribRoute.entry->getName() << '(' << ribRoute.route->faceId <<
-                 ',' << ribRoute.route->origin << ") readvertising-as " << action->prefix <<
-                 " old-signer " << rrIt->signer << " new-signer " << action->signer);
+    NFD_LOG_WARN("add-route " << ribRoute.entry->getName() << " face=" << ribRoute.route->faceId <<
+                 " origin=" << ribRoute.route->origin << " -> readvertising-as " << action->prefix <<
+                 " old-signer=" << rrIt->signer << " new-signer=" << action->signer);
   }
   rrIt->signer = action->signer;
 
@@ -85,14 +85,14 @@
   BOOST_VERIFY(isNewInMap);
 
   if (rrIt->nRibRoutes++ > 0) {
-    NFD_LOG_DEBUG("add-route " << ribRoute.entry->getName() << '(' << ribRoute.route->faceId <<
-                  ',' << ribRoute.route->origin << ") already-readvertised-as " << action->prefix);
+    NFD_LOG_DEBUG("add-route " << ribRoute.entry->getName() << " face=" << ribRoute.route->faceId <<
+                  " origin=" << ribRoute.route->origin << " -> already-readvertised-as " << action->prefix);
     return;
   }
 
-  NFD_LOG_DEBUG("add-route " << ribRoute.entry->getName() << '(' << ribRoute.route->faceId <<
-                ',' << ribRoute.route->origin << ") readvertising-as " << action->prefix <<
-                " signer " << action->signer);
+  NFD_LOG_DEBUG("add-route " << ribRoute.entry->getName() << " face=" << ribRoute.route->faceId <<
+                " origin=" << ribRoute.route->origin << " -> readvertising-as " << action->prefix <<
+                " signer=" << action->signer);
   rrIt->retryDelay = RETRY_DELAY_MIN;
   this->advertise(rrIt);
 }
@@ -102,8 +102,8 @@
 {
   auto indexIt = m_routeToRr.find(ribRoute);
   if (indexIt == m_routeToRr.end()) {
-    NFD_LOG_DEBUG("remove-route " << ribRoute.entry->getName() << '(' << ribRoute.route->faceId <<
-                  ',' << ribRoute.route->origin << ") not-readvertised");
+    NFD_LOG_DEBUG("remove-route " << ribRoute.entry->getName() << " face=" << ribRoute.route->faceId <<
+                  " origin=" << ribRoute.route->origin << " -> not-readvertised");
     return;
   }
 
@@ -111,8 +111,8 @@
   m_routeToRr.erase(indexIt);
 
   if (--rrIt->nRibRoutes > 0) {
-    NFD_LOG_DEBUG("remove-route " << ribRoute.entry->getName() << '(' << ribRoute.route->faceId <<
-                  ',' << ribRoute.route->origin << ") needed-by " << rrIt->nRibRoutes);
+    NFD_LOG_DEBUG("remove-route " << ribRoute.entry->getName() << " face=" << ribRoute.route->faceId <<
+                  " origin=" << ribRoute.route->origin << " -> needed-by " << rrIt->nRibRoutes);
     return;
   }
 
@@ -149,19 +149,19 @@
   BOOST_ASSERT(rrIt->nRibRoutes > 0);
 
   if (!m_destination->isAvailable()) {
-    NFD_LOG_DEBUG("advertise " << rrIt->prefix << " destination-unavailable");
+    NFD_LOG_DEBUG("advertise " << rrIt->prefix << " -> destination unavailable");
     return;
   }
 
   m_destination->advertise(*rrIt,
     [=] {
-      NFD_LOG_DEBUG("advertise " << rrIt->prefix << " success");
+      NFD_LOG_DEBUG("advertise " << rrIt->prefix << " -> success");
       rrIt->retryDelay = RETRY_DELAY_MIN;
       rrIt->retryEvt = getScheduler().schedule(randomizeTimer(m_policy->getRefreshInterval()),
                                                [=] { advertise(rrIt); });
     },
     [=] (const std::string& msg) {
-      NFD_LOG_DEBUG("advertise " << rrIt->prefix << " failure: " << msg);
+      NFD_LOG_DEBUG("advertise " << rrIt->prefix << " -> failure: " << msg);
       rrIt->retryDelay = std::min(RETRY_DELAY_MAX, rrIt->retryDelay * 2);
       rrIt->retryEvt = getScheduler().schedule(randomizeTimer(rrIt->retryDelay),
                                                [=] { advertise(rrIt); });
@@ -174,18 +174,18 @@
   BOOST_ASSERT(rrIt->nRibRoutes == 0);
 
   if (!m_destination->isAvailable()) {
-    NFD_LOG_DEBUG("withdraw " << rrIt->prefix << " destination-unavailable");
+    NFD_LOG_DEBUG("withdraw " << rrIt->prefix << " -> destination unavailable");
     m_rrs.erase(rrIt);
     return;
   }
 
   m_destination->withdraw(*rrIt,
     [=] {
-      NFD_LOG_DEBUG("withdraw " << rrIt->prefix << " success");
+      NFD_LOG_DEBUG("withdraw " << rrIt->prefix << " -> success");
       m_rrs.erase(rrIt);
     },
     [=] (const std::string& msg) {
-      NFD_LOG_DEBUG("withdraw " << rrIt->prefix << " failure: " << msg);
+      NFD_LOG_DEBUG("withdraw " << rrIt->prefix << " -> failure: " << msg);
       rrIt->retryDelay = std::min(RETRY_DELAY_MAX, rrIt->retryDelay * 2);
       rrIt->retryEvt = getScheduler().schedule(randomizeTimer(rrIt->retryDelay),
                                                [=] { withdraw(rrIt); });
diff --git a/daemon/rib/rib-update.cpp b/daemon/rib/rib-update.cpp
index 935ccce..8fc5000 100644
--- a/daemon/rib/rib-update.cpp
+++ b/daemon/rib/rib-update.cpp
@@ -1,6 +1,6 @@
 /* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
 /*
- * Copyright (c) 2014-2023,  Regents of the University of California,
+ * Copyright (c) 2014-2025,  Regents of the University of California,
  *                           Arizona Board of Regents,
  *                           Colorado State University,
  *                           University Pierre & Marie Curie, Sorbonne University,
@@ -44,10 +44,9 @@
 std::ostream&
 operator<<(std::ostream& os, const RibUpdate& update)
 {
-  return os << "RibUpdate {\n"
-            << "  Name: " << update.getName() << "\n"
-            << "  Action: " << update.getAction() << "\n"
-            << "  " << update.getRoute() << "\n"
+  return os << "RibUpdate{" << update.getAction()
+            << ", " << update.getName()
+            << ", " << update.getRoute()
             << "}";
 }
 
diff --git a/daemon/rib/route.cpp b/daemon/rib/route.cpp
index 5011290..642aa1e 100644
--- a/daemon/rib/route.cpp
+++ b/daemon/rib/route.cpp
@@ -35,13 +35,14 @@
 computeExpiration(const ndn::PrefixAnnouncement& ann)
 {
   auto validityEnd = time::steady_clock::duration::max();
-  if (ann.getValidityPeriod()) {
+  const auto& validityPeriod = ann.getValidityPeriod();
+  if (validityPeriod) {
     auto now = time::system_clock::now();
-    if (!ann.getValidityPeriod()->isValid(now)) {
+    if (!validityPeriod->isValid(now)) {
       validityEnd = time::steady_clock::duration::zero();
     }
     else {
-      validityEnd = ann.getValidityPeriod()->getPeriod().second - now;
+      validityEnd = validityPeriod->getPeriod().second - now;
     }
   }
   return time::steady_clock::now() +
@@ -62,8 +63,8 @@
 std::ostream&
 operator<<(std::ostream& os, const Route& route)
 {
-  os << "Route("
-     << "faceid: " << route.faceId
+  os << "Route{"
+     << "face: " << route.faceId
      << ", origin: " << route.origin
      << ", cost: " << route.cost
      << ", flags: " << ndn::AsHex{route.flags};
@@ -72,14 +73,14 @@
     os << ", expires in: " << time::duration_cast<time::milliseconds>(*route.expires - time::steady_clock::now());
   }
   else {
-    os << ", never expires";
+    os << ", expires: never";
   }
 
   if (route.announcement) {
     os << ", announcement: (" << *route.announcement << ')';
   }
 
-  return os << ')';
+  return os << '}';
 }
 
 } // namespace nfd::rib