evtr: modularize debug output
authorAggelos Economopoulos <aoiko@cc.ece.ntua.gr>
Mon, 15 Feb 2010 18:48:58 +0000 (20:48 +0200)
committerAggelos Economopoulos <aoiko@cc.ece.ntua.gr>
Mon, 15 Feb 2010 18:51:12 +0000 (20:51 +0200)
lib/libevtr/evtr.c
lib/libevtr/evtr.h
usr.bin/evtranalyze/evtranalyze.c

index 743a987..4aa341e 100644 (file)
 
 #include "evtr.h"
 
+static unsigned evtr_debug;
+
+#define DEFINE_DEBUG_FLAG(nam, chr)            \
+       nam = chr - 'a'
+
+enum debug_flags {
+       DEFINE_DEBUG_FLAG(IO, 'i'),
+       DEFINE_DEBUG_FLAG(DS, 't'),     /* data structures */
+       DEFINE_DEBUG_FLAG(MISC, 'm'),
+};
+
+#define printd(subsys, ...)                            \
+       do {                                            \
+               if (evtr_debug & (subsys)) {    \
+                       fprintf(stderr, __VA_ARGS__);   \
+               }                                       \
+       } while (0)
+
+static
+void
+printd_set_flags(const char *str, unsigned int *flags)
+{
+       /*
+        * This is suboptimal as we don't detect
+        * invalid flags.
+        */
+       for (; *str; ++str) {
+               if ('A' == *str) {
+                       *flags = -1;
+                       return;
+               }
+               if (!islower(*str))
+                       err(2, "invalid debug flag %c\n", *str);
+               *flags |= *str - 'a';
+       }
+}
+
+
 enum {
        MAX_EVHDR_SIZE = PATH_MAX + 200,
        /* string namespaces */
@@ -201,13 +239,10 @@ struct evtr_query {
        int bufsize;
 };
 
-static int
-evtr_debug = 0;
-
 void
-evtr_set_debug(int lvl)
+evtr_set_debug(const char *str)
 {
-       evtr_debug = lvl;
+       printd_set_flags(str, &evtr_debug);
 }
 
 static int id_map_cmp(struct id_map *, struct id_map *);
@@ -218,17 +253,11 @@ static int thread_cmp(struct evtr_thread *, struct evtr_thread *);
 RB_PROTOTYPE2(thread_tree, evtr_thread, rb_node, thread_cmp, void *);
 RB_GENERATE2(thread_tree, evtr_thread, rb_node, thread_cmp, void *, id);
 
-#define printd(...)                            \
-       do {                                    \
-       if (evtr_debug)                         \
-               fprintf(stderr, __VA_ARGS__);   \
-       } while (0)
-
 static inline
 void
 validate_string(const char *str)
 {
-       if (!evtr_debug)
+       if (!(evtr_debug & MISC))
                return;
        for (; *str; ++str)
                assert(isprint(*str));
@@ -318,7 +347,7 @@ parse_format_data(evtr_event_t ev, const char *fmt, ...)
        if (strcmp(fmt, ev->fmt))
                return 0;
        vsnprintf(buf, sizeof(buf), fmt, __DECONST(void *, ev->fmtdata));
-       printd("string is: %s\n", buf);
+       printd(MISC, "string is: %s\n", buf);
        va_start(ap, fmt);
        return vsscanf(buf, fmt, ap);
 }
@@ -447,7 +476,7 @@ thread_map_find(struct thread_map *map, void *id)
                if (_cmp((type)osid->data, data)) {                     \
                        return EEXIST;                                  \
                }                                                       \
-               printd("mapping already exists, skipping\n");           \
+               printd(DS, "mapping already exists, skipping\n");               \
                /* we're OK with redefinitions of an id to the same string */ \
                return 0;                                               \
        }                                                               \
@@ -569,7 +598,6 @@ thread_creation_callback(evtr_event_t ev, void *d)
        void *ktd;
        char buf[20];
 
-       //printd("thread_creation_callback\n");
        if (parse_format_data(ev, "new_td %p %s", &ktd, buf) != 2) {
                return;
        }
@@ -586,7 +614,7 @@ thread_creation_callback(evtr_event_t ev, void *d)
                evtr->err = ENOMEM;
                return;
        }
