Skip to content

Commit ecf893c

Browse files
ijonijon
committed
auditlog: fix logging for unsuccessful ldap logins (#11438)
Move audit logging of login operations from schemeshard to grpc service auth (`AuthService`). Update web-login service login to utilize `AuthService.Login`. Establish `AuthService` as the sole gateway and single audit point for all login operations. KIKIMR-22173
1 parent 8133d2b commit ecf893c

File tree

12 files changed

+700
-235
lines changed

12 files changed

+700
-235
lines changed

‎ydb/core/grpc_services/audit_logins.cpp‎

Lines changed: 59 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,59 @@
1+
#include "defs.h"
2+
3+
#include <ydb/core/util/address_classifier.h>
4+
#include <ydb/core/audit/audit_log.h>
5+
6+
#include <ydb/public/api/protos/ydb_auth.pb.h>
7+
8+
#include "base/base.h"
9+
#include "audit_logins.h"
10+
11+
namespace NKikimr {
12+
namespace NGRpcService {
13+
14+
void AuditLogLogin(IAuditCtx* ctx, const TString& database, const Ydb::Auth::LoginRequest& request, const Ydb::Auth::LoginResponse& response, const TString& errorDetails)
15+
{
16+
static const TString GrpcLoginComponentName = "grpc-login";
17+
static const TString LoginOperationName = "LOGIN";
18+
19+
//NOTE: EmptyValue couldn't be an empty string as AUDIT_PART() skips parts with an empty values
20+
static const TString EmptyValue = "{none}";
21+
22+
auto peerName = NKikimr::NAddressClassifier::ExtractAddress(ctx->GetPeerName());
23+
24+
auto status = response.operation().status();
25+
TString detailed_status;
26+
TString reason;
27+
if (status != Ydb::StatusIds::SUCCESS) {
28+
detailed_status = Ydb::StatusIds::StatusCode_Name(status);
29+
if (response.operation().issues_size() > 0) {
30+
reason = response.operation().issues(0).message();
31+
}
32+
if (errorDetails) {
33+
if (!reason.empty()) {
34+
reason += ": ";
35+
}
36+
reason += errorDetails;
37+
}
38+
}
39+
40+
// NOTE: audit field set here must be in sync with ydb/core/security/login_page.cpp, AuditLogWebUILogout()
41+
AUDIT_LOG(
42+
AUDIT_PART("component", GrpcLoginComponentName)
43+
AUDIT_PART("remote_address", (!peerName.empty() ? peerName : EmptyValue))
44+
AUDIT_PART("database", (!database.empty() ? database : EmptyValue))
45+
AUDIT_PART("operation", LoginOperationName)
46+
AUDIT_PART("status", (status == Ydb::StatusIds::SUCCESS ? TString("SUCCESS") : TString("ERROR")))
47+
AUDIT_PART("detailed_status", detailed_status, status != Ydb::StatusIds::SUCCESS)
48+
AUDIT_PART("reason", reason, status != Ydb::StatusIds::SUCCESS)
49+
50+
// Login
51+
AUDIT_PART("login_user", (!request.user().empty() ? request.user() : EmptyValue))
52+
53+
//TODO: (?) it is possible to show masked version of the resulting token here
54+
);
55+
}
56+
57+
}
58+
}
59+

‎ydb/core/grpc_services/audit_logins.h‎

Lines changed: 18 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,18 @@
1+
#pragma once
2+
#include "defs.h"
3+
4+
namespace Ydb::Auth {
5+
6+
class LoginRequest;
7+
class LoginResponse;
8+
9+
}
10+
11+
namespace NKikimr::NGRpcService {
12+
13+
class IAuditCtx;
14+
15+
// logins log
16+
void AuditLogLogin(IAuditCtx* ctx, const TString& database, const Ydb::Auth::LoginRequest& request, const Ydb::Auth::LoginResponse& response, const TString& errorDetails);
17+
18+
} // namespace NKikimr::NGRpcService

‎ydb/core/grpc_services/rpc_login.cpp‎

Lines changed: 55 additions & 42 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
#include "grpc_request_proxy.h"
22
#include "service_auth.h"
3+
#include "audit_logins.h"
34

45
#include "rpc_request_base.h"
56

@@ -28,8 +29,6 @@ class TLoginRPC : public TRpcRequestActor<TLoginRPC, TEvLoginRequest, true> {
2829
public:
2930
using TRpcRequestActor::TRpcRequestActor;
3031

31-
THolder<TEvSchemeShard::TEvLoginResult> Result;
32-
Ydb::StatusIds_StatusCode Status = Ydb::StatusIds::SUCCESS;
3332
TDuration Timeout = TDuration::MilliSeconds(60000);
3433
TActorId PipeClient;
3534

@@ -50,8 +49,7 @@ class TLoginRPC : public TRpcRequestActor<TLoginRPC, TEvLoginRequest, true> {
5049
}
5150

5251
void HandleTimeout() {
53-
Status = Ydb::StatusIds::TIMEOUT;
54-
ReplyAndPassAway();
52+
ReplyErrorAndPassAway(Ydb::StatusIds::TIMEOUT, "Login timeout");
5553
}
5654

5755
void HandleNavigate(TEvTxProxySchemeCache::TEvNavigateKeySetResult::TPtr& ev) {
@@ -68,42 +66,39 @@ class TLoginRPC : public TRpcRequestActor<TLoginRPC, TEvLoginRequest, true> {
6866
return;
6967
}
7068
}
71-
Status = Ydb::StatusIds::SCHEME_ERROR;
72-
ReplyAndPassAway();
69+
ReplyErrorAndPassAway(Ydb::StatusIds::SCHEME_ERROR, "No database found");
7370
}
7471

7572
void Handle(TEvLdapAuthProvider::TEvAuthenticateResponse::TPtr& ev) {
76-
TEvLdapAuthProvider::TEvAuthenticateResponse* response = ev->Get();
77-
if (response->Status == TEvLdapAuthProvider::EStatus::SUCCESS) {
73+
const TEvLdapAuthProvider::TEvAuthenticateResponse& response = *ev->Get();
74+
if (response.Status == TEvLdapAuthProvider::EStatus::SUCCESS) {
7875
Send(MakeSchemeCacheID(), new TEvTxProxySchemeCache::TEvNavigateKeySet(CreateNavigateKeySetRequest(PathToDatabase).Release()));
7976
} else {
80-
TResponse loginResponse;
81-
Ydb::Operations::Operation& operation = *loginResponse.mutable_operation();
82-
Ydb::Issue::IssueMessage* issue = operation.add_issues();
83-
issue->set_message(response->Error.Message);
84-
Status = ConvertLdapStatus(response->Status);
85-
issue->set_issue_code(Status);
86-
operation.set_ready(true);
87-
operation.set_status(Status);
88-
Reply(loginResponse);
77+
ReplyErrorAndPassAway(ConvertLdapStatus(response.Status), response.Error.Message, response.Error.LogMessage);
8978
}
9079
}
9180

9281
void HandleResult(TEvSchemeShard::TEvLoginResult::TPtr& ev) {
93-
Status = Ydb::StatusIds::SUCCESS;
94-
Result = ev->Release();
95-
ReplyAndPassAway();
82+
const NKikimrScheme::TEvLoginResult& loginResult = ev->Get()->Record;
83+
if (loginResult.error()) {
84+
// explicit error takes precedence
85+
ReplyErrorAndPassAway(Ydb::StatusIds::UNAUTHORIZED, loginResult.error(), /*loginResult.details()*/ TString());
86+
} else if (loginResult.token().empty()) {
87+
// empty token is still an error
88+
ReplyErrorAndPassAway(Ydb::StatusIds::INTERNAL_ERROR, "Failed to produce a token");
89+
} else {
90+
// success = token + no errors
91+
ReplyAndPassAway(loginResult.token());
92+
}
9693
}
9794

9895
void HandleUndelivered(TEvents::TEvUndelivered::TPtr&) {
99-
Status = Ydb::StatusIds::UNAVAILABLE;
100-
ReplyAndPassAway();
96+
ReplyErrorAndPassAway(Ydb::StatusIds::UNAVAILABLE, "SchemeShard is unreachable");
10197
}
10298

10399
void HandleConnect(TEvTabletPipe::TEvClientConnected::TPtr& ev) {
104100
if (ev->Get()->Status != NKikimrProto::OK) {
105-
Status = Ydb::StatusIds::UNAVAILABLE;
106-
ReplyAndPassAway();
101+
ReplyErrorAndPassAway(Ydb::StatusIds::UNAVAILABLE, "SchemeShard is unavailable");
107102
}
108103
}
109104

@@ -118,28 +113,46 @@ class TLoginRPC : public TRpcRequestActor<TLoginRPC, TEvLoginRequest, true> {
118113
}
119114
}
120115

121-
void ReplyAndPassAway() {
122-
if (PipeClient) {
123-
NTabletPipe::CloseClient(SelfId(), PipeClient);
124-
}
116+
void ReplyAndPassAway(const TString& resultToken) {
125117
TResponse response;
118+
126119
Ydb::Operations::Operation& operation = *response.mutable_operation();
127-
if (Result) {
128-
const NKikimrScheme::TEvLoginResult& record = Result->Record;
129-
if (record.error()) {
130-
Ydb::Issue::IssueMessage* issue = operation.add_issues();
131-
issue->set_message(record.error());
132-
issue->set_issue_code(Ydb::StatusIds::UNAUTHORIZED);
133-
Status = Ydb::StatusIds::UNAUTHORIZED;
134-
}
135-
if (record.token()) {
136-
Ydb::Auth::LoginResult result;
137-
result.set_token(record.token());
138-
operation.mutable_result()->PackFrom(result);
139-
}
120+
operation.set_ready(true);
121+
operation.set_status(Ydb::StatusIds::SUCCESS);
122+
// Pack result to google::protobuf::Any
123+
{
124+
Ydb::Auth::LoginResult result;
125+
result.set_token(resultToken);
126+
operation.mutable_result()->PackFrom(result);
140127
}
128+
129+
AuditLogLogin(Request.Get(), PathToDatabase, *GetProtoRequest(), response, /* errorDetails */ TString());
130+
131+
return CleanupAndReply(response);
132+
}
133+
134+
void ReplyErrorAndPassAway(const Ydb::StatusIds_StatusCode status, const TString& error, const TString& reason = "") {
135+
TResponse response;
136+
137+
Ydb::Operations::Operation& operation = *response.mutable_operation();
141138
operation.set_ready(true);
142-
operation.set_status(Status);
139+
operation.set_status(status);
140+
if (error) {
141+
Ydb::Issue::IssueMessage* issue = operation.add_issues();
142+
issue->set_issue_code(status);
143+
issue->set_message(error);
144+
}
145+
146+
AuditLogLogin(Request.Get(), PathToDatabase, *GetProtoRequest(), response, reason);
147+
148+
return CleanupAndReply(response);
149+
}
150+
151+
void CleanupAndReply(const TResponse& response) {
152+
if (PipeClient) {
153+
NTabletPipe::CloseClient(SelfId(), PipeClient);
154+
}
155+
143156
return Reply(response);
144157
}
145158

‎ydb/core/grpc_services/ya.make‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ LIBRARY()
33
SRCS(
44
audit_log.cpp
55
audit_dml_operations.cpp
6+
audit_logins.cpp
67
db_metadata_cache.h
78
grpc_endpoint_publish_actor.cpp
89
grpc_helper.cpp

‎ydb/core/security/ldap_auth_provider/ldap_auth_provider.cpp‎

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -179,6 +179,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
179179
if (!NKikimrLdap::IsSuccess(result)) {
180180
TStringBuilder logErrorMessage;
181181
logErrorMessage << "Could not start TLS. " << NKikimrLdap::ErrorToString(result);
182+
LDAP_LOG_D(logErrorMessage);
182183
TEvLdapAuthProvider::TError error {
183184
.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = NKikimrLdap::IsRetryableError(result)
184185
};
@@ -194,6 +195,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
194195
TStringBuilder logErrorMessage;
195196
logErrorMessage << "Could not perform initial LDAP bind for dn " << Settings.GetBindDn() << " on server " + UrisCreator.GetUris() << ". "
196197
<< NKikimrLdap::ErrorToString(result);
198+
LDAP_LOG_D(logErrorMessage);
197199
TEvLdapAuthProvider::TError error {
198200
.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = NKikimrLdap::IsRetryableError(result)
199201
};
@@ -217,6 +219,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
217219
if (!NKikimrLdap::IsSuccess(result)) {
218220
TStringBuilder logErrorMessage;
219221
logErrorMessage << "Could not set LDAP ca file \"" << caCertificateFile + "\": " << NKikimrLdap::ErrorToString(result);
222+
LDAP_LOG_D(logErrorMessage);
220223
NKikimrLdap::Unbind(*ld);
221224
return {{NKikimrLdap::ErrorToStatus(result),
222225
{.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = NKikimrLdap::IsRetryableError(result)}}};
@@ -227,6 +230,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
227230
if (!NKikimrLdap::IsSuccess(result)) {
228231
TStringBuilder logErrorMessage;
229232
logErrorMessage << "Could not initialize LDAP connection for uris: " << UrisCreator.GetUris() << ". " << NKikimrLdap::LdapError(*ld);
233+
LDAP_LOG_D(logErrorMessage);
230234
return {{TEvLdapAuthProvider::EStatus::UNAVAILABLE,
231235
{.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = false}}};
232236
}
@@ -236,6 +240,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
236240
NKikimrLdap::Unbind(*ld);
237241
TStringBuilder logErrorMessage;
238242
logErrorMessage << "Could not set LDAP protocol version: " << NKikimrLdap::ErrorToString(result);
243+
LDAP_LOG_D(logErrorMessage);
239244
return {{NKikimrLdap::ErrorToStatus(result),
240245
{.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = NKikimrLdap::IsRetryableError(result)}}};
241246
}
@@ -247,6 +252,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
247252
NKikimrLdap::Unbind(*ld);
248253
TStringBuilder logErrorMessage;
249254
logErrorMessage << "Could not set require certificate option: " << NKikimrLdap::ErrorToString(result);
255+
LDAP_LOG_D(logErrorMessage);
250256
return {{NKikimrLdap::ErrorToStatus(result),
251257
{.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = NKikimrLdap::IsRetryableError(result)}}};
252258
}
@@ -261,12 +267,14 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
261267
TStringBuilder logErrorMessage;
262268
logErrorMessage << "Could not get dn for the first entry matching " << FilterCreator.GetFilter(request.Login)
263269
<< " on server " << UrisCreator.GetUris() << ". " << NKikimrLdap::LdapError(*request.Ld);
270+
LDAP_LOG_D(logErrorMessage);
264271
return {{TEvLdapAuthProvider::EStatus::UNAUTHORIZED,
265272
{.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = false}}};
266273
}
267274
if (request.Password.empty()) {
268275
TStringBuilder logErrorMessage;
269276
logErrorMessage << "LDAP login failed for user " << TString(dn) << ". Empty password";
277+
LDAP_LOG_D(logErrorMessage);
270278
NKikimrLdap::MemFree(dn);
271279
return {{.Status = TEvLdapAuthProvider::EStatus::UNAUTHORIZED, .Error = {.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = false}}};
272280
}
@@ -276,6 +284,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
276284
TStringBuilder logErrorMessage;
277285
logErrorMessage << "LDAP login failed for user " << TString(dn) << " on server " << UrisCreator.GetUris() << ". "
278286
<< NKikimrLdap::ErrorToString((result));
287+
LDAP_LOG_D(logErrorMessage);
279288
error.Message = ERROR_MESSAGE;
280289
error.LogMessage = logErrorMessage;
281290
error.Retryable = NKikimrLdap::IsRetryableError(result);
@@ -302,6 +311,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
302311
<< NKikimrLdap::ErrorToString(result);
303312
response.Status = NKikimrLdap::ErrorToStatus(result);
304313
response.Error = {.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = NKikimrLdap::IsRetryableError(result)};
314+
LDAP_LOG_D(logErrorMessage);
305315
return response;
306316
}
307317
const int countEntries = NKikimrLdap::CountEntries(request.Ld, searchMessage);
@@ -317,6 +327,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
317327
response.Error = {.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = false};
318328
response.Status = TEvLdapAuthProvider::EStatus::UNAUTHORIZED;
319329
NKikimrLdap::MsgFree(searchMessage);
330+
LDAP_LOG_D(logErrorMessage);
320331
return response;
321332
}
322333
response.SearchMessage = searchMessage;

0 commit comments

Comments
 (0)