SERVER-27773 add operationTime field to the command response

7 files changed, 127 insertions, 4 deletions

diff --git a/src/mongo/db/commands.cpp b/src/mongo/db/commands.cpp
index 99163e22786..de0f2c72d95 100644
--- a/src/mongo/db/commands.cpp
+++ b/src/mongo/db/commands.cpp
@@ -36,6 +36,7 @@
 #include <vector>
 
 #include "mongo/bson/mutable/document.h"
+#include "mongo/bson/timestamp.h"
 #include "mongo/db/audit.h"
 #include "mongo/db/auth/action_set.h"
 #include "mongo/db/auth/action_type.h"
@@ -195,6 +196,10 @@ void Command::appendCommandWCStatus(BSONObjBuilder& result,
     }
 }
 
+void Command::appendOperationTime(BSONObjBuilder& result, LogicalTime operationTime) {
+    result.append("operationTime", operationTime.asTimestamp());
+}
+
 Status Command::checkAuthForOperation(OperationContext* txn,
                                       const std::string& dbname,
                                       const BSONObj& cmdObj) {
@@ -315,6 +320,36 @@ void _generateErrorResponse(OperationContext* txn,
     replyBuilder->setMetadata(metadata);
 }
 
+void _generateErrorResponse(OperationContext* txn,
+                            rpc::ReplyBuilderInterface* replyBuilder,
+                            const DBException& exception,
+                            const BSONObj& metadata,
+                            LogicalTime operationTime) {
+    Command::registerError(txn, exception);
+
+    // We could have thrown an exception after setting fields in the builder,
+    // so we need to reset it to a clean state just to be sure.
+    replyBuilder->reset();
+
+    // We need to include some extra information for SendStaleConfig.
+    if (exception.getCode() == ErrorCodes::SendStaleConfig) {
+        const SendStaleConfigException& scex =
+            static_cast<const SendStaleConfigException&>(exception);
+        replyBuilder->setCommandReply(scex.toStatus(),
+                                      BSON("ns" << scex.getns() << "vReceived"
+                                                << BSONArray(scex.getVersionReceived().toBSON())
+                                                << "vWanted"
+                                                << BSONArray(scex.getVersionWanted().toBSON())
+                                                << "operationTime"
+                                                << operationTime.asTimestamp()));
+    } else {
+        replyBuilder->setCommandReply(exception.toStatus(),
+                                      BSON("operationTime" << operationTime.asTimestamp()));
+    }
+
+    replyBuilder->setMetadata(metadata);
+}
+
 }  // namespace
 
 void Command::generateErrorResponse(OperationContext* txn,
@@ -322,6 +357,22 @@ void Command::generateErrorResponse(OperationContext* txn,
                                     const DBException& exception,
                                     const rpc::RequestInterface& request,
                                     Command* command,
+                                    const BSONObj& metadata,
+                                    LogicalTime operationTime) {
+    LOG(1) << "assertion while executing command '" << request.getCommandName() << "' "
+           << "on database '" << request.getDatabase() << "' "
+           << "with arguments '" << command->getRedactedCopyForLogging(request.getCommandArgs())
+           << "' metadata '" << request.getMetadata() << "' and operationTime '"
+           << operationTime.toString() << "': " << exception.toString();
+
+    _generateErrorResponse(txn, replyBuilder, exception, metadata, operationTime);
+}
+
+void Command::generateErrorResponse(OperationContext* txn,
+                                    rpc::ReplyBuilderInterface* replyBuilder,
+                                    const DBException& exception,
+                                    const rpc::RequestInterface& request,
+                                    Command* command,
                                     const BSONObj& metadata) {
     LOG(1) << "assertion while executing command '" << request.getCommandName() << "' "
            << "on database '" << request.getDatabase() << "' "
diff --git a/src/mongo/db/commands.h b/src/mongo/db/commands.h
index 263a96988b6..b853c7a2a94 100644
--- a/src/mongo/db/commands.h
+++ b/src/mongo/db/commands.h
@@ -28,6 +28,7 @@
 
 #pragma once
 
+#include <boost/optional.hpp>
 #include <string>
 #include <vector>
 
@@ -39,6 +40,7 @@
 #include "mongo/db/client.h"
 #include "mongo/db/commands/server_status_metric.h"
 #include "mongo/db/jsobj.h"
+#include "mongo/db/logical_time.h"
 #include "mongo/db/query/explain.h"
 #include "mongo/db/write_concern.h"
 #include "mongo/rpc/reply_builder_interface.h"
@@ -331,6 +333,11 @@ public:
     static bool appendCommandStatus(BSONObjBuilder& result, const Status& status);
 
     /**
+     * Appends "operationTime" field to the command result object as a Timestamp type.
+     */
+    static void appendOperationTime(BSONObjBuilder& result, LogicalTime operationTime);
+
+    /**
      * Helper for setting a writeConcernError field in the command result object if
      * a writeConcern error occurs.
      *
@@ -402,6 +409,17 @@ public:
 
     /**
      * Generates a command error response. This overload of generateErrorResponse is intended
+     * to also add an operationTime.
+     */
+    static void generateErrorResponse(OperationContext* txn,
+                                      rpc::ReplyBuilderInterface* replyBuilder,
+                                      const DBException& exception,
+                                      const rpc::RequestInterface& request,
+                                      Command* command,
+                                      const BSONObj& metadata,
+                                      LogicalTime operationTime);
+    /**
+     * Generates a command error response. This overload of generateErrorResponse is intended
      * to be called if the command is successfully parsed, but there is an error before we have
      * a handle to the actual Command object. This can happen, for example, when the command
      * is not found.
diff --git a/src/mongo/db/commands/dbcommands.cpp b/src/mongo/db/commands/dbcommands.cpp
index c536b367462..8c72e2050ae 100644
--- a/src/mongo/db/commands/dbcommands.cpp
+++ b/src/mongo/db/commands/dbcommands.cpp
@@ -31,7 +31,6 @@
 #include "mongo/platform/basic.h"
 
 #include <array>
-#include <boost/optional.hpp>
 #include <time.h>
 
 #include "mongo/base/disallow_copying.h"
@@ -75,6 +74,7 @@
 #include "mongo/db/json.h"
 #include "mongo/db/keypattern.h"
 #include "mongo/db/lasterror.h"
+#include "mongo/db/logical_clock.h"
 #include "mongo/db/matcher/extensions_callback_disallow_extensions.h"
 #include "mongo/db/namespace_string.h"
 #include "mongo/db/op_observer.h"
@@ -129,6 +129,22 @@ MONGO_INITIALIZER(InitializeRegisterErrorHandler)(InitializerContext* const) {
     Command::registerRegisterError(registerErrorImpl);
     return Status::OK();
 }
+/**
+ * For replica set members it returns the last known op time from txn. Otherwise will return
+ * uninitialized logical time.
+ */
+LogicalTime _getClientOperationTime(OperationContext* txn) {
+    repl::ReplicationCoordinator* replCoord =
+        repl::ReplicationCoordinator::get(txn->getClient()->getServiceContext());
+    const bool isReplSet =
+        replCoord->getReplicationMode() == repl::ReplicationCoordinator::modeReplSet;
+    LogicalTime operationTime;
+    if (isReplSet) {
+        operationTime = LogicalTime(
+            repl::ReplClientInfo::forClient(txn->getClient()).getLastOp().getTimestamp());
+    }
+    return operationTime;
+}
 }  // namespace
 
 
@@ -1377,6 +1393,7 @@ bool Command::run(OperationContext* txn,
 
     std::string errmsg;
     bool result;
+    auto startOperationTime = _getClientOperationTime(txn);
     if (!supportsWriteConcern(cmd)) {
         if (commandSpecifiesWriteConcern(cmd)) {
             auto result = appendCommandStatus(
@@ -1445,6 +1462,19 @@ bool Command::run(OperationContext* txn,
     }
 
     appendCommandStatus(inPlaceReplyBob, result, errmsg);
+
+    auto finishOperationTime = _getClientOperationTime(txn);
+    auto operationTime = finishOperationTime;
+    invariant(finishOperationTime >= startOperationTime);
+
+    // this command did not write, so return current clusterTime.
+    if (finishOperationTime == startOperationTime) {
+        // TODO: SERVER-27786 to return the clusterTime of the read.
+        operationTime = LogicalClock::get(txn)->getClusterTime().getTime();
+    }
+
+    appendOperationTime(inPlaceReplyBob, operationTime);
+
     inPlaceReplyBob.doneFast();
 
     BSONObjBuilder metadataBob;
@@ -1622,6 +1652,8 @@ void mongo::execCommandDatabase(OperationContext* txn,
         BSONObjBuilder metadataBob;
         appendOpTimeMetadata(txn, request, &metadataBob);
 
-        Command::generateErrorResponse(txn, replyBuilder, e, request, command, metadataBob.done());
+        auto operationTime = _getClientOperationTime(txn);
+        Command::generateErrorResponse(
+            txn, replyBuilder, e, request, command, metadataBob.done(), operationTime);
     }
 }
diff --git a/src/mongo/db/commands_test.cpp b/src/mongo/db/commands_test.cpp
index 5b910cc308f..d26eed1ad74 100644
--- a/src/mongo/db/commands_test.cpp
+++ b/src/mongo/db/commands_test.cpp
@@ -74,4 +74,15 @@ TEST(Commands, appendCommandStatusNoOverwrite) {
 
     ASSERT_BSONOBJ_EQ(actualResult.obj(), expectedResult.obj());
 }
+
+TEST(Commands, appendOperationTime) {
+    BSONObjBuilder actualResult;
+    LogicalTime testTime(Timestamp(1));
+    Command::appendOperationTime(actualResult, testTime);
+
+    BSONObjBuilder expectedResult;
+    expectedResult.append("operationTime", Timestamp(1));
+
+    ASSERT_BSONOBJ_EQ(actualResult.obj(), expectedResult.obj());
+}
 }  // namespace mongo
diff --git a/src/mongo/db/logical_clock.h b/src/mongo/db/logical_clock.h
index ffb78848986..5c04207e324 100644
--- a/src/mongo/db/logical_clock.h
+++ b/src/mongo/db/logical_clock.h
@@ -53,7 +53,8 @@ public:
     /**
      *  Creates an instance of LogicalClock. The TimeProofService must already be fully initialized.
      *  The validateProof indicates if the advanceClusterTime validates newTime. It should do so
-     *  only when LogicalClock installed on mongos and the auth is off.
+     *  only when LogicalClock installed on mongos and the auth is on. When the auth is off we
+     *  assume that the DBA uses other ways to validate authenticity of user messages.
      */
     LogicalClock(ServiceContext*, std::unique_ptr<TimeProofService>, bool validateProof);
 
diff --git a/src/mongo/db/repl/repl_set_request_votes_args.cpp b/src/mongo/db/repl/repl_set_request_votes_args.cpp
index f2626cefa75..83ded65f45f 100644
--- a/src/mongo/db/repl/repl_set_request_votes_args.cpp
+++ b/src/mongo/db/repl/repl_set_request_votes_args.cpp
@@ -49,6 +49,7 @@ const std::string kReasonFieldName = "reason";
 const std::string kSetNameFieldName = "setName";
 const std::string kTermFieldName = "term";
 const std::string kVoteGrantedFieldName = "voteGranted";
+const std::string kOperationTime = "operationTime";
 
 const std::string kLegalArgsFieldNames[] = {
     kCandidateIndexFieldName,
@@ -58,10 +59,11 @@ const std::string kLegalArgsFieldNames[] = {
     kLastDurableOpTimeFieldName,
     kSetNameFieldName,
     kTermFieldName,
+    kOperationTime,
 };
 
 const std::string kLegalResponseFieldNames[] = {
-    kOkFieldName, kReasonFieldName, kTermFieldName, kVoteGrantedFieldName,
+    kOkFieldName, kReasonFieldName, kTermFieldName, kVoteGrantedFieldName, kOperationTime,
 };
 
 }  // namespace
diff --git a/src/mongo/db/service_context_d_test_fixture.cpp b/src/mongo/db/service_context_d_test_fixture.cpp
index 268a7cee984..9d6087e066e 100644
--- a/src/mongo/db/service_context_d_test_fixture.cpp
+++ b/src/mongo/db/service_context_d_test_fixture.cpp
@@ -37,11 +37,13 @@
 #include "mongo/db/concurrency/write_conflict_exception.h"
 #include "mongo/db/curop.h"
 #include "mongo/db/db_raii.h"
+#include "mongo/db/logical_clock.h"
 #include "mongo/db/op_observer_noop.h"
 #include "mongo/db/operation_context.h"
 #include "mongo/db/service_context.h"
 #include "mongo/db/service_context_d.h"
 #include "mongo/db/storage/storage_options.h"
+#include "mongo/db/time_proof_service.h"
 #include "mongo/stdx/memory.h"
 #include "mongo/unittest/temp_dir.h"
 #include "mongo/util/scopeguard.h"
@@ -51,6 +53,12 @@ namespace mongo {
 void ServiceContextMongoDTest::setUp() {
     Client::initThread(getThreadName().c_str());
     ServiceContext* serviceContext = getServiceContext();
+
+    auto timeProofService = stdx::make_unique<TimeProofService>();
+    auto logicalClock =
+        stdx::make_unique<LogicalClock>(serviceContext, std::move(timeProofService), false);
+    LogicalClock::set(serviceContext, std::move(logicalClock));
+
     if (!serviceContext->getGlobalStorageEngine()) {
         // When using the "ephemeralForTest" storage engine, it is fine for the temporary directory
         // to go away after the global storage engine is initialized.