print average time per transaction and sample variance.

4 files changed, 67 insertions, 9 deletions

diff --git a/src/benchmark-cipher.c b/src/benchmark-cipher.c
index c0695153a5..b620723a2a 100644
--- a/src/benchmark-cipher.c
+++ b/src/benchmark-cipher.c
@@ -69,7 +69,7 @@ cipher_mac_bench (int algo, int mac_algo, int size)
   key.data = _key;
   key.size = keysize;
 
-  printf ("Checking %s with %s (%dkb payload)... ", gnutls_cipher_get_name (algo),
+  printf ("Checking %s with %s (%dkb payload)...\n", gnutls_cipher_get_name (algo),
       gnutls_mac_get_name(mac_algo), size);
   fflush (stdout);
 
@@ -140,7 +140,7 @@ cipher_bench (int algo, int size, int aead)
   key.data = _key;
   key.size = keysize;
 
-  printf ("Checking %s (%dkb payload)... ", gnutls_cipher_get_name (algo),
+  printf ("Checking %s (%dkb payload)...\n", gnutls_cipher_get_name (algo),
           size);
   fflush (stdout);
 
@@ -185,7 +185,7 @@ mac_bench (int algo, int size)
     return;
   memset (_key, 0xf0, blocksize);
 
-  printf ("Checking %s (%dkb payload)... ", gnutls_mac_get_name (algo), size);
+  printf ("Checking %s (%dkb payload)...\n", gnutls_mac_get_name (algo), size);
   fflush (stdout);
 
   start_benchmark(&st);
diff --git a/src/benchmark-tls.c b/src/benchmark-tls.c
index b133671e14..37a2a323fd 100644
--- a/src/benchmark-tls.c
+++ b/src/benchmark-tls.c
@@ -30,6 +30,7 @@
 #include <errno.h>
 #include <gnutls/gnutls.h>
 #include <gnutls/crypto.h>
+#include <math.h>
 
 #define fail(...) \
 	{ \
@@ -214,7 +215,7 @@ static void test_ciphersuite(const char *cipher_prio, int size)
 
     HANDSHAKE(client, server);
 
-    fprintf(stdout, "Testing %s with %d packet size: ",
+    fprintf(stdout, "Testing %s with %d packet size...\n",
             gnutls_cipher_suite_get_name(gnutls_kx_get(server),
                                          gnutls_cipher_get(server),
                                          gnutls_mac_get(server)), size);
@@ -250,6 +251,7 @@ static void test_ciphersuite(const char *cipher_prio, int size)
     while (benchmark_must_finish == 0);
 
     stop_benchmark(&st, NULL);
+    fprintf(stdout, "\n");
 
     gnutls_bye(client, GNUTLS_SHUT_WR);
     gnutls_bye(server, GNUTLS_SHUT_WR);
@@ -264,6 +266,41 @@ static void test_ciphersuite(const char *cipher_prio, int size)
 
 }
 
+static
+double calc_avg(unsigned int *diffs, unsigned int diffs_size)
+{
+double avg = 0;
+unsigned int i;
+
+  for(i=0;i<diffs_size;i++)
+    avg += diffs[i];
+    
+  avg /= diffs_size;
+
+  return avg;
+}
+
+static
+double calc_sstdev(unsigned int *diffs, unsigned int diffs_size, double avg)
+{
+double sum = 0, d;
+unsigned int i;
+
+  for (i=0;i<diffs_size;i++) {
+    d = ((double)diffs[i] - avg);
+    d *= d;
+    
+    sum += d;
+  }
+  sum /= diffs_size - 1;
+  
+  return sum;
+}
+
+
+unsigned int diffs[32*1024];
+unsigned int diffs_size = 0;
+
 static void test_ciphersuite_kx(const char *cipher_prio)
 {
     /* Server stuff. */
@@ -281,6 +318,8 @@ static void test_ciphersuite_kx(const char *cipher_prio)
     /* Need to enable anonymous KX specifically. */
     int ret;
     struct benchmark_st st;
+    struct timespec tr_start, tr_stop;
+    double avg, sstddev;
 
     /* Init server */
     gnutls_certificate_allocate_credentials(&s_certcred);
@@ -305,6 +344,8 @@ static void test_ciphersuite_kx(const char *cipher_prio)
     start_benchmark(&st);
 
     do {
+        gettime(&tr_start);
+        
         gnutls_init(&server, GNUTLS_SERVER);
         ret = gnutls_priority_set_direct(server, cipher_prio, &str);
         if (ret < 0) {
@@ -342,13 +383,24 @@ static void test_ciphersuite_kx(const char *cipher_prio)
         gnutls_deinit(client);
         gnutls_deinit(server);
 
+        gettime(&tr_stop);
+
+        diffs[diffs_size++] = timespec_sub_ms(&tr_stop, &tr_start);
+        if (diffs_size > sizeof(diffs))
+          abort();
+
         st.size += 1;
     }
     while (benchmark_must_finish == 0);
 
-    fprintf(stdout, "Tested %s: ", suite);
+    fprintf(stdout, "Benchmarked %s.\n", suite);
     stop_benchmark(&st, "transactions");
 
+    avg = calc_avg(diffs, diffs_size);
+    sstddev = calc_sstdev(diffs, diffs_size, avg);
+
+    printf("  Average time: %.2f ms, sample variance: %.2f\n\n", avg, sstddev);
+
     gnutls_anon_free_client_credentials(c_anoncred);
     gnutls_anon_free_server_credentials(s_anoncred);
 
@@ -364,7 +416,7 @@ void benchmark_tls(int debug_level, int ciphers)
 
     if (ciphers != 0)
       {
-        printf("Testing throughput in cipher/MAC combinations:\n");
+        printf("Testing throughput in cipher/MAC combinations:\n\n");
 
         test_ciphersuite(PRIO_ARCFOUR_128_MD5, 1024);
         test_ciphersuite(PRIO_ARCFOUR_128_MD5, 4096);
@@ -388,7 +440,7 @@ void benchmark_tls(int debug_level, int ciphers)
       }
     else
       {
-        printf("\nTesting key exchanges (RSA/DH bits: %d, EC bits: %d):\n", rsa_bits, ec_bits);
+        printf("\nTesting key exchanges (RSA/DH bits: %d, EC bits: %d):\n\n", rsa_bits, ec_bits);
         test_ciphersuite_kx(PRIO_DH);
         test_ciphersuite_kx(PRIO_ECDH);
         test_ciphersuite_kx(PRIO_ECDHE_ECDSA);
diff --git a/src/benchmark.c b/src/benchmark.c
index 398c732a38..8ab3f8c2b1 100644
--- a/src/benchmark.c
+++ b/src/benchmark.c
@@ -142,14 +142,14 @@ double stop_benchmark(struct benchmark_st * st, const char* metric)
   if (metric == NULL)
     { /* assume bytes/sec */
       value2human (st->size, secs, &ddata, &dspeed, imetric);
-      printf ("Processed %.2f %s in %.2f secs: ", ddata, imetric, secs);
+      printf ("  Processed %.2f %s in %.2f secs: ", ddata, imetric, secs);
       printf ("%.2f %s/sec\n", dspeed, imetric);
     }
   else
     {
       ddata = (double) st->size;
       dspeed = ddata / secs;
-      printf ("Processed %.2f %s in %.2f secs: ", ddata, metric, secs);
+      printf ("  Processed %.2f %s in %.2f secs: ", ddata, metric, secs);
       printf ("%.2f %s/sec\n", dspeed, metric);
     }
 
diff --git a/src/benchmark.h b/src/benchmark.h
index 40bd60240d..bcc07c7dbf 100644
--- a/src/benchmark.h
+++ b/src/benchmark.h
@@ -47,3 +47,9 @@ extern int benchmark_must_finish;
 void start_benchmark(struct benchmark_st * st);
 double stop_benchmark(struct benchmark_st * st, const char* metric);
 
+inline static unsigned int
+timespec_sub_ms (struct timespec *a, struct timespec *b)
+{
+  return (a->tv_sec * 1000 + a->tv_nsec / (1000 * 1000) -
+          (b->tv_sec * 1000 + b->tv_nsec / (1000 * 1000)));
+}