[WIP] Log database changes.

Gary Lockyer gary at catalyst.net.nz
Thu Apr 5 03:13:59 UTC 2018


I'm currently adding logging of Database changes, the attached patch set
is the work to date.

It still needs the the following done:
* separating out the common code with the auth logging
* cleaning up the code
* plumbing the remote IP through
  - it's not currently available in all cases
* Add a session ID GUID and log that in the Authorization messages as
  well
* Log/Audit group membership changes.
* Write unit and integration Tests.

Notes:
* Currently the attribute truncation limit is set artificially low to
  aid development

Sample Human readable messages.
  Values enclosed in {} are base64 encoded
  Values ending with ... have been truncated.

  Line breaks added for clarity

Samdb Change [Add] at [Thu, 05 Apr 2018 14:56:28.086708 NZST]
  transaction id [d9184e5e-aeca-4793-b7a7-a8a558378421]
  status [Success] remote host [Unknown]
  SID [S-1-5-21-202143440-2159076023-2784540227-500]
  DN [CN=krbtgt,CN=Users,DC=addom,DC=samba,DC=example,DC=com]
  attributes [
    accountExpires [9223372036854775807]
    adminCount [1]
    clearTextPassword [REDACTED SECRET ATTRIBUTE]
    description [Key Distribution Cen...]
    isCriticalSystemObject [TRUE]
    objectClass [top] [person] [organizationalPerson] [user]
    objectSid {AQUAAAAAAAUVAAAA0HYMDLfisIA=...}
    sAMAccountName [krbtgt]
    servicePrincipalName [kadmin/changepw]
    showInAdvancedViewOnly [TRUE] userAccountControl [514]]

Password Change [Reset] at [Thu, 05 Apr 2018 14:56:28.086738 NZST]
   transaction id [d9184e5e-aeca-4793-b7a7-a8a558378421]
   status [Success] remote host [Unknown]
   SID [S-1-5-21-202143440-2159076023-2784540227-500]
   DN [CN=krbtgt,CN=Users,DC=addom,DC=samba,DC=example,DC=com]


Sample JSON messages:
JSON samdbChange: {
  "timestamp": "2018-04-05T14:56:28.086749+1200",
  "type": "samdbChange",
  "samdbChange": {
    "status": "Success",
    "version": {"major": 1, "minor": 0},
    "remoteAddress": "NULL",
    "operation": "Add",
    "userSid": "S-1-5-21-202143440-2159076023-2784540227-500",
    "dn": "CN=krbtgt,CN=Users,DC=addom,DC=samba,DC=example,DC=com",
    "transactionId": "d9184e5e-aeca-4793-b7a7-a8a558378421",
    "attributes": {
      "adminCount": {"values": [{"value": "1"}]},
      "objectSid": {"values": [
         {"truncated": true, "base64": true,
            "value": "AQUAAAAAAAUVAAAA0HYMDLfisIA="}]},
    "accountExpires": {"values": [{"value": "9223372036854775807"}]},
    "objectClass": {"values": [
      {"value": "top"},
      {"value": "person"},
      {"value": "organizationalPerson"},
      {"value": "user"}
    ]},
    "clearTextPassword": {"redacted": true},
    "description": {"values": [
      {"truncated": true, "value": "Key Distribution Cen"}
    ]},
    "isCriticalSystemObject": {"values": [{"value": "TRUE"}]},
    "sAMAccountName": {"values": [{"value": "krbtgt"}]},
    "servicePrincipalName": {"values": [{"value": "kadmin/changepw"}]},
    "showInAdvancedViewOnly": {"values": [{"value": "TRUE"}]},
    "userAccountControl": {"values": [{"value": "514"}]}}}}

JSON passwordChange: {
  "timestamp": "2018-04-05T14:56:28.086947+1200",
  "type": "passwordChange",
  "passwordChange": {
    "status": "Success",
    "version": {"major": 1, "minor": 0},
    "remoteAddress": "NULL",
    "userSid": "S-1-5-21-202143440-2159076023-2784540227-500",
    "action": "Reset",
    "dn": "CN=krbtgt,CN=Users,DC=addom,DC=samba,DC=example,DC=com",
   "transactionId": "d9184e5e-aeca-4793-b7a7-a8a558378421"}}

Comments appreciated
Gary
-------------- next part --------------
From 2bee51fe277a33b17e628f9bcbc6dc17e98b13cc Mon Sep 17 00:00:00 2001
From: Gary Lockyer <gary at catalyst.net.nz>
Date: Wed, 4 Apr 2018 11:55:00 +1200
Subject: [PATCH 1/5] dsdb: refactor password attibutes to constant

Signed-off-by: Gary Lockyer <gary at catalyst.net.nz>
---
 source4/dsdb/common/util.h                     | 8 ++++++++
 source4/dsdb/samdb/ldb_modules/password_hash.c | 8 ++------
 2 files changed, 10 insertions(+), 6 deletions(-)

diff --git a/source4/dsdb/common/util.h b/source4/dsdb/common/util.h
index ede6d8b..7689c20 100644
--- a/source4/dsdb/common/util.h
+++ b/source4/dsdb/common/util.h
@@ -65,6 +65,14 @@ bool is_attr_in_list(const char * const * attrs, const char *attr);
 #define DSDB_SECRET_ATTRIBUTES_COMMA ,
 #define DSDB_SECRET_ATTRIBUTES DSDB_SECRET_ATTRIBUTES_EX(DSDB_SECRET_ATTRIBUTES_COMMA)
 
+#define DSDB_PASSWORD_ATTRIBUTES_EX(sep) \
+	"userPassword" sep \
+	"clearTextPassword" sep \
+	"unicodePwd" sep \
+	"dBCSPwd"
+
+#define DSDB_PASSWORD_ATTRIBUTES_COMMA ,
+#define DSDB_PASSWORD_ATTRIBUTES DSDB_PASSWORD_ATTRIBUTES_EX(DSDB_PASSWORD_ATTRIBUTES_COMMA)
 struct GUID;
 
 char *NS_GUID_string(TALLOC_CTX *mem_ctx, const struct GUID *guid);
