Merge "Setup the update-sender with its own trace buffer" into R2.22.x

src/ifmap/ifmap_log.cc

@@ -20,6 +20,11 @@ SandeshTraceBufferPtr IFMapPeerTraceBuf(
 SandeshTraceBufferPtr IFMapSmTraceBuf(
     SandeshTraceBufferCreate("IFMapSmTraceBuf", 50000));
 
+// Trace buffer for update-sender messages
+SandeshTraceBufferPtr IFMapUpdateSenderBuf(
+    SandeshTraceBufferCreate("IFMapUpdateSenderBuf", 50000));
+
 // Trace buffer for xmpp messages
 SandeshTraceBufferPtr IFMapXmppTraceBuf(
     SandeshTraceBufferCreate("IFMapXmppTraceBuf", 50000));
+

src/ifmap/ifmap_log.h

@@ -15,6 +15,7 @@ extern SandeshTraceBufferPtr IFMapTraceBuf;
 extern SandeshTraceBufferPtr IFMapBigMsgTraceBuf;
 extern SandeshTraceBufferPtr IFMapPeerTraceBuf;
 extern SandeshTraceBufferPtr IFMapSmTraceBuf;
+extern SandeshTraceBufferPtr IFMapUpdateSenderBuf;
 extern SandeshTraceBufferPtr IFMapXmppTraceBuf;
 
 // Log and trace regular messages
@@ -84,6 +85,13 @@ do { \
     IFMAP_SM_TRACE(obj##Trace, __VA_ARGS__); \
 } while(0)
 
+#define IFMAP_UPD_SENDER_TRACE(obj, ...) \
+do { \
+    if (!LoggingDisabled()) { \
+        obj::TraceMsg(IFMapUpdateSenderBuf, __FILE__, __LINE__, __VA_ARGS__); \
+    } \
+} while(0)
+
 // Log and trace big-sized messages
 
 #define IFMAP_DEBUG_LOG_BIG_MSG(obj, category, ...) \

src/ifmap/ifmap_log.sandesh

@@ -392,3 +392,60 @@ trace sandesh IFMapXmlLoadErrorTrace {
     2: u32 length
 }
 
+trace sandesh IFMapUSSplitBlocked {
+    1: string message1
+    2: string blocked_set
+    3: string message2
+    4: string marker
+}
+
+trace sandesh IFMapUSAllBlocked {
+    1: string marker
+    2: string message
+    3: string entry
+}
+
+trace sandesh IFMapUSSubsetBlocked {
+    1: string message1
+    2: string blocked_clients
+    3: string message2
+    4: string entry
+    5: string message3
+    6: string marker
+}
+
+trace sandesh IFMapUSMoveAfterLast {
+    1: string message1
+    2: string marker
+    3: string message2
+    4: string entry
+    5: string message3
+    6: string blocked_set
+}
+
+trace sandesh IFMapUSMarkerMerge {
+    1: string message1
+    2: string marker1
+    3: string message2
+    4: string marker2
+}
+
+trace sandesh IFMapUSMarkerSplit {
+    1: string message1
+    2: string blocked_set
+    3: string message2
+    4: string marker
+}
+
+trace sandesh IFMapUSSendScheduled {
+    1: string message1
+    2: string send_scheduled
+    3: string message2
+    4: u32 client
+    5: string marker
+}
+
+trace sandesh IFMapUSQueueActive {
+    1: string message
+    2: string clients
+}

src/ifmap/ifmap_update.cc

@@ -53,8 +53,7 @@ std::string IFMapUpdate::ConfigName() {
 }
 
 std::string IFMapUpdate::ToString() {
-    std::string name = ConfigName();
-    return TypeToString() + " of " + name;
+    return TypeToString() + ":" + ConfigName();
 }
 
 void IFMapUpdate::AdvertiseReset(const BitSet &set) {
@@ -73,6 +72,10 @@ IFMapMarker::IFMapMarker()
     : IFMapListEntry(MARKER) {
 }
 
+std::string IFMapMarker::ToString() {
+    return std::string("Marker:") + mask.ToNumberedString();
+}
+
 IFMapState::IFMapState(IFMapNode *node)
     : sig_(kInvalidSig), data_(node), crc_(0) {
 }

src/ifmap/ifmap_update.h

@@ -51,12 +51,16 @@ struct IFMapListEntry {
     };
     IFMapListEntry(EntryType type) :
         type(type), queue_insert_at(0), sequence(0) { }
+    virtual ~IFMapListEntry() { }
 
     boost::intrusive::list_member_hook<> node;
     EntryType type;
     uint64_t queue_insert_at;
     uint64_t sequence;
 
+    virtual std::string ToString() {
+        return std::string("To implement");
+    }
     bool IsMarker() const { return ((type == MARKER) ? true : false); }
     bool IsUpdate() const { return ((type == UPDATE) ? true : false); }
     bool IsDelete() const { return ((type == DELETE) ? true : false); }
@@ -82,6 +86,7 @@ class IFMapUpdate : public IFMapListEntry {
 public:
     IFMapUpdate(IFMapNode *node, bool positive);
     IFMapUpdate(IFMapLink *link, bool positive);
+    virtual ~IFMapUpdate() { }
 
     void AdvertiseReset(const BitSet &set);
     void AdvertiseOr(const BitSet &set);
@@ -90,7 +95,7 @@ class IFMapUpdate : public IFMapListEntry {
 
     const IFMapObjectPtr &data() const { return data_; }
     std::string ConfigName();
-    std::string ToString();
+    virtual std::string ToString();
     bool IsNode() const { return data_.IsNode(); }
     bool IsLink() const { return data_.IsLink(); }
 
@@ -103,6 +108,8 @@ class IFMapUpdate : public IFMapListEntry {
 
 struct IFMapMarker : public IFMapListEntry {
     IFMapMarker();
+    virtual ~IFMapMarker() { }
+    virtual std::string ToString();
     BitSet mask;
 };
 

src/ifmap/ifmap_update_sender.cc

@@ -38,11 +38,16 @@ class IFMapUpdateSender::SendTask : public Task {
         for (size_t i = send_scheduled.find_first(); i != BitSet::npos;
              i = send_scheduled.find_next(i)) {
             // Dequeue from client marker (i).
+            IFMAP_UPD_SENDER_TRACE(IFMapUSSendScheduled, "Send scheduled for",
+                send_scheduled.ToNumberedString(), "client", i,
+                sender_->queue_->GetMarker(i)->ToString());
             sender_->Send(sender_->queue_->GetMarker(i));
         }
         if (sender_->queue_active_) {
             // Dequeue from tail marker.
             // Reset queue_active_
+            IFMAP_UPD_SENDER_TRACE(IFMapUSQueueActive, "Queue active for",
+                sender_->queue_->tail_marker()->ToString());
             sender_->Send(sender_->queue_->tail_marker());
             sender_->queue_active_ = false;
         }
@@ -113,6 +118,8 @@ void IFMapUpdateSender::Send(IFMapMarker *imarker) {
     // blocked clients, insert it before marker and continue with the ready
     // set.
     if (!blocked_clients.empty()) {
+        IFMAP_UPD_SENDER_TRACE(IFMapUSSplitBlocked, "Splitting blocked clients",
+            blocked_clients.ToNumberedString(), "from", marker->ToString());
         queue_->MarkerSplitBefore(marker, marker, blocked_clients);
     }
 
@@ -169,13 +176,18 @@ void IFMapUpdateSender::Send(IFMapMarker *imarker) {
             if (!blocked_set.empty()) {
                 // All the clients in this marker are blocked. We are done.
                 if (blocked_set == marker->mask) {
+                    IFMAP_UPD_SENDER_TRACE(IFMapUSAllBlocked, marker->ToString(),
+                        "blocked before", curr->ToString());
                     queue_->MoveMarkerBefore(marker, curr);
                     return;
                 }
                 // Only a subset of clients in this marker are blocked. Insert
                 // a marker for them 'before' curr since they have seen
                 // everything before curr. Let the ready clients continue the
                 // traversal.
+                IFMAP_UPD_SENDER_TRACE(IFMapUSSubsetBlocked, "Clients",
+                    blocked_set.ToNumberedString(), "blocked before",
+                    curr->ToString(), "and split from", marker->ToString());
                 queue_->MarkerSplitBefore(marker, curr, blocked_set);
                 send_set.Reset(blocked_set);
             }
@@ -190,8 +202,8 @@ void IFMapUpdateSender::Send(IFMapMarker *imarker) {
 
     // The buffer will be filled in the common case of updates being added
     // after the tail_marker.
+    BitSet blk_set;
     if (!message_->IsEmpty()) {
-        BitSet blk_set;
         SendUpdate(base_send_set, &blk_set);
     }
     // If the last node in the Q was the tail_marker, we would have already
@@ -207,6 +219,9 @@ void IFMapUpdateSender::Send(IFMapMarker *imarker) {
         // is advantageous since by the time we get the next trigger, a blocked
         // client could have become ready and splitting the marker now would be
         // useless.
+        IFMAP_UPD_SENDER_TRACE(IFMapUSMoveAfterLast, "Moving", marker->ToString(),
+            "before", last->ToString(), "with blocked_set",
+            blk_set.ToNumberedString());
         queue_->MoveMarkerAfter(marker, last);
     }
     return;
@@ -279,6 +294,8 @@ IFMapMarker* IFMapUpdateSender::ProcessMarker(IFMapMarker *marker,
     // If all the clients are ready or all are blocked, merge marker into
     // next_marker. marker will be deleted.
     if (blocked_set.empty() || ready_set.empty()) {
+        IFMAP_UPD_SENDER_TRACE(IFMapUSMarkerMerge, "Merging", marker->ToString(),
+            "into", next_marker->ToString());
         queue_->MarkerMerge(next_marker, marker, marker->mask);
         assert(next_marker->mask == total_set);
     } else {
@@ -287,8 +304,12 @@ IFMapMarker* IFMapUpdateSender::ProcessMarker(IFMapMarker *marker,
         // split next_marker into 2 markers: first with the blocked_set and the
         // second with the ready_set, with first(blocked) preceding the
         // second(ready).
+        IFMAP_UPD_SENDER_TRACE(IFMapUSMarkerMerge, "Merging", marker->ToString(),
+            "into", next_marker->ToString());
         queue_->MarkerMerge(next_marker, marker, marker->mask);
         assert(next_marker->mask == total_set);
+        IFMAP_UPD_SENDER_TRACE(IFMapUSMarkerSplit, "Splitting blocked clients",
+            blocked_set.ToNumberedString(), "from", next_marker->ToString());
         queue_->MarkerSplitBefore(next_marker, next_marker, blocked_set);
     }
     if (ready_set.empty()) {