From 80c84eca36fb6b26b35b394c0820d740d81a5076 Mon Sep 17 00:00:00 2001
From: Florian Dold <florian.dold@gmail.com>
Date: Fri, 10 May 2019 20:12:15 +0200
Subject: Create async scopes.

Log statements contain an async scope identifier, which allows to
correlate logs from the same request.
---
 src/backend/taler-merchant-httpd.c           | 64 +++++++++++++++++++++++++++-
 src/backend/taler-merchant-httpd.h           |  4 ++
 src/backend/taler-merchant-httpd_exchanges.c |  1 +
 src/lib/test_merchant_api.c                  |  1 +
 4 files changed, 69 insertions(+), 1 deletion(-)

diff --git a/src/backend/taler-merchant-httpd.c b/src/backend/taler-merchant-httpd.c
index 77dd7449..b92aad47 100644
--- a/src/backend/taler-merchant-httpd.c
+++ b/src/backend/taler-merchant-httpd.c
@@ -151,6 +151,24 @@ static char *serve_unixpath;
 static mode_t unixpath_mode;
 
 
+/**
+ * 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;
+}
+
+
 /**
  * A client has requested the given url using the given method
  * (#MHD_HTTP_METHOD_GET, #MHD_HTTP_METHOD_PUT,
@@ -282,6 +300,46 @@ url_handler (void *cls,
               "Handling request (%s) for URL `%s'\n",
               method,
               url);
+
+  struct TM_HandlerContext *hc;
+  struct GNUNET_AsyncScopeId aid;
+  const char *correlation_id = NULL;
+
+  hc = *con_cls;
+
+  if (NULL == hc)
+  {
+    GNUNET_async_scope_fresh (&aid);
+    /* 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;
+    }
+  }
+  else
+  {
+    aid = hc->async_scope_id;
+  }
+
+  GNUNET_SCHEDULER_begin_async_scope (&aid);
+
+  if (NULL != correlation_id)
+    GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                "Handling request for (%s) 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);
+
   for (unsigned int i=0;NULL != handlers[i].url;i++)
   {
     struct TMH_RequestHandler *rh = &handlers[i];
@@ -292,7 +350,6 @@ url_handler (void *cls,
            (0 == strcasecmp (method,
                              rh->method)) ) )
     {
-      struct TM_HandlerContext *hc;
       int ret;
 
       ret = rh->handler (rh,
@@ -302,7 +359,12 @@ url_handler (void *cls,
 			 upload_data_size);
       hc = *con_cls;
       if (NULL != hc)
+      {
         hc->rh = rh;
+        /* Store the async context ID, so we can restore it if
+         * we get another callack for this request. */
+        hc->async_scope_id = aid;
+      }
       return ret;
     }
   }
diff --git a/src/backend/taler-merchant-httpd.h b/src/backend/taler-merchant-httpd.h
index 9d494db9..ee3d88fe 100644
--- a/src/backend/taler-merchant-httpd.h
+++ b/src/backend/taler-merchant-httpd.h
@@ -257,6 +257,10 @@ struct TM_HandlerContext
    */
   const struct TMH_RequestHandler *rh;
 
+  /**
+   * Asynchronous request context id.
+   */
+  struct GNUNET_AsyncScopeId async_scope_id;
 };
 
 
diff --git a/src/backend/taler-merchant-httpd_exchanges.c b/src/backend/taler-merchant-httpd_exchanges.c
index b8c9be04..ed6ece98 100644
--- a/src/backend/taler-merchant-httpd_exchanges.c
+++ b/src/backend/taler-merchant-httpd_exchanges.c
@@ -1056,6 +1056,7 @@ TMH_EXCHANGES_init (const struct GNUNET_CONFIGURATION_Handle *cfg)
     GNUNET_break (0);
     return GNUNET_SYSERR;
   }
+  GNUNET_CURL_enable_async_scope_header (merchant_curl_ctx, "Taler-Correlation-Id");
   merchant_curl_rc = GNUNET_CURL_gnunet_rc_create (merchant_curl_ctx);
   /* get exchanges from the merchant configuration and try to connect to them */
   GNUNET_CONFIGURATION_iterate_sections (cfg,
diff --git a/src/lib/test_merchant_api.c b/src/lib/test_merchant_api.c
index e373e6b7..344112d9 100644
--- a/src/lib/test_merchant_api.c
+++ b/src/lib/test_merchant_api.c
@@ -4995,6 +4995,7 @@ run (void *cls)
   GNUNET_assert (ctx = GNUNET_CURL_init
     (&GNUNET_CURL_gnunet_scheduler_reschedule,
      &rc));
+  GNUNET_CURL_enable_async_scope_header (ctx, "Taler-Correlation-Id");
   rc = GNUNET_CURL_gnunet_rc_create (ctx);
   GNUNET_assert (NULL != (exchange
     = TALER_EXCHANGE_connect (ctx,
-- 
cgit v1.2.3