kdc: refactor Samba-specific auditing API in terms of existing API

Make Samba-specific HDB auth status API a wrapper on the existing auditing API,
with a view towards unifying the two APIs in a future commit.

The term "auth status" is replaced with "auth event", and the HDB auth_status
method is replaced with a more general purpose audit method which has access to
the entire request structure.

kdc/kerberos5.c

@@ -38,37 +38,60 @@
 #undef __attribute__
 #define __attribute__(X)
 
-struct kdc_pa_auth_status {
+/*
-    int auth_status;
+ * Audit a HDB auth "event", generally indicating pre-authentication success or
-    const char *auth_details;
+ * failure, or client authorization success.
-    void *free_ptr;
+ */
-};
+
+static void
+audit_auth_event(astgs_request_t r, int event_type, const char *event_details)
+{
+    heim_number_t hevent_type = NULL;
+    heim_string_t hevent_details = NULL;
+
+    hevent_type = heim_number_create(event_type);
+    if (event_details)
+	hevent_details = heim_string_create(event_details);
+    /* else, clear existing details */
+
+    _kdc_audit_addkv_object((kdc_request_t)r, HDB_REQUEST_KV_AUTH_EVENT_TYPE,
+			    hevent_type);
+    if (hevent_details)
+	_kdc_audit_addkv_object((kdc_request_t)r, HDB_REQUEST_KV_AUTH_EVENT_DETAILS,
+				hevent_details);
+    else
+	_kdc_audit_delkv((kdc_request_t)r, HDB_REQUEST_KV_AUTH_EVENT_DETAILS);
+
+    heim_release(hevent_type);
+    heim_release(hevent_details);
+}
+
+/*
+ * Returns TRUE is an auth event has already been audited; used to catch-all
+ * unknown pre-authentication mechanisms.
+ */
+
+static krb5_boolean
+audited_auth_event_p(astgs_request_t r)
+{
+    return !!_kdc_audit_getkv((kdc_request_t)r, HDB_REQUEST_KV_AUTH_EVENT_TYPE);
+}
+
+/*
+ * Notify the HDB backend of the audited event.
+ */
 
 static krb5_error_code
-_kdc_audit_auth_status(astgs_request_t r,
+notify_hdb_audit(astgs_request_t r)
-		       struct kdc_pa_auth_status *status,
-		       const char *pa_type)
 {
     struct HDB *hdb;
-    krb5_error_code ret = 0;
 
-    if (r->clientdb)
+    hdb = r->clientdb ? r->clientdb : r->config->db[0];
-	hdb = r->clientdb;
-    else
-	hdb = r->config->db[0];
 
-    if (hdb && hdb->hdb_auth_status)
+    if (hdb && hdb->hdb_audit && audited_auth_event_p(r))
-	ret = hdb->hdb_auth_status(r->context,
+	return hdb->hdb_audit(r->context, hdb, r->client, (hdb_request_t)r);
-				   hdb,
-				   r->client,
-				   &r->tv_start,
-				   r->addr,
-				   r->cname,
-				   status->auth_status,
-				   status->auth_details,
-				   pa_type);
 
-    return ret;
+    return 0;
 }
 
 void
