src/lib/krb5/os/trace.c

   1 /* -*- mode: c; c-basic-offset: 4; indent-tabs-mode: nil -*- */
   2 /* lib/krb5/os/trace.c - krb5int_trace implementation */
   3 /*
   4  * Copyright 2009 by the Massachusetts Institute of Technology.
   5  * All Rights Reserved.
   6  *
   7  * Export of this software from the United States of America may
   8  *   require a specific license from the United States Government.
   9  *   It is the responsibility of any person or organization contemplating
  10  *   export to obtain such a license before exporting.
  11  *
  12  * WITHIN THAT CONSTRAINT, permission to use, copy, modify, and
  13  * distribute this software and its documentation for any purpose and
  14  * without fee is hereby granted, provided that the above copyright
  15  * notice appear in all copies and that both that copyright notice and
  16  * this permission notice appear in supporting documentation, and that
  17  * the name of M.I.T. not be used in advertising or publicity pertaining
  18  * to distribution of the software without specific, written prior
  19  * permission.  Furthermore if you modify this software you must label
  20  * your software as modified software and not distribute it in such a
  21  * fashion that it might be confused with the original M.I.T. software.
  22  * M.I.T. makes no representations about the suitability of
  23  * this software for any purpose.  It is provided "as is" without express
  24  * or implied warranty.
  25  */
  26
  27 /*
  28  * krb5int_trace is defined in k5-trace.h as a macro or static inline
  29  * function, and is called like so:
  30  *
  31  *   void krb5int_trace(krb5_context context, const char *fmt, ...)
  32  *
  33  * Arguments may or may not be evaluated, so don't pass argument
  34  * expressions with side effects.  Tracing support and calls can be
  35  * explicitly compiled out with DISABLE_TRACING, but compile-time
  36  * support is enabled by default.  Tracing calls use a custom
  37  * formatter supporting the following format specifications:
  38  */
  39
  40 #include "k5-int.h"
  41 #include "cm.h"
  42
  43 #ifndef DISABLE_TRACING
  44
  45 static void subfmt(krb5_context context, struct k5buf *buf,
  46                    const char *fmt, ...);
  47
  48 /* Return a four-byte hex string from the first two bytes of a SHA-1 hash of a
  49  * byte array.  Return NULL on failure. */
  50 static char *
  51 hash_bytes(krb5_context context, const void *ptr, size_t len)
  52 {
  53     krb5_checksum cksum;
  54     krb5_data d = make_data((void *) ptr, len);
  55     char *s = NULL;
  56
  57     if (krb5_k_make_checksum(context, CKSUMTYPE_NIST_SHA, NULL, 0, &d,
  58                              &cksum) != 0)
  59         return NULL;
  60     if (cksum.length >= 2)
  61         (void) asprintf(&s, "%02X%02X", cksum.contents[0], cksum.contents[1]);
  62     krb5_free_checksum_contents(context, &cksum);
  63     return s;
  64 }
  65
  66 static char *
  67 principal_type_string(krb5_int32 type)
  68 {
  69     switch (type) {
  70     case KRB5_NT_UNKNOWN: return "unknown";
  71     case KRB5_NT_PRINCIPAL: return "principal";
  72     case KRB5_NT_SRV_INST: return "service instance";
  73     case KRB5_NT_SRV_HST: return "service with host as instance";
  74     case KRB5_NT_SRV_XHST: return "service with host as components";
  75     case KRB5_NT_UID: return "unique ID";
  76     case KRB5_NT_X500_PRINCIPAL: return "X.509";
  77     case KRB5_NT_SMTP_NAME: return "SMTP email";
  78     case KRB5_NT_ENTERPRISE_PRINCIPAL: return "Windows 2000 UPN";
  79     case KRB5_NT_WELLKNOWN: return "well-known";
  80     case KRB5_NT_MS_PRINCIPAL: return "Windows 2000 UPN and SID";
  81     case KRB5_NT_MS_PRINCIPAL_AND_ID: return "NT 4 style name";
  82     case KRB5_NT_ENT_PRINCIPAL_AND_ID: return "NT 4 style name and SID";
  83     default: return "?";
  84     }
  85 }
  86
  87 static char *
  88 trace_format(krb5_context context, const char *fmt, va_list ap)
  89 {
  90     struct k5buf buf;
  91     krb5_error_code kerr;
  92     size_t len, i;
  93     int err;
  94     struct conn_state *cs;
  95     const krb5_data *d;
  96     krb5_data data;
  97     char addrbuf[NI_MAXHOST], portbuf[NI_MAXSERV], tmpbuf[200], *str;
  98     const char *p;
  99     krb5_const_principal princ;
 100     const krb5_keyblock *keyblock;
 101     krb5_key key;
 102     const krb5_checksum *cksum;
 103     krb5_pa_data **padata;
 104     krb5_ccache ccache;
 105     krb5_keytab keytab;
 106     krb5_creds *creds;
 107     krb5_enctype *etypes, etype;
 108
 109     krb5int_buf_init_dynamic(&buf);
 110     while (TRUE) {
 111         /* Advance to the next word in braces. */
 112         len = strcspn(fmt, "{");
 113         krb5int_buf_add_len(&buf, fmt, len);
 114         if (fmt[len] == '\0')
 115             break;
 116         fmt += len + 1;
 117         len = strcspn(fmt, "}");
 118         if (fmt[len] == '\0' || len > sizeof(tmpbuf) - 1)
 119             break;
 120         memcpy(tmpbuf, fmt, len);
 121         tmpbuf[len] = '\0';
 122         fmt += len + 1;
 123
 124         /* Process the format word. */
 125         if (strcmp(tmpbuf, "int") == 0) {
 126             krb5int_buf_add_fmt(&buf, "%d", va_arg(ap, int));
 127         } else if (strcmp(tmpbuf, "long") == 0) {
 128             krb5int_buf_add_fmt(&buf, "%ld", va_arg(ap, long));
 129         } else if (strcmp(tmpbuf, "str") == 0) {
 130             p = va_arg(ap, const char *);
 131             krb5int_buf_add(&buf, (p == NULL) ? "(null)" : p);
 132         } else if (strcmp(tmpbuf, "lenstr") == 0) {
 133             len = va_arg(ap, size_t);
 134             p = va_arg(ap, const char *);
 135             if (p == NULL && len != 0)
 136                 krb5int_buf_add(&buf, "(null)");
 137             else
 138                 krb5int_buf_add_len(&buf, p, len);
 139         } else if (strcmp(tmpbuf, "hexlenstr") == 0) {
 140             len = va_arg(ap, size_t);
 141             p = va_arg(ap, const char *);
 142             if (p == NULL && len != 0)
 143                 krb5int_buf_add(&buf, "(null)");
 144             else {
 145                 for (i = 0; i < len; i++)
 146                     krb5int_buf_add_fmt(&buf, "%02X", (unsigned char) p[i]);
 147             }
 148         } else if (strcmp(tmpbuf, "hashlenstr") == 0) {
 149             len = va_arg(ap, size_t);
 150             p = va_arg(ap, const char *);
 151             if (p == NULL && len != 0)
 152                 krb5int_buf_add(&buf, "(null)");
 153             else {
 154                 str = hash_bytes(context, p, len);
 155                 if (str != NULL)
 156                     krb5int_buf_add(&buf, str);
 157                 free(str);
 158             }
 159         } else if (strcmp(tmpbuf, "connstate") == 0) {
 160             cs = va_arg(ap, struct conn_state *);
 161             if (cs->socktype == SOCK_DGRAM)
 162                 krb5int_buf_add(&buf, "dgram");
 163             else if (cs->socktype == SOCK_STREAM)
 164                 krb5int_buf_add(&buf, "stream");
 165             else
 166                 krb5int_buf_add_fmt(&buf, "socktype%d", cs->socktype);
 167
 168             if (getnameinfo((struct sockaddr *)&cs->addr, cs->addrlen,
 169                             addrbuf, sizeof(addrbuf), portbuf, sizeof(portbuf),
 170                             NI_NUMERICHOST|NI_NUMERICSERV) != 0) {
 171                 if (cs->family == AF_UNSPEC)
 172                     krb5int_buf_add(&buf, " AF_UNSPEC");
 173                 else
 174                     krb5int_buf_add_fmt(&buf, " af%d", cs->family);
 175             } else
 176                 krb5int_buf_add_fmt(&buf, " %s:%s", addrbuf, portbuf);
 177         } else if (strcmp(tmpbuf, "data") == 0) {
 178             d = va_arg(ap, krb5_data *);
 179             if (d == NULL || (d->length != 0 && d->data == NULL))
 180                 krb5int_buf_add(&buf, "(null)");
 181             else
 182                 krb5int_buf_add_len(&buf, d->data, d->length);
 183         } else if (strcmp(tmpbuf, "hexdata") == 0) {
 184             d = va_arg(ap, krb5_data *);
 185             if (d == NULL)
 186                 krb5int_buf_add(&buf, "(null)");
 187             else
 188                 subfmt(context, &buf, "{hexlenstr}", d->length, d->data);
 189         } else if (strcmp(tmpbuf, "errno") == 0) {
 190             err = va_arg(ap, int);
 191             p = NULL;
 192 #ifdef HAVE_STRERROR_R
 193             if (strerror_r(err, tmpbuf, sizeof(tmpbuf)) == 0)
 194                 p = tmpbuf;
 195 #endif
 196             if (p == NULL)
 197                 p = strerror(err);
 198             krb5int_buf_add_fmt(&buf, "%d/%s", err, p);
 199         } else if (strcmp(tmpbuf, "kerr") == 0) {
 200             kerr = va_arg(ap, krb5_error_code);
 201             p = krb5_get_error_message(context, kerr);
 202             krb5int_buf_add_fmt(&buf, "%ld/%s", (long) kerr,
 203                                 kerr ? p : "Success");
 204             krb5_free_error_message(context, p);
 205         } else if (strcmp(tmpbuf, "keyblock") == 0) {
 206             keyblock = va_arg(ap, const krb5_keyblock *);
 207             if (keyblock == NULL)
 208                 krb5int_buf_add(&buf, "(null)");
 209             else {
 210                 subfmt(context, &buf, "{etype}/{hashlenstr}",
 211                        keyblock->enctype, keyblock->length,
 212                        keyblock->contents);
 213             }
 214         } else if (strcmp(tmpbuf, "key") == 0) {
 215             key = va_arg(ap, krb5_key);
 216             if (key == NULL)
 217                 krb5int_buf_add(&buf, "(null)");
 218             else
 219                 subfmt(context, &buf, "{keyblock}", &key->keyblock);
 220         } else if (strcmp(tmpbuf, "cksum") == 0) {
 221             cksum = va_arg(ap, const krb5_checksum *);
 222             data = make_data(cksum->contents, cksum->length);
 223             subfmt(context, &buf, "{int}/{hexdata}",
 224                    (int) cksum->checksum_type, &data);
 225         } else if (strcmp(tmpbuf, "princ") == 0) {
 226             princ = va_arg(ap, krb5_principal);
 227             if (krb5_unparse_name(context, princ, &str) == 0) {
 228                 krb5int_buf_add(&buf, str);
 229                 krb5_free_unparsed_name(context, str);
 230             }
 231         } else if (strcmp(tmpbuf, "ptype") == 0) {
 232             p = principal_type_string(va_arg(ap, krb5_int32));
 233             krb5int_buf_add(&buf, p);
 234         } else if (strcmp(tmpbuf, "patypes") == 0) {
 235             padata = va_arg(ap, krb5_pa_data **);
 236             if (padata == NULL || *padata == NULL)
 237                 krb5int_buf_add(&buf, "(empty)");
 238             for (; padata != NULL && *padata != NULL; padata++) {
 239                 krb5int_buf_add_fmt(&buf, "%d", (int) (*padata)->pa_type);
 240                 if (*(padata + 1) != NULL)
 241                     krb5int_buf_add(&buf, ", ");
 242             }
 243         } else if (strcmp(tmpbuf, "etype") == 0) {
 244             etype = va_arg(ap, krb5_enctype);
 245             if (krb5_enctype_to_name(etype, TRUE, tmpbuf, sizeof(tmpbuf)) == 0)
 246                 krb5int_buf_add(&buf, tmpbuf);
 247             else
 248                 krb5int_buf_add_fmt(&buf, "%d", (int) etype);
 249         } else if (strcmp(tmpbuf, "etypes") == 0) {
 250             etypes = va_arg(ap, krb5_enctype *);
 251             if (etypes == NULL || *etypes == 0)
 252                 krb5int_buf_add(&buf, "(empty)");
 253             for (; etypes != NULL && *etypes != 0; etypes++) {
 254                 subfmt(context, &buf, "{etype}", *etypes);
 255                 if (*(etypes + 1) != 0)
 256                     krb5int_buf_add(&buf, ", ");
 257             }
 258         } else if (strcmp(tmpbuf, "ccache") == 0) {
 259             ccache = va_arg(ap, krb5_ccache);
 260             krb5int_buf_add(&buf, krb5_cc_get_type(context, ccache));
 261             krb5int_buf_add(&buf, ":");
 262             krb5int_buf_add(&buf, krb5_cc_get_name(context, ccache));
 263         } else if (strcmp(tmpbuf, "keytab") == 0) {
 264             keytab = va_arg(ap, krb5_keytab);
 265             if (krb5_kt_get_name(context, keytab, tmpbuf, sizeof(tmpbuf)) == 0)
 266                 krb5int_buf_add(&buf, tmpbuf);
 267         } else if (strcmp(tmpbuf, "creds") == 0) {
 268             creds = va_arg(ap, krb5_creds *);
 269             subfmt(context, &buf, "{princ} -> {princ}",
 270                    creds->client, creds->server);
 271         }
 272     }
 273     return krb5int_buf_data(&buf);
 274 }
 275
 276 /* Allows trace_format formatters to be represented in terms of other
 277  * formatters. */
 278 static void
 279 subfmt(krb5_context context, struct k5buf *buf, const char *fmt, ...)
 280 {
 281     va_list ap;
 282     char *str;
 283
 284     va_start(ap, fmt);
 285     str = trace_format(context, fmt, ap);
 286     if (str != NULL)
 287         krb5int_buf_add(buf, str);
 288     free(str);
 289     va_end(ap);
 290 }
 291
 292 void
 293 krb5int_init_trace(krb5_context context)
 294 {
 295     const char *filename;
 296
 297     filename = getenv("KRB5_TRACE");
 298     if (filename)
 299         (void) krb5_set_trace_filename(context, filename);
 300 }
 301
 302 void
 303 krb5int_trace(krb5_context context, const char *fmt, ...)
 304 {
 305     va_list ap;
 306     struct krb5_trace_info info;
 307     char *str = NULL, *msg = NULL;
 308     krb5_int32 sec, usec;
 309
 310     if (context == NULL || context->trace_callback == NULL)
 311         return;
 312     va_start(ap, fmt);
 313     str = trace_format(context, fmt, ap);
 314     if (str == NULL)
 315         goto cleanup;
 316     if (krb5_crypto_us_timeofday(&sec, &usec) != 0)
 317         goto cleanup;
 318     if (asprintf(&msg, "[%d] %d.%d: %s\n", (int) getpid(), (int) sec,
 319                  (int) usec, str) < 0)
 320         goto cleanup;
 321     info.message = msg;
 322     context->trace_callback(context, &info, context->trace_callback_data);
 323 cleanup:
 324     free(str);
 325     free(msg);
 326     va_end(ap);
 327 }
 328
 329 krb5_error_code KRB5_CALLCONV
 330 krb5_set_trace_callback(krb5_context context, krb5_trace_callback fn,
 331                         void *cb_data)
 332 {
 333     /* Allow the old callback to destroy its data if necessary. */
 334     if (context->trace_callback != NULL)
 335         context->trace_callback(context, NULL, context->trace_callback_data);
 336     context->trace_callback = fn;
 337     context->trace_callback_data = cb_data;
 338     return 0;
 339 }
 340
 341 static void KRB5_CALLCONV
 342 file_trace_cb(krb5_context context, const struct krb5_trace_info *info, void *data)
 343 {
 344     int *fd = data;
 345
 346     if (info == NULL) {
 347         /* Null info means destroy the callback data. */
 348         close(*fd);
 349         free(fd);
 350         return;
 351     }
 352
 353     (void) write(*fd, info->message, strlen(info->message));
 354 }
 355
 356 krb5_error_code KRB5_CALLCONV
 357 krb5_set_trace_filename(krb5_context context, const char *filename)
 358 {
 359     int *fd;
 360
 361     /* Create callback data containing a file descriptor. */
 362     fd = malloc(sizeof(*fd));
 363     if (fd == NULL)
 364         return ENOMEM;
 365     *fd = open(filename, O_WRONLY|O_CREAT|O_APPEND, 0600);
 366     if (*fd == -1) {
 367         free(fd);
 368         return errno;
 369     }
 370
 371     return krb5_set_trace_callback(context, file_trace_cb, fd);
 372 }
 373
 374 #else /* DISABLE_TRACING */
 375
 376 krb5_error_code KRB5_CALLCONV
 377 krb5_set_trace_callback(krb5_context context, krb5_trace_callback fn,
 378                         void *cb_data)
 379 {
 380     if (fn == NULL)
 381         return 0;
 382     return KRB5_TRACE_NOSUPP;
 383 }
 384
 385 krb5_error_code KRB5_CALLCONV
 386 krb5_set_trace_filename(krb5_context context, const char *filename)
 387 {
 388     return KRB5_TRACE_NOSUPP;
 389 }
 390
 391 #endif /* DISABLE_TRACING */