X-Git-Url: https://git.kernel.dk/?a=blobdiff_plain;f=blkparse_fmt.c;h=c42e6d7b7219d532c4ae34d937e0ea9660535426;hb=d025d6c67760a52e34e6c7352f33ad5dbbb4f6f4;hp=30bab91a02195347bb880f8097af04d4e9aecb9d;hpb=e820abd79354e5b8596e1ec8105ffe36d36f9c20;p=blktrace.git

diff --git a/blkparse_fmt.c b/blkparse_fmt.c
index 30bab91..c42e6d7 100644
--- a/blkparse_fmt.c
+++ b/blkparse_fmt.c
@@ -7,10 +7,11 @@
 #include <stdlib.h>
 #include <unistd.h>
 #include <ctype.h>
+#include <time.h>
 
 #include "blktrace.h"
 
-#define VALID_SPECS	"BCDFGMPQRSTU"
+#define VALID_SPECS	"ABCDFGIMPQRSTUWX"
 
 #define HEADER		"%D %2c %8s %5T.%9t %5p %2a %3d "
 
@@ -43,19 +44,8 @@ int add_format_spec(char *option)
 		return 1;
 	}
 	option += 2;
-	if (*option == '\0') {
-		fprintf(stderr,"Bad format specifier - need fmt %s\n", option);
-		return 1;
-	}
 
-	/*
-	 * Set both merges (front and back)
-	 */
-	if (spec == 'M') {
-		override_format['B'] = strdup(option);
-		override_format['M'] = strdup(option);
-	} else
-		override_format[spec] = strdup(option);
+	override_format[spec] = strdup(option);
 
 	return 0;
 }
@@ -63,22 +53,70 @@ int add_format_spec(char *option)
 static inline void fill_rwbs(char *rwbs, struct blk_io_trace *t)
 {
 	int w = t->action & BLK_TC_ACT(BLK_TC_WRITE);
-	int b = t->action & BLK_TC_ACT(BLK_TC_BARRIER);
+	int a = t->action & BLK_TC_ACT(BLK_TC_AHEAD);
 	int s = t->action & BLK_TC_ACT(BLK_TC_SYNC);
+	int m = t->action & BLK_TC_ACT(BLK_TC_META);
+	int d = t->action & BLK_TC_ACT(BLK_TC_DISCARD);
+	int f = t->action & BLK_TC_ACT(BLK_TC_FLUSH);
+	int u = t->action & BLK_TC_ACT(BLK_TC_FUA);
 	int i = 0;
 
-	if (w)
+	if (f)
+		rwbs[i++] = 'F'; /* flush */
+
+	if (d)
+		rwbs[i++] = 'D';
+	else if (w)
 		rwbs[i++] = 'W';
-	else
+	else if (t->bytes)
 		rwbs[i++] = 'R';
-	if (b)
-		rwbs[i++] = 'B';
+	else
+		rwbs[i++] = 'N';
+
+	if (u)
+		rwbs[i++] = 'F'; /* fua */
+	if (a)
+		rwbs[i++] = 'A';
 	if (s)
 		rwbs[i++] = 'S';
+	if (m)
+		rwbs[i++] = 'M';
 
 	rwbs[i] = '\0';
 }
 
+static const char *
+print_time(unsigned long long timestamp)
+{
+	static char	timebuf[128];
+	struct tm	*tm;
+	time_t		sec;
+	unsigned long	nsec;
+
+	sec  = abs_start_time.tv_sec + SECONDS(timestamp);
+	nsec = abs_start_time.tv_nsec + NANO_SECONDS(timestamp);
+	if (nsec >= 1000000000) {
+		nsec -= 1000000000;
+		sec += 1;
+	}
+
+	tm = localtime(&sec);
+	snprintf(timebuf, sizeof(timebuf),
+			"%02u:%02u:%02u.%06lu",
+			tm->tm_hour,
+			tm->tm_min,
+			tm->tm_sec,
+			nsec / 1000);
+	return timebuf;
+}
+
+static inline int pdu_rest_is_zero(unsigned char *pdu, int len)
+{
+	static char zero[4096];
+
+	return !memcmp(pdu, zero, len);
+}
+
 static char *dump_pdu(unsigned char *pdu_buf, int pdu_len)
 {
 	static char p[4096];
@@ -92,18 +130,40 @@ static char *dump_pdu(unsigned char *pdu_buf, int pdu_len)
 			len += sprintf(p + len, " ");
 
 		len += sprintf(p + len, "%02x", pdu_buf[i]);
+
+		/*
+		 * usually dump for cdb dumps where we can see lots of
+		 * zeroes, stop when the rest is just zeroes and indicate
+		 * so with a .. appended
+		 */
+		if (!pdu_buf[i] && pdu_rest_is_zero(pdu_buf + i, pdu_len - i)) {
+			sprintf(p + len, " ..");
+			break;
+		}
 	}
 
 	return p;
 }
 
