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)
This commit is contained in:
Dr. Matthias St. Pierre 2019-03-13 00:14:55 +01:00
parent 13d06925e8
commit fe50e11571
2 changed files with 17 additions and 10 deletions

View file

@ -136,6 +136,8 @@ static size_t internal_trace_cb(const char *buf, size_t cnt,
switch (cmd) { switch (cmd) {
case OSSL_TRACE_CTRL_BEGIN: case OSSL_TRACE_CTRL_BEGIN:
if (!ossl_assert(!trace_data->ingroup))
return 0;
trace_data->ingroup = 1; trace_data->ingroup = 1;
tid.ltid = 0; tid.ltid = 0;
@ -147,9 +149,14 @@ static size_t internal_trace_cb(const char *buf, size_t cnt,
strlen(buffer), buffer); strlen(buffer), buffer);
break; break;
case OSSL_TRACE_CTRL_WRITE: case OSSL_TRACE_CTRL_WRITE:
if (!ossl_assert(trace_data->ingroup))
return 0;
ret = BIO_write(trace_data->bio, buf, cnt); ret = BIO_write(trace_data->bio, buf, cnt);
break; break;
case OSSL_TRACE_CTRL_END: case OSSL_TRACE_CTRL_END:
if (!ossl_assert(trace_data->ingroup))
return 0;
trace_data->ingroup = 0; trace_data->ingroup = 0;
BIO_ctrl(trace_data->bio, PREFIX_CTRL_SET_PREFIX, 0, NULL); BIO_ctrl(trace_data->bio, PREFIX_CTRL_SET_PREFIX, 0, NULL);

View file

@ -218,7 +218,7 @@ static int trace_detach_cb(int category, int type, const void *data)
return 1; 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, const char **prefix, const char **suffix,
int (*attach_cb)(int, int, const void *), int (*attach_cb)(int, int, const void *),
int (*detach_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) { if (channel != NULL && curr_channel != NULL) {
BIO_free(curr_channel); BIO_free(curr_channel);
trace_channels[category].type = 0;
trace_channels[category].bio = NULL; trace_channels[category].bio = NULL;
} }
/* Before running callbacks are done, set new data where appropriate */ /* Before running callbacks are done, set new data where appropriate */
if (channel != NULL && *channel != NULL) { if (channel != NULL && *channel != NULL) {
trace_channels[category].type = type;
trace_channels[category].bio = *channel; trace_channels[category].bio = *channel;
} }
@ -313,10 +315,11 @@ void ossl_trace_cleanup(void)
/* We force the TRACE category to be treated last */ /* We force the TRACE category to be treated last */
if (category == OSSL_TRACE_CATEGORY_TRACE) if (category == OSSL_TRACE_CATEGORY_TRACE)
continue; continue;
set_trace_data(category, &channel, &prefix, &suffix, set_trace_data(category, 0, &channel, &prefix, &suffix,
trace_attach_cb, trace_detach_cb); 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); trace_attach_cb, trace_detach_cb);
CRYPTO_THREAD_lock_free(trace_lock); CRYPTO_THREAD_lock_free(trace_lock);
#endif #endif
@ -326,11 +329,9 @@ int OSSL_trace_set_channel(int category, BIO *channel)
{ {
#ifndef OPENSSL_NO_TRACE #ifndef OPENSSL_NO_TRACE
if (category < 0 || category >= OSSL_TRACE_CATEGORY_NUM 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)) trace_attach_cb, trace_detach_cb))
return 0; return 0;
trace_channels[category].type = SIMPLE_CHANNEL;
#endif #endif
return 1; 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); 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)) trace_attach_w_callback_cb, trace_detach_cb))
goto err; goto err;
trace_channels[category].type = CALLBACK_CHANNEL;
goto done; goto done;
err: err:
@ -403,7 +403,7 @@ int OSSL_trace_set_prefix(int category, const char *prefix)
#ifndef OPENSSL_NO_TRACE #ifndef OPENSSL_NO_TRACE
if (category >= 0 || category < OSSL_TRACE_CATEGORY_NUM) 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); trace_attach_cb, trace_detach_cb);
rv = 0; rv = 0;
#endif #endif
@ -416,7 +416,7 @@ int OSSL_trace_set_suffix(int category, const char *suffix)
#ifndef OPENSSL_NO_TRACE #ifndef OPENSSL_NO_TRACE
if (category >= 0 || category < OSSL_TRACE_CATEGORY_NUM) 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); trace_attach_cb, trace_detach_cb);
rv = 0; rv = 0;
#endif #endif