SERVER-52862 Move logAuthentication hooks to AuthenticationSession

6 files changed, 249 insertions, 134 deletions

diff --git a/src/mongo/db/auth/SConscript b/src/mongo/db/auth/SConscript
index 9772da3465f..b8a784a79d6 100644
--- a/src/mongo/db/auth/SConscript
+++ b/src/mongo/db/auth/SConscript
@@ -47,6 +47,7 @@ env.Library(
         'saslauth',
     ],
     LIBDEPS_PRIVATE=[
+        '$BUILD_DIR/mongo/db/audit',
         '$BUILD_DIR/mongo/db/stats/counters',
     ],
 )
@@ -270,10 +271,8 @@ env.Library(
     ],
     LIBDEPS_PRIVATE=[
         '$BUILD_DIR/mongo/client/sasl_client',
-        '$BUILD_DIR/mongo/db/audit',
         '$BUILD_DIR/mongo/db/commands',
         '$BUILD_DIR/mongo/db/commands/test_commands_enabled',
-        '$BUILD_DIR/mongo/db/stats/counters',
         'auth',
         'auth_impl_internal',
         'authentication_session',
diff --git a/src/mongo/db/auth/auth_decorations.cpp b/src/mongo/db/auth/auth_decorations.cpp
index c8cf55fd765..a3b5059e380 100644
--- a/src/mongo/db/auth/auth_decorations.cpp
+++ b/src/mongo/db/auth/auth_decorations.cpp
@@ -32,7 +32,6 @@
 #include <memory>
 #include <utility>
 
-#include "mongo/db/auth/authentication_session.h"
 #include "mongo/db/auth/authorization_manager.h"
 #include "mongo/db/auth/authorization_session.h"
 #include "mongo/db/auth/sasl_options.h"
@@ -45,9 +44,6 @@
 namespace mongo {
 namespace {
 
-const auto getAuthenticationSession =
-    Client::declareDecoration<boost::optional<AuthenticationSession>>();
-
 const auto getAuthorizationManager =
     ServiceContext::declareDecoration<std::unique_ptr<AuthorizationManager>>();
 
@@ -96,10 +92,6 @@ ServiceContext::ConstructorActionRegisterer destroyAuthorizationManagerRegistere
 
 }  // namespace
 
-boost::optional<AuthenticationSession>& AuthenticationSession::_get(Client* client) {
-    return getAuthenticationSession(client);
-}
-
 AuthorizationManager* AuthorizationManager::get(ServiceContext* service) {
     return getAuthorizationManager(service).get();
 }
diff --git a/src/mongo/db/auth/authentication_session.cpp b/src/mongo/db/auth/authentication_session.cpp
index 227709de932..54e7e6efe36 100644
--- a/src/mongo/db/auth/authentication_session.cpp
+++ b/src/mongo/db/auth/authentication_session.cpp
@@ -31,14 +31,68 @@
 
 #include "mongo/db/auth/authentication_session.h"
 
+#include "mongo/client/authenticate.h"
 #include "mongo/db/audit.h"
+#include "mongo/db/client.h"
 #include "mongo/logv2/log.h"
 
 namespace mongo {
 namespace {
-constexpr auto kDiagnosticLogLevel = 0;
+constexpr auto kDiagnosticLogLevel = 3;
+
+Status crossVerifyUserNames(const UserName& oldUser, const UserName& newUser) noexcept {
+    if (oldUser.getFullName().empty()) {
+        return Status::OK();
+    }
+
+    if (!getTestCommandsEnabled()) {
+        // Authenticating the __system@local user to the admin database on mongos is required
+        // by the auth passthrough test suite, hence we forgive this set of errors in testing.
+
+        if (oldUser.getDB() != newUser.getDB()) {
+            return {ErrorCodes::ProtocolError,
+                    "Attempt to switch database target during SASL authentication."};
+        }
+    }
+
+    if (oldUser.getUser().empty() || newUser.getUser().empty()) {
+        // If we don't have a user and our databases match, no harm and nothing more to do.
+        return Status::OK();
+    }
+
+    if (oldUser.getUser() != newUser.getUser()) {
+        return {ErrorCodes::ProtocolError, "Attempt to switch user during SASL authentication."};
+    }
+
+    return Status::OK();
 }
 
+const auto getAuthenticationSession =
+    Client::declareDecoration<boost::optional<AuthenticationSession>>();
+
+class AuthenticationClientObserver final : public ServiceContext::ClientObserver {
+public:
+    void onCreateClient(Client* client) override {}
+
+    void onDestroyClient(Client* client) override {
+        auto& maybeSession = getAuthenticationSession(client);
+        if (maybeSession) {
+            maybeSession->markFailed(
+                {ErrorCodes::AuthenticationAbandoned,
+                 "Authentication session abandoned, client has likely disconnected"});
+        }
+    }
+
+    void onCreateOperationContext(OperationContext* opCtx) override {}
+    void onDestroyOperationContext(OperationContext* opCtx) override {}
+};
+
+auto registerer = ServiceContext::ConstructorActionRegisterer{
+    "AuthenticationClientObserver", [](ServiceContext* service) {
+        service->registerClientObserver(std::make_unique<AuthenticationClientObserver>());
+    }};
+}  // namespace
+
 AuthenticationSession::StepGuard::StepGuard(OperationContext* opCtx, StepType currentStep)
     : _opCtx(opCtx), _currentStep(currentStep) {
     auto client = _opCtx->getClient();
@@ -46,7 +100,7 @@ AuthenticationSession::StepGuard::StepGuard(OperationContext* opCtx, StepType cu
     LOGV2_DEBUG(
         5286300, kDiagnosticLogLevel, "Starting authentication step", "step"_attr = _currentStep);
 
-    auto& maybeSession = _get(client);
+    auto& maybeSession = getAuthenticationSession(client);
     ON_BLOCK_EXIT([&] {
         if (maybeSession) {
             // If we successfully made/kept a session, update it and track it.
@@ -63,6 +117,19 @@ AuthenticationSession::StepGuard::StepGuard(OperationContext* opCtx, StepType cu
         maybeSession.emplace(client);
     };
 
+    auto startActiveSession = [&] {
+        if (maybeSession) {
+            invariant(maybeSession->_lastStep);
+            auto lastStep = *maybeSession->_lastStep;
+            if (lastStep == StepType::kSaslSupportedMechanisms) {
+                // We can follow saslSupportedMechanisms with saslStart or authenticate.
+                return;
+            }
+        }
+
+        createSession();
+    };
+
     switch (_currentStep) {
         case StepType::kSaslSupportedMechanisms: {
             createSession();
@@ -70,39 +137,87 @@ AuthenticationSession::StepGuard::StepGuard(OperationContext* opCtx, StepType cu
         } break;
         case StepType::kSpeculativeAuthenticate:
         case StepType::kSpeculativeSaslStart: {
-            createSession();
+            startActiveSession();
             maybeSession->_isSpeculative = true;
         } break;
         case StepType::kAuthenticate:
         case StepType::kSaslStart: {
-            createSession();
+            startActiveSession();
         } break;
         case StepType::kSaslContinue: {
             uassert(ErrorCodes::ProtocolError, "No SASL session state found", maybeSession);
+
+            uassert(ErrorCodes::ProtocolError,
+                    "saslContinue must follow saslStart",
+                    maybeSession->_mech);
         } break;
     }
 }
 
 AuthenticationSession::StepGuard::~StepGuard() {
-    auto& maybeSession = _get(_opCtx->getClient());
+    auto& maybeSession = getAuthenticationSession(_opCtx->getClient());
     if (maybeSession) {
         LOGV2_DEBUG(5286301,
                     kDiagnosticLogLevel,
                     "Finished authentication step",
                     "step"_attr = _currentStep);
-        if (maybeSession->isFinished()) {
+        if (maybeSession->_isFinished) {
             // We're done with this session, reset it.
             maybeSession.reset();
+        } else {
+            maybeSession->_lastStep = _currentStep;
         }
     }
 }
 
 AuthenticationSession* AuthenticationSession::get(Client* client) {
-    auto& maybeSession = _get(client);
+    auto& maybeSession = getAuthenticationSession(client);
     tassert(5286302, "Unable to retrieve authentication session", static_cast<bool>(maybeSession));
     return &(*maybeSession);
 }
 
+void AuthenticationSession::setMechanismName(StringData mechanismName) {
+    LOGV2_DEBUG(
+        5286200, kDiagnosticLogLevel, "Setting mechanism name", "mechanism"_attr = mechanismName);
+    tassert(5286201, "Attempt to change the mechanism name", _mechName.empty());
+
+    _mechName = mechanismName.toString();
+    _mechCounter = authCounter.getMechanismCounter(_mechName);
+    _mechCounter->incAuthenticateReceived();
+    if (_isSpeculative) {
+        _mechCounter->incSpeculativeAuthenticateReceived();
+    }
+}
+
+void AuthenticationSession::_verifyUserNameFromSaslSupportedMechanisms(const UserName& userName) {
+    if (auto status = crossVerifyUserNames(_ssmUserName, userName); !status.isOK()) {
+        LOGV2(5286202,
+              "Different user name was supplied to saslSupportedMechs",
+              "error"_attr = status);
+
+        // Reset _ssmUserName since we have found a conflict.
+        auto ssmUserName = std::exchange(_ssmUserName, {});
+        audit::logAuthentication(_client,
+                                 auth::kSaslSupportedMechanisms,
+                                 std::move(ssmUserName),
+                                 ErrorCodes::AuthenticationAbandoned);
+    }
+}
+
+void AuthenticationSession::setUserNameForSaslSupportedMechanisms(UserName userName) {
+    _verifyUserNameFromSaslSupportedMechanisms(userName);
+
+    _ssmUserName = userName;
+}
+
+void AuthenticationSession::updateUserName(UserName userName) {
+    LOGV2_DEBUG(5286203, kDiagnosticLogLevel, "Updating user name", "userName"_attr = userName);
+
+    _verifyUserNameFromSaslSupportedMechanisms(userName);
+    uassertStatusOK(crossVerifyUserNames(_userName, userName));
+    _userName = userName;
+}
+
 void AuthenticationSession::setMechanism(std::unique_ptr<ServerMechanismBase> mech,
                                          boost::optional<BSONObj> options) {
     tassert(5286303, "Attempted to override previous authentication mechanism", !_mech);
@@ -112,37 +227,69 @@ void AuthenticationSession::setMechanism(std::unique_ptr<ServerMechanismBase> me
         uassertStatusOK(_mech->setOptions(options->getOwned()));
     }
 
-    if (_mech && _mech->isClusterMember()) {
-        setAsClusterMember();
-    }
-
     LOGV2_DEBUG(5286304, kDiagnosticLogLevel, "Determined mechanism for authentication");
 }
 
 void AuthenticationSession::setAsClusterMember() {
-    _isClusterMember = true;
+    if (std::exchange(_isClusterMember, true)) {
+        return;
+    }
+
+    _mechCounter->incClusterAuthenticateReceived();
 
     LOGV2_DEBUG(5286305, kDiagnosticLogLevel, "Marking as cluster member");
 }
 
-void AuthenticationSession::markSuccessful() {
-    // Log success.
+void AuthenticationSession::_finish() {
     _isFinished = true;
+    if (_mech) {
+        // Since both isClusterMember() and getPrincipalName() can return differently over the
+        // course of authentication, only get the values when we finish.
+        if (_mech->isClusterMember()) {
+            setAsClusterMember();
+        }
+        updateUserName({_mech->getPrincipalName(), _mech->getAuthenticationDatabase()});
+    }
+}
+
+void AuthenticationSession::markSuccessful() {
+    _finish();
+
+    _mechCounter->incAuthenticateSuccessful();
+    if (_isClusterMember) {
+        _mechCounter->incClusterAuthenticateSuccessful();
+    }
+    if (_isSpeculative) {
+        _mechCounter->incSpeculativeAuthenticateSuccessful();
+    }
+
+    audit::logAuthentication(_client, _mechName, _userName, ErrorCodes::OK);
+
     LOGV2_DEBUG(5286306,
                 kDiagnosticLogLevel,
                 "Successfully authenticated",
-                "isSpeculative"_attr = isSpeculative(),
-                "isClusterMember"_attr = isClusterMember());
+                "client"_attr = _client->getRemote(),
+                "isSpeculative"_attr = _isSpeculative,
+                "isClusterMember"_attr = _isClusterMember,
+                "mechanism"_attr = _mechName,
+                "user"_attr = _userName.getUser(),
+                "db"_attr = _userName.getDB());
 }
 
 void AuthenticationSession::markFailed(const Status& status) {
-    // Log the error.
-    _isFinished = true;
+    _finish();
+
+    audit::logAuthentication(_client, _mechName, _userName, status.code());
+
     LOGV2_DEBUG(5286307,
                 kDiagnosticLogLevel,
                 "Failed to authenticate",
-                "isSpeculative"_attr = isSpeculative(),
-                "isClusterMember"_attr = isClusterMember(),
+                "client"_attr = _client->getRemote(),
+                "isSpeculative"_attr = _isSpeculative,
+                "isClusterMember"_attr = _isClusterMember,
+                "mechanism"_attr = _mechName,
+                "user"_attr = _userName.getUser(),
+                "db"_attr = _userName.getDB(),
                 "error"_attr = status);
 }
 
diff --git a/src/mongo/db/auth/authentication_session.h b/src/mongo/db/auth/authentication_session.h
index 38807455086..0b95b4ed2fb 100644
--- a/src/mongo/db/auth/authentication_session.h
+++ b/src/mongo/db/auth/authentication_session.h
@@ -30,8 +30,12 @@
 #pragma once
 
 #include <memory>
+#include <string>
+
+#include <boost/optional.hpp>
 
 #include "mongo/db/auth/sasl_mechanism_registry.h"
+#include "mongo/db/auth/user_name.h"
 #include "mongo/db/stats/counters.h"
 
 namespace mongo {
@@ -76,7 +80,7 @@ public:
         OperationContext* const _opCtx;
         const StepType _currentStep;
 
-        AuthenticationSession* _session;
+        AuthenticationSession* _session = nullptr;
     };
 
     /**
@@ -108,26 +112,58 @@ public:
     }
 
     /**
-     * This returns true if the session currently believes itself to be a cluster member.
+     * This returns the mechanism name for this session.
      */
-    bool isClusterMember() const {
-        if (_mech && _mech->isClusterMember()) {
-            // If we're doing sasl and we have a mechanism, then we know.
-            return true;
-        }
+    StringData getMechanismName() const {
+        return _mechName;
+    }
+
+    /**
+     * This returns the user portion of the UserName which may be an empty StringData.
+     */
+    StringData getUserName() const {
+        return _userName.getUser();
+    }
 
-        // Otherwise, rely on what the implementation has told us directly.
-        return _isClusterMember;
+    /**
+     * This returns the database portion of the UserName which may be an empty StringData.
+     */
+    StringData getDatabase() const {
+        return _userName.getDB();
     }
 
     /**
-     * This returns true once either markFailed or markSuccessful is invoked.
+     * Set the mechanism name for this session.
+     *
+     * If the mechanism name is not recognized, this will throw.
+     */
+    void setMechanismName(StringData mechanismName);
+
+    /**
+     * Update the database for this session.
+     *
+     * The database will be validated against the current database for this session.
      */
-    bool isFinished() const {
-        return _isFinished;
+    void updateDatabase(StringData database) {
+        updateUserName(UserName("", database.toString()));
     }
 
     /**
+     * Update the user name for this session.
+     *
+     * The user name will be validated against the current user name for this session.
+     */
+    void updateUserName(UserName userName);
+
+    /**
+     * Set the last user name used with `saslSupportedMechs` for this session.
+     *
+     * This user name does no emit an exception when it conflicts, but it does create an audit
+     * entry.
+     */
+    void setUserNameForSaslSupportedMechanisms(UserName userName);
+
+    /**
      * Mark the session as a cluster member.
      *
      * This is used for x509 authentication since it lacks a mechanism in the traditional sense.
@@ -143,15 +179,11 @@ public:
 
     /**
      * Mark the session as succssfully authenticated.
-     *
-     * TODO(SERVER-52862) This should increment counters and log.
      */
     void markSuccessful();
 
     /**
      * Mark the session as unable to authenticate.
-     *
-     * TODO(SERVER-52862) This should increment counters and log.
      */
     void markFailed(const Status& status);
 
@@ -202,12 +234,26 @@ public:
 private:
     static boost::optional<AuthenticationSession>& _get(Client* client);
 
+    void _finish();
+    void _verifyUserNameFromSaslSupportedMechanisms(const UserName& user);
+
     Client* const _client;
 
+    boost::optional<StepType> _lastStep;
+
     bool _isSpeculative = false;
     bool _isClusterMember = false;
     bool _isFinished = false;
 
+    // The user name can be provided in advance by saslSupportedMechs.
+    UserName _ssmUserName;
+
+    std::string _mechName;
+    boost::optional<AuthCounter::MechanismCounterHandle> _mechCounter;
+
+    // The user name can be provided partially by the command namespace or in full by a client
+    // certificate. If we have a authN mechanism, we use its principal name instead.
+    UserName _userName;
     std::unique_ptr<ServerMechanismBase> _mech;
 };
 
diff --git a/src/mongo/db/auth/sasl_commands.cpp b/src/mongo/db/auth/sasl_commands.cpp
index 0a14aeba223..2e4281a7b21 100644
--- a/src/mongo/db/auth/sasl_commands.cpp
+++ b/src/mongo/db/auth/sasl_commands.cpp
@@ -39,7 +39,6 @@
 #include "mongo/bson/util/bson_extract.h"
 #include "mongo/client/authenticate.h"
 #include "mongo/client/sasl_client_authenticate.h"
-#include "mongo/db/audit.h"
 #include "mongo/db/auth/authentication_session.h"
 #include "mongo/db/auth/authorization_session.h"
 #include "mongo/db/auth/authz_manager_external_state_mock.h"
@@ -51,7 +50,6 @@
 #include "mongo/db/commands.h"
 #include "mongo/db/commands/authentication_commands.h"
 #include "mongo/db/server_options.h"
-#include "mongo/db/stats/counters.h"
 #include "mongo/logv2/log.h"
 #include "mongo/util/base64.h"
 #include "mongo/util/sequence_util.h"
@@ -135,9 +133,9 @@ public:
     }
 } cmdSaslContinue;
 
-StatusWith<SaslReply> doSaslStep(OperationContext* opCtx,
-                                 const SaslPayload& payload,
-                                 AuthenticationSession* session) try {
+SaslReply doSaslStep(OperationContext* opCtx,
+                     const SaslPayload& payload,
+                     AuthenticationSession* session) {
     auto mechanismPtr = session->getMechanism();
     invariant(mechanismPtr);
     auto& mechanism = *mechanismPtr;
@@ -166,7 +164,7 @@ StatusWith<SaslReply> doSaslStep(OperationContext* opCtx,
 
         sleepmillis(saslGlobalParams.authFailedDelay.load());
         // All the client needs to know is that authentication has failed.
-        return AuthorizationManager::authenticationFailedStatus;
+        uassertStatusOK(AuthorizationManager::authenticationFailedStatus);
     }
 
     if (mechanism.isSuccess()) {
@@ -197,14 +195,11 @@ StatusWith<SaslReply> doSaslStep(OperationContext* opCtx,
     reply.setPayload(std::move(replyPayload));
 
     return reply;
-} catch (const DBException& ex) {
-    return ex.toStatus();
 }
 
 SaslReply doSaslStart(OperationContext* opCtx,
                       AuthenticationSession* session,
-                      const SaslStartCommand& request,
-                      std::string* principalName) {
+                      const SaslStartCommand& request) {
     auto mechanism = uassertStatusOK(
         SASLServerMechanismRegistry::get(opCtx->getServiceContext())
             .getServerMechanism(request.getMechanism(), request.getDbName().toString()));
@@ -217,56 +212,19 @@ SaslReply doSaslStart(OperationContext* opCtx,
 
     session->setMechanism(std::move(mechanism), request.getOptions());
 
-    auto swReply = doSaslStep(opCtx, request.getPayload(), session);
-    if (!swReply.isOK() || session->getMechanism()->isSuccess()) {
-        // Only attempt to populate principal name if we're done (successfully or not).
-        *principalName = session->getMechanism()->getPrincipalName().toString();
-    }
-
-    auto reply = uassertStatusOK(swReply);
-    return reply;
+    return doSaslStep(opCtx, request.getPayload(), session);
 }
 
 SaslReply runSaslStart(OperationContext* opCtx,
                        AuthenticationSession* session,
                        const SaslStartCommand& request) {
     opCtx->markKillOnClientDisconnect();
-    auto client = opCtx->getClient();
 
-    auto db = request.getDbName();
-    auto mechanismName = request.getMechanism().toString();
-
-    SaslReply reply;
-    std::string principalName;
-    try {
-        auto mechCounter = authCounter.getMechanismCounter(mechanismName);
-        mechCounter.incAuthenticateReceived();
-        if (session->isSpeculative()) {
-            mechCounter.incSpeculativeAuthenticateReceived();
-        }
-
-        reply = doSaslStart(opCtx, session, request, &principalName);
-
-        if (session->isClusterMember()) {
-            mechCounter.incClusterAuthenticateReceived();
-        }
-        if (session->getMechanism()->isSuccess()) {
-            mechCounter.incAuthenticateSuccessful();
-            if (session->isClusterMember()) {
-                mechCounter.incClusterAuthenticateSuccessful();
-            }
-            if (session->isSpeculative()) {
-                mechCounter.incSpeculativeAuthenticateSuccessful();
-            }
-            audit::logAuthentication(
-                client, mechanismName, UserName(principalName, db), ErrorCodes::OK);
-        }
-    } catch (const AssertionException& ex) {
-        audit::logAuthentication(client, mechanismName, UserName(principalName, db), ex.code());
-        throw;
-    }
+    // Note that while updateDatabase can throw, it should not be able to for saslStart.
+    session->updateDatabase(request.getDbName());
+    session->setMechanismName(request.getMechanism());
 
-    return reply;
+    return doSaslStart(opCtx, session, request);
 }
 
 SaslReply runSaslContinue(OperationContext* opCtx,
@@ -291,45 +249,12 @@ SaslReply runSaslContinue(OperationContext* opCtx,
                           AuthenticationSession* session,
                           const SaslContinueCommand& cmd) {
     opCtx->markKillOnClientDisconnect();
-    auto* client = Client::getCurrent();
-
-    auto mechanismPtr = session->getMechanism();
-    invariant(mechanismPtr);
-    auto& mechanism = *mechanismPtr;
-
-    // Authenticating the __system@local user to the admin database on mongos is required
-    // by the auth passthrough test suite.
-    if (mechanism.getAuthenticationDatabase() != cmd.getDbName() && !getTestCommandsEnabled()) {
-        uasserted(ErrorCodes::ProtocolError,
-                  "Attempt to switch database target during SASL authentication.");
-    }
 
     uassert(ErrorCodes::ProtocolError,
             "sasl: Mismatched conversation id",
             cmd.getConversationId() == 1);
 
-    auto swReply = doSaslStep(opCtx, cmd.getPayload(), session);
-
-    if (mechanism.isSuccess() || !swReply.isOK()) {
-        audit::logAuthentication(
-            client,
-            mechanism.mechanismName(),
-            UserName(mechanism.getPrincipalName(), mechanism.getAuthenticationDatabase()),
-            swReply.getStatus().code());
-
-        auto mechCounter = authCounter.getMechanismCounter(mechanism.mechanismName());
-        if (mechanism.isSuccess()) {
-            mechCounter.incAuthenticateSuccessful();
-            if (mechanism.isClusterMember()) {
-                mechCounter.incClusterAuthenticateSuccessful();
-            }
-            if (session->isSpeculative()) {
-                mechCounter.incSpeculativeAuthenticateSuccessful();
-            }
-        }
-    }
-
-    return uassertStatusOK(swReply);
+    return doSaslStep(opCtx, cmd.getPayload(), session);
 }
 
 constexpr auto kDBFieldName = "db"_sd;
diff --git a/src/mongo/db/auth/user_name.h b/src/mongo/db/auth/user_name.h
index e6c2d14db3e..81afb1895a3 100644
--- a/src/mongo/db/auth/user_name.h
+++ b/src/mongo/db/auth/user_name.h
@@ -70,14 +70,20 @@ public:
      * Gets the user part of a UserName.
      */
     StringData getUser() const {
-        return StringData(_fullName).substr(0, _splitPoint);
+        return StringData(_fullName.data(), _splitPoint);
     }
 
     /**
      * Gets the database name part of a UserName.
      */
     StringData getDB() const {
-        return StringData(_fullName).substr(_splitPoint + 1);
+        if (_fullName.empty()) {
+            return _fullName;
+        }
+
+        const auto offset = _splitPoint + 1;
+        invariant(offset <= _fullName.size());
+        return StringData(_fullName.data() + offset, _fullName.size() - offset);
     }
 
     /**