auditlog: add logins (#7546)

Add audit logging for login operation.

KIKIMR-21774

ydb/core/grpc_services/rpc_login.cpp

@@ -63,6 +63,7 @@ class TLoginRPC : public TRpcRequestActor<TLoginRPC, TEvLoginRequest, true> {
                 PipeClient = RegisterWithSameMailbox(pipe);
                 THolder<TEvSchemeShard::TEvLogin> request = MakeHolder<TEvSchemeShard::TEvLogin>();
                 request.Get()->Record = CreateLoginRequest(Credentials, AppData()->AuthConfig);
+                request.Get()->Record.SetPeerName(Request->GetPeerName());
                 NTabletPipe::SendData(SelfId(), PipeClient, request.Release());
                 return;
             }

ydb/core/protos/flat_tx_scheme.proto

@@ -144,14 +144,15 @@ message TEvUpdateConfigResult {
 
 message TEvLogin {
     optional string User = 1;
-    optional string Password = 2;
+    optional string Password = 2 [(Ydb.sensitive) = true];
     optional string ExternalAuth = 3;
     optional uint64 ExpiresAfterMs = 4;
+    optional string PeerName = 5;  // IP address actually, same as TEvModifySchemeTransaction.PeerName
 }
 
 message TEvLoginResult {
     optional string Error = 1;
-    optional string Token = 2;
+    optional string Token = 2;  // signed jwt token
 }
 
 // Sending actor registers itself to be notified when tx completes

ydb/core/security/login_page.cpp

@@ -113,6 +113,7 @@ class TLoginRequest : public NActors::TActorBootstrapped<TLoginRequest> {
         PipeClient = RegisterWithSameMailbox(pipe);
         THolder<TEvSchemeShard::TEvLogin> request = MakeHolder<TEvSchemeShard::TEvLogin>();
         request.Get()->Record = CreateLoginRequest(AuthCredentials, AppData()->AuthConfig);
+        request.Get()->Record.SetPeerName(Request->Address->ToString());
         NTabletPipe::SendData(SelfId(), PipeClient, request.Release());
     }
 

ydb/core/testlib/basics/runtime.cpp

@@ -17,6 +17,7 @@ namespace NActors {
     void TTestBasicRuntime::Initialize(TEgg egg)
     {
         AddICStuff();
+        AddAuditLogStuff();
 
         TTestActorRuntime::Initialize(std::move(egg));
     }
@@ -76,4 +77,21 @@ namespace NActors {
             }
         }
     }
+
+    void TTestBasicRuntime::AddAuditLogStuff()
+    {
+        if (AuditLogBackends) {
+            for (ui32 nodeIndex = 0; nodeIndex < GetNodeCount(); ++nodeIndex) {
+                AddLocalService(
+                    NKikimr::NAudit::MakeAuditServiceID(),
+                    TActorSetupCmd(
+                        NKikimr::NAudit::CreateAuditWriter(std::move(AuditLogBackends)).Release(),
+                        TMailboxType::HTSwap,
+                        0
+                    ),
+                    nodeIndex
+                );
+            }
+        }
+    }
 }

ydb/core/testlib/basics/runtime.h

@@ -1,5 +1,6 @@
 #pragma once
 
+#include <ydb/core/audit/audit_log_service.h>
 #include <ydb/core/testlib/actors/test_runtime.h>
 #include <ydb/library/actors/interconnect/interconnect.h>
 
@@ -12,9 +13,13 @@ namespace NActors {
         using TNodeLocationCallback = std::function<TNodeLocation(ui32)>;
         TNodeLocationCallback LocationCallback;
 
+        NKikimr::NAudit::TAuditLogBackends AuditLogBackends;
+
         ~TTestBasicRuntime();
 
         void Initialize(TEgg) override;
+
         void AddICStuff();
+        void AddAuditLogStuff();
     };
 }

ydb/core/tx/schemeshard/schemeshard__login.cpp

@@ -1,7 +1,9 @@
-#include "schemeshard_impl.h"
 #include <ydb/library/security/util.h>
 #include <ydb/core/protos/auth.pb.h>
 
