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 "os-proto.h"
42
43 #ifndef DISABLE_TRACING
44
45 static void subfmt(krb5_context context, struct k5buf *buf,
46 const char *fmt, ...);
47
48 static krb5_boolean
buf_is_printable(const char * p,size_t len)49 buf_is_printable(const char *p, size_t len)
50 {
51 size_t i;
52
53 for (i = 0; i < len; i++) {
54 if (p[i] < 32 || p[i] > 126)
55 break;
56 }
57 return i == len;
58 }
59
60 static void
buf_add_printable_len(struct k5buf * buf,const char * p,size_t len)61 buf_add_printable_len(struct k5buf *buf, const char *p, size_t len)
62 {
63 char text[5];
64 size_t i;
65
66 if (buf_is_printable(p, len)) {
67 k5_buf_add_len(buf, p, len);
68 } else {
69 for (i = 0; i < len; i++) {
70 if (buf_is_printable(p + i, 1)) {
71 k5_buf_add_len(buf, p + i, 1);
72 } else {
73 snprintf(text, sizeof(text), "\\x%02x",
74 (unsigned)(p[i] & 0xff));
75 k5_buf_add_len(buf, text, 4);
76 }
77 }
78 }
79 }
80
81 static void
buf_add_printable(struct k5buf * buf,const char * p)82 buf_add_printable(struct k5buf *buf, const char *p)
83 {
84 buf_add_printable_len(buf, p, strlen(p));
85 }
86
87 /* Return a four-byte hex string from the first two bytes of a SHA-1 hash of a
88 * byte array. Return NULL on failure. */
89 static char *
hash_bytes(krb5_context context,const void * ptr,size_t len)90 hash_bytes(krb5_context context, const void *ptr, size_t len)
91 {
92 krb5_checksum cksum;
93 krb5_data d = make_data((void *) ptr, len);
94 char *s = NULL;
95
96 if (krb5_k_make_checksum(context, CKSUMTYPE_SHA1, NULL, 0, &d,
97 &cksum) != 0)
98 return NULL;
99 if (cksum.length >= 2)
100 (void) asprintf(&s, "%02X%02X", cksum.contents[0], cksum.contents[1]);
101 krb5_free_checksum_contents(context, &cksum);
102 return s;
103 }
104
105 static char *
principal_type_string(krb5_int32 type)106 principal_type_string(krb5_int32 type)
107 {
108 switch (type) {
109 case KRB5_NT_UNKNOWN: return "unknown";
110 case KRB5_NT_PRINCIPAL: return "principal";
111 case KRB5_NT_SRV_INST: return "service instance";
112 case KRB5_NT_SRV_HST: return "service with host as instance";
113 case KRB5_NT_SRV_XHST: return "service with host as components";
114 case KRB5_NT_UID: return "unique ID";
115 case KRB5_NT_X500_PRINCIPAL: return "X.509";
116 case KRB5_NT_SMTP_NAME: return "SMTP email";
117 case KRB5_NT_ENTERPRISE_PRINCIPAL: return "Windows 2000 UPN";
118 case KRB5_NT_WELLKNOWN: return "well-known";
119 case KRB5_NT_MS_PRINCIPAL: return "Windows 2000 UPN and SID";
120 case KRB5_NT_MS_PRINCIPAL_AND_ID: return "NT 4 style name";
121 case KRB5_NT_ENT_PRINCIPAL_AND_ID: return "NT 4 style name and SID";
122 default: return "?";
123 }
124 }
125
126 static char *
padata_type_string(krb5_preauthtype type)127 padata_type_string(krb5_preauthtype type)
128 {
129 switch (type) {
130 case KRB5_PADATA_TGS_REQ: return "PA-TGS-REQ";
131 case KRB5_PADATA_ENC_TIMESTAMP: return "PA-ENC-TIMESTAMP";
132 case KRB5_PADATA_PW_SALT: return "PA-PW-SALT";
133 case KRB5_PADATA_ENC_UNIX_TIME: return "PA-ENC-UNIX-TIME";
134 case KRB5_PADATA_ENC_SANDIA_SECURID: return "PA-SANDIA-SECUREID";
135 case KRB5_PADATA_SESAME: return "PA-SESAME";
136 case KRB5_PADATA_OSF_DCE: return "PA-OSF-DCE";
137 case KRB5_CYBERSAFE_SECUREID: return "PA-CYBERSAFE-SECUREID";
138 case KRB5_PADATA_AFS3_SALT: return "PA-AFS3-SALT";
139 case KRB5_PADATA_ETYPE_INFO: return "PA-ETYPE-INFO";
140 case KRB5_PADATA_SAM_CHALLENGE: return "PA-SAM-CHALLENGE";
141 case KRB5_PADATA_SAM_RESPONSE: return "PA-SAM-RESPONSE";
142 case KRB5_PADATA_PK_AS_REQ_OLD: return "PA-PK-AS-REQ_OLD";
143 case KRB5_PADATA_PK_AS_REP_OLD: return "PA-PK-AS-REP_OLD";
144 case KRB5_PADATA_PK_AS_REQ: return "PA-PK-AS-REQ";
145 case KRB5_PADATA_PK_AS_REP: return "PA-PK-AS-REP";
146 case KRB5_PADATA_ETYPE_INFO2: return "PA-ETYPE-INFO2";
147 case KRB5_PADATA_SVR_REFERRAL_INFO: return "PA-SVR-REFERRAL-INFO";
148 case KRB5_PADATA_SAM_REDIRECT: return "PA-SAM-REDIRECT";
149 case KRB5_PADATA_GET_FROM_TYPED_DATA: return "PA-GET-FROM-TYPED-DATA";
150 case KRB5_PADATA_SAM_CHALLENGE_2: return "PA-SAM-CHALLENGE2";
151 case KRB5_PADATA_SAM_RESPONSE_2: return "PA-SAM-RESPONSE2";
152 case KRB5_PADATA_PAC_REQUEST: return "PA-PAC-REQUEST";
153 case KRB5_PADATA_FOR_USER: return "PA-FOR_USER";
154 case KRB5_PADATA_S4U_X509_USER: return "PA-FOR-X509-USER";
155 case KRB5_PADATA_AS_CHECKSUM: return "PA-AS-CHECKSUM";
156 case KRB5_PADATA_FX_COOKIE: return "PA-FX-COOKIE";
157 case KRB5_PADATA_FX_FAST: return "PA-FX-FAST";
158 case KRB5_PADATA_FX_ERROR: return "PA-FX-ERROR";
159 case KRB5_PADATA_ENCRYPTED_CHALLENGE: return "PA-ENCRYPTED-CHALLENGE";
160 case KRB5_PADATA_OTP_CHALLENGE: return "PA-OTP-CHALLENGE";
161 case KRB5_PADATA_OTP_REQUEST: return "PA-OTP-REQUEST";
162 case KRB5_PADATA_OTP_PIN_CHANGE: return "PA-OTP-PIN-CHANGE";
163 case KRB5_PADATA_PKINIT_KX: return "PA-PKINIT-KX";
164 case KRB5_ENCPADATA_REQ_ENC_PA_REP: return "PA-REQ-ENC-PA-REP";
165 case KRB5_PADATA_AS_FRESHNESS: return "PA_AS_FRESHNESS";
166 case KRB5_PADATA_SPAKE: return "PA-SPAKE";
167 case KRB5_PADATA_REDHAT_IDP_OAUTH2: return "PA-REDHAT-IDP-OAUTH2";
168 case KRB5_PADATA_REDHAT_PASSKEY: return "PA-REDHAT-PASSKEY";
169 default: return NULL;
170 }
171 }
172
173 static char *
trace_format(krb5_context context,const char * fmt,va_list ap)174 trace_format(krb5_context context, const char *fmt, va_list ap)
175 {
176 struct k5buf buf;
177 krb5_error_code kerr;
178 size_t len, i;
179 int err;
180 struct remote_address *ra;
181 const krb5_data *d;
182 krb5_data data;
183 char addrbuf[128], tmpbuf[200], *str;
184 const char *p;
185 krb5_const_principal princ;
186 const krb5_keyblock *keyblock;
187 krb5_key key;
188 const krb5_checksum *cksum;
189 krb5_pa_data **padata;
190 krb5_preauthtype pa_type;
191 const char *name;
192 krb5_ccache ccache;
193 krb5_keytab keytab;
194 krb5_creds *creds;
195 krb5_enctype *etypes, etype;
196
197 k5_buf_init_dynamic(&buf);
198 while (TRUE) {
199 /* Advance to the next word in braces. */
200 len = strcspn(fmt, "{");
201 k5_buf_add_len(&buf, fmt, len);
202 if (fmt[len] == '\0')
203 break;
204 fmt += len + 1;
205 len = strcspn(fmt, "}");
206 if (fmt[len] == '\0' || len > sizeof(tmpbuf) - 1)
207 break;
208 memcpy(tmpbuf, fmt, len);
209 tmpbuf[len] = '\0';
210 fmt += len + 1;
211
212 /* Process the format word. */
213 if (strcmp(tmpbuf, "int") == 0) {
214 k5_buf_add_fmt(&buf, "%d", va_arg(ap, int));
215 } else if (strcmp(tmpbuf, "long") == 0) {
216 k5_buf_add_fmt(&buf, "%ld", va_arg(ap, long));
217 } else if (strcmp(tmpbuf, "str") == 0) {
218 p = va_arg(ap, const char *);
219 buf_add_printable(&buf, (p == NULL) ? "(null)" : p);
220 } else if (strcmp(tmpbuf, "lenstr") == 0) {
221 len = va_arg(ap, size_t);
222 p = va_arg(ap, const char *);
223 if (p == NULL && len != 0)
224 k5_buf_add(&buf, "(null)");
225 else if (p != NULL)
226 buf_add_printable_len(&buf, p, len);
227 } else if (strcmp(tmpbuf, "hexlenstr") == 0) {
228 len = va_arg(ap, size_t);
229 p = va_arg(ap, const char *);
230 if (p == NULL && len != 0)
231 k5_buf_add(&buf, "(null)");
232 else {
233 for (i = 0; i < len; i++)
234 k5_buf_add_fmt(&buf, "%02X", (unsigned char)p[i]);
235 }
236 } else if (strcmp(tmpbuf, "hashlenstr") == 0) {
237 len = va_arg(ap, size_t);
238 p = va_arg(ap, const char *);
239 if (p == NULL && len != 0)
240 k5_buf_add(&buf, "(null)");
241 else {
242 str = hash_bytes(context, p, len);
243 if (str != NULL)
244 k5_buf_add(&buf, str);
245 free(str);
246 }
247 } else if (strcmp(tmpbuf, "raddr") == 0) {
248 ra = va_arg(ap, struct remote_address *);
249 if (ra->transport == UDP)
250 k5_buf_add(&buf, "dgram");
251 else if (ra->transport == TCP)
252 k5_buf_add(&buf, "stream");
253 else if (ra->transport == HTTPS)
254 k5_buf_add(&buf, "https");
255 else if (ra->transport == UNIXSOCK)
256 k5_buf_add(&buf, "UNIX domain socket");
257 else
258 k5_buf_add_fmt(&buf, "transport%d", ra->transport);
259
260 k5_print_addr_port(ss2sa(&ra->saddr), addrbuf, sizeof(addrbuf));
261 k5_buf_add_fmt(&buf, " %s", addrbuf);
262 } else if (strcmp(tmpbuf, "data") == 0) {
263 d = va_arg(ap, krb5_data *);
264 if (d == NULL || (d->length != 0 && d->data == NULL))
265 k5_buf_add(&buf, "(null)");
266 else
267 buf_add_printable_len(&buf, d->data, d->length);
268 } else if (strcmp(tmpbuf, "hexdata") == 0) {
269 d = va_arg(ap, krb5_data *);
270 if (d == NULL)
271 k5_buf_add(&buf, "(null)");
272 else
273 subfmt(context, &buf, "{hexlenstr}", d->length, d->data);
274 } else if (strcmp(tmpbuf, "errno") == 0) {
275 err = va_arg(ap, int);
276 k5_buf_add_fmt(&buf, "%d", err);
277 if (strerror_r(err, tmpbuf, sizeof(tmpbuf)) == 0)
278 k5_buf_add_fmt(&buf, "/%s", tmpbuf);
279 } else if (strcmp(tmpbuf, "kerr") == 0) {
280 kerr = va_arg(ap, krb5_error_code);
281 p = krb5_get_error_message(context, kerr);
282 k5_buf_add_fmt(&buf, "%ld/%s", (long)kerr, kerr ? p : "Success");
283 krb5_free_error_message(context, p);
284 } else if (strcmp(tmpbuf, "keyblock") == 0) {
285 keyblock = va_arg(ap, const krb5_keyblock *);
286 if (keyblock == NULL)
287 k5_buf_add(&buf, "(null)");
288 else {
289 subfmt(context, &buf, "{etype}/{hashlenstr}",
290 keyblock->enctype, keyblock->length,
291 keyblock->contents);
292 }
293 } else if (strcmp(tmpbuf, "key") == 0) {
294 key = va_arg(ap, krb5_key);
295 if (key == NULL)
296 k5_buf_add(&buf, "(null)");
297 else
298 subfmt(context, &buf, "{keyblock}", &key->keyblock);
299 } else if (strcmp(tmpbuf, "cksum") == 0) {
300 cksum = va_arg(ap, const krb5_checksum *);
301 data = make_data(cksum->contents, cksum->length);
302 subfmt(context, &buf, "{int}/{hexdata}",
303 (int) cksum->checksum_type, &data);
304 } else if (strcmp(tmpbuf, "princ") == 0) {
305 princ = va_arg(ap, krb5_principal);
306 if (krb5_unparse_name(context, princ, &str) == 0) {
307 k5_buf_add(&buf, str);
308 krb5_free_unparsed_name(context, str);
309 }
310 } else if (strcmp(tmpbuf, "ptype") == 0) {
311 p = principal_type_string(va_arg(ap, krb5_int32));
312 k5_buf_add(&buf, p);
313 } else if (strcmp(tmpbuf, "patypes") == 0) {
314 padata = va_arg(ap, krb5_pa_data **);
315 if (padata == NULL || *padata == NULL)
316 k5_buf_add(&buf, "(empty)");
317 for (; padata != NULL && *padata != NULL; padata++) {
318 pa_type = (*padata)->pa_type;
319 name = padata_type_string(pa_type);
320 if (name != NULL)
321 k5_buf_add_fmt(&buf, "%s (%d)", name, (int)pa_type);
322 else
323 k5_buf_add_fmt(&buf, "%d", (int)pa_type);
324
325 if (*(padata + 1) != NULL)
326 k5_buf_add(&buf, ", ");
327 }
328 } else if (strcmp(tmpbuf, "patype") == 0) {
329 pa_type = va_arg(ap, krb5_preauthtype);
330 name = padata_type_string(pa_type);
331 if (name != NULL)
332 k5_buf_add_fmt(&buf, "%s (%d)", name, (int)pa_type);
333 else
334 k5_buf_add_fmt(&buf, "%d", (int)pa_type);
335 } else if (strcmp(tmpbuf, "etype") == 0) {
336 etype = va_arg(ap, krb5_enctype);
337 if (krb5_enctype_to_name(etype, TRUE, tmpbuf, sizeof(tmpbuf)) == 0)
338 k5_buf_add(&buf, tmpbuf);
339 else
340 k5_buf_add_fmt(&buf, "%d", (int)etype);
341 } else if (strcmp(tmpbuf, "etypes") == 0) {
342 etypes = va_arg(ap, krb5_enctype *);
343 if (etypes == NULL || *etypes == 0)
344 k5_buf_add(&buf, "(empty)");
345 for (; etypes != NULL && *etypes != 0; etypes++) {
346 subfmt(context, &buf, "{etype}", *etypes);
347 if (*(etypes + 1) != 0)
348 k5_buf_add(&buf, ", ");
349 }
350 } else if (strcmp(tmpbuf, "ccache") == 0) {
351 ccache = va_arg(ap, krb5_ccache);
352 k5_buf_add(&buf, krb5_cc_get_type(context, ccache));
353 k5_buf_add(&buf, ":");
354 k5_buf_add(&buf, krb5_cc_get_name(context, ccache));
355 } else if (strcmp(tmpbuf, "keytab") == 0) {
356 keytab = va_arg(ap, krb5_keytab);
357 if (krb5_kt_get_name(context, keytab, tmpbuf, sizeof(tmpbuf)) == 0)
358 k5_buf_add(&buf, tmpbuf);
359 } else if (strcmp(tmpbuf, "creds") == 0) {
360 creds = va_arg(ap, krb5_creds *);
361 subfmt(context, &buf, "{princ} -> {princ}",
362 creds->client, creds->server);
363 }
364 }
365 return k5_buf_cstring(&buf);
366 }
367
368 /* Allows trace_format formatters to be represented in terms of other
369 * formatters. */
370 static void
subfmt(krb5_context context,struct k5buf * buf,const char * fmt,...)371 subfmt(krb5_context context, struct k5buf *buf, const char *fmt, ...)
372 {
373 va_list ap;
374 char *str;
375
376 va_start(ap, fmt);
377 str = trace_format(context, fmt, ap);
378 if (str != NULL)
379 k5_buf_add(buf, str);
380 free(str);
381 va_end(ap);
382 }
383
384 void
k5_init_trace(krb5_context context)385 k5_init_trace(krb5_context context)
386 {
387 const char *filename;
388
389 filename = secure_getenv("KRB5_TRACE");
390 if (filename)
391 (void) krb5_set_trace_filename(context, filename);
392 }
393
394 void
krb5int_trace(krb5_context context,const char * fmt,...)395 krb5int_trace(krb5_context context, const char *fmt, ...)
396 {
397 va_list ap;
398 krb5_trace_info info;
399 char *str = NULL, *msg = NULL;
400 krb5_timestamp sec;
401 krb5_int32 usec;
402
403 if (context == NULL || context->trace_callback == NULL)
404 return;
405 va_start(ap, fmt);
406 str = trace_format(context, fmt, ap);
407 if (str == NULL)
408 goto cleanup;
409 if (k5_us_timeofday(&sec, &usec) != 0)
410 goto cleanup;
411 if (asprintf(&msg, "[%d] %u.%06d: %s\n", (int)getpid(),
412 (unsigned int)sec, (int)usec, str) < 0)
413 goto cleanup;
414 info.message = msg;
415 context->trace_callback(context, &info, context->trace_callback_data);
416 cleanup:
417 free(str);
418 free(msg);
419 va_end(ap);
420 }
421
422 krb5_error_code KRB5_CALLCONV
krb5_set_trace_callback(krb5_context context,krb5_trace_callback fn,void * cb_data)423 krb5_set_trace_callback(krb5_context context, krb5_trace_callback fn,
424 void *cb_data)
425 {
426 /* Allow the old callback to destroy its data if necessary. */
427 if (context->trace_callback != NULL)
428 context->trace_callback(context, NULL, context->trace_callback_data);
429 context->trace_callback = fn;
430 context->trace_callback_data = cb_data;
431 return 0;
432 }
433
434 static void KRB5_CALLCONV
file_trace_cb(krb5_context context,const krb5_trace_info * info,void * data)435 file_trace_cb(krb5_context context, const krb5_trace_info *info, void *data)
436 {
437 int *fd = data;
438
439 if (info == NULL) {
440 /* Null info means destroy the callback data. */
441 close(*fd);
442 free(fd);
443 return;
444 }
445
446 (void) write(*fd, info->message, strlen(info->message));
447 }
448
449 krb5_error_code KRB5_CALLCONV
krb5_set_trace_filename(krb5_context context,const char * filename)450 krb5_set_trace_filename(krb5_context context, const char *filename)
451 {
452 int *fd;
453
454 /* Create callback data containing a file descriptor. */
455 fd = malloc(sizeof(*fd));
456 if (fd == NULL)
457 return ENOMEM;
458 *fd = open(filename, O_WRONLY|O_CREAT|O_APPEND, 0600);
459 if (*fd == -1) {
460 free(fd);
461 return errno;
462 }
463
464 return krb5_set_trace_callback(context, file_trace_cb, fd);
465 }
466
467 #else /* DISABLE_TRACING */
468
469 krb5_error_code KRB5_CALLCONV
krb5_set_trace_callback(krb5_context context,krb5_trace_callback fn,void * cb_data)470 krb5_set_trace_callback(krb5_context context, krb5_trace_callback fn,
471 void *cb_data)
472 {
473 if (fn == NULL)
474 return 0;
475 return KRB5_TRACE_NOSUPP;
476 }
477
478 krb5_error_code KRB5_CALLCONV
krb5_set_trace_filename(krb5_context context,const char * filename)479 krb5_set_trace_filename(krb5_context context, const char *filename)
480 {
481 return KRB5_TRACE_NOSUPP;
482 }
483
484 #endif /* DISABLE_TRACING */
485