X-Git-Url: http://git.vrable.net/?a=blobdiff_plain;f=bluesky%2Fstore.c;h=50d7a21d3f8793eafc9303a0707b266e1818576e;hb=d7d143ef0ccf0f49a8fd23a3c76bc68c0b04e07e;hp=eea44f2e72c47eb0b09dc7441b3a230871f250fc;hpb=fb15c75f3c8eeb3d7b277795ced44bb4928273a1;p=bluesky.git

diff --git a/bluesky/store.c b/bluesky/store.c
index eea44f2..50d7a21 100644
--- a/bluesky/store.c
+++ b/bluesky/store.c
@@ -197,6 +197,7 @@ 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;
+    bluesky_time_hires latency = bluesky_now_hires() - async->exec_time;
 
     g_mutex_lock(async->store->lock);
     async->store->pending--;
@@ -217,8 +218,8 @@ void bluesky_store_async_mark_complete(BlueSkyStoreAsync *async)
     }
 
     g_log("bluesky/store", G_LOG_LEVEL_DEBUG,
-          "[%p] complete: elapsed = %"PRIi64" ns",
-          async, elapsed);
+          "[%p] complete: elapsed = %"PRIi64" ns, latency = %"PRIi64" ns",
+          async, elapsed, latency);
 }
 
 void bluesky_store_async_submit(BlueSkyStoreAsync *async)
@@ -227,6 +228,10 @@ void bluesky_store_async_submit(BlueSkyStoreAsync *async)
 
     async->start_time = bluesky_now_hires();
 
+    // Backends should fill this in with a better estimate of the actual time
+    // processing was started, if there could be a delay from submission time.
+    async->exec_time = bluesky_now_hires();
+
     g_log("bluesky/store", G_LOG_LEVEL_DEBUG, "[%p] submit: %s %s",
           async,
           async->op == STORE_OP_GET ? "GET"