fw: refactor strategy logging and improve ASF probe logging
Bring strategy logging in line with format from 6bf94c0.
This should also marginally improve performance when log level is raised.
Refs: #5262, #5267
Co-authored-by: Davide Pesavento <davidepesa@gmail.com>
Change-Id: I6493b6476f3d0c6ae5562b66abfa46f6c6f4903d
diff --git a/daemon/fw/access-strategy.cpp b/daemon/fw/access-strategy.cpp
index c2b6504..688867f 100644
--- a/daemon/fw/access-strategy.cpp
+++ b/daemon/fw/access-strategy.cpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/*
- * Copyright (c) 2014-2022, Regents of the University of California,
+ * Copyright (c) 2014-2023, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -65,7 +65,7 @@
case RetxSuppressionResult::FORWARD:
return afterReceiveRetxInterest(interest, ingress, pitEntry);
case RetxSuppressionResult::SUPPRESS:
- NFD_LOG_DEBUG(interest << " interestFrom " << ingress << " retx-suppress");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "suppressed");
return;
}
}
@@ -79,7 +79,7 @@
// has measurements for Interest Name?
if (mi != nullptr) {
- NFD_LOG_DEBUG(interest << " interestFrom " << ingress << " new-interest mi=" << miName);
+ NFD_LOG_INTEREST_FROM(interest, ingress, "new mi=" << miName);
// send to last working nexthop
bool isSentToLastNexthop = this->sendToLastNexthop(interest, ingress, pitEntry, *mi, fibEntry);
@@ -88,7 +88,7 @@
}
}
else {
- NFD_LOG_DEBUG(interest << " interestFrom " << ingress << " new-interest no-mi");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "new no-mi");
}
// no measurements, or last working nexthop unavailable
@@ -105,8 +105,8 @@
AccessStrategy::afterReceiveRetxInterest(const Interest& interest, const FaceEndpoint& ingress,
const shared_ptr<pit::Entry>& pitEntry)
{
+ NFD_LOG_INTEREST_FROM(interest, ingress, "retx");
const auto& fibEntry = this->lookupFib(*pitEntry);
- NFD_LOG_DEBUG(interest << " interestFrom " << ingress << " retx-forward");
this->multicast(interest, ingress.face, pitEntry, fibEntry);
}
@@ -116,29 +116,29 @@
const fib::Entry& fibEntry)
{
if (mi.lastNexthop == face::INVALID_FACEID) {
- NFD_LOG_DEBUG(pitEntry->getInterest() << " no-last-nexthop");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "no-last-nexthop");
return false;
}
if (mi.lastNexthop == ingress.face.getId()) {
- NFD_LOG_DEBUG(pitEntry->getInterest() << " last-nexthop-is-downstream");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "last-nexthop-is-downstream");
return false;
}
Face* outFace = this->getFace(mi.lastNexthop);
if (outFace == nullptr || !fibEntry.hasNextHop(*outFace)) {
- NFD_LOG_DEBUG(pitEntry->getInterest() << " last-nexthop-gone");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "last-nexthop-gone");
return false;
}
if (wouldViolateScope(ingress.face, interest, *outFace)) {
- NFD_LOG_DEBUG(pitEntry->getInterest() << " last-nexthop-violates-scope");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "last-nexthop-violates-scope");
return false;
}
auto rto = mi.rtt.getEstimatedRto();
- NFD_LOG_DEBUG(pitEntry->getInterest() << " interestTo " << mi.lastNexthop
- << " last-nexthop rto=" << time::duration_cast<time::microseconds>(rto).count());
+ NFD_LOG_INTEREST_FROM(interest, ingress, "to=" << mi.lastNexthop << " last-nexthop rto="
+ << time::duration_cast<time::microseconds>(rto).count() << "us");
if (!this->sendInterest(interest, *outFace, pitEntry)) {
return false;
@@ -164,8 +164,8 @@
Face* inFace = this->getFace(inFaceId);
if (inFace == nullptr) {
- NFD_LOG_DEBUG(pitEntry->getInterest() << " timeoutFrom " << firstOutFaceId
- << " inFace-gone " << inFaceId);
+ NFD_LOG_DEBUG(pitEntry->getName() << " timeout from=" << firstOutFaceId
+ << " in-face-gone=" << inFaceId);
return;
}
@@ -178,8 +178,7 @@
const Interest& interest = inRecord->getInterest();
const fib::Entry& fibEntry = this->lookupFib(*pitEntry);
- NFD_LOG_DEBUG(pitEntry->getInterest() << " timeoutFrom " << firstOutFaceId
- << " multicast-except " << firstOutFaceId);
+ NFD_LOG_DEBUG(pitEntry->getName() << " timeout from=" << firstOutFaceId << " multicast");
this->multicast(interest, *inFace, pitEntry, fibEntry, firstOutFaceId);
}
@@ -195,7 +194,8 @@
wouldViolateScope(inFace, interest, outFace)) {
continue;
}
- NFD_LOG_DEBUG(pitEntry->getInterest() << " interestTo " << outFace.getId() << " multicast");
+ NFD_LOG_DEBUG(interest.getName() << " nonce=" << interest.getNonce()
+ << " multicast to=" << outFace.getId());
if (this->sendInterest(interest, outFace, pitEntry)) {
++nSent;
}
@@ -213,19 +213,18 @@
}
if (!pitEntry->hasInRecords()) { // already satisfied by another upstream
- NFD_LOG_DEBUG(pitEntry->getInterest() << " dataFrom " << ingress << " not-fastest");
+ NFD_LOG_DATA_FROM(data, ingress, "not-fastest");
return;
}
auto outRecord = pitEntry->getOutRecord(ingress.face);
- if (outRecord == pitEntry->out_end()) { // no out-record
- NFD_LOG_DEBUG(pitEntry->getInterest() << " dataFrom " << ingress << " no-out-record");
+ if (outRecord == pitEntry->out_end()) {
+ NFD_LOG_DATA_FROM(data, ingress, "no-out-record");
return;
}
auto rtt = time::steady_clock::now() - outRecord->getLastRenewed();
- NFD_LOG_DEBUG(pitEntry->getInterest() << " dataFrom " << ingress
- << " rtt=" << time::duration_cast<time::microseconds>(rtt).count());
+ NFD_LOG_DATA_FROM(data, ingress, "rtt=" << time::duration_cast<time::microseconds>(rtt).count() << "us");
this->updateMeasurements(ingress.face, data, rtt);
}
diff --git a/daemon/fw/asf-strategy.cpp b/daemon/fw/asf-strategy.cpp
index d4ea944..8ff31a2 100644
--- a/daemon/fw/asf-strategy.cpp
+++ b/daemon/fw/asf-strategy.cpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/*
- * Copyright (c) 2014-2022, Regents of the University of California,
+ * Copyright (c) 2014-2023, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -25,7 +25,6 @@
#include "asf-strategy.hpp"
#include "algorithm.hpp"
-#include "common/global.hpp"
#include "common/logger.hpp"
namespace nfd::fw::asf {
@@ -75,11 +74,11 @@
if (!hasPendingOutRecords(*pitEntry)) {
auto* faceToUse = getBestFaceForForwarding(interest, ingress.face, fibEntry, pitEntry);
if (faceToUse == nullptr) {
- NFD_LOG_DEBUG(interest << " new-interest from=" << ingress << " no-nexthop");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "new no-nexthop");
sendNoRouteNack(ingress.face, pitEntry);
}
else {
- NFD_LOG_DEBUG(interest << " new-interest from=" << ingress << " forward-to=" << faceToUse->getId());
+ NFD_LOG_INTEREST_FROM(interest, ingress, "new forward-to=" << faceToUse->getId());
forwardInterest(interest, *faceToUse, fibEntry, pitEntry);
sendProbe(interest, ingress, *faceToUse, fibEntry, pitEntry);
}
@@ -91,13 +90,12 @@
auto suppressResult = m_retxSuppression->decidePerUpstream(*pitEntry, *faceToUse);
if (suppressResult == RetxSuppressionResult::SUPPRESS) {
// Cannot be sent on this face, interest was received within the suppression window
- NFD_LOG_DEBUG(interest << " retx-interest from=" << ingress
- << " forward-to=" << faceToUse->getId() << " suppressed");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "retx forward-to=" << faceToUse->getId() << " suppressed");
}
else {
// The retx arrived after the suppression period: forward it but don't probe, because
// probing was done earlier for this interest when it was newly received
- NFD_LOG_DEBUG(interest << " retx-interest from=" << ingress << " forward-to=" << faceToUse->getId());
+ NFD_LOG_INTEREST_FROM(interest, ingress, "retx forward-to=" << faceToUse->getId());
auto* outRecord = forwardInterest(interest, *faceToUse, fibEntry, pitEntry);
if (outRecord && suppressResult == RetxSuppressionResult::FORWARD) {
m_retxSuppression->incrementIntervalForOutRecord(*outRecord);
@@ -111,17 +109,16 @@
const auto& nexthops = fibEntry.getNextHops();
auto it = findEligibleNextHopWithEarliestOutRecord(ingress.face, interest, nexthops, pitEntry);
if (it == nexthops.end()) {
- NFD_LOG_DEBUG(interest << " retx-interest from=" << ingress << " no eligible nexthop");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "retx no-nexthop");
return;
}
auto& outFace = it->getFace();
auto suppressResult = m_retxSuppression->decidePerUpstream(*pitEntry, outFace);
if (suppressResult == RetxSuppressionResult::SUPPRESS) {
- NFD_LOG_DEBUG(interest << " retx-interest from=" << ingress
- << " retry-to=" << outFace.getId() << " suppressed");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "retx retry-to=" << outFace.getId() << " suppressed");
}
else {
- NFD_LOG_DEBUG(interest << " retx-interest from=" << ingress << " retry-to=" << outFace.getId());
+ NFD_LOG_INTEREST_FROM(interest, ingress, "retx retry-to=" << outFace.getId());
// sendInterest() is used here instead of forwardInterest() because the measurements info
// were already attached to this face in the previous forwarding
auto* outRecord = sendInterest(interest, outFace, pitEntry);
@@ -137,25 +134,24 @@
{
NamespaceInfo* namespaceInfo = m_measurements.getNamespaceInfo(pitEntry->getName());
if (namespaceInfo == nullptr) {
- NFD_LOG_DEBUG(pitEntry->getName() << " data from=" << ingress << " no-measurements");
+ NFD_LOG_DATA_FROM(data, ingress, "no-measurements");
return;
}
// Record the RTT between the Interest out to Data in
FaceInfo* faceInfo = namespaceInfo->getFaceInfo(ingress.face.getId());
if (faceInfo == nullptr) {
- NFD_LOG_DEBUG(pitEntry->getName() << " data from=" << ingress << " no-face-info");
+ NFD_LOG_DATA_FROM(data, ingress, "no-face-info");
return;
}
auto outRecord = pitEntry->getOutRecord(ingress.face);
if (outRecord == pitEntry->out_end()) {
- NFD_LOG_DEBUG(pitEntry->getName() << " data from=" << ingress << " no-out-record");
+ NFD_LOG_DATA_FROM(data, ingress, "no-out-record");
}
else {
faceInfo->recordRtt(time::steady_clock::now() - outRecord->getLastRenewed());
- NFD_LOG_DEBUG(pitEntry->getName() << " data from=" << ingress
- << " rtt=" << faceInfo->getLastRtt() << " srtt=" << faceInfo->getSrtt());
+ NFD_LOG_DATA_FROM(data, ingress, "rtt=" << faceInfo->getLastRtt() << " srtt=" << faceInfo->getSrtt());
}
// Extend lifetime for measurements associated with Face
@@ -169,7 +165,7 @@
AsfStrategy::afterReceiveNack(const lp::Nack& nack, const FaceEndpoint& ingress,
const shared_ptr<pit::Entry>& pitEntry)
{
- NFD_LOG_DEBUG(nack.getInterest() << " nack from=" << ingress << " reason=" << nack.getReason());
+ NFD_LOG_NACK_FROM(nack, ingress, "");
onTimeoutOrNack(pitEntry->getName(), ingress.face.getId(), true);
}
@@ -213,7 +209,8 @@
Interest probeInterest(interest);
probeInterest.refreshNonce();
- NFD_LOG_TRACE("Sending probe " << probeInterest << " to=" << faceToProbe->getId());
+ NFD_LOG_DEBUG("Sending probe " << probeInterest.getName() << " nonce=" << probeInterest.getNonce()
+ << " to=" << faceToProbe->getId() << " trigger-nonce=" << interest.getNonce());
forwardInterest(probeInterest, *faceToProbe, fibEntry, pitEntry);
m_probing.afterForwardingProbe(fibEntry, interest.getName());
diff --git a/daemon/fw/best-route-strategy.cpp b/daemon/fw/best-route-strategy.cpp
index 0de6265..a275b3a 100644
--- a/daemon/fw/best-route-strategy.cpp
+++ b/daemon/fw/best-route-strategy.cpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/*
- * Copyright (c) 2014-2022, Regents of the University of California,
+ * Copyright (c) 2014-2023, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -61,9 +61,9 @@
BestRouteStrategy::afterReceiveInterest(const Interest& interest, const FaceEndpoint& ingress,
const shared_ptr<pit::Entry>& pitEntry)
{
- RetxSuppressionResult suppression = m_retxSuppression->decidePerPitEntry(*pitEntry);
+ auto suppression = m_retxSuppression->decidePerPitEntry(*pitEntry);
if (suppression == RetxSuppressionResult::SUPPRESS) {
- NFD_LOG_DEBUG(interest << " from=" << ingress << " suppressed");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "suppressed");
return;
}
@@ -78,8 +78,7 @@
});
if (it == nexthops.end()) {
- NFD_LOG_DEBUG(interest << " from=" << ingress << " noNextHop");
-
+ NFD_LOG_INTEREST_FROM(interest, ingress, "new no-nexthop");
lp::NackHeader nackHeader;
nackHeader.setReason(lp::NackReason::NO_ROUTE);
this->sendNack(nackHeader, ingress.face, pitEntry);
@@ -88,7 +87,7 @@
}
Face& outFace = it->getFace();
- NFD_LOG_DEBUG(interest << " from=" << ingress << " newPitEntry-to=" << outFace.getId());
+ NFD_LOG_INTEREST_FROM(interest, ingress, "new to=" << outFace.getId());
this->sendInterest(interest, outFace, pitEntry);
return;
}
@@ -102,19 +101,19 @@
if (it != nexthops.end()) {
Face& outFace = it->getFace();
this->sendInterest(interest, outFace, pitEntry);
- NFD_LOG_DEBUG(interest << " from=" << ingress << " retransmit-unused-to=" << outFace.getId());
+ NFD_LOG_INTEREST_FROM(interest, ingress, "retx unused-to=" << outFace.getId());
return;
}
// find an eligible upstream that is used earliest
it = findEligibleNextHopWithEarliestOutRecord(ingress.face, interest, nexthops, pitEntry);
if (it == nexthops.end()) {
- NFD_LOG_DEBUG(interest << " from=" << ingress << " retransmitNoNextHop");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "retx no-nexthop");
}
else {
Face& outFace = it->getFace();
this->sendInterest(interest, outFace, pitEntry);
- NFD_LOG_DEBUG(interest << " from=" << ingress << " retransmit-retry-to=" << outFace.getId());
+ NFD_LOG_INTEREST_FROM(interest, ingress, "retx retry-to=" << outFace.getId());
}
}
diff --git a/daemon/fw/multicast-strategy.cpp b/daemon/fw/multicast-strategy.cpp
index ab8e12a..678f52a 100644
--- a/daemon/fw/multicast-strategy.cpp
+++ b/daemon/fw/multicast-strategy.cpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/*
- * Copyright (c) 2014-2022, Regents of the University of California,
+ * Copyright (c) 2014-2023, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -67,10 +67,9 @@
for (const auto& nexthop : nexthops) {
Face& outFace = nexthop.getFace();
- RetxSuppressionResult suppressResult = m_retxSuppression->decidePerUpstream(*pitEntry, outFace);
-
+ auto suppressResult = m_retxSuppression->decidePerUpstream(*pitEntry, outFace);
if (suppressResult == RetxSuppressionResult::SUPPRESS) {
- NFD_LOG_DEBUG(interest << " from=" << ingress << " to=" << outFace.getId() << " suppressed");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "to=" << outFace.getId() << " suppressed");
continue;
}
@@ -78,7 +77,7 @@
continue;
}
- NFD_LOG_DEBUG(interest << " from=" << ingress << " pitEntry-to=" << outFace.getId());
+ NFD_LOG_INTEREST_FROM(interest, ingress, "to=" << outFace.getId());
auto* sentOutRecord = this->sendInterest(interest, outFace, pitEntry);
if (sentOutRecord && suppressResult == RetxSuppressionResult::FORWARD) {
m_retxSuppression->incrementIntervalForOutRecord(*sentOutRecord);
@@ -93,16 +92,15 @@
// no need to check for suppression, as it is a new next hop
auto nextHopFaceId = nextHop.getFace().getId();
- auto& interest = pitEntry->getInterest();
+ const auto& interest = pitEntry->getInterest();
// try to find an incoming face record that doesn't violate scope restrictions
for (const auto& r : pitEntry->getInRecords()) {
auto& inFace = r.getFace();
+
if (isNextHopEligible(inFace, interest, nextHop, pitEntry)) {
-
- NFD_LOG_DEBUG(interest << " from=" << inFace.getId() << " pitEntry-to=" << nextHopFaceId);
+ NFD_LOG_INTEREST_FROM(interest, inFace.getId(), "new-nexthop to=" << nextHopFaceId);
this->sendInterest(interest, nextHop.getFace(), pitEntry);
-
break; // just one eligible incoming face record is enough
}
}
diff --git a/daemon/fw/process-nack-traits.cpp b/daemon/fw/process-nack-traits.cpp
index 4b4fbbc..25b2526 100644
--- a/daemon/fw/process-nack-traits.cpp
+++ b/daemon/fw/process-nack-traits.cpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/*
- * Copyright (c) 2014-2022, Regents of the University of California,
+ * Copyright (c) 2014-2023, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -58,26 +58,20 @@
auto inR = pitEntry->getInRecord(*lastFaceNotNacked);
if (inR != pitEntry->in_end()) {
// one out-record not Nacked, which is also a downstream
- NFD_LOG_DEBUG(nack.getInterest() << " nack-from=" << inFace.getId() <<
- " nack=" << nack.getReason() <<
- " nack-to(bidirectional)=" << lastFaceNotNacked->getId() <<
- " out-nack=" << outNack.getReason());
+ NFD_LOG_NACK_FROM(nack, inFace.getId(), "bidirectional nack-to=" << lastFaceNotNacked->getId()
+ << " out-nack=" << outNack.getReason());
this->sendNackForProcessNackTraits(pitEntry, *lastFaceNotNacked, outNack);
return;
}
}
if (nOutRecordsNotNacked > 0) {
- NFD_LOG_DEBUG(nack.getInterest() << " nack-from=" << inFace.getId() <<
- " nack=" << nack.getReason() <<
- " waiting=" << nOutRecordsNotNacked);
+ NFD_LOG_NACK_FROM(nack, inFace.getId(), "waiting=" << nOutRecordsNotNacked);
// continue waiting
return;
}
- NFD_LOG_DEBUG(nack.getInterest() << " nack-from=" << inFace.getId() <<
- " nack=" << nack.getReason() <<
- " nack-to=all out-nack=" << outNack.getReason());
+ NFD_LOG_NACK_FROM(nack, inFace.getId(), "nack-to=all out-nack=" << outNack.getReason());
this->sendNacksForProcessNackTraits(pitEntry, outNack);
}
diff --git a/daemon/fw/random-strategy.cpp b/daemon/fw/random-strategy.cpp
index b4950e7..a7ba224 100644
--- a/daemon/fw/random-strategy.cpp
+++ b/daemon/fw/random-strategy.cpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/*
- * Copyright (c) 2014-2022, Regents of the University of California,
+ * Copyright (c) 2014-2023, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -66,8 +66,7 @@
[&] (const auto& nh) { return isNextHopEligible(ingress.face, interest, nh, pitEntry); });
if (nhs.empty()) {
- NFD_LOG_DEBUG(interest << " from=" << ingress << " no nexthop");
-
+ NFD_LOG_INTEREST_FROM(interest, ingress, "no-nexthop");
lp::NackHeader nackHeader;
nackHeader.setReason(lp::NackReason::NO_ROUTE);
this->sendNack(nackHeader, ingress.face, pitEntry);
diff --git a/daemon/fw/retx-suppression.hpp b/daemon/fw/retx-suppression.hpp
index 7cf6893..ac658b0 100644
--- a/daemon/fw/retx-suppression.hpp
+++ b/daemon/fw/retx-suppression.hpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/*
- * Copyright (c) 2014-2022, Regents of the University of California,
+ * Copyright (c) 2014-2023, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -26,22 +26,12 @@
#ifndef NFD_DAEMON_FW_RETX_SUPPRESSION_HPP
#define NFD_DAEMON_FW_RETX_SUPPRESSION_HPP
-#include "core/common.hpp"
-
namespace nfd::fw {
enum class RetxSuppressionResult {
- /** \brief Interest is new (not a retransmission)
- */
- NEW,
-
- /** \brief Interest is retransmission and should be forwarded
- */
- FORWARD,
-
- /** \brief Interest is retransmission and should be suppressed
- */
- SUPPRESS
+ NEW, ///< Interest is new (not a retransmission).
+ FORWARD, ///< Interest is a retransmission and should be forwarded.
+ SUPPRESS, ///< Interest is a retransmission and should be suppressed.
};
} // namespace nfd::fw
diff --git a/daemon/fw/self-learning-strategy.cpp b/daemon/fw/self-learning-strategy.cpp
index 399b970..19d9d75 100644
--- a/daemon/fw/self-learning-strategy.cpp
+++ b/daemon/fw/self-learning-strategy.cpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/*
- * Copyright (c) 2014-2022, Regents of the University of California,
+ * Copyright (c) 2014-2023, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -76,7 +76,7 @@
if (isNonDiscovery) { // "non-discovery" Interest
inRecordInfo->isNonDiscoveryInterest = true;
if (nexthops.empty()) { // return NACK if no matching FIB entry exists
- NFD_LOG_DEBUG("NACK non-discovery Interest=" << interest << " from=" << ingress << " noNextHop");
+ NFD_LOG_INTEREST_FROM(interest, ingress, "non-discovery no-nexthop");
lp::NackHeader nackHeader;
nackHeader.setReason(lp::NackReason::NO_ROUTE);
this->sendNack(nackHeader, ingress.face, pitEntry);
@@ -104,7 +104,7 @@
{
auto outRecord = pitEntry->getOutRecord(ingress.face);
if (outRecord == pitEntry->out_end()) {
- NFD_LOG_DEBUG("Data " << data.getName() << " from=" << ingress << " no out-record");
+ NFD_LOG_DATA_FROM(data, ingress, "no-out-record");
return;
}
@@ -132,11 +132,11 @@
SelfLearningStrategy::afterReceiveNack(const lp::Nack& nack, const FaceEndpoint& ingress,
const shared_ptr<pit::Entry>& pitEntry)
{
- NFD_LOG_DEBUG("Nack for " << nack.getInterest() << " from=" << ingress
- << " reason=" << nack.getReason());
+ NFD_LOG_NACK_FROM(nack, ingress, "");
+
if (nack.getReason() == lp::NackReason::NO_ROUTE) { // remove FIB entries
BOOST_ASSERT(this->lookupFib(*pitEntry).hasNextHops());
- NFD_LOG_DEBUG("Send NACK to all downstreams");
+ NFD_LOG_DEBUG("Send Nack to all downstreams");
this->sendNacks(nack.getHeader(), pitEntry);
renewRoute(nack.getInterest().getName(), ingress.face.getId(), 0_ms);
}
@@ -153,8 +153,7 @@
continue;
}
- NFD_LOG_DEBUG("send discovery Interest=" << interest << " from=" << inFace.getId() <<
- " to=" << outFace.getId());
+ NFD_LOG_INTEREST_FROM(interest, inFace.getId(), "send discovery to=" << outFace.getId());
auto outRecord = this->sendInterest(interest, outFace, pitEntry);
if (outRecord != nullptr) {
outRecord->insertStrategyInfo<OutRecordInfo>().first->isNonDiscoveryInterest = false;
@@ -173,8 +172,7 @@
}
Face& outFace = nexthop.getFace();
- NFD_LOG_DEBUG("send non-discovery Interest=" << interest << " from=" << inFace.getId() <<
- " to=" << outFace.getId());
+ NFD_LOG_INTEREST_FROM(interest, inFace.getId(), "send non-discovery to=" << outFace.getId());
auto outRecord = this->sendInterest(interest, outFace, pitEntry);
if (outRecord != nullptr) {
outRecord->insertStrategyInfo<OutRecordInfo>().first->isNonDiscoveryInterest = true;
@@ -198,13 +196,13 @@
auto pitEntry = pitEntryWeak.lock();
auto inFace = this->getFace(inFaceId);
if (pitEntry && inFace) {
- NFD_LOG_DEBUG("found PrefixAnnouncement=" << pa.getAnnouncedName());
+ NFD_LOG_DEBUG("Found PrefixAnnouncement=" << pa.getAnnouncedName());
data.setTag(make_shared<lp::PrefixAnnouncementTag>(lp::PrefixAnnouncementHeader(pa)));
this->sendDataToAll(data, pitEntry, *inFace);
this->setExpiryTimer(pitEntry, 0_ms);
}
else {
- NFD_LOG_DEBUG("PIT entry or Face no longer exists");
+ NFD_LOG_DEBUG("PIT entry or face no longer exists");
}
});
}
diff --git a/daemon/fw/strategy.hpp b/daemon/fw/strategy.hpp
index 285e1a8..5e99d6a 100644
--- a/daemon/fw/strategy.hpp
+++ b/daemon/fw/strategy.hpp
@@ -1,6 +1,6 @@
/* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
/*
- * Copyright (c) 2014-2022, Regents of the University of California,
+ * Copyright (c) 2014-2023, Regents of the University of California,
* Arizona Board of Regents,
* Colorado State University,
* University Pierre & Marie Curie, Sorbonne University,
@@ -490,9 +490,10 @@
} // namespace nfd::fw
-/** \brief Registers a strategy
+/**
+ * \brief Registers a forwarding strategy.
*
- * This macro should appear once in .cpp of each strategy.
+ * This macro should appear once in the `.cpp` of each strategy.
*/
#define NFD_REGISTER_STRATEGY(S) \
static class NfdAuto ## S ## StrategyRegistrationClass \
@@ -504,4 +505,25 @@
} \
} g_nfdAuto ## S ## StrategyRegistrationVariable
+/// Logs the reception of \p interest on \p ingress, followed by \p msg, at DEBUG level.
+#define NFD_LOG_INTEREST_FROM(interest, ingress, msg) \
+ NFD_LOG_DEBUG("interest=" << (interest).getName() << \
+ " nonce=" << (interest).getNonce() << \
+ " from=" << (ingress) << \
+ ' ' << msg)
+
+/// Logs the reception of \p data on \p ingress, followed by \p msg, at DEBUG level.
+#define NFD_LOG_DATA_FROM(data, ingress, msg) \
+ NFD_LOG_DEBUG("data=" << (data).getName() << \
+ " from=" << (ingress) << \
+ ' ' << msg)
+
+/// Logs the reception of \p nack on \p ingress, followed by \p msg, at DEBUG level.
+#define NFD_LOG_NACK_FROM(nack, ingress, msg) \
+ NFD_LOG_DEBUG("nack=" << (nack).getInterest().getName() << \
+ " nonce=" << (nack).getInterest().getNonce() << \
+ " reason=" << (nack).getReason() << \
+ " from=" << (ingress) << \
+ ' ' << msg)
+
#endif // NFD_DAEMON_FW_STRATEGY_HPP