From: Michael Vrable <mvrable@cs.ucsd.edu>
Date: Thu, 10 Mar 2011 19:17:33 +0000 (-0800)
Subject: Add a debug option to dump statistics counters every ten seconds
X-Git-Url: https://git.vrable.net/?a=commitdiff_plain;h=e282bc08ad6c2a69a38af6a9179947af70ac0b17;p=bluesky.git

Add a debug option to dump statistics counters every ten seconds

Data is appended to a file, so that it can be analyzed later.  Timestamps
are incldued to align results with benchmarks.
---

diff --git a/bluesky/bluesky.h b/bluesky/bluesky.h
index 9921091..5ef2f28 100644
--- a/bluesky/bluesky.h
+++ b/bluesky/bluesky.h
@@ -54,6 +54,7 @@ struct bluesky_stats {
 struct bluesky_stats *bluesky_stats_new(const char *name);
 void bluesky_stats_add(struct bluesky_stats *stats, int64_t value);
 void bluesky_stats_dump_all();
+void bluesky_stats_run_periodic_dump(FILE *f);
 
 /* BlueSky status and error codes.  Various frontends should translate these to
  * the appropriate error code for whatever protocol they implement. */
diff --git a/bluesky/debug.c b/bluesky/debug.c
index 7de5095..bea8322 100644
--- a/bluesky/debug.c
+++ b/bluesky/debug.c
@@ -166,3 +166,48 @@ void bluesky_stats_dump_all()
     }
     g_static_mutex_unlock(&stats_lock);
 }
+
+static void periodic_stats_dumper(FILE *f)
+{
+    const int64_t interval = 10 * 1000000000ULL;
+    bluesky_time_hires timestamp = bluesky_now_hires();
+    bluesky_time_hires next_timestamp = timestamp;
+
+    while (TRUE) {
+        g_static_mutex_lock(&stats_lock);
+        timestamp = bluesky_now_hires();
+        fprintf(f, "********\ntime=%f\n\n", timestamp / 1e9);
+        for (GList *item = stats_list; item != NULL; item = item->next) {
+            struct bluesky_stats *stats = (struct bluesky_stats *)item->data;
+            fprintf(f, "%s: count=%"PRIi64" sum=%"PRIi64"\n",
+                    stats->name, stats->count, stats->sum);
+        }
+        g_static_mutex_unlock(&stats_lock);
+        fflush(f);
+
+        /* Wait until ten seconds from the last timestamp, with a few extra
+         * checks for sanity (always try to wait some amount of time in the
+         * range [0, 20] seconds). */
+        timestamp = bluesky_now_hires();
+        next_timestamp += interval;
+        if (next_timestamp < timestamp) {
+            next_timestamp = timestamp;
+            continue;
+        }
+        if (next_timestamp - timestamp > 2 * interval) {
+            next_timestamp = timestamp + interval;
+        }
+
+        struct timespec delay;
+        delay.tv_sec = (next_timestamp - timestamp) / 1000000000;
+        delay.tv_nsec = (next_timestamp - timestamp) % 1000000000;
+        nanosleep(&delay, NULL);
+    }
+}
+
+/* Start a background thread that will periodically dump statistics counters to
+ * he specified file every ten seconds. */
+void bluesky_stats_run_periodic_dump(FILE *f)
+{
+    g_thread_create((GThreadFunc)periodic_stats_dumper, f, FALSE, NULL);
+}
diff --git a/nfs3/nfsd.c b/nfs3/nfsd.c
index e95ac7c..40d7a6e 100644
--- a/nfs3/nfsd.c
+++ b/nfs3/nfsd.c
@@ -64,6 +64,10 @@ int main(int argc, char *argv[])
     store = bluesky_store_new(target);
     fs = bluesky_init_fs("export", store, key);
 
+    const char *stats_output = getenv("BLUESKY_STATS_OUT");
+    if (stats_output != NULL)
+        bluesky_stats_run_periodic_dump(fopen(stats_output, "a"));
+
     bluesky_crypt_random_bytes(nfsd_instance_verf_cookie,
                                sizeof(nfsd_instance_verf_cookie));