debug: add timestamps for debug messages

Timestamps on debug messages help establish what takes long to process.
Debug messages are print only if DDEBUG flag is passed.

Add timestamps for debug messages. Remove dead code from dprintf dummies
for non-debug builds. Remove timestamps from current debug messages.

Signed-off-by: Mateusz Kusiak <mateusz.kusiak@intel.com>

diff --git a/mdadm.h b/mdadm.h
index 5aa50854a250a3d156e34817762b49cde7f5b832..b9945a29d9504bd89364f914a787e2ed59491993 100644 (file)
--- a/mdadm.h
+++ b/mdadm.h
@@ -1899,15 +1899,23 @@ static inline sighandler_t signal_s(int sig, sighandler_t handler)
 }
 
 #ifdef DEBUG
+#include <time.h>
+
 #define dprintf(fmt, arg...) \
-       fprintf(stderr, "%s: %s: "fmt, Name, __func__, ##arg)
+       do { \
+               struct timespec ts; \
+               clock_gettime(CLOCK_MONOTONIC, &ts); \
+               double timestamp = ts.tv_sec + ts.tv_nsec / 1e9; \
+               fprintf(stderr, "[%10.5f] %s: %s: " fmt, timestamp, Name, __func__, ##arg); \
+       } while (0)
+
 #define dprintf_cont(fmt, arg...) \
        fprintf(stderr, fmt, ##arg)
 #else
 #define dprintf(fmt, arg...) \
-        ({ if (0) fprintf(stderr, "%s: %s: " fmt, Name, __func__, ##arg); 0; })
+       do { } while (0)
 #define dprintf_cont(fmt, arg...) \
-        ({ if (0) fprintf(stderr, fmt, ##arg); 0; })
+       do { } while (0)
 #endif
 
 static inline int xasprintf(char **strp, const char *fmt, ...) {

diff --git a/monitor.c b/monitor.c
index 81ae88934f30e9cbe4252d2d4938bece1cba04bd..3c54f8cb24868b62f8a36a862209f35e82263141 100644 (file)
--- a/monitor.c
+++ b/monitor.c
@@ -406,7 +406,6 @@ static int read_and_act(struct active_array *a)
        struct mdinfo *mdi;
        int ret = 0;
        int count = 0;
-       struct timeval tv;
        bool write_checkpoint = false;
 
        a->next_state = bad_word;
@@ -453,10 +452,8 @@ static int read_and_act(struct active_array *a)
                check_for_cleared_bb(a, mdi);
        }
 
-       gettimeofday(&tv, NULL);
-       dprintf("(%d): %ld.%06ld state:%s prev:%s action:%s prev: %s start:%llu\n",
+       dprintf("(%d): state:%s prev:%s action:%s prev: %s start:%llu\n",
                a->info.container_member,
-               tv.tv_sec, tv.tv_usec,
                array_states[a->curr_state],
                array_states[a->prev_state],
                sync_actions[a->curr_action],

diff --git a/super-intel.c b/super-intel.c
index 55c71e262e03a9716bf1509d51ab9a9c05f9d47a..87026f5a0e80fec36b9523e34b7d3094a682413c 100644 (file)
--- a/super-intel.c
+++ b/super-intel.c
@@ -5092,7 +5092,6 @@ imsm_thunderdome(struct intel_super **super_list, int len)
        for (i = 0; i < tbl_size; i++) {
                struct imsm_disk *d;
                struct intel_disk *idisk;
-               struct imsm_super *mpb = super_table[i]->anchor;
 
                s = super_table[i];
                d = &s->disks->disk;
@@ -5108,7 +5107,7 @@ imsm_thunderdome(struct intel_super **super_list, int len)
 
                if (!s)
                        dprintf("marking family: %#x from %d:%d offline\n",
-                               mpb->family_num,
+                               super_table[i]->anchor->family_num,
                                super_table[i]->disks->major,
                                super_table[i]->disks->minor);
                super_table[i] = s;