24-3: auditlog: fix logging for unsuccessful ldap logins

ydb/core/base/ticket_parser.h

@@ -154,14 +154,24 @@ namespace NKikimr {
 
         struct TError {
             TString Message;
+            TString LogMessage;
             bool Retryable = true;
 
             bool empty() const {
-                return Message.empty();
+                return Message.empty() && LogMessage.empty();
+            }
+
+            bool HasMessage() const {
+                return !Message.empty();
+            }
+
+            bool HasLogMessage() const {
+                return !LogMessage.empty();
             }
 
             void clear() {
                 Message.clear();
+                LogMessage.clear();
                 Retryable = true;
             }
 

ydb/core/grpc_services/audit_logins.cpp

@@ -0,0 +1,59 @@
+#include "defs.h"
+
+#include <ydb/core/util/address_classifier.h>
+#include <ydb/core/audit/audit_log.h>
+
+#include <ydb/public/api/protos/ydb_auth.pb.h>
+
+#include "base/base.h"
+#include "audit_logins.h"
+
+namespace NKikimr {
+namespace NGRpcService {
+
+void AuditLogLogin(IAuditCtx* ctx, const TString& database, const Ydb::Auth::LoginRequest& request, const Ydb::Auth::LoginResponse& response, const TString& errorDetails)
+{
+    static const TString GrpcLoginComponentName = "grpc-login";
+    static const TString LoginOperationName = "LOGIN";
+
+    //NOTE: EmptyValue couldn't be an empty string as AUDIT_PART() skips parts with an empty values
+    static const TString EmptyValue = "{none}";
+
+    auto peerName = NKikimr::NAddressClassifier::ExtractAddress(ctx->GetPeerName());
+
+    auto status = response.operation().status();
+    TString detailed_status;
+    TString reason;
+    if (status != Ydb::StatusIds::SUCCESS) {
+        detailed_status = Ydb::StatusIds::StatusCode_Name(status);
+        if (response.operation().issues_size() > 0) {
+            reason = response.operation().issues(0).message();
+        }
+        if (errorDetails) {
+            if (!reason.empty()) {
+                reason += ": ";
+            }
+            reason += errorDetails;
+        }
+    }
+
+    // NOTE: audit field set here must be in sync with ydb/core/security/login_page.cpp, AuditLogWebUILogout()
+    AUDIT_LOG(
+        AUDIT_PART("component", GrpcLoginComponentName)
+        AUDIT_PART("remote_address", (!peerName.empty() ? peerName : EmptyValue))
+        AUDIT_PART("database", (!database.empty() ? database : EmptyValue))
+        AUDIT_PART("operation", LoginOperationName)
+        AUDIT_PART("status", (status == Ydb::StatusIds::SUCCESS ? TString("SUCCESS") : TString("ERROR")))
+        AUDIT_PART("detailed_status", detailed_status, status != Ydb::StatusIds::SUCCESS)
+        AUDIT_PART("reason", reason, status != Ydb::StatusIds::SUCCESS)
+
+        // Login
+        AUDIT_PART("login_user", (!request.user().empty() ? request.user() : EmptyValue))
+
+        //TODO: (?) it is possible to show masked version of the resulting token here
+    );
+}
+
+}
+}
+

ydb/core/grpc_services/audit_logins.h

@@ -0,0 +1,18 @@
+#pragma once
+#include "defs.h"
+
+namespace Ydb::Auth {
+
+class LoginRequest;
+class LoginResponse;
+
+}
+
+namespace NKikimr::NGRpcService {
+
+class IAuditCtx;
+
+// logins log
+void AuditLogLogin(IAuditCtx* ctx, const TString& database, const Ydb::Auth::LoginRequest& request, const Ydb::Auth::LoginResponse& response, const TString& errorDetails);
+
+} // namespace NKikimr::NGRpcService

ydb/core/grpc_services/rpc_login.cpp

@@ -1,5 +1,6 @@
 #include "grpc_request_proxy.h"
 #include "service_auth.h"
+#include "audit_logins.h"
 
 #include "rpc_request_base.h"
 
@@ -28,8 +29,6 @@ class TLoginRPC : public TRpcRequestActor<TLoginRPC, TEvLoginRequest, true> {
 public:
     using TRpcRequestActor::TRpcRequestActor;
 
-    THolder<TEvSchemeShard::TEvLoginResult> Result;
-    Ydb::StatusIds_StatusCode Status = Ydb::StatusIds::SUCCESS;
     TDuration Timeout = TDuration::MilliSeconds(60000);
     TActorId PipeClient;
 
@@ -50,8 +49,7 @@ class TLoginRPC : public TRpcRequestActor<TLoginRPC, TEvLoginRequest, true> {
     }
 
     void HandleTimeout() {
-        Status = Ydb::StatusIds::TIMEOUT;
-        ReplyAndPassAway();
+        ReplyErrorAndPassAway(Ydb::StatusIds::TIMEOUT, "Login timeout");
     }
 
     void HandleNavigate(TEvTxProxySchemeCache::TEvNavigateKeySetResult::TPtr& ev) {
@@ -68,42 +66,39 @@ class TLoginRPC : public TRpcRequestActor<TLoginRPC, TEvLoginRequest, true> {
                 return;
             }
         }
-        Status = Ydb::StatusIds::SCHEME_ERROR;
-        ReplyAndPassAway();
+        ReplyErrorAndPassAway(Ydb::StatusIds::SCHEME_ERROR, "No database found");
     }
 
     void Handle(TEvLdapAuthProvider::TEvAuthenticateResponse::TPtr& ev) {
-        TEvLdapAuthProvider::TEvAuthenticateResponse* response = ev->Get();
-        if (response->Status == TEvLdapAuthProvider::EStatus::SUCCESS) {
+        const TEvLdapAuthProvider::TEvAuthenticateResponse& response = *ev->Get();
+        if (response.Status == TEvLdapAuthProvider::EStatus::SUCCESS) {
             Send(MakeSchemeCacheID(), new TEvTxProxySchemeCache::TEvNavigateKeySet(CreateNavigateKeySetRequest(PathToDatabase).Release()));
         } else {
-            TResponse loginResponse;
-            Ydb::Operations::Operation& operation = *loginResponse.mutable_operation();
-            Ydb::Issue::IssueMessage* issue = operation.add_issues();
-            issue->set_message(response->Error.Message);
-            Status = ConvertLdapStatus(response->Status);
-            issue->set_issue_code(Status);
-            operation.set_ready(true);
-            operation.set_status(Status);
-            Reply(loginResponse);
+            ReplyErrorAndPassAway(ConvertLdapStatus(response.Status), response.Error.Message, response.Error.LogMessage);
         }
     }
 
     void HandleResult(TEvSchemeShard::TEvLoginResult::TPtr& ev) {
-        Status = Ydb::StatusIds::SUCCESS;
-        Result = ev->Release();
-        ReplyAndPassAway();
+        const NKikimrScheme::TEvLoginResult& loginResult = ev->Get()->Record;
+        if (loginResult.error()) {
+            // explicit error takes precedence
+            ReplyErrorAndPassAway(Ydb::StatusIds::UNAUTHORIZED, loginResult.error(), /*loginResult.details()*/ TString());
+        } else if (loginResult.token().empty()) {
+            // empty token is still an error
+            ReplyErrorAndPassAway(Ydb::StatusIds::INTERNAL_ERROR, "Failed to produce a token");
+        } else {
+            // success = token + no errors
+            ReplyAndPassAway(loginResult.token());
+        }
     }
 
     void HandleUndelivered(TEvents::TEvUndelivered::TPtr&) {
-        Status = Ydb::StatusIds::UNAVAILABLE;
-        ReplyAndPassAway();
+        ReplyErrorAndPassAway(Ydb::StatusIds::UNAVAILABLE, "SchemeShard is unreachable");
     }
 
     void HandleConnect(TEvTabletPipe::TEvClientConnected::TPtr& ev) {
         if (ev->Get()->Status != NKikimrProto::OK) {
-            Status = Ydb::StatusIds::UNAVAILABLE;
-            ReplyAndPassAway();
+            ReplyErrorAndPassAway(Ydb::StatusIds::UNAVAILABLE, "SchemeShard is unavailable");
         }
     }
 
@@ -118,28 +113,46 @@ class TLoginRPC : public TRpcRequestActor<TLoginRPC, TEvLoginRequest, true> {
         }
     }
 
-    void ReplyAndPassAway() {
-        if (PipeClient) {
-            NTabletPipe::CloseClient(SelfId(), PipeClient);
-        }
+    void ReplyAndPassAway(const TString& resultToken) {
         TResponse response;
+
         Ydb::Operations::Operation& operation = *response.mutable_operation();
-        if (Result) {
-            const NKikimrScheme::TEvLoginResult& record = Result->Record;
-            if (record.error()) {
-                Ydb::Issue::IssueMessage* issue = operation.add_issues();
-                issue->set_message(record.error());
-                issue->set_issue_code(Ydb::StatusIds::UNAUTHORIZED);
-                Status = Ydb::StatusIds::UNAUTHORIZED;
-            }
-            if (record.token()) {
-                Ydb::Auth::LoginResult result;
-                result.set_token(record.token());
-                operation.mutable_result()->PackFrom(result);
-            }
+        operation.set_ready(true);
+        operation.set_status(Ydb::StatusIds::SUCCESS);
+        // Pack result to google::protobuf::Any
+        {
+            Ydb::Auth::LoginResult result;
+            result.set_token(resultToken);
+            operation.mutable_result()->PackFrom(result);
         }
+
+        AuditLogLogin(Request.Get(), PathToDatabase, *GetProtoRequest(), response, /* errorDetails */ TString());
+
+        return CleanupAndReply(response);
+    }
+
+    void ReplyErrorAndPassAway(const Ydb::StatusIds_StatusCode status, const TString& error, const TString& reason = "") {
+        TResponse response;
+
+        Ydb::Operations::Operation& operation = *response.mutable_operation();
         operation.set_ready(true);
-        operation.set_status(Status);
+        operation.set_status(status);
+        if (error) {
+            Ydb::Issue::IssueMessage* issue = operation.add_issues();
+            issue->set_issue_code(status);
+            issue->set_message(error);
+        }
+
+        AuditLogLogin(Request.Get(), PathToDatabase, *GetProtoRequest(), response, reason);
+
+        return CleanupAndReply(response);
+    }
+
+    void CleanupAndReply(const TResponse& response) {
+        if (PipeClient) {
+            NTabletPipe::CloseClient(SelfId(), PipeClient);
+        }
+
         return Reply(response);
     }
 

ydb/core/grpc_services/ya.make

@@ -3,6 +3,7 @@ LIBRARY()
 SRCS(
     audit_log.cpp
     audit_dml_operations.cpp
+    audit_logins.cpp
     db_metadata_cache.h
     grpc_endpoint_publish_actor.cpp
     grpc_helper.cpp