Add generic trace API
authorRichard Levitte <levitte@openssl.org>
Tue, 11 Dec 2018 22:58:29 +0000 (23:58 +0100)
committerRichard Levitte <levitte@openssl.org>
Wed, 6 Mar 2019 10:15:13 +0000 (11:15 +0100)
The idea is that the application shall be able to register output
channels or callbacks to print tracing output as it sees fit.

OpenSSL internals, on the other hand, want to print thoses texts using
normal printing routines, such as BIO_printf() or BIO_dump() through
well defined BIOs.

When the application registers callbacks, the tracing functionality
sets up an internal BIO that simply forwards received text to the
appropriate application provided callback.

Co-authored-by: Dr. Matthias St. Pierre <Matthias.St.Pierre@ncp-e.com>
Reviewed-by: Paul Dale <paul.dale@oracle.com>
(Merged from https://github.com/openssl/openssl/pull/8198)

crypto/build.info
crypto/include/internal/cryptlib_int.h
crypto/trace.c [new file with mode: 0644]
include/openssl/trace.h [new file with mode: 0644]
util/libcrypto.num

index 94ed06e..e3e9cee 100644 (file)
@@ -13,6 +13,7 @@ SOURCE[../libcrypto]=\
         ebcdic.c uid.c o_time.c o_str.c o_dir.c o_fopen.c ctype.c \
         threads_pthread.c threads_win.c threads_none.c getenv.c \
         o_init.c o_fips.c mem_sec.c init.c context.c sparse_array.c \
+        trace.c \
         {- $target{cpuid_asm_src} -} {- $target{uplink_aux_src} -}
 
 DEPEND[cversion.o]=buildinf.h
index 618dadb..422ef01 100644 (file)
@@ -32,4 +32,6 @@ int ossl_init_thread_start(uint64_t opts);
 # define OPENSSL_INIT_THREAD_ERR_STATE       0x02
 # define OPENSSL_INIT_THREAD_RAND            0x04
 
+int ossl_trace_init(void);
+void ossl_trace_cleanup(void);
 void ossl_malloc_setup_failures(void);
diff --git a/crypto/trace.c b/crypto/trace.c
new file mode 100644 (file)
index 0000000..fba33e9
--- /dev/null
@@ -0,0 +1,342 @@
+/*
+ * Copyright 2019 The OpenSSL Project Authors. All Rights Reserved.
+ *
+ * Licensed under the Apache License 2.0 (the "License").  You may not use
+ * this file except in compliance with the License.  You can obtain a copy
+ * in the file LICENSE in the source distribution or at
+ * https://www.openssl.org/source/license.html
+ */
+
+#include <stdio.h>
+#include <string.h>
+
+#include <openssl/bio.h>
+#include <openssl/crypto.h>
+#include <openssl/trace.h>
+#include "internal/bio.h"
+#include "internal/nelem.h"
+#include "internal/cryptlib_int.h"
+
+#include "e_os.h"                /* strcasecmp for Windows */
+
+static CRYPTO_RWLOCK *trace_lock = NULL;
+
+static const BIO  *current_channel = NULL;
+
+/*-
+ * INTERNAL TRACE CHANNEL IMPLEMENTATION
+ *
+ * For our own flexibility, all trace categories are associated with a
+ * BIO sink object, also called the trace channel. Instead of a BIO object,
+ * the application can also provide a callback function, in which case an
+ * internal trace channel is attached, which simply calls the registered
+ * callback function.
+ */
+static int trace_write(BIO *b, const char *buf,
+                               size_t num, size_t *written);
+static int trace_puts(BIO *b, const char *str);
+static long trace_ctrl(BIO *channel, int cmd, long argl, void *argp);
+static int trace_free(BIO *b);
+
+static const BIO_METHOD trace_method = {
+    BIO_TYPE_SOURCE_SINK,
+    "trace",
+    trace_write,
+    NULL,                        /* old write */
+    NULL,                        /* read_ex */
+    NULL,                        /* read */
+    trace_puts,
+    NULL,                        /* gets */
+    trace_ctrl,                  /* ctrl */
+    NULL,                        /* create */
+    trace_free,                  /* free */
+    NULL,                        /* callback_ctrl */
+};
+
+struct trace_data_st {
+    OSSL_trace_cb callback;
+    int category;
+    void *data;
+};
+
+static int trace_write(BIO *channel,
+                       const char *buf, size_t num, size_t *written)
+{
+    struct trace_data_st *ctx = BIO_get_data(channel);
+    size_t cnt = ctx->callback(buf, num, ctx->category, OSSL_TRACE_CTRL_DURING,
+                               ctx->data);
+
+    *written = cnt;
+    return cnt != 0;
+}
+
+static int trace_puts(BIO *channel, const char *str)
+{
+    size_t written;
+
+    if (trace_write(channel, str, strlen(str), &written))
+        return (int)written;
+
+    return EOF;
+}
+
+static long trace_ctrl(BIO *channel, int cmd, long argl, void *argp)
+{
+    struct trace_data_st *ctx = BIO_get_data(channel);
+
+    switch (cmd) {
+    case OSSL_TRACE_CTRL_BEGIN:
+    case OSSL_TRACE_CTRL_END:
+        /* We know that the callback is likely to return 0 here */
+        ctx->callback("", 0, ctx->category, cmd, ctx->data);
+        return 1;
+    default:
+        break;
+    }
+    return -2;                   /* Unsupported */
+}
+
+static int trace_free(BIO *channel)
+{
+    if (channel == NULL)
+        return 0;
+    OPENSSL_free(BIO_get_data(channel));
+    return 1;
+}
+
+/*-
+ * TRACE
+ */
+
+/* Helper struct and macro to get name string to number mapping */
+struct trace_category_st {
+    const char * const name;
+    const int num;
+};
+#define TRACE_CATEGORY_(name)       { #name, OSSL_TRACE_CATEGORY_##name }
+
+static const struct trace_category_st trace_categories[] = {
+    TRACE_CATEGORY_(ANY),
+};
+
+const char *OSSL_trace_get_category_name(int num)
+{
+    size_t i;
+
+    for (i = 0; i < OSSL_NELEM(trace_categories); i++)
+        if (trace_categories[i].num == num)
+            return trace_categories[i].name;
+    return NULL; /* not found */
+}
+
+int OSSL_trace_get_category_num(const char *name)
+{
+    size_t i;
+
+    for (i = 0; i < OSSL_NELEM(trace_categories); i++)
+        if (strcasecmp(name, trace_categories[i].name) == 0)
+            return trace_categories[i].num;
+    return -1; /* not found */
+}
+
+/* We use one trace channel for each trace category */
+static struct {
+    enum { t_channel, t_callback } type;
+    BIO *bio;
+    char *prefix;
+    char *suffix;
+} trace_channels[OSSL_TRACE_CATEGORY_NUM] = {
+    { 0, NULL, NULL, NULL },
+};
+
+int ossl_trace_init(void)
+{
+    trace_lock = CRYPTO_THREAD_lock_new();
+    if (trace_lock == NULL)
+        return 0;
+    return 1;
+}
+
+void ossl_trace_cleanup(void)
+{
+    int category;
+
+    for (category = 0; category < OSSL_TRACE_CATEGORY_NUM; category++)
+        OSSL_trace_set_channel(category, NULL);
+    CRYPTO_THREAD_lock_free(trace_lock);
+}
+
+int OSSL_trace_set_channel(int category, BIO *channel)
+{
+    BIO *prev_channel;
+
+    if (category < 0 || category >= OSSL_TRACE_CATEGORY_NUM)
+        return 0;
+
+    prev_channel = trace_channels[category].bio;
+
+    if (prev_channel != NULL) {
+        BIO_free(prev_channel);
+        trace_channels[category].bio = NULL;
+    }
+
+    if (channel == NULL)
+        return 1; /* done */
+
+    trace_channels[category].bio = channel;
+    trace_channels[category].type = t_channel;
+
+    return 1;
+}
+
+int OSSL_trace_set_callback(int category, OSSL_trace_cb callback, void *data)
+{
+    BIO *channel = trace_channels[category].bio;
+    struct trace_data_st *trace_data = NULL;
+
+    if (channel != NULL) {
+        BIO_free(channel);
+        trace_channels[category].bio = NULL;
+    }
+
+    if (callback == NULL)
+        return 1; /* done */
+
+    channel = BIO_new(&trace_method);
+    if (channel == NULL)
+        goto err;
+
+    trace_data = OPENSSL_zalloc(sizeof(struct trace_data_st));
+    if (trace_data == NULL)
+        goto err;
+
+    trace_data->callback = callback;
+    trace_data->category = category;
+    trace_data->data = data;
+
+    BIO_set_data(channel, trace_data);
+
+    trace_channels[category].bio = channel;
+    trace_channels[category].type = t_callback;
+
+    return 1;
+
+ err:
+    BIO_free(channel);
+    OPENSSL_free(trace_data);
+
+    return 0;
+}
+
+int OSSL_trace_set_prefix(int category, const char *prefix)
+{
+    char *curr_prefix = trace_channels[category].prefix;
+
+    if (curr_prefix != NULL) {
+        OPENSSL_free(curr_prefix);
+        trace_channels[category].prefix = NULL;
+    }
+
+    if (prefix == NULL)
+        return 1; /* done */
+
+    curr_prefix = OPENSSL_strdup(prefix);
+    if (curr_prefix == NULL)
+        return 0;
+
+    trace_channels[category].prefix = curr_prefix;
+
+    return 1;
+}
+
+int OSSL_trace_set_suffix(int category, const char *suffix)
+{
+    char *curr_suffix = trace_channels[category].suffix;
+
+    if (curr_suffix != NULL) {
+        OPENSSL_free(curr_suffix);
+        trace_channels[category].suffix = NULL;
+    }
+
+    if (suffix == NULL)
+        return 1; /* done */
+
+    curr_suffix = OPENSSL_strdup(suffix);
+    if (curr_suffix == NULL)
+        return 0;
+
+    trace_channels[category].suffix = curr_suffix;
+
+    return 1;
+}
+
+static int ossl_trace_get_category(int category)
+{
+    if (category < 0 || category >= OSSL_TRACE_CATEGORY_NUM)
+        return -1;
+    if (trace_channels[category].bio != NULL)
+        return category;
+    return OSSL_TRACE_CATEGORY_ANY;
+}
+
+int OSSL_trace_enabled(int category)
+{
+    int ret = 0;
+    category = ossl_trace_get_category(category);
+    ret = trace_channels[category].bio != NULL;
+    return ret;
+}
+
+BIO *OSSL_trace_begin(int category)
+{
+    BIO *channel = NULL;
+    char *prefix = NULL;
+
+    category = ossl_trace_get_category(category);
+    channel = trace_channels[category].bio;
+    prefix = trace_channels[category].prefix;
+
+    if (channel != NULL) {
+        CRYPTO_THREAD_write_lock(trace_lock);
+        current_channel = channel;
+        switch (trace_channels[category].type) {
+        case t_channel:
+            if (prefix != NULL) {
+                (void)BIO_puts(channel, prefix);
+                (void)BIO_puts(channel, "\n");
+            }
+            break;
+        case t_callback:
+            (void)BIO_ctrl(channel, OSSL_TRACE_CTRL_BEGIN,
+                           prefix == NULL ? 0 : strlen(prefix), prefix);
+            break;
+        }
+    }
+    return channel;
+}
+
+void OSSL_trace_end(int category, BIO * channel)
+{
+    char *suffix = NULL;
+
+    category = ossl_trace_get_category(category);
+    suffix = trace_channels[category].suffix;
+    if (channel != NULL
+        && ossl_assert(channel == current_channel)) {
+        (void)BIO_flush(channel);
+        switch (trace_channels[category].type) {
+        case t_channel:
+            if (suffix != NULL) {
+                (void)BIO_puts(channel, suffix);
+                (void)BIO_puts(channel, "\n");
+            }
+            break;
+        case t_callback:
+            (void)BIO_ctrl(channel, OSSL_TRACE_CTRL_END,
+                           suffix == NULL ? 0 : strlen(suffix), suffix);
+            break;
+        }
+        current_channel = NULL;
+        CRYPTO_THREAD_unlock(trace_lock);
+    }
+}
diff --git a/include/openssl/trace.h b/include/openssl/trace.h
new file mode 100644 (file)
index 0000000..59523c3
--- /dev/null
@@ -0,0 +1,255 @@
+/*
+ * Copyright 2019 The OpenSSL Project Authors. All Rights Reserved.
+ *
+ * Licensed under the Apache License 2.0 (the "License").  You may not use
+ * this file except in compliance with the License.  You can obtain a copy
+ * in the file LICENSE in the source distribution or at
+ * https://www.openssl.org/source/license.html
+ */
+
+#ifndef OSSL_TRACE_H
+# define OSSL_TRACE_H
+
+# include <stdarg.h>
+
+# include <openssl/bio.h>
+
+# ifdef  __cplusplus
+extern "C" {
+# endif
+
+/*
+ * TRACE CATEGORIES
+ */
+
+/*
+ * The trace messages of the OpenSSL libraries are organized into different
+ * categories. For every trace category, the application can register a separate
+ * tracer callback. When a callback is registered, a so called trace channel is
+ * created for this category. This channel consists essentially of an internal
+ * BIO which sends all trace output it receives to the registered application
+ * callback.
+ *
+ * The ANY category is used as a fallback category.
+ */
+# define OSSL_TRACE_CATEGORY_ANY                 0 /* The fallback */
+# define OSSL_TRACE_CATEGORY_NUM                 1
+
+/* Returns the trace category number for the given |name| */
+int OSSL_trace_get_category_num(const char *name);
+
+/* Returns the trace category name for the given |num| */
+const char *OSSL_trace_get_category_name(int num);
+
+/*
+ * TRACE CONSUMERS
+ */
+
+/*
+ * Enables tracing for the given |category| by providing a BIO sink
+ * as |channel|. If a null pointer is passed as |channel|, an existing
+ * trace channel is removed and tracing for the category is disabled.
+ *
+ * Returns 1 on success and 0 on failure
+ */
+int OSSL_trace_set_channel(int category, BIO* channel);
+
+/*
+ * Attach a prefix and a suffix to the given |category|, to be printed at the
+ * beginning and at the end of each trace output group, i.e. when
+ * OSSL_trace_begin() and OSSL_trace_end() are called.
+ * If a null pointer is passed as argument, the existing prefix or suffix is
+ * removed.
+ *
+ * They return 1 on success and 0 on failure
+ */
+int OSSL_trace_set_prefix(int category, const char *prefix);
+int OSSL_trace_set_suffix(int category, const char *suffix);
+
+/*
+ * OSSL_trace_cb is the type tracing callback provided by the application.
+ * It MUST return the number of bytes written, or 0 on error (in other words,
+ * it can never write zero bytes).
+ *
+ * The |buffer| will always contain text, which may consist of several lines.
+ * The |data| argument points to whatever data was provided by the application
+ * when registering the tracer function.
+ *
+ * The |category| number is given, as well as a |cmd| number, described below.
+ */
+typedef size_t (*OSSL_trace_cb)(const char *buffer, size_t count,
+                                int category, int cmd, void *data);
+/*
+ * Possible |cmd| numbers.
+ */
+# define OSSL_TRACE_CTRL_BEGIN  0
+# define OSSL_TRACE_CTRL_DURING 1
+# define OSSL_TRACE_CTRL_END    2
+
+/*
+ * Enables tracing for the given |category| by creating an internal
+ * trace channel which sends the output to the given |callback|.
+ * If a null pointer is passed as callback, an existing trace channel
+ * is removed and tracing for the category is disabled.
+ *
+ * NOTE: OSSL_trace_set_channel() and OSSL_trace_set_callback() are mutually
+ *       exclusive.
+ *
+ * Returns 1 on success and 0 on failure
+ */
+int OSSL_trace_set_callback(int category, OSSL_trace_cb callback, void *data);
+
+/*
+ * TRACE PRODUCERS
+ */
+
+/*
+ * Returns 1 if tracing for the specified category is enabled, otherwise 0
+ */
+int OSSL_trace_enabled(int category);
+
+/*
+ * Wrap a group of tracing output calls.  OSSL_trace_begin() locks tracing and
+ * returns the trace channel associated with the given category, or NULL if no
+ * channel is associated with the category.  OSSL_trace_end() unlocks tracing.
+ *
+ * Usage:
+ *
+ *    BIO *out;
+ *    if ((out = OSSL_trace_begin(category)) != NULL) {
+ *        ...
+ *        BIO_fprintf(out, ...);
+ *        ...
+ *        OSSL_trace_end(category, out);
+ *    }
+ *
+ * See also the convenience macros OSSL_TRACE_BEGIN and OSSL_TRACE_END below.
+ */
+BIO *OSSL_trace_begin(int category);
+void OSSL_trace_end(int category, BIO *channel);
+
+/*
+ * OSSL_TRACE* Convenience Macros
+ */
+
+/*
+ * When the tracing feature is disabled, these macros are defined to
+ * produce dead code, which a good compiler should eliminate.
+ */
+
+/*
+ * OSSL_TRACE_BEGIN, OSSL_TRACE_END - Define a Trace Group
+ *
+ * These two macros can be used to create a block which is executed only
+ * if the corresponding trace category is enabled. Inside this block, a
+ * local variable named |trc_out| is defined, which points to the channel
+ * associated with the given trace category.
+ *
+ * Usage: (using 'TLS' as an example category)
+ *
+ *     OSSL_TRACE_BEGIN(TLS) {
+ *
+ *         BIO_fprintf(trc_out, ... );
+ *
+ *     } OSSL_TRACE_END(TLS);
+ *
+ *
+ * This expands to the following code
+ *
+ *     do {
+ *         BIO *trc_out = OSSL_trace_begin(OSSL_TRACE_CATEGORY_TLS);
+ *         if (trc_out != NULL) {
+ *             ...
+ *             BIO_fprintf(trc_out, ...);
+ *         }
+ *         OSSL_trace_end(OSSL_TRACE_CATEGORY_TLS, trc_out);
+ *     } while (0);
+ *
+ * The use of the inner '{...}' group and the trailing ';' is enforced
+ * by the definition of the macros in order to make the code look as much
+ * like C code as possible.
+ *
+ * Before returning from inside the trace block, it is necessary to
+ * call OSSL_TRACE_CANCEL(category).
+ */
+
+# define OSSL_TRACE_BEGIN(category) \
+    do { \
+        BIO *trc_out = OSSL_trace_begin(OSSL_TRACE_CATEGORY_##category); \
+ \
+        if (trc_out != NULL)
+
+# define OSSL_TRACE_END(category) \
+        OSSL_trace_end(OSSL_TRACE_CATEGORY_##category, trc_out); \
+    } while (0)
+
+# define OSSL_TRACE_CANCEL(category) \
+        OSSL_trace_end(OSSL_TRACE_CATEGORY_##category, trc_out) \
+
+/*
+ * OSSL_TRACE_ENABLED() - Check whether tracing is enabled for |category|
+ *
+ * Usage:
+ *
+ *     if (OSSL_TRACE_ENABLED(TLS)) {
+ *         ...
+ *     }
+ */
+
+# define OSSL_TRACE_ENABLED(category) \
+    OSSL_trace_enabled(OSSL_TRACE_CATEGORY_##category)
+
+/*
+ * OSSL_TRACE*() - OneShot Trace Macros
+ *
+ * These macros are intended to produce a simple printf-style trace output.
+ * Unfortunately, C90 macros don't support variable arguments, so the
+ * "vararg" OSSL_TRACEV() macro has a rather weird usage pattern:
+ *
+ *    OSSL_TRACEV(category, (trc_out, "format string", ...args...));
+ *
+ * Where 'channel' is the literal symbol of this name, not a variable.
+ * For that reason, it is currently not intended to be used directly,
+ * but only as helper macro for the other oneshot trace macros
+ * OSSL_TRACE(), OSSL_TRACE1(), OSSL_TRACE2(), ...
+ *
+ * Usage:
+ *
+ *    OSSL_TRACE(INIT, "Hello world!\n");
+ *    OSSL_TRACE1(TLS, "The answer is %d\n", 42);
+ *    OSSL_TRACE2(TLS, "The ultimate question to answer %d is '%s'\n",
+ *                42, "What do you get when you multiply six by nine?");
+ */
+
+# define OSSL_TRACEV(category, args) \
+    OSSL_TRACE_BEGIN(category) \
+        BIO_printf args; \
+    OSSL_TRACE_END(category)
+
+# define OSSL_TRACE(category, text) \
+    OSSL_TRACEV(category, (trc_out, "%s", text))
+
+# define OSSL_TRACE1(category, format, arg1) \
+    OSSL_TRACEV(category, (trc_out, format, arg1))
+# define OSSL_TRACE2(category, format, arg1, arg2) \
+    OSSL_TRACEV(category, (trc_out, format, arg1, arg2))
+# define OSSL_TRACE3(category, format, arg1, arg2, arg3) \
+    OSSL_TRACEV(category, (trc_out, format, arg1, arg2, arg3))
+# define OSSL_TRACE4(category, format, arg1, arg2, arg3, arg4) \
+    OSSL_TRACEV(category, (trc_out, format, arg1, arg2, arg3, arg4))
+# define OSSL_TRACE5(category, format, arg1, arg2, arg3, arg4, arg5) \
+    OSSL_TRACEV(category, (trc_out, format, arg1, arg2, arg3, arg4, arg5))
+# define OSSL_TRACE6(category, format, arg1, arg2, arg3, arg4, arg5, arg6) \
+    OSSL_TRACEV(category, (trc_out, format, arg1, arg2, arg3, arg4, arg5, arg6))
+# define OSSL_TRACE7(category, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7) \
+    OSSL_TRACEV(category, (trc_out, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7))
+# define OSSL_TRACE8(category, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8) \
+    OSSL_TRACEV(category, (trc_out, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8))
+# define OSSL_TRACE9(category, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8) \
+    OSSL_TRACEV(category, (trc_out, format, arg1, arg2, arg3, arg4, arg5, arg6, arg7, arg8, arg9))
+
+# ifdef  __cplusplus
+}
+# endif
+
+#endif
index 9957cf8..cb0cb22 100644 (file)
@@ -4646,3 +4646,12 @@ OPENSSL_CTX_free                        4601     3_0_0   EXIST::FUNCTION:
 OPENSSL_LH_flush                        4602   3_0_0   EXIST::FUNCTION:
 BN_native2bn                            4603   3_0_0   EXIST::FUNCTION:
 BN_bn2nativepad                         4604   3_0_0   EXIST::FUNCTION:
+OSSL_trace_get_category_num             4605   3_0_0   EXIST::FUNCTION:
+OSSL_trace_get_category_name            4606   3_0_0   EXIST::FUNCTION:
+OSSL_trace_set_channel                  4607   3_0_0   EXIST::FUNCTION:
+OSSL_trace_set_prefix                   4608   3_0_0   EXIST::FUNCTION:
+OSSL_trace_set_suffix                   4609   3_0_0   EXIST::FUNCTION:
+OSSL_trace_set_callback                 4610   3_0_0   EXIST::FUNCTION:
+OSSL_trace_enabled                      4611   3_0_0   EXIST::FUNCTION:
+OSSL_trace_begin                        4612   3_0_0   EXIST::FUNCTION:
+OSSL_trace_end                          4613   3_0_0   EXIST::FUNCTION: