3 Authentication and authorization logging
5 Copyright (C) Andrew Bartlett <abartlet@samba.org> 2017
7 This program is free software; you can redistribute it and/or modify
8 it under the terms of the GNU General Public License as published by
9 the Free Software Foundation; either version 3 of the License, or
10 (at your option) any later version.
12 This program is distributed in the hope that it will be useful,
13 but WITHOUT ANY WARRANTY; without even the implied warranty of
14 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
15 GNU General Public License for more details.
17 You should have received a copy of the GNU General Public License
18 along with this program. If not, see <http://www.gnu.org/licenses/>.
22 * Debug log levels for authentication logging (these both map to
23 * LOG_NOTICE in syslog)
25 #define AUTH_FAILURE_LEVEL 2
26 #define AUTH_SUCCESS_LEVEL 3
27 #define AUTHZ_SUCCESS_LEVEL 4
29 /* 5 is used for both authentication and authorization */
30 #define AUTH_ANONYMOUS_LEVEL 5
31 #define AUTHZ_ANONYMOUS_LEVEL 5
33 #define AUTHZ_JSON_TYPE "Authorization"
34 #define AUTH_JSON_TYPE "Authentication"
37 * JSON message version numbers
39 * If adding a field increment the minor version
40 * If removing or changing the format/meaning of a field
41 * increment the major version.
49 #include "../lib/tsocket/tsocket.h"
50 #include "common_auth.h"
51 #include "lib/util/util_str_escape.h"
52 #include "libcli/security/dom_sid.h"
53 #include "libcli/security/security_token.h"
54 #include "librpc/gen_ndr/server_id.h"
55 #include "source4/lib/messaging/messaging.h"
56 #include "source4/lib/messaging/irpc.h"
57 #include "lib/util/server_id_db.h"
58 #include "lib/param/param.h"
61 * Get a human readable timestamp.
63 * Returns the current time formatted as
64 * "Tue, 14 Mar 2017 08:38:42.209028 NZDT"
66 * The returned string is allocated by talloc in the supplied context.
67 * It is the callers responsibility to free it.
70 static const char* get_timestamp(TALLOC_CTX *frame)
72 char buffer[40]; /* formatted time less usec and timezone */
73 char tz[10]; /* formatted time zone */
74 struct tm* tm_info; /* current local time */
75 struct timeval tv; /* current system time */
76 int r; /* response code from gettimeofday */
77 const char * ts; /* formatted time stamp */
79 r = gettimeofday(&tv, NULL);
81 DBG_ERR("Unable to get time of day: (%d) %s\n",
87 tm_info = localtime(&tv.tv_sec);
88 if (tm_info == NULL) {
89 DBG_ERR("Unable to determine local time\n");
93 strftime(buffer, sizeof(buffer)-1, "%a, %d %b %Y %H:%M:%S", tm_info);
94 strftime(tz, sizeof(tz)-1, "%Z", tm_info);
95 ts = talloc_asprintf(frame, "%s.%06ld %s", buffer, tv.tv_usec, tz);
97 DBG_ERR("Out of memory formatting time stamp\n");
103 * Determine the type of the password supplied for the
104 * authorisation attempt.
107 static const char* get_password_type(const struct auth_usersupplied_info *ui);
112 #include "system/time.h"
115 * Context required by the JSON generation
119 struct json_context {
124 static NTSTATUS get_auth_event_server(struct imessaging_context *msg_ctx,
125 struct server_id *auth_event_server)
128 TALLOC_CTX *frame = talloc_stackframe();
129 unsigned num_servers, i;
130 struct server_id *servers;
132 status = irpc_servers_byname(msg_ctx, frame,
134 &num_servers, &servers);
136 if (!NT_STATUS_IS_OK(status)) {
137 DBG_NOTICE("Failed to find 'auth_event' registered on the "
138 "message bus to send JSON authentication events to: %s\n",
145 * Select the first server that is listening, because
146 * we get connection refused as
147 * NT_STATUS_OBJECT_NAME_NOT_FOUND without waiting
149 for (i = 0; i < num_servers; i++) {
150 status = imessaging_send(msg_ctx, servers[i], MSG_PING,
152 if (NT_STATUS_IS_OK(status)) {
153 *auth_event_server = servers[i];
158 DBG_NOTICE("Failed to find a running 'auth_event' server "
159 "registered on the message bus to send JSON "
160 "authentication events to\n");
162 return NT_STATUS_OBJECT_NAME_NOT_FOUND;
165 static void auth_message_send(struct imessaging_context *msg_ctx,
168 struct server_id auth_event_server;
170 DATA_BLOB json_blob = data_blob_string_const(json);
171 if (msg_ctx == NULL) {
175 /* Need to refetch the address each time as the destination server may
176 * have disconnected and reconnected in the interim, in which case
177 * messages may get lost, manifests in the auth_log tests
179 status = get_auth_event_server(msg_ctx, &auth_event_server);
180 if (!NT_STATUS_IS_OK(status)) {
184 status = imessaging_send(msg_ctx, auth_event_server, MSG_AUTH_LOG,
187 /* If the server crashed, try to find it again */
188 if (NT_STATUS_EQUAL(status, NT_STATUS_OBJECT_NAME_NOT_FOUND)) {
189 status = get_auth_event_server(msg_ctx, &auth_event_server);
190 if (!NT_STATUS_IS_OK(status)) {
193 imessaging_send(msg_ctx, auth_event_server, MSG_AUTH_LOG,
200 * Write the json object to the debug logs.
203 static void log_json(struct imessaging_context *msg_ctx,
204 struct json_context *context,
205 const char *type, int debug_class, int debug_level)
209 if (context->error) {
213 json = json_dumps(context->root, 0);
215 DBG_ERR("Unable to convert JSON object to string\n");
216 context->error = true;
220 DEBUGC(debug_class, debug_level, ("JSON %s: %s\n", type, json));
221 auth_message_send(msg_ctx, json);
230 * Create a new json logging context.
232 * Free with a call to free_json_context
235 static struct json_context get_json_context(void) {
237 struct json_context context;
238 context.error = false;
240 context.root = json_object();
241 if (context.root == NULL) {
242 context.error = true;
243 DBG_ERR("Unable to create json_object\n");
249 * free a previously created json_context
252 static void free_json_context(struct json_context *context)
255 json_decref(context->root);
260 * Output a JSON pair with name name and integer value value
263 static void add_int(struct json_context *context,
269 if (context->error) {
273 rc = json_object_set_new(context->root, name, json_integer(value));
275 DBG_ERR("Unable to set name [%s] value [%d]\n", name, value);
276 context->error = true;
282 * Output a JSON pair with name name and string value value
285 static void add_string(struct json_context *context,
291 if (context->error) {
296 rc = json_object_set_new(context->root, name, json_string(value));
298 rc = json_object_set_new(context->root, name, json_null());
301 DBG_ERR("Unable to set name [%s] value [%s]\n", name, value);
302 context->error = true;
308 * Output a JSON pair with name name and object value
311 static void add_object(struct json_context *context,
313 struct json_context *value)
318 context->error = true;
320 if (context->error) {
323 rc = json_object_set_new(context->root, name, value->root);
325 DBG_ERR("Unable to add object [%s]\n", name);
326 context->error = true;
331 * Output a version object
333 * "version":{"major":1,"minor":0}
336 static void add_version(struct json_context *context, int major, int minor)
338 struct json_context version = get_json_context();
339 add_int(&version, "major", major);
340 add_int(&version, "minor", minor);
341 add_object(context, "version", &version);
345 * Output the current date and time as a timestamp in ISO 8601 format
347 * "timestamp":"2017-03-06T17:18:04.455081+1300"
350 static void add_timestamp(struct json_context *context)
352 char buffer[40]; /* formatted time less usec and timezone */
353 char timestamp[50]; /* the formatted ISO 8601 time stamp */
354 char tz[10]; /* formatted time zone */
355 struct tm* tm_info; /* current local time */
356 struct timeval tv; /* current system time */
357 int r; /* response code from gettimeofday */
359 if (context->error) {
363 r = gettimeofday(&tv, NULL);
365 DBG_ERR("Unable to get time of day: (%d) %s\n",
368 context->error = true;
372 tm_info = localtime(&tv.tv_sec);
373 if (tm_info == NULL) {
374 DBG_ERR("Unable to determine local time\n");
375 context->error = true;
379 strftime(buffer, sizeof(buffer)-1, "%Y-%m-%dT%T", tm_info);
380 strftime(tz, sizeof(tz)-1, "%z", tm_info);
381 snprintf(timestamp, sizeof(timestamp),"%s.%06ld%s",
382 buffer, tv.tv_usec, tz);
383 add_string(context,"timestamp", timestamp);
388 * Output an address pair, with name name.
390 * "localAddress":"ipv6::::0"
393 static void add_address(struct json_context *context,
395 const struct tsocket_address *address)
398 TALLOC_CTX *frame = talloc_stackframe();
400 if (context->error) {
404 s = tsocket_address_string(address, frame);
405 add_string(context, name, s);
411 * Output a SID with name name
416 static void add_sid(struct json_context *context,
418 const struct dom_sid *sid)
420 char sid_buf[DOM_SID_STR_BUFLEN];
422 if (context->error) {
426 dom_sid_string_buf(sid, sid_buf, sizeof(sid_buf));
427 add_string(context, name, sid_buf);
431 * Write a machine parsable json formatted authentication log entry.
433 * IF removing or changing the format/meaning of a field please update the
434 * major version number AUTH_MAJOR
436 * IF adding a new field please update the minor version number AUTH_MINOR
438 * To process the resulting log lines from the commend line use jq to
441 * grep "JSON Authentication" log file |
443 * jq -rc '"\(.timestamp)\t\(.Authentication.status)\t
444 * \(.Authentication.clientDomain)\t
445 * \(.Authentication.clientAccount)
446 * \t\(.Authentication.workstation)
447 * \t\(.Authentication.remoteAddress)
448 * \t\(.Authentication.localAddress)"'
450 static void log_authentication_event_json(
451 struct imessaging_context *msg_ctx,
452 struct loadparm_context *lp_ctx,
453 const struct auth_usersupplied_info *ui,
455 const char *domain_name,
456 const char *account_name,
457 const char *unix_username,
461 struct json_context context = get_json_context();
462 struct json_context authentication;
463 char negotiate_flags[11];
465 add_timestamp(&context);
466 add_string(&context, "type", AUTH_JSON_TYPE);
468 authentication = get_json_context();
469 add_version(&authentication, AUTH_MAJOR, AUTH_MINOR);
470 add_string(&authentication, "status", nt_errstr(status));
471 add_address(&authentication, "localAddress", ui->local_host);
472 add_address(&authentication, "remoteAddress", ui->remote_host);
473 add_string(&authentication,
474 "serviceDescription",
475 ui->service_description);
476 add_string(&authentication, "authDescription", ui->auth_description);
477 add_string(&authentication, "clientDomain", ui->client.domain_name);
478 add_string(&authentication, "clientAccount", ui->client.account_name);
479 add_string(&authentication, "workstation", ui->workstation_name);
480 add_string(&authentication, "becameAccount", account_name);
481 add_string(&authentication, "becameDomain", domain_name);
482 add_sid(&authentication, "becameSid", sid);
483 add_string(&authentication, "mappedAccount", ui->mapped.account_name);
484 add_string(&authentication, "mappedDomain", ui->mapped.domain_name);
485 add_string(&authentication,
487 ui->netlogon_trust_account.computer_name);
488 add_string(&authentication,
489 "netlogonTrustAccount",
490 ui->netlogon_trust_account.account_name);
491 snprintf(negotiate_flags,
492 sizeof( negotiate_flags),
494 ui->netlogon_trust_account.negotiate_flags);
495 add_string(&authentication, "netlogonNegotiateFlags", negotiate_flags);
496 add_int(&authentication,
497 "netlogonSecureChannelType",
498 ui->netlogon_trust_account.secure_channel_type);
499 add_sid(&authentication,
500 "netlogonTrustAccountSid",
501 ui->netlogon_trust_account.sid);
502 add_string(&authentication, "passwordType", get_password_type(ui));
503 add_object(&context,AUTH_JSON_TYPE, &authentication);
505 log_json(msg_ctx, &context, AUTH_JSON_TYPE, DBGC_AUTH_AUDIT, debug_level);
506 free_json_context(&context);
510 * Log details of a successful authorization to a service,
511 * in a machine parsable json format
513 * IF removing or changing the format/meaning of a field please update the
514 * major version number AUTHZ_MAJOR
516 * IF adding a new field please update the minor version number AUTHZ_MINOR
518 * To process the resulting log lines from the commend line use jq to
521 * grep "JSON Authentication" log_file |\
522 * sed "s;^[^{]*;;" |\
523 * jq -rc '"\(.timestamp)\t
524 * \(.Authorization.domain)\t
525 * \(.Authorization.account)\t
526 * \(.Authorization.remoteAddress)"'
529 static void log_successful_authz_event_json(
530 struct imessaging_context *msg_ctx,
531 struct loadparm_context *lp_ctx,
532 const struct tsocket_address *remote,
533 const struct tsocket_address *local,
534 const char *service_description,
535 const char *auth_type,
536 const char *transport_protection,
537 struct auth_session_info *session_info,
540 struct json_context context = get_json_context();
541 struct json_context authorization;
542 char account_flags[11];
544 //start_object(&context, NULL);
545 add_timestamp(&context);
546 add_string(&context, "type", AUTHZ_JSON_TYPE);
547 authorization = get_json_context();
548 add_version(&authorization, AUTHZ_MAJOR, AUTHZ_MINOR);
549 add_address(&authorization, "localAddress", local);
550 add_address(&authorization, "remoteAddress", remote);
551 add_string(&authorization, "serviceDescription", service_description);
552 add_string(&authorization, "authType", auth_type);
553 add_string(&authorization, "domain", session_info->info->domain_name);
554 add_string(&authorization, "account", session_info->info->account_name);
555 add_sid(&authorization, "sid", &session_info->security_token->sids[0]);
556 add_string(&authorization,
558 session_info->info->logon_server);
559 add_string(&authorization, "transportProtection", transport_protection);
561 snprintf(account_flags,
562 sizeof(account_flags),
564 session_info->info->acct_flags);
565 add_string(&authorization, "accountFlags", account_flags);
566 add_object(&context,AUTHZ_JSON_TYPE, &authorization);
573 free_json_context(&context);
578 static void log_no_json(struct imessaging_context *msg_ctx,
579 struct loadparm_context *lp_ctx)
581 if (msg_ctx && lp_ctx && lpcfg_auth_event_notification(lp_ctx)) {
582 static bool auth_event_logged = false;
583 if (auth_event_logged == false) {
584 auth_event_logged = true;
585 DBG_ERR("auth event notification = true but Samba was not compiled with jansson\n");
588 static bool json_logged = false;
589 if (json_logged == false) {
591 DBG_NOTICE("JSON auth logs not available unless compiled with jansson\n");
598 static void log_authentication_event_json(
599 struct imessaging_context *msg_ctx,
600 struct loadparm_context *lp_ctx,
601 const struct auth_usersupplied_info *ui,
603 const char *domain_name,
604 const char *account_name,
605 const char *unix_username,
609 log_no_json(msg_ctx, lp_ctx);
613 static void log_successful_authz_event_json(
614 struct imessaging_context *msg_ctx,
615 struct loadparm_context *lp_ctx,
616 const struct tsocket_address *remote,
617 const struct tsocket_address *local,
618 const char *service_description,
619 const char *auth_type,
620 const char *transport_protection,
621 struct auth_session_info *session_info,
624 log_no_json(msg_ctx, lp_ctx);
631 * Determine the type of the password supplied for the
632 * authorisation attempt.
635 static const char* get_password_type(const struct auth_usersupplied_info *ui)
638 const char *password_type = NULL;
640 if (ui->password_type != NULL) {
641 password_type = ui->password_type;
642 } else if (ui->auth_description != NULL &&
643 strncmp("ServerAuthenticate", ui->auth_description, 18) == 0)
645 if (ui->netlogon_trust_account.negotiate_flags
646 & NETLOGON_NEG_SUPPORTS_AES) {
647 password_type = "HMAC-SHA256";
648 } else if (ui->netlogon_trust_account.negotiate_flags
649 & NETLOGON_NEG_STRONG_KEYS) {
650 password_type = "HMAC-MD5";
652 password_type = "DES";
654 } else if (ui->password_state == AUTH_PASSWORD_RESPONSE &&
655 (ui->logon_parameters & MSV1_0_ALLOW_MSVCHAPV2) &&
656 ui->password.response.nt.length == 24) {
657 password_type = "MSCHAPv2";
658 } else if ((ui->logon_parameters & MSV1_0_CLEARTEXT_PASSWORD_SUPPLIED)
659 || (ui->password_state == AUTH_PASSWORD_PLAIN)) {
660 password_type = "Plaintext";
661 } else if (ui->password_state == AUTH_PASSWORD_HASH) {
662 password_type = "Supplied-NT-Hash";
663 } else if (ui->password_state == AUTH_PASSWORD_RESPONSE
664 && ui->password.response.nt.length > 24) {
665 password_type = "NTLMv2";
666 } else if (ui->password_state == AUTH_PASSWORD_RESPONSE
667 && ui->password.response.nt.length == 24) {
668 password_type = "NTLMv1";
669 } else if (ui->password_state == AUTH_PASSWORD_RESPONSE
670 && ui->password.response.lanman.length == 24) {
671 password_type = "LANMan";
672 } else if (ui->password_state == AUTH_PASSWORD_RESPONSE
673 && ui->password.response.nt.length == 0
674 && ui->password.response.lanman.length == 0) {
675 password_type = "No-Password";
677 return password_type;
681 * Write a human readable authentication log entry.
684 static void log_authentication_event_human_readable(
685 const struct auth_usersupplied_info *ui,
687 const char *domain_name,
688 const char *account_name,
689 const char *unix_username,
693 TALLOC_CTX *frame = NULL;
695 const char *ts = NULL; /* formatted current time */
696 char *remote = NULL; /* formatted remote host */
697 char *local = NULL; /* formatted local host */
698 char *nl = NULL; /* NETLOGON details if present */
699 char *trust_computer_name = NULL;
700 char *trust_account_name = NULL;
701 char *logon_line = NULL;
702 const char *password_type = NULL;
704 frame = talloc_stackframe();
706 password_type = get_password_type(ui);
707 /* Get the current time */
708 ts = get_timestamp(frame);
710 /* Only log the NETLOGON details if they are present */
711 if (ui->netlogon_trust_account.computer_name ||
712 ui->netlogon_trust_account.account_name) {
713 trust_computer_name = log_escape(frame,
714 ui->netlogon_trust_account.computer_name);
715 trust_account_name = log_escape(frame,
716 ui->netlogon_trust_account.account_name);
717 nl = talloc_asprintf(frame,
718 " NETLOGON computer [%s] trust account [%s]",
719 trust_computer_name, trust_account_name);
722 remote = tsocket_address_string(ui->remote_host, frame);
723 local = tsocket_address_string(ui->local_host, frame);
725 if (NT_STATUS_IS_OK(status)) {
726 char sid_buf[DOM_SID_STR_BUFLEN];
728 dom_sid_string_buf(sid, sid_buf, sizeof(sid_buf));
729 logon_line = talloc_asprintf(frame,
730 " became [%s]\\[%s] [%s].",
731 log_escape(frame, domain_name),
732 log_escape(frame, account_name),
735 logon_line = talloc_asprintf(
737 " mapped to [%s]\\[%s].",
738 log_escape(frame, ui->mapped.domain_name),
739 log_escape(frame, ui->mapped.account_name));
742 DEBUGC(DBGC_AUTH_AUDIT, debug_level,
743 ("Auth: [%s,%s] user [%s]\\[%s]"
744 " at [%s] with [%s] status [%s]"
745 " workstation [%s] remote host [%s]"
748 ui->service_description,
749 ui->auth_description,
750 log_escape(frame, ui->client.domain_name),
751 log_escape(frame, ui->client.account_name),
755 log_escape(frame, ui->workstation_name),
766 * Log details of an authentication attempt.
767 * Successful and unsuccessful attempts are logged.
769 * NOTE: msg_ctx and lp_ctx is optional, but when supplied allows streaming the
770 * authentication events over the message bus.
772 void log_authentication_event(struct imessaging_context *msg_ctx,
773 struct loadparm_context *lp_ctx,
774 const struct auth_usersupplied_info *ui,
776 const char *domain_name,
777 const char *account_name,
778 const char *unix_username,
781 /* set the log level */
782 int debug_level = AUTH_FAILURE_LEVEL;
784 if (NT_STATUS_IS_OK(status)) {
785 debug_level = AUTH_SUCCESS_LEVEL;
786 if (dom_sid_equal(sid, &global_sid_Anonymous)) {
787 debug_level = AUTH_ANONYMOUS_LEVEL;
791 if (CHECK_DEBUGLVLC(DBGC_AUTH_AUDIT, debug_level)) {
792 log_authentication_event_human_readable(ui,
800 if (CHECK_DEBUGLVLC(DBGC_AUTH_AUDIT_JSON, debug_level) ||
801 (msg_ctx && lp_ctx && lpcfg_auth_event_notification(lp_ctx))) {
802 log_authentication_event_json(msg_ctx, lp_ctx,
816 * Log details of a successful authorization to a service,
817 * in a human readable format.
820 static void log_successful_authz_event_human_readable(
821 const struct tsocket_address *remote,
822 const struct tsocket_address *local,
823 const char *service_description,
824 const char *auth_type,
825 const char *transport_protection,
826 struct auth_session_info *session_info,
829 TALLOC_CTX *frame = NULL;
831 const char *ts = NULL; /* formatted current time */
832 char *remote_str = NULL; /* formatted remote host */
833 char *local_str = NULL; /* formatted local host */
834 char sid_buf[DOM_SID_STR_BUFLEN];
836 frame = talloc_stackframe();
838 /* Get the current time */
839 ts = get_timestamp(frame);
841 remote_str = tsocket_address_string(remote, frame);
842 local_str = tsocket_address_string(local, frame);
844 dom_sid_string_buf(&session_info->security_token->sids[0],
848 DEBUGC(DBGC_AUTH_AUDIT, debug_level,
849 ("Successful AuthZ: [%s,%s] user [%s]\\[%s] [%s]"
852 " local host [%s]\n",
855 log_escape(frame, session_info->info->domain_name),
856 log_escape(frame, session_info->info->account_name),
866 * Log details of a successful authorization to a service.
868 * Only successful authorizations are logged. For clarity:
869 * - NTLM bad passwords will be recorded by log_authentication_event
870 * - Kerberos decrypt failures need to be logged in gensec_gssapi et al
872 * The service may later refuse authorization due to an ACL.
874 * NOTE: msg_ctx and lp_ctx is optional, but when supplied allows streaming the
875 * authentication events over the message bus.
877 void log_successful_authz_event(struct imessaging_context *msg_ctx,
878 struct loadparm_context *lp_ctx,
879 const struct tsocket_address *remote,
880 const struct tsocket_address *local,
881 const char *service_description,
882 const char *auth_type,
883 const char *transport_protection,
884 struct auth_session_info *session_info)
886 int debug_level = AUTHZ_SUCCESS_LEVEL;
888 /* set the log level */
889 if (security_token_is_anonymous(session_info->security_token)) {
890 debug_level = AUTH_ANONYMOUS_LEVEL;
893 if (CHECK_DEBUGLVLC(DBGC_AUTH_AUDIT, debug_level)) {
894 log_successful_authz_event_human_readable(remote,
898 transport_protection,
902 if (CHECK_DEBUGLVLC(DBGC_AUTH_AUDIT_JSON, debug_level) ||
903 (msg_ctx && lp_ctx && lpcfg_auth_event_notification(lp_ctx))) {
904 log_successful_authz_event_json(msg_ctx, lp_ctx,
909 transport_protection,