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         const char *user_sid = NULL;
 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         user_sid = dom_sid_string(ctx, sid);
 794         timestamp = audit_get_timestamp(ctx);
 795         action = get_password_action(request, reply);
 796         dn = dsdb_audit_get_primary_dn(request);
 797
 798         log_entry = talloc_asprintf(
 799                 mem_ctx,
 800                 "[%s] at [%s] status [%s] "
 801                 "remote host [%s] SID [%s] DN [%s]",
 802                 action,
 803                 timestamp,
 804                 ldb_strerror(reply->error),
 805                 remote_host,
 806                 user_sid,
 807                 dn);
 808         TALLOC_FREE(ctx);
 809         return log_entry;
 810 }
 811 /*
 812  * @brief Generate a human readable string, detailing attributes in a message
 813  *
 814  * For modify operations each attribute is prefixed with the action.
 815  * Normal values are enclosed in []
 816  * Base64 values are enclosed in {}
 817  * Truncated values are indicated by three trailing dots "..."
 818  *
 819  * @param ldb The ldb_context
 820  * @param buffer The attributes will be appended to the buffer.
 821  *               assumed to have been allocated via talloc.
 822  * @param operation The operation type
 823  * @param message the message to process
 824  *
 825  */
 826 static char *log_attributes(
 827         struct ldb_context *ldb,
 828         char *buffer,
 829         enum ldb_request_type operation,
 830         const struct ldb_message *message)
 831 {
 832         int i, j;
 833         for (i=0;i<message->num_elements;i++) {
 834                 if (i > 0) {
 835                         buffer = talloc_asprintf_append_buffer(buffer, " ");
 836                 }
 837
 838                 if (message->elements[i].name == NULL) {
 839                         ldb_debug(
 840                                 ldb,
 841                                 LDB_DEBUG_ERROR,
 842                                 "Error: Invalid element name (NULL) at "
 843                                 "position %d", i);
 844                         return NULL;
 845                 }
 846
 847                 if (operation == LDB_MODIFY) {
 848                         const char *action =NULL;
 849                         action = dsdb_audit_get_modification_action(
 850                                 message->elements[i].flags);
 851                         buffer = talloc_asprintf_append_buffer(
 852                                 buffer,
 853                                 "%s: %s ",
 854                                 action,
 855                                 message->elements[i].name);
 856                 } else {
 857                         buffer = talloc_asprintf_append_buffer(
 858                                 buffer,
 859                                 "%s ",
 860                                 message->elements[i].name);
 861                 }
 862
 863                 if (dsdb_audit_redact_attribute(message->elements[i].name)) {
 864                         /*
 865                          * Do not log the value of any secret or password
 866                          * attributes
 867                          */
 868                         buffer = talloc_asprintf_append_buffer(
 869                                 buffer,
 870                                 "[REDACTED SECRET ATTRIBUTE]");
 871                         continue;
 872                 }
 873
 874                 for (j=0;j<message->elements[i].num_values;j++) {
 875                         struct ldb_val v;
 876                         bool use_b64_encode = false;
 877                         int length;
 878                         if (j > 0) {
 879                                 buffer = talloc_asprintf_append_buffer(
 880                                         buffer,
 881                                         " ");
 882                         }
 883
 884                         v = message->elements[i].values[j];
 885                         length = min(MAX_LENGTH, v.length);
 886                         use_b64_encode = ldb_should_b64_encode(ldb, &v);
 887                         if (use_b64_encode) {
 888                                 const char *encoded = ldb_base64_encode(
 889                                         buffer,
 890                                         (char *)v.data,
 891                                         length);
 892                                 buffer = talloc_asprintf_append_buffer(
 893                                         buffer,
 894                                         "{%s%s}",
 895                                         encoded,
 896                                         (v.length > MAX_LENGTH ? "..." : ""));
 897                         } else {
 898                                 buffer = talloc_asprintf_append_buffer(
 899                                         buffer,
 900                                         "[%*.*s%s]",
 901                                         length,
 902                                         length,
 903                                         (char *)v.data,
 904                                         (v.length > MAX_LENGTH ? "..." : ""));
 905                         }
 906                 }
 907         }
 908         return buffer;
 909 }
 910
 911 /*
 912  * @brief generate a human readable log entry detailing an ldb operation.
 913  *
 914  * Generate a human readable log entry detailing an ldb operation.
 915  *
 916  * @param mem_ctx The talloc context owning the returned string.
 917  * @param module the ldb module
 918  * @param request the request
 919  * @param reply the result of the operation
 920  *
 921  * @return the log entry.
 922  *
 923  */
 924 static char *operation_human_readable(
 925         TALLOC_CTX *mem_ctx,
 926         struct ldb_module *module,
 927         const struct ldb_request *request,
 928         const struct ldb_reply *reply)
 929 {
 930         struct ldb_context *ldb = NULL;
 931         const char *remote_host = NULL;
 932         const struct dom_sid *sid = NULL;
 933         const char *user_sid = NULL;
 934         const char *timestamp = NULL;
 935         const char *op_name = NULL;
 936         char *log_entry = NULL;
 937         const char *dn = NULL;
 938         const char *new_dn = NULL;
 939         const struct ldb_message *message = NULL;
 940
 941         TALLOC_CTX *ctx = talloc_new(NULL);
 942
 943         ldb = ldb_module_get_ctx(module);
 944
 945         remote_host = dsdb_audit_get_remote_host(ldb, ctx);
 946         if (remote_host != NULL && dsdb_audit_is_system_session(module)) {
 947                 sid = dsdb_audit_get_actual_sid(ldb);
 948         } else {
 949                 sid = dsdb_audit_get_user_sid(module);
 950         }
 951         user_sid = dom_sid_string(ctx, sid);
 952         timestamp = audit_get_timestamp(ctx);
 953         op_name = dsdb_audit_get_operation_name(request);
 954         dn = dsdb_audit_get_primary_dn(request);
 955         new_dn = dsdb_audit_get_secondary_dn(request);
 956
 957         message = dsdb_audit_get_message(request);
 958
 959         log_entry = talloc_asprintf(
 960                 mem_ctx,
 961                 "[%s] at [%s] status [%s] "
 962                 "remote host [%s] SID [%s] DN [%s]",
 963                 op_name,
 964                 timestamp,
 965                 ldb_strerror(reply->error),
 966                 remote_host,
 967                 user_sid,
 968                 dn);
 969         if (new_dn != NULL) {
 970                 log_entry = talloc_asprintf_append_buffer(
 971                         log_entry,
 972                         " New DN [%s]",
 973                         new_dn);
 974         }
 975         if (message != NULL) {
 976                 log_entry = talloc_asprintf_append_buffer(log_entry,
 977                                                           " attributes [");
 978                 log_entry = log_attributes(ldb,
 979                                            log_entry,
 980                                            request->operation,
 981                                            message);
 982                 log_entry = talloc_asprintf_append_buffer(log_entry, "]");
 983         }
 984         TALLOC_FREE(ctx);
 985         return log_entry;
 986 }
 987
 988 /*
 989  * @brief generate a human readable log entry detailing a replicated update
 990  *        operation.
 991  *
 992  * Generate a human readable log entry detailing a replicated update operation
 993  *
 994  * @param mem_ctx The talloc context owning the returned string.
 995  * @param module the ldb module
 996  * @param request the request
 997  * @param reply the result of the operation.
 998  *
 999  * @return the log entry.
1000  *
1001  */
1002 static char *replicated_update_human_readable(
1003         TALLOC_CTX *mem_ctx,
1004         struct ldb_module *module,
1005         const struct ldb_request *request,
1006         const struct ldb_reply *reply)
1007 {
1008         struct dsdb_extended_replicated_objects *ro = talloc_get_type(
1009                 request->op.extended.data,
1010                 struct dsdb_extended_replicated_objects);
1011         const char *partition_dn = NULL;
1012         const char *error = NULL;
1013         char *log_entry = NULL;
1014         char *timestamp = NULL;
1015         struct GUID_txt_buf object_buf;
1016         const char *object = NULL;
1017         struct GUID_txt_buf invocation_buf;
1018         const char *invocation = NULL;
1019
1020
1021         TALLOC_CTX *ctx = talloc_new(NULL);
1022
1023         timestamp = audit_get_timestamp(ctx);
1024         error = get_friendly_werror_msg(ro->error);
1025         partition_dn = ldb_dn_get_linearized(ro->partition_dn);
1026         object = GUID_buf_string(
1027                 &ro->source_dsa->source_dsa_obj_guid,
1028                 &object_buf);
1029         invocation = GUID_buf_string(
1030                 &ro->source_dsa->source_dsa_invocation_id,
1031                 &invocation_buf);
1032
1033
1034         log_entry = talloc_asprintf(
1035                 mem_ctx,
1036                 "at [%s] status [%s] error [%s] partition [%s] objects [%d] "
1037                 "links [%d] object [%s] invocation [%s]",
1038                 timestamp,
1039                 ldb_strerror(reply->error),
1040                 error,
1041                 partition_dn,
1042                 ro->num_objects,
1043                 ro->linked_attributes_count,
1044                 object,
1045                 invocation);
1046
1047         TALLOC_FREE(ctx);
1048         return log_entry;
1049 }
1050 /*
1051  * @brief create a human readable log entry detailing a transaction event.
1052  *
1053  * Create a human readable log entry detailing a transaction event.
1054  * i.e. begin, commit, roll back
1055  *
1056  * @param mem_ctx The talloc context owning the returned string.
1057  * @param action a one word description of the event/action
1058  * @param duration the duration of the transaction.
1059  *
1060  * @return the log entry
1061  */
1062 static char *transaction_human_readable(
1063         TALLOC_CTX *mem_ctx,
1064         const char* action,
1065         const int64_t duration)
1066 {
1067         const char *timestamp = NULL;
1068         char *log_entry = NULL;
1069
1070         TALLOC_CTX *ctx = talloc_new(NULL);
1071
1072         timestamp = audit_get_timestamp(ctx);
1073
1074         log_entry = talloc_asprintf(
1075                 mem_ctx,
1076                 "[%s] at [%s] duration [%"PRIi64"]",
1077                 action,
1078                 timestamp,
1079                 duration);
1080
1081         TALLOC_FREE(ctx);
1082         return log_entry;
1083 }
1084
1085 /*
1086  * @brief generate a human readable log entry detailing a commit failure.
1087  *
1088  * Generate generate a human readable log entry detailing a commit failure.
1089  *
1090  * @param mem_ctx The talloc context owning the returned string.
1091  * @param action the commit action, "prepare" or "commit"
1092  * @param status the status code returned by commit
1093  * @param reason any extra failure information/reason available
1094  *
1095  * @return the log entry
1096  */
1097 static char *commit_failure_human_readable(
1098         TALLOC_CTX *mem_ctx,
1099         const char *action,
1100         const int64_t duration,
1101         int status,
1102         const char *reason)
1103 {
1104         const char *timestamp = NULL;
1105         char *log_entry = NULL;
1106
1107         TALLOC_CTX *ctx = talloc_new(NULL);
1108
1109         timestamp = audit_get_timestamp(ctx);
1110
1111         log_entry = talloc_asprintf(
1112                 mem_ctx,
1113                 "[%s] at [%s] duration [%"PRIi64"] status [%d] reason [%s]",
1114                 action,
1115                 timestamp,
1116                 duration,
1117                 status,
1118                 reason);
1119
1120         TALLOC_FREE(ctx);
1121         return log_entry;
1122 }
1123
1124 /*
1125  * @brief log details of a standard ldb operation.
1126  *
1127  * Log the details of an ldb operation in JSON and or human readable format
1128  * and send over the message bus.
1129  *
1130  * @param module the ldb_module
1131  * @param request the operation request.
1132  * @param reply the operation result.
1133  * @param the status code returned for the operation.
1134  *
1135  */
1136 static void log_standard_operation(
1137         struct ldb_module *module,
1138         const struct ldb_request *request,
1139         const struct ldb_reply *reply)
1140 {
1141
1142         const struct ldb_message *message = dsdb_audit_get_message(request);
1143         bool password_changed = has_password_changed(message);
1144         struct audit_private *audit_private =
1145                 talloc_get_type_abort(ldb_module_get_private(module),
1146                                       struct audit_private);
1147
1148         TALLOC_CTX *ctx = talloc_new(NULL);
1149
1150         if (CHECK_DEBUGLVLC(DBGC_DSDB_AUDIT, OPERATION_LOG_LVL)) {
1151                 char *entry = NULL;
1152                 entry = operation_human_readable(
1153                         ctx,
1154                         module,
1155                         request,
1156                         reply);
1157                 audit_log_human_text(
1158                         OPERATION_HR_TAG,
1159                         entry,
1160                         DBGC_DSDB_AUDIT,
1161                         OPERATION_LOG_LVL);
1162                 TALLOC_FREE(entry);
1163         }
1164         if (CHECK_DEBUGLVLC(DBGC_DSDB_PWD_AUDIT, PASSWORD_LOG_LVL)) {
1165                 if (password_changed) {
1166                         char *entry = NULL;
1167                         entry = password_change_human_readable(
1168                                 ctx,
1169                                 module,
1170                                 request,
1171                                 reply);
1172                         audit_log_human_text(
1173                                 PASSWORD_HR_TAG,
1174                                 entry,
1175                                 DBGC_DSDB_PWD_AUDIT,
1176                                 PASSWORD_LOG_LVL);
1177                         TALLOC_FREE(entry);
1178                 }
1179         }
1180         if (CHECK_DEBUGLVLC(DBGC_DSDB_AUDIT_JSON, OPERATION_LOG_LVL) ||
1181                 (audit_private->msg_ctx
1182                  && audit_private->send_samdb_events)) {
1183                 struct json_object json;
1184                 json = operation_json(module, request, reply);
1185                 audit_log_json(
1186                         &json,
1187                         DBGC_DSDB_AUDIT_JSON,
1188                         OPERATION_LOG_LVL);
1189                 if (audit_private->msg_ctx
1190                     && audit_private->send_samdb_events) {
1191                         audit_message_send(
1192                                 audit_private->msg_ctx,
1193                                 DSDB_EVENT_NAME,
1194                                 MSG_DSDB_LOG,
1195                                 &json);
1196                 }
1197                 json_free(&json);
1198         }
1199         if (CHECK_DEBUGLVLC(DBGC_DSDB_PWD_AUDIT_JSON, PASSWORD_LOG_LVL) ||
1200                 (audit_private->msg_ctx
1201                  && audit_private->send_password_events)) {
1202                 if (password_changed) {
1203                         struct json_object json;
1204                         json = password_change_json(module, request, reply);
1205                         audit_log_json(
1206                                 &json,
1207                                 DBGC_DSDB_PWD_AUDIT_JSON,
1208                                 PASSWORD_LOG_LVL);
1209                         if (audit_private->send_password_events) {
1210                                 audit_message_send(
1211                                         audit_private->msg_ctx,
1212                                         DSDB_PWD_EVENT_NAME,
1213                                         MSG_DSDB_PWD_LOG,
1214                                         &json);
1215                         }
1216                         json_free(&json);
1217                 }
1218         }
1219         TALLOC_FREE(ctx);
1220 }
1221
1222 /*
1223  * @brief log details of a replicated update.
1224  *
1225  * Log the details of a replicated update in JSON and or human readable
1226  * format and send over the message bus.
1227  *
1228  * @param module the ldb_module
1229  * @param request the operation request
1230  * @param reply the result of the operation.
1231  *
1232  */
1233 static void log_replicated_operation(
1234         struct ldb_module *module,
1235         const struct ldb_request *request,
1236         const struct ldb_reply *reply)
1237 {
1238
1239         struct audit_private *audit_private =
1240                 talloc_get_type_abort(ldb_module_get_private(module),
1241                                 struct audit_private);
1242
1243         TALLOC_CTX *ctx = talloc_new(NULL);
1244
1245         if (CHECK_DEBUGLVLC(DBGC_DSDB_AUDIT, REPLICATION_LOG_LVL)) {
1246                 char *entry = NULL;
1247                 entry = replicated_update_human_readable(
1248                         ctx,
1249                         module,
1250                         request,
1251                         reply);
1252                 audit_log_human_text(
1253                         REPLICATION_HR_TAG,
1254                         entry,
1255                         DBGC_DSDB_AUDIT,
1256                         REPLICATION_LOG_LVL);
1257                 TALLOC_FREE(entry);
1258         }
1259         if (CHECK_DEBUGLVLC(DBGC_DSDB_AUDIT_JSON, REPLICATION_LOG_LVL) ||
1260                 (audit_private->msg_ctx && audit_private->send_samdb_events)) {
1261                 struct json_object json;
1262                 json = replicated_update_json(module, request, reply);
1263                 audit_log_json(
1264                         &json,
1265                         DBGC_DSDB_AUDIT_JSON,
1266                         REPLICATION_LOG_LVL);
1267                 if (audit_private->send_samdb_events) {
1268                         audit_message_send(
1269                                 audit_private->msg_ctx,
1270                                 DSDB_EVENT_NAME,
1271                                 MSG_DSDB_LOG,
1272                                 &json);
1273                 }
1274                 json_free(&json);
1275         }
1276         TALLOC_FREE(ctx);
1277 }
1278
1279 /*
1280  * @brief log details of an ldb operation.
1281  *
1282  * Log the details of an ldb operation in JSON and or human readable format
1283  * and send over the message bus.
1284  *
1285  * @param module the ldb_module
1286  * @param request the operation request
1287  * @part reply the result of the operation
1288  *
1289  */
1290 static void log_operation(
1291         struct ldb_module *module,
1292         const struct ldb_request *request,
1293         const struct ldb_reply *reply)
1294 {
1295
1296         if (request->operation == LDB_EXTENDED) {
1297                 if (strcmp(
1298                         request->op.extended.oid,
1299                         DSDB_EXTENDED_REPLICATED_OBJECTS_OID) != 0) {
1300
1301                         log_replicated_operation(module, request, reply);
1302                 }
1303         } else {
1304                 log_standard_operation(module, request, reply);
1305         }
1306 }
1307
1308 /*
1309  * @brief log details of a transaction event.
1310  *
1311  * Log the details of a transaction event in JSON and or human readable format
1312  * and send over the message bus.
1313  *
1314  * @param module the ldb_module
1315  * @param action the transaction event i.e. begin, commit, roll back.
1316  * @param log_level the logging level
1317  *
1318  */
1319 static void log_transaction(
1320         struct ldb_module *module,
1321         const char *action,
1322         int log_level)
1323 {
1324
1325         struct audit_private *audit_private =
1326                 talloc_get_type_abort(ldb_module_get_private(module),
1327                                       struct audit_private);
1328         const struct timeval now = timeval_current();
1329         const int64_t duration = usec_time_diff(&now, &audit_private->transaction_start);
1330
1331         TALLOC_CTX *ctx = talloc_new(NULL);
1332
1333         if (CHECK_DEBUGLVLC(DBGC_DSDB_TXN_AUDIT, log_level)) {
1334                 char* entry = NULL;
1335                 entry = transaction_human_readable(ctx, action, duration);
1336                 audit_log_human_text(
1337                         TRANSACTION_HR_TAG,
1338                         entry,
1339                         DBGC_DSDB_TXN_AUDIT,
1340                         log_level);
1341                 TALLOC_FREE(entry);
1342         }
1343         if (CHECK_DEBUGLVLC(DBGC_DSDB_TXN_AUDIT_JSON, log_level) ||
1344                 (audit_private->msg_ctx && audit_private->send_samdb_events)) {
1345                 struct json_object json;
1346                 json = transaction_json(
1347                         action,
1348                         &audit_private->transaction_guid,
1349                         duration);
1350                 audit_log_json(
1351                         &json,
1352                         DBGC_DSDB_TXN_AUDIT_JSON,
1353                         log_level);
1354                 if (audit_private->send_samdb_events) {
1355                         audit_message_send(
1356                                 audit_private->msg_ctx,
1357                                 DSDB_EVENT_NAME,
1358                                 MSG_DSDB_LOG,
1359                                 &json);
1360                 }
1361                 json_free(&json);
1362         }
1363         TALLOC_FREE(ctx);
1364 }
1365
1366 /*
1367  * @brief log details of a commit failure.
1368  *
1369  * Log the details of a commit failure in JSON and or human readable
1370  * format and send over the message bus.
1371  *
1372  * @param module the ldb_module
1373  * @param action the commit action "prepare" or "commit"
1374  * @param status the ldb status code returned by prepare commit.
1375  *
1376  */
1377 static void log_commit_failure(
1378         struct ldb_module *module,
1379         const char *action,
1380         int status)
1381 {
1382
1383         struct audit_private *audit_private =
1384                 talloc_get_type_abort(ldb_module_get_private(module),
1385                                       struct audit_private);
1386         const char* reason = dsdb_audit_get_ldb_error_string(module, status);
1387         const int log_level = TRANSACTION_LOG_FAILURE_LVL;
1388         const struct timeval now = timeval_current();
1389         const int64_t duration = usec_time_diff(&now,
1390                                                 &audit_private->transaction_start);
1391
1392         TALLOC_CTX *ctx = talloc_new(NULL);
1393
1394         if (CHECK_DEBUGLVLC(DBGC_DSDB_TXN_AUDIT, log_level)) {
1395
1396                 char* entry = NULL;
1397                 entry = commit_failure_human_readable(
1398                         ctx,
1399                         action,
1400                         duration,
1401                         status,
1402                         reason);
1403                 audit_log_human_text(
1404                         TRANSACTION_HR_TAG,
1405                         entry,
1406                         DBGC_DSDB_TXN_AUDIT,
1407                         TRANSACTION_LOG_FAILURE_LVL);
1408                 TALLOC_FREE(entry);
1409         }
1410         if (CHECK_DEBUGLVLC(DBGC_DSDB_TXN_AUDIT_JSON, log_level) ||
1411                 (audit_private->msg_ctx
1412                  && audit_private->send_samdb_events)) {
1413                 struct json_object json;
1414                 json = commit_failure_json(
1415                         action,
1416                         duration,
1417                         status,
1418                         reason,
1419                         &audit_private->transaction_guid);
1420                 audit_log_json(
1421                         &json,
1422                         DBGC_DSDB_TXN_AUDIT_JSON,
1423                         log_level);
1424                 if (audit_private->send_samdb_events) {
1425                         audit_message_send(audit_private->msg_ctx,
1426                                            DSDB_EVENT_NAME,
1427                                            MSG_DSDB_LOG,
1428                                            &json);
1429                 }
1430                 json_free(&json);
1431         }
1432         TALLOC_FREE(ctx);
1433 }
1434
1435 /*
1436  * Context needed by audit_callback
1437  */
1438 struct audit_callback_context {
1439         struct ldb_request *request;
1440         struct ldb_module *module;
1441 };
1442
1443 /*
1444  * @brief call back function for the ldb_operations.
1445  *
1446  * As the LDB operations are async, and we wish to examine the results of
1447  * the operations, a callback needs to be registered to process the results
1448  * of the LDB operations.
1449  *
1450  * @param req the ldb request
1451  * @param res the result of the operation
1452  *
1453  * @return the LDB_STATUS
1454  */
1455 static int audit_callback(struct ldb_request *req, struct ldb_reply *ares)
1456 {
1457         struct audit_callback_context *ac = NULL;
1458
1459         ac = talloc_get_type(
1460                 req->context,
1461                 struct audit_callback_context);
1462
1463         if (!ares) {
1464                 return ldb_module_done(
1465                         ac->request,
1466                         NULL,
1467                         NULL,
1468                         LDB_ERR_OPERATIONS_ERROR);
1469         }
1470
1471         /* pass on to the callback */
1472         switch (ares->type) {
1473         case LDB_REPLY_ENTRY:
1474                 return ldb_module_send_entry(
1475                         ac->request,
1476                         ares->message,
1477                         ares->controls);
1478
1479         case LDB_REPLY_REFERRAL:
1480                 return ldb_module_send_referral(
1481                         ac->request,
1482                         ares->referral);
1483
1484         case LDB_REPLY_DONE:
1485                 /*
1486                  * Log the operation once DONE
1487                  */
1488                 log_operation(ac->module, ac->request, ares);
1489                 return ldb_module_done(
1490                         ac->request,
1491                         ares->controls,
1492                         ares->response,
1493                         ares->error);
1494
1495         default:
1496                 /* Can't happen */
1497                 return LDB_ERR_OPERATIONS_ERROR;
1498         }
1499 }
1500
1501 /*
1502  * @brief Add the current transaction identifier to the request.
1503  *
1504  * Add the current transaction identifier in the module private data,
1505  * to the request as a control.
1506  *
1507  * @param module
1508  * @param req the request.
1509  *
1510  * @return an LDB_STATUS code, LDB_SUCCESS if successful.
1511  */
1512 static int add_transaction_id(
1513         struct ldb_module *module,
1514         struct ldb_request *req)
1515 {
1516         struct audit_private *audit_private =
1517                 talloc_get_type_abort(ldb_module_get_private(module),
1518                                       struct audit_private);
1519         struct dsdb_control_transaction_identifier *transaction_id;
1520         int ret;
1521
1522         transaction_id = talloc_zero(
1523                 req,
1524                 struct dsdb_control_transaction_identifier);
1525         if (transaction_id == NULL) {
1526                 struct ldb_context *ldb = ldb_module_get_ctx(module);
1527                 return ldb_oom(ldb);
1528         }
1529         transaction_id->transaction_guid = audit_private->transaction_guid;
1530         ret = ldb_request_add_control(req,
1531                                       DSDB_CONTROL_TRANSACTION_IDENTIFIER_OID,
1532                                       false,
1533                                       transaction_id);
1534         return ret;
1535
1536 }
1537
1538 /*
1539  * @brief log details of an add operation.
1540  *
1541  * Log the details of an add operation.
1542  *
1543  * @param module the ldb_module
1544  * @param req the ldb_request
1545  *
1546  * @return ldb status code
1547  */
1548 static int log_add(
1549         struct ldb_module *module,
1550         struct ldb_request *req)
1551 {
1552         struct audit_callback_context *context = NULL;
1553         struct ldb_request *new_req = NULL;
1554         struct ldb_context *ldb = NULL;
1555         int ret;
1556
1557         ldb = ldb_module_get_ctx(module);
1558         context = talloc_zero(req, struct audit_callback_context);
1559
1560         if (context == NULL) {
1561                 return ldb_oom(ldb);
1562         }
1563         context->request = req;
1564         context->module  = module;
1565         /*
1566          * We want to log the return code status, so we need to register
1567          * a callback function to get the actual result.
1568          * We need to take a new copy so that we don't alter the callers copy
1569          */
1570         ret = ldb_build_add_req(
1571                 &new_req,
1572                 ldb,
1573                 req,
1574                 req->op.add.message,
1575                 req->controls,
1576                 context,
1577                 audit_callback,
1578                 req);
1579         if (ret != LDB_SUCCESS) {
1580                 return ret;
1581         }
1582         ret = add_transaction_id(module, new_req);
1583         if (ret != LDB_SUCCESS) {
1584                 return ret;
1585         }
1586         return ldb_next_request(module, new_req);
1587 }
1588
1589 /*
1590  * @brief log details of an delete operation.
1591  *
1592  * Log the details of an delete operation.
1593  *
1594  * @param module the ldb_module
1595  * @param req the ldb_request
1596  *
1597  * @return ldb status code
1598  */
1599 static int log_delete(
1600         struct ldb_module *module,
1601         struct ldb_request *req)
1602 {
1603         struct audit_callback_context *context = NULL;
1604         struct ldb_request *new_req = NULL;
1605         struct ldb_context *ldb = NULL;
1606         int ret;
1607
1608         ldb = ldb_module_get_ctx(module);
1609         context = talloc_zero(req, struct audit_callback_context);
1610
1611         if (context == NULL) {
1612                 return ldb_oom(ldb);
1613         }
1614         context->request = req;
1615         context->module  = module;
1616         /*
1617          * We want to log the return code status, so we need to register
1618          * a callback function to get the actual result.
1619          * We need to take a new copy so that we don't alter the callers copy
1620          */
1621         ret = ldb_build_del_req(&new_req,
1622                                 ldb,
1623                                 req,
1624                                 req->op.del.dn,
1625                                 req->controls,
1626                                 context,
1627                                 audit_callback,
1628                                 req);
1629         if (ret != LDB_SUCCESS) {
1630                 return ret;
1631         }
1632         ret = add_transaction_id(module, new_req);
1633         if (ret != LDB_SUCCESS) {
1634                 return ret;
1635         }
1636         return ldb_next_request(module, new_req);
1637 }
1638
1639 /*
1640  * @brief log details of a modify operation.
1641  *
1642  * Log the details of a modify operation.
1643  *
1644  * @param module the ldb_module
1645  * @param req the ldb_request
1646  *
1647  * @return ldb status code
1648  */
1649 static int log_modify(
1650         struct ldb_module *module,
1651         struct ldb_request *req)
1652 {
1653         struct audit_callback_context *context = NULL;
1654         struct ldb_request *new_req = NULL;
1655         struct ldb_context *ldb = NULL;
1656         int ret;
1657
1658         ldb = ldb_module_get_ctx(module);
1659         context = talloc_zero(req, struct audit_callback_context);
1660
1661         if (context == NULL) {
1662                 return ldb_oom(ldb);
1663         }
1664         context->request = req;
1665         context->module  = module;
1666         /*
1667          * We want to log the return code status, so we need to register
1668          * a callback function to get the actual result.
1669          * We need to take a new copy so that we don't alter the callers copy
1670          */
1671         ret = ldb_build_mod_req(
1672                 & new_req,
1673                 ldb,
1674                 req,
1675                 req->op.mod.message,
1676                 req->controls,
1677                 context,
1678                 audit_callback,
1679                 req);
1680         if (ret != LDB_SUCCESS) {
1681                 return ret;
1682         }
1683         ret = add_transaction_id(module, new_req);
1684         if (ret != LDB_SUCCESS) {
1685                 return ret;
1686         }
1687         return ldb_next_request(module, new_req);
1688 }
1689
1690 /*
1691  * @brief process a transaction start.
1692  *
1693  * process a transaction start, as we don't currently log transaction starts
1694  * just generate the new transaction_id.
1695  *
1696  * @param module the ldb_module
1697  * @param req the ldb_request
1698  *
1699  * @return ldb status code
1700  */
1701 static int log_start_transaction(struct ldb_module *module)
1702 {
1703         struct audit_private *audit_private =
1704                 talloc_get_type_abort(ldb_module_get_private(module),
1705                                       struct audit_private);
1706
1707         /*
1708          * We do not log transaction begins
1709          * however we do generate a new transaction_id and record the start
1710          * time so that we can log the transaction duration.
1711          *
1712          */
1713         audit_private->transaction_guid = GUID_random();
1714         audit_private->transaction_start = timeval_current();
1715         return ldb_next_start_trans(module);
1716 }
1717
1718 /*
1719  * @brief log details of a prepare commit.
1720  *
1721  * Log the details of a prepare commit, currently only details of
1722  * failures are logged.
1723  *
1724  * @param module the ldb_module
1725  * @param req the ldb_request
1726  *
1727  * @return ldb status code
1728  */
1729 static int log_prepare_commit(struct ldb_module *module)
1730 {
1731
1732         int ret = ldb_next_prepare_commit(module);
1733         if (ret != LDB_SUCCESS) {
1734                 /*
1735                  * We currently only log prepare commit failures
1736                  */
1737                 log_commit_failure(module, "prepare", ret);
1738         }
1739         return ret;
1740 }
1741
1742 /*
1743  * @brief process a transaction end aka commit.
1744  *
1745  * process a transaction end, as we don't currently log transaction ends
1746  * just clear transaction_id.
1747  *
1748  * @param module the ldb_module
1749  * @param req the ldb_request
1750  *
1751  * @return ldb status code
1752  */
1753 static int log_end_transaction(struct ldb_module *module)
1754 {
1755         struct audit_private *audit_private =
1756                 talloc_get_type_abort(ldb_module_get_private(module),
1757                                       struct audit_private);
1758         int ret = 0;
1759
1760
1761         ret = ldb_next_end_trans(module);
1762         if (ret == LDB_SUCCESS) {
1763                 log_transaction(
1764                         module,
1765                         "commit",
1766                         TRANSACTION_LOG_COMPLETION_LVL);
1767         } else {
1768                 log_commit_failure(module, "commit", ret);
1769         }
1770         /*
1771          * Clear the transaction id inserted by log_start_transaction
1772          */
1773         audit_private->transaction_guid = GUID_zero();
1774         return ret;
1775 }
1776
1777 /*
1778  * @brief log details of a transaction delete aka roll back.
1779  *
1780  * Log details of a transaction roll back.
1781  *
1782  * @param module the ldb_module
1783  * @param req the ldb_request
1784  *
1785  * @return ldb status code
1786  */
1787 static int log_del_transaction(struct ldb_module *module)
1788 {
1789         struct audit_private *audit_private =
1790                 talloc_get_type_abort(ldb_module_get_private(module),
1791                                       struct audit_private);
1792
1793         log_transaction(module, "rollback", TRANSACTION_LOG_FAILURE_LVL);
1794         audit_private->transaction_guid = GUID_zero();
1795         return ldb_next_del_trans(module);
1796 }
1797
1798 /*
1799  * @brief log details of an extended operation.
1800  *
1801  * Log the details of an extended operation.
1802  *
1803  * @param module the ldb_module
1804  * @param req the ldb_request
1805  *
1806  * @return ldb status code
1807  */
1808 static int log_extended(
1809         struct ldb_module *module,
1810         struct ldb_request *req)
1811 {
1812         struct audit_callback_context *context = NULL;
1813         struct ldb_request *new_req = NULL;
1814         struct ldb_context *ldb = NULL;
1815         int ret;
1816
1817         /*
1818          * Currently we only log replication extended operations
1819          */
1820         if (strcmp(
1821                 req->op.extended.oid,
1822                 DSDB_EXTENDED_REPLICATED_OBJECTS_OID) != 0) {
1823
1824                 return ldb_next_request(module, req);
1825         }
1826         ldb = ldb_module_get_ctx(module);
1827         context = talloc_zero(req, struct audit_callback_context);
1828
1829         if (context == NULL) {
1830                 return ldb_oom(ldb);
1831         }
1832         context->request = req;
1833         context->module  = module;
1834         /*
1835          * We want to log the return code status, so we need to register
1836          * a callback function to get the actual result.
1837          * We need to take a new copy so that we don't alter the callers copy
1838          */
1839         ret = ldb_build_extended_req(
1840                 &new_req,
1841                 ldb,
1842                 req,
1843                 req->op.extended.oid,
1844                 req->op.extended.data,
1845                 req->controls,
1846                 context,
1847                 audit_callback,
1848                 req);
1849         if (ret != LDB_SUCCESS) {
1850                 return ret;
1851         }
1852         ret = add_transaction_id(module, new_req);
1853         if (ret != LDB_SUCCESS) {
1854                 return ret;
1855         }
1856         return ldb_next_request(module, new_req);
1857 }
1858
1859 /*
1860  * @brief module initialisation
1861  */
1862 static int log_init(struct ldb_module *module)
1863 {
1864
1865         struct ldb_context *ldb = ldb_module_get_ctx(module);
1866         struct audit_private *audit_private = NULL;
1867         struct loadparm_context *lp_ctx
1868                 = talloc_get_type_abort(ldb_get_opaque(ldb, "loadparm"),
1869                                         struct loadparm_context);
1870         struct tevent_context *ev = ldb_get_event_context(ldb);
1871         bool sdb_events = false;
1872         bool pwd_events = false;
1873
1874         audit_private = talloc_zero(module, struct audit_private);
1875         if (audit_private == NULL) {
1876                 return ldb_module_oom(module);
1877         }
1878
1879         if (lp_ctx != NULL) {
1880                 sdb_events = lpcfg_dsdb_event_notification(lp_ctx);
1881                 pwd_events = lpcfg_dsdb_password_event_notification(lp_ctx);
1882         }
1883         if (sdb_events || pwd_events) {
1884                 audit_private->send_samdb_events = sdb_events;
1885                 audit_private->send_password_events = pwd_events;
1886                 audit_private->msg_ctx
1887                         = imessaging_client_init(audit_private,
1888                                                  lp_ctx,
1889                                                  ev);
1890         }
1891
1892         ldb_module_set_private(module, audit_private);
1893         return ldb_next_init(module);
1894 }
1895
1896 static const struct ldb_module_ops ldb_audit_log_module_ops = {
1897         .name              = "audit_log",
1898         .init_context      = log_init,
1899         .add               = log_add,
1900         .modify            = log_modify,
1901         .del               = log_delete,
1902         .start_transaction = log_start_transaction,
1903         .prepare_commit    = log_prepare_commit,
1904         .end_transaction   = log_end_transaction,
1905         .del_transaction   = log_del_transaction,
1906         .extended          = log_extended,
1907 };
1908
1909 int ldb_audit_log_module_init(const char *version)
1910 {
1911         LDB_MODULE_CHECK_VERSION(version);
1912         return ldb_register_module(&ldb_audit_log_module_ops);
1913 }