-       printd("inserting new thread %p: %s\n", td->id, td->comm);
+       printd(DS, "inserting new thread %p: %s\n", td->id, td->comm);
        thread_map_insert(&evtr->threads, td);
 }
 
@@ -603,10 +631,9 @@ thread_switch_callback(evtr_event_t ev, void *d)
        char tidstr[40];
        char fmtdata[sizeof(void *) + sizeof(char *)];
 
-       //printd("thread_switch_callback\n");
        cpu = evtr_cpu(evtr, ev->cpu);
        if (!cpu) {
-               printd("invalid cpu %d\n", ev->cpu);
+               warnx("invalid cpu %d\n", ev->cpu);
                return;
        }
        if (parse_format_data(ev, "sw  %p > %p", &ktdp, &ktdn) != 2) {
@@ -614,7 +641,7 @@ thread_switch_callback(evtr_event_t ev, void *d)
        }
        tdp = thread_map_find(&evtr->threads, ktdp);
        if (!tdp) {
-               printd("switching from unknown thread %p\n", ktdp);
+               printd(DS, "switching from unknown thread %p\n", ktdp);
        }
        tdn = thread_map_find(&evtr->threads, ktdn);
        if (!tdn) {
@@ -639,11 +666,11 @@ thread_switch_callback(evtr_event_t ev, void *d)
 
                tdn = thread_map_find(&evtr->threads, ktdn);
                assert(tdn != NULL);
-               printd("switching to unknown thread %p\n", ktdn);
+               printd(DS, "switching to unknown thread %p\n", ktdn);
                cpu->td = tdn;
                return;
        }
-       printd("cpu %d: switching to thread %p\n", ev->cpu, ktdn);
+       printd(DS, "cpu %d: switching to thread %p\n", ev->cpu, ktdn);
        cpu->td = tdn;
 }
 
@@ -898,7 +925,7 @@ evtr_dump_string(evtr_t evtr, uint64_t ts, const char *str, int ns)
                return 0;
        }
 
-       printd("hash_insert %s ns %d id %d\n", str, ns, ent->id);
+       printd(DS, "hash_insert %s ns %d id %d\n", str, ns, ent->id);
        s.eh.type = EVTR_TYPE_STR;
        s.eh.ts = ts;
        s.ns = ns;
@@ -944,7 +971,7 @@ replace_strid(void *_ctx, const char *s)
                ctx->evtr->err = !0;
        }
        validate_string(ret);
-       printd("replacing strid %d (ns %d) with string '%s' (or int %#x)\n", (int)s,
+       printd(DS, "replacing strid %d (ns %d) with string '%s' (or int %#x)\n", (int)s,
               EVTR_NS_DSTR, ret ? ret : "NULL", (int)ret);
        return ret;
 }