@@ -512,9 +535,7 @@ _kdc_log_timestamp(astgs_request_t r, const char *type,
 #ifdef PKINIT
 
 static krb5_error_code
-pa_pkinit_validate(astgs_request_t r,
+pa_pkinit_validate(astgs_request_t r, const PA_DATA *pa)
-		   const PA_DATA *pa,
-		   struct kdc_pa_auth_status *auth_status)
 {
     pk_client_params *pkp = NULL;
     char *client_cert = NULL;
@@ -525,7 +546,7 @@ pa_pkinit_validate(astgs_request_t r,
 	ret = KRB5KRB_AP_ERR_BAD_INTEGRITY;
 	_kdc_r_log(r, 4, "Failed to decode PKINIT PA-DATA -- %s",
 		   r->cname);
-	auth_status->auth_status = HDB_AUTHSTATUS_PKINIT_FAILURE;
+	audit_auth_event(r, HDB_AUTH_EVENT_PKINIT_FAILED, NULL);
 	goto out;
     }
 
@@ -533,11 +554,9 @@ pa_pkinit_validate(astgs_request_t r,
     if (ret) {
 	_kdc_set_e_text(r, "PKINIT certificate not allowed to "
 			"impersonate principal");
-	auth_status->auth_status = HDB_AUTHSTATUS_PKINIT_FAILURE;
+	audit_auth_event(r, HDB_AUTH_EVENT_PKINIT_FAILED, client_cert);
 	goto out;
     }
-    auth_status->auth_details = client_cert;
-    auth_status->free_ptr = client_cert;
 
     r->pa_endtime = _kdc_pk_endtime(pkp);
     if (!r->client->entry.flags.synthetic)
@@ -554,10 +573,12 @@ pa_pkinit_validate(astgs_request_t r,
     ret = _kdc_add_initial_verified_cas(r->context, r->config,
 					pkp, &r->et);
 
-    auth_status->auth_status = HDB_AUTHSTATUS_PKINIT_SUCCESS;
+    audit_auth_event(r, HDB_AUTH_EVENT_PKINIT_SUCCEEDED, client_cert);
+
  out:
     if (pkp)
 	_kdc_pk_free_client_param(r->context, pkp);
+    free(client_cert);
 
     return ret;
 }
@@ -565,9 +586,7 @@ pa_pkinit_validate(astgs_request_t r,
 #endif /* PKINIT */
 
 static krb5_error_code
-pa_gss_validate(astgs_request_t r,
+pa_gss_validate(astgs_request_t r, const PA_DATA *pa)
-		const PA_DATA *pa,
-		struct kdc_pa_auth_status *auth_status)
 {
     gss_client_params *gcp = NULL;
     char *client_name = NULL;
@@ -583,11 +602,9 @@ pa_gss_validate(astgs_request_t r,
 	if (ret) {
 	    _kdc_set_e_text(r, "GSS-API client not allowed to "
 			    "impersonate principal");
-	    auth_status->auth_status = HDB_AUTHSTATUS_GSS_FAILURE;
+	    audit_auth_event(r, HDB_AUTH_EVENT_GSS_PA_FAILED, client_name);
 	    goto out;
 	}
-	auth_status->auth_details = client_name;
-	auth_status->free_ptr = client_name;
 
 	r->pa_endtime = _kdc_gss_endtime(r, gcp);
 
@@ -609,7 +626,7 @@ pa_gss_validate(astgs_request_t r,
 	goto out;
     }
 
-    auth_status->auth_status = HDB_AUTHSTATUS_GSS_SUCCESS;
+    audit_auth_event(r, HDB_AUTH_EVENT_GSS_PA_SUCCEEDED, client_name);
 
     heim_assert(r->pa_state == NULL, "already have PA state, should be NULL");
     r->pa_state = (struct as_request_pa_state *)gcp;
@@ -618,6 +635,7 @@ pa_gss_validate(astgs_request_t r,
 out:
     if (gcp)
 	_kdc_gss_free_client_param(r, gcp);
+    free(client_name);
 
     return ret;
 }
@@ -644,9 +662,7 @@ pa_gss_cleanup(astgs_request_t r)
 }
 
 static krb5_error_code
-pa_enc_chal_validate(astgs_request_t r,
+pa_enc_chal_validate(astgs_request_t r, const PA_DATA *pa)
-		     const PA_DATA *pa,
-		     struct kdc_pa_auth_status *auth_status)
 {
     krb5_data pepper1, pepper2;
     int invalidPassword = 0;
@@ -669,7 +685,7 @@ pa_enc_chal_validate(astgs_request_t r,
        ret = KRB5KDC_ERR_CLIENT_REVOKED;
        kdc_log(r->context, r->config, 0,
                "Client (%s) is locked out", r->cname);
-       auth_status->auth_status = HDB_AUTHSTATUS_CLIENT_LOCKED_OUT;
+       audit_auth_event(r, HDB_AUTH_EVENT_CLIENT_LOCKED_OUT, NULL);
        return ret;
     }
 
@@ -795,12 +811,12 @@ pa_enc_chal_validate(astgs_request_t r,
 	/*
 	 * Success
 	 */
-	auth_status->auth_status = HDB_AUTHSTATUS_CORRECT_PASSWORD;
+	audit_auth_event(r, HDB_AUTH_EVENT_LTK_PREAUTH_SUCCEEDED, NULL);
 	goto out;
     }
 
     if (invalidPassword) {
-	auth_status->auth_status = HDB_AUTHSTATUS_WRONG_PASSWORD;
+	audit_auth_event(r, HDB_AUTH_EVENT_LTK_PREAUTH_FAILED, NULL);
 	ret = KRB5KDC_ERR_PREAUTH_FAILED;
     } else {
 	ret = KRB5KDC_ERR_ETYPE_NOSUPP;
@@ -812,9 +828,7 @@ pa_enc_chal_validate(astgs_request_t r,
 }
 
 static krb5_error_code
-pa_enc_ts_validate(astgs_request_t r,
+pa_enc_ts_validate(astgs_request_t r, const PA_DATA *pa)
-		   const PA_DATA *pa,
-		   struct kdc_pa_auth_status *auth_status)
 {
     EncryptedData enc_data;
     krb5_error_code ret;
@@ -841,7 +855,7 @@ pa_enc_ts_validate(astgs_request_t r,
        ret = KRB5KDC_ERR_CLIENT_REVOKED;
        kdc_log(r->context, r->config, 0,
                "Client (%s) is locked out", r->cname);
-       auth_status->auth_status = HDB_AUTHSTATUS_CLIENT_LOCKED_OUT;
+       audit_auth_event(r, HDB_AUTH_EVENT_CLIENT_LOCKED_OUT, NULL);
        return ret;
     }
 
@@ -910,12 +924,8 @@ pa_enc_ts_validate(astgs_request_t r,
 		   "(enctype %s) error %s",
 		   r->cname, str ? str : "unknown enctype", msg);
 	krb5_free_error_message(r->context, msg);
-
+	audit_auth_event(r, HDB_AUTH_EVENT_LTK_PREAUTH_FAILED,
-	free(auth_status->free_ptr);
+			 str ? str : "unknown enctype");
-	auth_status->auth_status = HDB_AUTHSTATUS_WRONG_PASSWORD;
-	auth_status->auth_details = str ? str : "unknown enctype";
-	auth_status->free_ptr = str;
-
 	if(hdb_next_enctype2key(r->context, &r->client->entry, NULL,
 				enc_data.etype, &pa_key) == 0)
 	    goto try_next_key;
@@ -926,10 +936,6 @@ pa_enc_ts_validate(astgs_request_t r,
 	goto out;
     }
     free_EncryptedData(&enc_data);
-    free(auth_status->free_ptr);
-    auth_status->auth_status = HDB_AUTHSTATUS_INVALID;
-    auth_status->auth_details = NULL;
-    auth_status->free_ptr = NULL;
     ret = decode_PA_ENC_TS_ENC(ts_data.data,
 			       ts_data.length,
 			       &p,
@@ -954,7 +960,7 @@ pa_enc_ts_validate(astgs_request_t r,
 		   (unsigned)labs(kdc_time - p.patimestamp),
 		   r->context->max_skew,
 		   r->cname);
-	auth_status->auth_details = "AP_ERR_SKEW";
+	audit_auth_event(r, HDB_AUTH_EVENT_CLIENT_TIME_SKEW, NULL);
 
 	/*
 	 * The following is needed to make windows clients to
@@ -980,9 +986,8 @@ pa_enc_ts_validate(astgs_request_t r,
 	       r->cname, str ? str : "unknown enctype");
     _kdc_audit_addkv((kdc_request_t)r, 0, "pa-etype", "%d",
 		     (int)pa_key->key.keytype);
-    auth_status->auth_status = HDB_AUTHSTATUS_CORRECT_PASSWORD;
+    audit_auth_event(r, HDB_AUTH_EVENT_LTK_PREAUTH_SUCCEEDED,
-    auth_status->auth_details = str ? str : "unknown enctype";
+		     str ? str : "unknown enctype");
-    auth_status->free_ptr = str;
 
     ret = 0;
 
@@ -1000,9 +1005,7 @@ struct kdc_patypes {
 #define PA_SYNTHETIC_OK	4
 #define PA_REPLACE_REPLY_KEY	8   /* PA mech replaces reply key */
 #define PA_USES_LONG_TERM_KEY	16  /* PA mech uses client's long-term key */
-    krb5_error_code (*validate)(astgs_request_t,
+    krb5_error_code (*validate)(astgs_request_t, const PA_DATA *pa);
-				const PA_DATA *pa,
-				struct kdc_pa_auth_status *auth_status);
     krb5_error_code (*finalize_pac)(astgs_request_t r);
     void (*cleanup)(astgs_request_t r);
 };
@@ -2218,12 +2221,11 @@ _kdc_as_rep(astgs_request_t r)
     }
     default:
     {
-	struct kdc_pa_auth_status auth_status = {HDB_AUTHSTATUS_CLIENT_UNKNOWN, NULL, NULL};
 	msg = krb5_get_error_message(r->context, ret);
 	kdc_log(r->context, config, 4, "UNKNOWN -- %s: %s", r->cname, msg);
 	krb5_free_error_message(r->context, msg);
 	ret = KRB5KDC_ERR_C_PRINCIPAL_UNKNOWN;
-	_kdc_audit_auth_status(r, &auth_status, NULL);
+	audit_auth_event(r, HDB_AUTH_EVENT_CLIENT_UNKNOWN, NULL);
 	goto out;
     }
     }
@@ -2284,28 +2286,22 @@ _kdc_as_rep(astgs_request_t r)
 	    i = 0;
 	    pa = _kdc_find_padata(req, &i, pat[n].type);
 	    if (pa) {
-		struct kdc_pa_auth_status auth_status = {HDB_AUTHSTATUS_INVALID, NULL, NULL};
-
                 if (r->client->entry.flags.synthetic &&
                     !(pat[n].flags & PA_SYNTHETIC_OK)) {
                     kdc_log(r->context, config, 4, "UNKNOWN -- %s", r->cname);
                     ret = KRB5KDC_ERR_C_PRINCIPAL_UNKNOWN;
                     goto out;
                 }
-                _kdc_audit_addkv((kdc_request_t)r, KDC_AUDIT_VIS, "pa", "%s",
+		_kdc_audit_addkv((kdc_request_t)r, KDC_AUDIT_VIS, "pa", "%s",
-                                 pat[n].name);
+				 pat[n].name);
-		ret = pat[n].validate(r, pa, &auth_status);
+		ret = pat[n].validate(r, pa);
 		if (ret != 0) {
 		    krb5_error_code  ret2;
 		    Key *ckey = NULL;
 		    krb5_boolean default_salt;
 
-		    if (auth_status.auth_status == HDB_AUTHSTATUS_INVALID)
+		    if (!audited_auth_event_p(r))
-			auth_status.auth_status = HDB_AUTHSTATUS_GENERIC_FAILURE;
+			audit_auth_event(r, HDB_AUTH_EVENT_OTHER_PREAUTH_FAILED, NULL);
-		    _kdc_audit_auth_status(r,
-					   &auth_status,
-					   pat[n].name);
-		    free(auth_status.free_ptr);
 
 		    /*
 		     * If there is a client key, send ETYPE_INFO{,2}
@@ -2321,17 +2317,13 @@ _kdc_as_rep(astgs_request_t r)
 		    }
 		    goto out;
 		}
+		if (!audited_auth_event_p(r))
+		    audit_auth_event(r, HDB_AUTH_EVENT_OTHER_PREAUTH_SUCCEEDED, NULL);
 		kdc_log(r->context, config, 4,
 			"%s pre-authentication succeeded -- %s",
 			pat[n].name, r->cname);
 		found_pa = 1;
 		r->pa_used = &pat[n];
-
-		if (auth_status.auth_status == HDB_AUTHSTATUS_INVALID)
-		    auth_status.auth_status = HDB_AUTHSTATUS_GENERIC_SUCCESS;
-
-		_kdc_audit_auth_status(r, &auth_status, r->pa_used->name);
-		free(auth_status.free_ptr);
 		r->et.flags.pre_authent = 1;
 	    }
 	}
@@ -2420,14 +2412,7 @@ _kdc_as_rep(astgs_request_t r)
 	r->et.flags.anonymous = 1;
     }
 
-    {
+    audit_auth_event(r, HDB_AUTH_EVENT_CLIENT_AUTHORIZED, NULL);
-	struct kdc_pa_auth_status auth_status
-		= {HDB_AUTHSTATUS_AUTHORIZATION_SUCCESS,
-		   NULL,
-		   NULL};
-
-	_kdc_audit_auth_status(r, &auth_status, NULL);
-    }
 
     /*
      * Select the best encryption type for the KDC with out regard to
@@ -2787,6 +2772,8 @@ _kdc_as_rep(astgs_request_t r)
     }
 
 out:
+    notify_hdb_audit(r);
+
     /*
      * In case of a non proxy error, build an error message.
      */

kdc/libkdc-exports.def

@@ -17,6 +17,9 @@ EXPORTS
 	krb5_kdc_update_time
 	krb5_kdc_pk_initialize
 	_kdc_audit_addkv
+	_kdc_audit_addkv_object
+	_kdc_audit_delkv
+	_kdc_audit_getkv
 	_kdc_audit_addreason
 	_kdc_audit_vaddkv
 	_kdc_audit_vaddreason

kdc/process.c

@@ -94,6 +94,24 @@ _kdc_audit_addkv_timediff(kdc_request_t r, const char *k,
     heim_audit_addkv_timediff((heim_svc_req_desc)r,k, start, end);
 }
 
+void
+_kdc_audit_addkv_object(kdc_request_t r, const char *k, heim_object_t obj)
+{
+    heim_audit_addkv_object((heim_svc_req_desc)r, k, obj);
+}
+
+void
+_kdc_audit_delkv(kdc_request_t r, const char *k)
+{
+    heim_audit_delkv((heim_svc_req_desc)r, k);
+}
+
+heim_object_t
+_kdc_audit_getkv(kdc_request_t r, const char *k)
+{
+    return heim_audit_getkv((heim_svc_req_desc)r, k);
+}
+
 /*
  * Add up to 3 key value pairs to record HostAddresses from request body or
  * PA-TGS ticket or whatever.
@@ -334,7 +352,7 @@ process_request(krb5_context context,
     r->request.length = len;
     r->datagram_reply = datagram_reply;
     r->reply = reply;
-    r->kv = heim_array_create();
+    r->kv = heim_dict_create(10);
     if (!r->kv) {
 	free(r);
 	return krb5_enomem(context);

kdc/version-script.map

@@ -21,6 +21,9 @@ HEIMDAL_KDC_1.0 {
 		krb5_kdc_update_time;
 		krb5_kdc_pk_initialize;
 		_kdc_audit_addkv;
+		_kdc_audit_addkv_object;
+		_kdc_audit_delkv;
+		_kdc_audit_getkv;
 		_kdc_audit_addreason;
 		_kdc_audit_vaddkv;
 		_kdc_audit_vaddreason;

lib/base/heimbase-svc.h

@@ -70,7 +70,8 @@
     const char *e_text;                                         \
     char *e_text_buf;                                           \
     heim_string_t reason;                                       \
-    heim_array_t kv;                                            \
+    /* auditing key/value store */                              \
+    heim_dict_t kv;                                             \
     int32_t ret
 
 #endif /* HEIMBASE_SVC_H */

lib/base/log.c

@@ -655,32 +655,34 @@ heim_add_debug_dest(heim_context context, const char *program,
     return 0;
 }
 
-static heim_string_t
+struct heim_audit_kv_tuple {
+    heim_string_t key;
+    heim_object_t value;
+};
+
+static struct heim_audit_kv_tuple zero_tuple;
+
+static struct heim_audit_kv_tuple
 fmtkv(int flags, const char *k, const char *fmt, va_list ap)
         __attribute__ ((__format__ (__printf__, 3, 0)))
 {
-    heim_string_t str;
     size_t i;
     ssize_t j;
-    char *buf1;
+    struct heim_audit_kv_tuple kv;
-    char *buf2;
+    char *value;
-    char *buf3;
+    char *value_vis;
-    int ret = vasprintf(&buf1, fmt, ap);
-    if (ret < 0 || !buf1)
-	return NULL;;
 
-    j = asprintf(&buf2, "%s=%s", k, buf1);
+    j = vasprintf(&value, fmt, ap);
-    free(buf1);
+    if (j < 0 || value == NULL)
-    if (j < 0 || !buf2)
+	return zero_tuple;
-	return NULL;;
 
     /* We optionally eat the whitespace. */
 
     if (flags & HEIM_SVC_AUDIT_EATWHITE) {
-	for (i=0, j=0; buf2[i]; i++)
+	for (i=0, j=0; value[i]; i++)
-	    if (buf2[i] != ' ' && buf2[i] != '\t')
+	    if (value[i] != ' ' && value[i] != '\t')
-		buf2[j++] = buf2[i];
+		value[j++] = value[i];
-	buf2[j] = '\0';
+	value[j] = '\0';
     }
 
     if (flags & (HEIM_SVC_AUDIT_VIS | HEIM_SVC_AUDIT_VISLAST)) {
@@ -688,48 +690,50 @@ fmtkv(int flags, const char *k, const char *fmt, va_list ap)
 
         if (flags & HEIM_SVC_AUDIT_VIS)
             vis_flags |= VIS_WHITE;
-	buf3 = malloc((j + 1) * 4 + 1);
+	value_vis = malloc((j + 1) * 4 + 1);
-        if (buf3)
+        if (value_vis)
-            strvisx(buf3, buf2, j, vis_flags);
+            strvisx(value_vis, value, j, vis_flags);
-	free(buf2);
+	free(value);
-        if (buf3 == NULL)
+        if (value_vis == NULL)
-            return NULL;
+            return zero_tuple;
     } else
-	buf3 = buf2;
+	value_vis = value;
 
-    str = heim_string_create(buf3);
+    kv.key = heim_string_create(k);
-    free(buf3);
+    kv.value = heim_string_ref_create(value_vis, free);
-    return str;
+
+    return kv;
 }
 
 void
 heim_audit_vaddreason(heim_svc_req_desc r, const char *fmt, va_list ap)
 	__attribute__ ((__format__ (__printf__, 2, 0)))
 {
-    heim_string_t str;
+    struct heim_audit_kv_tuple kv;
 
-    str = fmtkv(HEIM_SVC_AUDIT_VISLAST, "reason", fmt, ap);
+    kv = fmtkv(HEIM_SVC_AUDIT_VISLAST, "reason", fmt, ap);
-    if (!str) {
+    if (kv.key == NULL || kv.value == NULL) {
         heim_log(r->hcontext, r->logf, 1, "heim_audit_vaddreason: "
                  "failed to add reason (out of memory)");
         return;
     }
 
     heim_log(r->hcontext, r->logf, 7, "heim_audit_vaddreason(): "
-             "adding reason %s", heim_string_get_utf8(str));
+             "adding reason %s", heim_string_get_utf8(kv.value));
     if (r->reason) {
         heim_string_t str2;
 
         str2 = heim_string_create_with_format("%s: %s",
-                                              heim_string_get_utf8(str),
+                                              heim_string_get_utf8(kv.value),
                                               heim_string_get_utf8(r->reason));
         if (str2) {
-            heim_release(str);
+            heim_release(kv.value);
-            str = str2;
+            kv.value = str2;
         }
     }
     heim_release(r->reason);
-    r->reason = str;
+    r->reason = kv.value;
+    heim_release(kv.key);
 }
 
 void
@@ -754,19 +758,23 @@ heim_audit_vaddkv(heim_svc_req_desc r, int flags, const char *k,
 		  const char *fmt, va_list ap)
 	__attribute__ ((__format__ (__printf__, 4, 0)))
 {
-    heim_string_t str;
+    struct heim_audit_kv_tuple kv;
 
-    str = fmtkv(flags, k, fmt, ap);
+    kv = fmtkv(flags, k, fmt, ap);
-    if (!str) {
+    if (kv.key == NULL || kv.value == NULL) {
         heim_log(r->hcontext, r->logf, 1, "heim_audit_vaddkv: "
                  "failed to add kv pair (out of memory)");
+	heim_release(kv.key);
+	heim_release(kv.value);
         return;
     }
 
     heim_log(r->hcontext, r->logf, 7, "heim_audit_vaddkv(): "
-             "adding kv pair %s", heim_string_get_utf8(str));
+             "adding kv pair %s=%s",
-    heim_array_append_value(r->kv, str);
+	     heim_string_get_utf8(kv.key), heim_string_get_utf8(kv.value));
-    heim_release(str);
+    heim_dict_set_value(r->kv, kv.key, kv.value);
+    heim_release(kv.key);
+    heim_release(kv.value);
 }
 
 void
@@ -808,14 +816,106 @@ heim_audit_addkv_timediff(heim_svc_req_desc r, const char *k,
     heim_audit_addkv(r, 0, k, "%s%ld.%06d", sign, sec, usec);
 }
 
+void
+heim_audit_addkv_object(heim_svc_req_desc r, const char *k, heim_object_t obj)
+{
+    heim_string_t key = heim_string_create(k);
+    heim_string_t value;
+
+    if (key == NULL)
+	return;
+
+    value = heim_json_copy_serialize(obj, 0, NULL);
+    heim_log(r->hcontext, r->logf, 7, "heim_audit_addkv_object(): "
+	     "adding kv pair %s=%s",
+	     k, value ? heim_string_get_utf8(value) : "<unprintable>");
+    heim_dict_set_value(r->kv, key, obj);
+    heim_release(key);
+    heim_release(value);
+}
+
+void
+heim_audit_delkv(heim_svc_req_desc r, const char *k)
+{
+    heim_string_t key = heim_string_create(k);
+
+    if (key == NULL)
+	return;
+
+    heim_log(r->hcontext, r->logf, 7, "heim_audit_delkv(): "
+	     "deleting kv pair %s", k);
+    heim_dict_delete_key(r->kv, key);
+    heim_release(key);
+}
+
+heim_object_t
+heim_audit_getkv(heim_svc_req_desc r, const char *k)
+{
+    heim_string_t key;
+    heim_object_t value;
+
+    key = heim_string_create(k);
+    if (key == NULL)
+	return NULL;
+
+    value = heim_dict_get_value(r->kv, key);
+    heim_release(key);
+    return value;
+}
+
+struct heim_audit_kv_buf {
+    char buf[1024];
+    size_t pos;
+};
+
+static void
+audit_trail_iterator(heim_object_t key, heim_object_t value, void *arg)
+{
+    struct heim_audit_kv_buf *kvb = arg;
+    char num[32];
+    const char *k = heim_string_get_utf8(key), *v;
+
+    if (k == NULL || *k == '#')
+	return;
+
+    switch (heim_get_tid(value)) {
+    case HEIM_TID_STRING:
+	v = heim_string_get_utf8(value);
+	break;
+    case HEIM_TID_NUMBER:
+	snprintf(num, sizeof(num), "%d", heim_number_get_int(value));
+	v = num;
+	break;
+    case HEIM_TID_NULL:
+	v = "null";
+	break;
+    case HEIM_TID_BOOL:
+	v = heim_bool_val(value) ? "true" : "false";
+	break;
+    default:
+	v = NULL;
+	break;
+    }
+
+    if (v == NULL)
+	return;
+
+    if (kvb->pos < sizeof(kvb->buf) - 1)
+	kvb->buf[kvb->pos++] = ' ';
+    for (; *k && kvb->pos < sizeof(kvb->buf) - 1; kvb->pos++)
+	kvb->buf[kvb->pos] = *k++;
+    if (kvb->pos < sizeof(kvb->buf) - 1)
+	kvb->buf[kvb->pos++] = '=';
+    for (; *v && kvb->pos < sizeof(kvb->buf) - 1; kvb->pos++)
+	kvb->buf[kvb->pos] = *v++;
+}
+
 void
 heim_audit_trail(heim_svc_req_desc r, heim_error_code ret, const char *retname)
 {
     const char *retval;
-    char kvbuf[1024];
+    struct heim_audit_kv_buf kvb;
     char retvalbuf[30]; /* Enough for UNKNOWN-%d */
-    size_t nelem;
-    size_t i, j;
 
 #define CASE(x)	case x : retval = #x; break
     if (retname) {
@@ -838,26 +938,14 @@ heim_audit_trail(heim_svc_req_desc r, heim_error_code ret, const char *retname)
     if (r->e_text && r->kv)
 	heim_audit_addkv(r, HEIM_SVC_AUDIT_VIS, "e-text", "%s", r->e_text);
 
-    nelem = r->kv ? heim_array_get_length(r->kv) : 0;
+    kvb.pos = 0;
-    for (i=0, j=0; i < nelem; i++) {
+    heim_dict_iterate_f(r->kv, &kvb, audit_trail_iterator);
-	heim_string_t s;
+    kvb.buf[kvb.pos] = '\0';
-	const char *kvpair;
-
-        /* We know these are strings... */
-	s = heim_array_get_value(r->kv, i);
-	kvpair = heim_string_get_utf8(s);
-
-	if (j < sizeof(kvbuf) - 1)
-	    kvbuf[j++] = ' ';
-	for (; *kvpair && j < sizeof(kvbuf) - 1; j++)
-	    kvbuf[j] = *kvpair++;
-    }
-    kvbuf[j] = '\0';
 
     heim_log(r->hcontext, r->logf, 3, "%s %s %s %s %s%s%s%s",
              r->reqtype, retval, r->from,
              r->cname ? r->cname : "<unknown>",
              r->sname ? r->sname : "<unknown>",
-             kvbuf, r->reason ? " " : "",
+             kvb.buf, r->reason ? " reason=" : "",
              r->reason ? heim_string_get_utf8(r->reason) : "");
 }

lib/base/version-script.map

@@ -29,8 +29,11 @@ HEIMDAL_BASE_1.0 {
 		heim_array_iterate_reverse_f;
 		heim_array_set_value;
 		heim_audit_addkv;
+		heim_audit_addkv_object;
 		heim_audit_addkv_timediff;
 		heim_audit_addreason;
+		heim_audit_delkv;
+		heim_audit_getkv;
 		heim_audit_trail;
 		heim_audit_vaddkv;
 		heim_audit_vaddreason;

lib/hdb/hdb.h

@@ -42,8 +42,10 @@
 
 #include <hdb_err.h>
 
+#include <heimbase-svc.h>
 #include <heim_asn1.h>
 #include <hdb_asn1.h>
+
 typedef HDB_keyset hdb_keyset;
 typedef HDB_entry hdb_entry;
 typedef HDB_entry_alias hdb_entry_alias;
@@ -79,78 +81,41 @@ enum hdb_lockop{ HDB_RLOCK, HDB_WLOCK };
 #define HDB_CAP_F_PASSWORD_UPDATE_KEYS	4
 #define HDB_CAP_F_SHARED_DIRECTORY      8
 
-/* auth status values */
-
 /*
- * Un-initialised value, not permitted, used to indicate that a value
+ * HDB auditing
- * wasn't set for the benifit of logic in the caller, must not be
- * passed to hdb_auth_status()
  */
 
-#define HDB_AUTHSTATUS_INVALID                  0
+/* auth event type enumeration, currently for AS only */
+#define HDB_AUTH_EVENT_INVALID			0   /* no event logged */
+#define HDB_AUTH_EVENT_CLIENT_AUTHORIZED	1   /* all authn/authz checks passed */
+#define HDB_AUTH_EVENT_CLIENT_UNKNOWN	        2   /* client unknown */
+#define HDB_AUTH_EVENT_CLIENT_LOCKED_OUT	3   /* client locked out */
+#define HDB_AUTH_EVENT_CLIENT_TIME_SKEW		4   /* client time skew */
+#define HDB_AUTH_EVENT_LTK_PREAUTH_FAILED	5   /* long term key preauth failed */
+#define HDB_AUTH_EVENT_LTK_PREAUTH_SUCCEEDED	6   /* long term key preauth succeeded */
+#define HDB_AUTH_EVENT_PKINIT_SUCCEEDED	        7   /* PKINIT preauth succeeded */
+#define HDB_AUTH_EVENT_PKINIT_FAILED	        8   /* PKINIT preauth succeeded */
+#define HDB_AUTH_EVENT_GSS_PA_SUCCEEDED		9   /* GSS preauth succeeded */
+#define HDB_AUTH_EVENT_GSS_PA_FAILED		10  /* GSS preauth failed */
+#define HDB_AUTH_EVENT_OTHER_PREAUTH_FAILED   	11  /* unknown preauth failed */
+#define HDB_AUTH_EVENT_OTHER_PREAUTH_SUCCEEDED	12  /* unknown preauth succeeded */
 
-/*
+/* auth event keys, query request with heim_audit_getkv() */
- * A ticket was issued after authorization was successfully completed
+#define HDB_REQUEST_KV_AUTH_EVENT_TYPE		"#auth_event_type"	/* heim_number_t */
- * (eg flags on the entry and expiry times were checked)
+#define HDB_REQUEST_KV_AUTH_EVENT_DETAILS	"#auth_event_details"	/* heim_string_t */
- */
+#define HDB_REQUEST_KV_PA_NAME			"pa"			/* heim_string_t */
-#define HDB_AUTHSTATUS_AUTHORIZATION_SUCCESS	1
 
-/*
+#define heim_pcontext krb5_context
- * The user supplied the wrong password to a password-based
+#define heim_pconfig struct krb5_kdc_configuration *
- * authentication mechanism (eg ENC-TS, ENC-CHAL)
- *
- * The HDB backend might increment a bad password count.
- */
-#define HDB_AUTHSTATUS_WRONG_PASSWORD		2
 
-/*
+struct krb5_kdc_configuration;
- * The user supplied a correct password to a password-based
- * authentication mechanism (eg ENC-TS, ENC-CHAL)
- *
- * The HDB backend might reset a bad password count.
- */
-#define HDB_AUTHSTATUS_CORRECT_PASSWORD	        3
 
-/*
+typedef struct hdb_request_desc {
- * Attempted authenticaton with an unknown user
+    HEIM_SVC_REQUEST_DESC_COMMON_ELEMENTS;
- */
+} *hdb_request_t;
-#define HDB_AUTHSTATUS_CLIENT_UNKNOWN	        4
 
-/*
+#undef heim_pcontext
- * Attempted authenticaton with an known user that is already locked
+#undef heim_pconfig
- * out.
- */
-#define HDB_AUTHSTATUS_CLIENT_LOCKED_OUT	5
-
-/*
- * Successful authentication with a pre-authentication mechanism
- */
-#define HDB_AUTHSTATUS_GENERIC_SUCCESS	        6
-
-/*
- * Failed authentication with a pre-authentication mechanism
- */
-#define HDB_AUTHSTATUS_GENERIC_FAILURE	        7
-
-/*
- * Successful pre-authentication with PKINIT (smart card login etc)
- */
-#define HDB_AUTHSTATUS_PKINIT_SUCCESS	        8
-
-/*
- * Failed pre-authentication with PKINIT (smart card login etc)
- */
-#define HDB_AUTHSTATUS_PKINIT_FAILURE	        9
-
-/*
- * Successful pre-authentication with GSS pre-authentication
- */
-#define HDB_AUTHSTATUS_GSS_SUCCESS		10
-
-/*
- * Failed pre-authentication with GSS pre-authentication
- */
-#define HDB_AUTHSTATUS_GSS_FAILURE		11
 
 /* key usage for master key */
 #define HDB_KU_MKEY	0x484442
@@ -340,23 +305,16 @@ typedef struct HDB {
     krb5_error_code (*hdb_password)(krb5_context, struct HDB*, hdb_entry_ex*, const char *, int);
 
     /**
-     * Auth feedback
+     * Authentication auditing
      *
-     * This is a feedback call that allows backends that provides
+     * Event details are available by querying the request using
-     * lockout functionality to register failure and/or successes.
+     * heim_audit_getkv(HDB_REQUEST_KV_...).
      *
      * In case the entry is locked out, the backend should set the
      * hdb_entry.flags.locked-out flag.
      */
-    krb5_error_code (*hdb_auth_status)(krb5_context,
+    krb5_error_code (*hdb_audit)(krb5_context, struct HDB *, hdb_entry_ex *, hdb_request_t);
-				       struct HDB *,
+
-				       hdb_entry_ex *,
-				       const struct timeval *start_time,
-				       const struct sockaddr *from_addr,
-				       const char *original_client_name,
-				       int auth_type,
-				       const char *auth_details,
-				       const char *pa_type);
     /**
      * Check if delegation is allowed.
      */