Skip to content

Commit f9c53d9

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 171a671 commit f9c53d9

File tree

12 files changed

+700
-233
lines changed

12 files changed

+700
-233
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
@@ -181,6 +181,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
181181
if (!NKikimrLdap::IsSuccess(result)) {
182182
TStringBuilder logErrorMessage;
183183
logErrorMessage << "Could not start TLS. " << NKikimrLdap::ErrorToString(result);
184+
LDAP_LOG_D(logErrorMessage);
184185
TEvLdapAuthProvider::TError error {
185186
.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = NKikimrLdap::IsRetryableError(result)
186187
};
@@ -197,6 +198,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
197198
TStringBuilder logErrorMessage;
198199
logErrorMessage << "Could not perform initial LDAP bind for dn " << Settings.GetBindDn() << " on server " + UrisCreator.GetUris() << ". "
199200
<< NKikimrLdap::ErrorToString(result);
201+
LDAP_LOG_D(logErrorMessage);
200202
TEvLdapAuthProvider::TError error {
201203
.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = NKikimrLdap::IsRetryableError(result)
202204
};
@@ -220,6 +222,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
220222
if (!NKikimrLdap::IsSuccess(result)) {
221223
TStringBuilder logErrorMessage;
222224
logErrorMessage << "Could not set LDAP ca file \"" << caCertificateFile + "\": " << NKikimrLdap::ErrorToString(result);
225+
LDAP_LOG_D(logErrorMessage);
223226
NKikimrLdap::Unbind(*ld);
224227
return {{NKikimrLdap::ErrorToStatus(result),
225228
{.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = NKikimrLdap::IsRetryableError(result)}}};
@@ -231,6 +234,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
231234
if (!NKikimrLdap::IsSuccess(result)) {
232235
TStringBuilder logErrorMessage;
233236
logErrorMessage << "Could not initialize LDAP connection for uris: " << UrisCreator.GetUris() << ". " << NKikimrLdap::LdapError(*ld);
237+
LDAP_LOG_D(logErrorMessage);
234238
return {{TEvLdapAuthProvider::EStatus::UNAVAILABLE,
235239
{.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = false}}};
236240
}
@@ -240,6 +244,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
240244
NKikimrLdap::Unbind(*ld);
241245
TStringBuilder logErrorMessage;
242246
logErrorMessage << "Could not set LDAP protocol version: " << NKikimrLdap::ErrorToString(result);
247+
LDAP_LOG_D(logErrorMessage);
243248
return {{NKikimrLdap::ErrorToStatus(result),
244249
{.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = NKikimrLdap::IsRetryableError(result)}}};
245250
}
@@ -251,6 +256,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
251256
NKikimrLdap::Unbind(*ld);
252257
TStringBuilder logErrorMessage;
253258
logErrorMessage << "Could not set require certificate option: " << NKikimrLdap::ErrorToString(result);
259+
LDAP_LOG_D(logErrorMessage);
254260
return {{NKikimrLdap::ErrorToStatus(result),
255261
{.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = NKikimrLdap::IsRetryableError(result)}}};
256262
}
@@ -265,12 +271,14 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
265271
TStringBuilder logErrorMessage;
266272
logErrorMessage << "Could not get dn for the first entry matching " << FilterCreator.GetFilter(request.Login)
267273
<< " on server " << UrisCreator.GetUris() << ". " << NKikimrLdap::LdapError(*request.Ld);
274+
LDAP_LOG_D(logErrorMessage);
268275
return {{TEvLdapAuthProvider::EStatus::UNAUTHORIZED,
269276
{.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = false}}};
270277
}
271278
if (request.Password.empty()) {
272279
TStringBuilder logErrorMessage;
273280
logErrorMessage << "LDAP login failed for user " << TString(dn) << ". Empty password";
281+
LDAP_LOG_D(logErrorMessage);
274282
NKikimrLdap::MemFree(dn);
275283
return {{.Status = TEvLdapAuthProvider::EStatus::UNAUTHORIZED, .Error = {.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = false}}};
276284
}
@@ -281,6 +289,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
281289
TStringBuilder logErrorMessage;
282290
logErrorMessage << "LDAP login failed for user " << TString(dn) << " on server " << UrisCreator.GetUris() << ". "
283291
<< NKikimrLdap::ErrorToString((result));
292+
LDAP_LOG_D(logErrorMessage);
284293
error.Message = ERROR_MESSAGE;
285294
error.LogMessage = logErrorMessage;
286295
error.Retryable = NKikimrLdap::IsRetryableError(result);
@@ -311,6 +320,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
311320
<< NKikimrLdap::ErrorToString(result);
312321
response.Status = NKikimrLdap::ErrorToStatus(result);
313322
response.Error = {.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = NKikimrLdap::IsRetryableError(result)};
323+
LDAP_LOG_D(logErrorMessage);
314324
return response;
315325
}
316326
const int countEntries = NKikimrLdap::CountEntries(request.Ld, searchMessage);
@@ -326,6 +336,7 @@ class TLdapAuthProvider : public NActors::TActorBootstrapped<TLdapAuthProvider>
326336
response.Error = {.Message = ERROR_MESSAGE, .LogMessage = logErrorMessage, .Retryable = false};
327337
response.Status = TEvLdapAuthProvider::EStatus::UNAUTHORIZED;
328338
NKikimrLdap::MsgFree(searchMessage);
339+
LDAP_LOG_D(logErrorMessage);
329340
return response;
330341
}
331342
response.SearchMessage = searchMessage;

0 commit comments

Comments
 (0)