From: Jens Axboe <axboe@fb.com>
Date: Wed, 9 Jul 2014 21:01:03 +0000 (+0200)
Subject: Add some basic debug output for log compression
X-Git-Tag: fio-2.1.11~2
X-Git-Url: https://git.kernel.dk/?p=fio.git;a=commitdiff_plain;h=0c56718d787c5846db7e75d5a01b88342797c681

Add some basic debug output for log compression

Guarded by --debug=compress, like the other debug measures.

Signed-off-by: Jens Axboe <axboe@fb.com>
---

diff --git a/README b/README
index 457b83dc..e378d3b0 100644
--- 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 e248695e..923fa399 100644
--- 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 57aa7024..cf1d7f93 100644
--- 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 79c189b7..100b5d79 100644
--- 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);