diff --git a/source4/dsdb/samdb/ldb_modules/password_hash.c b/source4/dsdb/samdb/ldb_modules/password_hash.c
index c872f20..8023185 100644
--- a/source4/dsdb/samdb/ldb_modules/password_hash.c
+++ b/source4/dsdb/samdb/ldb_modules/password_hash.c
@@ -3991,10 +3991,7 @@ static int password_hash_needed(struct ldb_module *module,
 	const struct ldb_message *msg = NULL;
 	struct ph_context *ac = NULL;
 	const char *passwordAttrs[] = {
-		"userPassword",
-		"clearTextPassword",
-		"unicodePwd",
-		"dBCSPwd",
+		DSDB_PASSWORD_ATTRIBUTES,
 		NULL
 	};
 	const char **a = NULL;
@@ -4225,8 +4222,7 @@ static int password_hash_modify(struct ldb_module *module, struct ldb_request *r
 {
 	struct ldb_context *ldb = ldb_module_get_ctx(module);
 	struct ph_context *ac = NULL;
-	const char *passwordAttrs[] = { "userPassword", "clearTextPassword",
-		"unicodePwd", "dBCSPwd", NULL }, **l;
+	const char *passwordAttrs[] = {DSDB_PASSWORD_ATTRIBUTES, NULL}, **l;
 	unsigned int del_attr_cnt, add_attr_cnt, rep_attr_cnt;
 	struct ldb_message_element *passwordAttr;
 	struct ldb_message *msg;
-- 
2.7.4


From 12247f1254fb5df81b469b39b3c93314417a97d3 Mon Sep 17 00:00:00 2001
From: Gary Lockyer <gary at catalyst.net.nz>
Date: Wed, 4 Apr 2018 11:56:30 +1200
Subject: [PATCH 2/5] logging: add ldb audit classes

Signed-off-by: Gary Lockyer <gary at catalyst.net.nz>
---
 docs-xml/smbdotconf/logging/loglevel.xml | 14 +++++++++++++-
 lib/util/debug.c                         |  4 ++++
 lib/util/debug.h                         |  4 ++++
 3 files changed, 21 insertions(+), 1 deletion(-)

diff --git a/docs-xml/smbdotconf/logging/loglevel.xml b/docs-xml/smbdotconf/logging/loglevel.xml
index d3b5c45..6ff8a24 100644
--- a/docs-xml/smbdotconf/logging/loglevel.xml
+++ b/docs-xml/smbdotconf/logging/loglevel.xml
@@ -46,6 +46,8 @@
         <listitem><para><parameter moreinfo="none">auth_audit</parameter></para></listitem>
         <listitem><para><parameter moreinfo="none">auth_json_audit</parameter></para></listitem>
         <listitem><para><parameter moreinfo="none">kerberos</parameter></para></listitem>
+        <listitem><para><parameter moreinfo="none">kerberos</parameter></para></listitem>
+        <listitem><para><parameter moreinfo="none">kerberos</parameter></para></listitem>
     </itemizedlist>
 
     <para>Authentication and authorization audit information is logged
@@ -66,7 +68,17 @@
 	<listitem><para>4: Authorization Success</para></listitem>
 	<listitem><para>5: Anonymous Authentication and Authorization Success</para></listitem>
     </itemizedlist>
-    
+ 
+    <para>Changes to the samdb database are logged
+    under the samdb_audit, and if Samba is compiled against the jansson
+    JSON library, a JSON representation is logged under
+    samdb_json_audit.</para>
+ 
+    <para>Password changes and Password resets are logged under
+    the password_audit, and if Samba is compiled against the jansson
+    JSON library, a JSON representation is logged under the
+    password_json_audit.</para>
+
 
     
 </description>
diff --git a/lib/util/debug.c b/lib/util/debug.c
index d010b72..f35df2d 100644
--- a/lib/util/debug.c
+++ b/lib/util/debug.c
@@ -543,6 +543,10 @@ static const char *default_classname_table[] = {
 	[DBGC_DRS_REPL] =       "drs_repl",
 	[DBGC_SMB2] =           "smb2",
 	[DBGC_SMB2_CREDITS] =   "smb2_credits",
+	[DBGC_SAMDB_AUDIT]  =	"samdb_audit",
+	[DBGC_SAMDB_AUDIT_JSON] = "samdb_json_audit",
+	[DBGC_PWD_AUDIT]  =	"password_audit",
+	[DBGC_PWD_AUDIT_JSON] = "password_json_audit",
 };
 
 /*
diff --git a/lib/util/debug.h b/lib/util/debug.h
index 1e184b4..b80cb5d 100644
--- a/lib/util/debug.h
+++ b/lib/util/debug.h
@@ -95,6 +95,10 @@ bool dbghdr( int level, const char *location, const char *func);
 #define DBGC_DRS_REPL           27
 #define DBGC_SMB2               28
 #define DBGC_SMB2_CREDITS       29
+#define DBGC_SAMDB_AUDIT	30
+#define DBGC_SAMDB_AUDIT_JSON	31
+#define DBGC_PWD_AUDIT		32
+#define DBGC_PWD_AUDIT_JSON	33
 
 /* So you can define DBGC_CLASS before including debug.h */
 #ifndef DBGC_CLASS
-- 
2.7.4


From 87db28e2d4121a7d0c6e8e123a09b1fa5fef6a76 Mon Sep 17 00:00:00 2001
From: Gary Lockyer <gary at catalyst.net.nz>
Date: Wed, 4 Apr 2018 11:59:41 +1200
Subject: [PATCH 3/5] dsdb: audit samdb and password changes

Signed-off-by: Gary Lockyer <gary at catalyst.net.nz>
---
 source4/dsdb/samdb/ldb_modules/audit_log.c         | 1362 ++++++++++++++++++++
 source4/dsdb/samdb/ldb_modules/samba_dsdb.c        |    3 +-
 .../dsdb/samdb/ldb_modules/tests/test_audit_log.c  |  153 +++
 source4/dsdb/samdb/ldb_modules/wscript_build       |   12 +
 .../dsdb/samdb/ldb_modules/wscript_build_server    |   15 +
 5 files changed, 1544 insertions(+), 1 deletion(-)
 create mode 100644 source4/dsdb/samdb/ldb_modules/audit_log.c
 create mode 100644 source4/dsdb/samdb/ldb_modules/tests/test_audit_log.c

diff --git a/source4/dsdb/samdb/ldb_modules/audit_log.c b/source4/dsdb/samdb/ldb_modules/audit_log.c
new file mode 100644
index 0000000..b3c4b38
--- /dev/null
+++ b/source4/dsdb/samdb/ldb_modules/audit_log.c
@@ -0,0 +1,1362 @@
+/*
+   ldb database library
+
+   Copyright (C) Andrew Bartlett <abartlet at samba.org> 2018
+
+   This program is free software; you can redistribute it and/or modify
+   it under the terms of the GNU General Public License as published by
+   the Free Software Foundation; either version 3 of the License, or
+   (at your option) any later version.
+
+   This program is distributed in the hope that it will be useful,
+   but WITHOUT ANY WARRANTY; without even the implied warranty of
+   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+   GNU General Public License for more details.
+
+   You should have received a copy of the GNU General Public License
+   along with this program.  If not, see <http://www.gnu.org/licenses/>.
+*/
+
+/*
+ * Provide an audit log of changes made to the database
+ *
+ */
+
+#include "includes.h"
+#include "ldb_module.h"
+
+#include "dsdb/samdb/samdb.h"
+#include "dsdb/samdb/ldb_modules/util.h"
+#include "lib/tsocket/tsocket.h"
+#include "libcli/security/dom_sid.h"
+#include "lib/messaging/messaging.h"
+#include "lib/messaging/irpc.h"
+
+#define AUDIT_JSON_TYPE "samdbChange"
+#define AUDIT_JSON_TAG "JSON samdbChange:"
+#define AUDIT_HR_TAG "Samdb Change"
+#define AUDIT_MAJOR 1
+#define AUDIT_MINOR 0
+
+#define PASSWORD_JSON_TYPE "passwordChange"
+#define PASSWORD_JSON_TAG "JSON passwordChange:"
+#define PASSWORD_HR_TAG "Password Change"
+#define PASSWORD_MAJOR 1
+#define PASSWORD_MINOR 0
+
+#define TRANSACTION_JSON_TYPE "samdbTransaction"
+#define TRANSACTION_JSON_TAG "JSON samdbTransaction:"
+#define TRANSACTION_HR_TAG "Samdn Transaction"
+#define TRANSACTION_MAJOR 1
+#define TRANSACTION_MINOR 0
+
+#define MAX_LENGTH 20 
+#define min(a,b) (((a)>(b))?(b):(a))
+
+static const char * const secret_attributes[]   = {DSDB_SECRET_ATTRIBUTES};
+static const char * const password_attributes[] = {DSDB_PASSWORD_ATTRIBUTES};
+
+struct audit_context {
+	struct imessaging_context *msg_ctx;
+	struct GUID transaction_guid;
+};
+
+static void log_message(const char* prefix, const char* message) {
+	DBG_INFO("%s %s\n",prefix, message);
+}
+
+static struct tsocket_address *get_remote_address(
+	struct ldb_context *ldb)
+{
+	void *opaque_remote_address = NULL;
+	struct tsocket_address *remote_address;
+
+	opaque_remote_address = ldb_get_opaque(ldb,
+					       "remoteAddress");
+	if (opaque_remote_address == NULL) {
+		return NULL;
+	}
+
+	remote_address = talloc_get_type(opaque_remote_address,
+				      struct tsocket_address);
+	return remote_address;
+}
+
+static const struct dom_sid *get_user_sid(struct ldb_module *module)
+{
+	struct security_token *user_token = NULL;
+
+	user_token = acl_user_token(module);
+	if (user_token == NULL) {
+		return NULL;
+	}
+	return &user_token->sids[0];
+
+}
+
+/*
+ * Get a human readable timestamp.
+ *
+ * Returns the current time formatted as
+ *  "Tue, 14 Mar 2017 08:38:42.209028 NZDT"
+ *
+ * The returned string is allocated by talloc in the supplied context.
+ * It is the callers responsibility to free it.
+ *
+ */
+static const char* get_timestamp(TALLOC_CTX *frame)
+{
+	char buffer[40];	/* formatted time less usec and timezone */
+	char tz[10];		/* formatted time zone			 */
+	struct tm* tm_info;	/* current local time			 */
+	struct timeval tv;	/* current system time			 */
+	int r;			/* response code from gettimeofday	 */
+	const char * ts;	/* formatted time stamp			 */
+
+	r = gettimeofday(&tv, NULL);
+	if (r) {
+		DBG_ERR("Unable to get time of day: (%d) %s\n",
+			errno,
+			strerror(errno));
+		return NULL;
+	}
+
+	tm_info = localtime(&tv.tv_sec);
+	if (tm_info == NULL) {
+		DBG_ERR("Unable to determine local time\n");
+		return NULL;
+	}
+
+	strftime(buffer, sizeof(buffer)-1, "%a, %d %b %Y %H:%M:%S", tm_info);
+	strftime(tz, sizeof(tz)-1, "%Z", tm_info);
+	ts = talloc_asprintf(frame, "%s.%06ld %s", buffer, tv.tv_usec, tz);
+	if (ts == NULL) {
+		DBG_ERR("Out of memory formatting time stamp\n");
+	}
+	return ts;
+}
+static const char *get_remote_host(
+	struct ldb_context *ldb,
+	TALLOC_CTX *mem_ctx)
+{
+	struct tsocket_address *remote_address;
+	const char* remote_host = NULL;
+
+	remote_address = get_remote_address(ldb);
+	if (remote_address == NULL) {
+		remote_host = talloc_asprintf(mem_ctx, "Unknown");
+		return remote_host;
+	}
+
+	remote_host = tsocket_address_string(remote_address, mem_ctx);
+	return remote_host;
+}
+
+static const char* get_primary_dn(const struct ldb_request *request) {
+	switch (request->operation) {
+	case LDB_ADD:
+		return ldb_dn_get_linearized(request->op.add.message->dn);
+	case LDB_MODIFY:
+		return ldb_dn_get_linearized(request->op.mod.message->dn);
+	case LDB_DELETE:
+		return ldb_dn_get_linearized(request->op.del.dn);
+	case LDB_RENAME:
+		return ldb_dn_get_linearized(request->op.rename.olddn);
+	default:
+		return NULL;
+	}
+}
+
+static const struct ldb_message *get_message(const struct ldb_request *request) {
+	switch (request->operation) {
+	case LDB_ADD:
+		return request->op.add.message;
+	case LDB_MODIFY:
+		return request->op.mod.message;
+	default:
+		return NULL;
+	}
+}
+
+static const char* get_secondary_dn(const struct ldb_request *request) {
+	switch (request->operation) {
+	case LDB_RENAME:
+		return ldb_dn_get_linearized(request->op.rename.newdn);
+	default:
+		return NULL;
+	}
+}
+
+static const char *get_operation_name(const struct ldb_request *request) {
+	switch (request->operation) {
+	case LDB_SEARCH:
+		return "Search";
+	case LDB_ADD:
+		return "Add";
+	case LDB_MODIFY:
+		return "Modify";
+	case LDB_DELETE:
+		return "Delete";
+	case LDB_RENAME:
+		return "Rename";
+	case LDB_EXTENDED:
+		return "Extended";
+	case LDB_REQ_REGISTER_CONTROL:
+		return "Register Control";
+	case LDB_REQ_REGISTER_PARTITION:
+		return "Register Partition";
+	default:
+		return "Unknown";
+	}
+}
+
+static const char *get_modification_action(unsigned int flags) {
+	switch (flags & LDB_FLAG_MOD_MASK) {
+	case LDB_FLAG_MOD_ADD:
+		return "add";
+	case LDB_FLAG_MOD_DELETE:
+		return "delete";
+	case LDB_FLAG_MOD_REPLACE:
+		return "replace";
+	default:
+		return "";
+	}
+}
+
+static bool has_password_changed(const struct ldb_message *message)
+{
+	int i;
+	if (message == NULL) {
+		return false;
+	}
+	for (i=0;i<message->num_elements;i++) {
+		if (ldb_attr_in_list(password_attributes,
+				     message->elements[i].name)) {
+			return true;
+		}
+	}
+	return false;
+}
+
+static const char *get_password_action(const struct ldb_request *request)
+{
+	if(request->operation == LDB_ADD) {
+		return "Reset";
+	} else {
+		struct ldb_control *pav_ctrl = NULL;
+		struct dsdb_control_password_acl_validation *pav = NULL;
+
+		pav_ctrl = ldb_request_get_control(
+			discard_const(request),
+			DSDB_CONTROL_PASSWORD_ACL_VALIDATION_OID);
+		if (pav_ctrl == NULL) {
+			return "Change";
+		}
+
+		pav = talloc_get_type_abort(
+			pav_ctrl->data,
+			struct dsdb_control_password_acl_validation);
+
+		if (pav == NULL) {
+			return "Change";
+		}
+		if (pav->pwd_reset) {
+			return "Reset";
+		} else {
+			return "Change";
+		}
+	}
+}
+
+
+#ifdef HAVE_JANSSON
+
+#include <jansson.h>
+#include "system/time.h"
+
+static NTSTATUS get_event_server(struct imessaging_context *msg_ctx,
+				      struct server_id *auth_event_server)
+{
+	NTSTATUS status;
+	TALLOC_CTX *frame = talloc_stackframe();
+	unsigned num_servers, i;
+	struct server_id *servers;
+
+	status = irpc_servers_byname(msg_ctx, frame,
+				     AUTH_EVENT_NAME,
+				     &num_servers, &servers);
+
+	if (!NT_STATUS_IS_OK(status)) {
+		DBG_NOTICE("Failed to find 'auth_event' registered on the "
+			   "message bus to send JSON authentication events to: %s\n",
+			   nt_errstr(status));
+		TALLOC_FREE(frame);
+		return status;
+	}
+
+	/*
+	 * Select the first server that is listening, because
+	 * we get connection refused as
+	 * NT_STATUS_OBJECT_NAME_NOT_FOUND without waiting
+	 */
+	for (i = 0; i < num_servers; i++) {
+		status = imessaging_send(msg_ctx, servers[i], MSG_PING,
+					 &data_blob_null);
+		if (NT_STATUS_IS_OK(status)) {
+			*auth_event_server = servers[i];
+			TALLOC_FREE(frame);
+			return NT_STATUS_OK;
+		}
+	}
+	DBG_NOTICE("Failed to find a running 'auth_event' server "
+		   "registered on the message bus to send JSON "
+		   "authentication events to\n");
+	TALLOC_FREE(frame);
+	return NT_STATUS_OBJECT_NAME_NOT_FOUND;
+}
+
+static void message_send(struct imessaging_context *msg_ctx,
+		         const char *json)
+{
+	struct server_id auth_event_server;
+	NTSTATUS status;
+	DATA_BLOB json_blob = data_blob_string_const(json);
+	if (msg_ctx == NULL) {
+		return;
+	}
+
+	/* Need to refetch the address each time as the destination server may
+	 * have disconnected and reconnected in the interim, in which case
+	 * messages may get lost
+	 */
+	status = get_event_server(msg_ctx, &auth_event_server);
+	if (!NT_STATUS_IS_OK(status)) {
+		return;
+	}
+
+	status = imessaging_send(msg_ctx,
+				 auth_event_server,
+				 MSG_AUTH_LOG,
+				 &json_blob);
+
+	/* If the server crashed, try to find it again */
+	if (NT_STATUS_EQUAL(status, NT_STATUS_OBJECT_NAME_NOT_FOUND)) {
+		status = get_event_server(msg_ctx, &auth_event_server);
+		if (!NT_STATUS_IS_OK(status)) {
+			return;
+		}
+		imessaging_send(msg_ctx,
+				auth_event_server,
+				MSG_AUTH_LOG,
+				&json_blob);
+
+	}
+}
+
+/*
+ * Context required by the JSON generation
+ *  routines
+ *
+ */
+struct json_context {
+	json_t *root;
+	bool error;
+};
+
+/*
+ * Create a new json logging context.
+ *
+ * Free with a call to free_json_context
+ *
+ */
+static struct json_context get_json_context(void) {
+
+	struct json_context context;
+	context.error = false;
+
+	context.root = json_object();
+	if (context.root == NULL) {
+		context.error = true;
+		DBG_ERR("Unable to create json_object\n");
+	}
+	return context;
+}
+
+/*
+ * Create a new json logging context, with an array top level object.
+ *
+ * Free with a call to free_json_context
+ *
+ */
+static struct json_context get_json_array_context(void) {
+
+	struct json_context context;
+	context.error = false;
+
+	context.root = json_array();
+	if (context.root == NULL) {
+		context.error = true;
+		DBG_ERR("Unable to create json_array\n");
+	}
+	return context;
+}
+
+
+/*
+ * free a previously created json_context
+ *
+ */
+static void free_json_context(struct json_context *context)
+{
+	if (context->root) {
+		json_decref(context->root);
+	}
+}
+
+/*
+ * Output a JSON pair with name name and integer value value
+ *
+ */
+static void add_int(struct json_context *context,
+		    const char* name,
+		    const int value)
+{
+	int rc = 0;
+
+	if (context->error) {
+		return;
+	}
+
+	rc = json_object_set_new(context->root, name, json_integer(value));
+	if (rc) {
+		DBG_ERR("Unable to set name [%s] value [%d]\n", name, value);
+		context->error = true;
+	}
+
+}
+
+/*
+ * Output a JSON pair with name name and integer value value
+ *
+ */
+static void add_bool(struct json_context *context,
+		    const char* name,
+		    const bool value)
+{
+	int rc = 0;
+
+	if (context->error) {
+		return;
+	}
+
+	rc = json_object_set_new(context->root, name, json_boolean(value));
+	if (rc) {
+		DBG_ERR("Unable to set name [%s] value [%d]\n", name, value);
+		context->error = true;
+	}
+
+}
+
+/*
+ * Output a JSON pair with name name and string value value
+ *
+ */
+static void add_string(struct json_context *context,
+		       const char* name,
+		       const char* value)
+{
+	int rc = 0;
+
+	if (context->error) {
+		return;
+	}
+
+	if (value) {
+		rc = json_object_set_new(context->root, name, json_string(value));
+	} else {
+		rc = json_object_set_new(context->root, name, json_null());
+	}
+	if (rc) {
+		DBG_ERR("Unable to set name [%s] value [%s]\n", name, value);
+		context->error = true;
+	}
+}
+
+static void assert_is_array(struct json_context *array) {
+
+	if (array->error) {
+		return;
+	}
+
+	if (json_is_array(array->root) == false) {
+		DBG_ERR("JSON object is not an array");
+		array->error = true;
+		return;
+	}
+}
+
+/*
+ * Output a JSON pair with name name and object value
+ *
+ */
+static void add_object(struct json_context *context,
+		       const char* name,
+		       struct json_context *value)
+{
+	int rc = 0;
+
+	if (value->error) {
+		context->error = true;
+	}
+	if (context->error) {
+		return;
+	}
+
+	if (json_is_array(context->root)) {
+		rc = json_array_append_new(context->root, value->root);
+	} else if (json_is_object(context->root)) {
+		rc = json_object_set_new(context->root, name, value->root);
+	} else {
+		DBG_ERR("Invalid JSON object type\n");
+		context->error = true;
+	}
+	if (rc) {
+		DBG_ERR("Unable to add object [%s]\n", name);
+		context->error = true;
+	}
+}
+/*
+ * Output a JSON pair with name name and string value value
+ *
+ */
+static void add_stringn(struct json_context *context,
+			const char *name,
+			const char *value,
+			const size_t len)
+{
+
+	int rc = 0;
+	if (context->error) {
+		return;
+	}
+
+	if (value && len > 0) {
+		rc = json_object_set_new(context->root,
+					 "value",
+					 json_stringn(value, len));
+	} else {
+		rc = json_object_set_new(context->root, name, json_null());
+	}
+	if (rc) {
+		DBG_ERR("Unable to set name [%s] value [%s]\n", name, value);
+		context->error = true;
+	}
+}
+
+/*
+ * Add an ldb_value to a json object array
+ *
+ */
+static void add_ldb_value(struct json_context *array,
+			  const struct ldb_val lv)
+{
+
+	assert_is_array(array);
+	if (array->error) {
+		return;
+	}
+
+	if (lv.length > 0) {
+		bool base64 = ldb_should_b64_encode(NULL, &lv);
+		int len = min(lv.length, MAX_LENGTH);
+		struct json_context value = get_json_context();
+		TALLOC_CTX *frame = talloc_stackframe();
+		if (lv.length > MAX_LENGTH) {
+			add_bool(&value, "truncated", true);
+		}
+		if (base64) {
+			const char *encoded = ldb_base64_encode(frame,
+								(char*) lv.data,
+								len);
+
+
+			add_bool(&value, "base64", true);
+			add_string(&value, "value", encoded);
+		} else {
+			add_stringn(&value, "value", (char *)lv.data, len);
+		}
+		TALLOC_FREE(frame);
+		/*
+		 * As array is a JSON array the element name is NULL
+		 */
+		add_object(array, NULL, &value);
+	}
+}
+
+/*
+ * Output a version object
+ *
+ * "version":{"major":1,"minor":0}
+ *
+ */
+static void add_version(struct json_context *context, int major, int minor)
+{
+	struct json_context version = get_json_context();
+	add_int(&version, "major", major);
+	add_int(&version, "minor", minor);
+	add_object(context, "version", &version);
+}
+
+/*
+ * Output the current date and time as a timestamp in ISO 8601 format
+ *
+ * "timestamp":"2017-03-06T17:18:04.455081+1300"
+ *
+ */
+static void add_timestamp(struct json_context *context)
+{
+	char buffer[40];	/* formatted time less usec and timezone */
+	char timestamp[50];	/* the formatted ISO 8601 time stamp	 */
+	char tz[10];		/* formatted time zone			 */
+	struct tm* tm_info;	/* current local time			 */
+	struct timeval tv;	/* current system time			 */
+	int r;			/* response code from gettimeofday	 */
+
+	if (context->error) {
+		return;
+	}
+
+	r = gettimeofday(&tv, NULL);
+	if (r) {
+		DBG_ERR("Unable to get time of day: (%d) %s\n",
+			errno,
+			strerror(errno));
+		context->error = true;
+		return;
+	}
+
+	tm_info = localtime(&tv.tv_sec);
+	if (tm_info == NULL) {
+		DBG_ERR("Unable to determine local time\n");
+		context->error = true;
+		return;
+	}
+
+	strftime(buffer, sizeof(buffer)-1, "%Y-%m-%dT%T", tm_info);
+	strftime(tz, sizeof(tz)-1, "%z", tm_info);
+	snprintf(timestamp, sizeof(timestamp),"%s.%06ld%s",
+		 buffer, tv.tv_usec, tz);
+	add_string(context,"timestamp", timestamp);
+}
+
+
+/*
+ * Output an address pair, with name name.
+ *
+ * "localAddress":"ipv6::::0"
+ *
+ */
+static void add_address(struct json_context *context,
+			const char *name,
+			const struct tsocket_address *address)
+{
+	char *s = NULL;
+	TALLOC_CTX *frame = talloc_stackframe();
+
+	if (context->error) {
+		return;
+	}
+
+	s = tsocket_address_string(address, frame);
+	add_string(context, name, s);
+	talloc_free(frame);
+
+}
+
+/*
+ * Add a formatted string representation of a sid to a json object.
+ *
+ * "sid":"S-1-5-18"
+ *
+ */
+static void add_sid(struct json_context *context,
+		    const char *name,
+		    const struct dom_sid *sid)
+{
+	char sid_buf[DOM_SID_STR_BUFLEN];
+
+	if (context->error) {
+		return;
+	}
+
+	dom_sid_string_buf(sid, sid_buf, sizeof(sid_buf));
+	add_string(context, name, sid_buf);
+}
+
+/*
+ * Add a formatted string representation of a GUID to a json object.
+ *
+ */
+static void add_guid(struct json_context *context,
+		     const char *name,
+		     struct GUID *guid)
+{
+
+	char *guid_str;
+	struct GUID_txt_buf guid_buff;
+
+	if (context->error) {
+		return;
+	}
+
+        guid_str = GUID_buf_string(guid, &guid_buff);
+	add_string(context, name, guid_str);
+}
+
+static struct json_context attributes_json(
+	enum ldb_request_type operation,
+	const struct ldb_message* message)
+{
+
+	struct json_context attributes = get_json_context();
+	int i, j;
+	for (i=0;i<message->num_elements;i++) {
+		struct json_context values = get_json_array_context();
+		struct json_context attribute = get_json_context();
+		bool redact = ldb_attr_in_list(
+			secret_attributes,
+			message->elements[i].name);
+		if (redact) {
+			add_bool(&attribute, "redacted", true);
+			add_object(&attributes,
+				   message->elements[i].name,
+				   &attribute);
+			continue;
+		}
+
+		if (operation == LDB_MODIFY) {
+			const char *action =NULL;
+			action = get_modification_action(
+				message->elements[i].flags);
+			add_string(&attribute, "action" , action);
+		}
+
+		for (j=0;j<message->elements[i].num_values;j++) {
+			add_ldb_value(&values,
+				      message->elements[i].values[j]);
+		}
+		add_object(&attribute, "values", &values);
+		add_object(&attributes, message->elements[i].name, &attribute);
+	}
+
+	return attributes;
+}
+
+static char *operation_json(
+	TALLOC_CTX *mem_ctx,
+	struct ldb_module *module,
+	const struct ldb_request *request,
+	const int ret)
+{
+	struct ldb_context *ldb = NULL;
+	const struct dom_sid *sid = NULL;
+	struct json_context context = {.error = false, .root = NULL};
+	struct json_context audit   = {.error = false, .root = NULL};
+	const struct tsocket_address *remote = NULL;
+	const char *dn = NULL;
+	const char* operation = NULL;
+	char* json = NULL;
+	char* log_entry = NULL;
+	const struct ldb_message *message = NULL;
+	struct audit_context *ac =
+		talloc_get_type(ldb_module_get_private(module),
+				struct audit_context);
+
+	ldb = ldb_module_get_ctx(module);
+
+	remote = get_remote_address(ldb);
+	sid = get_user_sid(module);
+	dn = get_primary_dn(request);
+	operation = get_operation_name(request);
+
+	context = get_json_context();
+	add_timestamp(&context);
+	add_string(&context, "type", AUDIT_JSON_TYPE);
+	if (context.error) {
+		goto exit;
+	}
+
+	audit = get_json_context();
+	add_version(&audit, AUDIT_MAJOR, AUDIT_MINOR);
+	add_string(&audit, "status", ldb_strerror(ret));
+	add_string(&audit, "operation", operation);
+	add_address(&audit, "remoteAddress", remote);
+	add_sid(&audit, "userSid", sid);
+	add_string(&audit, "dn", dn);
+	add_guid(&audit, "transactionId", &ac->transaction_guid);
+
+	message = get_message(request);
+	if (message != NULL) {
+		struct json_context attributes = attributes_json(request->operation, message);
+		add_object(&audit, "attributes", &attributes);
+	}
+	add_object(&context, AUDIT_JSON_TYPE, &audit);
+	if (context.error) {
+		free_json_context(&audit);
+		goto exit;
+	}
+
+
+	json = json_dumps(context.root, 0);
+	if (json == NULL) {
+		DBG_ERR("Unable to convert JSON object to string\n");
+		goto exit;
+	}
+
+	log_entry = talloc_strdup(mem_ctx, json);
+
+exit:
+	if (json != NULL) {
+		free(json);
+	}
+	free_json_context(&context);
+	return log_entry;
+}
+
+static char *password_change_json(
+	TALLOC_CTX *mem_ctx,
+	struct ldb_module *module,
+	const struct ldb_request *request,
+	const int ret)
+{
+	struct ldb_context *ldb = NULL;
+	const struct dom_sid *sid = NULL;
+	const char* dn = NULL;
+	const char* new_dn = NULL;
+	struct json_context context;
+	struct json_context audit;
+	const struct tsocket_address *remote = NULL;
+	char* json = NULL;
+	char* log_entry = NULL;
+	const char* action = NULL;
+	struct audit_context *ac =
+		talloc_get_type(ldb_module_get_private(module),
+				struct audit_context);
+
+
+	TALLOC_CTX *frame = talloc_stackframe();
+
+
+	ldb = ldb_module_get_ctx(module);
+
+	remote = get_remote_address(ldb);
+	sid = get_user_sid(module);
+	dn = get_primary_dn(request);
+	new_dn = get_secondary_dn(request);
+	action = get_password_action(request);
+	context = get_json_context();
+
+	add_timestamp(&context);
+	add_string(&context, "type", PASSWORD_JSON_TYPE);
+
+	if (context.error) {
+		goto exit;
+	}
+	audit = get_json_context();
+	add_version(&audit, PASSWORD_MAJOR, PASSWORD_MINOR);
+	add_string(&audit, "status", ldb_strerror(ret));
+	add_address(&audit, "remoteAddress", remote);
+	add_sid(&audit, "userSid", sid);
+	add_string(&audit, "dn", dn);
+	add_string(&audit, "action", action);
+	add_guid(&audit, "transactionId", &ac->transaction_guid);
+	if(new_dn != NULL) {
+		add_string(&audit, "newDn", new_dn);
+	}
+
+	add_object(&context, PASSWORD_JSON_TYPE, &audit);
+
+	json = json_dumps(context.root, 0);
+	if (json == NULL) {
+		DBG_ERR("Unable to convert JSON object to string\n");
+		goto exit;
+	}
+
+	log_entry = talloc_strdup(mem_ctx, json);
+
+exit:
+	if (json != NULL) {
+		free(json);
+	}
+	free_json_context(&context);
+	TALLOC_FREE(frame);
+	return log_entry;
+}
+
+static char *transaction_json(
+	TALLOC_CTX *mem_ctx,
+	const char *action,
+	struct GUID *transaction_id)
+{
+	struct json_context context = {.error = false, .root = NULL};
+	struct json_context audit   = {.error = false, .root = NULL};
+	char* json = NULL;
+	char* log_entry = NULL;
+
+	context = get_json_context();
+	add_timestamp(&context);
+	add_string(&context, "type", TRANSACTION_JSON_TYPE);
+	if (context.error) {
+		goto exit;
+	}
+
+	audit = get_json_context();
+	add_version(&audit, TRANSACTION_MAJOR, TRANSACTION_MINOR);
+	add_string(&audit, "action", action);
+	add_guid(&audit, "transactionId", transaction_id);
+
+	add_object(&context, TRANSACTION_JSON_TYPE, &audit);
+
+	json = json_dumps(context.root, 0);
+	if (json == NULL) {
+		DBG_ERR("Unable to convert JSON object to string\n");
+		goto exit;
+	}
+
+	log_entry = talloc_strdup(mem_ctx, json);
+
+exit:
+	if (json != NULL) {
+		free(json);
+	}
+	free_json_context(&context);
+	return log_entry;
+}
+
+
+#endif
+
+static char *password_change_human_readable(
+	TALLOC_CTX *mem_ctx,
+	struct ldb_module *module,
+	const struct ldb_request *request,
+	int ret)
+{
+	struct ldb_context *ldb = NULL;
+	const char *remote_host = NULL;
+	const struct dom_sid *sid = NULL;
+	const char *user_sid = NULL;
+	const char *timestamp = NULL;
+	char *log_entry = NULL;
+	const char *action = NULL;
+	const char *dn = NULL;
+	const char* transaction_id;
+	struct GUID_txt_buf guid_buff;
+	struct audit_context *ac =
+		talloc_get_type(ldb_module_get_private(module),
+				struct audit_context);
+
+	TALLOC_CTX *frame = talloc_stackframe();
+
+	ldb = ldb_module_get_ctx(module);
+
+	remote_host = get_remote_host(ldb, frame);
+	sid = get_user_sid(module);
+	user_sid = dom_sid_string(frame, sid);
+	timestamp = get_timestamp(frame);
+	action = get_password_action(request);
+	dn = get_primary_dn(request);
+        transaction_id = GUID_buf_string(&ac->transaction_guid, &guid_buff);
+
+	log_entry = talloc_asprintf(
+		frame,
+		"[%s] at [%s] transaction id [%s] status [%s] "
+		"remote host [%s] SID [%s] DN [%s]",
+		action,
+		timestamp,
+		transaction_id,
+		ldb_strerror(ret),
+		remote_host,
+		user_sid,
+		dn);
+	TALLOC_FREE(frame);
+	return log_entry;
+}
+
+static char *log_attributes(struct ldb_context *ldb,
+			    char *buffer,
+			    enum ldb_request_type operation,
+			    const struct ldb_message *message)
+{
+	int i, j;
+	for (i=0;i<message->num_elements;i++) {
+		if (i > 0) {
+			buffer = talloc_asprintf_append_buffer(buffer, " ");
+		}
+
+		if (message->elements[i].name == NULL) {
+			ldb_debug(ldb,
+				  LDB_DEBUG_ERROR,
+				  "Error: Invalid element name (NULL) at "
+				  "position %d", i);
+			return NULL;
+		}
+
+		if (operation == LDB_MODIFY) {
+			const char *action =NULL;
+			action = get_modification_action(
+				message->elements[i].flags);
+			buffer = talloc_asprintf_append_buffer(
+				buffer,
+				"%s: %s ",
+				action,
+				message->elements[i].name);
+		} else {
+			buffer = talloc_asprintf_append_buffer(
+				buffer,
+				"%s ",
+				message->elements[i].name);
+		}
+
+		if (ldb_attr_in_list(secret_attributes, message->elements[i].name)) {
+			/* Do not log the value of any secret attributes */
+			buffer = talloc_asprintf_append_buffer(
+				buffer,
+				"[REDACTED SECRET ATTRIBUTE]");
+			continue;
+		}
+
+		for (j=0;j<message->elements[i].num_values;j++) {
+			struct ldb_val v;
+			bool use_b64_encode = false;
+			int length;
+			if (j > 0) {
+				buffer = talloc_asprintf_append_buffer(buffer, " ");
+			}
+
+			v = message->elements[i].values[j];
+			length = min(MAX_LENGTH, v.length);
+			use_b64_encode = ldb_should_b64_encode(ldb, &v);
+			if (use_b64_encode) {
+				const char *encoded = ldb_base64_encode(
+					buffer,
+					(char *)v.data,
+					length);
+				buffer = talloc_asprintf_append_buffer(
+					buffer,
+				        "{%s%s}",
+					encoded,
+					(v.length > MAX_LENGTH ? "..." : ""));
+			} else {
+				buffer = talloc_asprintf_append_buffer(
+					buffer,
+					"[%*.*s%s]",
+					length,
+					length,
+					(char *)v.data,
+					(v.length > MAX_LENGTH ? "..." : ""));
+			}
+		}
+	}
+	return buffer;
+}
+
+static char *operation_human_readable(
+	TALLOC_CTX *mem_ctx,
+	struct ldb_module *module,
+	const struct ldb_request *request,
+	const int ret)
+{
+	struct ldb_context *ldb = NULL;
+	const char *remote_host = NULL;
+	const struct dom_sid *sid = NULL;
+	const char *user_sid = NULL;
+	const char *timestamp = NULL;
+	const char *op_name = NULL;
+	char *log_entry = NULL;
+	const char *dn = NULL;
+	const char *new_dn = NULL;
+	const struct ldb_message *message = NULL;
+	const char* transaction_id;
+	struct GUID_txt_buf guid_buff;
+	struct audit_context *ac =
+		talloc_get_type(ldb_module_get_private(module),
+				struct audit_context);
+
+	TALLOC_CTX *frame = talloc_stackframe();
+
+	ldb = ldb_module_get_ctx(module);
+
+	remote_host = get_remote_host(ldb, frame);
+	sid = get_user_sid(module);
+	user_sid = dom_sid_string(frame, sid);
+	timestamp = get_timestamp(frame);
+	op_name = get_operation_name(request);
+	dn = get_primary_dn(request);
+	new_dn = get_secondary_dn(request);
+        transaction_id = GUID_buf_string(&ac->transaction_guid, &guid_buff);
+
+	message = get_message(request);
+
+	log_entry = talloc_asprintf(
+		mem_ctx,
+		"[%s] at [%s] transaction id [%s] status [%s] "
+		"remote host [%s] SID [%s] DN [%s]",
+		op_name,
+		timestamp,
+		transaction_id,
+		ldb_strerror(ret),
+		remote_host,
+		user_sid,
+		dn);
+	if (new_dn != NULL) {
+		log_entry = talloc_asprintf_append_buffer(
+			log_entry,
+			" New DN [%s]",
+			new_dn);
+	}
+	if (message != NULL) {
+		log_entry = talloc_asprintf_append_buffer(log_entry,
+							  " attributes [");
+		log_entry = log_attributes(ldb,
+					   log_entry,
+					   request->operation,
+					   message);
+		log_entry = talloc_asprintf_append_buffer(log_entry, "]");
+	}
+	TALLOC_FREE(frame);
+	return log_entry;
+}
+
+static char *transaction_human_readable(
+	TALLOC_CTX *mem_ctx,
+	const char* action,
+	struct GUID *transaction_id)
+{
+	const char *timestamp = NULL;
+	char *log_entry = NULL;
+	const char* transaction_str;
+	struct GUID_txt_buf guid_buff;
+
+	TALLOC_CTX *frame = talloc_stackframe();
+
+	timestamp = get_timestamp(frame);
+        transaction_str = GUID_buf_string(transaction_id, &guid_buff);
+
+	log_entry = talloc_asprintf(
+		mem_ctx,
+		"[%s] at [%s] transaction id [%s]",
+		action,
+		timestamp,
+		transaction_str);
+	TALLOC_FREE(frame);
+	return log_entry;
+}
+
+static void log_operation(
+	struct ldb_module *module,
+	const struct ldb_request *request,
+	const int ret)
+{
+
+	const struct ldb_message *message = get_message(request);
+	bool password_changed = has_password_changed(message);
+	char *entry = NULL;
+	struct audit_context *ac =
+		talloc_get_type(ldb_module_get_private(module),
+				struct audit_context);
+
+	TALLOC_CTX *frame = talloc_stackframe();
+
+	if (CHECK_DEBUGLVLC(DBGC_SAMDB_AUDIT, DBGLVL_INFO)) {
+		entry = operation_human_readable(frame,
+						 module,
+						 request,
+						 ret);
+		log_message(AUDIT_HR_TAG, entry);
+	}
+	if (CHECK_DEBUGLVLC(DBGC_PWD_AUDIT, DBGLVL_INFO)) {
+		if (password_changed) {
+			TALLOC_FREE(entry);
+			entry = password_change_human_readable(frame,
+							       module,
+							       request,
+							       ret);
+			log_message(PASSWORD_HR_TAG, entry);
+		}
+	}
+#ifdef HAVE_JANSSON
+	if (CHECK_DEBUGLVLC(DBGC_SAMDB_AUDIT_JSON, DBGLVL_INFO)) {
+		entry = operation_json(frame, module, request, ret);
+		log_message(AUDIT_JSON_TAG, entry);
+		message_send(ac->msg_ctx, entry);
+	}
+	if (CHECK_DEBUGLVLC(DBGC_PWD_AUDIT_JSON, DBGLVL_INFO)) {
+		if (password_changed) {
+			TALLOC_FREE(entry);
+			entry = password_change_json(frame,
+						     module,
+						     request,
+						     ret);
+			log_message(PASSWORD_JSON_TAG, entry);
+			message_send(ac->msg_ctx, entry);
+		}
+	}
+#endif
+	TALLOC_FREE(frame);
+}
+
+static void log_transaction(
+	struct ldb_module *module,
+	const char *action)
+{
+
+	struct audit_context *ac =
+		talloc_get_type(ldb_module_get_private(module),
+				struct audit_context);
+	const char* entry = NULL;
+
+	TALLOC_CTX *frame = talloc_stackframe();
+
+	if (CHECK_DEBUGLVLC(DBGC_SAMDB_AUDIT, DBGLVL_INFO)
+	    || CHECK_DEBUGLVLC(DBGC_PWD_AUDIT, DBGLVL_INFO)) {
+		entry = transaction_human_readable(frame,
+						   action,
+						   &ac->transaction_guid);
+		log_message(TRANSACTION_HR_TAG, entry);
+	}
+#ifdef HAVE_JANSSON
+	if (CHECK_DEBUGLVLC(DBGC_SAMDB_AUDIT_JSON, DBGLVL_INFO)
+	    || CHECK_DEBUGLVLC(DBGC_PWD_AUDIT_JSON, DBGLVL_INFO)) {
+		entry = transaction_json(frame, action, &ac->transaction_guid);
+		log_message(TRANSACTION_JSON_TAG, entry);
+		message_send(ac->msg_ctx, entry);
+	}
+#endif
+	TALLOC_FREE(frame);
+}
+
+static int log_add(
+	struct ldb_module *module,
+	struct ldb_request *req)
+{
+
+	int ret = ldb_next_request(module, req);
+	log_operation(module, req, ret);
+	return ret;
+}
+
+static int log_delete(
+	struct ldb_module *module,
+	struct ldb_request *req)
+{
+
+	int ret = ldb_next_request(module, req);
+	log_operation(module, req, ret);
+	return ret;
+}
+
+static int log_modify(
+	struct ldb_module *module,
+	struct ldb_request *req)
+{
+	int ret = ldb_next_request(module, req);
+	log_operation(module, req, ret);
+	return ret;
+}
+
+static int log_rename(
+	struct ldb_module *module,
+	struct ldb_request *req)
+{
+	int ret = ldb_next_request(module, req);
+	log_operation(module, req, ret);
+	return ret;
+}
+
+static int log_search(
+	struct ldb_module *module,
+	struct ldb_request *req)
+{
+
+	return ldb_next_request(module, req);
+}
+
+static int log_start_transaction(struct ldb_module *module)
+{
+	struct audit_context *ac =
+		talloc_get_type(ldb_module_get_private(module),
+				struct audit_context);
+
+	/*
+	 * We do not currently log transaction begins
+	 *
+	 */
+	ac->transaction_guid = GUID_random();
+	return ldb_next_start_trans(module);
+}
+
+static int log_end_transaction(struct ldb_module *module)
+{
+	struct audit_context *ac =
+		talloc_get_type(ldb_module_get_private(module),
+				struct audit_context);
+
+	/*
+	 * We do not currently log transaction commits
+	 */
+	memset(&ac->transaction_guid, 0, sizeof(struct GUID));
+
+	return ldb_next_end_trans(module);
+}
+
+static int log_del_transaction(struct ldb_module *module)
+{
+	struct audit_context *ac =
+		talloc_get_type(ldb_module_get_private(module),
+				struct audit_context);
+
+	log_transaction(module, "rollback");
+	memset(&ac->transaction_guid, 0, sizeof(struct GUID));
+	return ldb_next_del_trans(module);
+}
+
+static int log_init(struct ldb_module *module)
+{
+
+	struct ldb_context *ldb = ldb_module_get_ctx(module);
+	struct audit_context *context = NULL;
+	struct loadparm_context *lp_ctx
+		= talloc_get_type_abort(ldb_get_opaque(ldb, "loadparm"),
+					struct loadparm_context);
+
+	context = talloc_zero(module, struct audit_context);
+	if (context == NULL) {
+		return ldb_module_oom(module);
+	}
+	context->msg_ctx = imessaging_client_init(context,
+					 	  lp_ctx,
+					 	  ldb_get_event_context(ldb));
+
+	ldb_module_set_private(module, context);
+	return ldb_next_init(module);
+}
+
+static const struct ldb_module_ops ldb_audit_log_module_ops = {
+	.name              = "audit_log",
+	.search            = log_search,
+	.add		   = log_add,
+	.modify		   = log_modify,
+	.del		   = log_delete,
+	.rename		   = log_rename,
+	.init_context	   = log_init,
+	.start_transaction = log_start_transaction,
+	.end_transaction   = log_end_transaction,
+	.del_transaction   = log_del_transaction,
+};
+
+int ldb_audit_log_module_init(const char *version)
+{
+	LDB_MODULE_CHECK_VERSION(version);
+	return ldb_register_module(&ldb_audit_log_module_ops);
+}
diff --git a/source4/dsdb/samdb/ldb_modules/samba_dsdb.c b/source4/dsdb/samdb/ldb_modules/samba_dsdb.c
index e0acb4e..fc3dc9e 100644
--- a/source4/dsdb/samdb/ldb_modules/samba_dsdb.c
+++ b/source4/dsdb/samdb/ldb_modules/samba_dsdb.c
@@ -289,7 +289,8 @@ static int samba_dsdb_init(struct ldb_module *module)
 					     "extended_dn_store",
 					     NULL };
 	/* extended_dn_in or extended_dn_in_openldap goes here */
-	static const char *modules_list1a[] = {"objectclass",
+	static const char *modules_list1a[] = {"audit_log",
+					     "objectclass",
 					     "tombstone_reanimate",
 					     "descriptor",
 					     "acl",
diff --git a/source4/dsdb/samdb/ldb_modules/tests/test_audit_log.c b/source4/dsdb/samdb/ldb_modules/tests/test_audit_log.c
new file mode 100644
index 0000000..66adced
--- /dev/null
+++ b/source4/dsdb/samdb/ldb_modules/tests/test_audit_log.c
@@ -0,0 +1,153 @@
+/*
+   Unit tests for the audit logging code in audit_log.c
+
+   Copyright (C) Andrew Bartlett <abartlet at samba.org> 2018
+
+   This program is free software; you can redistribute it and/or modify
+   it under the terms of the GNU General Public License as published by
+   the Free Software Foundation; either version 3 of the License, or
+   (at your option) any later version.
+
+   This program is distributed in the hope that it will be useful,
+   but WITHOUT ANY WARRANTY; without even the implied warranty of
+   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+   GNU General Public License for more details.
+
+   You should have received a copy of the GNU General Public License
+   along with this program.  If not, see <http://www.gnu.org/licenses/>.
+*/
+
+#include <stdarg.h>
+#include <stddef.h>
+#include <setjmp.h>
+#include <unistd.h>
+#include <cmocka.h>
+
+int ldb_audit_log_module_init(const char *version);
+#define TEST_AUDIT_LOG
+#include "../audit_log.c"
+
+#define TEST_BE "tdb"
+struct ldbtest_ctx {
+	struct tevent_context *ev;
+	struct ldb_context *ldb;
+	struct ldb_module *module;
+
+	const char *dbfile;
+	const char *lockfile;   /* lockfile is separate */
+
+	const char *dbpath;
+};
+
+static void unlink_old_db(struct ldbtest_ctx *test_ctx)
+{
+	int ret;
+
+	errno = 0;
+	ret = unlink(test_ctx->lockfile);
+	if (ret == -1 && errno != ENOENT) {
+		print_error("unable to delete %s\n", test_ctx->lockfile);
+		fail();
+	}
+
+	errno = 0;
+	ret = unlink(test_ctx->dbfile);
+	if (ret == -1 && errno != ENOENT) {
+		print_error("unable to delete %s\n", test_ctx->dbfile);
+		fail();
+	}
+}
+
+static const struct ldb_module_ops eol_ops = {
+	.name              = "eol",
+	.search            = NULL,
+	.add		   = NULL,
+	.modify		   = NULL,
+	.del		   = NULL,
+	.rename		   = NULL,
+	.init_context	   = NULL
+};
+
+static int setup(void **state)
+{
+	struct ldbtest_ctx *test_ctx = NULL;
+	struct ldb_module *eol = NULL;
+	int rc;
+
+	test_ctx = talloc_zero(NULL, struct ldbtest_ctx);
+	assert_non_null(test_ctx);
+
+	test_ctx->ev = tevent_context_init(test_ctx);
+	assert_non_null(test_ctx->ev);
+
+	test_ctx->ldb = ldb_init(test_ctx, test_ctx->ev);
+	assert_non_null(test_ctx->ldb);
+
+
+
+        test_ctx->module = ldb_module_new(
+		test_ctx,
+		test_ctx->ldb,
+		"audit_log",
+		&ldb_audit_log_module_ops);
+	assert_non_null(test_ctx->module);
+	eol = ldb_module_new(test_ctx, test_ctx->ldb, "eol", &eol_ops);
+	assert_non_null(eol);
+	ldb_module_set_next(test_ctx->module, eol);
+
+	test_ctx->dbfile = talloc_strdup(test_ctx, "audittest.ldb");
+	assert_non_null(test_ctx->dbfile);
+
+	test_ctx->lockfile = talloc_asprintf(test_ctx, "%s-lock",
+					     test_ctx->dbfile);
+	assert_non_null(test_ctx->lockfile);
+
+	test_ctx->dbpath = talloc_asprintf(test_ctx,
+			TEST_BE"://%s", test_ctx->dbfile);
+	assert_non_null(test_ctx->dbpath);
+
+	unlink_old_db(test_ctx);
+
+	rc = ldb_connect(test_ctx->ldb, test_ctx->dbpath, 0, NULL);
+	assert_int_equal(rc, 0);
+	*state = test_ctx;
+	return 0;
+}
+
+static int teardown(void **state)
+{
+	struct ldbtest_ctx *test_ctx = talloc_get_type_abort(*state,
+							struct ldbtest_ctx);
+
+	unlink_old_db(test_ctx);
+	talloc_free(test_ctx);
+	return 0;
+}
+static void test_empty(void **state)
+{
+	struct ldbtest_ctx *test_ctx =
+		talloc_get_type_abort(*state, struct ldbtest_ctx);
+	struct ldb_context *ldb = test_ctx->ldb;
+	struct ldb_message *msg = ldb_msg_new(ldb);
+	//struct audit_data *data = talloc_get_type(
+	//	ldb_module_get_private(test_ctx->module),
+	//	struct audit_data);
+	//int ret = LDB_SUCCESS;
+
+	msg->dn = ldb_dn_new(msg, ldb, "dc=test");
+	ldb_msg_add_string(msg, "unicodePwd", "value01");
+
+}
+
+
+int main(void) {
+	const struct CMUnitTest tests[] = {
+		cmocka_unit_test_setup_teardown(
+			test_empty,
+			setup,
+			teardown),
+	};
+
+	cmocka_set_message_output(CM_OUTPUT_SUBUNIT);
+	return cmocka_run_group_tests(tests, NULL, NULL);
+}
diff --git a/source4/dsdb/samdb/ldb_modules/wscript_build b/source4/dsdb/samdb/ldb_modules/wscript_build
index 9e0ac28..bb7088e 100644
--- a/source4/dsdb/samdb/ldb_modules/wscript_build
+++ b/source4/dsdb/samdb/ldb_modules/wscript_build
@@ -40,6 +40,18 @@ bld.SAMBA_BINARY('test_encrypted_secrets',
             DSDB_MODULE_HELPERS
         ''',
         install=False)
+bld.SAMBA_BINARY('test_audit_log',
+        source='tests/test_audit_log.c',
+        deps='''
+            talloc
+            samba-util
+            samdb-common
+            samdb
+            cmocka
+            gnutls
+            DSDB_MODULE_HELPERS
+        ''',
+        install=False)
 
 if bld.AD_DC_BUILD_IS_ENABLED():
     bld.PROCESS_SEPARATE_RULE("server")
diff --git a/source4/dsdb/samdb/ldb_modules/wscript_build_server b/source4/dsdb/samdb/ldb_modules/wscript_build_server
index 368260a..3157ad1 100644
--- a/source4/dsdb/samdb/ldb_modules/wscript_build_server
+++ b/source4/dsdb/samdb/ldb_modules/wscript_build_server
@@ -425,3 +425,18 @@ bld.SAMBA_MODULE('ldb_encrypted_secrets',
             gnutls
         '''
 	)
+
+bld.SAMBA_MODULE('ldb_audit_log',
+	source='audit_log.c',
+	subsystem='ldb',
+	init_function='ldb_audit_log_module_init',
+	module_init_name='ldb_init_module',
+	internal_module=False,
+	deps='''
+            talloc
+            samba-util
+            samdb-common
+            DSDB_MODULE_HELPERS
+            samdb
+        '''
+	)
-- 
2.7.4


From 771915d94dec5f1c05400fc3e673753f0332fbd8 Mon Sep 17 00:00:00 2001
From: Gary Lockyer <gary at catalyst.net.nz>
Date: Wed, 4 Apr 2018 12:38:25 +1200
Subject: [PATCH 4/5] cldap: set the remote ip address

Signed-off-by: Gary Lockyer <gary at catalyst.net.nz>
---
 source4/cldap_server/rootdse.c | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/source4/cldap_server/rootdse.c b/source4/cldap_server/rootdse.c
index 3f389ce..8c616ad 100644
--- a/source4/cldap_server/rootdse.c
+++ b/source4/cldap_server/rootdse.c
@@ -166,6 +166,8 @@ void cldapd_rootdse_request(struct cldap_socket *cldap,
 	cldapd_rootdse_fill(cldapd, tmp_ctx, search, &reply.response,
 			    reply.result);
 
+	ldb_set_opaque(cldapd->samctx, "remoteAddress", NULL);
+	
 	status = cldap_reply_send(cldap, &reply);
 	if (!NT_STATUS_IS_OK(status)) {
 		DEBUG(2,("cldap rootdse query failed '%s' - %s\n",
-- 
2.7.4


From a18b6cf3fec785264dc2124f008868fcbab803eb Mon Sep 17 00:00:00 2001
From: Gary Lockyer <gary at catalyst.net.nz>
Date: Wed, 4 Apr 2018 12:39:55 +1200
Subject: [PATCH 5/5] dsdb pass the remote address to samdb connect

Signed-off-by: Gary Lockyer <gary at catalyst.net.nz>
---
 source3/passdb/pdb_samba_dsdb.c    |  2 +-
 source4/dns_server/dlz_bind9.c     |  2 +-
 source4/dsdb/samdb/samdb.c         | 37 +++++++++++++++++++++++++++++--------
 source4/dsdb/samdb/samdb.h         |  2 +-
 source4/ldap_server/ldap_backend.c |  9 +++++----
 source4/torture/dns/dlz_bind9.c    |  4 +++-
 6 files changed, 40 insertions(+), 16 deletions(-)

diff --git a/source3/passdb/pdb_samba_dsdb.c b/source3/passdb/pdb_samba_dsdb.c
index 05052a6..f48f1fd 100644
--- a/source3/passdb/pdb_samba_dsdb.c
+++ b/source3/passdb/pdb_samba_dsdb.c
@@ -3893,7 +3893,7 @@ static NTSTATUS pdb_init_samba_dsdb(struct pdb_methods **pdb_method,
 				state->lp_ctx,
 				system_session(state->lp_ctx),
 				0, location,
-				&state->ldb, &errstring);
+				NULL, &state->ldb, &errstring);
 
 	if (!state->ldb) {
 		DEBUG(0, ("samdb_connect failed: %s: %s\n",
diff --git a/source4/dns_server/dlz_bind9.c b/source4/dns_server/dlz_bind9.c
index cf171cb..17afd1f 100644
--- a/source4/dns_server/dlz_bind9.c
+++ b/source4/dns_server/dlz_bind9.c
@@ -706,7 +706,7 @@ _PUBLIC_ isc_result_t dlz_create(const char *dlzname,
 	ret = samdb_connect_url(state, state->ev_ctx, state->lp,
 				system_session(state->lp), 0,
 				state->options.url,
-				&state->samdb, &errstring);
+				NULL, &state->samdb, &errstring);
 	if (ret != LDB_SUCCESS) {
 		state->log(ISC_LOG_ERROR,
 			   "samba_dlz: Failed to connect to %s: %s",
diff --git a/source4/dsdb/samdb/samdb.c b/source4/dsdb/samdb/samdb.c
index 1f80267..7a1bb79 100644
--- a/source4/dsdb/samdb/samdb.c
+++ b/source4/dsdb/samdb/samdb.c
@@ -42,6 +42,7 @@
 #include "auth/credentials/credentials.h"
 #include "param/secrets.h"
 #include "auth/auth.h"
+#include "lib/tsocket/tsocket.h"
 
 /*
   connect to the SAM database specified by URL
@@ -51,7 +52,9 @@ int samdb_connect_url(TALLOC_CTX *mem_ctx,
 		      struct tevent_context *ev_ctx,
 		      struct loadparm_context *lp_ctx,
 		      struct auth_session_info *session_info,
-		      unsigned int flags, const char *url,
+		      unsigned int flags,
+		      const char *url,
+		      struct tsocket_address *remote_address,
 		      struct ldb_context **ldb_ret,
 		      char **errstring)
 {
@@ -59,13 +62,17 @@ int samdb_connect_url(TALLOC_CTX *mem_ctx,
 	int ret;
 	*ldb_ret = NULL;
 	*errstring = NULL;
-	ldb = ldb_wrap_find(url, ev_ctx, lp_ctx, session_info, NULL, flags);
-	if (ldb != NULL) {
-		*ldb_ret = talloc_reference(mem_ctx, ldb);
-		if (*ldb_ret == NULL) {
-			return LDB_ERR_OPERATIONS_ERROR;
+
+	if (remote_address == NULL) {
+		ldb = ldb_wrap_find(url, ev_ctx, lp_ctx,
+				    session_info, NULL, flags);
+		if (ldb != NULL) {
+			*ldb_ret = talloc_reference(mem_ctx, ldb);
+			if (*ldb_ret == NULL) {
+				return LDB_ERR_OPERATIONS_ERROR;
+			}
+			return LDB_SUCCESS;
 		}
-		return LDB_SUCCESS;
 	}
 
 	ldb = samba_ldb_init(mem_ctx, ev_ctx, lp_ctx, session_info, NULL);
@@ -91,6 +98,20 @@ int samdb_connect_url(TALLOC_CTX *mem_ctx,
 		return LDB_ERR_OPERATIONS_ERROR;
 	}
 
+	/*
+	 * If a remote_address was specified, then set it on the DB
+	 * and do not add to the wrap list (as we need to keep the LDB
+	 * pointer unique for the address).
+	 *
+	 * We use this for audit logging and for the "netlogon" attribute
+	 */
+	if (remote_address != NULL) {
+		ldb_set_opaque(ldb, "remoteAddress",
+			       remote_address);
+		*ldb_ret = ldb;
+		return LDB_SUCCESS;
+	}
+		
 	if (!ldb_wrap_add(url, ev_ctx, lp_ctx, session_info, NULL, flags, ldb)) {
 		*errstring = talloc_asprintf(mem_ctx,
 					     "Failed to add cached DB reference"
@@ -118,7 +139,7 @@ struct ldb_context *samdb_connect(TALLOC_CTX *mem_ctx,
 	char *errstring;
 	struct ldb_context *ldb;
 	int ret = samdb_connect_url(mem_ctx, ev_ctx, lp_ctx, session_info, flags,
-				    "sam.ldb", &ldb, &errstring);
+				    "sam.ldb", NULL, &ldb, &errstring);
 	if (ret == LDB_SUCCESS) {
 		return ldb;
 	}
diff --git a/source4/dsdb/samdb/samdb.h b/source4/dsdb/samdb/samdb.h
index eb52740..43fae64 100644
--- a/source4/dsdb/samdb/samdb.h
+++ b/source4/dsdb/samdb/samdb.h
@@ -28,7 +28,7 @@ struct dsdb_extended_replicated_object;
 struct dsdb_extended_replicated_objects;
 struct loadparm_context;
 struct tevent_context;
-
+struct tsocket_address;
 struct dsdb_trust_routing_table;
 
 #include "librpc/gen_ndr/security.h"
diff --git a/source4/ldap_server/ldap_backend.c b/source4/ldap_server/ldap_backend.c
index 95c7ee7..39f1aa2 100644
--- a/source4/ldap_server/ldap_backend.c
+++ b/source4/ldap_server/ldap_backend.c
@@ -31,6 +31,7 @@
 #include <ldb_errors.h>
 #include <ldb_module.h>
 #include "ldb_wrap.h"
+#include "lib/tsocket/tsocket.h"
 
 static int map_ldb_error(TALLOC_CTX *mem_ctx, int ldb_err,
 	const char *add_err_string, const char **errstring)
@@ -188,7 +189,10 @@ int ldapsrv_backend_Init(struct ldapsrv_connection *conn,
 				    conn->lp_ctx,
 				    conn->session_info,
 				    conn->global_catalog ? LDB_FLG_RDONLY : 0,
-				    "sam.ldb", &conn->ldb, errstring);
+				    "sam.ldb",
+				    conn->connection->remote_address,
+				    &conn->ldb,
+				    errstring);
 	if (ret != LDB_SUCCESS) {
 		return ret;
 	}
@@ -229,9 +233,6 @@ int ldapsrv_backend_Init(struct ldapsrv_connection *conn,
 		ldb_set_opaque(conn->ldb, "supportedSASLMechanisms", sasl_mechs);
 	}
 
-	ldb_set_opaque(conn->ldb, "remoteAddress",
-		       conn->connection->remote_address);
-
 	return LDB_SUCCESS;
 }
 
diff --git a/source4/torture/dns/dlz_bind9.c b/source4/torture/dns/dlz_bind9.c
index 2234e7a..6448713 100644
--- a/source4/torture/dns/dlz_bind9.c
+++ b/source4/torture/dns/dlz_bind9.c
@@ -92,7 +92,9 @@ static isc_result_t dlz_bind9_writeable_zone_hook(dns_view_t *view,
 				    system_session(tctx->lp_ctx),
 				    0,
 				    test_dlz_bind9_binddns_dir(tctx, "dns/sam.ldb"),
-				    &samdb, &errstring);
+				    NULL,
+				    &samdb,
+				    &errstring);
 	struct ldb_message *msg;
 	const char *attrs[] = {
 		NULL
-- 
2.7.4

-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 473 bytes
Desc: OpenPGP digital signature
URL: <http://lists.samba.org/pipermail/samba-technical/attachments/20180405/9f4c98d5/signature.sig>


More information about the samba-technical mailing list