From 10c56bcea05df9ac5a7036850039900fbe435e00 Mon Sep 17 00:00:00 2001
From: Christian Grothoff <christian@grothoff.org>
Date: Fri, 20 Mar 2020 02:36:50 +0100
Subject: improving benchmarking logic, including more timings

---
 src/testing/testing_api_cmd_refresh.c | 67 ++++++++++++++++++++++++++++++++---
 1 file changed, 63 insertions(+), 4 deletions(-)

(limited to 'src/testing/testing_api_cmd_refresh.c')

diff --git a/src/testing/testing_api_cmd_refresh.c b/src/testing/testing_api_cmd_refresh.c
index 2f91df377..51c3890ba 100644
--- a/src/testing/testing_api_cmd_refresh.c
+++ b/src/testing/testing_api_cmd_refresh.c
@@ -28,11 +28,23 @@
 #include "taler_signatures.h"
 #include "backoff.h"
 
+/**
+ * How long do we wait AT MOST when retrying?
+ */
+#define MAX_BACKOFF GNUNET_TIME_relative_multiply ( \
+    GNUNET_TIME_UNIT_MILLISECONDS, 100)
+
 /**
  * How often do we retry before giving up?
  */
 #define NUM_RETRIES 5
 
+/**
+ * How long do we wait AT MOST when retrying?
+ */
+#define MAX_BACKOFF GNUNET_TIME_relative_multiply ( \
+    GNUNET_TIME_UNIT_MILLISECONDS, 100)
+
 /**
  * Information about a fresh coin generated by the refresh
  * operation.
@@ -119,6 +131,11 @@ struct RefreshMeltState
    */
   struct GNUNET_TIME_Relative backoff;
 
+  /**
+   * How long did we wait in total for retries?
+   */
+  struct GNUNET_TIME_Relative total_backoff;
+
   /**
    * Number of bytes in @e refresh_data.
    */
@@ -201,6 +218,11 @@ struct RefreshRevealState
    */
   struct GNUNET_TIME_Relative backoff;
 
+  /**
+   * How long did we wait in total for retries?
+   */
+  struct GNUNET_TIME_Relative total_backoff;
+
   /**
    * Number of fresh coins withdrawn, set by the
    * reveal callback as it comes from the exchange,
@@ -251,6 +273,11 @@ struct RefreshLinkState
    */
   struct GNUNET_TIME_Relative backoff;
 
+  /**
+   * How long did we wait in total for retries?
+   */
+  struct GNUNET_TIME_Relative total_backoff;
+
   /**
    * Expected HTTP response code.
    */
@@ -341,7 +368,10 @@ reveal_cb (void *cls,
         if (TALER_EC_DB_COMMIT_FAILED_ON_RETRY == ec)
           rrs->backoff = GNUNET_TIME_UNIT_ZERO;
         else
-          rrs->backoff = EXCHANGE_LIB_BACKOFF (rrs->backoff);
+          rrs->backoff = GNUNET_TIME_randomized_backoff (rrs->backoff,
+                                                         MAX_BACKOFF);
+        rrs->total_backoff = GNUNET_TIME_relative_add (rrs->total_backoff,
+                                                       rrs->backoff);
         rrs->retry_task = GNUNET_SCHEDULER_add_delayed (rrs->backoff,
                                                         &do_reveal_retry,
                                                         rrs);
@@ -391,6 +421,14 @@ reveal_cb (void *cls,
       fc->sig.rsa_signature = GNUNET_CRYPTO_rsa_signature_dup
                                 (sigs[i].rsa_signature);
     }
+    if (0 != rrs->total_backoff.rel_value_us)
+    {
+      GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                  "Total reveal backoff for %s was %s\n",
+                  rrs->is->commands[rrs->is->ip].label,
+                  GNUNET_STRINGS_relative_time_to_string (rrs->total_backoff,
+                                                          GNUNET_YES));
+    }
     break;
   default:
     GNUNET_log (GNUNET_ERROR_TYPE_WARNING,
@@ -568,7 +606,10 @@ link_cb (void *cls,
         if (TALER_EC_DB_COMMIT_FAILED_ON_RETRY == ec)
           rls->backoff = GNUNET_TIME_UNIT_ZERO;
         else
-          rls->backoff = EXCHANGE_LIB_BACKOFF (rls->backoff);
+          rls->backoff = GNUNET_TIME_randomized_backoff (rls->backoff,
+                                                         MAX_BACKOFF);
+        rls->total_backoff = GNUNET_TIME_relative_add (rls->total_backoff,
+                                                       rls->backoff);
         rls->retry_task = GNUNET_SCHEDULER_add_delayed (rls->backoff,
                                                         &do_link_retry,
                                                         rls);
@@ -663,6 +704,14 @@ link_cb (void *cls,
       TALER_TESTING_interpreter_fail (rls->is);
       return;
     }
+    if (0 != rls->total_backoff.rel_value_us)
+    {
+      GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                  "Total link backoff for %s was %s\n",
+                  rls->is->commands[rls->is->ip].label,
+                  GNUNET_STRINGS_relative_time_to_string (rls->total_backoff,
+                                                          GNUNET_YES));
+    }
     break;
   default:
     GNUNET_log (GNUNET_ERROR_TYPE_ERROR,
@@ -851,7 +900,10 @@ melt_cb (void *cls,
         if (TALER_EC_DB_COMMIT_FAILED_ON_RETRY == ec)
           rms->backoff = GNUNET_TIME_UNIT_ZERO;
         else
-          rms->backoff = EXCHANGE_LIB_BACKOFF (rms->backoff);
+          rms->backoff = GNUNET_TIME_randomized_backoff (rms->backoff,
+                                                         MAX_BACKOFF);
+        rms->total_backoff = GNUNET_TIME_relative_add (rms->total_backoff,
+                                                       rms->backoff);
         rms->retry_task = GNUNET_SCHEDULER_add_delayed
                             (rms->backoff,
                             &do_melt_retry,
@@ -872,7 +924,14 @@ melt_cb (void *cls,
     return;
   }
   rms->noreveal_index = noreveal_index;
-
+  if (0 != rms->total_backoff.rel_value_us)
+  {
+    GNUNET_log (GNUNET_ERROR_TYPE_INFO,
+                "Total melt backoff for %s was %s\n",
+                rms->is->commands[rms->is->ip].label,
+                GNUNET_STRINGS_relative_time_to_string (rms->total_backoff,
+                                                        GNUNET_YES));
+  }
   if (GNUNET_YES == rms->double_melt)
   {
     TALER_LOG_DEBUG ("Doubling the melt (%s)\n",
-- 
cgit v1.2.3