MB-32576: Improve dcp disconnect messages

Improve the disconnect log messages for the DCP consumer and producer
to:

1.  Make it clear that the last message refers to all messages and
    not just noops.
2.  Include the DCP noop interval.

Example Producer Disconnect Log Message:

"Disconnecting because a message has not been received for the DCP idle
timeout of 360s. Sent last message (e.g. mutation/noop/streamEnd) 0s
ago. Received last message 361s ago. Last sent noop 0s ago. DCP noop
interval is 1s. opaque: 10000019, pendingRecv: false."

Example Consumer Disconnect Log Message:

Disconnecting because a message has not been received for the DCP idle
timeout of 360s. Received last message (e.g. mutation/noop/StreamEnd)
361s ago. DCP noop interval is 1s.

Change-Id: I56a891cc25a1afdf8590613fd2057ea13dab5ba2
Reviewed-on: http://review.couchbase.org/108164
Tested-by: Build Bot <[email protected]>
Reviewed-by: Paolo Cocchi <[email protected]>

Author: owend74

engines/ep/src/dcp/consumer.cc

@@ -1411,16 +1411,16 @@ ENGINE_ERROR_CODE DcpConsumer::handleNoop(struct dcp_message_producers* producer
         return ret;
     }
 
+    // MB-29441: Set the noop-interval on the producer:
+    //     - dcpNoopTxInterval, if the producer is a >=5.0.0 node
+    //     - 180 seconds, if the producer is a pre-5.0.0 node
+    //       (this is the expected value on a pre-5.0.0 producer)
+    auto intervalCount =
+            producerIsVersion5orHigher ? dcpNoopTxInterval.count() : 180;
+
     if (pendingSendNoopInterval) {
         ENGINE_ERROR_CODE ret;
         uint32_t opaque = ++opaqueCounter;
-
-        // MB-29441: Set the noop-interval on the producer:
-        //     - dcpNoopTxInterval, if the producer is a >=5.0.0 node
-        //     - 180 seconds, if the producer is a pre-5.0.0 node
-        //         (this is the expected value on a pre-5.0.0 producer)
-        auto intervalCount =
-                producerIsVersion5orHigher ? dcpNoopTxInterval.count() : 180;
         std::string interval = std::to_string(intervalCount);
         ret = producers->control(opaque, noopIntervalCtrlMsg, interval);
         pendingSendNoopInterval = false;
@@ -1432,9 +1432,12 @@ ENGINE_ERROR_CODE DcpConsumer::handleNoop(struct dcp_message_producers* producer
     if ((now - lastMessageTime) > dcpIdleTimeout) {
         logger->info(
                 "Disconnecting because a message has not been received for "
-                "{}s. lastMessageTime:{}",
+                "the DCP idle timeout of {}s. "
+                "Received last message (e.g. mutation/noop/StreamEnd) {}s ago. "
+                "DCP noop interval is {}s.",
                 dcpIdleTimeout,
-                (now - lastMessageTime));
+                (now - lastMessageTime),
+                intervalCount);
         return ENGINE_DISCONNECT;
     }
 

engines/ep/src/dcp/producer.cc

@@ -1514,15 +1514,17 @@ ENGINE_ERROR_CODE DcpProducer::maybeDisconnect() {
     if (noopCtx.enabled && elapsedTime > dcpIdleTimeout) {
         logger->info(
                 "Disconnecting because a message has not been received for "
-                "DCP "
-                "idle timeout (which is "
-                "{}s). Sent last message {}s ago, received last message {}s "
-                "ago. noopCtx {{now - sendTime:{}, opaque: {}, "
-                "pendingRecv:{}}}",
+                "the DCP idle timeout of {}s. "
+                "Sent last message (e.g. mutation/noop/streamEnd) {}s ago. "
+                "Received last message {}s ago. "
+                "Last sent noop {}s ago. "
+                "DCP noop interval is {}s. "
+                "opaque: {}, pendingRecv: {}.",
                 dcpIdleTimeout,
                 (now - lastSendTime),
                 elapsedTime,
                 (now - noopCtx.sendTime),
+                noopCtx.dcpNoopTxInterval.count(),
                 noopCtx.opaque,
                 noopCtx.pendingRecv ? "true" : "false");
         return ENGINE_DISCONNECT;