From 7aa31ecd5c4cee5604eb6b3c57faf3dce8b13ad1 Mon Sep 17 00:00:00 2001 From: Tom Henderson Date: Sat, 8 Apr 2017 22:31:01 -0700 Subject: [PATCH] mesh: Improve logging --- src/mesh/model/dot11s/hwmp-protocol-mac.cc | 25 ++++++++++---- src/mesh/model/dot11s/hwmp-protocol.cc | 39 +++++++++++++++++++--- src/mesh/model/dot11s/hwmp-rtable.cc | 14 ++++++++ 3 files changed, 67 insertions(+), 11 deletions(-) diff --git a/src/mesh/model/dot11s/hwmp-protocol-mac.cc b/src/mesh/model/dot11s/hwmp-protocol-mac.cc index 90b62a2b5..c2feb0b1f 100644 --- a/src/mesh/model/dot11s/hwmp-protocol-mac.cc +++ b/src/mesh/model/dot11s/hwmp-protocol-mac.cc @@ -41,6 +41,7 @@ namespace dot11s { HwmpProtocolMac::HwmpProtocolMac (uint32_t ifIndex, Ptr protocol) : m_ifIndex (ifIndex), m_protocol (protocol) { + NS_LOG_FUNCTION (this << ifIndex << protocol); } HwmpProtocolMac::~HwmpProtocolMac () { @@ -48,12 +49,14 @@ HwmpProtocolMac::~HwmpProtocolMac () void HwmpProtocolMac::SetParent (Ptr parent) { + NS_LOG_FUNCTION (this << parent); m_parent = parent; } bool HwmpProtocolMac::ReceiveData (Ptr packet, const WifiMacHeader & header) { + NS_LOG_FUNCTION (this << packet << header); NS_ASSERT (header.IsData ()); MeshHeader meshHdr; @@ -95,6 +98,7 @@ HwmpProtocolMac::ReceiveData (Ptr packet, const WifiMacHeader & header) bool HwmpProtocolMac::ReceiveAction (Ptr packet, const WifiMacHeader & header) { + NS_LOG_FUNCTION (this << packet << header); m_stats.rxMgt++; m_stats.rxMgtBytes += packet->GetSize (); WifiActionHeader actionHdr; @@ -166,6 +170,7 @@ HwmpProtocolMac::ReceiveAction (Ptr packet, const WifiMacHeader & header bool HwmpProtocolMac::Receive (Ptr packet, const WifiMacHeader & header) { + NS_LOG_FUNCTION (this << packet << header); if (header.IsData ()) { return ReceiveData (packet, header); @@ -186,6 +191,7 @@ bool HwmpProtocolMac::UpdateOutcomingFrame (Ptr packet, WifiMacHeader & header, Mac48Address from, Mac48Address to) { + NS_LOG_FUNCTION (this << packet << header << from << to); if (!header.IsData ()) { return true; @@ -218,7 +224,7 @@ HwmpProtocolMac::GetWifiActionHeader () void HwmpProtocolMac::SendPreq (IePreq preq) { - NS_LOG_FUNCTION_NOARGS (); + NS_LOG_FUNCTION (this); std::vector preq_vector; preq_vector.push_back (preq); SendPreq (preq_vector); @@ -226,6 +232,7 @@ HwmpProtocolMac::SendPreq (IePreq preq) void HwmpProtocolMac::SendPreq (std::vector preq) { + NS_LOG_FUNCTION (this); Ptr packet = Create (); MeshInformationElementVector elements; for (std::vector::iterator i = preq.begin (); i != preq.end (); i++) @@ -255,7 +262,7 @@ HwmpProtocolMac::SendPreq (std::vector preq) void HwmpProtocolMac::RequestDestination (Mac48Address dst, uint32_t originator_seqno, uint32_t dst_seqno) { - NS_LOG_FUNCTION_NOARGS (); + NS_LOG_FUNCTION (this << dst << originator_seqno << dst_seqno); for (std::vector::iterator i = m_myPreq.begin (); i != m_myPreq.end (); i++) { if (i->IsFull ()) @@ -279,7 +286,7 @@ HwmpProtocolMac::RequestDestination (Mac48Address dst, uint32_t originator_seqno void HwmpProtocolMac::SendMyPreq () { - NS_LOG_FUNCTION_NOARGS (); + NS_LOG_FUNCTION (this); if (m_preqTimer.IsRunning ()) { return; @@ -297,7 +304,7 @@ HwmpProtocolMac::SendMyPreq () void HwmpProtocolMac::SendPrep (IePrep prep, Mac48Address receiver) { - NS_LOG_FUNCTION_NOARGS (); + NS_LOG_FUNCTION (this << receiver); //Create packet Ptr packet = Create (); MeshInformationElementVector elements; @@ -322,7 +329,7 @@ void HwmpProtocolMac::ForwardPerr (std::vector failedDestinations, std::vector< Mac48Address> receivers) { - NS_LOG_FUNCTION_NOARGS (); + NS_LOG_FUNCTION (this); Ptr packet = Create (); Ptr perr = Create (); MeshInformationElementVector elements; @@ -376,8 +383,9 @@ void HwmpProtocolMac::InitiatePerr (std::vector failedDestinations, std::vector< Mac48Address> receivers) { + NS_LOG_FUNCTION (this); //All duplicates in PERR are checked here, and there is no reason to - //check it at any athoer place + //check it at any other place { std::vector::const_iterator end = receivers.end (); for (std::vector::const_iterator i = receivers.begin (); i != end; i++) @@ -394,6 +402,7 @@ HwmpProtocolMac::InitiatePerr (std::vector fail if (should_add) { m_myPerr.receivers.push_back (*i); + NS_LOG_DEBUG ("Initiate PERR: Adding receiver: " << (*i)); } } } @@ -413,6 +422,7 @@ HwmpProtocolMac::InitiatePerr (std::vector fail if (should_add) { m_myPerr.destinations.push_back (*i); + NS_LOG_DEBUG ("Initiate PERR: Adding failed destination: " << (*i).destination); } } } @@ -421,7 +431,7 @@ HwmpProtocolMac::InitiatePerr (std::vector fail void HwmpProtocolMac::SendMyPerr () { - NS_LOG_FUNCTION_NOARGS (); + NS_LOG_FUNCTION (this); if (m_perrTimer.IsRunning ()) { return; @@ -476,6 +486,7 @@ HwmpProtocolMac::Report (std::ostream & os) const void HwmpProtocolMac::ResetStats () { + NS_LOG_FUNCTION (this); m_stats = Statistics (); } diff --git a/src/mesh/model/dot11s/hwmp-protocol.cc b/src/mesh/model/dot11s/hwmp-protocol.cc index d072e6d8d..cd54f3663 100644 --- a/src/mesh/model/dot11s/hwmp-protocol.cc +++ b/src/mesh/model/dot11s/hwmp-protocol.cc @@ -195,18 +195,19 @@ HwmpProtocol::HwmpProtocol () : m_doFlag (false), m_rfFlag (false) { - NS_LOG_FUNCTION_NOARGS (); + NS_LOG_FUNCTION (this); m_coefficient = CreateObject (); } HwmpProtocol::~HwmpProtocol () { - NS_LOG_FUNCTION_NOARGS (); + NS_LOG_FUNCTION (this); } void HwmpProtocol::DoInitialize () { + NS_LOG_FUNCTION (this); m_coefficient->SetAttribute ("Max", DoubleValue (m_randomStart.GetSeconds ())); if (m_isRoot) { @@ -218,7 +219,7 @@ HwmpProtocol::DoInitialize () void HwmpProtocol::DoDispose () { - NS_LOG_FUNCTION_NOARGS (); + NS_LOG_FUNCTION (this); for (std::map::iterator i = m_preqTimeouts.begin (); i != m_preqTimeouts.end (); i++) { i->second.preqTimeout.Cancel (); @@ -243,6 +244,7 @@ HwmpProtocol::RequestRoute ( MeshL2RoutingProtocol::RouteReplyCallback routeReply ) { + NS_LOG_FUNCTION (this << sourceIface << source << destination << constPacket << protocolType); Ptr packet = constPacket->Copy (); HwmpTag tag; if (sourceIface == GetMeshPoint ()->GetIfIndex ()) @@ -329,6 +331,7 @@ bool HwmpProtocol::ForwardUnicast (uint32_t sourceIface, const Mac48Address source, const Mac48Address destination, Ptr packet, uint16_t protocolType, RouteReplyCallback routeReply, uint32_t ttl) { + NS_LOG_FUNCTION (this << sourceIface << source << destination << packet << protocolType << ttl); NS_ASSERT (destination != Mac48Address::GetBroadcast ()); HwmpRtable::LookupResult result = m_rtable->LookupReactive (destination); NS_LOG_DEBUG ("Requested src = "<LookupReactiveExpired (destination); + NS_LOG_DEBUG ("Path error " << result.retransmitter); //1. Lookup expired reactive path. If exists - start path error // procedure towards a next hop of this path //2. If there was no reactive path, we lookup expired proactive @@ -361,10 +365,12 @@ HwmpProtocol::ForwardUnicast (uint32_t sourceIface, const Mac48Address source, // root if (result.retransmitter == Mac48Address::GetBroadcast ()) { + NS_LOG_DEBUG ("Path error, lookup expired proactive path"); result = m_rtable->LookupProactiveExpired (); } if (result.retransmitter != Mac48Address::GetBroadcast ()) { + NS_LOG_DEBUG ("Path error, initiate reactive path error"); std::vector destinations = m_rtable->GetUnreachableDestinations (result.retransmitter); InitiatePathError (MakePathError (destinations)); } @@ -402,12 +408,14 @@ HwmpProtocol::ForwardUnicast (uint32_t sourceIface, const Mac48Address source, else { m_stats.totalDropped++; + NS_LOG_DEBUG ("Dropping packet from " << source << " to " << destination << " due to queue overflow"); return false; } } void HwmpProtocol::ReceivePreq (IePreq preq, Mac48Address from, uint32_t interface, Mac48Address fromMp, uint32_t metric) { + NS_LOG_FUNCTION (this << from << interface << fromMp << metric); preq.IncrementMetric (metric); //acceptance cretirea: std::map >::const_iterator i = m_hwmpSeqnoMetricDatabase.find ( @@ -430,7 +438,7 @@ HwmpProtocol::ReceivePreq (IePreq preq, Mac48Address from, uint32_t interface, M } m_hwmpSeqnoMetricDatabase[preq.GetOriginatorAddress ()] = std::make_pair (preq.GetOriginatorSeqNumber (), preq.GetMetric ()); - NS_LOG_DEBUG ("I am " << GetAddress () << "Accepted preq from address" << from << ", preq:" << preq); + NS_LOG_DEBUG ("I am " << GetAddress () << ", Accepted preq from address" << from << ", preq:" << preq); std::vector > destinations = preq.GetDestinationList (); //Add reactive path to originator: if ( @@ -571,6 +579,7 @@ HwmpProtocol::ReceivePreq (IePreq preq, Mac48Address from, uint32_t interface, M void HwmpProtocol::ReceivePrep (IePrep prep, Mac48Address from, uint32_t interface, Mac48Address fromMp, uint32_t metric) { + NS_LOG_FUNCTION (this << from << interface << fromMp << metric); prep.IncrementMetric (metric); //acceptance cretirea: std::map >::const_iterator i = m_hwmpSeqnoMetricDatabase.find ( @@ -650,6 +659,7 @@ HwmpProtocol::ReceivePrep (IePrep prep, Mac48Address from, uint32_t interface, M void HwmpProtocol::ReceivePerr (std::vector destinations, Mac48Address from, uint32_t interface, Mac48Address fromMp) { + NS_LOG_FUNCTION (this << from << interface << fromMp); //Acceptance cretirea: NS_LOG_DEBUG ("I am "< retval; @@ -700,6 +710,7 @@ HwmpProtocol::SendPrep ( bool HwmpProtocol::Install (Ptr mp) { + NS_LOG_FUNCTION (this << mp); m_mp = mp; std::vector > interfaces = mp->GetInterfaces (); for (std::vector >::const_iterator i = interfaces.begin (); i != interfaces.end (); i++) @@ -732,11 +743,13 @@ HwmpProtocol::Install (Ptr mp) void HwmpProtocol::PeerLinkStatus (Mac48Address meshPointAddress, Mac48Address peerAddress, uint32_t interface, bool status) { + NS_LOG_FUNCTION (this << meshPointAddress << peerAddress << interface << status); if (status) { return; } std::vector destinations = m_rtable->GetUnreachableDestinations (peerAddress); + NS_LOG_DEBUG (destinations.size () << " failed destinations for peer address " << peerAddress); InitiatePathError (MakePathError (destinations)); } void @@ -747,6 +760,7 @@ HwmpProtocol::SetNeighboursCallback (Callback, uint32_ bool HwmpProtocol::DropDataFrame (uint32_t seqno, Mac48Address source) { + NS_LOG_FUNCTION (this << seqno << source); if (source == GetAddress ()) { return true; @@ -769,6 +783,7 @@ HwmpProtocol::DropDataFrame (uint32_t seqno, Mac48Address source) HwmpProtocol::PathError HwmpProtocol::MakePathError (std::vector destinations) { + NS_LOG_FUNCTION (this); PathError retval; //HwmpRtable increments a sequence number as written in 11B.9.7.2 retval.receivers = GetPerrReceivers (destinations); @@ -787,6 +802,7 @@ HwmpProtocol::MakePathError (std::vector destinations) void HwmpProtocol::InitiatePathError (PathError perr) { + NS_LOG_FUNCTION (this); for (HwmpProtocolMacMap::const_iterator i = m_interfaces.begin (); i != m_interfaces.end (); i++) { std::vector receivers_for_interface; @@ -803,6 +819,7 @@ HwmpProtocol::InitiatePathError (PathError perr) void HwmpProtocol::ForwardPathError (PathError perr) { + NS_LOG_FUNCTION (this); for (HwmpProtocolMacMap::const_iterator i = m_interfaces.begin (); i != m_interfaces.end (); i++) { std::vector receivers_for_interface; @@ -820,6 +837,7 @@ HwmpProtocol::ForwardPathError (PathError perr) std::vector > HwmpProtocol::GetPerrReceivers (std::vector failedDest) { + NS_LOG_FUNCTION (this); HwmpRtable::PrecursorList retval; for (unsigned int i = 0; i < failedDest.size (); i++) { @@ -847,6 +865,7 @@ HwmpProtocol::GetPerrReceivers (std::vector failedDest) std::vector HwmpProtocol::GetPreqReceivers (uint32_t interface) { + NS_LOG_FUNCTION (this << interface); std::vector retval; if (!m_neighboursCallback.IsNull ()) { @@ -862,6 +881,7 @@ HwmpProtocol::GetPreqReceivers (uint32_t interface) std::vector HwmpProtocol::GetBroadcastReceivers (uint32_t interface) { + NS_LOG_FUNCTION (this << interface); std::vector retval; if (!m_neighboursCallback.IsNull ()) { @@ -878,6 +898,7 @@ HwmpProtocol::GetBroadcastReceivers (uint32_t interface) bool HwmpProtocol::QueuePacket (QueuedPacket packet) { + NS_LOG_FUNCTION (this); if (m_rqueue.size () > m_maxQueueSize) { return false; @@ -889,6 +910,7 @@ HwmpProtocol::QueuePacket (QueuedPacket packet) HwmpProtocol::QueuedPacket HwmpProtocol::DequeueFirstPacketByDst (Mac48Address dst) { + NS_LOG_FUNCTION (this << dst); QueuedPacket retval; retval.pkt = 0; for (std::vector::iterator i = m_rqueue.begin (); i != m_rqueue.end (); i++) @@ -906,6 +928,7 @@ HwmpProtocol::DequeueFirstPacketByDst (Mac48Address dst) HwmpProtocol::QueuedPacket HwmpProtocol::DequeueFirstPacket () { + NS_LOG_FUNCTION (this); QueuedPacket retval; retval.pkt = 0; if (m_rqueue.size () != 0) @@ -919,6 +942,7 @@ HwmpProtocol::DequeueFirstPacket () void HwmpProtocol::ReactivePathResolved (Mac48Address dst) { + NS_LOG_FUNCTION (this << dst); std::map::iterator i = m_preqTimeouts.find (dst); if (i != m_preqTimeouts.end ()) { @@ -946,6 +970,7 @@ HwmpProtocol::ReactivePathResolved (Mac48Address dst) void HwmpProtocol::ProactivePathResolved () { + NS_LOG_FUNCTION (this); //send all packets to root HwmpRtable::LookupResult result = m_rtable->LookupProactive (); NS_ASSERT (result.retransmitter != Mac48Address::GetBroadcast ()); @@ -971,6 +996,7 @@ HwmpProtocol::ProactivePathResolved () bool HwmpProtocol::ShouldSendPreq (Mac48Address dst) { + NS_LOG_FUNCTION (this << dst); std::map::const_iterator i = m_preqTimeouts.find (dst); if (i == m_preqTimeouts.end ()) { @@ -985,6 +1011,7 @@ HwmpProtocol::ShouldSendPreq (Mac48Address dst) void HwmpProtocol::RetryPathDiscovery (Mac48Address dst, uint8_t numOfRetry) { + NS_LOG_FUNCTION (this << dst << (uint16_t) numOfRetry); HwmpRtable::LookupResult result = m_rtable->LookupReactive (dst); if (result.retransmitter == Mac48Address::GetBroadcast ()) { @@ -1028,17 +1055,20 @@ HwmpProtocol::RetryPathDiscovery (Mac48Address dst, uint8_t numOfRetry) void HwmpProtocol::SetRoot () { + NS_LOG_FUNCTION (this); NS_LOG_DEBUG ("ROOT IS: " << m_address); m_isRoot = true; } void HwmpProtocol::UnsetRoot () { + NS_LOG_FUNCTION (this); m_proactivePreqTimer.Cancel (); } void HwmpProtocol::SendProactivePreq () { + NS_LOG_FUNCTION (this); IePreq preq; //By default: must answer preq.SetHopcount (0); @@ -1165,6 +1195,7 @@ HwmpProtocol::Report (std::ostream & os) const void HwmpProtocol::ResetStats () { + NS_LOG_FUNCTION (this); m_stats = Statistics (); for (HwmpProtocolMacMap::const_iterator plugin = m_interfaces.begin (); plugin != m_interfaces.end (); plugin++) { diff --git a/src/mesh/model/dot11s/hwmp-rtable.cc b/src/mesh/model/dot11s/hwmp-rtable.cc index b66d60d29..43cf34afd 100644 --- a/src/mesh/model/dot11s/hwmp-rtable.cc +++ b/src/mesh/model/dot11s/hwmp-rtable.cc @@ -59,6 +59,7 @@ void HwmpRtable::AddReactivePath (Mac48Address destination, Mac48Address retransmitter, uint32_t interface, uint32_t metric, Time lifetime, uint32_t seqnum) { + NS_LOG_FUNCTION (this << destination << retransmitter << interface << metric << lifetime.GetSeconds () << seqnum); std::map::iterator i = m_routes.find (destination); if (i == m_routes.end ()) { @@ -77,6 +78,7 @@ void HwmpRtable::AddProactivePath (uint32_t metric, Mac48Address root, Mac48Address retransmitter, uint32_t interface, Time lifetime, uint32_t seqnum) { + NS_LOG_FUNCTION (this << metric << root << retransmitter << interface << lifetime << seqnum); m_root.root = root; m_root.retransmitter = retransmitter; m_root.metric = metric; @@ -88,6 +90,7 @@ void HwmpRtable::AddPrecursor (Mac48Address destination, uint32_t precursorInterface, Mac48Address precursorAddress, Time lifetime) { + NS_LOG_FUNCTION (this << destination << precursorInterface << precursorAddress << lifetime); Precursor precursor; precursor.interface = precursorInterface; precursor.address = precursorAddress; @@ -116,6 +119,7 @@ HwmpRtable::AddPrecursor (Mac48Address destination, uint32_t precursorInterface, void HwmpRtable::DeleteProactivePath () { + NS_LOG_FUNCTION (this); m_root.precursors.clear (); m_root.interface = INTERFACE_ANY; m_root.metric = MAX_METRIC; @@ -126,6 +130,7 @@ HwmpRtable::DeleteProactivePath () void HwmpRtable::DeleteProactivePath (Mac48Address root) { + NS_LOG_FUNCTION (this << root); if (m_root.root == root) { DeleteProactivePath (); @@ -134,6 +139,7 @@ HwmpRtable::DeleteProactivePath (Mac48Address root) void HwmpRtable::DeleteReactivePath (Mac48Address destination) { + NS_LOG_FUNCTION (this << destination); std::map::iterator i = m_routes.find (destination); if (i != m_routes.end ()) { @@ -143,6 +149,7 @@ HwmpRtable::DeleteReactivePath (Mac48Address destination) HwmpRtable::LookupResult HwmpRtable::LookupReactive (Mac48Address destination) { + NS_LOG_FUNCTION (this << destination); std::map::iterator i = m_routes.find (destination); if (i == m_routes.end ()) { @@ -158,17 +165,20 @@ HwmpRtable::LookupReactive (Mac48Address destination) HwmpRtable::LookupResult HwmpRtable::LookupReactiveExpired (Mac48Address destination) { + NS_LOG_FUNCTION (this << destination); std::map::iterator i = m_routes.find (destination); if (i == m_routes.end ()) { return LookupResult (); } + NS_LOG_DEBUG ("Returning reactive route to " << destination); return LookupResult (i->second.retransmitter, i->second.interface, i->second.metric, i->second.seqnum, i->second.whenExpire - Simulator::Now ()); } HwmpRtable::LookupResult HwmpRtable::LookupProactive () { + NS_LOG_FUNCTION (this); if (m_root.whenExpire < Simulator::Now ()) { NS_LOG_DEBUG ("Proactive route has expired and will be deleted, sorry."); @@ -179,12 +189,15 @@ HwmpRtable::LookupProactive () HwmpRtable::LookupResult HwmpRtable::LookupProactiveExpired () { + NS_LOG_FUNCTION (this); + NS_LOG_DEBUG ("Returning proactive route to root"); return LookupResult (m_root.retransmitter, m_root.interface, m_root.metric, m_root.seqnum, m_root.whenExpire - Simulator::Now ()); } std::vector HwmpRtable::GetUnreachableDestinations (Mac48Address peerAddress) { + NS_LOG_FUNCTION (this << peerAddress); HwmpProtocol::FailedDestination dst; std::vector retval; for (std::map::iterator i = m_routes.begin (); i != m_routes.end (); i++) @@ -209,6 +222,7 @@ HwmpRtable::GetUnreachableDestinations (Mac48Address peerAddress) HwmpRtable::PrecursorList HwmpRtable::GetPrecursors (Mac48Address destination) { + NS_LOG_FUNCTION (this << destination); //We suppose that no duplicates here can be PrecursorList retval; std::map::iterator route = m_routes.find (destination);