Refactor: Capture vbucket id in DurabilityMonitor throw messages

It would be useful to capture the vbucket id in throws messages to
assist debugging issues, for example the following exception is
seen in MB-34956

"ActiveDurabilityMonitor::processSeqnoAck: seqno(20371) is greater than lastTrackedSeqno(0)"

Having the vbucket of that ADM could be useful.

This patch lifts throwException from the collection's VB::Manifest code
and modifies it for use in ADM/PDM. The code attempts to avoid the use
of any non-standard macros, so __func__ is used over __FUNCTION__ or
__PRETTY_FUNCTION.

With this change the above throw message now becomes (if vb was 67)

"ActiveDurabilityMonitor::processSeqnoAck: vb:67 seqno(20371) is greater than lastTrackedSeqno(0)"

Change-Id: I53268f82899a1db3f51db1efa45b7dcd8dc29b9e
Reviewed-on: http://review.couchbase.org/111860
Reviewed-by: Dave Rigby <[email protected]>
Tested-by: Build Bot <[email protected]>

Author: jimwwalker

engines/ep/src/durability/active_durability_monitor.cc

@@ -206,6 +206,18 @@ struct ActiveDurabilityMonitor::State {
                                   const std::string& node,
                                   bool shouldAck);
 
+    /**
+     * throw exception with the following error string:
+     *   "ActiveDurabilityMonitor::State::<thrower>:<error> vb:x"
+     *
+     * @param thrower a string for who is throwing, typically __func__
+     * @param error a string containing the error and any useful data
+     * @throws exception
+     */
+    template <class exception>
+    [[noreturn]] void throwException(const std::string& thrower,
+                                     const std::string& error) const;
+
 public:
     /// The container of pending Prepares.
     Container trackedWrites;
