source4/dsdb/samdb/ldb_modules/audit_log.c

   1 /*
   2    ldb database library
   3
   4    Copyright (C) Andrew Bartlett <abartlet@samba.org> 2018
   5
   6    This program is free software; you can redistribute it and/or modify
   7    it under the terms of the GNU General Public License as published by
   8    the Free Software Foundation; either version 3 of the License, or
   9    (at your option) any later version.
  10
  11    This program is distributed in the hope that it will be useful,
  12    but WITHOUT ANY WARRANTY; without even the implied warranty of
  13    MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  14    GNU General Public License for more details.
  15
  16    You should have received a copy of the GNU General Public License
  17    along with this program.  If not, see <http://www.gnu.org/licenses/>.
  18 */
  19
  20 /*
  21  * Provide an audit log of changes made to the database and at a
  22  * higher level details of any password changes and resets.
  23  *
  24  */
  25
  26 #include "includes.h"
  27 #include "ldb_module.h"
  28 #include "lib/audit_logging/audit_logging.h"
  29
  30 #include "dsdb/samdb/samdb.h"
  31 #include "dsdb/samdb/ldb_modules/util.h"
  32 #include "dsdb/samdb/ldb_modules/audit_util_proto.h"
  33 #include "libcli/security/dom_sid.h"
  34 #include "auth/common_auth.h"
  35 #include "param/param.h"
  36 #include "librpc/gen_ndr/windows_event_ids.h"
  37
  38 #define OPERATION_JSON_TYPE "dsdbChange"
  39 #define OPERATION_HR_TAG "DSDB Change"
  40 #define OPERATION_MAJOR 1
  41 #define OPERATION_MINOR 0
  42 #define OPERATION_LOG_LVL 5
  43
  44 #define PASSWORD_JSON_TYPE "passwordChange"
  45 #define PASSWORD_HR_TAG "Password Change"
  46 #define PASSWORD_MAJOR 1
  47 #define PASSWORD_MINOR 1
  48 #define PASSWORD_LOG_LVL 5
  49
  50 #define TRANSACTION_JSON_TYPE "dsdbTransaction"
  51 #define TRANSACTION_HR_TAG "DSDB Transaction"
  52 #define TRANSACTION_MAJOR 1
  53 #define TRANSACTION_MINOR 0
  54 #define TRANSACTION_LOG_FAILURE_LVL 5
  55 #define TRANSACTION_LOG_COMPLETION_LVL 10
  56
  57 #define REPLICATION_JSON_TYPE "replicatedUpdate"
  58 #define REPLICATION_HR_TAG "Replicated Update"
  59 #define REPLICATION_MAJOR 1
  60 #define REPLICATION_MINOR 0
  61 #define REPLICATION_LOG_LVL 5
  62 /*
  63  * Attribute values are truncated in the logs if they are longer than
  64  * MAX_LENGTH
  65  */
  66 #define MAX_LENGTH 1024
  67
  68 #define min(a, b) (((a)>(b))?(b):(a))
  69
  70 /*
  71  * Private data for the module, stored in the ldb_module private data
  72  */
  73 struct audit_private {
  74         /*
  75          * Should details of database operations be sent over the
  76          * messaging bus.
  77          */
  78         bool send_samdb_events;
  79         /*
  80          * Should details of password changes and resets be sent over
  81          * the messaging bus.
  82          */
  83         bool send_password_events;
  84         /*
  85          * The messaging context to send the messages over.  Will only
  86          * be set if send_samdb_events or send_password_events are
  87          * true.
  88          */
  89         struct imessaging_context *msg_ctx;
  90         /*
  91          * Unique transaction id for the current transaction
  92          */
  93         struct GUID transaction_guid;
  94         /*
  95          * Transaction start time, used to calculate the transaction
  96          * duration.
  97          */
  98         struct timeval transaction_start;
  99 };
 100
 101 /*
 102  * @brief Has the password changed.
 103  *
 104  * Does the message contain a change to one of the password attributes? The
 105  * password attributes are defined in DSDB_PASSWORD_ATTRIBUTES
 106  *
 107  * @return true if the message contains a password attribute
 108  *
 109  */
 110 static bool has_password_changed(const struct ldb_message *message)
 111 {
 112         int i;
 113         if (message == NULL) {
 114                 return false;
 115         }
 116         for (i=0;i<message->num_elements;i++) {
 117                 if (dsdb_audit_is_password_attribute(
 118                         message->elements[i].name)) {
 119                         return true;
 120                 }
 121         }
 122         return false;
 123 }
 124
 125 /*
 126  * @brief get the password change windows event id
 127  *
 128  * Get the Windows Event Id for the action being performed on the user password.
 129  *
 130  * This routine assumes that the request contains password attributes and that the
 131  * password ACL checks have been performed by acl.c
 132  *
 133  * @param request the ldb_request to inspect
 134  * @param reply the ldb_reply, will contain the password controls
 135  *
 136  * @return The windows event code.
 137  */
 138 static enum event_id_type get_password_windows_event_id(
 139         const struct ldb_request *request,
 140         const struct ldb_reply *reply)
 141 {
 142         if(request->operation == LDB_ADD) {
 143                 return EVT_ID_PASSWORD_RESET;
 144         } else {
 145                 struct ldb_control *pav_ctrl = NULL;
 146                 struct dsdb_control_password_acl_validation *pav = NULL;
 147
 148                 pav_ctrl = ldb_reply_get_control(
 149                         discard_const(reply),
 150                         DSDB_CONTROL_PASSWORD_ACL_VALIDATION_OID);
 151                 if (pav_ctrl == NULL) {
 152                         return EVT_ID_PASSWORD_RESET;
 153                 }
 154
 155                 pav = talloc_get_type_abort(
 156                         pav_ctrl->data,
 157                         struct dsdb_control_password_acl_validation);
 158
 159                 if (pav->pwd_reset) {
 160                         return EVT_ID_PASSWORD_RESET;
 161                 } else {
 162                         return EVT_ID_PASSWORD_CHANGE;
 163                 }
 164         }
 165 }
 166 /*
 167  * @brief Is the request a password "Change" or a "Reset"
 168  *
 169  * Get a description of the action being performed on the user password.  This
 170  * routine assumes that the request contains password attributes and that the
 171  * password ACL checks have been performed by acl.c
 172  *
 173  * @param request the ldb_request to inspect
 174  * @param reply the ldb_reply, will contain the password controls
 175  *
 176  * @return "Change" if the password is being changed.
 177  *         "Reset"  if the password is being reset.
 178  */
 179 static const char *get_password_action(
 180         const struct ldb_request *request,
 181         const struct ldb_reply *reply)
 182 {
 183         if(request->operation == LDB_ADD) {
 184                 return "Reset";
 185         } else {
 186                 struct ldb_control *pav_ctrl = NULL;
 187                 struct dsdb_control_password_acl_validation *pav = NULL;
 188
 189                 pav_ctrl = ldb_reply_get_control(
 190                         discard_const(reply),
 191                         DSDB_CONTROL_PASSWORD_ACL_VALIDATION_OID);
 192                 if (pav_ctrl == NULL) {
 193                         return "Reset";
 194                 }
 195
 196                 pav = talloc_get_type_abort(
 197                         pav_ctrl->data,
 198                         struct dsdb_control_password_acl_validation);
 199
 200                 if (pav->pwd_reset) {
 201                         return "Reset";
 202                 } else {
 203                         return "Change";
 204                 }
 205         }
 206 }
 207
 208 /*
 209  * @brief generate a JSON object detailing an ldb operation.
 210  *
 211  * Generate a JSON object detailing an ldb operation.
 212  *
 213  * @param module the ldb module
 214  * @param request the request
 215  * @param reply the result of the operation.
 216  *
 217  * @return the generated JSON object, should be freed with json_free.
 218  *
 219  *
 220  */
 221 static struct json_object operation_json(
 222         struct ldb_module *module,
 223         const struct ldb_request *request,
 224         const struct ldb_reply *reply)
 225 {
 226         struct ldb_context *ldb = NULL;
 227         const struct dom_sid *sid = NULL;
 228         bool as_system = false;
 229         struct json_object wrapper = json_empty_object;
 230         struct json_object audit = json_empty_object;
 231         const struct tsocket_address *remote = NULL;
 232         const char *dn = NULL;
 233         const char* operation = NULL;
 234         const struct GUID *unique_session_token = NULL;
 235         const struct ldb_message *message = NULL;
 236         struct audit_private *audit_private
 237                 = talloc_get_type_abort(ldb_module_get_private(module),
 238                                         struct audit_private);
 239         int rc = 0;
 240
 241         ldb = ldb_module_get_ctx(module);
 242
 243         remote = dsdb_audit_get_remote_address(ldb);
 244         if (remote != NULL && dsdb_audit_is_system_session(module)) {
 245                 as_system = true;
 246                 sid = dsdb_audit_get_actual_sid(ldb);
 247                 unique_session_token =
 248                         dsdb_audit_get_actual_unique_session_token(ldb);
 249         } else {
 250                 sid = dsdb_audit_get_user_sid(module);
 251                 unique_session_token =
 252                         dsdb_audit_get_unique_session_token(module);
 253         }
 254         dn = dsdb_audit_get_primary_dn(request);
 255         operation = dsdb_audit_get_operation_name(request);
 256
 257         audit = json_new_object();
 258         if (json_is_invalid(&audit)) {
 259                 goto failure;
 260         }
 261         rc = json_add_version(&audit, OPERATION_MAJOR, OPERATION_MINOR);
 262         if (rc != 0) {
 263                 goto failure;
 264         }
 265         rc = json_add_int(&audit, "statusCode", reply->error);
 266         if (rc != 0) {
 267                 goto failure;
 268         }
 269         rc = json_add_string(&audit, "status", ldb_strerror(reply->error));
 270         if (rc != 0) {
 271                 goto failure;
 272         }
 273         rc = json_add_string(&audit, "operation", operation);
 274         if (rc != 0) {
 275                 goto failure;
 276         }
 277         rc = json_add_address(&audit, "remoteAddress", remote);
 278         if (rc != 0) {
 279                 goto failure;
 280         }
 281         rc = json_add_bool(&audit, "performedAsSystem", as_system);
 282         if (rc != 0) {
 283                 goto failure;
 284         }
 285         rc = json_add_sid(&audit, "userSid", sid);
 286         if (rc != 0) {
 287                 goto failure;
 288         }
 289         rc = json_add_string(&audit, "dn", dn);
 290         if (rc != 0) {
 291                 goto failure;
 292         }
 293         rc = json_add_guid(
 294             &audit, "transactionId", &audit_private->transaction_guid);
 295         if (rc != 0) {
 296                 goto failure;
 297         }
 298         rc = json_add_guid(&audit, "sessionId", unique_session_token);
 299         if (rc != 0) {
 300                 goto failure;
 301         }
 302
 303         message = dsdb_audit_get_message(request);
 304         if (message != NULL) {
 305                 struct json_object attributes =
 306                         dsdb_audit_attributes_json(
 307                                 request->operation,
 308                                 message);
 309                 if (json_is_invalid(&attributes)) {
 310                         goto failure;
 311                 }
 312                 rc = json_add_object(&audit, "attributes", &attributes);
 313                 if (rc != 0) {
 314                         goto failure;
 315                 }
 316         }
 317
 318         wrapper = json_new_object();
 319         if (json_is_invalid(&wrapper)) {
 320                 goto failure;
 321         }
 322         rc = json_add_timestamp(&wrapper);
 323         if (rc != 0) {
 324                 goto failure;
 325         }
 326         rc = json_add_string(&wrapper, "type", OPERATION_JSON_TYPE);
 327         if (rc != 0) {
 328                 goto failure;
 329         }
 330         rc = json_add_object(&wrapper, OPERATION_JSON_TYPE, &audit);
 331         if (rc != 0) {
 332                 goto failure;
 333         }
 334         return wrapper;
 335
 336 failure:
 337         /*
 338          * On a failure audit will not have been added to wrapper so it
 339          * needs to free it to avoid a leak.
 340          *
 341          * wrapper is freed to invalidate it as it will have only been
 342          * partially constructed and may be inconsistent.
 343          *
 344          * All the json manipulation routines handle a freed object correctly
 345          */
 346         json_free(&audit);
 347         json_free(&wrapper);
 348         DBG_ERR("Unable to create ldb operation JSON audit message\n");
 349         return wrapper;
 350 }
 351
 352 /*
 353  * @brief generate a JSON object detailing a replicated update.
 354  *
 355  * Generate a JSON object detailing a replicated update
 356  *
 357  * @param module the ldb module
 358  * @param request the request
 359  * @paran reply the result of the operation
 360  *
 361  * @return the generated JSON object, should be freed with json_free.
 362  *         NULL if there was an error generating the message.
 363  *
 364  */
 365 static struct json_object replicated_update_json(
 366         struct ldb_module *module,
 367         const struct ldb_request *request,
 368         const struct ldb_reply *reply)
 369 {
 370         struct json_object wrapper = json_empty_object;
 371         struct json_object audit = json_empty_object;
 372         struct audit_private *audit_private
 373                 = talloc_get_type_abort(ldb_module_get_private(module),
 374                                         struct audit_private);
 375         struct dsdb_extended_replicated_objects *ro = talloc_get_type(
 376                 request->op.extended.data,
 377                 struct dsdb_extended_replicated_objects);
 378         const char *partition_dn = NULL;
 379         const char *error = NULL;
 380         int rc = 0;
 381
 382         partition_dn = ldb_dn_get_linearized(ro->partition_dn);
 383         error = get_friendly_werror_msg(ro->error);
 384
 385         audit = json_new_object();
 386         if (json_is_invalid(&audit)) {
 387                 goto failure;
 388         }
 389         rc = json_add_version(&audit, REPLICATION_MAJOR, REPLICATION_MINOR);
 390         if (rc != 0) {
 391                 goto failure;
 392         }
 393         rc = json_add_int(&audit, "statusCode", reply->error);
 394         if (rc != 0) {
 395                 goto failure;
 396         }
 397         rc = json_add_string(&audit, "status", ldb_strerror(reply->error));
 398         if (rc != 0) {
 399                 goto failure;
 400         }
 401         rc = json_add_guid(
 402             &audit, "transactionId", &audit_private->transaction_guid);
 403         if (rc != 0) {
 404                 goto failure;
 405         }
 406         rc = json_add_int(&audit, "objectCount", ro->num_objects);
 407         if (rc != 0) {
 408                 goto failure;
 409         }
 410         rc = json_add_int(&audit, "linkCount", ro->linked_attributes_count);
 411         if (rc != 0) {
 412                 goto failure;
 413         }
 414         rc = json_add_string(&audit, "partitionDN", partition_dn);
 415         if (rc != 0) {
 416                 goto failure;
 417         }
 418         rc = json_add_string(&audit, "error", error);
 419         if (rc != 0) {
 420                 goto failure;
 421         }
 422         rc = json_add_int(&audit, "errorCode", W_ERROR_V(ro->error));
 423         if (rc != 0) {
 424                 goto failure;
 425         }
 426         rc = json_add_guid(
 427             &audit, "sourceDsa", &ro->source_dsa->source_dsa_obj_guid);
 428         if (rc != 0) {
 429                 goto failure;
 430         }
 431         rc = json_add_guid(
 432             &audit, "invocationId", &ro->source_dsa->source_dsa_invocation_id);
 433         if (rc != 0) {
 434                 goto failure;
 435         }
 436
 437         wrapper = json_new_object();
 438         if (json_is_invalid(&wrapper)) {
 439                 goto failure;
 440         }
 441         rc = json_add_timestamp(&wrapper);
 442         if (rc != 0) {
 443                 goto failure;
 444         }
 445         rc = json_add_string(&wrapper, "type", REPLICATION_JSON_TYPE);
 446         if (rc != 0) {
 447                 goto failure;
 448         }
 449         rc = json_add_object(&wrapper, REPLICATION_JSON_TYPE, &audit);
 450         if (rc != 0) {
 451                 goto failure;
 452         }
 453         return wrapper;
 454 failure:
 455         /*
 456          * On a failure audit will not have been added to wrapper so it
 457          * needs to be freed it to avoid a leak.
 458          *
 459          * wrapper is freed to invalidate it as it will have only been
 460          * partially constructed and may be inconsistent.
 461          *
 462          * All the json manipulation routines handle a freed object correctly
 463          */
 464         json_free(&audit);
 465         json_free(&wrapper);
 466         DBG_ERR("Unable to create replicated update JSON audit message\n");
 467         return wrapper;
 468 }
 469
 470 /*
 471  * @brief generate a JSON object detailing a password change.
 472  *
 473  * Generate a JSON object detailing a password change.
 474  *
 475  * @param module the ldb module
 476  * @param request the request
 477  * @param reply the result/response
 478  * @param status the status code returned for the underlying ldb operation.
 479  *
 480  * @return the generated JSON object.
 481  *
 482  */
 483 static struct json_object password_change_json(
 484         struct ldb_module *module,
 485         const struct ldb_request *request,
 486         const struct ldb_reply *reply)
 487 {
 488         struct ldb_context *ldb = NULL;
 489         const struct dom_sid *sid = NULL;
 490         const char *dn = NULL;
 491         struct json_object wrapper = json_empty_object;
 492         struct json_object audit = json_empty_object;
 493         const struct tsocket_address *remote = NULL;
 494         const char* action = NULL;
 495         const struct GUID *unique_session_token = NULL;
 496         struct audit_private *audit_private
 497                 = talloc_get_type_abort(ldb_module_get_private(module),
 498                                         struct audit_private);
 499         int rc = 0;
 500         enum event_id_type event_id;
 501
 502         ldb = ldb_module_get_ctx(module);
 503
 504         remote = dsdb_audit_get_remote_address(ldb);
 505         sid = dsdb_audit_get_user_sid(module);
 506         dn = dsdb_audit_get_primary_dn(request);
 507         action = get_password_action(request, reply);
 508         unique_session_token = dsdb_audit_get_unique_session_token(module);
 509         event_id = get_password_windows_event_id(request, reply);
 510
 511         audit = json_new_object();
 512         if (json_is_invalid(&audit)) {
 513                 goto failure;
 514         }
 515         rc = json_add_version(&audit, PASSWORD_MAJOR, PASSWORD_MINOR);
 516         if (rc != 0) {
 517                 goto failure;
 518         }
 519         rc = json_add_int(&audit, "eventId", event_id);
 520         if (rc != 0) {
 521                 goto failure;
 522         }
 523         rc = json_add_int(&audit, "statusCode", reply->error);
 524         if (rc != 0) {
 525                 goto failure;
 526         }
 527         rc = json_add_string(&audit, "status", ldb_strerror(reply->error));
 528         if (rc != 0) {
 529                 goto failure;
 530         }
 531         rc = json_add_address(&audit, "remoteAddress", remote);
 532         if (rc != 0) {
 533                 goto failure;
 534         }
 535         rc = json_add_sid(&audit, "userSid", sid);
 536         if (rc != 0) {
 537                 goto failure;
 538         }
 539         rc = json_add_string(&audit, "dn", dn);
 540         if (rc != 0) {
 541                 goto failure;
 542         }
 543         rc = json_add_string(&audit, "action", action);
 544         if (rc != 0) {
 545                 goto failure;
 546         }
 547         rc = json_add_guid(
 548             &audit, "transactionId", &audit_private->transaction_guid);
 549         if (rc != 0) {
 550                 goto failure;
 551         }
 552         rc = json_add_guid(&audit, "sessionId", unique_session_token);
 553         if (rc != 0) {
 554                 goto failure;
 555         }
 556
 557         wrapper = json_new_object();
 558         if (json_is_invalid(&wrapper)) {
 559                 goto failure;
 560         }
 561         rc = json_add_timestamp(&wrapper);
 562         if (rc != 0) {
 563                 goto failure;
 564         }
 565         rc = json_add_string(&wrapper, "type", PASSWORD_JSON_TYPE);
 566         if (rc != 0) {
 567                 goto failure;
 568         }
 569         rc = json_add_object(&wrapper, PASSWORD_JSON_TYPE, &audit);
 570         if (rc != 0) {
 571                 goto failure;
 572         }
 573
 574         return wrapper;
 575 failure:
 576         /*
 577          * On a failure audit will not have been added to wrapper so it
 578          * needs to free it to avoid a leak.
 579          *
 580          * wrapper is freed to invalidate it as it will have only been
 581          * partially constructed and may be inconsistent.
 582          *
 583          * All the json manipulation routines handle a freed object correctly
 584          */
 585         json_free(&wrapper);
 586         json_free(&audit);
 587         DBG_ERR("Unable to create password change JSON audit message\n");
 588         return wrapper;
 589 }
 590
 591
 592 /*
 593  * @brief create a JSON object containing details of a transaction event.
 594  *
 595  * Create a JSON object detailing a transaction transaction life cycle events,
 596  * i.e. begin, commit, roll back
 597  *
 598  * @param action a one word description of the event/action
 599  * @param transaction_id the GUID identifying the current transaction.
 600  * @param status the status code returned by the operation
 601  * @param duration the duration of the operation.
 602  *
 603  * @return a JSON object detailing the event
 604  */
 605 static struct json_object transaction_json(
 606         const char *action,
 607         struct GUID *transaction_id,
 608         const int64_t duration)
 609 {
 610         struct json_object wrapper = json_empty_object;
 611         struct json_object audit = json_empty_object;
 612         int rc = 0;
 613
 614         audit = json_new_object();
 615         if (json_is_invalid(&audit)) {
 616                 goto failure;
 617         }
 618
 619         rc = json_add_version(&audit, TRANSACTION_MAJOR, TRANSACTION_MINOR);
 620         if (rc != 0) {
 621                 goto failure;
 622         }
 623         rc = json_add_string(&audit, "action", action);
 624         if (rc != 0) {
 625                 goto failure;
 626         }
 627         rc = json_add_guid(&audit, "transactionId", transaction_id);
 628         if (rc != 0) {
 629                 goto failure;
 630         }
 631         rc = json_add_int(&audit, "duration", duration);
 632         if (rc != 0) {
 633                 goto failure;
 634         }
 635
 636         wrapper = json_new_object();
 637         if (json_is_invalid(&wrapper)) {
 638                 goto failure;
 639         }
 640         rc = json_add_timestamp(&wrapper);
 641         if (rc != 0) {
 642                 goto failure;
 643         }
 644         rc = json_add_string(&wrapper, "type", TRANSACTION_JSON_TYPE);
 645         if (rc != 0) {
 646                 goto failure;
 647         }
 648         rc = json_add_object(&wrapper, TRANSACTION_JSON_TYPE, &audit);
 649         if (rc != 0) {
 650                 goto failure;
 651         }
 652
 653         return wrapper;
 654 failure:
 655         /*
 656          * On a failure audit will not have been added to wrapper so it
 657          * needs to free it to avoid a leak.
 658          *
 659          * wrapper is freed to invalidate it as it will have only been
 660          * partially constructed and may be inconsistent.
 661          *
 662          * All the json manipulation routines handle a freed object correctly
 663          */
 664         json_free(&wrapper);
 665         json_free(&audit);
 666         DBG_ERR("Unable to create transaction JSON audit message\n");
 667         return wrapper;
 668 }
 669
 670
 671 /*
 672  * @brief generate a JSON object detailing a commit failure.
 673  *
 674  * Generate a JSON object containing details of a commit failure.
 675  *
 676  * @param action the commit action, "commit" or "prepare"
 677  * @param status the status code returned by commit
 678  * @param reason any extra failure information/reason available
 679  * @param transaction_id the GUID identifying the current transaction.
 680  */
 681 static struct json_object commit_failure_json(
 682         const char *action,
 683         const int64_t duration,
 684         int status,
 685         const char *reason,
 686         struct GUID *transaction_id)
 687 {
 688         struct json_object wrapper = json_empty_object;
 689         struct json_object audit = json_empty_object;
 690         int rc = 0;
 691
 692         audit = json_new_object();
 693         if (json_is_invalid(&audit)) {
 694                 goto failure;
 695         }
 696         rc = json_add_version(&audit, TRANSACTION_MAJOR, TRANSACTION_MINOR);
 697         if (rc != 0) {
 698                 goto failure;
 699         }
 700         rc = json_add_string(&audit, "action", action);
 701         if (rc != 0) {
 702                 goto failure;
 703         }
 704         rc = json_add_guid(&audit, "transactionId", transaction_id);
 705         if (rc != 0) {
 706                 goto failure;
 707         }
 708         rc = json_add_int(&audit, "duration", duration);
 709         if (rc != 0) {
 710                 goto failure;
 711         }
 712         rc = json_add_int(&audit, "statusCode", status);
 713         if (rc != 0) {
 714                 goto failure;
 715         }
 716         rc = json_add_string(&audit, "status", ldb_strerror(status));
 717         if (rc != 0) {
 718                 goto failure;
 719         }
 720         rc = json_add_string(&audit, "reason", reason);
 721         if (rc != 0) {
 722                 goto failure;
 723         }
 724
 725         wrapper = json_new_object();
 726         if (json_is_invalid(&wrapper)) {
 727                 goto failure;
 728         }
 729         rc = json_add_timestamp(&wrapper);
 730         if (rc != 0) {
 731                 goto failure;
 732         }
 733         rc = json_add_string(&wrapper, "type", TRANSACTION_JSON_TYPE);
 734         if (rc != 0) {
 735                 goto failure;
 736         }
 737         rc = json_add_object(&wrapper, TRANSACTION_JSON_TYPE, &audit);
 738         if (rc != 0) {
 739                 goto failure;
 740         }
 741
 742         return wrapper;
 743 failure:
 744         /*
 745          * On a failure audit will not have been added to wrapper so it
 746          * needs to free it to avoid a leak.
 747          *
 748          * wrapper is freed to invalidate it as it will have only been
 749          * partially constructed and may be inconsistent.
 750          *
 751          * All the json manipulation routines handle a freed object correctly
 752          */
 753         json_free(&audit);
 754         json_free(&wrapper);
 755         DBG_ERR("Unable to create commit failure JSON audit message\n");
 756         return wrapper;
 757 }
 758
 759 /*
 760  * @brief Print a human readable log line for a password change event.
 761  *
 762  * Generate a human readable log line detailing a password change.
 763  *
 764  * @param mem_ctx The talloc context that will own the generated log line.
 765  * @param module the ldb module
 766  * @param request the request
 767  * @param reply the result/response
 768  * @param status the status code returned for the underlying ldb operation.
 769  *
 770  * @return the generated log line.
 771  */
 772 static char *password_change_human_readable(
 773         TALLOC_CTX *mem_ctx,
 774         struct ldb_module *module,
 775         const struct ldb_request *request,
 776         const struct ldb_reply *reply)
 777 {
 778         struct ldb_context *ldb = NULL;
 779         const char *remote_host = NULL;
 780         const struct dom_sid *sid = NULL;
 781         struct dom_sid_buf user_sid;
 782         const char *timestamp = NULL;
 783         char *log_entry = NULL;
 784         const char *action = NULL;
 785         const char *dn = NULL;
 786
 787         TALLOC_CTX *ctx = talloc_new(NULL);
 788
 789         ldb = ldb_module_get_ctx(module);
 790
 791         remote_host = dsdb_audit_get_remote_host(ldb, ctx);
 792         sid = dsdb_audit_get_user_sid(module);
 793         timestamp = audit_get_timestamp(ctx);
 794         action = get_password_action(request, reply);
 795         dn = dsdb_audit_get_primary_dn(request);
 796
 797         log_entry = talloc_asprintf(
 798                 mem_ctx,
 799                 "[%s] at [%s] status [%s] "
 800                 "remote host [%s] SID [%s] DN [%s]",
 801                 action,
 802                 timestamp,
 803                 ldb_strerror(reply->error),
 804                 remote_host,
 805                 dom_sid_str_buf(sid, &user_sid),
 806                 dn);
 807         TALLOC_FREE(ctx);
 808         return log_entry;
 809 }
 810 /*
 811  * @brief Generate a human readable string, detailing attributes in a message
 812  *
 813  * For modify operations each attribute is prefixed with the action.
 814  * Normal values are enclosed in []
 815  * Base64 values are enclosed in {}
 816  * Truncated values are indicated by three trailing dots "..."
 817  *
 818  * @param ldb The ldb_context
 819  * @param buffer The attributes will be appended to the buffer.
 820  *               assumed to have been allocated via talloc.
 821  * @param operation The operation type
 822  * @param message the message to process
 823  *
 824  */
 825 static char *log_attributes(
 826         struct ldb_context *ldb,
 827         char *buffer,
 828         enum ldb_request_type operation,
 829         const struct ldb_message *message)
 830 {
 831         size_t i, j;
 832         for (i=0;i<message->num_elements;i++) {
 833                 if (i > 0) {
 834                         buffer = talloc_asprintf_append_buffer(buffer, " ");
 835                 }
 836
 837                 if (message->elements[i].name == NULL) {
 838                         ldb_debug(
 839                                 ldb,
 840                                 LDB_DEBUG_ERROR,
 841                                 "Error: Invalid element name (NULL) at "
 842                                 "position %zu", i);
 843                         return NULL;
 844                 }
 845
 846                 if (operation == LDB_MODIFY) {
 847                         const char *action =NULL;
 848                         action = dsdb_audit_get_modification_action(
 849                                 message->elements[i].flags);
 850                         buffer = talloc_asprintf_append_buffer(
 851                                 buffer,
 852                                 "%s: %s ",
 853                                 action,
 854                                 message->elements[i].name);
 855                 } else {
 856                         buffer = talloc_asprintf_append_buffer(
 857                                 buffer,
 858                                 "%s ",
 859                                 message->elements[i].name);
 860                 }
 861
 862                 if (dsdb_audit_redact_attribute(message->elements[i].name)) {
 863                         /*
 864                          * Do not log the value of any secret or password
 865                          * attributes
 866                          */
 867                         buffer = talloc_asprintf_append_buffer(
 868                                 buffer,
 869                                 "[REDACTED SECRET ATTRIBUTE]");
 870                         continue;
 871                 }
 872
 873                 for (j=0;j<message->elements[i].num_values;j++) {
 874                         struct ldb_val v;
 875                         bool use_b64_encode = false;
 876                         size_t length;
 877                         if (j > 0) {
 878                                 buffer = talloc_asprintf_append_buffer(
 879                                         buffer,
 880                                         " ");
 881                         }
 882
 883                         v = message->elements[i].values[j];
 884                         length = min(MAX_LENGTH, v.length);
 885                         use_b64_encode = ldb_should_b64_encode(ldb, &v);
 886                         if (use_b64_encode) {
 887                                 const char *encoded = ldb_base64_encode(
 888                                         buffer,
 889                                         (char *)v.data,
 890                                         length);
 891                                 buffer = talloc_asprintf_append_buffer(
 892                                         buffer,
 893                                         "{%s%s}",
 894                                         encoded,
 895                                         (v.length > MAX_LENGTH ? "..." : ""));
 896                         } else {
 897                                 buffer = talloc_asprintf_append_buffer(
 898                                         buffer,
 899                                         "[%*.*s%s]",
 900                                         (int)length,
 901                                         (int)length,
 902                                         (char *)v.data,
 903                                         (v.length > MAX_LENGTH ? "..." : ""));
 904                         }
 905                 }
 906         }
 907         return buffer;
 908 }
 909
 910 /*
 911  * @brief generate a human readable log entry detailing an ldb operation.
 912  *
 913  * Generate a human readable log entry detailing an ldb operation.
 914  *
 915  * @param mem_ctx The talloc context owning the returned string.
 916  * @param module the ldb module
 917  * @param request the request
 918  * @param reply the result of the operation
 919  *
 920  * @return the log entry.
 921  *
 922  */
 923 static char *operation_human_readable(
 924         TALLOC_CTX *mem_ctx,
 925         struct ldb_module *module,
 926         const struct ldb_request *request,
 927         const struct ldb_reply *reply)
 928 {
 929         struct ldb_context *ldb = NULL;
 930         const char *remote_host = NULL;
 931         const struct dom_sid *sid = NULL;
 932         struct dom_sid_buf user_sid;
 933         const char *timestamp = NULL;
 934         const char *op_name = NULL;
 935         char *log_entry = NULL;
 936         const char *dn = NULL;
 937         const char *new_dn = NULL;
 938         const struct ldb_message *message = NULL;
 939
 940         TALLOC_CTX *ctx = talloc_new(NULL);
 941
 942         ldb = ldb_module_get_ctx(module);
 943
 944         remote_host = dsdb_audit_get_remote_host(ldb, ctx);
 945         if (remote_host != NULL && dsdb_audit_is_system_session(module)) {
 946                 sid = dsdb_audit_get_actual_sid(ldb);
 947         } else {
 948                 sid = dsdb_audit_get_user_sid(module);
 949         }
 950         timestamp = audit_get_timestamp(ctx);
 951         op_name = dsdb_audit_get_operation_name(request);
 952         dn = dsdb_audit_get_primary_dn(request);
 953         new_dn = dsdb_audit_get_secondary_dn(request);
 954
 955         message = dsdb_audit_get_message(request);
 956
 957         log_entry = talloc_asprintf(
 958                 mem_ctx,
 959                 "[%s] at [%s] status [%s] "
 960                 "remote host [%s] SID [%s] DN [%s]",
 961                 op_name,
 962                 timestamp,
 963                 ldb_strerror(reply->error),
 964                 remote_host,
 965                 dom_sid_str_buf(sid, &user_sid),
 966                 dn);
 967         if (new_dn != NULL) {
 968                 log_entry = talloc_asprintf_append_buffer(
 969                         log_entry,
 970                         " New DN [%s]",
 971                         new_dn);
 972         }
 973         if (message != NULL) {
 974                 log_entry = talloc_asprintf_append_buffer(log_entry,
 975                                                           " attributes [");
 976                 log_entry = log_attributes(ldb,
 977                                            log_entry,
 978                                            request->operation,
 979                                            message);
 980                 log_entry = talloc_asprintf_append_buffer(log_entry, "]");
 981         }
 982         TALLOC_FREE(ctx);
 983         return log_entry;
 984 }
 985
 986 /*
 987  * @brief generate a human readable log entry detailing a replicated update
 988  *        operation.
 989  *
 990  * Generate a human readable log entry detailing a replicated update operation
 991  *
 992  * @param mem_ctx The talloc context owning the returned string.
 993  * @param module the ldb module
 994  * @param request the request
 995  * @param reply the result of the operation.
 996  *
 997  * @return the log entry.
 998  *
 999  */
