X-Git-Url: https://git.kernel.dk/?p=fio.git;a=blobdiff_plain;f=fio.c;h=412f00295b27f6aff1e190d8b2e0bd37d502133b;hp=8c48a71c0481b69c8a1235d6a53f481c8bb3279c;hb=0c7e37a04aa04ba22e812f8de7971fcef46b8191;hpb=e9c047a0d8dfc32634b896e1600c6f1aa4174378

diff --git a/fio.c b/fio.c
index 8c48a71c..412f0029 100644
--- a/fio.c
+++ b/fio.c
@@ -43,13 +43,17 @@ int thread_number = 0;
 static char run_str[MAX_JOBS + 1];
 int shm_id = 0;
 static struct timeval genesis;
+static int temp_stall_ts;
 
 static void print_thread_status(void);
 
 extern unsigned long long mlock_size;
 
 /*
- * thread life cycle
+ * Thread life cycle. Once a thread has a runstate beyond TD_INITIALIZED, it
+ * will never back again. It may cycle between running/verififying/fsyncing.
+ * Once the thread reaches TD_EXITED, it is just waiting for the core to
+ * reap it.
  */
 enum {
 	TD_NOT_CREATED = 0,
@@ -57,6 +61,7 @@ enum {
 	TD_INITIALIZED,
 	TD_RUNNING,
 	TD_VERIFYING,
+	TD_FSYNCING,
 	TD_EXITED,
 	TD_REAPED,
 };
@@ -98,6 +103,10 @@ static void sig_handler(int sig)
 	}
 }
 
+/*
+ * The ->file_map[] contains a map of blocks we have or have not done io
+ * to yet. Used to make sure we cover the entire range in a fair fashion.
+ */
 static int random_map_free(struct thread_data *td, unsigned long long block)
 {
 	unsigned int idx = RAND_MAP_IDX(td, block);
@@ -106,6 +115,9 @@ static int random_map_free(struct thread_data *td, unsigned long long block)
 	return (td->file_map[idx] & (1UL << bit)) == 0;
 }
 
+/*
+ * Return the next free block in the map.
+ */
 static int get_next_free_block(struct thread_data *td, unsigned long long *b)
 {
 	int i;
@@ -125,6 +137,9 @@ static int get_next_free_block(struct thread_data *td, unsigned long long *b)
 	return 1;
 }
 
+/*
+ * Mark a given offset as used in the map.
+ */
 static void mark_random_map(struct thread_data *td, struct io_u *io_u)
 {
 	unsigned long long block = io_u->offset / (unsigned long long) td->min_bs;
@@ -150,6 +165,11 @@ static void mark_random_map(struct thread_data *td, struct io_u *io_u)
 		io_u->buflen = blocks * td->min_bs;
 }
 
+/*
+ * For random io, generate a random new block and see if it's used. Repeat
+ * until we find a free one. For sequential io, just return the end of
+ * the last io issued.
+ */
 static int get_next_offset(struct thread_data *td, unsigned long long *offset)
 {
 	unsigned long long b, rb;
@@ -199,6 +219,9 @@ static unsigned int get_next_buflen(struct thread_data *td)
 	return buflen;
 }
 
