xref: /openssl/crypto/trace.c (revision 3eed43f8)
1 /*
2  * Copyright 2019-2023 The OpenSSL Project Authors. All Rights Reserved.
3  *
4  * Licensed under the Apache License 2.0 (the "License").  You may not use
5  * this file except in compliance with the License.  You can obtain a copy
6  * in the file LICENSE in the source distribution or at
7  * https://www.openssl.org/source/license.html
8  */
9 
10 #include <stdio.h>
11 #include <string.h>
12 
13 #include "internal/thread_once.h"
14 #include <openssl/bio.h>
15 #include <openssl/crypto.h>
16 #include <openssl/trace.h>
17 #include "internal/bio.h"
18 #include "internal/nelem.h"
19 #include "internal/refcount.h"
20 #include "crypto/cryptlib.h"
21 #include "crypto/ctype.h"
22 
23 #ifndef OPENSSL_NO_TRACE
24 
25 static CRYPTO_RWLOCK *trace_lock = NULL;
26 
27 static const BIO  *current_channel = NULL;
28 
29 /*-
30  * INTERNAL TRACE CHANNEL IMPLEMENTATION
31  *
32  * For our own flexibility, all trace categories are associated with a
33  * BIO sink object, also called the trace channel. Instead of a BIO object,
34  * the application can also provide a callback function, in which case an
35  * internal trace channel is attached, which simply calls the registered
36  * callback function.
37  */
38 static int trace_write(BIO *b, const char *buf,
39                                size_t num, size_t *written);
40 static int trace_puts(BIO *b, const char *str);
41 static long trace_ctrl(BIO *channel, int cmd, long argl, void *argp);
42 static int trace_free(BIO *b);
43 
44 static const BIO_METHOD trace_method = {
45     BIO_TYPE_SOURCE_SINK,
46     "trace",
47     trace_write,
48     NULL,                        /* old write */
49     NULL,                        /* read_ex */
50     NULL,                        /* read */
51     trace_puts,
52     NULL,                        /* gets */
53     trace_ctrl,                  /* ctrl */
54     NULL,                        /* create */
55     trace_free,                  /* free */
56     NULL,                        /* callback_ctrl */
57 };
58 
59 struct trace_data_st {
60     OSSL_trace_cb callback;
61     int category;
62     void *data;
63 };
64 
trace_write(BIO * channel,const char * buf,size_t num,size_t * written)65 static int trace_write(BIO *channel,
66                        const char *buf, size_t num, size_t *written)
67 {
68     struct trace_data_st *ctx = BIO_get_data(channel);
69     size_t cnt = ctx->callback(buf, num, ctx->category, OSSL_TRACE_CTRL_WRITE,
70                                ctx->data);
71 
72     *written = cnt;
73     return cnt != 0;
74 }
75 
trace_puts(BIO * channel,const char * str)76 static int trace_puts(BIO *channel, const char *str)
77 {
78     size_t written;
79 
80     if (trace_write(channel, str, strlen(str), &written))
81         return (int)written;
82 
83     return EOF;
84 }
85 
trace_ctrl(BIO * channel,int cmd,long argl,void * argp)86 static long trace_ctrl(BIO *channel, int cmd, long argl, void *argp)
87 {
88     struct trace_data_st *ctx = BIO_get_data(channel);
89 
90     switch (cmd) {
91     case OSSL_TRACE_CTRL_BEGIN:
92     case OSSL_TRACE_CTRL_END:
93         /* We know that the callback is likely to return 0 here */
94         ctx->callback("", 0, ctx->category, cmd, ctx->data);
95         return 1;
96     default:
97         break;
98     }
99     return -2;                   /* Unsupported */
100 }
101 
trace_free(BIO * channel)102 static int trace_free(BIO *channel)
103 {
104     if (channel == NULL)
105         return 0;
106     OPENSSL_free(BIO_get_data(channel));
107     return 1;
108 }
109 #endif
110 
111 /*-
112  * TRACE
113  */
114 
115 /* Helper struct and macro to get name string to number mapping */
116 struct trace_category_st {
117     const char * const name;
118     const int num;
119 };
120 #define TRACE_CATEGORY_(name)       { #name, OSSL_TRACE_CATEGORY_##name }
121 
122 static const struct trace_category_st
123     trace_categories[OSSL_TRACE_CATEGORY_NUM] = {
124     TRACE_CATEGORY_(ALL),
125     TRACE_CATEGORY_(TRACE),
126     TRACE_CATEGORY_(INIT),
127     TRACE_CATEGORY_(TLS),
128     TRACE_CATEGORY_(TLS_CIPHER),
129     TRACE_CATEGORY_(CONF),
130     TRACE_CATEGORY_(ENGINE_TABLE),
131     TRACE_CATEGORY_(ENGINE_REF_COUNT),
132     TRACE_CATEGORY_(PKCS5V2),
133     TRACE_CATEGORY_(PKCS12_KEYGEN),
134     TRACE_CATEGORY_(PKCS12_DECRYPT),
135     TRACE_CATEGORY_(X509V3_POLICY),
136     TRACE_CATEGORY_(BN_CTX),
137     TRACE_CATEGORY_(CMP),
138     TRACE_CATEGORY_(STORE),
139     TRACE_CATEGORY_(DECODER),
140     TRACE_CATEGORY_(ENCODER),
141     TRACE_CATEGORY_(REF_COUNT),
142     TRACE_CATEGORY_(HTTP),
143     TRACE_CATEGORY_(PROVIDER),
144     TRACE_CATEGORY_(QUERY),
145 }; /* KEEP THIS LIST IN SYNC with #define OSSL_TRACE_CATEGORY_... in trace.h */
146 
OSSL_trace_get_category_name(int num)147 const char *OSSL_trace_get_category_name(int num)
148 {
149     if (num < 0 || (size_t)num >= OSSL_NELEM(trace_categories))
150         return NULL;
151     /*
152      * Partial check that OSSL_TRACE_CATEGORY_... macros
153      * are synced with trace_categories array
154      */
155     if (!ossl_assert(trace_categories[num].name != NULL)
156         || !ossl_assert(trace_categories[num].num == num))
157         return NULL;
158     return trace_categories[num].name;
159 }
160 
OSSL_trace_get_category_num(const char * name)161 int OSSL_trace_get_category_num(const char *name)
162 {
163     size_t i;
164 
165     if (name == NULL)
166         return -1;
167 
168     for (i = 0; i < OSSL_NELEM(trace_categories); i++)
169         if (OPENSSL_strcasecmp(name, trace_categories[i].name) == 0)
170             return trace_categories[i].num;
171 
172     return -1; /* not found */
173 }
174 
175 #ifndef OPENSSL_NO_TRACE
176 
177 /* We use one trace channel for each trace category */
178 static struct {
179     enum { SIMPLE_CHANNEL, CALLBACK_CHANNEL } type;
180     BIO *bio;
181     char *prefix;
182     char *suffix;
183 } trace_channels[OSSL_TRACE_CATEGORY_NUM] = {
184     { 0, NULL, NULL, NULL },
185 };
186 
187 #endif
188 
189 #ifndef OPENSSL_NO_TRACE
190 
191 enum {
192     CHANNEL,
193     PREFIX,
194     SUFFIX
195 };
196 
trace_attach_cb(int category,int type,const void * data)197 static int trace_attach_cb(int category, int type, const void *data)
198 {
199     switch (type) {
200     case CHANNEL:
201         OSSL_TRACE2(TRACE, "Attach channel %p to category '%s'\n",
202                     data, trace_categories[category].name);
203         break;
204     case PREFIX:
205         OSSL_TRACE2(TRACE, "Attach prefix \"%s\" to category '%s'\n",
206                     (const char *)data, trace_categories[category].name);
207         break;
208     case SUFFIX:
209         OSSL_TRACE2(TRACE, "Attach suffix \"%s\" to category '%s'\n",
210                     (const char *)data, trace_categories[category].name);
211         break;
212     default:                     /* No clue */
213         break;
214     }
215     return 1;
216 }
217 
trace_detach_cb(int category,int type,const void * data)218 static int trace_detach_cb(int category, int type, const void *data)
219 {
220     switch (type) {
221     case CHANNEL:
222         OSSL_TRACE2(TRACE, "Detach channel %p from category '%s'\n",
223                     data, trace_categories[category].name);
224         break;
225     case PREFIX:
226         OSSL_TRACE2(TRACE, "Detach prefix \"%s\" from category '%s'\n",
227                     (const char *)data, trace_categories[category].name);
228         break;
229     case SUFFIX:
230         OSSL_TRACE2(TRACE, "Detach suffix \"%s\" from category '%s'\n",
231                     (const char *)data, trace_categories[category].name);
232         break;
233     default:                     /* No clue */
234         break;
235     }
236     return 1;
237 }
238 
239 static int do_ossl_trace_init(void);
240 static CRYPTO_ONCE trace_inited = CRYPTO_ONCE_STATIC_INIT;
DEFINE_RUN_ONCE_STATIC(ossl_trace_init)241 DEFINE_RUN_ONCE_STATIC(ossl_trace_init)
242 {
243     return do_ossl_trace_init();
244 }
245 
set_trace_data(int category,int type,BIO ** channel,const char ** prefix,const char ** suffix,int (* attach_cb)(int,int,const void *),int (* detach_cb)(int,int,const void *))246 static int set_trace_data(int category, int type, BIO **channel,
247                           const char **prefix, const char **suffix,
248                           int (*attach_cb)(int, int, const void *),
249                           int (*detach_cb)(int, int, const void *))
250 {
251     BIO *curr_channel = NULL;
252     char *curr_prefix = NULL;
253     char *curr_suffix = NULL;
254 
255     /* Ensure do_ossl_trace_init() is called once */
256     if (!RUN_ONCE(&trace_inited, ossl_trace_init))
257         return 0;
258 
259     curr_channel = trace_channels[category].bio;
260     curr_prefix = trace_channels[category].prefix;
261     curr_suffix = trace_channels[category].suffix;
262 
263     /* Make sure to run the detach callback first on all data */
264     if (prefix != NULL && curr_prefix != NULL) {
265         detach_cb(category, PREFIX, curr_prefix);
266     }
267 
268     if (suffix != NULL && curr_suffix != NULL) {
269         detach_cb(category, SUFFIX, curr_suffix);
270     }
271 
272     if (channel != NULL && curr_channel != NULL) {
273         detach_cb(category, CHANNEL, curr_channel);
274     }
275 
276     /* After detach callbacks are done, clear data where appropriate */
277     if (prefix != NULL && curr_prefix != NULL) {
278         OPENSSL_free(curr_prefix);
279         trace_channels[category].prefix = NULL;
280     }
281 
282     if (suffix != NULL && curr_suffix != NULL) {
283         OPENSSL_free(curr_suffix);
284         trace_channels[category].suffix = NULL;
285     }
286 
287     if (channel != NULL && curr_channel != NULL) {
288         BIO_free(curr_channel);
289         trace_channels[category].type = 0;
290         trace_channels[category].bio = NULL;
291     }
292 
293     /* Before running callbacks are done, set new data where appropriate */
294     if (prefix != NULL && *prefix != NULL) {
295         if ((curr_prefix = OPENSSL_strdup(*prefix)) == NULL)
296             return 0;
297         trace_channels[category].prefix = curr_prefix;
298     }
299 
300     if (suffix != NULL && *suffix != NULL) {
301         if ((curr_suffix = OPENSSL_strdup(*suffix)) == NULL)
302             return 0;
303         trace_channels[category].suffix = curr_suffix;
304     }
305 
306     if (channel != NULL && *channel != NULL) {
307         trace_channels[category].type = type;
308         trace_channels[category].bio = *channel;
309         /*
310          * This must not be done before setting prefix/suffix,
311          * as those may fail, and then the caller is mislead to free *channel.
312          */
313     }
314 
315     /* Finally, run the attach callback on the new data */
316     if (channel != NULL && *channel != NULL) {
317         attach_cb(category, CHANNEL, *channel);
318     }
319 
320     if (prefix != NULL && *prefix != NULL) {
321         attach_cb(category, PREFIX, *prefix);
322     }
323 
324     if (suffix != NULL && *suffix != NULL) {
325         attach_cb(category, SUFFIX, *suffix);
326     }
327 
328     return 1;
329 }
330 
do_ossl_trace_init(void)331 static int do_ossl_trace_init(void)
332 {
333     trace_lock = CRYPTO_THREAD_lock_new();
334     return trace_lock != NULL;
335 }
336 
337 #endif
338 
ossl_trace_cleanup(void)339 void ossl_trace_cleanup(void)
340 {
341 #ifndef OPENSSL_NO_TRACE
342     int category;
343     BIO *channel = NULL;
344     const char *prefix = NULL;
345     const char *suffix = NULL;
346 
347     for (category = 0; category < OSSL_TRACE_CATEGORY_NUM; category++) {
348         /* We force the TRACE category to be treated last */
349         if (category == OSSL_TRACE_CATEGORY_TRACE)
350             continue;
351         set_trace_data(category, 0, &channel, &prefix, &suffix,
352                        trace_attach_cb, trace_detach_cb);
353     }
354     set_trace_data(OSSL_TRACE_CATEGORY_TRACE, 0, &channel,
355                    &prefix, &suffix,
356                    trace_attach_cb, trace_detach_cb);
357     CRYPTO_THREAD_lock_free(trace_lock);
358 #endif
359 }
360 
OSSL_trace_set_channel(int category,BIO * channel)361 int OSSL_trace_set_channel(int category, BIO *channel)
362 {
363 #ifndef OPENSSL_NO_TRACE
364     if (category >= 0 && category < OSSL_TRACE_CATEGORY_NUM)
365         return set_trace_data(category, SIMPLE_CHANNEL, &channel, NULL, NULL,
366                               trace_attach_cb, trace_detach_cb);
367 #endif
368     return 0;
369 }
370 
371 #ifndef OPENSSL_NO_TRACE
trace_attach_w_callback_cb(int category,int type,const void * data)372 static int trace_attach_w_callback_cb(int category, int type, const void *data)
373 {
374     switch (type) {
375     case CHANNEL:
376         OSSL_TRACE2(TRACE,
377                     "Attach channel %p to category '%s' (with callback)\n",
378                     data, trace_categories[category].name);
379         break;
380     case PREFIX:
381         OSSL_TRACE2(TRACE, "Attach prefix \"%s\" to category '%s'\n",
382                     (const char *)data, trace_categories[category].name);
383         break;
384     case SUFFIX:
385         OSSL_TRACE2(TRACE, "Attach suffix \"%s\" to category '%s'\n",
386                     (const char *)data, trace_categories[category].name);
387         break;
388     default:                     /* No clue */
389         break;
390     }
391     return 1;
392 }
393 #endif
394 
OSSL_trace_set_callback(int category,OSSL_trace_cb callback,void * data)395 int OSSL_trace_set_callback(int category, OSSL_trace_cb callback, void *data)
396 {
397 #ifndef OPENSSL_NO_TRACE
398     BIO *channel = NULL;
399     struct trace_data_st *trace_data = NULL;
400 
401     if (category < 0 || category >= OSSL_TRACE_CATEGORY_NUM)
402         return 0;
403 
404     if (callback != NULL) {
405         if ((channel = BIO_new(&trace_method)) == NULL
406             || (trace_data =
407                 OPENSSL_zalloc(sizeof(struct trace_data_st))) == NULL)
408             goto err;
409 
410         trace_data->callback = callback;
411         trace_data->category = category;
412         trace_data->data = data;
413 
414         BIO_set_data(channel, trace_data);
415     }
416 
417     if (!set_trace_data(category, CALLBACK_CHANNEL, &channel, NULL, NULL,
418                         trace_attach_w_callback_cb, trace_detach_cb))
419         goto err;
420 
421     return 1;
422 
423  err:
424     BIO_free(channel);
425     OPENSSL_free(trace_data);
426 #endif
427 
428     return 0;
429 }
430 
OSSL_trace_set_prefix(int category,const char * prefix)431 int OSSL_trace_set_prefix(int category, const char *prefix)
432 {
433 #ifndef OPENSSL_NO_TRACE
434     if (category >= 0 && category < OSSL_TRACE_CATEGORY_NUM)
435         return set_trace_data(category, 0, NULL, &prefix, NULL,
436                               trace_attach_cb, trace_detach_cb);
437 #endif
438     return 0;
439 }
440 
OSSL_trace_set_suffix(int category,const char * suffix)441 int OSSL_trace_set_suffix(int category, const char *suffix)
442 {
443 #ifndef OPENSSL_NO_TRACE
444     if (category >= 0 && category < OSSL_TRACE_CATEGORY_NUM)
445         return set_trace_data(category, 0, NULL, NULL, &suffix,
446                               trace_attach_cb, trace_detach_cb);
447 #endif
448     return 0;
449 }
450 
451 #ifndef OPENSSL_NO_TRACE
ossl_trace_get_category(int category)452 static int ossl_trace_get_category(int category)
453 {
454     if (category < 0 || category >= OSSL_TRACE_CATEGORY_NUM)
455         return -1;
456     if (trace_channels[category].bio != NULL)
457         return category;
458     return OSSL_TRACE_CATEGORY_ALL;
459 }
460 #endif
461 
OSSL_trace_enabled(int category)462 int OSSL_trace_enabled(int category)
463 {
464     int ret = 0;
465 #ifndef OPENSSL_NO_TRACE
466     category = ossl_trace_get_category(category);
467     if (category >= 0)
468         ret = trace_channels[category].bio != NULL;
469 #endif
470     return ret;
471 }
472 
OSSL_trace_begin(int category)473 BIO *OSSL_trace_begin(int category)
474 {
475     BIO *channel = NULL;
476 #ifndef OPENSSL_NO_TRACE
477     char *prefix = NULL;
478 
479     category = ossl_trace_get_category(category);
480     if (category < 0 || !OSSL_trace_enabled(category))
481         return NULL;
482 
483     channel = trace_channels[category].bio;
484     prefix = trace_channels[category].prefix;
485 
486     if (channel != NULL) {
487         if (!CRYPTO_THREAD_write_lock(trace_lock))
488             return NULL;
489         current_channel = channel;
490         switch (trace_channels[category].type) {
491         case SIMPLE_CHANNEL:
492             if (prefix != NULL) {
493                 (void)BIO_puts(channel, prefix);
494                 (void)BIO_puts(channel, "\n");
495             }
496             break;
497         case CALLBACK_CHANNEL:
498             (void)BIO_ctrl(channel, OSSL_TRACE_CTRL_BEGIN,
499                            prefix == NULL ? 0 : strlen(prefix), prefix);
500             break;
501         }
502     }
503 #endif
504     return channel;
505 }
506 
OSSL_trace_end(int category,BIO * channel)507 void OSSL_trace_end(int category, BIO *channel)
508 {
509 #ifndef OPENSSL_NO_TRACE
510     char *suffix = NULL;
511 
512     category = ossl_trace_get_category(category);
513     if (category < 0)
514         return;
515     suffix = trace_channels[category].suffix;
516     if (channel != NULL
517         && ossl_assert(channel == current_channel)) {
518         (void)BIO_flush(channel);
519         switch (trace_channels[category].type) {
520         case SIMPLE_CHANNEL:
521             if (suffix != NULL) {
522                 (void)BIO_puts(channel, suffix);
523                 (void)BIO_puts(channel, "\n");
524             }
525             break;
526         case CALLBACK_CHANNEL:
527             (void)BIO_ctrl(channel, OSSL_TRACE_CTRL_END,
528                            suffix == NULL ? 0 : strlen(suffix), suffix);
529             break;
530         }
531         current_channel = NULL;
532         CRYPTO_THREAD_unlock(trace_lock);
533     }
534 #endif
535 }
536 
OSSL_trace_string(BIO * out,int text,int full,const unsigned char * data,size_t size)537 int OSSL_trace_string(BIO *out, int text, int full,
538                       const unsigned char *data, size_t size)
539 {
540     unsigned char buf[OSSL_TRACE_STRING_MAX + 1];
541     int len, i;
542 
543     if (!full && size > OSSL_TRACE_STRING_MAX) {
544         BIO_printf(out, "[len %zu limited to %d]: ",
545                    size, OSSL_TRACE_STRING_MAX);
546         len = OSSL_TRACE_STRING_MAX;
547     } else {
548         len = (int)size;
549     }
550     if (!text) { /* mask control characters while preserving newlines */
551         for (i = 0; i < len; i++, data++)
552             buf[i] = (char)*data != '\n' && ossl_iscntrl((int)*data)
553                 ? ' ' : *data;
554         if (len == 0 || data[-1] != '\n')
555             buf[len++] = '\n';
556         data = buf;
557     }
558     return BIO_printf(out, "%.*s", len, data);
559 }
560