Add some basic debug output for log compression
authorJens Axboe <axboe@fb.com>
Wed, 9 Jul 2014 21:01:03 +0000 (23:01 +0200)
committerJens Axboe <axboe@fb.com>
Wed, 9 Jul 2014 21:01:03 +0000 (23:01 +0200)
Guarded by --debug=compress, like the other debug measures.

Signed-off-by: Jens Axboe <axboe@fb.com>
README
debug.h
init.c
iolog.c

diff --git a/README b/README
index 457b83dced1ff21ba90057bf3657b44131d9b76c..e378d3b0cd2a334787ccbeaa47835ab4610eb2c6 100644 (file)
--- a/README
+++ b/README
@@ -210,6 +210,7 @@ Currently, additional logging is available for:
        time            Dump info related to internal time keeping
        net             Dump info related to networking connections
        rate            Dump info related to IO rate switching
+       compress        Dump info related to log compress/decompress
        ? or help       Show available debug options.
 
 One can specify multiple debug options: e.g. --debug=file,mem will enable
diff --git a/debug.h b/debug.h
index e248695e52b30b803563484ae365c04d9a6f80cc..923fa39958037c3d0aa549e9a6def4b3a9c09756 100644 (file)
--- a/debug.h
+++ b/debug.h
@@ -20,6 +20,7 @@ enum {
        FD_TIME,
        FD_NET,
        FD_RATE,
+       FD_COMPRESS,
        FD_DEBUG_MAX,
 };
 
diff --git a/init.c b/init.c
index 57aa702471acd65d9a12ec79064204fa1f87f40d..cf1d7f938fb33acfda49b540d94c65249245e070 100644 (file)
--- a/init.c
+++ b/init.c
@@ -1569,7 +1569,7 @@ static void usage(const char *name)
        printf("%s [options] [job options] <job file(s)>\n", name);
        printf("  --debug=options\tEnable debug logging. May be one/more of:\n"
                "\t\t\tprocess,file,io,mem,blktrace,verify,random,parse,\n"
-               "\t\t\tdiskutil,job,mutex,profile,time,net,rate\n");
+               "\t\t\tdiskutil,job,mutex,profile,time,net,rate,compress\n");
        printf("  --parse-only\t\tParse options only, don't start any IO\n");
        printf("  --output\t\tWrite output to file\n");
        printf("  --runtime\t\tRuntime in seconds\n");
@@ -1677,6 +1677,10 @@ struct debug_level debug_levels[] = {
          .help = "Rate logging",
          .shift = FD_RATE,
        },
+       { .name = "compress",
+         .help = "Log compression logging",
+         .shift = FD_COMPRESS,
+       },
        { .name = NULL, },
 };
 
diff --git a/iolog.c b/iolog.c
index 79c189b70af83e1e5d452ab08b1bff291222709a..100b5d79eb14001cdbdddda7cc17c337765f0b52 100644 (file)
--- a/iolog.c
+++ b/iolog.c
@@ -735,6 +735,11 @@ static void finish_chunk(z_stream *stream, FILE *f,
 static size_t inflate_chunk(struct iolog_compress *ic, int gz_hdr, FILE *f,
                            z_stream *stream, struct inflate_chunk_iter *iter)
 {
+       size_t ret;
+
+       dprint(FD_COMPRESS, "inflate chunk size=%lu, seq=%u",
+                               (unsigned long) ic->len, ic->seq);
+
        if (ic->seq != iter->seq) {
                if (iter->seq)
                        finish_chunk(stream, f, iter);
@@ -777,7 +782,11 @@ static size_t inflate_chunk(struct iolog_compress *ic, int gz_hdr, FILE *f,
                        break;
        }
 
-       return (void *) stream->next_in - ic->buf;
+       ret = (void *) stream->next_in - ic->buf;
+
+       dprint(FD_COMPRESS, "inflated to size=%lu\n", (unsigned long) ret);
+
+       return ret;
 }
 
 /*
@@ -798,6 +807,9 @@ static int inflate_gz_chunks(struct io_log *log, FILE *f)
                if (log->log_gz_store) {
                        size_t ret;
 
+                       dprint(FD_COMPRESS, "log write chunk size=%lu, "
+                               "seq=%u\n", (unsigned long) ic->len, ic->seq);
+
                        ret = fwrite(ic->buf, ic->len, 1, f);
                        if (ret != 1 || ferror(f)) {
                                iter.err = errno;
@@ -986,6 +998,8 @@ static int gz_work(struct tp_work *work)
        stream.next_in = (void *) data->samples;
        stream.avail_in = data->nr_samples * log_entry_sz(data->log);
 
+       dprint(FD_COMPRESS, "deflate input size=%lu, seq=%u\n",
+                               (unsigned long) stream.avail_in, seq);
        do {
                c = get_new_chunk(seq);
                stream.avail_out = GZ_CHUNK;
@@ -1015,10 +1029,13 @@ static int gz_work(struct tp_work *work)
                        stream.next_out = c->buf;
                        ret = deflate(&stream, Z_FINISH);
                        c->len = GZ_CHUNK - stream.avail_out;
+                       total += c->len;
                        flist_add_tail(&c->list, &list);
                } while (ret != Z_STREAM_END);
        }
 
+       dprint(FD_COMPRESS, "deflated to size=%lu\n", (unsigned long) total);
+
        ret = deflateEnd(&stream);
        if (ret != Z_OK)
                log_err("fio: deflateEnd %d\n", ret);