@@ -383,16 +395,12 @@ void ActiveDurabilityMonitor::setReplicationTopology(
     Expects(!topology.is_null());
 
     if (!topology.is_array()) {
-        throw std::invalid_argument(
-                "ActiveDurabilityMonitor::setReplicationTopology: Topology is "
-                "not an "
-                "array");
+        throwException<std::invalid_argument>(__func__,
+                                              "Topology is not an array");
     }
 
     if (topology.size() == 0) {
-        throw std::invalid_argument(
-                "ActiveDurabilityMonitor::setReplicationTopology: Topology is "
-                "empty");
+        throwException<std::invalid_argument>(__func__, "Topology is empty");
     }
 
     // Setting the replication topology also resets the topology in all
@@ -442,17 +450,15 @@ void ActiveDurabilityMonitor::addSyncWrite(const void* cookie,
     auto durReq = item->getDurabilityReqs();
 
     if (durReq.getLevel() == cb::durability::Level::None) {
-        throw std::invalid_argument(
-                "ActiveDurabilityMonitor::addSyncWrite: Level::None");
+        throwException<std::invalid_argument>(__func__, "Level::None");
     }
 
     // The caller must have already checked this and returned a proper error
     // before executing down here. Here we enforce it again for defending from
     // unexpected races between VBucket::setState (which sets the replication
     // topology).
     if (!isDurabilityPossible()) {
-        throw std::logic_error(
-                "ActiveDurabilityMonitor::addSyncWrite: Impossible");
+        throwException<std::logic_error>(__func__, "Impossible");
     }
 
     state.wlock()->addSyncWrite(cookie, std::move(item));
@@ -504,9 +510,9 @@ void ActiveDurabilityMonitor::processTimeout(
         std::chrono::steady_clock::time_point asOf) {
     // @todo: Add support for DurabilityMonitor at Replica
     if (vb.getState() != vbucket_state_active) {
-        throw std::logic_error("ActiveDurabilityMonitor::processTimeout: " +
-                               vb.getId().to_string() + " state is: " +
-                               VBucket::toString(vb.getState()));
+        throwException<std::logic_error>(
+                __func__,
+                "state is: " + std::string(VBucket::toString(vb.getState())));
     }
 
     // Identify SyncWrites which can be timed out as of this time point
@@ -688,10 +694,9 @@ ActiveDurabilityMonitor::State::advanceNodePosition(const std::string& node) {
     auto firstChainFound = firstChainItr != firstChain->positions.end();
     if (!firstChainFound && !secondChain) {
         // Attempting to advance for a node we don't know about, panic
-        throw std::logic_error(
-                "ActiveDurabilityMonitor::State::advanceNodePosition: "
-                "Attempting to advance positions for an invalid node " +
-                node);
+        throwException<std::logic_error>(
+                __func__,
+                "Attempting to advance positions for an invalid node " + node);
     }
 
     std::unordered_map<std::string, Position>::iterator secondChainItr;
@@ -700,10 +705,11 @@ ActiveDurabilityMonitor::State::advanceNodePosition(const std::string& node) {
         secondChainItr = secondChain->positions.find(node);
         secondChainFound = secondChainItr != secondChain->positions.end();
         if (!firstChainFound && !secondChainFound) {
-            throw std::logic_error(
-                    "ActiveDurabilityMonitor::State::advanceNodePosition "
+            throwException<std::logic_error>(
+                    __func__,
                     "Attempting to advance positions for an invalid node " +
-                    node + ". Node is not in firstChain or secondChain");
+                            node +
+                            ". Node is not in firstChain or secondChain");
         }
     }
 
@@ -829,10 +835,8 @@ int64_t ActiveDurabilityMonitor::State::getNodeWriteSeqno(
         }
     }
 
-    throw std::invalid_argument(
-            "ActiveDurabilityMonitor::State::getNodeWriteSeqno: "
-            "Node " +
-            node + " not found");
+    throwException<std::invalid_argument>(__func__,
+                                          "Node " + node + " not found");
 }
 
 int64_t ActiveDurabilityMonitor::State::getNodeAckSeqno(
@@ -850,17 +854,14 @@ int64_t ActiveDurabilityMonitor::State::getNodeAckSeqno(
         }
     }
 
-    throw std::invalid_argument(
-            "ActiveDurabilityMonitor::State::getNodeAckSeqno: "
-            "Node " +
-            node + " not found");
+    throwException<std::invalid_argument>(__func__,
+                                          "Node " + node + " not found");
 }
 
 DurabilityMonitor::SyncWrite ActiveDurabilityMonitor::State::removeSyncWrite(
         Container::iterator it) {
     if (it == trackedWrites.end()) {
-        throw std::logic_error(
-                "ActiveDurabilityMonitor::commit: Position points to end");
+        throwException<std::logic_error>(__func__, "Position points to end");
     }
 
     Container::iterator prev;
@@ -923,10 +924,8 @@ void ActiveDurabilityMonitor::commit(const SyncWrite& sw) {
                             vb.lockCollections(key),
                             sw.getCookie());
     if (result != ENGINE_SUCCESS) {
-        throw std::logic_error(
-                "ActiveDurabilityMonitor::commit: VBucket::commit failed with "
-                "status:" +
-                std::to_string(result));
+        throwException<std::logic_error>(
+                __func__, "failed with status:" + std::to_string(result));
     }
 
     // Record the duration of the SyncWrite in histogram.
@@ -966,10 +965,8 @@ void ActiveDurabilityMonitor::abort(const SyncWrite& sw) {
                            vb.lockCollections(key),
                            sw.getCookie());
     if (result != ENGINE_SUCCESS) {
-        throw std::logic_error(
-                "ActiveDurabilityMonitor::abort: VBucket::abort failed with "
-                "status:" +
-                std::to_string(result));
+        throwException<std::logic_error>(
+                __func__, "failed with status:" + std::to_string(result));
     }
     auto s = state.wlock();
     s->lastAbortedSeqno = sw.getBySeqno();
@@ -995,15 +992,14 @@ void ActiveDurabilityMonitor::State::processSeqnoAck(const std::string& node,
                                                      int64_t seqno,
                                                      CompletedQueue& toCommit) {
     if (!firstChain) {
-        throw std::logic_error(
-                "ActiveDurabilityMonitor::processSeqnoAck: FirstChain not "
-                "set");
+        throwException<std::logic_error>(__func__, "FirstChain not set");
     }
     if (seqno > lastTrackedSeqno) {
-        throw std::invalid_argument(
-                "ActiveDurabilityMonitor::processSeqnoAck: seqno(" +
-                std::to_string(seqno) + ") is greater than lastTrackedSeqno(" +
-                std::to_string(lastTrackedSeqno) + ")");
+        throwException<std::invalid_argument>(
+                __func__,
+                "seqno(" + std::to_string(seqno) +
+                        ") is greater than lastTrackedSeqno(" +
+                        std::to_string(lastTrackedSeqno) + ")");
     }
 
     // We should never ack for the active
@@ -1122,17 +1118,19 @@ ActiveDurabilityMonitor::State::makeChain(
         auto firstChainItr = firstChain->positions.find(firstChain->active);
         if (firstChainItr == firstChain->positions.end()) {
             // Sanity - we should never make a chain in this state
-            throw std::logic_error(
-                    "ADM::State::makeChain did not find the "
+            throwException<std::logic_error>(
+                    __func__,
+                    "did not find the "
                     "active node for the first chain in the "
                     "first chain.");
         }
 
         auto newChainItr = ptr->positions.find(ptr->active);
         if (newChainItr == ptr->positions.end()) {
             // Sanity - we should never make a chain in this state
-            throw std::logic_error(
-                    "ADM::State::makeChain did not find the "
+            throwException<std::logic_error>(
+                    __func__,
+                    "did not find the "
                     "active node for the first chain in the "
                     "new chain.");
         }
@@ -1163,9 +1161,8 @@ void ActiveDurabilityMonitor::State::setReplicationTopology(
     if (topology.size() > 1) {
         if (topology.size() > 2) {
             // Too many chains specified
-            throw std::invalid_argument(
-                    "ActiveDurabilityMonitor::State::setReplicationTopology: "
-                    "Too many chains specified");
+            throwException<std::invalid_argument>(__func__,
+                                                  "Too many chains specified");
         }
 
         auto& sChain = topology.at(1);
@@ -1383,3 +1380,17 @@ void ActiveDurabilityMonitor::checkForCommit() {
 
     processCompletedSyncWriteQueue();
 }
+
+template <class exception>
+[[noreturn]] void ActiveDurabilityMonitor::State::throwException(
+        const std::string& thrower, const std::string& error) const {
+    throw exception("ActiveDurabilityMonitor::State::" + thrower + " " +
+                    adm.vb.getId().to_string() + " " + error);
+}
+
+template <class exception>
+[[noreturn]] void ActiveDurabilityMonitor::throwException(
+        const std::string& thrower, const std::string& error) const {
+    throw exception("ActiveDurabilityMonitor::" + thrower + " " +
+                    vb.getId().to_string() + " " + error);
+}

engines/ep/src/durability/active_durability_monitor.h

@@ -218,6 +218,18 @@ class ActiveDurabilityMonitor : public DurabilityMonitor {
 protected:
     void toOStream(std::ostream& os) const override;
 
+    /**
+     * throw exception with the following error string:
+     *   "ActiveDurabilityMonitor::<thrower>:<error> vb:x"
+     *
+     * @param thrower a string for who is throwing, typically __func__
+     * @param error a string containing the error and any useful data
+     * @throws exception
+     */
+    template <class exception>
+    [[noreturn]] void throwException(const std::string& thrower,
+                                     const std::string& error) const;
+
     /**
      * Commit the given SyncWrite.
      *

engines/ep/src/durability/passive_durability_monitor.cc

@@ -90,13 +90,13 @@ void PassiveDurabilityMonitor::addSyncWrite(queued_item item) {
     auto durReq = item->getDurabilityReqs();
 
     if (durReq.getLevel() == cb::durability::Level::None) {
-        throw std::invalid_argument(
-                "PassiveDurabilityMonitor::addSyncWrite: Level::None");
+        throwException<std::invalid_argument>(__func__, "Level::None");
     }
     if (durReq.getTimeout().isDefault()) {
-        throw std::invalid_argument(
-                "PassiveDurabilityMonitor::addSyncWrite: timeout is default "
-                "(explicit value should have been specified by Active node)");
+        throwException<std::invalid_argument>(
+                __func__,
+                "timeout is default (explicit value should have been specified "
+                "by Active node)");
     }
 
     // Need to specify defaultTimeout for SyncWrite ctor, but we've already
@@ -187,19 +187,19 @@ void PassiveDurabilityMonitor::completeSyncWrite(const StoredDocKey& key,
     auto s = state.wlock();
 
     if (s->trackedWrites.empty()) {
-        throw std::logic_error(
-                "PassiveDurabilityMonitor::resolvePrepare: No tracked, but "
-                "received " +
-                to_string(res) + " for key " + key.to_string());
+        throwException<std::logic_error>(__func__,
+                                         "No tracked, but received " +
+                                                 to_string(res) + " for key " +
+                                                 key.to_string());
     }
 
     const auto next = s->getIteratorNext(s->highCompletedSeqno.it);
 
     if (next == s->trackedWrites.end()) {
-        throw std::logic_error(
-                "PassiveDurabilityMonitor::resolvePrepare: No Prepare waiting "
-                "for completion, but received " +
-                to_string(res) + " for key " + key.to_string());
+        throwException<std::logic_error>(
+                __func__,
+                "No Prepare waiting for completion, but received " +
+                        to_string(res) + " for key " + key.to_string());
     }
 
     // Sanity check for In-Order Commit
@@ -208,8 +208,7 @@ void PassiveDurabilityMonitor::completeSyncWrite(const StoredDocKey& key,
         ss << "Pending resolution for '" << *next
            << "', but received unexpected " + to_string(res) + " for key "
            << key;
-        throw std::logic_error("PassiveDurabilityMonitor::resolvePrepare: " +
-                               ss.str());
+        throwException<std::logic_error>(__func__, "" + ss.str());
     }
 
     // Note: Update last-write-seqno first to enforce monotonicity and
@@ -439,3 +438,9 @@ void PassiveDurabilityMonitor::State::checkForAndRemovePrepares() {
         it = next;
     }
 }
+
+template <class exception>
+[[noreturn]] void PassiveDurabilityMonitor::throwException(
+        const std::string& thrower, const std::string& error) const {
+    throw exception(thrower + error + vb.getId().to_string());
+}

engines/ep/src/durability/passive_durability_monitor.h

@@ -122,6 +122,17 @@ class PassiveDurabilityMonitor : public DurabilityMonitor {
 
 protected:
     void toOStream(std::ostream& os) const override;
+    /**
+     * throw exception with the following error string:
+     *   "<thrower>:<error> vb:x"
+     *
+     * @param thrower a string for who is throwing, typically __FUNCTION__
+     * @param error a string containing the error and any useful data
+     * @throws exception
+     */
+    template <class exception>
+    [[noreturn]] void throwException(const std::string& thrower,
+                                     const std::string& error) const;
 
     // The VBucket owning this DurabilityMonitor instance
     VBucket& vb;