[Qemu-devel] [PATCH 08/26] FVD: add debugging utilities

[Chunqiang Tang <ctang@us.ibm.com>]

This patch is part of the Fast Virtual Disk (FVD) proposal.
See http://wiki.qemu.org/Features/FVD.

This patch adds some debugging utilities to FVD.

Signed-off-by: Chunqiang Tang <ctang@us.ibm.com>
---
 block/blksim.c      |    7 +-
 block/fvd-debug.c   |  369 +++++++++++++++++++++++++++++++++++++++++++++++++++
 block/fvd-ext.h     |   71 ++++++++++
 block/fvd-journal.c |   23 +++
 block/fvd.c         |    2 +
 block/fvd.h         |    1 +
 qemu-io-auto.c      |   17 ++-
 7 files changed, 478 insertions(+), 12 deletions(-)
 create mode 100644 block/fvd-debug.c
 create mode 100644 block/fvd-ext.h
 create mode 100644 block/fvd-journal.c

diff --git a/block/blksim.c b/block/blksim.c
index 5c7ef43..16e44ee 100644
--- a/block/blksim.c
+++ b/block/blksim.c
@@ -19,12 +19,7 @@
 #include "qemu-queue.h"
 #include "qemu-common.h"
 #include "block/blksim.h"
-
-#if 1
-# define QDEBUG(format,...) do {} while (0)
-#else
-# define QDEBUG printf
-#endif
+#include "block/fvd-ext.h"
 
 typedef enum
 {
diff --git a/block/fvd-debug.c b/block/fvd-debug.c
new file mode 100644
index 0000000..36b4c43
--- /dev/null
+++ b/block/fvd-debug.c
@@ -0,0 +1,369 @@
+/*
+ * QEMU Fast Virtual Disk Format Debugging Utilities
+ *
+ * Copyright IBM, Corp. 2010
+ *
+ * Authors:
+ *    Chunqiang Tang <ctang@us.ibm.com>
+ *
+ * This work is licensed under the terms of the GNU GPL, version 2 or later.
+ * See the COPYING.LIB file in the top-level directory.
+ *
+ */
+
+#ifndef ENABLE_TRACE_IO
+#define TRACE_REQUEST(...) do {} while (0)
+#define TRACE_STORE_IN_FVD(...) do {} while (0)
+
+#else
+
+static void TRACE_REQUEST(int do_write, int64_t sector_num, int nb_sectors)
+{
+    if (do_write) {
+        QDEBUG("TRACE_REQUEST: write sector_num=%" PRId64
+               " nb_sectors=%d    [ ", sector_num, nb_sectors);
+    } else {
+        QDEBUG("TRACE_REQUEST: read  sector_num=%" PRId64 " nb_sectors=%d    "
+               "[ ", sector_num, nb_sectors);
+    }
+
+    int64_t end = sector_num + nb_sectors;
+    int64_t sec;
+    for (sec = sector_num; sec < end; sec++) {
+        QDEBUG("sec%" PRId64 " ", sec);
+    }
+    QDEBUG(" ]\n");
+}
+
+static void TRACE_STORE_IN_FVD(const char *str, int64_t sector_num,
+                               int nb_sectors)
+{
+    QDEBUG("TRACE_STORE: %s sector_num=%" PRId64 " nb_sectors=%d   [ ",
+           str, sector_num, nb_sectors);
+    int64_t end = sector_num + nb_sectors;
+    int64_t sec;
+    for (sec = sector_num; sec < end; sec++) {
+        QDEBUG("sec%" PRId64 " ", sec);
+    }
+    QDEBUG(" ]\n");
+}
+#endif
+
+#ifndef FVD_DEBUG
+#define my_qemu_malloc qemu_malloc
+#define my_qemu_mallocz qemu_mallocz
+#define my_qemu_blockalign qemu_blockalign
+#define my_qemu_free qemu_free
+#define my_qemu_vfree qemu_vfree
+#define my_qemu_aio_get qemu_aio_get
+#define my_qemu_aio_release qemu_aio_release
+#define COPY_UUID(to,from) do {} while (0)
+
+#else
+FILE *__fvd_debug_fp;
+static unsigned long long int fvd_uuid = 1;
+static int64_t pending_qemu_malloc = 0;
+static int64_t pending_qemu_aio_get = 0;
+static int64_t pending_local_writes = 0;
+static const char *alloc_file;
+static int alloc_line;
+
+#define my_qemu_malloc(size) \
+    ((void*)(alloc_file=__FILE__, alloc_line=__LINE__, _my_qemu_malloc(size)))
+
+#define my_qemu_mallocz(size) \
+    ((void*)(alloc_file=__FILE__, alloc_line=__LINE__, _my_qemu_mallocz(size)))
+
+#define my_qemu_blockalign(bs,size) \
+    ((void*)(alloc_file=__FILE__, \
+             alloc_line=__LINE__, \
+             _my_qemu_blockalign(bs,size)))
+
+#define my_qemu_aio_get(pool,bs,cb,op) \
+    ((void*)(alloc_file=__FILE__, \
+             alloc_line=__LINE__, \
+             _my_qemu_aio_get(pool,bs,cb,op)))
+
+#define my_qemu_free(p) \
+    (alloc_file=__FILE__, alloc_line=__LINE__, _my_qemu_free(p))
+
+#define my_qemu_vfree(p) \
+    (alloc_file=__FILE__, alloc_line=__LINE__, _my_qemu_vfree(p))
+
+static void COPY_UUID(FvdAIOCB * to, FvdAIOCB * from)
+{
+    if (from) {
+        to->uuid = from->uuid;
+        FVD_DEBUG_ACB(to);
+    }
+}
+
+#ifdef DEBUG_MEMORY_LEAK
+#define MAX_TRACER 10485760
+static int alloc_tracer_used = 1;       /* slot 0 is not used. */
+static void **alloc_tracers = NULL;
+
+static void __attribute__ ((constructor)) init_mem_alloc_tracers(void)
+{
+    if (!alloc_tracers) {
+        alloc_tracers = qemu_mallocz(sizeof(void *) * MAX_TRACER);
+    }
+}
+
+static void trace_alloc(void *p, size_t size)
+{
+    alloc_tracer_t *t = p;
+    t->magic = FVD_ALLOC_MAGIC;
+    t->alloc_file = alloc_file;
+    t->alloc_line = alloc_line;
+    t->size = size;
+
+    if (alloc_tracer_used < MAX_TRACER) {
+        t->alloc_tracer = alloc_tracer_used++;
+        alloc_tracers[t->alloc_tracer] = t;
+        QDEBUG("Allocate memory using tracer%d in %s on line %d.\n",
+               t->alloc_tracer, alloc_file, alloc_line);
+    } else {
+        t->alloc_tracer = 0;
+    }
+
+    /* Set header and footer to detect out-of-range writes. */
+    if (size != (size_t) - 1) {
+        uint8_t *q = (uint8_t *) p;
+        uint64_t *header = (uint64_t *) (q + 512 - sizeof(uint64_t));
+        uint64_t *footer = (uint64_t *) (q + size - 512);
+        *header = FVD_ALLOC_MAGIC;
+        *footer = FVD_ALLOC_MAGIC;
+    }
+}
+
+static void trace_free(void *p)
+{
+    alloc_tracer_t *t = p;
+
+    QDEBUG("Free memory with tracer%d in %s on line %d.\n",
+           t->alloc_tracer, alloc_file, alloc_line);
+    ASSERT(t->magic == FVD_ALLOC_MAGIC && t->alloc_tracer >= 0);
+
+    /* Check header and footer to detect out-of-range writes. */
+    if (t->size != (size_t) - 1) {
+        uint8_t *q = (uint8_t *) p;
+        uint64_t *header = (uint64_t *) (q + 512 - sizeof(uint64_t));
+        uint64_t *footer = (uint64_t *) (q + t->size - 512);
+        ASSERT(*header == FVD_ALLOC_MAGIC);
+        ASSERT(*footer == FVD_ALLOC_MAGIC);
+    }
+
+    if (t->alloc_tracer) {
+        ASSERT(alloc_tracers[t->alloc_tracer] == t);
+        alloc_tracers[t->alloc_tracer] = NULL;
+        t->alloc_tracer = -INT_MAX;
+    } else {
+        t->alloc_tracer *= -1;  /* Guard against double free. */
+    }
+}
+
+static void dump_alloc_tracers(void)
+{
+    int unfreed = 0;
+    int i;
+    for (i = 1; i < alloc_tracer_used; i++) {
+        if (!alloc_tracers[i]) {
+            continue;
+        }
+
+        unfreed++;
+        alloc_tracer_t *t = alloc_tracers[i];
+
+        if (t->size == (size_t) - 1) {
+            FvdAIOCB *acb = container_of(alloc_tracers[i], FvdAIOCB, tracer);
+            ASSERT(acb->magic == FVDAIOCB_MAGIC);
+            QDEBUG("Memory %p with tracer%d allocated in %s on line %d "
+                   "(FvdAIOCB acb%llu-%p) is not freed. magic %s\n",
+                   alloc_tracers[i], i, t->alloc_file, t->alloc_line,
+                   acb->uuid, acb,
+                   t->magic == FVD_ALLOC_MAGIC ? "correct" : "wrong");
+        } else {
+            QDEBUG("Memory %p with tracer%d allocated in %s on line %d is "
+                   "not freed. magic %s\n",
+                   alloc_tracers[i], i, t->alloc_file, t->alloc_line,
+                   t->magic == FVD_ALLOC_MAGIC ? "correct" : "wrong");
+
+            uint8_t *q = (uint8_t *) t;
+            uint64_t *header = (uint64_t *) (q + 512 - sizeof(uint64_t));
+            uint64_t *footer = (uint64_t *) (q + t->size - 512);
+            ASSERT(*header == FVD_ALLOC_MAGIC);
+            ASSERT(*footer == FVD_ALLOC_MAGIC);
+        }
+    }
+
+    QDEBUG("Unfreed memory allocations: %d\n", unfreed);
+}
+#endif
+
+static inline void *_my_qemu_aio_get(AIOPool * pool, BlockDriverState * bs,
+                                     BlockDriverCompletionFunc * cb,
+                                     void *opaque)
+{
+    pending_qemu_aio_get++;
+    FvdAIOCB *acb = (FvdAIOCB *) qemu_aio_get(&fvd_aio_pool, bs, cb, opaque);
+    acb->uuid = ++fvd_uuid;
+    acb->magic = FVDAIOCB_MAGIC;
+
+    FVD_DEBUG_ACB(acb);
+
+#ifdef DEBUG_MEMORY_LEAK
+    trace_alloc(&acb->tracer, -1);
+#endif
+
+    return acb;
+}
+
+static inline void my_qemu_aio_release(void *p)
+{
+    pending_qemu_aio_get--;
+    ASSERT(pending_qemu_aio_get >= 0);
+
+#ifdef DEBUG_MEMORY_LEAK
+    FvdAIOCB *acb = p;
+    trace_free(&acb->tracer);
+#endif
+
+    qemu_aio_release(p);
+}
+
+static inline void *_my_qemu_malloc(size_t size)
+{
+    ASSERT(size > 0);
+    pending_qemu_malloc++;
+#ifndef DEBUG_MEMORY_LEAK
+    return qemu_malloc(size);
+#else
+
+    size += 1024;       /* 512 bytes header and 512 bytes footer. */
+    uint8_t *ret = qemu_malloc(size);
+    trace_alloc(ret, size);
+    return ret + 512;
+#endif
+}
+
+static inline void *_my_qemu_mallocz(size_t size)
+{
+    ASSERT(size > 0);
+    pending_qemu_malloc++;
+#ifndef DEBUG_MEMORY_LEAK
+    return qemu_mallocz(size);
+#else
+
+    size += 1024;       /* 512 bytes header and 512 bytes footer. */
+    uint8_t *ret = qemu_mallocz(size);
+    trace_alloc(ret, size);
+    return ret + 512;
+#endif
+}
+
+static inline void *_my_qemu_blockalign(BlockDriverState * bs, size_t size)
+{
+    ASSERT(size > 0);
+    pending_qemu_malloc++;
+
+#ifndef DEBUG_MEMORY_LEAK
+    return qemu_blockalign(bs, size);
+#else
+
+    size += 1024;       /* 512 bytes header and 512 bytes footer. */
+    uint8_t *ret = qemu_blockalign(bs, size);
+    trace_alloc(ret, size);
+    return ret + 512;
+#endif
+}
+
+static inline void _my_qemu_free(void *ptr)
+{
+    pending_qemu_malloc--;
+    ASSERT(pending_qemu_malloc >= 0);
+#ifndef DEBUG_MEMORY_LEAK
+    qemu_free(ptr);
+#else
+
+    uint8_t *q = ((uint8_t *) ptr) - 512;
+    trace_free(q);
+    qemu_free(q);
+#endif
+}
+
+static inline void _my_qemu_vfree(void *ptr)
+{
+    pending_qemu_malloc--;
+    ASSERT(pending_qemu_malloc >= 0);
+#ifndef DEBUG_MEMORY_LEAK
+    qemu_vfree(ptr);
+#else
+
+    uint8_t *q = ((uint8_t *) ptr) - 512;
+    trace_free(q);
+    qemu_vfree(q);
+#endif
+}
+
+static void count_pending_requests(BDRVFvdState * s)
+{
+    int m = 0, n = 0, k = 0;
+    FvdAIOCB *w;
+
+    QLIST_FOREACH(w, &s->copy_locks, copy_lock.next) {
+        m++;
+        QDEBUG("copy_lock: acb%llu-%p\n", w->uuid, w);
+    }
+
+    QLIST_FOREACH(w, &s->write_locks, write.next_write_lock) {
+        k++;
+        QDEBUG("write_lock: acb%llu-%p\n", w->uuid, w);
+    }
+
+    if (s->use_bjnl) {
+        QTAILQ_FOREACH(w, &s->bjnl.queued_bufs, jcb.bjnl_next_queued_buf) {
+            n++;
+            QDEBUG("bjnl.pending_write: acb%llu-%p\n", w->uuid, w);
+        }
+    } else {
+        QLIST_FOREACH(w, &s->ujnl.wait4_recycle, jcb.ujnl_next_wait4_recycle) {
+            n++;
+            QDEBUG("ujnl.wait4_recycle: acb%llu-%p\n", w->uuid, w);
+        }
+    }
+
+    QDEBUG("Debug_memory_leak: copy_locks=%d  write_locks=%d "
+           "journal_locks=%d\n", m, k, n);
+}
+
+static void dump_resource_summary(BDRVFvdState * s)
+{
+#ifdef DEBUG_MEMORY_LEAK
+    dump_alloc_tracers();
+#endif
+
+    QDEBUG("Resource summary: outstanding_copy_on_read_data=%" PRId64
+           " total_copy_on_read_data=%" PRId64 " total_prefetch_data=%" PRId64
+           " " " pending_qemu_malloc=%" PRId64 " pending_qemu_aio_get=%" PRId64
+           " pending_local_writes=%" PRId64 "\n",
+           s->outstanding_copy_on_read_data, s->total_copy_on_read_data,
+           s->total_prefetch_data, pending_qemu_malloc, pending_qemu_aio_get,
+           pending_local_writes);
+    count_pending_requests(s);
+}
+
+void init_fvd_debug_fp(void)
+{
+    char buf[256];
+    sprintf(buf, "/tmp/fvd.log-%d", getpid());
+    if ((__fvd_debug_fp = fopen(buf, "wt")) == NULL) {
+        __fvd_debug_fp = stdout;
+    }
+}
+#endif
+
+void fvd_check_memory_leak(void)
+{
+    ASSERT(pending_qemu_malloc == 0);
+}
diff --git a/block/fvd-ext.h b/block/fvd-ext.h
new file mode 100644
index 0000000..641b9e9
--- /dev/null
+++ b/block/fvd-ext.h
@@ -0,0 +1,71 @@
+/*
+ * QEMU Fast Virtual Disk Format Exported Symbols
+ *
+ * Copyright IBM, Corp. 2010
+ *
+ * Authors:
+ *    Chunqiang Tang <ctang@us.ibm.com>
+ *
+ * This work is licensed under the terms of the GNU GPL, version 2 or later.
+ * See the COPYING.LIB file in the top-level directory.
+ *
+ */
+
+/*=============================================================================
+ *  A short description: this header file contains functions of the FVD block
+ *  device driver that are used by other external modules. These functions are
+ *  mainly for testing and debugging urposes.
+ *============================================================================*/
+
+#ifndef __fvd_ext_h__
+#define __fvd_ext_h__
+
+//#define FVD_DEBUG
+//#define ENABLE_QDEBUG
+
+void fvd_check_memory_leak (void);
+void fvd_init_prefetch (void * bs);
+void fvd_emulate_host_crash (bool cond);
+
+#ifndef FVD_DEBUG
+# define ASSERT(x) do {} while (0)
+# define FVD_DEBUG_ACB(...) do {} while (0)
+# define QPAUSE(...) do {} while (0)
+# undef ENABLE_QDEBUG
+
+#else
+
+extern FILE *__fvd_debug_fp;
+void init_fvd_debug_fp(void);
+void FVD_DEBUG_ACB(void *p);
+
+# define ASSERT(x) \
+    do { \
+        if (!(x)) { \
+            fprintf(stderr, "Assertion failed in process %d at %s:%d. Wait.", \
+                    getpid(),__FILE__, __LINE__); \
+            fgetc (stdin); abort(); \
+        } \
+    } while (0) \
+
+# define QPAUSE(format,...) \
+    do { \
+        fprintf(stderr, format, ##__VA_ARGS__); \
+        fprintf(stderr, " Pause process %d for debugging...\n", getpid()); \
+        fgetc(stdin); \
+    } while (0)
+
+#endif
+
+#ifndef ENABLE_QDEBUG
+# define QDEBUG(format,...) do {} while (0)
+#else
+# define QDEBUG(format,...) \
+    do { \
+        if (__fvd_debug_fp==NULL) init_fvd_debug_fp(); \
+        fprintf(__fvd_debug_fp, format, ##__VA_ARGS__); \
+        fflush(__fvd_debug_fp); \
+    } while(0)
+#endif
+
+#endif
diff --git a/block/fvd-journal.c b/block/fvd-journal.c
new file mode 100644
index 0000000..5824e35
--- /dev/null
+++ b/block/fvd-journal.c
@@ -0,0 +1,23 @@
+/*
+ * QEMU Fast Virtual Disk Format Metadata Journal
+ *
+ * Copyright IBM, Corp. 2010
+ *
+ * Authors:
+ *    Chunqiang Tang <ctang@us.ibm.com>
+ *
+ * This work is licensed under the terms of the GNU GPL, version 2 or later.
+ * See the COPYING.LIB file in the top-level directory.
+ *
+ */
+
+#ifdef FVD_DEBUG
+static bool emulate_host_crash = true;
+#else
+static bool emulate_host_crash = false;
+#endif
+
+void fvd_emulate_host_crash(bool cond)
+{
+    emulate_host_crash = cond;
+}
diff --git a/block/fvd.c b/block/fvd.c
index bc2645c..13fe940 100644
--- a/block/fvd.c
+++ b/block/fvd.c
@@ -25,6 +25,7 @@
 
 /* Use include to avoid exposing too many FVD symbols, and to allow inline
  * function optimization. */
+#include "block/fvd-debug.c"
 #include "block/fvd-flush.c"
 #include "block/fvd-update.c"
 #include "block/fvd-misc.c"
@@ -32,6 +33,7 @@
 #include "block/fvd-open.c"
 #include "block/fvd-read.c"
 #include "block/fvd-write.c"
+#include "block/fvd-journal.c"
 
 static BlockDriver bdrv_fvd = {
     .format_name = "fvd",
diff --git a/block/fvd.h b/block/fvd.h
index b83b7aa..9847e7f 100644
--- a/block/fvd.h
+++ b/block/fvd.h
@@ -18,6 +18,7 @@
 #include "block.h"
 #include "qemu-queue.h"
 #include "qemu-common.h"
+#include "block/fvd-ext.h"
 
 enum {
     FVD_MAGIC = ('F' | 'V' << 8 | 'D' << 16 | '\0' << 24),
diff --git a/qemu-io-auto.c b/qemu-io-auto.c
index 73d79c7..67c84f8 100644
--- a/qemu-io-auto.c
+++ b/qemu-io-auto.c
@@ -35,14 +35,9 @@
 #include "qemu-timer.h"
 #include "qemu-common.h"
 #include "block_int.h"
+#include "block/fvd-ext.h"
 #include "block/blksim.h"
 
-#if 1
-# define QDEBUG(format,...) do {} while (0)
-#else
-# define QDEBUG printf
-#endif
-
 #define die(format,...) \
     do { \
         fprintf (stderr, "%s:%d --- ", __FILE__, __LINE__); \
@@ -582,6 +577,11 @@ static void open_test_file(const char *format, const char *test_file, int flags)
     if (bdrv_open(bs, test_file, flags, drv) < 0) {
         die("Failed to open '%s'\n", test_file);
     }
+
+    if (!strncmp(bs->drv->format_name, "fvd", 3)) {
+        bool emulate_crash = (rand() % 10 != 0);      /* Random crash test. */
+        fvd_emulate_host_crash(emulate_crash);
+    }
 }
 
 static void perform_test(const char *truth_file, const char *test_file,
@@ -688,7 +688,12 @@ static void perform_test(const char *truth_file, const char *test_file,
     }
 
     printf("Test process %d finished successfully\n", getpid());
+
+    int is_fvd = (strncmp(bs->drv->format_name, "fvd", 3) == 0);
     bdrv_delete(bs);
+    if (is_fvd) {
+        fvd_check_memory_leak();
+    }
     close(fd);
 }
 
-- 
1.7.0.4