[PATCH v2 2/3] iolog: add iolog_write for version 3

[Mohamad Gebai <mogeb@fb.com>]

Add timestamps to all actions for iolog version 3. Fio now generates iolog
files using version 3 by default, and only supports writing using that
version. Reading iolog v2 still works as expected.

Signed-off-by: Mohamad Gebai <mogeb@fb.com>
---
 fio.h   |  1 +
 iolog.c | 15 ++++++++++++---
 2 files changed, 13 insertions(+), 3 deletions(-)

diff --git a/fio.h b/fio.h
index 8830ff34..de7eca79 100644
--- a/fio.h
+++ b/fio.h
@@ -425,20 +425,21 @@ struct thread_data {
 	unsigned long io_hist_len;
 
 	/*
 	 * For IO replaying
 	 */
 	struct flist_head io_log_list;
 	FILE *io_log_rfile;
 	unsigned int io_log_blktrace;
 	unsigned int io_log_blktrace_swap;
 	unsigned long long io_log_last_ttime;
+	struct timespec io_log_start_time;
 	unsigned int io_log_current;
 	unsigned int io_log_checkmark;
 	unsigned int io_log_highmark;
 	unsigned int io_log_version;
 	struct timespec io_log_highmark_time;
 
 	/*
 	 * For tracking/handling discards
 	 */
 	struct flist_head trim_list;
diff --git a/iolog.c b/iolog.c
index f6023ee2..51aecd43 100644
--- a/iolog.c
+++ b/iolog.c
@@ -34,46 +34,54 @@ static const char iolog_ver2[] = "fio version 2 iolog";
 static const char iolog_ver3[] = "fio version 3 iolog";
 
 void queue_io_piece(struct thread_data *td, struct io_piece *ipo)
 {
 	flist_add_tail(&ipo->list, &td->io_log_list);
 	td->total_io_size += ipo->len;
 }
 
 void log_io_u(const struct thread_data *td, const struct io_u *io_u)
 {
+	struct timespec now;
+
 	if (!td->o.write_iolog_file)
 		return;
 
-	fprintf(td->iolog_f, "%s %s %llu %llu\n", io_u->file->file_name,
+	fio_gettime(&now, NULL);
+	fprintf(td->iolog_f, "%lu %s %s %llu %llu\n", utime_since_now(&td->io_log_start_time),
+						io_u->file->file_name,
 						io_ddir_name(io_u->ddir),
 						io_u->offset, io_u->buflen);
+
 }
 
 void log_file(struct thread_data *td, struct fio_file *f,
 	      enum file_log_act what)
 {
 	const char *act[] = { "add", "open", "close" };
+	struct timespec now;
 
 	assert(what < 3);
 
 	if (!td->o.write_iolog_file)
 		return;
 
 
 	/*
 	 * this happens on the pre-open/close done before the job starts
 	 */
 	if (!td->iolog_f)
 		return;
 
-	fprintf(td->iolog_f, "%s %s\n", f->file_name, act[what]);
+	fio_gettime(&now, NULL);
+	fprintf(td->iolog_f, "%lu %s %s\n", utime_since_now(&td->io_log_start_time),
+						f->file_name, act[what]);
 }
 
 static void iolog_delay(struct thread_data *td, unsigned long delay)
 {
 	uint64_t usec = utime_since_now(&td->last_issue);
 	unsigned long orig_delay = delay;
 	uint64_t this_delay;
 	struct timespec ts;
 
 	if (delay < td->time_offset) {
@@ -731,25 +739,26 @@ static bool init_iolog_write(struct thread_data *td)
 		perror("fopen write iolog");
 		return false;
 	}
 
 	/*
 	 * That's it for writing, setup a log buffer and we're done.
 	  */
 	td->iolog_f = f;
 	td->iolog_buf = malloc(8192);
 	setvbuf(f, td->iolog_buf, _IOFBF, 8192);
+	fio_gettime(&td->io_log_start_time, NULL);
 
 	/*
 	 * write our version line
 	 */
-	if (fprintf(f, "%s\n", iolog_ver2) < 0) {
+	if (fprintf(f, "%s\n", iolog_ver3) < 0) {
 		perror("iolog init\n");
 		return false;
 	}
 
 	/*
 	 * add all known files
 	 */
 	for_each_file(td, ff, i)
 		log_file(td, ff, FIO_LOG_ADD_FILE);
 
-- 
2.30.2