+#define pdu_start(t)	(((void *) (t) + sizeof(struct blk_io_trace)))
+
 static unsigned int get_pdu_int(struct blk_io_trace *t)
 {
-	__u64 *val = (__u64 *) ((char *) t + sizeof(*t));
+	__u64 *val = pdu_start(t);
 
 	return be64_to_cpu(*val);
 }
 
+static void get_pdu_remap(struct blk_io_trace *t, struct blk_io_trace_remap *r)
+{
+	struct blk_io_trace_remap *__r = pdu_start(t);
+	__u64 sector_from = __r->sector_from;
+
+	r->device_from = be32_to_cpu(__r->device_from);
+	r->device_to   = be32_to_cpu(__r->device_to);
+	r->sector_from = be64_to_cpu(sector_from);
+}
+
 static void print_field(char *act, struct per_cpu_info *pci,
 			struct blk_io_trace *t, unsigned long long elapsed,
 			int pdu_len, unsigned char *pdu_buf, char field,
@@ -126,11 +186,14 @@ static void print_field(char *act, struct per_cpu_info *pci,
 	case 'c':
 		fprintf(ofp, strcat(format, "d"), pci->cpu);
 		break;
-	case 'C':
-		fprintf(ofp, strcat(format, "s"), t->comm);
+	case 'C': {
+		char *name = find_process_name(t->pid);
+
+		fprintf(ofp, strcat(format, "s"), name);
 		break;
+	}
 	case 'd': {
-		char rwbs[4];
+		char rwbs[8];
 
 		fill_rwbs(rwbs, t);
 		fprintf(ofp, strcat(format, "s"), rwbs);
@@ -149,7 +212,7 @@ static void print_field(char *act, struct per_cpu_info *pci,
 		fprintf(ofp, strcat(format, "d"), MINOR(t->device));
 		break;
 	case 'n':
-		fprintf(ofp, strcat(format, "u"), t->bytes >> 9);
+		fprintf(ofp, strcat(format, "u"), t_sec(t));
 		break;
 	case 'N':
 		fprintf(ofp, strcat(format, "u"), t->bytes);
@@ -183,10 +246,12 @@ static void print_field(char *act, struct per_cpu_info *pci,
 		}
 		fprintf(ofp, strcat(format, "llu"), elapsed / 1000);
 		break;
-	case 'U': {
+	case 'U':
 		fprintf(ofp, strcat(format, "u"), get_pdu_int(t));
 		break;
-	}
+	case 'z':
+		fprintf(ofp, strcat(format, "s"), print_time(t->time));
+		break;
 	default:
 		fprintf(ofp,strcat(format, "c"), field);
 		break;
@@ -224,10 +289,21 @@ static void process_default(char *act, struct per_cpu_info *pci,
 			    struct blk_io_trace *t, unsigned long long elapsed,
 			    int pdu_len, unsigned char *pdu_buf)
 {
-	char rwbs[4];
+	struct blk_io_trace_remap r = { .device_from = 0, };
+	char rwbs[8];
+	char *name;
 
 	fill_rwbs(rwbs, t);
 
+	 /*
+	  * For remaps we have to modify the device using the remap structure
+	  * passed up.
+	  */
+	 if (act[0] == 'A') {
+		 get_pdu_remap(t, &r);
+		 t->device = r.device_to;
+	 }
+
 	/*
 	 * The header is always the same
 	 */
@@ -236,7 +312,10 @@ static void process_default(char *act, struct per_cpu_info *pci,
 		(int) SECONDS(t->time), (unsigned long) NANO_SECONDS(t->time),
 		t->pid, act, rwbs);
 
+	name = find_process_name(t->pid);
+
 	switch (act[0]) {
+	case 'R':	/* Requeue */
 	case 'C': 	/* Complete */
 		if (t->action & BLK_TC_ACT(BLK_TC_PC)) {
 			char *p = dump_pdu(pdu_buf, pdu_len);
@@ -245,13 +324,23 @@ static void process_default(char *act, struct per_cpu_info *pci,
 			fprintf(ofp, "[%d]\n", t->error);
 		} else {
 			if (elapsed != -1ULL) {
-				fprintf(ofp, "%llu + %u (%8llu) [%d]\n",
-					(unsigned long long) t->sector,
-					t->bytes >> 9, elapsed, t->error);
+				if (t_sec(t))
+					fprintf(ofp, "%llu + %u (%8llu) [%d]\n",
+						(unsigned long long) t->sector,
+						t_sec(t), elapsed, t->error);
+				else
+					fprintf(ofp, "%llu (%8llu) [%d]\n",
+						(unsigned long long) t->sector,
+						elapsed, t->error);
 			} else {
-				fprintf(ofp, "%llu + %u [%d]\n",
-					(unsigned long long) t->sector,
-					t->bytes >> 9, t->error);
+				if (t_sec(t))
+					fprintf(ofp, "%llu + %u [%d]\n",
+						(unsigned long long) t->sector,
+						t_sec(t), t->error);
+				else
+					fprintf(ofp, "%llu [%d]\n",
+						(unsigned long long) t->sector,
+						t->error);
 			}
 		}
 		break;
@@ -259,49 +348,69 @@ static void process_default(char *act, struct per_cpu_info *pci,
 	case 'D': 	/* Issue */
 	case 'I': 	/* Insert */
 	case 'Q': 	/* Queue */
-	case 'W':	/* Bounce */
+	case 'B':	/* Bounce */
 		if (t->action & BLK_TC_ACT(BLK_TC_PC)) {
 			char *p;
 			fprintf(ofp, "%u ", t->bytes);
 			p = dump_pdu(pdu_buf, pdu_len);
 			if (p)
 				fprintf(ofp, "(%s) ", p);
-			fprintf(ofp, "[%s]\n", t->comm);
+			fprintf(ofp, "[%s]\n", name);
 		} else {
 			if (elapsed != -1ULL) {
-				fprintf(ofp, "%llu + %u (%8llu) [%s]\n",
-					(unsigned long long) t->sector,
-					t->bytes >> 9, elapsed, t->comm);
+				if (t_sec(t))
+					fprintf(ofp, "%llu + %u (%8llu) [%s]\n",
+						(unsigned long long) t->sector,
+						t_sec(t), elapsed, name);
+				else
+					fprintf(ofp, "(%8llu) [%s]\n", elapsed,
+						name);
 			} else {
-				fprintf(ofp, "%llu + %u [%s]\n",
-					(unsigned long long) t->sector,
-					t->bytes >> 9, t->comm);
+				if (t_sec(t))
+					fprintf(ofp, "%llu + %u [%s]\n",
+						(unsigned long long) t->sector,
+						t_sec(t), name);
+				else
+					fprintf(ofp, "[%s]\n", name);
 			}
 		}
 		break;
 
-	case 'B':	/* Back merge */
+	case 'M':	/* Back merge */
 	case 'F':	/* Front merge */
-	case 'M':	/* Front or back merge */
 	case 'G':	/* Get request */
 	case 'S':	/* Sleep request */
-		fprintf(ofp, "%llu + %u [%s]\n", (unsigned long long) t->sector,
-			t->bytes >> 9, t->comm);
+		if (t_sec(t))
+			fprintf(ofp, "%llu + %u [%s]\n",
+				(unsigned long long) t->sector, t_sec(t), name);
+		else
+			fprintf(ofp, "[%s]\n", name);
 		break;
 
 	case 'P':	/* Plug */
-		fprintf(ofp, "[%s]\n", t->comm);
+		fprintf(ofp, "[%s]\n", name);
 		break;
 
 	case 'U':	/* Unplug IO */
-	case 'T': {	/* Unplug timer */
-		fprintf(ofp, "[%s] %u\n", t->comm, get_pdu_int(t));
+	case 'T': 	/* Unplug timer */
+		fprintf(ofp, "[%s] %u\n", name, get_pdu_int(t));
+		break;
+
+	case 'A': 	/* remap */
+		get_pdu_remap(t, &r);
+		fprintf(ofp, "%llu + %u <- (%d,%d) %llu\n",
+			(unsigned long long) t->sector, t_sec(t),
+			MAJOR(r.device_from), MINOR(r.device_from),
+			(unsigned long long) r.sector_from);
 		break;
-	}
 
 	case 'X': 	/* Split */
 		fprintf(ofp, "%llu / %u [%s]\n", (unsigned long long) t->sector,
-			get_pdu_int(t), t->comm);
+			get_pdu_int(t), name);
+		break;
+
+	case 'm':	/* Message */
+		fprintf(ofp, "%*s\n", pdu_len, pdu_buf);
 		break;
 
 	default:
@@ -341,7 +450,7 @@ void process_fmt(char *act, struct per_cpu_info *pci, struct blk_io_trace *t,
 			case 'r': fprintf(ofp, "\r"); break;
 			case 't': fprintf(ofp, "\t"); break;
 			default:
-				fprintf(stderr,	
+				fprintf(stderr,
 					"Invalid escape char in format %c\n",
 					p[1]);
 				exit(1);