+/*
+ * Check if we are above the minimum rate given.
+ */
 static int check_min_rate(struct thread_data *td, struct timeval *now)
 {
 	unsigned long spent;
@@ -221,7 +244,7 @@ static int check_min_rate(struct thread_data *td, struct timeval *now)
 
 		rate = (td->this_io_bytes[ddir] - td->rate_bytes) / spent;
 		if (rate < td->ratemin) {
-			printf("%s: min rate %d not met, got %ldKiB/sec\n", td->name, td->ratemin, rate);
+			fprintf(f_out, "%s: min rate %d not met, got %ldKiB/sec\n", td->name, td->ratemin, rate);
 			if (rate_quit)
 				terminate_threads(td->groupid);
 			return 1;
@@ -273,8 +296,8 @@ static void hexdump(void *buffer, int len)
 	int i;
 
 	for (i = 0; i < len; i++)
-		printf("%02x", p[i]);
-	printf("\n");
+		fprintf(f_out, "%02x", p[i]);
+	fprintf(f_out, "\n");
 }
 
 static int verify_io_u_crc32(struct verify_header *hdr, struct io_u *io_u)
@@ -286,8 +309,8 @@ static int verify_io_u_crc32(struct verify_header *hdr, struct io_u *io_u)
 	c = crc32(p, hdr->len - sizeof(*hdr));
 
 	if (c != hdr->crc32) {
-		fprintf(stderr, "crc32: verify failed at %llu/%u\n", io_u->offset, io_u->buflen);
-		fprintf(stderr, "crc32: wanted %lx, got %lx\n", hdr->crc32, c);
+		log_err("crc32: verify failed at %llu/%u\n", io_u->offset, io_u->buflen);
+		log_err("crc32: wanted %lx, got %lx\n", hdr->crc32, c);
 		return 1;
 	}
 
@@ -304,7 +327,7 @@ static int verify_io_u_md5(struct verify_header *hdr, struct io_u *io_u)
 	md5_update(&md5_ctx, p, hdr->len - sizeof(*hdr));
 
 	if (memcmp(hdr->md5_digest, md5_ctx.hash, sizeof(md5_ctx.hash))) {
-		fprintf(stderr, "md5: verify failed at %llu/%u\n", io_u->offset, io_u->buflen);
+		log_err("md5: verify failed at %llu/%u\n", io_u->offset, io_u->buflen);
 		hexdump(hdr->md5_digest, sizeof(hdr->md5_digest));
 		hexdump(md5_ctx.hash, sizeof(md5_ctx.hash));
 		return 1;
@@ -326,7 +349,7 @@ static int verify_io_u(struct io_u *io_u)
 	else if (hdr->verify_type == VERIFY_CRC32)
 		ret = verify_io_u_crc32(hdr, io_u);
 	else {
-		fprintf(stderr, "Bad verify type %d\n", hdr->verify_type);
+		log_err("Bad verify type %d\n", hdr->verify_type);
 		ret = 1;
 	}
 
@@ -347,6 +370,11 @@ static void fill_md5(struct verify_header *hdr, void *p, unsigned int len)
 	memcpy(hdr->md5_digest, md5_ctx.hash, sizeof(md5_ctx.hash));
 }
 
+/*
+ * Return the data direction for the next io_u. If the job is a
+ * mixed read/write workload, check the rwmix cycle and switch if
+ * necessary.
+ */
 static int get_rw_ddir(struct thread_data *td)
 {
 	if (td_rw(td)) {
@@ -360,11 +388,11 @@ static int get_rw_ddir(struct thread_data *td)
 		 * Check if it's time to seed a new data direction.
 		 */
 		if (elapsed >= td->rwmixcycle) {
-			unsigned long v;
+			int v;
 			long r;
 
-			r = os_random_long(&td->random_state);
-			v = 100UL * r / (unsigned long) (RAND_MAX + 1.0);
+			r = os_random_long(&td->rwmix_state);
+			v = 1 + (int) (100.0 * (r / (RAND_MAX + 1.0)));
 			if (v < td->rwmixread)
 				td->rwmix_ddir = DDIR_READ;
 			else
@@ -467,6 +495,10 @@ struct io_u *__get_io_u(struct thread_data *td)
 	return io_u;
 }
 
+/*
+ * Return an io_u to be processed. Gets a buflen and offset, sets direction,
+ * etc. The returned io_u is fully ready to be prepped and submitted.
+ */
 static struct io_u *get_io_u(struct thread_data *td)
 {
 	struct io_u *io_u;
@@ -512,7 +544,6 @@ static struct io_u *get_io_u(struct thread_data *td)
 
 static inline void td_set_runstate(struct thread_data *td, int runstate)
 {
-	td->old_runstate = td->runstate;
 	td->runstate = runstate;
 }
 
@@ -604,6 +635,10 @@ static void ios_completed(struct thread_data *td,struct io_completion_data *icd)
 	}
 }
 
+/*
+ * When job exits, we can cancel the in-flight IO if we are using async
+ * io. Attempt to do so.
+ */
 static void cleanup_pending_aio(struct thread_data *td)
 {
 	struct timespec ts = { .tv_sec = 0, .tv_nsec = 0};
@@ -657,6 +692,10 @@ static int do_io_u_verify(struct thread_data *td, struct io_u **io_u)
 	return ret;
 }
 
+/*
+ * The main verify engine. Runs over the writes we previusly submitted,
+ * reads the blocks back in, and checks the crc/md5 of the data.
+ */
 static void do_verify(struct thread_data *td)
 {
 	struct timeval t;
@@ -738,7 +777,7 @@ static void do_verify(struct thread_data *td)
 }
 
 /*
- * Main IO worker functions. It retrieves io_u's to process and queues
+ * Main IO worker function. It retrieves io_u's to process and queues
  * and reaps them, checking for rate and errors along the way.
  */
 static void do_io(struct thread_data *td)
@@ -747,6 +786,8 @@ static void do_io(struct thread_data *td)
 	struct timeval s, e;
 	unsigned long usec;
 
+	td_set_runstate(td, TD_RUNNING);
+
 	while (td->this_io_bytes[td->ddir] < td->io_size) {
 		struct timespec ts = { .tv_sec = 0, .tv_nsec = 0};
 		struct timespec *timeout;
@@ -822,8 +863,10 @@ static void do_io(struct thread_data *td)
 	if (td->cur_depth)
 		cleanup_pending_aio(td);
 
-	if (should_fsync(td) && td->end_fsync)
+	if (should_fsync(td) && td->end_fsync) {
+		td_set_runstate(td, TD_FSYNCING);
 		sync_td(td);
+	}
 }
 
 static void cleanup_io(struct thread_data *td)
@@ -847,7 +890,7 @@ static int init_io(struct thread_data *td)
 	else if (td->io_engine == FIO_SPLICEIO)
 		return fio_spliceio_init(td);
 	else {
-		fprintf(stderr, "bad io_engine %d\n", td->io_engine);
+		log_err("bad io_engine %d\n", td->io_engine);
 		return 1;
 	}
 }
@@ -874,7 +917,7 @@ static void cleanup_io_u(struct thread_data *td)
 	} else if (td->mem_type == MEM_MMAP)
 		munmap(td->orig_buffer, td->orig_buffer_size);
 	else