+#include "schemeshard_audit_log.h"
+#include "schemeshard_impl.h"
+
 namespace NKikimr {
 namespace NSchemeShard {
 
@@ -76,13 +78,16 @@ struct TSchemeShard::TTxLogin : TSchemeShard::TRwTxBase {
         THolder<TEvSchemeShard::TEvLoginResult> result = MakeHolder<TEvSchemeShard::TEvLoginResult>();
         const auto& loginRequest = GetLoginRequest();
         if (loginRequest.ExternalAuth || AppData(ctx)->AuthConfig.GetEnableLoginAuthentication()) {
-            NLogin::TLoginProvider::TLoginUserResponse LoginResponse = Self->LoginProvider.LoginUser(loginRequest);
-            if (LoginResponse.Error) {
-                result->Record.SetError(LoginResponse.Error);
+            NLogin::TLoginProvider::TLoginUserResponse loginResponse = Self->LoginProvider.LoginUser(loginRequest);
+            if (loginResponse.Error) {
+                result->Record.SetError(loginResponse.Error);
             }
-            if (LoginResponse.Token) {
-                result->Record.SetToken(LoginResponse.Token);
+            if (loginResponse.Token) {
+                result->Record.SetToken(loginResponse.Token);
             }
+
+            AuditLogLogin(Request->Get()->Record, result->Record, Self);
+
         } else {
             result->Record.SetError("Login authentication is disabled");
         }

ydb/core/tx/schemeshard/schemeshard_audit_log.cpp

@@ -9,6 +9,13 @@
 
 namespace NKikimr::NSchemeShard {
 
+namespace {
+    const TString SchemeshardComponentName = "schemeshard";
+
+    //NOTE: EmptyValue couldn't be an empty string as AUDIT_PART() skips parts with an empty values
+    const TString EmptyValue = "{none}";
+}
+
 TString GeneralStatus(NKikimrScheme::EStatus actualStatus) {
     switch(actualStatus) {
         case NKikimrScheme::EStatus::StatusAlreadyExists:
@@ -62,11 +69,6 @@ TPath DatabasePathFromWorkingDir(TSchemeShard* SS, const TString &opWorkingDir)
 }
 
 void AuditLogModifySchemeTransaction(const NKikimrScheme::TEvModifySchemeTransaction& request, const NKikimrScheme::TEvModifySchemeTransactionResult& response, TSchemeShard* SS, const TString& userSID) {
-    static const TString SchemeshardComponentName = "schemeshard";
-
-    //NOTE: EmptyValue couldn't be an empty string as AUDIT_PART() skips parts with an empty values
-    static const TString EmptyValue = "{none}";
-
     // Each TEvModifySchemeTransaction.Transaction is a self sufficient operation and should be logged independently
     // (even if it was packed into a single TxProxy transaction with some other operations).
     for (const auto& operation : request.GetTransaction()) {
@@ -79,7 +81,7 @@ void AuditLogModifySchemeTransaction(const NKikimrScheme::TEvModifySchemeTransac
         AUDIT_LOG(
             AUDIT_PART("component", SchemeshardComponentName)
             AUDIT_PART("tx_id", std::to_string(request.GetTxId()))
-            AUDIT_PART("remote_address", (!peerName.empty() ? peerName : EmptyValue) )
+            AUDIT_PART("remote_address", (!peerName.empty() ? peerName : EmptyValue))
             AUDIT_PART("subject", (!userSID.empty() ? userSID : EmptyValue))
             AUDIT_PART("database", (!databasePath.IsEmpty() ? databasePath.GetDomainPathString() : EmptyValue))
             AUDIT_PART("operation", logEntry.Operation)
@@ -165,4 +167,24 @@ void AuditLogModifySchemeTransactionDeprecated(const NKikimrScheme::TEvModifySch
     }
 }
 
+void AuditLogLogin(const NKikimrScheme::TEvLogin& request, const NKikimrScheme::TEvLoginResult& response, TSchemeShard* SS) {
+    static const TString LoginOperationName = "LOGIN";
+
+    TPath databasePath = TPath::Root(SS);
+    auto peerName = NKikimr::NAddressClassifier::ExtractAddress(request.GetPeerName());
+
+    AUDIT_LOG(
+        AUDIT_PART("component", SchemeshardComponentName)
+        AUDIT_PART("remote_address", (!peerName.empty() ? peerName : EmptyValue))
+        AUDIT_PART("database", (!databasePath.PathString().empty() ? databasePath.PathString() : EmptyValue))
+        AUDIT_PART("operation", LoginOperationName)
+        AUDIT_PART("status", TString(response.GetError().empty() ? "SUCCESS" : "ERROR"))
+        AUDIT_PART("reason", response.GetError(), response.HasError())
+
+        // Login
+        AUDIT_PART("login_user", (request.HasUser() ? request.GetUser() : EmptyValue))
+        AUDIT_PART("login_auth_domain", (!request.GetExternalAuth().empty() ? request.GetExternalAuth() : EmptyValue))
+    );
+}
+
 }

ydb/core/tx/schemeshard/schemeshard_audit_log.h

@@ -5,6 +5,9 @@
 namespace NKikimrScheme {
 class TEvModifySchemeTransaction;
 class TEvModifySchemeTransactionResult;
+
+class TEvLogin;
+class TEvLoginResult;
 }
 
 namespace NKikimr::NSchemeShard {
@@ -14,4 +17,5 @@ class TSchemeShard;
 void AuditLogModifySchemeTransaction(const NKikimrScheme::TEvModifySchemeTransaction& request, const NKikimrScheme::TEvModifySchemeTransactionResult& response, TSchemeShard* SS, const TString& userSID);
 void AuditLogModifySchemeTransactionDeprecated(const NKikimrScheme::TEvModifySchemeTransaction& request, const NKikimrScheme::TEvModifySchemeTransactionResult& response, TSchemeShard* SS, const TString& userSID);
 
+void AuditLogLogin(const NKikimrScheme::TEvLogin& request, const NKikimrScheme::TEvLoginResult& response, TSchemeShard* SS);
 }

ydb/core/tx/schemeshard/ut_login/ut_login.cpp

@@ -1,3 +1,5 @@
+#include <util/string/join.h>
+
 #include <ydb/core/tx/schemeshard/ut_helpers/helpers.h>
 #include <ydb/library/login/login.h>
 #include <ydb/core/protos/auth.pb.h>
@@ -6,15 +8,47 @@ using namespace NKikimr;
 using namespace NSchemeShard;
 using namespace NSchemeShardUT_Private;
 
+namespace NSchemeShardUT_Private {
+
+// convert into generic test helper?
+void TestCreateAlterLoginCreateUser(TTestActorRuntime& runtime, ui64 txId, const TString& database, const TString& user, const TString& password, const TVector<TExpectedResult>& expectedResults) {
+    std::unique_ptr<TEvSchemeShard::TEvModifySchemeTransaction> modifyTx(CreateAlterLoginCreateUser(txId, user, password));
+    //TODO: move setting of TModifyScheme.WorkingDir into CreateAlterLoginCreateUser()
+    //NOTE: TModifyScheme.Name isn't set, intentionally
+    modifyTx->Record.MutableTransaction(0)->SetWorkingDir(database);
+    AsyncSend(runtime, TTestTxConfig::SchemeShard, modifyTx.release());
+    // AlterLoginCreateUser is synchronous in nature, result is returned immediately
+    TestModificationResults(runtime, txId, expectedResults);
+}
+
+}  // namespace NSchemeShardUT_Private
+
+namespace {
+
+class TMemoryLogBackend: public TLogBackend {
+public:
+    std::vector<std::string>& Buffer;
+
+    TMemoryLogBackend(std::vector<std::string>& buffer)
+        : Buffer(buffer)
+    {}
+
+    virtual void WriteData(const TLogRecord& rec) override {
+        Buffer.emplace_back(rec.Data, rec.Len);
+    }
+
+    virtual void ReopenLog() override {
+    }
+};
+
+}  // anonymous namespace
+
 Y_UNIT_TEST_SUITE(TSchemeShardLoginTest) {
     Y_UNIT_TEST(BasicLogin) {
         TTestBasicRuntime runtime;
         TTestEnv env(runtime);
         ui64 txId = 100;
-        TActorId sender = runtime.AllocateEdgeActor();
-        std::unique_ptr<TEvSchemeShard::TEvModifySchemeTransaction> transaction(CreateAlterLoginCreateUser(++txId, "user1", "password1"));
-        transaction->Record.MutableTransaction(0)->SetWorkingDir("/MyRoot");
-        ForwardToTablet(runtime, TTestTxConfig::SchemeShard, sender, transaction.release());
+        TestCreateAlterLoginCreateUser(runtime, ++txId, "/MyRoot", "user1", "password1", {{NKikimrScheme::StatusSuccess}});
         auto resultLogin = Login(runtime, "user1", "password1");
         UNIT_ASSERT_VALUES_EQUAL(resultLogin.error(), "");
         auto describe = DescribePath(runtime, TTestTxConfig::SchemeShard, "/MyRoot");
@@ -35,10 +69,7 @@ Y_UNIT_TEST_SUITE(TSchemeShardLoginTest) {
         TTestEnv env(runtime);
         runtime.GetAppData().AuthConfig.SetEnableLoginAuthentication(false);
         ui64 txId = 100;
-        TActorId sender = runtime.AllocateEdgeActor();
-        std::unique_ptr<TEvSchemeShard::TEvModifySchemeTransaction> transaction(CreateAlterLoginCreateUser(++txId, "user1", "password1"));
-        transaction->Record.MutableTransaction(0)->SetWorkingDir("/MyRoot");
-        ForwardToTablet(runtime, TTestTxConfig::SchemeShard, sender, transaction.release());
+        TestCreateAlterLoginCreateUser(runtime, ++txId, "/MyRoot", "user1", "password1", {{NKikimrScheme::StatusPreconditionFailed}});
         auto resultLogin = Login(runtime, "user1", "password1");
         UNIT_ASSERT_VALUES_EQUAL(resultLogin.error(), "Login authentication is disabled");
         UNIT_ASSERT_VALUES_EQUAL(resultLogin.token(), "");
@@ -48,4 +79,78 @@ Y_UNIT_TEST_SUITE(TSchemeShardLoginTest) {
         UNIT_ASSERT(describe.GetPathDescription().GetDomainDescription().HasSecurityState());
         UNIT_ASSERT(describe.GetPathDescription().GetDomainDescription().GetSecurityState().PublicKeysSize() > 0);
     }
+
+    NAudit::TAuditLogBackends CreateTestAuditLogBackends(std::vector<std::string>& buffer) {
+        NAudit::TAuditLogBackends logBackends;
+        logBackends[NKikimrConfig::TAuditConfig::TXT].emplace_back(new TMemoryLogBackend(buffer));
+        return logBackends;
+    }
+
+    Y_UNIT_TEST(AuditLogLoginSuccess) {
+        TTestBasicRuntime runtime;
+        std::vector<std::string> lines;
+        runtime.AuditLogBackends = std::move(CreateTestAuditLogBackends(lines));
+        TTestEnv env(runtime);
+
+        UNIT_ASSERT_VALUES_EQUAL(lines.size(), 1);   // alter root subdomain
+
+        ui64 txId = 100;
+
+        TestCreateAlterLoginCreateUser(runtime, ++txId, "/MyRoot", "user1", "password1", {{NKikimrScheme::StatusSuccess}});
+        UNIT_ASSERT_VALUES_EQUAL(lines.size(), 2);   // +user creation
+
+        // test body
+        {
+            auto resultLogin = Login(runtime, "user1", "password1");
+            UNIT_ASSERT_C(resultLogin.error().empty(), resultLogin);
+        }
+        UNIT_ASSERT_VALUES_EQUAL(lines.size(), 3);   // +user login
+
+        Cerr << "auditlog lines:\n" << JoinSeq('\n', lines) << Endl;
+        auto last = lines[lines.size() - 1];
+        Cerr << "auditlog last line:\n" << last << Endl;
+
+        UNIT_ASSERT_STRING_CONTAINS(last, "component=schemeshard");
+        UNIT_ASSERT_STRING_CONTAINS(last, "remote_address=");  // can't check the value
+        UNIT_ASSERT_STRING_CONTAINS(last, "database=/MyRoot");
+        UNIT_ASSERT_STRING_CONTAINS(last, "operation=LOGIN");
+        UNIT_ASSERT_STRING_CONTAINS(last, "status=SUCCESS");
+        UNIT_ASSERT(!last.contains("reason"));
+        UNIT_ASSERT_STRING_CONTAINS(last, "login_user=user1");
+        UNIT_ASSERT_STRING_CONTAINS(last, "login_auth_domain={none}");
+    }
+
+    Y_UNIT_TEST(AuditLogLoginFailure) {
+        TTestBasicRuntime runtime;
+        std::vector<std::string> lines;
+        runtime.AuditLogBackends = std::move(CreateTestAuditLogBackends(lines));
+        TTestEnv env(runtime);
+
+        UNIT_ASSERT_VALUES_EQUAL(lines.size(), 1);   // alter root subdomain
+
+        ui64 txId = 100;
+
+        TestCreateAlterLoginCreateUser(runtime, ++txId, "/MyRoot", "user1", "password1", {{NKikimrScheme::StatusSuccess}});
+        UNIT_ASSERT_VALUES_EQUAL(lines.size(), 2);   // +user creation
+
+        // test body
+        {
+            auto resultLogin = Login(runtime, "user1", "bad_password");
+            UNIT_ASSERT_C(!resultLogin.error().empty(), resultLogin);
+        }
+        UNIT_ASSERT_VALUES_EQUAL(lines.size(), 3);   // +user login
+
+        Cerr << "auditlog lines:\n" << JoinSeq('\n', lines) << Endl;
+        auto last = lines[lines.size() - 1];
+        Cerr << "auditlog last line:\n" << last << Endl;
+
+        UNIT_ASSERT_STRING_CONTAINS(last, "component=schemeshard");
+        UNIT_ASSERT_STRING_CONTAINS(last, "remote_address=");  // can't check the value
+        UNIT_ASSERT_STRING_CONTAINS(last, "database=/MyRoot");
+        UNIT_ASSERT_STRING_CONTAINS(last, "operation=LOGIN");
+        UNIT_ASSERT_STRING_CONTAINS(last, "status=ERROR");
+        UNIT_ASSERT_STRING_CONTAINS(last, "reason=Invalid password");
+        UNIT_ASSERT_STRING_CONTAINS(last, "login_user=user1");
+        UNIT_ASSERT_STRING_CONTAINS(last, "login_auth_domain={none}");
+    }
 }

ydb/services/auth/grpc_service.cpp

@@ -32,18 +32,21 @@ void TGRpcAuthService::SetupIncomingRequests(NYdbGrpc::TLoggerPtr logger) {
 #error ADD_REQUEST macro already defined
 #endif
 
-#define ADD_REQUEST_LIMIT(NAME, CB, LIMIT_TYPE) \
+#define ADD_REQUEST_LIMIT(NAME, CB, RATE_LIMITER_MODE, AUDIT_MODE) \
     MakeIntrusive<TGRpcRequest<Ydb::Auth::NAME##Request, Ydb::Auth::NAME##Response, TGRpcAuthService>>     \
         (this, this->GetService(), CQ_,                                                                    \
             [this](NYdbGrpc::IRequestContextBase *ctx) {                                                   \
                 NGRpcService::ReportGrpcReqToMon(*ActorSystem_, ctx->GetPeer(), GetSdkBuildInfo(ctx));     \
                 ActorSystem_->Send(GRpcRequestProxyId_,                                                    \
                     new TGrpcRequestOperationCall<Ydb::Auth::NAME##Request, Ydb::Auth::NAME##Response>     \
-                        (ctx, &CB, TRequestAuxSettings{TRateLimiterMode::LIMIT_TYPE, nullptr}));           \
+                        (ctx, &CB, TRequestAuxSettings{                                                    \
+                            .RlMode = RATE_LIMITER_MODE,                                                   \
+                            .AuditMode = AUDIT_MODE,                                                       \
+                        }));                                                                               \
             }, &Ydb::Auth::V1::AuthService::AsyncService::Request ## NAME,                                 \
             #NAME, logger, getCounterBlock("login", #NAME))->Run();
 
-    ADD_REQUEST_LIMIT(Login, DoLoginRequest, Off)
+    ADD_REQUEST_LIMIT(Login, DoLoginRequest, TRateLimiterMode::Off, TAuditMode::Auditable)
 
 #undef ADD_REQUEST_LIMIT