Fix bad sscan() -> scanf() conversion

Caused fio to stall waiting for disk updates.

Also add --debug=diskutil debug option, to trace what diskutil is doing.

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

5 files changed, 48 insertions, 21 deletions

diff --git a/README b/README
index ef614a28..7d6262ec 100644
--- a/README
+++ b/README
@@ -101,6 +101,7 @@ options in fio. Currently the options are:
 	all		Enable all debug options
 	random		Dump info related to random offset generation
 	parse		Dump info related to option matching and parsing
+	diskutil	Dump info related to disk utilization updates
 	? or help	Show available debug options.
 
 You can specify as many as you want, eg --debug=file,mem will enable
diff --git a/blktrace.c b/blktrace.c
index b7071808..111619c6 100644
--- a/blktrace.c
+++ b/blktrace.c
@@ -204,22 +204,16 @@ static void store_ipo(struct thread_data *td, unsigned long long offset,
 	list_add_tail(&ipo->list, &td->io_log_list);
 }
 
-/*
- * We only care for queue traces, most of the others are side effects
- * due to internal workings of the block layer.
- */
-static void handle_trace(struct thread_data *td, struct blk_io_trace *t,
-			 unsigned long long ttime, unsigned long *ios,
-			 unsigned int *bs)
+static void handle_trace_notify(struct thread_data *td, struct blk_io_trace *t)
 {
-	int rw;
+	printf("got notify: %x, %d\n", t->action, t->pid);
+}
 
-	if ((t->action & 0xffff) != __BLK_TA_QUEUE)
-		return;
-	if (t->action & BLK_TC_ACT(BLK_TC_PC))
-		return;
-	if (t->action & BLK_TC_ACT(BLK_TC_NOTIFY))
-		return;
+static void handle_trace_fs(struct thread_data *td, struct blk_io_trace *t,
+			    unsigned long long ttime, unsigned long *ios,
+			    unsigned int *bs)
+{
+	int rw;
 
 	trace_add_file(td, t->device);
 
@@ -234,6 +228,25 @@ static void handle_trace(struct thread_data *td, struct blk_io_trace *t,
 }
 
 /*
+ * We only care for queue traces, most of the others are side effects
+ * due to internal workings of the block layer.
+ */
+static void handle_trace(struct thread_data *td, struct blk_io_trace *t,
+			 unsigned long long ttime, unsigned long *ios,
+			 unsigned int *bs)
+{
+	if ((t->action & 0xffff) != __BLK_TA_QUEUE)
+		return;
+	if (t->action & BLK_TC_ACT(BLK_TC_PC))
+		return;
+
+	if (t->action & BLK_TC_ACT(BLK_TC_NOTIFY))
+		handle_trace_notify(td, t);
+	else
+		handle_trace_fs(td, t, ttime, ios, bs);
+}
+
+/*
  * Load a blktrace file by reading all the blk_io_trace entries, and storing
  * them as io_pieces like the fio text version would do.
  */
diff --git a/debug.h b/debug.h
index b11a9012..22577a8a 100644
--- a/debug.h
+++ b/debug.h
@@ -13,6 +13,7 @@ enum {
 	FD_VERIFY,
 	FD_RANDOM,
 	FD_PARSE,
+	FD_DISKUTIL,
 	FD_DEBUG_MAX,
 };
 
diff --git a/diskutil.c b/diskutil.c
index b5ba709e..b3bb605a 100644
--- a/diskutil.c
+++ b/diskutil.c
@@ -22,6 +22,8 @@ static int get_io_ticks(struct disk_util *du, struct disk_util_stat *dus)
 	char *p;
 	int ret;
 
+	dprint(FD_DISKUTIL, "open stat file: %s\n", du->path);
+
 	f = fopen(du->path, "r");
 	if (!f)
 		return 1;
@@ -32,19 +34,17 @@ static int get_io_ticks(struct disk_util *du, struct disk_util_stat *dus)
 		return 1;
 	}
 
-	ret = scanf(p, "%u %u %llu %u %u %u %llu %u %u %u %u\n", &dus->ios[0],
+	dprint(FD_DISKUTIL, "%s: %s", du->path, p);
+
+	ret = sscanf(p, "%u %u %llu %u %u %u %llu %u %u %u %u\n", &dus->ios[0],
 					&dus->merges[0], &dus->sectors[0],
 					&dus->ticks[0], &dus->ios[1],
 					&dus->merges[1], &dus->sectors[1],
 					&dus->ticks[1], &in_flight,
 					&dus->io_ticks, &dus->time_in_queue);
-	if (ret != 11) {
-		fclose(f);
-		return 1;
-	}
-
 	fclose(f);
-	return 0;
+	dprint(FD_DISKUTIL, "%s: stat read ok? %d\n", du->path, ret == 1);
+	return ret != 11;
 }
 
 static void update_io_tick_disk(struct disk_util *du)
@@ -80,6 +80,8 @@ void update_io_ticks(void)
 	struct list_head *entry;
 	struct disk_util *du;
 
+	dprint(FD_DISKUTIL, "update io ticks\n");
+
 	list_for_each(entry, &disk_list) {
 		du = list_entry(entry, struct disk_util, list);
 		update_io_tick_disk(du);
@@ -106,6 +108,8 @@ static void disk_util_add(int majdev, int mindev, char *path)
 	struct disk_util *du, *__du;
 	struct list_head *entry;
 
+	dprint(FD_DISKUTIL, "add maj/min %d/%d: %s\n", majdev, mindev, path);
+
 	du = malloc(sizeof(*du));
 	memset(du, 0, sizeof(*du));
 	INIT_LIST_HEAD(&du->list);
@@ -118,6 +122,8 @@ static void disk_util_add(int majdev, int mindev, char *path)
 	list_for_each(entry, &disk_list) {
 		__du = list_entry(entry, struct disk_util, list);
 
+		dprint(FD_DISKUTIL, "found %s in list\n", __du->name);
+
 		if (!strcmp(du->name, __du->name)) {
 			free(du->name);
 			free(du);
@@ -125,6 +131,8 @@ static void disk_util_add(int majdev, int mindev, char *path)
 		}
 	}
 
+	dprint(FD_DISKUTIL, "add %s to list\n", du->name);
+
 	fio_gettime(&du->time, NULL);
 	get_io_ticks(du, &du->last_dus);
 
@@ -246,6 +254,9 @@ static void __init_disk_util(struct thread_data *td, struct fio_file *f)
 		mindev = minor(st.st_dev);
 	}
 
+	dprint(FD_DISKUTIL, "%s belongs to maj/min %d/%d\n", f->file_name,
+							majdev, mindev);
+
 	du = disk_util_exists(majdev, mindev);
 	if (du) {
 		if (td->o.ioscheduler && !td->sysfs_root)
diff --git a/init.c b/init.c
index 7711189c..8683ba63 100644
--- a/init.c
+++ b/init.c
@@ -838,6 +838,7 @@ struct debug_level debug_levels[] = {
 	{ .name = "verify",	.shift = FD_VERIFY },
 	{ .name = "random",	.shift = FD_RANDOM },
 	{ .name = "parse",	.shift = FD_PARSE },
+	{ .name = "diskutil",	.shift = FD_DISKUTIL },
 	{ },
 };