MB-20852 [14/N]: Improve debug/logging in CheckpointManager 21/69021/8
authorDave Rigby <daver@couchbase.com>
Thu, 20 Oct 2016 13:58:01 +0000 (14:58 +0100)
committerDave Rigby <daver@couchbase.com>
Tue, 1 Nov 2016 07:56:54 +0000 (07:56 +0000)
Include information on the CheckpointCursors associated with a
CheckpointManager by adding a operator<< for CheckpointCursor. Add a
dump() method to CheckpointManager to assist in debugging their
contents (e.g. from gdb).

Also add some additional CheckpointManager/CouchKVStore logging.

Change-Id: I8c3de5b5ec0e8e297db8530dee87ac0edd869a91
Reviewed-on: http://review.couchbase.org/69021
Reviewed-by: Trond Norbye <trond.norbye@gmail.com>
Tested-by: buildbot <build@couchbase.com>
src/checkpoint.cc
src/checkpoint.h
src/couch-kvstore/couch-kvstore.cc

index ea5b5e5..689abb7 100644 (file)
@@ -92,6 +92,16 @@ MustSendCheckpointEnd CheckpointCursor::shouldSendCheckpointEndMetaItem() const
     return sendCheckpointEndMetaItem;
 }
 
+std::ostream& operator<<(std::ostream& os, const CheckpointCursor& c) {
+    os << "CheckpointCursor[" << &c << "] with"
+       << " name:" << c.name
+       << " currentCkpt:{id:" << (*c.currentCheckpoint)->getId()
+       << " state:" << to_string((*c.currentCheckpoint)->getState())
+       << "} currentPos:" << (*c.currentPos)->getBySeqno()
+       << " offset:" << c.offset.load();
+    return os;
+}
+
 Checkpoint::~Checkpoint() {
     LOG(EXTENSION_LOG_INFO,
         "Checkpoint %" PRIu64 " for vbucket %d is purged from memory",
@@ -315,7 +325,8 @@ std::ostream& operator <<(std::ostream& os, const Checkpoint& c) {
        << " items:[" << std::endl;
     for (const auto& e : c.toWrite) {
         os << "\t{" << e->getBySeqno() << ","
-           << to_string(e->getOperation()) << "}" << std::endl;
+           << to_string(e->getOperation()) << ","
+           << e->getKey() << "}" << std::endl;
     }
     os << "]";
     return os;
@@ -1099,6 +1110,10 @@ snapshot_range_t CheckpointManager::getAllItemsForCursor(
         range.end = (*it->second.currentCheckpoint)->getSnapshotEndSeqno();
     }
 
+    LOG(EXTENSION_LOG_DEBUG, "CheckpointManager::getAllItemsForCursor() "
+            "cursor:%s range:{%" PRIu64 ", %" PRIu64 "}",
+            name.c_str(), range.start, range.end);
+
     return range;
 }
 
@@ -1147,6 +1162,10 @@ bool CheckpointManager::incrCursor(CheckpointCursor &cursor) {
     return incrCursor(cursor);
 }
 
+void CheckpointManager::dump() const {
+    std::cerr << *this << std::endl;
+}
+
 void CheckpointManager::clear(RCPtr<VBucket> &vb, uint64_t seqno) {
     LockHolder lh(queueLock);
     clear_UNLOCKED(vb->getState(), seqno);
@@ -1844,10 +1863,16 @@ void CheckpointManager::addStats(ADD_STAT add_stat, const void *cookie) {
 }
 
 std::ostream& operator <<(std::ostream& os, const CheckpointManager& m) {
-    os << "CheckpointManager[" << &m << "] with "
-       << m.getNumCheckpoints() << " checkpoints, " << m.getNumItems() << " items." << std::endl;
-    for (auto* c : m.checkpointList) {
+    os << "CheckpointManager[" << &m << "] with numItems:"
+       << m.getNumItems() << " checkpoints:" << m.checkpointList.size()
+       << std::endl;
+    for (const auto* c : m.checkpointList) {
         os << "    " << *c << std::endl;
     }
+    os << "    connCursors:[" << std::endl;
+    for (const auto cur : m.connCursors) {
+        os << "        " << cur.first << ": " << cur.second << std::endl;
+    }
+    os << "    ]" << std::endl;
     return os;
 }
index af4ddd1..7ee84aa 100644 (file)
@@ -189,8 +189,12 @@ private:
     AtomicValue<size_t>              offset;
     bool                             fromBeginningOnChkCollapse;
     MustSendCheckpointEnd            sendCheckpointEndMetaItem;
+
+    friend std::ostream& operator<<(std::ostream& os, const CheckpointCursor& c);
 };
 
+std::ostream& operator<<(std::ostream& os, const CheckpointCursor& c);
+
 /**
  * The cursor index maps checkpoint cursor names to checkpoint cursors
  */
@@ -799,6 +803,8 @@ public:
         return ++lastBySeqno;
     }
 
+    void dump() const;
+
     static const std::string pCursorName;
 
 private:
index eed31ae..da7aa54 100644 (file)
@@ -935,6 +935,11 @@ bool CouchKVStore::snapshotVBucket(uint16_t vbucketId,
         }
     }
 
+    LOG(EXTENSION_LOG_DEBUG,
+        "CouchKVStore::snapshotVBucket: Snapshotted vbucket:%" PRIu16 " state:%s",
+        vbucketId,
+        vbstate.toJSON().c_str());
+
     st.snapshotHisto.add((gethrtime() - start) / 1000);
 
     return true;