-		fprintf(stderr, "Bad memory type %d\n", td->mem_type);
+		log_err("Bad memory type %d\n", td->mem_type);
 
 	td->orig_buffer = NULL;
 }
@@ -933,61 +976,39 @@ static int init_io_u(struct thread_data *td)
 	return 0;
 }
 
-static void cleanup_allocs(struct thread_data *td)
-{
-	if (td->directory)
-		free(td->directory);
-	if (td->iolog_file)
-		free(td->iolog_file);
-	if (td->exec_prerun)
-		free(td->exec_prerun);
-	if (td->exec_postrun)
-		free(td->exec_postrun);
-	if (td->ioscheduler)
-		free(td->ioscheduler);
-	if (td->sysfs_root)
-		free(td->sysfs_root);
-	if (td->file_name)
-		free(td->file_name);
-}
-
-static int create_file(struct thread_data *td, unsigned long long size,
-		       int extend)
+static int create_file(struct thread_data *td, unsigned long long size)
 {
 	unsigned long long left;
 	unsigned int bs;
-	int r, oflags;
 	char *b;
+	int r;
 
 	/*
 	 * unless specifically asked for overwrite, let normal io extend it
 	 */
-	if (td_write(td) && !td->overwrite)
+	if (!td->overwrite) {
+		td->real_file_size = size;
 		return 0;
+	}
 
 	if (!size) {
-		fprintf(stderr, "Need size for create\n");
+		log_err("Need size for create\n");
 		td_verror(td, EINVAL);
 		return 1;
 	}
 
-	if (!extend) {
-		oflags = O_CREAT | O_TRUNC;
-		printf("%s: Laying out IO file (%LuMiB)\n", td->name, size >> 20);
-	} else {
-		oflags = O_APPEND;
-		printf("%s: Extending IO file (%Lu -> %LuMiB)\n", td->name, (td->file_size - size) >> 20, td->file_size >> 20);
-	}
+	temp_stall_ts = 1;
+	fprintf(f_out, "%s: Laying out IO file (%LuMiB)\n",td->name,size >> 20);
 
-	td->fd = open(td->file_name, O_WRONLY | oflags, 0644);
+	td->fd = open(td->file_name, O_WRONLY | O_CREAT | O_TRUNC, 0644);
 	if (td->fd < 0) {
 		td_verror(td, errno);
-		return 1;
+		goto done_noclose;
 	}
 
-	if (!extend && ftruncate(td->fd, td->file_size) == -1) {
+	if (ftruncate(td->fd, td->file_size) == -1) {
 		td_verror(td, errno);
-		return 1;
+		goto done;
 	}
 
 	td->io_size = td->file_size;
@@ -1020,9 +1041,12 @@ static int create_file(struct thread_data *td, unsigned long long size,
 	else if (td->create_fsync)
 		fsync(td->fd);
 
+	free(b);
+done:
 	close(td->fd);
 	td->fd = -1;
-	free(b);
+done_noclose:
+	temp_stall_ts = 0;
 	return 0;
 }
 
@@ -1030,15 +1054,17 @@ static int file_size(struct thread_data *td)
 {
 	struct stat st;
 
-	if (fstat(td->fd, &st) == -1) {
-		td_verror(td, errno);
-		return 1;
-	}
+	if (td->overwrite) {
+		if (fstat(td->fd, &st) == -1) {
+			td_verror(td, errno);
+			return 1;
+		}
 
-	td->real_file_size = st.st_size;
+		td->real_file_size = st.st_size;
 
-	if (!td->file_size || td->file_size > td->real_file_size)
-		td->file_size = td->real_file_size;
+		if (!td->file_size || td->file_size > td->real_file_size)
+			td->file_size = td->real_file_size;
+	}
 
 	td->file_size -= td->file_offset;
 	return 0;
@@ -1082,13 +1108,13 @@ static int get_file_size(struct thread_data *td)
 		return ret;
 
 	if (td->file_offset > td->real_file_size) {
-		fprintf(stderr, "%s: offset extends end (%Lu > %Lu)\n", td->name, td->file_offset, td->real_file_size);
+		log_err("%s: offset extends end (%Lu > %Lu)\n", td->name, td->file_offset, td->real_file_size);
 		return 1;
 	}
 
 	td->io_size = td->file_size;
 	if (td->io_size == 0) {
-		fprintf(stderr, "%s: no io blocks\n", td->name);
+		log_err("%s: no io blocks\n", td->name);
 		td_verror(td, EINVAL);
 		return 1;
 	}
@@ -1181,17 +1207,16 @@ static int setup_file(struct thread_data *td)
 			td_verror(td, ENOENT);
 			return 1;
 		}
-		if (create_file(td, td->file_size, 0))
+		if (create_file(td, td->file_size))
+			return 1;
+	} else if (td->filetype == FIO_TYPE_FILE &&
+		   st.st_size < (off_t) td->file_size) {
+		if (create_file(td, td->file_size))
 			return 1;
-	} else if (td->filetype == FIO_TYPE_FILE) {
-		if (st.st_size < (off_t) td->file_size) {
-			if (create_file(td, td->file_size - st.st_size, 1))
-				return 1;
-		}
 	}
 
 	if (td->odirect)
-		flags |= O_DIRECT;
+		flags |= OS_O_DIRECT;
 
 	if (td_write(td) || td_rw(td)) {
 		if (td->filetype == FIO_TYPE_FILE) {
@@ -1267,7 +1292,7 @@ static int switch_ioscheduler(struct thread_data *td)
 
 	sprintf(tmp2, "[%s]", td->ioscheduler);
 	if (!strstr(tmp, tmp2)) {
-		fprintf(stderr, "fio: io scheduler %s not found\n", td->ioscheduler);
+		log_err("fio: io scheduler %s not found\n", td->ioscheduler);
 		td_verror(td, EINVAL);
 		fclose(f);
 		return 1;
@@ -1291,6 +1316,10 @@ static void clear_io_state(struct thread_data *td)
 		memset(td->file_map, 0, td->num_maps * sizeof(long));
 }
 
+/*
+ * Entry point for the thread based jobs. The process based jobs end up
+ * here as well, after a little setup.
+ */
 static void *thread_main(void *data)
 {
 	struct thread_data *td = data;
@@ -1406,7 +1435,6 @@ err:
 	}
 	if (td->mmap)
 		munmap(td->mmap, td->file_size);
-	cleanup_allocs(td);
 	cleanup_io(td);
 	cleanup_io_u(td);
 	td_set_runstate(td, TD_EXITED);
@@ -1414,6 +1442,10 @@ err:
 
 }
 
+/*
+ * We cannot pass the td data into a forked process, so attach the td and
+ * pass it to the thread worker.
+ */
 static void *fork_main(int shmid, int offset)
 {
 	struct thread_data *td;
@@ -1431,13 +1463,13 @@ static void *fork_main(int shmid, int offset)
 	return NULL;
 }
 
+/*
+ * Sets the status of the 'td' in the printed status map.
+ */
 static void check_str_update(struct thread_data *td)
 {
 	char c = run_str[td->thread_number - 1];
 
-	if (td->runstate == td->old_runstate)
-		return;
-
 	switch (td->runstate) {
 		case TD_REAPED:
 			c = '_';
@@ -1466,6 +1498,9 @@ static void check_str_update(struct thread_data *td)
 		case TD_VERIFYING:
 			c = 'V';
 			break;
+		case TD_FSYNCING:
+			c = 'F';
+			break;
 		case TD_CREATED:
 			c = 'C';
 			break;
@@ -1476,13 +1511,15 @@ static void check_str_update(struct thread_data *td)
 			c = 'P';
 			break;
 		default:
-			printf("state %d\n", td->runstate);
+			log_err("state %d\n", td->runstate);
 	}
 
 	run_str[td->thread_number - 1] = c;
-	td->old_runstate = td->runstate;
 }
 
+/*
+ * Convert seconds to a printable string.
+ */
 static void eta_to_str(char *str, int eta_sec)
 {
 	unsigned int d, h, m, s;
@@ -1511,6 +1548,9 @@ static void eta_to_str(char *str, int eta_sec)
 	str += sprintf(str, "%02ds", s);
 }
 
+/*
+ * Best effort calculation of the estimated pending runtime of a job.
+ */
 static int thread_eta(struct thread_data *td, unsigned long elapsed)
 {
 	unsigned long long bytes_total, bytes_done;
@@ -1565,10 +1605,10 @@ static int thread_eta(struct thread_data *td, unsigned long elapsed)
 		else if (t_eta)
 			eta_sec = t_eta;
 		else
-			eta_sec = INT_MAX;
+			eta_sec = 0;
 	} else {
 		/*
-		 * thread is already done
+		 * thread is already done or waiting for fsync
 		 */
 		eta_sec = 0;
 	}
@@ -1576,25 +1616,34 @@ static int thread_eta(struct thread_data *td, unsigned long elapsed)
 	return eta_sec;
 }
 
+/*
+ * Print status of the jobs we know about. This includes rate estimates,
+ * ETA, thread state, etc.
+ */
 static void print_thread_status(void)
 {
 	unsigned long elapsed = time_since_now(&genesis);
-	int i, nr_running, t_rate, m_rate, *eta_secs, eta_sec;
+	int i, nr_running, nr_pending, t_rate, m_rate, *eta_secs, eta_sec;
 	char eta_str[32];
 	double perc = 0.0;
 
+	if (temp_stall_ts || terse_output)
+		return;
+
 	eta_secs = malloc(thread_number * sizeof(int));
 	memset(eta_secs, 0, thread_number * sizeof(int));
 
-	nr_running = t_rate = m_rate = 0;
+	nr_pending = nr_running = t_rate = m_rate = 0;
 	for (i = 0; i < thread_number; i++) {
 		struct thread_data *td = &threads[i];
 
-		if (td->runstate == TD_RUNNING || td->runstate == TD_VERIFYING){
+		if (td->runstate == TD_RUNNING || td->runstate == TD_VERIFYING||
+		    td->runstate == TD_FSYNCING) {
 			nr_running++;
 			t_rate += td->rate;
 			m_rate += td->ratemin;
-		}
+		} else if (td->runstate < TD_RUNNING)
+			nr_pending++;
 
 		if (elapsed >= 3)
 			eta_secs[i] = thread_eta(td, elapsed);
@@ -1624,7 +1673,10 @@ static void print_thread_status(void)
 		eta_to_str(eta_str, eta_sec);
 	}
 
-	printf("Threads now running (%d)", nr_running);
+	if (!nr_running && !nr_pending)
+		return;
+
+	printf("Threads running: %d", nr_running);
 	if (m_rate || t_rate)
 		printf(", commitrate %d/%dKiB/sec", t_rate, m_rate);
 	if (eta_sec != INT_MAX) {
@@ -1636,6 +1688,9 @@ static void print_thread_status(void)
 	free(eta_secs);
 }
 
+/*
+ * Run over the job map and reap the threads that have exited, if any.
+ */
 static void reap_threads(int *nr_running, int *t_rate, int *m_rate)
 {
 	int i;
@@ -1689,8 +1744,7 @@ static void *fio_pin_memory(void)
 	if (phys_mem) {
 		if ((mlock_size + 128 * 1024 * 1024) > phys_mem) {
 			mlock_size = phys_mem - 128 * 1024 * 1024;
-			printf("fio: limiting mlocked memory to %lluMiB\n",
-							mlock_size >> 20);
+			fprintf(f_out, "fio: limiting mlocked memory to %lluMiB\n", mlock_size >> 20);
 		}
 	}
 
@@ -1708,6 +1762,9 @@ static void *fio_pin_memory(void)
 	return ptr;
 }
 
+/*
+ * Main function for kicking off and reaping jobs, as needed.
+ */
 static void run_threads(void)
 {
 	struct thread_data *td;
@@ -1717,8 +1774,10 @@ static void run_threads(void)
 
 	mlocked_mem = fio_pin_memory();
 
-	printf("Starting %d thread%s\n", thread_number, thread_number > 1 ? "s" : "");
-	fflush(stdout);
+	if (!terse_output) {
+		printf("Starting %d thread%s\n", thread_number, thread_number > 1 ? "s" : "");
+		fflush(stdout);
+	}
 
 	signal(SIGINT, sig_handler);
 	signal(SIGALRM, sig_handler);
@@ -1812,7 +1871,6 @@ static void run_threads(void)
 		 * Wait for the started threads to transition to
 		 * TD_INITIALIZED.
 		 */
-		printf("fio: Waiting for threads to initialize...\n");
 		gettimeofday(&this_start, NULL);
 		left = this_jobs;
 		while (left) {
@@ -1838,7 +1896,7 @@ static void run_threads(void)
 		}
 
 		if (left) {
-			fprintf(stderr, "fio: %d jobs failed to start\n", left);
+			log_err("fio: %d jobs failed to start\n", left);
 			for (i = 0; i < this_jobs; i++) {
 				td = map[i];
 				if (!td)
@@ -1851,7 +1909,6 @@ static void run_threads(void)
 		/*
 		 * start created threads (TD_INITIALIZED -> TD_RUNNING).
 		 */
-		printf("fio: Go for launch\n");
 		for (i = 0; i < thread_number; i++) {
 			td = &threads[i];
 
@@ -1888,7 +1945,7 @@ int main(int argc, char *argv[])
 		return 1;
 
 	if (!thread_number) {
-		printf("Nothing to do\n");
+		log_err("Nothing to do\n");
 		return 1;
 	}