Merge pull request #337 from cole-miller/truncate-tracing

Add some tracing to help debug the truncate issues

Author: cole-miller

src/uv.c

@@ -156,6 +156,7 @@ static int uvStart(struct raft_io *io,
 
 void uvMaybeFireCloseCb(struct uv *uv)
 {
+    tracef("uv maybe fire close cb");
     if (!uv->closing) {
         return;
     }

src/uv_append.c

@@ -6,6 +6,8 @@
 #include "uv_encoding.h"
 #include "uv_writer.h"
 
+#define tracef(...) Tracef(uv->tracer, __VA_ARGS__)
+
 /* The happy path for an append request is:
  *
  * - If there is a current segment and it is has enough spare capacity to hold
@@ -799,6 +801,8 @@ int UvBarrier(struct uv *uv,
 
 void UvUnblock(struct uv *uv)
 {
+    tracef("uv unblock");
+    tracef("clear uv barrier");
     uv->barrier = NULL;
     if (uv->closing) {
         uvMaybeFireCloseCb(uv);
@@ -817,6 +821,7 @@ void UvUnblock(struct uv *uv)
  * we're closing and abort there. */
 static void uvBarrierClose(struct uv *uv)
 {
+    tracef("uv barrier close");
     struct UvBarrier *barrier = NULL;
     queue *head;
     assert(uv->closing);
@@ -828,6 +833,7 @@ static void uvBarrierClose(struct uv *uv)
             barrier = segment->barrier;
             barrier->cb(barrier);
             if (segment->barrier == uv->barrier) {
+                tracef("clear uv barrier");
                 uv->barrier = NULL;
             }
         }
@@ -840,6 +846,7 @@ static void uvBarrierClose(struct uv *uv)
      * too. */
     if (uv->barrier != NULL) {
         uv->barrier->cb(uv->barrier);
+        tracef("clear uv barrier");
         uv->barrier = NULL;
     }
 }

src/uv_finalize.c

@@ -75,6 +75,7 @@ static void uvFinalizeAfterWorkCb(uv_work_t *work, int status)
 {
     struct uvDyingSegment *segment = work->data;
     struct uv *uv = segment->uv;
+    tracef("uv finalize after work cb status:%d", status);
     queue *head;
     int rv;
 
@@ -88,6 +89,7 @@ static void uvFinalizeAfterWorkCb(uv_work_t *work, int status)
     /* If we have no more dismissed segments to close, check if there's a
      * barrier to unblock or if we are done closing. */
     if (QUEUE_IS_EMPTY(&uv->finalize_reqs)) {
+        tracef("unblock barrier or close");
         if (uv->barrier != NULL && UvBarrierReady(uv)) {
             uv->barrier->cb(uv->barrier);
         }

src/uv_truncate.c

@@ -23,6 +23,7 @@ static void uvTruncateWorkCb(uv_work_t *work)
 {
     struct uvTruncate *truncate = work->data;
     struct uv *uv = truncate->uv;
+    tracef("uv truncate work cb");
     struct uvSnapshotInfo *snapshots;
     struct uvSegmentInfo *segments;
     struct uvSegmentInfo *segment;
@@ -89,6 +90,7 @@ static void uvTruncateWorkCb(uv_work_t *work)
     RaftHeapFree(segments);
     truncate->status = 0;
 
+    tracef("uv truncate work cb ok");
     return;
 
 err_after_list:
@@ -105,10 +107,12 @@ static void uvTruncateAfterWorkCb(uv_work_t *work, int status)
     assert(truncate != NULL);
     struct uv *uv = truncate->uv;
     assert(uv != NULL);
+    tracef("uv truncate after work cb status:%d", status);
     assert(status == 0);
     if (truncate->status != 0) {
         uv->errored = true;
     }
+    tracef("clear truncate work");
     uv->truncate_work.data = NULL;
     RaftHeapFree(truncate);
     UvUnblock(uv);
@@ -118,10 +122,12 @@ static void uvTruncateBarrierCb(struct UvBarrier *barrier)
 {
     struct uvTruncate *truncate = barrier->data;
     struct uv *uv = truncate->uv;
+    tracef("uv truncate barrier cb");
     int rv;
 
     /* If we're closing, don't perform truncation at all and abort here. */
     if (uv->closing) {
+        tracef("closing => don't truncate");
         RaftHeapFree(truncate);
         return;
     }
@@ -131,11 +137,13 @@ static void uvTruncateBarrierCb(struct UvBarrier *barrier)
     assert(uv->finalize_work.data == NULL);
     assert(uv->truncate_work.data == NULL);
 
+    tracef("set truncate work");
     uv->truncate_work.data = truncate;
     rv = uv_queue_work(uv->loop, &uv->truncate_work, uvTruncateWorkCb,
                        uvTruncateAfterWorkCb);
     if (rv != 0) {
         tracef("truncate index %lld: %s", truncate->index, uv_strerror(rv));
+	tracef("clear truncate work");
         uv->truncate_work.data = NULL;
         uv->errored = true;
     }
@@ -148,6 +156,7 @@ int UvTruncate(struct raft_io *io, raft_index index)
     int rv;
 
     uv = io->impl;
+    tracef("uv truncate %llu", index);
     assert(!uv->closing);
 
     /* We should truncate only entries that we were requested to append in the