From 6abd55eff09d83999c7a84e0ee63bdc3100f7666 Mon Sep 17 00:00:00 2001
From: Michael Vrable <mvrable@cs.ucsd.edu>
Date: Tue, 26 Jan 2010 14:57:52 -0800
Subject: [PATCH] Clean up logging in storage layer.

---
 bluesky/bluesky-private.h |  2 ++
 bluesky/cache.c           |  3 ---
 bluesky/s3store.c         |  3 ---
 bluesky/store.c           | 22 ++++++++++++++++------
 nfs3/nfsd.c               |  1 +
 nfs3/rpc.c                |  2 --
 6 files changed, 19 insertions(+), 14 deletions(-)

diff --git a/bluesky/bluesky-private.h b/bluesky/bluesky-private.h
index 95fc7d5..3e4d39b 100644
--- a/bluesky/bluesky-private.h
+++ b/bluesky/bluesky-private.h
@@ -64,6 +64,8 @@ typedef struct {
     int result;                 /* Result code; 0 for success. */
     struct BlueSkyNotifierList *notifiers;
 
+    bluesky_time_hires start_time;  /* Time operation was submitted. */
+
     gpointer store_private;     /* For use by the storage implementation */
 } BlueSkyStoreAsync;
 
diff --git a/bluesky/cache.c b/bluesky/cache.c
index 912c5fd..4fe4671 100644
--- a/bluesky/cache.c
+++ b/bluesky/cache.c
@@ -81,9 +81,6 @@ static void flushd_inode(gpointer key, gpointer value, gpointer user_data)
  * gradually flushed. */
 void bluesky_flushd_invoke(BlueSkyFS *fs)
 {
-    g_log("bluesky/flushd", G_LOG_LEVEL_DEBUG,
-          "Writeout process invoked");
-
     g_mutex_lock(fs->lock);
     g_hash_table_foreach(fs->inodes, flushd_inode, fs);
     g_mutex_unlock(fs->lock);
diff --git a/bluesky/s3store.c b/bluesky/s3store.c
index b4920dc..ccf0878 100644
--- a/bluesky/s3store.c
+++ b/bluesky/s3store.c
@@ -68,9 +68,6 @@ static void s3store_response_callback(S3Status status,
 {
     struct get_info *info = (struct get_info *)callbackData;
 
-    g_print("S3 operation complete, status=%s, now=%ld\n",
-            S3_get_status_name(status), bluesky_now_hires());
-
     if (status == 0) {
         info->success = 1;
     }
diff --git a/bluesky/store.c b/bluesky/store.c
index f8b3a6d..7a63b04 100644
--- a/bluesky/store.c
+++ b/bluesky/store.c
@@ -156,6 +156,8 @@ void bluesky_store_async_mark_complete(BlueSkyStoreAsync *async)
 {
     g_return_if_fail(async->status != ASYNC_COMPLETE);
 
+    bluesky_time_hires elapsed = bluesky_now_hires() - async->start_time;
+
     g_mutex_lock(async->store->lock);
     async->store->pending--;
     if (async->store->pending == 0)
@@ -170,12 +172,26 @@ void bluesky_store_async_mark_complete(BlueSkyStoreAsync *async)
         async->notifiers = nl->next;
         g_thread_pool_push(notifier_thread_pool, nl, NULL);
     }
+
+    g_log("bluesky/store", G_LOG_LEVEL_DEBUG,
+          "[%p] complete: elapsed = %"PRIi64" ns",
+          async, elapsed);
 }
 
 void bluesky_store_async_submit(BlueSkyStoreAsync *async)
 {
     BlueSkyStore *store = async->store;
 
+    async->start_time = bluesky_now_hires();
+
+    g_log("bluesky/store", G_LOG_LEVEL_DEBUG, "[%p] submit: %s %s",
+          async,
+          async->op == STORE_OP_GET ? "GET"
+            : async->op == STORE_OP_PUT ? "PUT"
+            : async->op == STORE_OP_DELETE ? "DELETE"
+            : async->op == STORE_OP_BARRIER ? "BARRIER" : "???",
+          async->key);
+
     /* Barriers are handled specially, and not handed down the storage
      * implementation layer. */
     if (async->op == STORE_OP_BARRIER) {
@@ -185,12 +201,6 @@ void bluesky_store_async_submit(BlueSkyStoreAsync *async)
         return;
     }
 
-    g_log("bluesky/store", G_LOG_LEVEL_DEBUG, "submit: %s %s",
-          async->op == STORE_OP_GET ? "GET"
-            : async->op == STORE_OP_PUT ? "PUT"
-            : async->op == STORE_OP_DELETE ? "DELETE" : "???",
-          async->key);
-
     g_mutex_lock(async->store->lock);
     async->store->pending++;
     g_mutex_unlock(async->store->lock);
diff --git a/nfs3/nfsd.c b/nfs3/nfsd.c
index e43f530..9b6ba39 100644
--- a/nfs3/nfsd.c
+++ b/nfs3/nfsd.c
@@ -30,6 +30,7 @@ int main(int argc, char *argv[])
 {
     int i;
     bluesky_init();
+    g_set_prgname("nfsd");
     register_rpc();
 
     bluesky_options.async_inode_fetches = 1;
diff --git a/nfs3/rpc.c b/nfs3/rpc.c
index 07c5d93..cda1330 100644
--- a/nfs3/rpc.c
+++ b/nfs3/rpc.c
@@ -505,8 +505,6 @@ nfs_program_3(RPCRequest *req)
     req->xdr_result = _xdr_result;
     result = (*local)((char *)req->args, req);
 
-    bluesky_debug_dump(fs);
-
     return;
 }
 
-- 
2.20.1