Line data Source code
1 : /*
2 : * Copyright (c) 1997-2020 Kungliga Tekniska Högskolan
3 : * (Royal Institute of Technology, Stockholm, Sweden).
4 : * All rights reserved.
5 : *
6 : * Portions Copyright (c) 2009 Apple Inc. All rights reserved.
7 : *
8 : * Redistribution and use in source and binary forms, with or without
9 : * modification, are permitted provided that the following conditions
10 : * are met:
11 : *
12 : * 1. Redistributions of source code must retain the above copyright
13 : * notice, this list of conditions and the following disclaimer.
14 : *
15 : * 2. Redistributions in binary form must reproduce the above copyright
16 : * notice, this list of conditions and the following disclaimer in the
17 : * documentation and/or other materials provided with the distribution.
18 : *
19 : * 3. Neither the name of the Institute nor the names of its contributors
20 : * may be used to endorse or promote products derived from this software
21 : * without specific prior written permission.
22 : *
23 : * THIS SOFTWARE IS PROVIDED BY THE INSTITUTE AND CONTRIBUTORS ``AS IS'' AND
24 : * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
25 : * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
26 : * ARE DISCLAIMED. IN NO EVENT SHALL THE INSTITUTE OR CONTRIBUTORS BE LIABLE
27 : * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
28 : * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
29 : * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
30 : * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
31 : * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
32 : * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
33 : * SUCH DAMAGE.
34 : */
35 :
36 : #include "baselocl.h"
37 : #include "heim_threads.h"
38 : #include "heimbase.h"
39 : #include "heimbase-svc.h"
40 : #include <assert.h>
41 : #include <stdarg.h>
42 : #include <vis.h>
43 : #include <base64.h>
44 :
45 : struct heim_log_facility_internal {
46 : int min;
47 : int max;
48 : heim_log_log_func_t log_func;
49 : heim_log_close_func_t close_func;
50 : void *data;
51 : };
52 :
53 : struct heim_log_facility_s {
54 : char *program;
55 : size_t refs;
56 : size_t len;
57 : struct heim_log_facility_internal *val;
58 : };
59 :
60 : typedef struct heim_pcontext_s *heim_pcontext;
61 : typedef struct heim_pconfig *heim_pconfig;
62 : struct heim_svc_req_desc_common_s {
63 : HEIM_SVC_REQUEST_DESC_COMMON_ELEMENTS;
64 : };
65 :
66 : static struct heim_log_facility_internal *
67 387006 : log_realloc(heim_log_facility *f)
68 : {
69 : struct heim_log_facility_internal *fp;
70 387006 : fp = realloc(f->val, (f->len + 1) * sizeof(*f->val));
71 387006 : if (fp == NULL)
72 0 : return NULL;
73 387006 : f->len++;
74 387006 : f->val = fp;
75 387006 : fp += f->len - 1;
76 387006 : return fp;
77 : }
78 :
79 : struct s2i {
80 : const char *s;
81 : int val;
82 : };
83 :
84 : #define L(X) { #X, LOG_ ## X }
85 :
86 : static struct s2i syslogvals[] = {
87 : L(EMERG),
88 : L(ALERT),
89 : L(CRIT),
90 : L(ERR),
91 : L(WARNING),
92 : L(NOTICE),
93 : L(INFO),
94 : L(DEBUG),
95 :
96 : L(AUTH),
97 : #ifdef LOG_AUTHPRIV
98 : L(AUTHPRIV),
99 : #endif
100 : #ifdef LOG_CRON
101 : L(CRON),
102 : #endif
103 : L(DAEMON),
104 : #ifdef LOG_FTP
105 : L(FTP),
106 : #endif
107 : L(KERN),
108 : L(LPR),
109 : L(MAIL),
110 : #ifdef LOG_NEWS
111 : L(NEWS),
112 : #endif
113 : L(SYSLOG),
114 : L(USER),
115 : #ifdef LOG_UUCP
116 : L(UUCP),
117 : #endif
118 : L(LOCAL0),
119 : L(LOCAL1),
120 : L(LOCAL2),
121 : L(LOCAL3),
122 : L(LOCAL4),
123 : L(LOCAL5),
124 : L(LOCAL6),
125 : L(LOCAL7),
126 : { NULL, -1 }
127 : };
128 :
129 : static int
130 0 : find_value(const char *s, struct s2i *table)
131 : {
132 0 : while (table->s && strcasecmp(table->s, s) != 0)
133 0 : table++;
134 0 : return table->val;
135 : }
136 :
137 : heim_error_code
138 387009 : heim_initlog(heim_context context,
139 : const char *program,
140 : heim_log_facility **fac)
141 : {
142 387009 : heim_log_facility *f = calloc(1, sizeof(*f));
143 387009 : if (f == NULL)
144 0 : return heim_enomem(context);
145 387009 : f->refs = 1;
146 387009 : f->program = strdup(program);
147 387009 : if (f->program == NULL) {
148 0 : free(f);
149 0 : return heim_enomem(context);
150 : }
151 387009 : *fac = f;
152 387009 : return 0;
153 : }
154 :
155 : heim_log_facility *
156 0 : heim_log_ref(heim_log_facility *fac)
157 : {
158 0 : if (fac)
159 0 : fac->refs++;
160 0 : return fac;
161 : }
162 :
163 : heim_error_code
164 387006 : heim_addlog_func(heim_context context,
165 : heim_log_facility *fac,
166 : int min,
167 : int max,
168 : heim_log_log_func_t log_func,
169 : heim_log_close_func_t close_func,
170 : void *data)
171 : {
172 387006 : struct heim_log_facility_internal *fp = log_realloc(fac);
173 387006 : if (fp == NULL)
174 0 : return heim_enomem(context);
175 387006 : fp->min = min;
176 387006 : fp->max = max;
177 387006 : fp->log_func = log_func;
178 387006 : fp->close_func = close_func;
179 387006 : fp->data = data;
180 387006 : return 0;
181 : }
182 :
183 :
184 : struct _heimdal_syslog_data{
185 : int priority;
186 : };
187 :
188 : static void HEIM_CALLCONV
189 0 : log_syslog(heim_context context, const char *timestr,
190 : const char *msg, void *data)
191 : {
192 0 : struct _heimdal_syslog_data *s = data;
193 0 : syslog(s->priority, "%s", msg);
194 0 : }
195 :
196 : static void HEIM_CALLCONV
197 0 : close_syslog(void *data)
198 : {
199 0 : free(data);
200 0 : closelog();
201 0 : }
202 :
203 : static heim_error_code
204 0 : open_syslog(heim_context context,
205 : heim_log_facility *facility, int min, int max,
206 : const char *sev, const char *fac)
207 : {
208 : struct _heimdal_syslog_data *sd;
209 : heim_error_code ret;
210 : int i;
211 :
212 0 : if (facility == NULL)
213 0 : return EINVAL;
214 0 : if ((sd = calloc(1, sizeof(*sd))) == NULL)
215 0 : return heim_enomem(context);
216 0 : i = find_value(sev, syslogvals);
217 0 : if (i == -1)
218 0 : i = LOG_ERR;
219 0 : sd->priority = i;
220 0 : i = find_value(fac, syslogvals);
221 0 : if (i == -1)
222 0 : i = LOG_AUTH;
223 0 : sd->priority |= i;
224 0 : roken_openlog(facility->program, LOG_PID | LOG_NDELAY, i);
225 0 : ret = heim_addlog_func(context, facility, min, max, log_syslog,
226 : close_syslog, sd);
227 0 : if (ret)
228 0 : free(sd);
229 0 : return ret;
230 : }
231 :
232 : struct file_data {
233 : char *filename;
234 : const char *mode;
235 : struct timeval tv;
236 : FILE *fd;
237 : int disp;
238 : #define FILEDISP_KEEPOPEN 0x1
239 : #define FILEDISP_REOPEN 0x2
240 : #define FILEDISP_IFEXISTS 0x4
241 : };
242 :
243 : #ifndef O_CLOEXEC
244 : #define O_CLOEXEC 0
245 : #endif
246 :
247 : static void HEIM_CALLCONV
248 0 : log_file(heim_context context, const char *timestr, const char *msg, void *data)
249 : {
250 : struct timeval tv;
251 0 : struct file_data *f = data;
252 0 : FILE *logf = f->fd;
253 : char *msgclean;
254 0 : size_t i = 0;
255 : size_t j;
256 :
257 0 : if (f->filename && (logf == NULL || (f->disp & FILEDISP_REOPEN))) {
258 0 : int flags = O_WRONLY|O_APPEND;
259 : int fd;
260 :
261 0 : if (f->mode[0] == 'e') {
262 0 : flags |= O_CLOEXEC;
263 0 : i = 1;
264 : }
265 0 : if (f->mode[i] == 'w')
266 0 : flags |= O_TRUNC;
267 0 : if (f->mode[i + 1] == '+')
268 0 : flags |= O_RDWR;
269 :
270 0 : if (f->disp & FILEDISP_IFEXISTS) {
271 : /* Cache failure for 1s */
272 0 : gettimeofday(&tv, NULL);
273 0 : if (tv.tv_sec == f->tv.tv_sec)
274 0 : return;
275 : } else {
276 0 : flags |= O_CREAT;
277 : }
278 :
279 0 : fd = open(f->filename, flags, 0666); /* umask best be set */
280 0 : if (fd == -1) {
281 0 : if (f->disp & FILEDISP_IFEXISTS)
282 0 : gettimeofday(&f->tv, NULL);
283 0 : return;
284 : }
285 0 : rk_cloexec(fd);
286 0 : logf = fdopen(fd, f->mode);
287 : }
288 0 : if (f->fd == NULL && (f->disp & FILEDISP_KEEPOPEN))
289 0 : f->fd = logf;
290 0 : if (logf == NULL)
291 0 : return;
292 : /*
293 : * make sure the log doesn't contain special chars:
294 : * we used to use strvisx(3) to encode the log, but this is
295 : * inconsistent with our syslog(3) code which does not do this.
296 : * It also makes it inelegant to write data which has already
297 : * been quoted such as what krb5_unparse_principal() gives us.
298 : * So, we change here to eat the special characters, instead.
299 : */
300 0 : if (msg && (msgclean = strdup(msg))) {
301 0 : for (i = 0, j = 0; msg[i]; i++)
302 0 : if (msg[i] >= 32 || msg[i] == '\t')
303 0 : msgclean[j++] = msg[i];
304 0 : fprintf(logf, "%s %s\n", timestr ? timestr : "", msgclean);
305 0 : free(msgclean);
306 : }
307 0 : if (logf != f->fd)
308 0 : fclose(logf);
309 : }
310 :
311 : static void HEIM_CALLCONV
312 0 : close_file(void *data)
313 : {
314 0 : struct file_data *f = data;
315 0 : if (f->fd && f->fd != stdout && f->fd != stderr)
316 0 : fclose(f->fd);
317 0 : free(f->filename);
318 0 : free(data);
319 0 : }
320 :
321 : static heim_error_code
322 0 : open_file(heim_context context, heim_log_facility *fac, int min, int max,
323 : const char *filename, const char *mode, FILE *f, int disp,
324 : int exp_tokens)
325 : {
326 0 : heim_error_code ret = 0;
327 : struct file_data *fd;
328 :
329 0 : if ((fd = calloc(1, sizeof(*fd))) == NULL)
330 0 : return heim_enomem(context);
331 :
332 0 : fd->filename = NULL;
333 0 : fd->mode = mode;
334 0 : fd->fd = f;
335 0 : fd->disp = disp;
336 :
337 0 : if (filename) {
338 0 : if (exp_tokens)
339 0 : ret = heim_expand_path_tokens(context, filename, 1, &fd->filename, NULL);
340 0 : else if ((fd->filename = strdup(filename)) == NULL)
341 0 : ret = heim_enomem(context);
342 : }
343 0 : if (ret == 0)
344 0 : ret = heim_addlog_func(context, fac, min, max, log_file, close_file, fd);
345 0 : if (ret) {
346 0 : free(fd->filename);
347 0 : free(fd);
348 0 : } else if (disp & FILEDISP_KEEPOPEN) {
349 0 : log_file(context, NULL, NULL, fd);
350 : }
351 0 : return ret;
352 : }
353 :
354 : heim_error_code
355 5 : heim_addlog_dest(heim_context context, heim_log_facility *f, const char *orig)
356 : {
357 5 : heim_error_code ret = 0;
358 5 : int min = 0, max = 3, n;
359 : char c;
360 5 : const char *p = orig;
361 : #ifdef _WIN32
362 : const char *q;
363 : #endif
364 :
365 5 : n = sscanf(p, "%d%c%d/", &min, &c, &max);
366 5 : if (n == 2) {
367 0 : if (ISPATHSEP(c)) {
368 0 : if (min < 0) {
369 0 : max = -min;
370 0 : min = 0;
371 : } else {
372 0 : max = min;
373 : }
374 : }
375 0 : if (c == '-')
376 0 : max = -1;
377 : }
378 5 : if (n) {
379 : #ifdef _WIN32
380 : q = strrchr(p, '\\');
381 : if (q != NULL)
382 : p = q;
383 : else
384 : #endif
385 0 : p = strchr(p, '/');
386 0 : if (p == NULL) {
387 0 : heim_set_error_message(context, EINVAL /*XXX HEIM_ERR_LOG_PARSE*/,
388 0 : N_("failed to parse \"%s\"", ""), orig);
389 0 : return EINVAL /*XXX HEIM_ERR_LOG_PARSE*/;
390 : }
391 0 : p++;
392 : }
393 5 : if (strcmp(p, "STDERR") == 0) {
394 0 : ret = open_file(context, f, min, max, NULL, "a", stderr,
395 : FILEDISP_KEEPOPEN, 0);
396 5 : } else if (strcmp(p, "CONSOLE") == 0) {
397 : /* XXX WIN32 */
398 0 : ret = open_file(context, f, min, max, "/dev/console", "w", NULL,
399 : FILEDISP_KEEPOPEN, 0);
400 5 : } else if (strncmp(p, "EFILE:", 5) == 0) {
401 0 : ret = open_file(context, f, min, max, p + sizeof("EFILE:") - 1, "a",
402 : NULL, FILEDISP_IFEXISTS | FILEDISP_REOPEN, 1);
403 5 : } else if (strncmp(p, "EFILE=", 5) == 0) {
404 0 : ret = open_file(context, f, min, max, p + sizeof("EFILE=") - 1, "a",
405 : NULL, FILEDISP_IFEXISTS | FILEDISP_KEEPOPEN, 1);
406 5 : } else if (strncmp(p, "FILE:", sizeof("FILE:") - 1) == 0) {
407 0 : ret = open_file(context, f, min, max, p + sizeof("FILE:") - 1, "a",
408 : NULL, FILEDISP_REOPEN, 1);
409 5 : } else if (strncmp(p, "FILE=", sizeof("FILE=") - 1) == 0) {
410 0 : ret = open_file(context, f, min, max, p + sizeof("FILE=") - 1, "a",
411 : NULL, FILEDISP_KEEPOPEN, 1);
412 5 : } else if (strncmp(p, "DEVICE:", sizeof("DEVICE:") - 1) == 0) {
413 0 : ret = open_file(context, f, min, max, p + sizeof("DEVICE:") - 1, "a",
414 : NULL, FILEDISP_REOPEN, 0);
415 5 : } else if (strncmp(p, "DEVICE=", sizeof("DEVICE=") - 1) == 0) {
416 0 : ret = open_file(context, f, min, max, p + sizeof("DEVICE=") - 1, "a",
417 : NULL, FILEDISP_KEEPOPEN, 0);
418 5 : } else if (strncmp(p, "SYSLOG", 6) == 0 && (p[6] == '\0' || p[6] == ':')) {
419 0 : char severity[128] = "";
420 0 : char facility[128] = "";
421 0 : p += 6;
422 0 : if (*p != '\0')
423 0 : p++;
424 0 : if (strsep_copy(&p, ":", severity, sizeof(severity)) != -1)
425 0 : strsep_copy(&p, ":", facility, sizeof(facility));
426 0 : if (*severity == '\0')
427 0 : strlcpy(severity, "ERR", sizeof(severity));
428 0 : if (*facility == '\0')
429 0 : strlcpy(facility, "AUTH", sizeof(facility));
430 0 : ret = open_syslog(context, f, min, max, severity, facility);
431 : } else {
432 5 : ret = EINVAL; /*XXX HEIM_ERR_LOG_PARSE*/
433 10 : heim_set_error_message(context, ret,
434 5 : N_("unknown log type: %s", ""), p);
435 : }
436 5 : return ret;
437 : }
438 :
439 : heim_error_code
440 0 : heim_openlog(heim_context context,
441 : const char *program,
442 : const char **specs,
443 : heim_log_facility **fac)
444 : {
445 : heim_error_code ret;
446 :
447 0 : ret = heim_initlog(context, program, fac);
448 0 : if (ret)
449 0 : return ret;
450 :
451 0 : if (specs) {
452 : size_t i;
453 0 : for (i = 0; specs[i] && ret == 0; i++)
454 0 : ret = heim_addlog_dest(context, *fac, specs[i]);
455 : } else {
456 0 : ret = heim_addlog_dest(context, *fac, "SYSLOG");
457 : }
458 0 : return ret;
459 : }
460 :
461 : void
462 3588505 : heim_closelog(heim_context context, heim_log_facility *fac)
463 : {
464 : int i;
465 :
466 3588505 : if (!fac || --(fac->refs))
467 3201903 : return;
468 773201 : for (i = 0; i < fac->len; i++)
469 386599 : (*fac->val[i].close_func)(fac->val[i].data);
470 386602 : free(fac->val);
471 386602 : free(fac->program);
472 386602 : fac->val = NULL;
473 386602 : fac->len = 0;
474 386602 : fac->program = NULL;
475 386602 : free(fac);
476 386602 : return;
477 : }
478 :
479 : static void
480 1411206 : format_time(heim_context context, time_t t, char *s, size_t len)
481 : {
482 2822412 : struct tm *tm = heim_context_get_log_utc(context) ?
483 1411206 : gmtime(&t) : localtime(&t);
484 1411206 : if (tm && strftime(s, len, heim_context_get_time_fmt(context), tm))
485 1411206 : return;
486 0 : snprintf(s, len, "%ld", (long)t);
487 : }
488 :
489 : #undef __attribute__
490 : #define __attribute__(X)
491 :
492 : heim_error_code
493 1411316 : heim_vlog_msg(heim_context context,
494 : heim_log_facility *fac,
495 : char **reply,
496 : int level,
497 : const char *fmt,
498 : va_list ap)
499 : __attribute__ ((__format__ (__printf__, 5, 0)))
500 : {
501 :
502 1411316 : char *msg = NULL;
503 1411316 : const char *actual = NULL;
504 : char buf[64];
505 1411316 : time_t t = 0;
506 : int i;
507 :
508 1411316 : if (!fac)
509 0 : fac = context->log_dest;
510 2822522 : for (i = 0; fac && i < fac->len; i++)
511 2822412 : if (fac->val[i].min <= level &&
512 1411206 : (fac->val[i].max < 0 || fac->val[i].max >= level)) {
513 1411206 : if (t == 0) {
514 1411206 : t = time(NULL);
515 1411206 : format_time(context, t, buf, sizeof(buf));
516 : }
517 1411206 : if (actual == NULL) {
518 1411206 : int ret = vasprintf(&msg, fmt, ap);
519 1411206 : if (ret < 0 || msg == NULL)
520 0 : actual = fmt;
521 : else
522 1411206 : actual = msg;
523 : }
524 1411206 : (*fac->val[i].log_func)(context, buf, actual, fac->val[i].data);
525 : }
526 1411316 : if (reply == NULL)
527 712747 : free(msg);
528 : else
529 698569 : *reply = msg;
530 1411316 : return 0;
531 : }
532 :
533 : heim_error_code
534 712747 : heim_vlog(heim_context context,
535 : heim_log_facility *fac,
536 : int level,
537 : const char *fmt,
538 : va_list ap)
539 : __attribute__ ((__format__ (__printf__, 4, 0)))
540 : {
541 712747 : return heim_vlog_msg(context, fac, NULL, level, fmt, ap);
542 : }
543 :
544 : heim_error_code
545 0 : heim_log_msg(heim_context context,
546 : heim_log_facility *fac,
547 : int level,
548 : char **reply,
549 : const char *fmt,
550 : ...)
551 : __attribute__ ((__format__ (__printf__, 5, 6)))
552 : {
553 : va_list ap;
554 : heim_error_code ret;
555 :
556 0 : va_start(ap, fmt);
557 0 : ret = heim_vlog_msg(context, fac, reply, level, fmt, ap);
558 0 : va_end(ap);
559 0 : return ret;
560 : }
561 :
562 :
563 : heim_error_code
564 712637 : heim_log(heim_context context,
565 : heim_log_facility *fac,
566 : int level,
567 : const char *fmt,
568 : ...)
569 : __attribute__ ((__format__ (__printf__, 4, 5)))
570 : {
571 : va_list ap;
572 : heim_error_code ret;
573 :
574 712637 : va_start(ap, fmt);
575 712637 : ret = heim_vlog(context, fac, level, fmt, ap);
576 712637 : va_end(ap);
577 712637 : return ret;
578 : }
579 :
580 : void
581 2031824 : heim_debug(heim_context context,
582 : int level,
583 : const char *fmt,
584 : ...)
585 : __attribute__ ((__format__ (__printf__, 3, 4)))
586 : {
587 : heim_log_facility *fac;
588 : va_list ap;
589 :
590 2031824 : if (context == NULL ||
591 : (fac = heim_get_debug_dest(context)) == NULL)
592 2031811 : return;
593 :
594 13 : va_start(ap, fmt);
595 13 : heim_vlog(context, fac, level, fmt, ap);
596 13 : va_end(ap);
597 : }
598 :
599 : void
600 1438654 : heim_vdebug(heim_context context,
601 : int level,
602 : const char *fmt,
603 : va_list ap)
604 : __attribute__ ((__format__ (__printf__, 3, 0)))
605 : {
606 : heim_log_facility *fac;
607 :
608 1438654 : if (context == NULL ||
609 : (fac = heim_get_debug_dest(context)) == NULL)
610 1438557 : return;
611 :
612 97 : heim_vlog(context, fac, level, fmt, ap);
613 : }
614 :
615 : heim_error_code
616 526286 : heim_have_debug(heim_context context, int level)
617 : {
618 526286 : return (context != NULL && heim_get_debug_dest(context) != NULL);
619 : }
620 :
621 : heim_error_code
622 0 : heim_add_warn_dest(heim_context context, const char *program,
623 : const char *log_spec)
624 : {
625 : heim_log_facility *fac;
626 :
627 : heim_error_code ret;
628 :
629 0 : if ((fac = heim_get_warn_dest(context)) == NULL) {
630 0 : ret = heim_initlog(context, program, &fac);
631 0 : if (ret)
632 0 : return ret;
633 0 : heim_set_warn_dest(context, fac);
634 : }
635 :
636 0 : ret = heim_addlog_dest(context, fac, log_spec);
637 0 : if (ret)
638 0 : return ret;
639 0 : return 0;
640 : }
641 :
642 : heim_error_code
643 5 : heim_add_debug_dest(heim_context context, const char *program,
644 : const char *log_spec)
645 : {
646 : heim_log_facility *fac;
647 : heim_error_code ret;
648 :
649 5 : if ((fac = heim_get_debug_dest(context)) == NULL) {
650 3 : ret = heim_initlog(context, program, &fac);
651 3 : if (ret)
652 0 : return ret;
653 3 : heim_set_debug_dest(context, fac);
654 : }
655 :
656 5 : ret = heim_addlog_dest(context, fac, log_spec);
657 5 : if (ret)
658 5 : return ret;
659 0 : return 0;
660 : }
661 :
662 : struct heim_audit_kv_tuple {
663 : heim_string_t key;
664 : heim_object_t value;
665 : };
666 :
667 : static struct heim_audit_kv_tuple zero_tuple;
668 :
669 : static struct heim_audit_kv_tuple
670 382782 : fmtkv(int flags, const char *k, const char *fmt, va_list ap)
671 : __attribute__ ((__format__ (__printf__, 3, 0)))
672 : {
673 : size_t i;
674 : ssize_t j;
675 : struct heim_audit_kv_tuple kv;
676 : char *value;
677 : char *value_vis;
678 :
679 382782 : j = vasprintf(&value, fmt, ap);
680 382782 : if (j < 0 || value == NULL)
681 0 : return zero_tuple;
682 :
683 : /* We optionally eat the whitespace. */
684 :
685 382782 : if (flags & HEIM_SVC_AUDIT_EATWHITE) {
686 2543044 : for (i=0, j=0; value[i]; i++)
687 2411039 : if (value[i] != ' ' && value[i] != '\t')
688 2352789 : value[j++] = value[i];
689 132005 : value[j] = '\0';
690 : }
691 :
692 382782 : if (flags & (HEIM_SVC_AUDIT_VIS | HEIM_SVC_AUDIT_VISLAST)) {
693 39264 : int vis_flags = VIS_CSTYLE | VIS_OCTAL | VIS_NL;
694 :
695 39264 : if (flags & HEIM_SVC_AUDIT_VIS)
696 37752 : vis_flags |= VIS_WHITE;
697 39264 : value_vis = malloc((j + 1) * 4 + 1);
698 39264 : if (value_vis)
699 39264 : strvisx(value_vis, value, j, vis_flags);
700 39264 : free(value);
701 39264 : if (value_vis == NULL)
702 0 : return zero_tuple;
703 : } else
704 343518 : value_vis = value;
705 :
706 382782 : if (k)
707 381270 : kv.key = heim_string_create(k);
708 : else
709 1512 : kv.key = NULL;
710 382782 : kv.value = heim_string_ref_create(value_vis, free);
711 :
712 382782 : return kv;
713 : }
714 :
715 : void
716 1512 : heim_audit_vaddreason(heim_svc_req_desc r, const char *fmt, va_list ap)
717 : __attribute__ ((__format__ (__printf__, 2, 0)))
718 : {
719 : struct heim_audit_kv_tuple kv;
720 :
721 1512 : kv = fmtkv(HEIM_SVC_AUDIT_VISLAST, NULL, fmt, ap);
722 1512 : if (kv.value == NULL) {
723 0 : heim_log(r->hcontext, r->logf, 1, "heim_audit_vaddreason: "
724 : "failed to add reason (out of memory)");
725 0 : return;
726 : }
727 :
728 1512 : heim_log(r->hcontext, r->logf, 7, "heim_audit_vaddreason(): "
729 1512 : "adding reason %s", heim_string_get_utf8(kv.value));
730 1512 : if (r->reason) {
731 : heim_string_t str2;
732 :
733 0 : str2 = heim_string_create_with_format("%s: %s",
734 0 : heim_string_get_utf8(kv.value),
735 : heim_string_get_utf8(r->reason));
736 0 : if (str2) {
737 0 : heim_release(kv.value);
738 0 : kv.value = str2;
739 : }
740 : }
741 1512 : heim_release(r->reason);
742 1512 : r->reason = kv.value;
743 : }
744 :
745 : void
746 0 : heim_audit_addreason(heim_svc_req_desc r, const char *fmt, ...)
747 : __attribute__ ((__format__ (__printf__, 2, 3)))
748 : {
749 : va_list ap;
750 :
751 0 : va_start(ap, fmt);
752 0 : heim_audit_vaddreason(r, fmt, ap);
753 0 : va_end(ap);
754 0 : }
755 :
756 : size_t
757 381270 : addkv(heim_svc_req_desc r, heim_object_t key, heim_object_t value)
758 : {
759 : size_t index;
760 : heim_object_t obj;
761 :
762 381270 : obj = heim_dict_get_value(r->kv, key);
763 381270 : if (obj) {
764 0 : if (heim_get_tid(obj) == HEIM_TID_ARRAY) {
765 0 : index = heim_array_get_length(obj);
766 0 : heim_array_append_value(obj, value);
767 : } else {
768 0 : heim_array_t array = heim_array_create();
769 :
770 0 : index = 1;
771 0 : heim_array_append_value(array, obj);
772 0 : heim_array_append_value(array, value);
773 0 : heim_dict_set_value(r->kv, key, array);
774 0 : heim_release(array); /* retained by r->kv */
775 : }
776 : } else {
777 381270 : index = 0;
778 381270 : heim_dict_set_value(r->kv, key, value);
779 : }
780 :
781 381270 : return index;
782 : }
783 :
784 : /*
785 : * add a key-value token. if the key already exists, the value is
786 : * promoted to an array of values.
787 : */
788 :
789 : void
790 381270 : heim_audit_vaddkv(heim_svc_req_desc r, int flags, const char *k,
791 : const char *fmt, va_list ap)
792 : __attribute__ ((__format__ (__printf__, 4, 0)))
793 : {
794 : struct heim_audit_kv_tuple kv;
795 : size_t index;
796 :
797 381270 : kv = fmtkv(flags, k, fmt, ap);
798 381270 : if (kv.key == NULL || kv.value == NULL) {
799 0 : heim_log(r->hcontext, r->logf, 1, "heim_audit_vaddkv: "
800 : "failed to add kv pair (out of memory)");
801 0 : heim_release(kv.key);
802 0 : heim_release(kv.value);
803 0 : return;
804 : }
805 :
806 381270 : index = addkv(r, kv.key, kv.value);
807 :
808 381270 : heim_log(r->hcontext, r->logf, 7, "heim_audit_vaddkv(): "
809 : "kv pair[%zu] %s=%s", index,
810 381270 : heim_string_get_utf8(kv.key), heim_string_get_utf8(kv.value));
811 :
812 381270 : heim_release(kv.key);
813 381270 : heim_release(kv.value);
814 : }
815 :
816 : void
817 90054 : heim_audit_addkv(heim_svc_req_desc r, int flags, const char *k,
818 : const char *fmt, ...)
819 : __attribute__ ((__format__ (__printf__, 4, 5)))
820 : {
821 : va_list ap;
822 :
823 90054 : va_start(ap, fmt);
824 90054 : heim_audit_vaddkv(r, flags, k, fmt, ap);
825 90054 : va_end(ap);
826 90054 : }
827 :
828 : void
829 71023 : heim_audit_addkv_timediff(heim_svc_req_desc r, const char *k,
830 : const struct timeval *start,
831 : const struct timeval *end)
832 : {
833 : time_t sec;
834 : int usec;
835 71023 : const char *sign = "";
836 :
837 141415 : if (end->tv_sec > start->tv_sec ||
838 140784 : (end->tv_sec == start->tv_sec && end->tv_usec >= start->tv_usec)) {
839 71023 : sec = end->tv_sec - start->tv_sec;
840 71023 : usec = end->tv_usec - start->tv_usec;
841 : } else {
842 0 : sec = start->tv_sec - end->tv_sec;
843 0 : usec = start->tv_usec - end->tv_usec;
844 0 : sign = "-";
845 : }
846 :
847 71023 : if (usec < 0) {
848 630 : usec += 1000000;
849 630 : sec -= 1;
850 : }
851 :
852 71023 : heim_audit_addkv(r, 0, k, "%s%ld.%06d", sign, (long)sec, usec);
853 71023 : }
854 :
855 : void
856 0 : heim_audit_setkv_bool(heim_svc_req_desc r, const char *k, int v)
857 : {
858 0 : heim_string_t key = heim_string_create(k);
859 : heim_number_t value;
860 :
861 0 : if (key == NULL)
862 0 : return;
863 :
864 0 : heim_log(r->hcontext, r->logf, 7, "heim_audit_setkv_bool(): "
865 : "setting kv pair %s=%s", k, v ? "true" : "false");
866 :
867 0 : value = heim_bool_create(v);
868 0 : heim_dict_set_value(r->kv, key, value);
869 0 : heim_release(key);
870 0 : heim_release(value);
871 : }
872 :
873 : void
874 0 : heim_audit_addkv_number(heim_svc_req_desc r, const char *k, int64_t v)
875 : {
876 0 : heim_string_t key = heim_string_create(k);
877 : heim_number_t value;
878 :
879 0 : if (key == NULL)
880 0 : return;
881 :
882 0 : heim_log(r->hcontext, r->logf, 7, "heim_audit_addkv_number(): "
883 : "adding kv pair %s=%lld", k, (long long)v);
884 :
885 0 : value = heim_number_create(v);
886 0 : addkv(r, key, value);
887 0 : heim_release(key);
888 0 : heim_release(value);
889 : }
890 :
891 : void
892 258072 : heim_audit_setkv_number(heim_svc_req_desc r, const char *k, int64_t v)
893 : {
894 258072 : heim_string_t key = heim_string_create(k);
895 : heim_number_t value;
896 :
897 258072 : if (key == NULL)
898 0 : return;
899 :
900 258072 : heim_log(r->hcontext, r->logf, 7, "heim_audit_setkv_number(): "
901 : "setting kv pair %s=%lld", k, (long long)v);
902 :
903 258072 : value = heim_number_create(v);
904 258072 : heim_dict_set_value(r->kv, key, value);
905 258072 : heim_release(key);
906 258072 : heim_release(value);
907 : }
908 :
909 : void
910 0 : heim_audit_addkv_object(heim_svc_req_desc r, const char *k, heim_object_t value)
911 : {
912 0 : heim_string_t key = heim_string_create(k);
913 : heim_string_t descr;
914 :
915 0 : if (key == NULL)
916 0 : return;
917 :
918 0 : descr = heim_json_copy_serialize(value, HEIM_JSON_F_NO_DATA_DICT, NULL);
919 0 : heim_log(r->hcontext, r->logf, 7, "heim_audit_addkv_object(): "
920 : "adding kv pair %s=%s",
921 : k, descr ? heim_string_get_utf8(descr) : "<unprintable>");
922 0 : addkv(r, key, value);
923 0 : heim_release(key);
924 0 : heim_release(descr);
925 : }
926 :
927 : void
928 0 : heim_audit_setkv_object(heim_svc_req_desc r, const char *k, heim_object_t value)
929 : {
930 0 : heim_string_t key = heim_string_create(k);
931 : heim_string_t descr;
932 :
933 0 : if (key == NULL)
934 0 : return;
935 :
936 0 : descr = heim_json_copy_serialize(value, HEIM_JSON_F_NO_DATA_DICT, NULL);
937 0 : heim_log(r->hcontext, r->logf, 7, "heim_audit_setkv_object(): "
938 : "setting kv pair %s=%s",
939 : k, descr ? heim_string_get_utf8(descr) : "<unprintable>");
940 0 : heim_dict_set_value(r->kv, key, value);
941 0 : heim_release(key);
942 0 : heim_release(descr);
943 : }
944 :
945 : heim_object_t
946 166280 : heim_audit_getkv(heim_svc_req_desc r, const char *k)
947 : {
948 : heim_string_t key;
949 : heim_object_t value;
950 :
951 166280 : key = heim_string_create(k);
952 166280 : if (key == NULL)
953 0 : return NULL;
954 :
955 166280 : value = heim_dict_get_value(r->kv, key);
956 166280 : heim_release(key);
957 166280 : return value;
958 : }
959 :
960 : struct heim_audit_kv_buf {
961 : char buf[1024];
962 : size_t pos;
963 : heim_object_t iter;
964 : };
965 :
966 : static void
967 : audit_trail_iterator(heim_object_t key, heim_object_t value, void *arg);
968 :
969 : static void
970 0 : audit_trail_iterator_array(heim_object_t value, void *arg, int *stop)
971 : {
972 0 : struct heim_audit_kv_buf *kvb = arg;
973 :
974 0 : audit_trail_iterator(kvb->iter, value, kvb);
975 0 : }
976 :
977 : static void
978 620933 : audit_trail_iterator(heim_object_t key, heim_object_t value, void *arg)
979 : {
980 620933 : struct heim_audit_kv_buf *kvb = arg;
981 : char num[32];
982 620933 : const char *k = heim_string_get_utf8(key), *v = NULL;
983 620933 : char *b64 = NULL;
984 :
985 620933 : if (k == NULL || *k == '#') /* # keys are hidden */
986 38268 : return;
987 :
988 601799 : switch (heim_get_tid(value)) {
989 381270 : case HEIM_TID_STRING:
990 381270 : v = heim_string_get_utf8(value);
991 381270 : break;
992 220529 : case HEIM_TID_NUMBER:
993 220529 : snprintf(num, sizeof(num), "%lld", (long long)heim_number_get_long(value));
994 220529 : v = num;
995 220529 : break;
996 0 : case HEIM_TID_NULL:
997 0 : v = "null";
998 0 : break;
999 0 : case HEIM_TID_BOOL:
1000 0 : v = heim_bool_val(value) ? "true" : "false";
1001 0 : break;
1002 0 : case HEIM_TID_ARRAY:
1003 0 : if (kvb->iter)
1004 0 : break; /* arrays cannot be nested */
1005 :
1006 0 : kvb->iter = key;
1007 0 : heim_array_iterate_f(value, kvb, audit_trail_iterator_array);
1008 0 : kvb->iter = NULL;
1009 0 : break;
1010 0 : case HEIM_TID_DATA: {
1011 0 : const heim_octet_string *data = heim_data_get_data(value);
1012 0 : if (rk_base64_encode(data->data, data->length, &b64) >= 0)
1013 0 : v = b64;
1014 0 : break;
1015 : }
1016 0 : default:
1017 0 : break;
1018 : }
1019 :
1020 601799 : if (v == NULL)
1021 0 : return;
1022 :
1023 601799 : if (kvb->pos < sizeof(kvb->buf) - 1)
1024 601799 : kvb->buf[kvb->pos++] = ' ';
1025 5300430 : for (; *k && kvb->pos < sizeof(kvb->buf) - 1; kvb->pos++)
1026 4698631 : kvb->buf[kvb->pos] = *k++;
1027 601799 : if (kvb->pos < sizeof(kvb->buf) - 1)
1028 601799 : kvb->buf[kvb->pos++] = '=';
1029 9089150 : for (; *v && kvb->pos < sizeof(kvb->buf) - 1; kvb->pos++)
1030 8487351 : kvb->buf[kvb->pos] = *v++;
1031 :
1032 601799 : free(b64);
1033 : }
1034 :
1035 : void
1036 71023 : heim_audit_trail(heim_svc_req_desc r, heim_error_code ret, const char *retname)
1037 : {
1038 : const char *retval;
1039 : struct heim_audit_kv_buf kvb;
1040 : char retvalbuf[30]; /* Enough for UNKNOWN-%d */
1041 :
1042 : #define CASE(x) case x : retval = #x; break
1043 71023 : if (retname) {
1044 70922 : retval = retname;
1045 101 : } else switch (ret ? ret : r->error_code) {
1046 0 : CASE(ENOMEM);
1047 0 : CASE(ENOENT);
1048 0 : CASE(EACCES);
1049 0 : case 0:
1050 0 : retval = "SUCCESS";
1051 0 : break;
1052 101 : default:
1053 : /* Wish we had a com_err number->symbolic name function */
1054 101 : (void) snprintf(retvalbuf, sizeof(retvalbuf), "UNKNOWN-%d", ret);
1055 101 : retval = retvalbuf;
1056 101 : break;
1057 : }
1058 :
1059 71023 : heim_audit_addkv_timediff(r, "elapsed", &r->tv_start, &r->tv_end);
1060 71023 : if (r->e_text && r->kv)
1061 19031 : heim_audit_addkv(r, HEIM_SVC_AUDIT_VIS, "e-text", "%s", r->e_text);
1062 :
1063 71023 : memset(&kvb, 0, sizeof(kvb));
1064 71023 : if (r->kv)
1065 71023 : heim_dict_iterate_f(r->kv, &kvb, audit_trail_iterator);
1066 71023 : kvb.buf[kvb.pos] = '\0';
1067 :
1068 285604 : heim_log(r->hcontext, r->logf, 3, "%s %s %s %s %s%s%s%s",
1069 : r->reqtype, retval, r->from,
1070 71023 : r->cname ? r->cname : "<unknown>",
1071 71023 : r->sname ? r->sname : "<unknown>",
1072 71023 : kvb.buf, r->reason ? " reason=" : "",
1073 72535 : r->reason ? heim_string_get_utf8(r->reason) : "");
1074 71023 : }
|
