MB-44697: Move collection logging from vbucket to bucket

Add create/drop logging to Manifest::isSuccessor which is a function used by every manifest change, and is "bucket" only. Change vbucket messages from INFO to DEBUG except for modifyScope which is new code in neo. Change-Id: I269baaac9ee1221187bb80f3a86bae070d6aed04 Reviewed-on: https://review.couchbase.org/c/kv_engine/+/167015 Tested-by: Build Bot <build@couchbase.com> Reviewed-by: Dave Rigby <daver@couchbase.com>
couchbase · Dec 7, 2021 · b36b531 · b36b531
1 parent 5824557
commit b36b531
Show file tree

Hide file tree

Showing 2 changed files with 66 additions and 21 deletions.
diff --git a/engines/ep/src/collections/manifest.cc b/engines/ep/src/collections/manifest.cc
@@ -683,6 +683,40 @@ cb::engine_error Manifest::isSuccessor(const Manifest& successor) const {
     // else must be a > uid and any changes must be valid or equal uid with no
     // changes
     if (successor.getUid() > uid) {
+        // Log scope creations
+        for (auto itr = successor.beginScopes(); itr != successor.endScopes();
+             ++itr) {
+            if (scopes.count(itr->first) == 0) {
+                EP_LOG_INFO("create scope:id:{}, name:{}, manifest:{:#x}{}",
+                            itr->first,
+                            itr->second.name,
+                            successor.getUid(),
+                            itr->second.dataLimit
+                                    ? fmt::format(", limit:{}",
+                                                  itr->second.dataLimit.value())
+                                    : "");
+            }
+        }
+
+        // Log creations
+        for (auto itr = successor.begin(); itr != successor.end(); ++itr) {
+            if (collections.count(itr->first) == 0) {
+                EP_LOG_INFO(
+                        "create collection:id:{}, name:{}, scope:{}, "
+                        "manifest:{:#x}{}",
+                        itr->first,
+                        itr->second.name,
+                        itr->second.sid,
+                        successor.getUid(),
+                        itr->second.maxTtl.has_value()
+                                ? ", maxttl:" +
+                                          std::to_string(
+                                                  itr->second.maxTtl.value()
+                                                          .count())
+                                : "");
+            }
+        }
+
         // For each scope-id in this is it in successor?
         for (const auto& [sid, scope] : scopes) {
             auto itr = successor.findScope(sid);
@@ -696,7 +730,11 @@ cb::engine_error Manifest::isSuccessor(const Manifest& successor) const {
                                     ", name:" + scope.name +
                                     ", new-name:" + itr->second.name);
                 }
-            } // else this sid has been removed and that's fine
+            } else {
+                EP_LOG_INFO("drop scope:id:{}, manifest:{:#x}",
+                            sid,
+                            successor.getUid());
+            }
         }
 
         // For each collection in this is it in successor?
@@ -734,7 +772,12 @@ cb::engine_error Manifest::isSuccessor(const Manifest& successor) const {
                                                                     seconds{0})
                                                     .count()));
                 }
-            } // else this cid has been removed and that's fine
+            } else {
+                EP_LOG_INFO("drop collection:id:{}, scope:{}, manifest:{:#x}",
+                            cid,
+                            collection.sid,
+                            successor.getUid());
+            }
         }
     } else if (uid == successor.getUid()) {
         if (*this != successor) {

diff --git a/engines/ep/src/collections/vbucket_manifest.cc b/engines/ep/src/collections/vbucket_manifest.cc
@@ -447,7 +447,7 @@ void Manifest::createCollection(const WriteHandle& wHandle,
                                             optionalSeqno,
                                             {/*no callback*/});
 
-    EP_LOG_INFO(
+    EP_LOG_DEBUG(
             "{} create collection:id:{}, name:{} in scope:{}, seq:{}, "
             "manifest:{:#x}{}{}",
             vb.getId(),
@@ -555,7 +555,7 @@ void Manifest::dropCollection(WriteHandle& wHandle,
             optionalSeqno,
             vb.getSaveDroppedCollectionCallback(cid, wHandle, itr->second));
 
-    EP_LOG_INFO(
+    EP_LOG_DEBUG(
             "{} drop collection:id:{} from scope:{}, seq:{}, manifest:{:#x}"
             "items:{} diskSize:{} {}{}",
             vb.getId(),
@@ -641,17 +641,18 @@ void Manifest::createScope(const WriteHandle& wHandle,
     auto seqno = vb.addSystemEventItem(
             std::move(item), optionalSeqno, {}, wHandle, {});
 
-    EP_LOG_INFO("{} create scope:id:{} name:{}, seq:{}, manifest:{:#x}{}{}{}",
-                vb.getId(),
-                sid,
-                scopeName,
-                seqno,
-                manifestUid,
-                entry.getDataLimit() ? fmt::format(", limit:{}",
-                                                   entry.getDataLimit().value())
-                                     : "",
-                dataLimitModified ? ", mod" : "",
-                optionalSeqno.has_value() ? ", replica" : "");
+    EP_LOG_DEBUG(
+            "{} create scope:id:{} name:{}, seq:{}, manifest:{:#x}{}{}{}",
+            vb.getId(),
+            sid,
+            scopeName,
+            seqno,
+            manifestUid,
+            entry.getDataLimit()
+                    ? fmt::format(", limit:{}", entry.getDataLimit().value())
+                    : "",
+            dataLimitModified ? ", mod" : "",
+            optionalSeqno.has_value() ? ", replica" : "");
 }
 
 void Manifest::modifyScope(const WriteHandle& wHandle,
@@ -661,6 +662,7 @@ void Manifest::modifyScope(const WriteHandle& wHandle,
     // Update under write lock
     modification.entry.setDataLimit(modification.dataLimit);
 
+    // Keep this logging - it's new and should be rare
     EP_LOG_INFO(
             "{} modifying scope:id:{} manifest:{:#x}{}",
             vb.getId(),
@@ -716,12 +718,12 @@ void Manifest::dropScope(const WriteHandle& wHandle,
         vb.checkpointManager->createNewCheckpoint();
     }
 
-    EP_LOG_INFO("{} drop scope:id:{} seq:{}, manifest:{:#x}{}",
-                vb.getId(),
-                sid,
-                seqno,
-                manifestUid,
-                optionalSeqno.has_value() ? ", replica" : "");
+    EP_LOG_DEBUG("{} drop scope:id:{} seq:{}, manifest:{:#x}{}",
+                 vb.getId(),
+                 sid,
+                 seqno,
+                 manifestUid,
+                 optionalSeqno.has_value() ? ", replica" : "");
 }
 
 Manifest::ManifestChanges Manifest::processManifest(