trace: ensure correct grouping

It is important that output to the trace channels occurs only inside
a trace group. This precondtion is satisfied whenever the standard
TRACE macros are used. It can be violated only by a bad programming
mistake, like copying the 'trc_out' pointer and using it outside
the trace group.

This commit enforces correct pairing of the OSSL_TRACE_CTRL_BEGIN and
OSSL_TRACE_CTRL_END callbacks, and checks that OSSL_TRACE_CTRL_WRITE
callbacks only occur within such groups.

While implementing it, it turned out that the group assertion failed

  apps/openssl.c:152: OpenSSL internal error: \
                      Assertion failed: trace_data->ingroup

because the set_trace_data() function invokes some callbacks which
generate trace output, but the correct channel type was set only
after the set_trace_data() call.

To fix the failed assertions, the correct channel type is now set
inside the set_trace_data() call, instead of doing it afterwards.

Reviewed-by: Paul Dale <paul.dale@oracle.com>
Reviewed-by: Richard Levitte <levitte@openssl.org>
(Merged from https://github.com/openssl/openssl/pull/8463)

diff --git a/apps/openssl.c b/apps/openssl.c
index db1dbb767d1f5519f1c87c48628120b426b28535..119d3e8ff679622df8726b5fdd4ec7ed3754cc08 100644 (file)
--- a/apps/openssl.c
+++ b/apps/openssl.c
@@ -136,6 +136,8 @@ static size_t internal_trace_cb(const char *buf, size_t cnt,
 
     switch (cmd) {
     case OSSL_TRACE_CTRL_BEGIN:
+        if (!ossl_assert(!trace_data->ingroup))
+            return 0;
         trace_data->ingroup = 1;
 
         tid.ltid = 0;
@@ -147,9 +149,14 @@ static size_t internal_trace_cb(const char *buf, size_t cnt,
                  strlen(buffer), buffer);
         break;
     case OSSL_TRACE_CTRL_WRITE:
+        if (!ossl_assert(trace_data->ingroup))
+            return 0;
+
         ret = BIO_write(trace_data->bio, buf, cnt);
         break;
     case OSSL_TRACE_CTRL_END:
+        if (!ossl_assert(trace_data->ingroup))
+            return 0;
         trace_data->ingroup = 0;
 
         BIO_ctrl(trace_data->bio, PREFIX_CTRL_SET_PREFIX, 0, NULL);

diff --git a/crypto/trace.c b/crypto/trace.c
index 533770c669f646070fe3cdeb54112cf83921c325..613664c3be634b75c4fad1828eebf3153e6fce61 100644 (file)
--- a/crypto/trace.c
+++ b/crypto/trace.c
@@ -218,7 +218,7 @@ static int trace_detach_cb(int category, int type, const void *data)
     return 1;
 }
 
-static int set_trace_data(int category, BIO **channel,
+static int 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 *))
@@ -253,11 +253,13 @@ static int set_trace_data(int category, BIO **channel,
 
     if (channel != NULL && curr_channel != NULL) {
         BIO_free(curr_channel);
+        trace_channels[category].type = 0;
         trace_channels[category].bio = NULL;
     }
 
     /* Before running callbacks are done, set new data where appropriate */
     if (channel != NULL && *channel != NULL) {
+        trace_channels[category].type = type;
         trace_channels[category].bio = *channel;
     }
 
@@ -313,10 +315,11 @@ void ossl_trace_cleanup(void)
         /* We force the TRACE category to be treated last */
         if (category == OSSL_TRACE_CATEGORY_TRACE)
             continue;
-        set_trace_data(category, &channel, &prefix, &suffix,
+        set_trace_data(category, 0, &channel, &prefix, &suffix,
                        trace_attach_cb, trace_detach_cb);
     }
-    set_trace_data(OSSL_TRACE_CATEGORY_TRACE, &channel, &prefix, &suffix,
+    set_trace_data(OSSL_TRACE_CATEGORY_TRACE, 0, &channel,
+                   &prefix, &suffix,
                    trace_attach_cb, trace_detach_cb);
     CRYPTO_THREAD_lock_free(trace_lock);
 #endif
@@ -326,11 +329,9 @@ int OSSL_trace_set_channel(int category, BIO *channel)
 {
 #ifndef OPENSSL_NO_TRACE
     if (category < 0 || category >= OSSL_TRACE_CATEGORY_NUM
-        || !set_trace_data(category, &channel, NULL, NULL,
+        || !set_trace_data(category, SIMPLE_CHANNEL, &channel, NULL, NULL,
                            trace_attach_cb, trace_detach_cb))
         return 0;
-
-    trace_channels[category].type = SIMPLE_CHANNEL;
 #endif
     return 1;
 }
@@ -381,11 +382,10 @@ int OSSL_trace_set_callback(int category, OSSL_trace_cb callback, void *data)
         BIO_set_data(channel, trace_data);
     }
 
-    if (!set_trace_data(category, &channel, NULL, NULL,
+    if (!set_trace_data(category, CALLBACK_CHANNEL, &channel, NULL, NULL,
                         trace_attach_w_callback_cb, trace_detach_cb))
         goto err;
 
-    trace_channels[category].type = CALLBACK_CHANNEL;
     goto done;
 
  err:
@@ -403,7 +403,7 @@ int OSSL_trace_set_prefix(int category, const char *prefix)
 
 #ifndef OPENSSL_NO_TRACE
     if (category >= 0 || category < OSSL_TRACE_CATEGORY_NUM)
-        return set_trace_data(category, NULL, &prefix, NULL,
+        return set_trace_data(category, 0, NULL, &prefix, NULL,
                               trace_attach_cb, trace_detach_cb);
     rv = 0;
 #endif
@@ -416,7 +416,7 @@ int OSSL_trace_set_suffix(int category, const char *suffix)
 
 #ifndef OPENSSL_NO_TRACE
     if (category >= 0 || category < OSSL_TRACE_CATEGORY_NUM)
-        return set_trace_data(category, NULL, NULL, &suffix,
+        return set_trace_data(category, 0, NULL, NULL, &suffix,
                               trace_attach_cb, trace_detach_cb);
     rv = 0;
 #endif