Squashed commit of the following:

commit a804a54c
Author: Johan Hugé <johan.huge@nexedi.com>
Date:   Wed Jun 24 15:26:32 2020 +0200

    Fix histogram printing mistakes

commit b62397e6
Author: Johan Hugé <johan.huge@nexedi.com>
Date:   Wed Jun 24 15:21:20 2020 +0200

    Clean up histogram printing and fix missing bracket

commit 8f5998b7
Author: Johan Hugé <johan.huge@nexedi.com>
Date:   Wed Jun 24 15:02:22 2020 +0200

    Fix compilation error caused by previous commit

commit 3f4964a6
Author: Johan Hugé <johan.huge@nexedi.com>
Date:   Wed Jun 24 15:01:20 2020 +0200

    Compute userspace timestamp after recvmsg in recvpacket

commit f09aa981
Author: Johan Hugé <johan.huge@nexedi.com>
Date:   Wed Jun 24 14:55:02 2020 +0200

    Fix timestamp buffer segmentation fault in recv_packet

commit 1593fe37
Author: Johan Hugé <johan.huge@nexedi.com>
Date:   Wed Jun 24 14:43:54 2020 +0200

    Allow displaying timestamps without enabling histograms in wrapper script

commit bd13db96
Author: Johan Hugé <johan.huge@nexedi.com>
Date:   Wed Jun 24 14:37:52 2020 +0200

    Fix still present segmentation fault caused by incrementing index without modulo

commit d067cff7
Author: Johan Hugé <johan.huge@nexedi.com>
Date:   Wed Jun 24 14:33:50 2020 +0200

    Fix segmentation fault caused by incorrectly accessing the cyclic timestamp buffer

commit 53fd7c47
Author: Johan Hugé <johan.huge@nexedi.com>
Date:   Wed Jun 24 13:58:00 2020 +0200

    Set ETF delta in microseconds instead of nanoseconds in the wrapper script

commit 923296b7
Author: Johan Hugé <johan.huge@nexedi.com>
Date:   Wed Jun 24 11:25:57 2020 +0200

    Set flag enabling error report in error socket queue

packet-exchange/src/client.c

