Create async scopes.

Log statements contain an async scope identifier, which allows to
correlate logs from the same request.
This commit is contained in:
Florian Dold 2019-05-10 20:11:29 +02:00
parent b8a718f859
commit 081280a88b
No known key found for this signature in database
GPG Key ID: D2E4F00F29D02A4B
2 changed files with 98 additions and 15 deletions

View File

@ -54,6 +54,24 @@
*/ */
#define UNIX_BACKLOG 500 #define UNIX_BACKLOG 500
/**
* Type of the closure associated with each HTTP request to the exchange.
*/
struct ExchangeHttpRequestClosure
{
/**
* Async Scope ID associated with this request.
*/
struct GNUNET_AsyncScopeId async_scope_id;
/**
* Opaque parsing context.
*/
void *opaque_post_parsing_context;
};
/** /**
* Which currency is used by this exchange? * Which currency is used by this exchange?
*/ */
@ -142,16 +160,38 @@ handle_mhd_completion_callback (void *cls,
void **con_cls, void **con_cls,
enum MHD_RequestTerminationCode toe) enum MHD_RequestTerminationCode toe)
{ {
if (NULL == *con_cls) struct ExchangeHttpRequestClosure *ecls = *con_cls;
GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Request completed\n");
if (NULL == ecls)
return; return;
TEH_PARSE_post_cleanup_callback (*con_cls); TEH_PARSE_post_cleanup_callback (ecls->opaque_post_parsing_context);
GNUNET_free (ecls);
*con_cls = NULL; *con_cls = NULL;
/* check that we didn't leave any transactions hanging */ /* check that we didn't leave any transactions hanging */
/* NOTE: In high-performance production, we might want to /* NOTE: In high-performance production, we might want to
remove this. */ remove this. */
TEH_plugin->preflight (TEH_plugin->cls, TEH_plugin->preflight (TEH_plugin->cls,
TEH_plugin->get_session (TEH_plugin->cls)); TEH_plugin->get_session (TEH_plugin->cls));
}
/**
* Return GNUNET_YES if given a valid correlation ID and
* GNUNET_NO otherwise.
*
* @returns GNUNET_YES iff given a valid correlation ID
*/
static int
is_valid_correlation_id (const char *correlation_id)
{
if (strlen (correlation_id) >= 64)
return GNUNET_NO;
for (int i = 0; i < strlen (correlation_id); i++)
if (!(isalnum (correlation_id[i]) || correlation_id[i] == '-'))
return GNUNET_NO;
return GNUNET_YES;
} }
@ -367,10 +407,45 @@ handle_mhd_request (void *cls,
&TEH_MHD_handler_static_response, MHD_HTTP_NOT_FOUND &TEH_MHD_handler_static_response, MHD_HTTP_NOT_FOUND
}; };
struct TEH_RequestHandler *rh; struct TEH_RequestHandler *rh;
struct ExchangeHttpRequestClosure *ecls = *con_cls;
int ret;
void **inner_cls;
struct GNUNET_AsyncScopeSave old_scope;
const char *correlation_id = NULL;
if (NULL == ecls) {
GNUNET_log (GNUNET_ERROR_TYPE_INFO, "Handling new request\n");
/* We're in a new async scope! */
ecls = *con_cls = GNUNET_new (struct ExchangeHttpRequestClosure);
GNUNET_async_scope_fresh (&ecls->async_scope_id);
/* We only read the correlation ID on the first callback for every client */
correlation_id = MHD_lookup_connection_value (connection,
MHD_HEADER_KIND,
"Taler-Correlation-Id");
if ((NULL != correlation_id) &&
(GNUNET_YES != is_valid_correlation_id (correlation_id)))
{
GNUNET_log (GNUNET_ERROR_TYPE_WARNING, "illegal incoming correlation ID\n");
correlation_id = NULL;
}
}
inner_cls = &ecls->opaque_post_parsing_context;
GNUNET_async_scope_enter (&ecls->async_scope_id, &old_scope);
if (NULL != correlation_id)
GNUNET_log (GNUNET_ERROR_TYPE_INFO,
"Handling request (%s) for URL '%s', correlation_id=%s\n",
method,
url,
correlation_id);
else
GNUNET_log (GNUNET_ERROR_TYPE_INFO,
"Handling request (%s) for URL '%s'\n",
method,
url);
GNUNET_log (GNUNET_ERROR_TYPE_INFO,
"Handling request for URL '%s'\n",
url);
if (0 == strcasecmp (method, if (0 == strcasecmp (method,
MHD_HTTP_METHOD_HEAD)) MHD_HTTP_METHOD_HEAD))
method = MHD_HTTP_METHOD_GET; /* treat HEAD as GET here, MHD will do the rest */ method = MHD_HTTP_METHOD_GET; /* treat HEAD as GET here, MHD will do the rest */
@ -382,17 +457,24 @@ handle_mhd_request (void *cls,
( (NULL == rh->method) || ( (NULL == rh->method) ||
(0 == strcasecmp (method, (0 == strcasecmp (method,
rh->method)) ) ) rh->method)) ) )
return rh->handler (rh, {
connection, ret = rh->handler (rh,
con_cls, connection,
upload_data, inner_cls,
upload_data_size); upload_data,
upload_data_size);
GNUNET_async_scope_restore (&old_scope);
return ret;
}
} }
return TEH_MHD_handler_static_response (&h404, ret = TEH_MHD_handler_static_response (&h404,
connection, connection,
con_cls, inner_cls,
upload_data, upload_data,
upload_data_size); upload_data_size);
GNUNET_async_scope_restore (&old_scope);
return ret;
} }

View File

@ -807,6 +807,7 @@ TALER_TESTING_setup (TALER_TESTING_Main main_cb,
is.ctx = GNUNET_CURL_init is.ctx = GNUNET_CURL_init
(&GNUNET_CURL_gnunet_scheduler_reschedule, (&GNUNET_CURL_gnunet_scheduler_reschedule,
&is.rc); &is.rc);
GNUNET_CURL_enable_async_scope_header (is.ctx, "Taler-Correlation-Id");
GNUNET_assert (NULL != is.ctx); GNUNET_assert (NULL != is.ctx);
is.rc = GNUNET_CURL_gnunet_rc_create (is.ctx); is.rc = GNUNET_CURL_gnunet_rc_create (is.ctx);