From 7589a41dc9e5b1f8b9f622be0c2970b3c697ed83 Mon Sep 17 00:00:00 2001
From: Michael Vrable <mvrable@cs.ucsd.edu>
Date: Wed, 16 Mar 2011 11:56:55 -0700
Subject: [PATCH] More work on the synthetic read benchmark

---
 nfs3/parse-synread.py | 33 +++++++++++++++++++++++++++++++++
 nfs3/synreadbench.c   | 24 ++++++++++++++++++++----
 2 files changed, 53 insertions(+), 4 deletions(-)
 create mode 100755 nfs3/parse-synread.py

diff --git a/nfs3/parse-synread.py b/nfs3/parse-synread.py
new file mode 100755
index 0000000..be718b8
--- /dev/null
+++ b/nfs3/parse-synread.py
@@ -0,0 +1,33 @@
+#!/usr/bin/python
+
+import struct, sys
+
+DATAPOINT = '<II'
+
+def load_log(f):
+    data = []
+    size = struct.calcsize(DATAPOINT)
+    d = f.read(size)
+    while len(d) == size:
+        i = struct.unpack(DATAPOINT, d)
+        data.append(i)
+        d = f.read(size)
+    return data
+
+if __name__ == '__main__':
+    data = []
+    for f in sys.argv[1:]:
+        data += load_log(open(f))
+    data.sort()
+
+    duration = data[-1][0] - data[0][0]
+    print "Time span: %d to %d (%d seconds)" % (data[0][0], data[-1][0], duration)
+
+    start = data[0][0] + 5
+    end = data[-1][0] - 5
+    truncated = [d for d in data if start <= d[0] <= end]
+    print len(data), len(truncated)
+    duration = float(end - start + 1)
+    print duration
+    print "Ops per second:", len(truncated) / duration
+    print "Bandwidth:", len(truncated) / duration * 32768
diff --git a/nfs3/synreadbench.c b/nfs3/synreadbench.c
index f4d5ad2..762bb64 100644
--- a/nfs3/synreadbench.c
+++ b/nfs3/synreadbench.c
@@ -35,6 +35,8 @@
 /* Maximum size of a single RPC message that we will accept (8 MB). */
 #define MAX_RPC_MSGSIZE (8 << 20)
 
+FILE *logfile = NULL;
+
 int threads;
 int completed = 0;
 int read_size = 32768;
@@ -44,6 +46,11 @@ struct bench_file {
     uint64_t size;
 };
 
+struct data_point {
+    uint32_t timestamp;     // Unix timestamp of completion
+    uint32_t latency;       // Latency, in microseconds
+} __attribute__((packed));
+
 GArray *bench_files;
 
 struct rpc_reply {
@@ -187,19 +194,27 @@ static void process_reply(NFSConnection *nfs, GString *msg)
         return;
     }
 
+    struct data_point d;
     info->end = now_hires();
-    printf("XID %d: Time = %"PRIi64"\n", xid, info->end - info->start);
+    d.timestamp = info->end / 1000000000;
+    d.latency = (info->end - info->start + 500) / 1000; /* Round off */
+    //printf("XID %d: Time = %"PRIi64"\n", xid, info->end - info->start);
     if (info->callback != NULL)
         info->callback(nfs, info->user_data,
                        msg->str + sizeof(*reply), msg->len - sizeof(*reply));
 
     g_hash_table_remove(nfs->xid_table, key);
     g_free(info);
+    if (logfile != NULL) {
+        fwrite(&d, sizeof(d), 1, logfile);
+        fflush(logfile);
+    }
 
     completed++;
+    /*
     if (completed == 128 * threads) {
         g_main_loop_quit(main_loop);
-    }
+    } */
 }
 
 static gboolean read_handler(GIOChannel *channel,
@@ -298,8 +313,6 @@ static void submit_random_read(NFSConnection *nfs)
 static void finish_read_request(NFSConnection *nfs, gpointer user_data,
                                 const char *reply, size_t len)
 {
-    printf("Done reading inode %d\n", GPOINTER_TO_INT(user_data));
-
     submit_random_read(nfs);
 }
 
@@ -427,12 +440,15 @@ int main(int argc, char *argv[])
         bf.size = i2;
         g_array_append_val(bench_files, bf);
     }
+    fclose(inodes);
 
     threads = 8;
     if (argc > 2)
         threads = atoi(argv[2]);
     if (argc > 3)
         read_size = atoi(argv[3]);
+    if (argc > 4)
+        logfile = fopen(argv[4], "wb");
 
     main_loop = g_main_loop_new(NULL, FALSE);
     nfs_connect("niniel.sysnet.ucsd.edu");
-- 
2.20.1