@@ -307,20 +307,15 @@ static void print_histograms() {
   if (tsn_task == SEND_PACKET_TASK) {
     printf("{\"measure_sets\": [{"
            "\"measure_type\": \"packet_send_timestamps\","
-           "\"props_names\": [\"user_space\", \"kernel_space\"],"
-           "\"units\": [\"us\", \"us\"],"
+           "\"props_names\": [\"kernel_space\"],"
+           "\"units\": [\"us\"],"
            "\"props_type\": \"histogram\","
-           "\"metadata\": {"
-           "\"i\": \"%dus\", \"duration\": \"%dh%d\", \"etf_offset\": \"%dus\","
-           "},"
-           "\"props\": [",
+           "\"metadata\": {\"i\": \"%dus\", \"duration\": \"%dh%d\", \"etf_offset\": \"%dus\",},"
+           "\"props\": [[",
            interval, duration_hour, duration_minutes, thread_params.etf_offset);
-    histogram = kernel_latency_hist;
 
-    max_hist_val = 0;
-    for (int j = 0; j < MAX_KERNEL_LATENCY; j++)
-      if (histogram[j])
-        max_hist_val = j > max_hist_val ? j : max_hist_val;
+    histogram = kernel_latency_hist;
+    max_hist_val = histogram_max(histogram, MAX_KERNEL_LATENCY - 1);
 
   } else {
     printf("{\"measure_sets\": [{"
@@ -328,25 +323,17 @@ static void print_histograms() {
            "\"props_names\": [\"rtt\"],"
            "\"units\": [\"us\"],"
            "\"props_type\": \"histogram\","
-           "\"metadata\": {"
-           "\"i\": \"%dus\", \"duration\": \"%dh%d\", \"etf_offset\": \"%dus\","
-           "},"
-           "\"props\": [",
+           "\"metadata\": {\"i\": \"%dus\", \"duration\": \"%dh%d\", \"etf_offset\": \"%dus\",},"
+           "\"props\": [[",
            interval, duration_hour, duration_minutes, thread_params.etf_offset);
-    histogram = rtt_hist;
 
-    max_hist_val = 0;
-    for (int j = 0; j < MAX_RTT; j++)
-      if (histogram[j])
-        max_hist_val = j > max_hist_val ? j : max_hist_val;
+    histogram = rtt_hist;
+    max_hist_val = histogram_max(histogram, MAX_RTT - 1);
   }
 
-  printf("[");
   for (int j = 0; j < max_hist_val; j++)
     printf("%" PRIi64 "%s", histogram[j], (j + 1 < max_hist_val ? ", " : ""));
-  printf("]");
-
-  printf("]}]}\n");
+  printf("]]}]}\n");
 }
 
 static void sighand(int sig_num) {

packet-exchange/src/common.c

@@ -35,6 +35,20 @@ uint64_t calcdiff_ns(struct timespec t1, struct timespec t2) {
 int max(int a, int b) { return a > b ? a : b; }
 int min(int a, int b) { return a < b ? a : b; }
 
+int histogram_min(uint64_t * histogram, int max_value) {
+  int ret = max_value;
+  for (int i = max_value; i >= 0; i--)
+    ret = histogram[i] ? i : ret;
+  return ret;
+}
+int histogram_max(uint64_t * histogram, int max_value) {
+  int ret = 0;
+  for (int i = 0; i <= max_value; i++)
+    ret = histogram[i] ? i : ret;
+  return ret;
+}
+
+
 static void sighand_wrapper(int sig) {
 
   // If we get un unexpected signal, report it, if not print the histogram

packet-exchange/src/common.h

@@ -18,6 +18,8 @@
 
 #define MAX_BUFFER_SIZE 1024
 
+#define TIMESTAMP_BUFFER_SIZE 64
+
 uint64_t ts_to_uint(struct timespec t);
 void add_ns(struct timespec *t, uint64_t ns);
 uint64_t calcdiff_ns(struct timespec t1, struct timespec t2);
@@ -27,6 +29,9 @@ void init_signals(void (*_sighand)(int), int enable_histograms);
 int min(int a, int b);
 int max(int a, int b);
 
+int histogram_min(uint64_t * histogram, int max_value);
+int histogram_max(uint64_t * histogram, int max_value);
+
 extern void (*previous_handlers[NSIG])(int);
 
 #endif

packet-exchange/src/recv_packet.c

@@ -39,9 +39,7 @@ static ingress_stat_t *stats;
 static uint64_t *kernel_latency_hist;
 static int use_histogram;
 
-static uint64_t timestamps_buffer[64];
-static int ts_buf_read_index = 0;
-static int ts_buf_write_index = 0;
+uint64_t post_kernel_timestamp;
 
 // Sets the interface
 static int set_if() {
@@ -130,11 +128,6 @@ void recv_udp_packet() {
 
   struct timespec ts;
 
-  if (params->use_timestamps) {
-    clock_gettime(CLOCK_REALTIME, &ts);
-    timestamps_buffer[ts_buf_write_index++] = ts_to_uint(ts);
-  }
-
   iov.iov_base = &rx_buffer;
   iov.iov_len = MAX_BUFFER_SIZE - 1;
 
@@ -150,13 +143,19 @@ void recv_udp_packet() {
   if (recvmsgerr < 0)
     error(EXIT_FAILURE, errno, "recvmsg failed, ret value: %d\n", recvmsgerr);
 
+  if (params->use_timestamps) {
+    clock_gettime(CLOCK_REALTIME, &ts);
+    post_kernel_timestamp = ts_to_uint(ts);
+  }
+
+
   if (params->use_timestamps) {
     for (cmsg = CMSG_FIRSTHDR(&msg); cmsg; cmsg = CMSG_NXTHDR(&msg, cmsg)) {
       if (cmsg->cmsg_level == SOL_SOCKET && cmsg->cmsg_type == SO_TIMESTAMPING) {
 
         struct timespec *stamp = (struct timespec *)CMSG_DATA(cmsg);
 
-        uint64_t kernel_latency = timestamps_buffer[ts_buf_read_index++] - ts_to_uint(*stamp);
+        uint64_t kernel_latency = post_kernel_timestamp - ts_to_uint(*stamp);
         kernel_latency /= 1000u;
 
         stats->min_kernel_latency = min(kernel_latency, stats->min_kernel_latency);

packet-exchange/src/send_packet.c

@@ -56,7 +56,7 @@ static struct sock_txtime sk_txtime;
 static char *tx_buffer;
 static int sock_fd;
 
-static uint64_t timestamps_buffer[64];
+static uint64_t timestamps_buffer[TIMESTAMP_BUFFER_SIZE];
 static int ts_buf_read_index = 0;
 static int ts_buf_write_index = 0;
 
@@ -129,7 +129,8 @@ void send_udp_packet(char *data,
 
   if (params->use_timestamps) {
     clock_gettime(CLOCK_REALTIME, &ts);
-    timestamps_buffer[ts_buf_write_index++] = ts_to_uint(ts);
+    timestamps_buffer[ts_buf_write_index] = ts_to_uint(ts);
+    ts_buf_write_index = (ts_buf_write_index + 1) % TIMESTAMP_BUFFER_SIZE;
   }
 
   packets_sent++;
@@ -220,7 +221,8 @@ static void process_error_queue() {
 
       struct timespec *stamp = (struct timespec *)CMSG_DATA(cmsg);
 
-      int kernel_latency = (ts_to_uint(*stamp) - timestamps_buffer[ts_buf_read_index++]) / 1000;
+      int kernel_latency = (ts_to_uint(*stamp) - timestamps_buffer[ts_buf_read_index]) / 1000;
+      ts_buf_read_index = (ts_buf_read_index + 1) % TIMESTAMP_BUFFER_SIZE;
 
       stats->min_kernel_latency = min(kernel_latency, stats->min_kernel_latency);
       stats->max_kernel_latency = max(kernel_latency, stats->max_kernel_latency);

packet-exchange/src/server.c

@@ -271,58 +271,36 @@ static void print_histograms() {
   if (enable_timestamps) {
     printf("{\"measure_sets\": [{"
            "\"measure_type\": \"packet_recv_timestamps\","
-           "\"props_names\": [\"user_space\", \"kernel_space\"],"
-           "\"units\": [\"us\", \"us\"],"
+           "\"props_names\": [\"kernel_space\"],"
+           "\"units\": [\"us\"],"
            "\"props_type\": \"histogram\","
-           "\"metadata\": {"
-           "\"i\": \"%dus\", \"duration\": \"%dh%d\""
-           "},"
-           "\"props\": [",
+           "\"metadata\": {\"i\": \"%dus\", \"duration\": \"%dh%d\"},"
+           "\"props\": [[",
            interval, duration_hour, duration_minutes);
 
-    max_latency = 0;
-    for (int j = 0; j < MAX_KERNEL_LATENCY; j++)
-      if (kernel_latency_hist[j])
-        max_latency = j;
+    max_latency = histogram_max(kernel_latency_hist, MAX_KERNEL_LATENCY - 1);
 
-    printf("[");
     for (int j = 0; j < max_latency; j++)
       printf("%" PRIi64 "%s", kernel_latency_hist[j], (j + 1 < max_latency ? ", " : ""));
-    printf("]");
+    printf("]]");
   }
 
-  max_jitter = 0;
-  for (int j = 0; j < MAX_JITTER; j++)
-    if (jitter_hist[j])
-      max_jitter = j;
+  max_jitter = histogram_max(jitter_hist, MAX_JITTER - 1);
+  min_jitter = histogram_min(jitter_hist, MAX_JITTER - 1);
 
-  min_jitter = MAX_JITTER - 1;
-  for (int j = MAX_JITTER - 1; j >= 0; j--)
-    if (jitter_hist[j])
-      min_jitter = j;
-
-  if (!enable_timestamps)
-    printf("{\"measure_sets\": [{");
-  else
-    printf("]}, {");
+  printf("%s", enable_timestamps ? "}, {" : "{\"measure_sets\": [{");
 
   printf("\"measure_type\": \"packet_jitter\","
          "\"props_names\": [\"jitter\"],"
          "\"units\": [\"us\"],"
          "\"props_type\": \"histogram\","
          "\"middle\": \"%d\","
-         "\"metadata\": {"
-         "\"i\": \"%dus\", \"duration\": \"%dh%d\""
-         "},"
+         "\"metadata\": {\"i\": \"%dus\", \"duration\": \"%dh%d\"},"
          "\"props\": [[",
-         MAX_JITTER / 2 - min_jitter,
-         interval,
-         duration_hour,
-         duration_minutes);
+         MAX_JITTER / 2 - min_jitter, interval, duration_hour, duration_minutes);
 
   for (int j = min_jitter; j < max_jitter; j++)
     printf("%" PRIi64 "%s", jitter_hist[j], (j + 1 < max_jitter ? ", " : ""));
-
   printf("]]}]}\n");
 }
 

scripts/run_client

@@ -3,7 +3,7 @@
 script_dir=$(dirname $(realpath $0))
 
 usage() {
-  echo "Usage: $0 (-e delta [-o etf_offset] | -p) [-bg] [-i INTERVAL] [-d TX_BUFFER_LEN] [emerald|slate|onyx]" 1>&2;
+  echo "Usage: $0 (-e delta [-o etf_offset] | -p) [-bgt] [-i INTERVAL] [-d TX_BUFFER_LEN] [emerald|slate|onyx]" 1>&2;
   exit 1;
 }
 
@@ -16,7 +16,7 @@ qdisc_options=""
 ip="192.168.99."
 etf_offset=500
 
-while getopts "bd:e:o:ghi:p" opt; do
+while getopts "bd:e:o:ghi:pt" opt; do
   case "${opt}" in
     b )
         client_options+=" -b"
@@ -33,7 +33,7 @@ while getopts "bd:e:o:ghi:p" opt; do
         etf_offset=${OPTARG}
         ;;
     g )
-        client_options+=" -g -t"
+        client_options+=" -g"
         use_histogram=1
         ;;
     h )
@@ -48,6 +48,9 @@ while getopts "bd:e:o:ghi:p" opt; do
         client_options+=" -q 1"
         qdisc_options+="-p"
       ;;
+    t )
+        client_options+=" -t"
+      ;;
     * )
         usage
       ;;