1000 static char *replicated_update_human_readable(
1001         TALLOC_CTX *mem_ctx,
1002         struct ldb_module *module,
1003         const struct ldb_request *request,
1004         const struct ldb_reply *reply)
1005 {
1006         struct dsdb_extended_replicated_objects *ro = talloc_get_type(
1007                 request->op.extended.data,
1008                 struct dsdb_extended_replicated_objects);
1009         const char *partition_dn = NULL;
1010         const char *error = NULL;
1011         char *log_entry = NULL;
1012         char *timestamp = NULL;
1013         struct GUID_txt_buf object_buf;
1014         const char *object = NULL;
1015         struct GUID_txt_buf invocation_buf;
1016         const char *invocation = NULL;
1017
1018
1019         TALLOC_CTX *ctx = talloc_new(NULL);
1020
1021         timestamp = audit_get_timestamp(ctx);
1022         error = get_friendly_werror_msg(ro->error);
1023         partition_dn = ldb_dn_get_linearized(ro->partition_dn);
1024         object = GUID_buf_string(
1025                 &ro->source_dsa->source_dsa_obj_guid,
1026                 &object_buf);
1027         invocation = GUID_buf_string(
1028                 &ro->source_dsa->source_dsa_invocation_id,
1029                 &invocation_buf);
1030
1031
1032         log_entry = talloc_asprintf(
1033                 mem_ctx,
1034                 "at [%s] status [%s] error [%s] partition [%s] objects [%d] "
1035                 "links [%d] object [%s] invocation [%s]",
1036                 timestamp,
1037                 ldb_strerror(reply->error),
1038                 error,
1039                 partition_dn,
1040                 ro->num_objects,
1041                 ro->linked_attributes_count,
1042                 object,
1043                 invocation);
1044
1045         TALLOC_FREE(ctx);
1046         return log_entry;
1047 }
1048 /*
1049  * @brief create a human readable log entry detailing a transaction event.
1050  *
1051  * Create a human readable log entry detailing a transaction event.
1052  * i.e. begin, commit, roll back
1053  *
1054  * @param mem_ctx The talloc context owning the returned string.
1055  * @param action a one word description of the event/action
1056  * @param duration the duration of the transaction.
1057  *
1058  * @return the log entry
1059  */
1060 static char *transaction_human_readable(
1061         TALLOC_CTX *mem_ctx,
1062         const char* action,
1063         const int64_t duration)
1064 {
1065         const char *timestamp = NULL;
1066         char *log_entry = NULL;
1067
1068         TALLOC_CTX *ctx = talloc_new(NULL);
1069
1070         timestamp = audit_get_timestamp(ctx);
1071
1072         log_entry = talloc_asprintf(
1073                 mem_ctx,
1074                 "[%s] at [%s] duration [%"PRIi64"]",
1075                 action,
1076                 timestamp,
1077                 duration);
1078
1079         TALLOC_FREE(ctx);
1080         return log_entry;
1081 }
1082
1083 /*
1084  * @brief generate a human readable log entry detailing a commit failure.
1085  *
1086  * Generate generate a human readable log entry detailing a commit failure.
1087  *
1088  * @param mem_ctx The talloc context owning the returned string.
1089  * @param action the commit action, "prepare" or "commit"
1090  * @param status the status code returned by commit
1091  * @param reason any extra failure information/reason available
1092  *
1093  * @return the log entry
1094  */
1095 static char *commit_failure_human_readable(
1096         TALLOC_CTX *mem_ctx,
1097         const char *action,
1098         const int64_t duration,
1099         int status,
1100         const char *reason)
1101 {
1102         const char *timestamp = NULL;
1103         char *log_entry = NULL;
1104
1105         TALLOC_CTX *ctx = talloc_new(NULL);
1106
1107         timestamp = audit_get_timestamp(ctx);
1108
1109         log_entry = talloc_asprintf(
1110                 mem_ctx,
1111                 "[%s] at [%s] duration [%"PRIi64"] status [%d] reason [%s]",
1112                 action,
1113                 timestamp,
1114                 duration,
1115                 status,
1116                 reason);
1117
1118         TALLOC_FREE(ctx);
1119         return log_entry;
1120 }
1121
1122 /*
1123  * @brief log details of a standard ldb operation.
1124  *
1125  * Log the details of an ldb operation in JSON and or human readable format
1126  * and send over the message bus.
1127  *
1128  * @param module the ldb_module
1129  * @param request the operation request.
1130  * @param reply the operation result.
1131  * @param the status code returned for the operation.
1132  *
1133  */
1134 static void log_standard_operation(
1135         struct ldb_module *module,
1136         const struct ldb_request *request,
1137         const struct ldb_reply *reply)
1138 {
1139
1140         const struct ldb_message *message = dsdb_audit_get_message(request);
1141         bool password_changed = has_password_changed(message);
1142         struct audit_private *audit_private =
1143                 talloc_get_type_abort(ldb_module_get_private(module),
1144                                       struct audit_private);
1145
1146         TALLOC_CTX *ctx = talloc_new(NULL);
1147
1148         if (CHECK_DEBUGLVLC(DBGC_DSDB_AUDIT, OPERATION_LOG_LVL)) {
1149                 char *entry = NULL;
1150                 entry = operation_human_readable(
1151                         ctx,
1152                         module,
1153                         request,
1154                         reply);
1155                 audit_log_human_text(
1156                         OPERATION_HR_TAG,
1157                         entry,
1158                         DBGC_DSDB_AUDIT,
1159                         OPERATION_LOG_LVL);
1160                 TALLOC_FREE(entry);
1161         }
1162         if (CHECK_DEBUGLVLC(DBGC_DSDB_PWD_AUDIT, PASSWORD_LOG_LVL)) {
1163                 if (password_changed) {
1164                         char *entry = NULL;
1165                         entry = password_change_human_readable(
1166                                 ctx,
1167                                 module,
1168                                 request,
1169                                 reply);
1170                         audit_log_human_text(
1171                                 PASSWORD_HR_TAG,
1172                                 entry,
1173                                 DBGC_DSDB_PWD_AUDIT,
1174                                 PASSWORD_LOG_LVL);
1175                         TALLOC_FREE(entry);
1176                 }
1177         }
1178         if (CHECK_DEBUGLVLC(DBGC_DSDB_AUDIT_JSON, OPERATION_LOG_LVL) ||
1179                 (audit_private->msg_ctx
1180                  && audit_private->send_samdb_events)) {
1181                 struct json_object json;
1182                 json = operation_json(module, request, reply);
1183                 audit_log_json(
1184                         &json,
1185                         DBGC_DSDB_AUDIT_JSON,
1186                         OPERATION_LOG_LVL);
1187                 if (audit_private->msg_ctx
1188                     && audit_private->send_samdb_events) {
1189                         audit_message_send(
1190                                 audit_private->msg_ctx,
1191                                 DSDB_EVENT_NAME,
1192                                 MSG_DSDB_LOG,
1193                                 &json);
1194                 }
1195                 json_free(&json);
1196         }
1197         if (CHECK_DEBUGLVLC(DBGC_DSDB_PWD_AUDIT_JSON, PASSWORD_LOG_LVL) ||
1198                 (audit_private->msg_ctx
1199                  && audit_private->send_password_events)) {
1200                 if (password_changed) {
1201                         struct json_object json;
1202                         json = password_change_json(module, request, reply);
1203                         audit_log_json(
1204                                 &json,
1205                                 DBGC_DSDB_PWD_AUDIT_JSON,
1206                                 PASSWORD_LOG_LVL);
1207                         if (audit_private->send_password_events) {
1208                                 audit_message_send(
1209                                         audit_private->msg_ctx,
1210                                         DSDB_PWD_EVENT_NAME,
1211                                         MSG_DSDB_PWD_LOG,
1212                                         &json);
1213                         }
1214                         json_free(&json);
1215                 }
1216         }
1217         TALLOC_FREE(ctx);
1218 }
1219
1220 /*
1221  * @brief log details of a replicated update.
1222  *
1223  * Log the details of a replicated update in JSON and or human readable
1224  * format and send over the message bus.
1225  *
1226  * @param module the ldb_module
1227  * @param request the operation request
1228  * @param reply the result of the operation.
1229  *
1230  */
1231 static void log_replicated_operation(
1232         struct ldb_module *module,
1233         const struct ldb_request *request,
1234         const struct ldb_reply *reply)
1235 {
1236
1237         struct audit_private *audit_private =
1238                 talloc_get_type_abort(ldb_module_get_private(module),
1239                                 struct audit_private);
1240
1241         TALLOC_CTX *ctx = talloc_new(NULL);
1242
1243         if (CHECK_DEBUGLVLC(DBGC_DSDB_AUDIT, REPLICATION_LOG_LVL)) {
1244                 char *entry = NULL;
1245                 entry = replicated_update_human_readable(
1246                         ctx,
1247                         module,
1248                         request,
1249                         reply);
1250                 audit_log_human_text(
1251                         REPLICATION_HR_TAG,
1252                         entry,
1253                         DBGC_DSDB_AUDIT,
1254                         REPLICATION_LOG_LVL);
1255                 TALLOC_FREE(entry);
1256         }
1257         if (CHECK_DEBUGLVLC(DBGC_DSDB_AUDIT_JSON, REPLICATION_LOG_LVL) ||
1258                 (audit_private->msg_ctx && audit_private->send_samdb_events)) {
1259                 struct json_object json;
1260                 json = replicated_update_json(module, request, reply);
1261                 audit_log_json(
1262                         &json,
1263                         DBGC_DSDB_AUDIT_JSON,
1264                         REPLICATION_LOG_LVL);
1265                 if (audit_private->send_samdb_events) {
1266                         audit_message_send(
1267                                 audit_private->msg_ctx,
1268                                 DSDB_EVENT_NAME,
1269                                 MSG_DSDB_LOG,
1270                                 &json);
1271                 }
1272                 json_free(&json);
1273         }
1274         TALLOC_FREE(ctx);
1275 }
1276
1277 /*
1278  * @brief log details of an ldb operation.
1279  *
1280  * Log the details of an ldb operation in JSON and or human readable format
1281  * and send over the message bus.
1282  *
1283  * @param module the ldb_module
1284  * @param request the operation request
1285  * @part reply the result of the operation
1286  *
1287  */
1288 static void log_operation(
1289         struct ldb_module *module,
1290         const struct ldb_request *request,
1291         const struct ldb_reply *reply)
1292 {
1293
1294         if (request->operation == LDB_EXTENDED) {
1295                 if (strcmp(
1296                         request->op.extended.oid,
1297                         DSDB_EXTENDED_REPLICATED_OBJECTS_OID) != 0) {
1298
1299                         log_replicated_operation(module, request, reply);
1300                 }
1301         } else {
1302                 log_standard_operation(module, request, reply);
1303         }
1304 }
1305
1306 /*
1307  * @brief log details of a transaction event.
1308  *
1309  * Log the details of a transaction event in JSON and or human readable format
1310  * and send over the message bus.
1311  *
1312  * @param module the ldb_module
1313  * @param action the transaction event i.e. begin, commit, roll back.
1314  * @param log_level the logging level
1315  *
1316  */
1317 static void log_transaction(
1318         struct ldb_module *module,
1319         const char *action,
1320         int log_level)
1321 {
1322
1323         struct audit_private *audit_private =
1324                 talloc_get_type_abort(ldb_module_get_private(module),
1325                                       struct audit_private);
1326         const struct timeval now = timeval_current();
1327         const int64_t duration = usec_time_diff(&now, &audit_private->transaction_start);
1328
1329         TALLOC_CTX *ctx = talloc_new(NULL);
1330
1331         if (CHECK_DEBUGLVLC(DBGC_DSDB_TXN_AUDIT, log_level)) {
1332                 char* entry = NULL;
1333                 entry = transaction_human_readable(ctx, action, duration);
1334                 audit_log_human_text(
1335                         TRANSACTION_HR_TAG,
1336                         entry,
1337                         DBGC_DSDB_TXN_AUDIT,
1338                         log_level);
1339                 TALLOC_FREE(entry);
1340         }
1341         if (CHECK_DEBUGLVLC(DBGC_DSDB_TXN_AUDIT_JSON, log_level) ||
1342                 (audit_private->msg_ctx && audit_private->send_samdb_events)) {
1343                 struct json_object json;
1344                 json = transaction_json(
1345                         action,
1346                         &audit_private->transaction_guid,
1347                         duration);
1348                 audit_log_json(
1349                         &json,
1350                         DBGC_DSDB_TXN_AUDIT_JSON,
1351                         log_level);
1352                 if (audit_private->send_samdb_events) {
1353                         audit_message_send(
1354                                 audit_private->msg_ctx,
1355                                 DSDB_EVENT_NAME,
1356                                 MSG_DSDB_LOG,
1357                                 &json);
1358                 }
1359                 json_free(&json);
1360         }
1361         TALLOC_FREE(ctx);
1362 }
1363
1364 /*
1365  * @brief log details of a commit failure.
1366  *
1367  * Log the details of a commit failure in JSON and or human readable
1368  * format and send over the message bus.
1369  *
1370  * @param module the ldb_module
1371  * @param action the commit action "prepare" or "commit"
1372  * @param status the ldb status code returned by prepare commit.
1373  *
1374  */
1375 static void log_commit_failure(
1376         struct ldb_module *module,
1377         const char *action,
1378         int status)
1379 {
1380
1381         struct audit_private *audit_private =
1382                 talloc_get_type_abort(ldb_module_get_private(module),
1383                                       struct audit_private);
1384         const char* reason = dsdb_audit_get_ldb_error_string(module, status);
1385         const int log_level = TRANSACTION_LOG_FAILURE_LVL;
1386         const struct timeval now = timeval_current();
1387         const int64_t duration = usec_time_diff(&now,
1388                                                 &audit_private->transaction_start);
1389
1390         TALLOC_CTX *ctx = talloc_new(NULL);
1391
1392         if (CHECK_DEBUGLVLC(DBGC_DSDB_TXN_AUDIT, log_level)) {
1393
1394                 char* entry = NULL;
1395                 entry = commit_failure_human_readable(
1396                         ctx,
1397                         action,
1398                         duration,
1399                         status,
1400                         reason);
1401                 audit_log_human_text(
1402                         TRANSACTION_HR_TAG,
1403                         entry,
1404                         DBGC_DSDB_TXN_AUDIT,
1405                         TRANSACTION_LOG_FAILURE_LVL);
1406                 TALLOC_FREE(entry);
1407         }
1408         if (CHECK_DEBUGLVLC(DBGC_DSDB_TXN_AUDIT_JSON, log_level) ||
1409                 (audit_private->msg_ctx
1410                  && audit_private->send_samdb_events)) {
1411                 struct json_object json;
1412                 json = commit_failure_json(
1413                         action,
1414                         duration,
1415                         status,
1416                         reason,
1417                         &audit_private->transaction_guid);
1418                 audit_log_json(
1419                         &json,
1420                         DBGC_DSDB_TXN_AUDIT_JSON,
1421                         log_level);
1422                 if (audit_private->send_samdb_events) {
1423                         audit_message_send(audit_private->msg_ctx,
1424                                            DSDB_EVENT_NAME,
1425                                            MSG_DSDB_LOG,
1426                                            &json);
1427                 }
1428                 json_free(&json);
1429         }
1430         TALLOC_FREE(ctx);
1431 }
1432
1433 /*
1434  * Context needed by audit_callback
1435  */
1436 struct audit_callback_context {
1437         struct ldb_request *request;
1438         struct ldb_module *module;
1439 };
1440
1441 /*
1442  * @brief call back function for the ldb_operations.
1443  *
1444  * As the LDB operations are async, and we wish to examine the results of
1445  * the operations, a callback needs to be registered to process the results
1446  * of the LDB operations.
1447  *
1448  * @param req the ldb request
1449  * @param res the result of the operation
1450  *
1451  * @return the LDB_STATUS
1452  */
1453 static int audit_callback(struct ldb_request *req, struct ldb_reply *ares)
1454 {
1455         struct audit_callback_context *ac = NULL;
1456
1457         ac = talloc_get_type(
1458                 req->context,
1459                 struct audit_callback_context);
1460
1461         if (!ares) {
1462                 return ldb_module_done(
1463                         ac->request,
1464                         NULL,
1465                         NULL,
1466                         LDB_ERR_OPERATIONS_ERROR);
1467         }
1468
1469         /* pass on to the callback */
1470         switch (ares->type) {
1471         case LDB_REPLY_ENTRY:
1472                 return ldb_module_send_entry(
1473                         ac->request,
1474                         ares->message,
1475                         ares->controls);
1476
1477         case LDB_REPLY_REFERRAL:
1478                 return ldb_module_send_referral(
1479                         ac->request,
1480                         ares->referral);
1481
1482         case LDB_REPLY_DONE:
1483                 /*
1484                  * Log the operation once DONE
1485                  */
1486                 log_operation(ac->module, ac->request, ares);
1487                 return ldb_module_done(
1488                         ac->request,
1489                         ares->controls,
1490                         ares->response,
1491                         ares->error);
1492
1493         default:
1494                 /* Can't happen */
1495                 return LDB_ERR_OPERATIONS_ERROR;
1496         }
1497 }
1498
1499 /*
1500  * @brief Add the current transaction identifier to the request.
1501  *
1502  * Add the current transaction identifier in the module private data,
1503  * to the request as a control.
1504  *
1505  * @param module
1506  * @param req the request.
1507  *
1508  * @return an LDB_STATUS code, LDB_SUCCESS if successful.
1509  */
1510 static int add_transaction_id(
1511         struct ldb_module *module,
1512         struct ldb_request *req)
1513 {
1514         struct audit_private *audit_private =
1515                 talloc_get_type_abort(ldb_module_get_private(module),
1516                                       struct audit_private);
1517         struct dsdb_control_transaction_identifier *transaction_id;
1518         int ret;
1519
1520         transaction_id = talloc_zero(
1521                 req,
1522                 struct dsdb_control_transaction_identifier);
1523         if (transaction_id == NULL) {
1524                 struct ldb_context *ldb = ldb_module_get_ctx(module);
1525                 return ldb_oom(ldb);
1526         }
1527         transaction_id->transaction_guid = audit_private->transaction_guid;
1528         ret = ldb_request_add_control(req,
1529                                       DSDB_CONTROL_TRANSACTION_IDENTIFIER_OID,
1530                                       false,
1531                                       transaction_id);
1532         return ret;
1533
1534 }
1535
1536 /*
1537  * @brief log details of an add operation.
1538  *
1539  * Log the details of an add operation.
1540  *
1541  * @param module the ldb_module
1542  * @param req the ldb_request
1543  *
1544  * @return ldb status code
1545  */
1546 static int log_add(
1547         struct ldb_module *module,
1548         struct ldb_request *req)
1549 {
1550         struct audit_callback_context *context = NULL;
1551         struct ldb_request *new_req = NULL;
1552         struct ldb_context *ldb = NULL;
1553         int ret;
1554
1555         ldb = ldb_module_get_ctx(module);
1556         context = talloc_zero(req, struct audit_callback_context);
1557
1558         if (context == NULL) {
1559                 return ldb_oom(ldb);
1560         }
1561         context->request = req;
1562         context->module  = module;
1563         /*
1564          * We want to log the return code status, so we need to register
1565          * a callback function to get the actual result.
1566          * We need to take a new copy so that we don't alter the callers copy
1567          */
1568         ret = ldb_build_add_req(
1569                 &new_req,
1570                 ldb,
1571                 req,
1572                 req->op.add.message,
1573                 req->controls,
1574                 context,
1575                 audit_callback,
1576                 req);
1577         if (ret != LDB_SUCCESS) {
1578                 return ret;
1579         }
1580         ret = add_transaction_id(module, new_req);
1581         if (ret != LDB_SUCCESS) {
1582                 return ret;
1583         }
1584         return ldb_next_request(module, new_req);
1585 }
1586
1587 /*
1588  * @brief log details of an delete operation.
1589  *
1590  * Log the details of an delete operation.
1591  *
1592  * @param module the ldb_module
1593  * @param req the ldb_request
1594  *
1595  * @return ldb status code
1596  */
1597 static int log_delete(
1598         struct ldb_module *module,
1599         struct ldb_request *req)
1600 {
1601         struct audit_callback_context *context = NULL;
1602         struct ldb_request *new_req = NULL;
1603         struct ldb_context *ldb = NULL;
1604         int ret;
1605
1606         ldb = ldb_module_get_ctx(module);
1607         context = talloc_zero(req, struct audit_callback_context);
1608
1609         if (context == NULL) {
1610                 return ldb_oom(ldb);
1611         }
1612         context->request = req;
1613         context->module  = module;
1614         /*
1615          * We want to log the return code status, so we need to register
1616          * a callback function to get the actual result.
1617          * We need to take a new copy so that we don't alter the callers copy
1618          */
1619         ret = ldb_build_del_req(&new_req,
1620                                 ldb,
1621                                 req,
1622                                 req->op.del.dn,
1623                                 req->controls,
1624                                 context,
1625                                 audit_callback,
1626                                 req);
1627         if (ret != LDB_SUCCESS) {
1628                 return ret;
1629         }
1630         ret = add_transaction_id(module, new_req);
1631         if (ret != LDB_SUCCESS) {
1632                 return ret;
1633         }
1634         return ldb_next_request(module, new_req);
1635 }
1636
1637 /*
1638  * @brief log details of a modify operation.
1639  *
1640  * Log the details of a modify operation.
1641  *
1642  * @param module the ldb_module
1643  * @param req the ldb_request
1644  *
1645  * @return ldb status code
1646  */
1647 static int log_modify(
1648         struct ldb_module *module,
1649         struct ldb_request *req)
1650 {
1651         struct audit_callback_context *context = NULL;
1652         struct ldb_request *new_req = NULL;
1653         struct ldb_context *ldb = NULL;
1654         int ret;
1655
1656         ldb = ldb_module_get_ctx(module);
1657         context = talloc_zero(req, struct audit_callback_context);
1658
1659         if (context == NULL) {
1660                 return ldb_oom(ldb);
1661         }
1662         context->request = req;
1663         context->module  = module;
1664         /*
1665          * We want to log the return code status, so we need to register
1666          * a callback function to get the actual result.
1667          * We need to take a new copy so that we don't alter the callers copy
1668          */
1669         ret = ldb_build_mod_req(
1670                 & new_req,
1671                 ldb,
1672                 req,
1673                 req->op.mod.message,
1674                 req->controls,
1675                 context,
1676                 audit_callback,
1677                 req);
1678         if (ret != LDB_SUCCESS) {
1679                 return ret;
1680         }
1681         ret = add_transaction_id(module, new_req);
1682         if (ret != LDB_SUCCESS) {
1683                 return ret;
1684         }
1685         return ldb_next_request(module, new_req);
1686 }
1687
1688 /*
1689  * @brief process a transaction start.
1690  *
1691  * process a transaction start, as we don't currently log transaction starts
1692  * just generate the new transaction_id.
1693  *
1694  * @param module the ldb_module
1695  * @param req the ldb_request
1696  *
1697  * @return ldb status code
1698  */
1699 static int log_start_transaction(struct ldb_module *module)
1700 {
1701         struct audit_private *audit_private =
1702                 talloc_get_type_abort(ldb_module_get_private(module),
1703                                       struct audit_private);
1704
1705         /*
1706          * We do not log transaction begins
1707          * however we do generate a new transaction_id and record the start
1708          * time so that we can log the transaction duration.
1709          *
1710          */
1711         audit_private->transaction_guid = GUID_random();
1712         audit_private->transaction_start = timeval_current();
1713         return ldb_next_start_trans(module);
1714 }
1715
1716 /*
1717  * @brief log details of a prepare commit.
1718  *
1719  * Log the details of a prepare commit, currently only details of
1720  * failures are logged.
1721  *
1722  * @param module the ldb_module
1723  * @param req the ldb_request
1724  *
1725  * @return ldb status code
1726  */
1727 static int log_prepare_commit(struct ldb_module *module)
1728 {
1729
1730         int ret = ldb_next_prepare_commit(module);
1731         if (ret != LDB_SUCCESS) {
1732                 /*
1733                  * We currently only log prepare commit failures
1734                  */
1735                 log_commit_failure(module, "prepare", ret);
1736         }
1737         return ret;
1738 }
1739
1740 /*
1741  * @brief process a transaction end aka commit.
1742  *
1743  * process a transaction end, as we don't currently log transaction ends
1744  * just clear transaction_id.
1745  *
1746  * @param module the ldb_module
1747  * @param req the ldb_request
1748  *
1749  * @return ldb status code
1750  */
1751 static int log_end_transaction(struct ldb_module *module)
1752 {
1753         struct audit_private *audit_private =
1754                 talloc_get_type_abort(ldb_module_get_private(module),
1755                                       struct audit_private);
1756         int ret = 0;
1757
1758
1759         ret = ldb_next_end_trans(module);
1760         if (ret == LDB_SUCCESS) {
1761                 log_transaction(
1762                         module,
1763                         "commit",
1764                         TRANSACTION_LOG_COMPLETION_LVL);
1765         } else {
1766                 log_commit_failure(module, "commit", ret);
1767         }
1768         /*
1769          * Clear the transaction id inserted by log_start_transaction
1770          */
1771         audit_private->transaction_guid = GUID_zero();
1772         return ret;
1773 }
1774
1775 /*
1776  * @brief log details of a transaction delete aka roll back.
1777  *
1778  * Log details of a transaction roll back.
1779  *
1780  * @param module the ldb_module
1781  * @param req the ldb_request
1782  *
1783  * @return ldb status code
1784  */
1785 static int log_del_transaction(struct ldb_module *module)
1786 {
1787         struct audit_private *audit_private =
1788                 talloc_get_type_abort(ldb_module_get_private(module),
1789                                       struct audit_private);
1790
1791         log_transaction(module, "rollback", TRANSACTION_LOG_FAILURE_LVL);
1792         audit_private->transaction_guid = GUID_zero();
1793         return ldb_next_del_trans(module);
1794 }
1795
1796 /*
1797  * @brief log details of an extended operation.
1798  *
1799  * Log the details of an extended operation.
1800  *
1801  * @param module the ldb_module
1802  * @param req the ldb_request
1803  *
1804  * @return ldb status code
1805  */
1806 static int log_extended(
1807         struct ldb_module *module,
1808         struct ldb_request *req)
1809 {
1810         struct audit_callback_context *context = NULL;
1811         struct ldb_request *new_req = NULL;
1812         struct ldb_context *ldb = NULL;
1813         int ret;
1814
1815         /*
1816          * Currently we only log replication extended operations
1817          */
1818         if (strcmp(
1819                 req->op.extended.oid,
1820                 DSDB_EXTENDED_REPLICATED_OBJECTS_OID) != 0) {
1821
1822                 return ldb_next_request(module, req);
1823         }
1824         ldb = ldb_module_get_ctx(module);
1825         context = talloc_zero(req, struct audit_callback_context);
1826
1827         if (context == NULL) {
1828                 return ldb_oom(ldb);
1829         }
1830         context->request = req;
1831         context->module  = module;
1832         /*
1833          * We want to log the return code status, so we need to register
1834          * a callback function to get the actual result.
1835          * We need to take a new copy so that we don't alter the callers copy
1836          */
1837         ret = ldb_build_extended_req(
1838                 &new_req,
1839                 ldb,
1840                 req,
1841                 req->op.extended.oid,
1842                 req->op.extended.data,
1843                 req->controls,
1844                 context,
1845                 audit_callback,
1846                 req);
1847         if (ret != LDB_SUCCESS) {
1848                 return ret;
1849         }
1850         ret = add_transaction_id(module, new_req);
1851         if (ret != LDB_SUCCESS) {
1852                 return ret;
1853         }
1854         return ldb_next_request(module, new_req);
1855 }
1856
1857 /*
1858  * @brief module initialisation
1859  */
1860 static int log_init(struct ldb_module *module)
1861 {
1862
1863         struct ldb_context *ldb = ldb_module_get_ctx(module);
1864         struct audit_private *audit_private = NULL;
1865         struct loadparm_context *lp_ctx
1866                 = talloc_get_type_abort(ldb_get_opaque(ldb, "loadparm"),
1867                                         struct loadparm_context);
1868         struct tevent_context *ev = ldb_get_event_context(ldb);
1869         bool sdb_events = false;
1870         bool pwd_events = false;
1871
1872         audit_private = talloc_zero(module, struct audit_private);
1873         if (audit_private == NULL) {
1874                 return ldb_module_oom(module);
1875         }
1876
1877         if (lp_ctx != NULL) {
1878                 sdb_events = lpcfg_dsdb_event_notification(lp_ctx);
1879                 pwd_events = lpcfg_dsdb_password_event_notification(lp_ctx);
1880         }
1881         if (sdb_events || pwd_events) {
1882                 audit_private->send_samdb_events = sdb_events;
1883                 audit_private->send_password_events = pwd_events;
1884                 audit_private->msg_ctx
1885                         = imessaging_client_init(audit_private,
1886                                                  lp_ctx,
1887                                                  ev);
1888         }
1889
1890         ldb_module_set_private(module, audit_private);
1891         return ldb_next_init(module);
1892 }
1893
1894 static const struct ldb_module_ops ldb_audit_log_module_ops = {
1895         .name              = "audit_log",
1896         .init_context      = log_init,
1897         .add               = log_add,
1898         .modify            = log_modify,
1899         .del               = log_delete,
1900         .start_transaction = log_start_transaction,
1901         .prepare_commit    = log_prepare_commit,
1902         .end_transaction   = log_end_transaction,
1903         .del_transaction   = log_del_transaction,
1904         .extended          = log_extended,
1905 };
1906
1907 int ldb_audit_log_module_init(const char *version)
1908 {
1909         LDB_MODULE_CHECK_VERSION(version);
1910         return ldb_register_module(&ldb_audit_log_module_ops);
1911 }