@@ -1208,7 +1235,7 @@ evtr_read(evtr_t evtr, void *buf, size_t size)
 {
        assert(size > 0);
        assert_foff_in_sync(evtr);
-//     printd("evtr_read at %#jx, %zd bytes\n", evtr->bytes, size);
+       printd(IO, "evtr_read at %#jx, %zd bytes\n", evtr->bytes, size);
        if (fread(buf, size, 1, evtr->f) != 1) {
                if (feof(evtr->f)) {
                        evtr->errmsg = "incomplete record";
@@ -1261,7 +1288,7 @@ evtr_load_fmt(evtr_t evtr, char *buf)
        fmtstr[evh->fmt_len] = '\0';
        fmt->fmt = fmtstr;
 
-       printd("fmt_map_insert (%d, %s)\n", evh->id, fmt->fmt);
+       printd(DS, "fmt_map_insert (%d, %s)\n", evh->id, fmt->fmt);
        evtr->err = fmt_map_insert(&evtr->fmtmap.root, fmt, evh->id);
        switch (evtr->err) {
        case ENOMEM:
@@ -1310,7 +1337,7 @@ evtr_load_string(evtr_t evtr, char *buf)
                return !0;
        }
        validate_string(sbuf);
-       printd("evtr_load_string:ns %d id %d : \"%s\"\n", evh->ns, evh->id,
+       printd(DS, "evtr_load_string:ns %d id %d : \"%s\"\n", evh->ns, evh->id,
               sbuf);
        evtr->err = string_map_insert(&evtr->maps[evh->ns - 1].root, sbuf, evh->id);
        switch (evtr->err) {
index fc9033f..71b5299 100644 (file)
@@ -153,7 +153,7 @@ int evtr_rewind(evtr_t);
 
 int evtr_ncpus(evtr_t);
 int evtr_cpufreqs(evtr_t, double *);
-void evtr_set_debug(int);
+void evtr_set_debug(const char *);
 
 
 #endif /* EVTR_H */
index 1524f00..85af0fd 100644 (file)
@@ -30,6 +30,7 @@
  */
 
 #include <assert.h>
+#include <ctype.h>
 #include <err.h>
 #include <inttypes.h>
 #include <libgen.h>
@@ -82,15 +83,43 @@ struct command {
 
 evtr_t evtr;
 char *opt_infile;
-static int evtranalyze_debug;
+static unsigned evtranalyze_debug;
 
-#define printd(...)                                    \
+#define DEFINE_DEBUG_FLAG(nam, chr)\
+       nam = chr - 'a'
+
+enum debug_flags {
+       DEFINE_DEBUG_FLAG(INTV, 'i'),
+       DEFINE_DEBUG_FLAG(SVG, 's'),
+       DEFINE_DEBUG_FLAG(MISC, 'm'),
+};
+
+#define printd(subsys, ...)                            \
        do {                                            \
-               if (evtranalyze_debug) {                \
+               if (evtranalyze_debug & (subsys)) {     \
                        fprintf(stderr, __VA_ARGS__);   \
                }                                       \
        } while (0)
 
+static
+void
+printd_set_flags(const char *str, unsigned int *flags)
+{
+       /*
+        * This is suboptimal as we don't detect
+        * invalid flags.
+        */
+       for (; *str; ++str) {
+               if ('A' == *str) {
+                       *flags = -1;
+                       return;
+               }
+               if (!islower(*str))
+                       err(2, "invalid debug flag %c\n", *str);
+               *flags |= *str - 'a';
+       }
+}
+
 static
 void
 usage(void)
@@ -383,21 +412,19 @@ ctxsw_prepare_event(void *_ctx, evtr_event_t ev)
        struct thread_info *tdi;
 
        (void)evtr;
-       printd("test1 (%ju:%ju) : %ju\n",
+       printd(INTV, "test1 (%ju:%ju) : %ju\n",
               (uintmax_t)ctx->interval.start,
               (uintmax_t)ctx->interval.end,
               (uintmax_t)ev->ts);
        if ((ev->ts > ctx->interval.end) ||
            (ev->ts < ctx->interval.start))
                return;
-       printd("PREPEV on %d\n", ev->cpu);
+       printd(INTV, "PREPEV on %d\n", ev->cpu);
 
        /* update first/last timestamps */
        c = &cpus[ev->cpu];
        if (!c->firstlast.start) {
                c->firstlast.start = ev->ts;
-               printd("setting firstlast.start (%d) = %ju\n", ev->cpu,
-                      (uintmax_t)c->firstlast.start);
        }
        c->firstlast.end = ev->ts;
        /*
@@ -432,7 +459,7 @@ find_first_last_ts(struct cpu_table *cputab, struct ts_interval *fl)
        fl->start = -1;
        fl->end = 0;
        for (i = 0; i < cputab->ncpus; ++i) {
-               printd("cpu%d: (%ju, %ju)\n", i,
+               printd(INTV, "cpu%d: (%ju, %ju)\n", i,
                       (uintmax_t)cpus[i].firstlast.start,
                       (uintmax_t)cpus[i].firstlast.end);
                if (cpus[i].firstlast.start &&
@@ -444,7 +471,7 @@ find_first_last_ts(struct cpu_table *cputab, struct ts_interval *fl)
                cpus[i].td = NULL;
                cpus[i].ts = 0;
        }
-       printd("global (%jd, %jd)\n", (uintmax_t)fl->start, (uintmax_t)fl->end);
+       printd(INTV, "global (%jd, %jd)\n", (uintmax_t)fl->start, (uintmax_t)fl->end);
 }
 
 static
@@ -506,12 +533,12 @@ ctxsw_draw_event(void *_ctx, evtr_event_t ev)
         * ctx->firstlast.start is invalid too.
         */
        assert(!ctx->firstlast.end || (ev->ts >= ctx->firstlast.start));
-       printd("test2 (%ju:%ju) : %ju\n", (uintmax_t)ctx->interval.start,
+       printd(INTV, "test2 (%ju:%ju) : %ju\n", (uintmax_t)ctx->interval.start,
               (uintmax_t)ctx->interval.end, (uintmax_t)ev->ts);
        if ((ev->ts > ctx->interval.end) ||
            (ev->ts < ctx->interval.start))
                return;
-       printd("DRAWEV %d\n", ev->cpu);
+       printd(INTV, "DRAWEV %d\n", ev->cpu);
        if (c->td != ev->td) {  /* thread switch (or preemption) */
                draw_ctx_switch(ctx, c, ev);
                /* XXX: this is silly */
@@ -538,7 +565,7 @@ cputab_init(struct cpu_table *ct)
 
        if ((ct->ncpus = evtr_ncpus(evtr)) <= 0)
                err(1, "No cpu information!\n");
-       printd("evtranalyze: ncpus %d\n", ct->ncpus);
+       printd(MISC, "evtranalyze: ncpus %d\n", ct->ncpus);
        if (!(ct->cpus = malloc(sizeof(struct cpu) * ct->ncpus))) {
                err(1, "Can't allocate memory\n");
        }
@@ -646,7 +673,6 @@ cmd_svg(int argc, char **argv)
        td_ctx.nr_top_threads = NR_TOP_THREADS;
        cputab_init(&td_ctx.cputab);    /* needed for parse_interval() */
 
-       printd("argc: %d, argv[0] = %s\n", argc, argv[0] ? argv[0] : "NULL");
        optind = 0;
        optreset = 1;
        while ((ch = getopt(argc, argv, "i:o:")) != -1) {
@@ -698,7 +724,7 @@ cmd_svg(int argc, char **argv)
        td_ctx.thread_rows = &thread_rows;
        rows_init(td_ctx.thread_rows, td_ctx.nr_top_threads, 300, 0.9);
        td_ctx.xscale = width / (td_ctx.firstlast.end - td_ctx.firstlast.start);
-       printd("first %ju, last %ju, xscale %lf\n",
+       printd(SVG, "first %ju, last %ju, xscale %lf\n",
               (uintmax_t)td_ctx.firstlast.start, (uintmax_t)td_ctx.firstlast.end,
               td_ctx.xscale);
 
@@ -734,7 +760,7 @@ cmd_show(int argc, char **argv)
         */
        freq = cputab.cpus[0].freq;
        freq /= 1000000;        /* we want to print out usecs */
-       printd("using freq = %lf\n", freq);
+       printd(MISC, "using freq = %lf\n", freq);
        filt.fmt = NULL;
        optind = 0;
        optreset = 1;
@@ -747,7 +773,6 @@ cmd_show(int argc, char **argv)
        }
        filt.flags = 0;
        filt.cpu = -1;
-       printd("fmt = %s\n", filt.fmt ? filt.fmt : "NULL");
        q = evtr_query_init(evtr, &filt, 1);
        if (!q)
                err(1, "Can't initialize query\n");
@@ -842,6 +867,7 @@ main(int argc, char **argv)
        int ch;
        FILE *inf;
        struct command *cmd;
+       char *tmp;
 
        while ((ch = getopt(argc, argv, "f:D:")) != -1) {
                switch (ch) {
@@ -849,8 +875,11 @@ main(int argc, char **argv)
                        opt_infile = optarg;
                        break;
                case 'D':
-                       evtranalyze_debug = atoi(optarg);
-                       evtr_set_debug(evtranalyze_debug);
+                       if ((tmp = strchr(optarg, ':'))) {
+                               *tmp++ = '\0';
+                               evtr_set_debug(tmp);
+                       }
+                       printd_set_flags(optarg, &evtranalyze_debug);
                        break;
                default:
                        usage();