diff options
Diffstat (limited to 'third_party/heimdal/lib/base/log.c')
| -rw-r--r-- | third_party/heimdal/lib/base/log.c | 1079 |
1 files changed, 1079 insertions, 0 deletions
diff --git a/third_party/heimdal/lib/base/log.c b/third_party/heimdal/lib/base/log.c new file mode 100644 index 0000000..9a97276 --- /dev/null +++ b/third_party/heimdal/lib/base/log.c @@ -0,0 +1,1079 @@ +/* + * Copyright (c) 1997-2020 Kungliga Tekniska Högskolan + * (Royal Institute of Technology, Stockholm, Sweden). + * All rights reserved. + * + * Portions Copyright (c) 2009 Apple Inc. All rights reserved. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * 3. Neither the name of the Institute nor the names of its contributors + * may be used to endorse or promote products derived from this software + * without specific prior written permission. + * + * THIS SOFTWARE IS PROVIDED BY THE INSTITUTE AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE INSTITUTE OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +#include "baselocl.h" +#include "heim_threads.h" +#include "heimbase-atomics.h" +#include "heimbase.h" +#include "heimbase-svc.h" +#include <assert.h> +#include <stdarg.h> +#include <vis.h> +#include <base64.h> + +struct heim_log_facility_internal { + int min; + int max; + heim_log_log_func_t log_func; + heim_log_close_func_t close_func; + void *data; +}; + +struct heim_log_facility_s { + char *program; + heim_base_atomic(uint32_t) refs; + size_t len; + struct heim_log_facility_internal *val; +}; + +typedef struct heim_pcontext_s *heim_pcontext; +typedef struct heim_pconfig *heim_pconfig; +struct heim_svc_req_desc_common_s { + HEIM_SVC_REQUEST_DESC_COMMON_ELEMENTS; +}; + +static struct heim_log_facility_internal * +log_realloc(heim_log_facility *f) +{ + struct heim_log_facility_internal *fp; + fp = realloc(f->val, (f->len + 1) * sizeof(*f->val)); + if (fp == NULL) + return NULL; + f->len++; + f->val = fp; + fp += f->len - 1; + return fp; +} + +struct s2i { + const char *s; + int val; +}; + +#define L(X) { #X, LOG_ ## X } + +static struct s2i syslogvals[] = { + L(EMERG), + L(ALERT), + L(CRIT), + L(ERR), + L(WARNING), + L(NOTICE), + L(INFO), + L(DEBUG), + + L(AUTH), +#ifdef LOG_AUTHPRIV + L(AUTHPRIV), +#endif +#ifdef LOG_CRON + L(CRON), +#endif + L(DAEMON), +#ifdef LOG_FTP + L(FTP), +#endif + L(KERN), + L(LPR), + L(MAIL), +#ifdef LOG_NEWS + L(NEWS), +#endif + L(SYSLOG), + L(USER), +#ifdef LOG_UUCP + L(UUCP), +#endif + L(LOCAL0), + L(LOCAL1), + L(LOCAL2), + L(LOCAL3), + L(LOCAL4), + L(LOCAL5), + L(LOCAL6), + L(LOCAL7), + { NULL, -1 } +}; + +static int +find_value(const char *s, struct s2i *table) +{ + while (table->s && strcasecmp(table->s, s) != 0) + table++; + return table->val; +} + +heim_error_code +heim_initlog(heim_context context, + const char *program, + heim_log_facility **fac) +{ + heim_log_facility *f = calloc(1, sizeof(*f)); + if (f == NULL) + return heim_enomem(context); + f->refs = 1; + f->program = strdup(program); + if (f->program == NULL) { + free(f); + return heim_enomem(context); + } + *fac = f; + return 0; +} + +heim_log_facility * +heim_log_ref(heim_log_facility *fac) +{ + if (fac) + (void) heim_base_atomic_inc_32(&fac->refs); + return fac; +} + +heim_error_code +heim_addlog_func(heim_context context, + heim_log_facility *fac, + int min, + int max, + heim_log_log_func_t log_func, + heim_log_close_func_t close_func, + void *data) +{ + struct heim_log_facility_internal *fp = log_realloc(fac); + if (fp == NULL) + return heim_enomem(context); + fp->min = min; + fp->max = max; + fp->log_func = log_func; + fp->close_func = close_func; + fp->data = data; + return 0; +} + + +struct _heimdal_syslog_data{ + int priority; +}; + +static void HEIM_CALLCONV +log_syslog(heim_context context, const char *timestr, + const char *msg, void *data) +{ + struct _heimdal_syslog_data *s = data; + syslog(s->priority, "%s", msg); +} + +static void HEIM_CALLCONV +close_syslog(void *data) +{ + free(data); + closelog(); +} + +static heim_error_code +open_syslog(heim_context context, + heim_log_facility *facility, int min, int max, + const char *sev, const char *fac) +{ + struct _heimdal_syslog_data *sd; + heim_error_code ret; + int i; + + if (facility == NULL) + return EINVAL; + if ((sd = calloc(1, sizeof(*sd))) == NULL) + return heim_enomem(context); + i = find_value(sev, syslogvals); + if (i == -1) + i = LOG_ERR; + sd->priority = i; + i = find_value(fac, syslogvals); + if (i == -1) + i = LOG_AUTH; + sd->priority |= i; + roken_openlog(facility->program, LOG_PID | LOG_NDELAY, i); + ret = heim_addlog_func(context, facility, min, max, log_syslog, + close_syslog, sd); + if (ret) + free(sd); + else + sd = NULL; + return ret; +} + +struct file_data { + char *filename; + const char *mode; + struct timeval tv; + FILE *fd; + int disp; +#define FILEDISP_KEEPOPEN 0x1 +#define FILEDISP_REOPEN 0x2 +#define FILEDISP_IFEXISTS 0x4 +}; + +#ifndef O_CLOEXEC +#define O_CLOEXEC 0 +#endif + +static void HEIM_CALLCONV +log_file(heim_context context, const char *timestr, const char *msg, void *data) +{ + struct timeval tv; + struct file_data *f = data; + FILE *logf = f->fd; + char *msgclean; + size_t i = 0; + size_t j; + + if (f->filename && (logf == NULL || (f->disp & FILEDISP_REOPEN))) { + int flags = O_WRONLY|O_APPEND; + int fd; + + if (f->mode[0] == 'e') { + flags |= O_CLOEXEC; + i = 1; + } + if (f->mode[i] == 'w') + flags |= O_TRUNC; + if (f->mode[i + 1] == '+') + flags |= O_RDWR; + + if (f->disp & FILEDISP_IFEXISTS) { + /* Cache failure for 1s */ + gettimeofday(&tv, NULL); + if (tv.tv_sec == f->tv.tv_sec) + return; + } else { + flags |= O_CREAT; + } + + fd = open(f->filename, flags, 0666); /* umask best be set */ + if (fd == -1) { + if (f->disp & FILEDISP_IFEXISTS) + gettimeofday(&f->tv, NULL); + return; + } + rk_cloexec(fd); + logf = fdopen(fd, f->mode); + } + if (f->fd == NULL && (f->disp & FILEDISP_KEEPOPEN)) + f->fd = logf; + if (logf == NULL) + return; + /* + * make sure the log doesn't contain special chars: + * we used to use strvisx(3) to encode the log, but this is + * inconsistent with our syslog(3) code which does not do this. + * It also makes it inelegant to write data which has already + * been quoted such as what krb5_unparse_principal() gives us. + * So, we change here to eat the special characters, instead. + */ + if (msg && (msgclean = strdup(msg))) { + for (i = 0, j = 0; msg[i]; i++) + if (msg[i] >= 32 || msg[i] == '\t') + msgclean[j++] = msg[i]; + fprintf(logf, "%s %s\n", timestr ? timestr : "", msgclean); + free(msgclean); + } + if (logf != f->fd) + fclose(logf); +} + +static void HEIM_CALLCONV +close_file(void *data) +{ + struct file_data *f = data; + if (f->fd && f->fd != stdout && f->fd != stderr) + fclose(f->fd); + free(f->filename); + free(data); +} + +static heim_error_code +open_file(heim_context context, heim_log_facility *fac, int min, int max, + const char *filename, const char *mode, FILE *f, int disp, + int exp_tokens) +{ + heim_error_code ret = 0; + struct file_data *fd; + + if ((fd = calloc(1, sizeof(*fd))) == NULL) + return heim_enomem(context); + + fd->filename = NULL; + fd->mode = mode; + fd->fd = f; + fd->disp = disp; + + if (filename) { + if (exp_tokens) + ret = heim_expand_path_tokens(context, filename, 1, &fd->filename, NULL); + else if ((fd->filename = strdup(filename)) == NULL) + ret = heim_enomem(context); + } + if (ret == 0) + ret = heim_addlog_func(context, fac, min, max, log_file, close_file, fd); + if (ret) { + free(fd->filename); + free(fd); + } else if (disp & FILEDISP_KEEPOPEN) { + log_file(context, NULL, NULL, fd); + fd = NULL; + } + return ret; +} + +heim_error_code +heim_addlog_dest(heim_context context, heim_log_facility *f, const char *orig) +{ + heim_error_code ret = 0; + int min = 0, max = 3, n; + char c; + const char *p = orig; +#ifdef _WIN32 + const char *q; +#endif + + n = sscanf(p, "%d%c%d/", &min, &c, &max); + if (n == 2) { + if (ISPATHSEP(c)) { + if (min < 0) { + max = -min; + min = 0; + } else { + max = min; + } + } + if (c == '-') + max = -1; + } + if (n) { +#ifdef _WIN32 + q = strrchr(p, '\\'); + if (q != NULL) + p = q; + else +#endif + p = strchr(p, '/'); + if (p == NULL) { + heim_set_error_message(context, EINVAL /*XXX HEIM_ERR_LOG_PARSE*/, + N_("failed to parse \"%s\"", ""), orig); + return EINVAL /*XXX HEIM_ERR_LOG_PARSE*/; + } + p++; + } + if (strcmp(p, "STDERR") == 0) { + ret = open_file(context, f, min, max, NULL, "a", stderr, + FILEDISP_KEEPOPEN, 0); + } else if (strcmp(p, "CONSOLE") == 0) { + /* XXX WIN32 */ + ret = open_file(context, f, min, max, "/dev/console", "w", NULL, + FILEDISP_KEEPOPEN, 0); + } else if (strncmp(p, "EFILE:", 5) == 0) { + ret = open_file(context, f, min, max, p + sizeof("EFILE:") - 1, "a", + NULL, FILEDISP_IFEXISTS | FILEDISP_REOPEN, 1); + } else if (strncmp(p, "EFILE=", 5) == 0) { + ret = open_file(context, f, min, max, p + sizeof("EFILE=") - 1, "a", + NULL, FILEDISP_IFEXISTS | FILEDISP_KEEPOPEN, 1); + } else if (strncmp(p, "FILE:", sizeof("FILE:") - 1) == 0) { + ret = open_file(context, f, min, max, p + sizeof("FILE:") - 1, "a", + NULL, FILEDISP_REOPEN, 1); + } else if (strncmp(p, "FILE=", sizeof("FILE=") - 1) == 0) { + ret = open_file(context, f, min, max, p + sizeof("FILE=") - 1, "a", + NULL, FILEDISP_KEEPOPEN, 1); + } else if (strncmp(p, "DEVICE:", sizeof("DEVICE:") - 1) == 0) { + ret = open_file(context, f, min, max, p + sizeof("DEVICE:") - 1, "a", + NULL, FILEDISP_REOPEN, 0); + } else if (strncmp(p, "DEVICE=", sizeof("DEVICE=") - 1) == 0) { + ret = open_file(context, f, min, max, p + sizeof("DEVICE=") - 1, "a", + NULL, FILEDISP_KEEPOPEN, 0); + } else if (strncmp(p, "SYSLOG", 6) == 0 && (p[6] == '\0' || p[6] == ':')) { + char severity[128] = ""; + char facility[128] = ""; + p += 6; + if (*p != '\0') + p++; + if (strsep_copy(&p, ":", severity, sizeof(severity)) != -1) + strsep_copy(&p, ":", facility, sizeof(facility)); + if (*severity == '\0') + strlcpy(severity, "ERR", sizeof(severity)); + if (*facility == '\0') + strlcpy(facility, "AUTH", sizeof(facility)); + ret = open_syslog(context, f, min, max, severity, facility); + } else { + ret = EINVAL; /*XXX HEIM_ERR_LOG_PARSE*/ + heim_set_error_message(context, ret, + N_("unknown log type: %s", ""), p); + } + return ret; +} + +heim_error_code +heim_openlog(heim_context context, + const char *program, + const char **specs, + heim_log_facility **fac) +{ + heim_error_code ret; + + ret = heim_initlog(context, program, fac); + if (ret) + return ret; + + if (specs) { + size_t i; + for (i = 0; specs[i] && ret == 0; i++) + ret = heim_addlog_dest(context, *fac, specs[i]); + } else { + ret = heim_addlog_dest(context, *fac, "SYSLOG"); + } + return ret; +} + +void +heim_closelog(heim_context context, heim_log_facility *fac) +{ + int i; + + if (!fac || heim_base_atomic_dec_32(&fac->refs)) + return; + for (i = 0; i < fac->len; i++) + (*fac->val[i].close_func)(fac->val[i].data); + free(fac->val); + free(fac->program); + fac->val = NULL; + fac->len = 0; + fac->program = NULL; + free(fac); + return; +} + +static void +format_time(heim_context context, time_t t, char *s, size_t len) +{ + struct tm *tm = heim_context_get_log_utc(context) ? + gmtime(&t) : localtime(&t); + if (tm && strftime(s, len, heim_context_get_time_fmt(context), tm)) + return; + snprintf(s, len, "%ld", (long)t); +} + +#undef __attribute__ +#define __attribute__(X) + +heim_error_code +heim_vlog_msg(heim_context context, + heim_log_facility *fac, + char **reply, + int level, + const char *fmt, + va_list ap) +__attribute__ ((__format__ (__printf__, 5, 0))) +{ + + char *msg = NULL; + const char *actual = NULL; + char buf[64]; + time_t t = 0; + int i; + + if (!fac) + fac = context->log_dest; + for (i = 0; fac && i < fac->len; i++) + if (fac->val[i].min <= level && + (fac->val[i].max < 0 || fac->val[i].max >= level)) { + if (t == 0) { + t = time(NULL); + format_time(context, t, buf, sizeof(buf)); + } + if (actual == NULL) { + int ret = vasprintf(&msg, fmt, ap); + if (ret < 0 || msg == NULL) + actual = fmt; + else + actual = msg; + } + (*fac->val[i].log_func)(context, buf, actual, fac->val[i].data); + } + if (reply == NULL) + free(msg); + else + *reply = msg; + return 0; +} + +heim_error_code +heim_vlog(heim_context context, + heim_log_facility *fac, + int level, + const char *fmt, + va_list ap) +__attribute__ ((__format__ (__printf__, 4, 0))) +{ + return heim_vlog_msg(context, fac, NULL, level, fmt, ap); +} + +heim_error_code +heim_log_msg(heim_context context, + heim_log_facility *fac, + int level, + char **reply, + const char *fmt, + ...) +__attribute__ ((__format__ (__printf__, 5, 6))) +{ + va_list ap; + heim_error_code ret; + + va_start(ap, fmt); + ret = heim_vlog_msg(context, fac, reply, level, fmt, ap); + va_end(ap); + return ret; +} + + +heim_error_code +heim_log(heim_context context, + heim_log_facility *fac, + int level, + const char *fmt, + ...) +__attribute__ ((__format__ (__printf__, 4, 5))) +{ + va_list ap; + heim_error_code ret; + + va_start(ap, fmt); + ret = heim_vlog(context, fac, level, fmt, ap); + va_end(ap); + return ret; +} + +void +heim_debug(heim_context context, + int level, + const char *fmt, + ...) +__attribute__ ((__format__ (__printf__, 3, 4))) +{ + heim_log_facility *fac; + va_list ap; + + if (context == NULL || + (fac = heim_get_debug_dest(context)) == NULL) + return; + + va_start(ap, fmt); + heim_vlog(context, fac, level, fmt, ap); + va_end(ap); +} + +void +heim_vdebug(heim_context context, + int level, + const char *fmt, + va_list ap) +__attribute__ ((__format__ (__printf__, 3, 0))) +{ + heim_log_facility *fac; + + if (context == NULL || + (fac = heim_get_debug_dest(context)) == NULL) + return; + + heim_vlog(context, fac, level, fmt, ap); +} + +heim_error_code +heim_have_debug(heim_context context, int level) +{ + return (context != NULL && heim_get_debug_dest(context) != NULL); +} + +heim_error_code +heim_add_warn_dest(heim_context context, const char *program, + const char *log_spec) +{ + heim_log_facility *fac; + + heim_error_code ret; + + if ((fac = heim_get_warn_dest(context)) == NULL) { + ret = heim_initlog(context, program, &fac); + if (ret) + return ret; + heim_set_warn_dest(context, fac); + } + + ret = heim_addlog_dest(context, fac, log_spec); + if (ret) + return ret; + return 0; +} + +heim_error_code +heim_add_debug_dest(heim_context context, const char *program, + const char *log_spec) +{ + heim_log_facility *fac; + heim_error_code ret; + + if ((fac = heim_get_debug_dest(context)) == NULL) { + ret = heim_initlog(context, program, &fac); + if (ret) + return ret; + heim_set_debug_dest(context, fac); + } + + ret = heim_addlog_dest(context, fac, log_spec); + if (ret) + return ret; + return 0; +} + +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))) +{ + size_t i; + ssize_t j; + struct heim_audit_kv_tuple kv; + char *value; + char *value_vis; + + j = vasprintf(&value, fmt, ap); + if (j < 0 || value == NULL) + return zero_tuple; + + /* We optionally eat the whitespace. */ + + if (flags & HEIM_SVC_AUDIT_EATWHITE) { + for (i=0, j=0; value[i]; i++) + if (value[i] != ' ' && value[i] != '\t') + value[j++] = value[i]; + value[j] = '\0'; + } + + if (flags & (HEIM_SVC_AUDIT_VIS | HEIM_SVC_AUDIT_VISLAST)) { + int vis_flags = VIS_CSTYLE | VIS_OCTAL | VIS_NL; + + if (flags & HEIM_SVC_AUDIT_VIS) + vis_flags |= VIS_WHITE; + value_vis = malloc((j + 1) * 4 + 1); + if (value_vis) + strvisx(value_vis, value, j, vis_flags); + free(value); + if (value_vis == NULL) + return zero_tuple; + } else + value_vis = value; + + if (k) + kv.key = heim_string_create(k); + else + kv.key = NULL; + kv.value = heim_string_ref_create(value_vis, free); + + return kv; +} + +void +heim_audit_vaddreason(heim_svc_req_desc r, const char *fmt, va_list ap) + __attribute__ ((__format__ (__printf__, 2, 0))) +{ + struct heim_audit_kv_tuple kv; + + kv = fmtkv(HEIM_SVC_AUDIT_VISLAST, NULL, fmt, ap); + if (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(kv.value)); + if (r->reason) { + heim_string_t str2; + + str2 = heim_string_create_with_format("%s: %s", + heim_string_get_utf8(kv.value), + heim_string_get_utf8(r->reason)); + if (str2) { + heim_release(kv.value); + kv.value = str2; + } + } + heim_release(r->reason); + r->reason = kv.value; +} + +void +heim_audit_addreason(heim_svc_req_desc r, const char *fmt, ...) + __attribute__ ((__format__ (__printf__, 2, 3))) +{ + va_list ap; + + va_start(ap, fmt); + heim_audit_vaddreason(r, fmt, ap); + va_end(ap); +} + +size_t +addkv(heim_svc_req_desc r, heim_object_t key, heim_object_t value) +{ + size_t index; + heim_object_t obj; + + obj = heim_dict_get_value(r->kv, key); + if (obj) { + if (heim_get_tid(obj) == HEIM_TID_ARRAY) { + index = heim_array_get_length(obj); + heim_array_append_value(obj, value); + } else { + heim_array_t array = heim_array_create(); + + index = 1; + heim_array_append_value(array, obj); + heim_array_append_value(array, value); + heim_dict_set_value(r->kv, key, array); + heim_release(array); /* retained by r->kv */ + } + } else { + index = 0; + heim_dict_set_value(r->kv, key, value); + } + + return index; +} + +/* + * add a key-value token. if the key already exists, the value is + * promoted to an array of values. + */ + +void +heim_audit_vaddkv(heim_svc_req_desc r, int flags, const char *k, + const char *fmt, va_list ap) + __attribute__ ((__format__ (__printf__, 4, 0))) +{ + struct heim_audit_kv_tuple kv; + size_t index; + + kv = fmtkv(flags, k, fmt, ap); + 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; + } + + index = addkv(r, kv.key, kv.value); + + heim_log(r->hcontext, r->logf, 7, "heim_audit_vaddkv(): " + "kv pair[%zu] %s=%s", index, + heim_string_get_utf8(kv.key), heim_string_get_utf8(kv.value)); + + heim_release(kv.key); + heim_release(kv.value); +} + +void +heim_audit_addkv(heim_svc_req_desc r, int flags, const char *k, + const char *fmt, ...) + __attribute__ ((__format__ (__printf__, 4, 5))) +{ + va_list ap; + + va_start(ap, fmt); + heim_audit_vaddkv(r, flags, k, fmt, ap); + va_end(ap); +} + +void +heim_audit_addkv_timediff(heim_svc_req_desc r, const char *k, + const struct timeval *start, + const struct timeval *end) +{ + time_t sec; + int usec; + const char *sign = ""; + + if (end->tv_sec > start->tv_sec || + (end->tv_sec == start->tv_sec && end->tv_usec >= start->tv_usec)) { + sec = end->tv_sec - start->tv_sec; + usec = end->tv_usec - start->tv_usec; + } else { + sec = start->tv_sec - end->tv_sec; + usec = start->tv_usec - end->tv_usec; + sign = "-"; + } + + if (usec < 0) { + usec += 1000000; + sec -= 1; + } + + heim_audit_addkv(r, 0, k, "%s%ld.%06d", sign, (long)sec, usec); +} + +void +heim_audit_setkv_bool(heim_svc_req_desc r, const char *k, int v) +{ + heim_string_t key = heim_string_create(k); + heim_number_t value; + + if (key == NULL) + return; + + heim_log(r->hcontext, r->logf, 7, "heim_audit_setkv_bool(): " + "setting kv pair %s=%s", k, v ? "true" : "false"); + + value = heim_bool_create(v); + heim_dict_set_value(r->kv, key, value); + heim_release(key); + heim_release(value); +} + +void +heim_audit_addkv_number(heim_svc_req_desc r, const char *k, int64_t v) +{ + heim_string_t key = heim_string_create(k); + heim_number_t value; + + if (key == NULL) + return; + + heim_log(r->hcontext, r->logf, 7, "heim_audit_addkv_number(): " + "adding kv pair %s=%lld", k, (long long)v); + + value = heim_number_create(v); + addkv(r, key, value); + heim_release(key); + heim_release(value); +} + +void +heim_audit_setkv_number(heim_svc_req_desc r, const char *k, int64_t v) +{ + heim_string_t key = heim_string_create(k); + heim_number_t value; + + if (key == NULL) + return; + + heim_log(r->hcontext, r->logf, 7, "heim_audit_setkv_number(): " + "setting kv pair %s=%lld", k, (long long)v); + + value = heim_number_create(v); + heim_dict_set_value(r->kv, key, value); + heim_release(key); + heim_release(value); +} + +void +heim_audit_addkv_object(heim_svc_req_desc r, const char *k, heim_object_t value) +{ + heim_string_t key = heim_string_create(k); + heim_string_t descr; + + if (key == NULL) + return; + + descr = heim_json_copy_serialize(value, HEIM_JSON_F_NO_DATA_DICT, NULL); + heim_log(r->hcontext, r->logf, 7, "heim_audit_addkv_object(): " + "adding kv pair %s=%s", + k, descr ? heim_string_get_utf8(descr) : "<unprintable>"); + addkv(r, key, value); + heim_release(key); + heim_release(descr); +} + +void +heim_audit_setkv_object(heim_svc_req_desc r, const char *k, heim_object_t value) +{ + heim_string_t key = heim_string_create(k); + heim_string_t descr; + + if (key == NULL) + return; + + descr = heim_json_copy_serialize(value, HEIM_JSON_F_NO_DATA_DICT, NULL); + heim_log(r->hcontext, r->logf, 7, "heim_audit_setkv_object(): " + "setting kv pair %s=%s", + k, descr ? heim_string_get_utf8(descr) : "<unprintable>"); + heim_dict_set_value(r->kv, key, value); + heim_release(key); + heim_release(descr); +} + +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; + heim_object_t iter; +}; + +static void +audit_trail_iterator(heim_object_t key, heim_object_t value, void *arg); + +static void +audit_trail_iterator_array(heim_object_t value, void *arg, int *stop) +{ + struct heim_audit_kv_buf *kvb = arg; + + audit_trail_iterator(kvb->iter, value, kvb); +} + +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 = NULL; + char *b64 = NULL; + + if (k == NULL || *k == '#') /* # keys are hidden */ + 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), "%lld", (long long)heim_number_get_long(value)); + v = num; + break; + case HEIM_TID_NULL: + v = "null"; + break; + case HEIM_TID_BOOL: + v = heim_bool_val(value) ? "true" : "false"; + break; + case HEIM_TID_ARRAY: + if (kvb->iter) + break; /* arrays cannot be nested */ + + kvb->iter = key; + heim_array_iterate_f(value, kvb, audit_trail_iterator_array); + kvb->iter = NULL; + break; + case HEIM_TID_DATA: { + const heim_octet_string *data = heim_data_get_data(value); + if (rk_base64_encode(data->data, data->length, &b64) >= 0) + v = b64; + break; + } + default: + 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++; + + free(b64); +} + +void +heim_audit_trail(heim_svc_req_desc r, heim_error_code ret, const char *retname) +{ + const char *retval; + struct heim_audit_kv_buf kvb; + char retvalbuf[30]; /* Enough for UNKNOWN-%d */ + +#define CASE(x) case x : retval = #x; break + if (retname) { + retval = retname; + } else switch (ret ? ret : r->error_code) { + CASE(ENOMEM); + CASE(ENOENT); + CASE(EACCES); + case 0: + retval = "SUCCESS"; + break; + default: + /* Wish we had a com_err number->symbolic name function */ + (void) snprintf(retvalbuf, sizeof(retvalbuf), "UNKNOWN-%d", + ret ? ret : r->error_code); + retval = retvalbuf; + break; + } + + heim_audit_addkv_timediff(r, "elapsed", &r->tv_start, &r->tv_end); + if (r->e_text && r->kv) + heim_audit_addkv(r, HEIM_SVC_AUDIT_VIS, "e-text", "%s", r->e_text); + + memset(&kvb, 0, sizeof(kvb)); + if (r->kv) + heim_dict_iterate_f(r->kv, &kvb, audit_trail_iterator); + kvb.buf[kvb.pos] = '\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>", + kvb.buf, r->reason ? " reason=" : "", + r->reason ? heim_string_get_utf8(r->reason) : ""); +} |