X-Git-Url: https://git.kernel.dk/?p=fio.git;a=blobdiff_plain;f=fio.c;h=412f00295b27f6aff1e190d8b2e0bd37d502133b;hp=34e8f59662ce0474e4fcb124c4aefff709ab1497;hb=0c7e37a04aa04ba22e812f8de7971fcef46b8191;hpb=e8e387c14948e0a038660e69ace4efa13cdfd3af diff --git a/fio.c b/fio.c index 34e8f596..412f0029 100644 --- a/fio.c +++ b/fio.c @@ -18,19 +18,12 @@ * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA * */ -#include -#include #include #include #include -#include #include #include -#include #include -#include -#include -#include #include #include #include @@ -49,31 +42,36 @@ int groupid = 0; int thread_number = 0; static char run_str[MAX_JOBS + 1]; int shm_id = 0; -static LIST_HEAD(disk_list); -static struct itimerval itimer; static struct timeval genesis; +static int temp_stall_ts; -static void update_io_ticks(void); -static void disk_util_timer_arm(void); 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, TD_CREATED, + TD_INITIALIZED, TD_RUNNING, TD_VERIFYING, + TD_FSYNCING, TD_EXITED, TD_REAPED, }; -#define should_fsync(td) (td_write(td) && (!(td)->odirect || (td)->override_sync)) +#define should_fsync(td) ((td_write(td) || td_rw(td)) && (!(td)->odirect || (td)->override_sync)) -static sem_t startup_sem; +static volatile int startup_sem; #define TERMINATE_ALL (-1) +#define JOB_START_TIMEOUT (5 * 1000) static void terminate_threads(int group_id) { @@ -105,65 +103,10 @@ static void sig_handler(int sig) } } -static unsigned long utime_since(struct timeval *s, struct timeval *e) -{ - double sec, usec; - - sec = e->tv_sec - s->tv_sec; - usec = e->tv_usec - s->tv_usec; - if (sec > 0 && usec < 0) { - sec--; - usec += 1000000; - } - - sec *= (double) 1000000; - - return sec + usec; -} - -static unsigned long utime_since_now(struct timeval *s) -{ - struct timeval t; - - gettimeofday(&t, NULL); - return utime_since(s, &t); -} - -static unsigned long mtime_since(struct timeval *s, struct timeval *e) -{ - double sec, usec; - - sec = e->tv_sec - s->tv_sec; - usec = e->tv_usec - s->tv_usec; - if (sec > 0 && usec < 0) { - sec--; - usec += 1000000; - } - - sec *= (double) 1000; - usec /= (double) 1000; - - return sec + usec; -} - -static unsigned long mtime_since_now(struct timeval *s) -{ - struct timeval t; - - gettimeofday(&t, NULL); - return mtime_since(s, &t); -} - -static inline unsigned long msec_now(struct timeval *s) -{ - return s->tv_sec * 1000 + s->tv_usec / 1000; -} - -static unsigned long time_since_now(struct timeval *s) -{ - return mtime_since_now(s) / 1000; -} - +/* + * 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); @@ -172,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; @@ -191,9 +137,12 @@ 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 block = io_u->offset / td->min_bs; + unsigned long long block = io_u->offset / (unsigned long long) td->min_bs; unsigned int blocks = 0; while (blocks < (io_u->buflen / td->min_bs)) { @@ -216,80 +165,23 @@ static void mark_random_map(struct thread_data *td, struct io_u *io_u) io_u->buflen = blocks * td->min_bs; } -static inline void add_stat_sample(struct io_stat *is, unsigned long val) -{ - if (val > is->max_val) - is->max_val = val; - if (val < is->min_val) - is->min_val = val; - - is->val += val; - is->val_sq += val * val; - is->samples++; -} - -static void add_log_sample(struct thread_data *td, struct io_log *iolog, - unsigned long val, int ddir) -{ - if (iolog->nr_samples == iolog->max_samples) { - int new_size = sizeof(struct io_sample) * iolog->max_samples*2; - - iolog->log = realloc(iolog->log, new_size); - iolog->max_samples <<= 1; - } - - iolog->log[iolog->nr_samples].val = val; - iolog->log[iolog->nr_samples].time = mtime_since_now(&td->epoch); - iolog->log[iolog->nr_samples].ddir = ddir; - iolog->nr_samples++; -} - -static void add_clat_sample(struct thread_data *td, int ddir,unsigned long msec) -{ - add_stat_sample(&td->clat_stat[ddir], msec); - - if (td->clat_log) - add_log_sample(td, td->clat_log, msec, ddir); -} - -static void add_slat_sample(struct thread_data *td, int ddir,unsigned long msec) -{ - add_stat_sample(&td->slat_stat[ddir], msec); - - if (td->slat_log) - add_log_sample(td, td->slat_log, msec, ddir); -} - -static void add_bw_sample(struct thread_data *td, int ddir) -{ - unsigned long spent = mtime_since_now(&td->stat_sample_time[ddir]); - unsigned long rate; - - if (spent < td->bw_avg_time) - return; - - rate = (td->this_io_bytes[ddir] - td->stat_io_bytes[ddir]) / spent; - add_stat_sample(&td->bw_stat[ddir], rate); - - if (td->bw_log) - add_log_sample(td, td->bw_log, rate, ddir); - - gettimeofday(&td->stat_sample_time[ddir], NULL); - td->stat_io_bytes[ddir] = td->this_io_bytes[ddir]; -} - +/* + * 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; long r; if (!td->sequential) { - unsigned long max_blocks = td->io_size / td->min_bs; + unsigned long long max_blocks = td->io_size / td->min_bs; int loops = 50; do { - lrand48_r(&td->random_state, &r); - b = ((max_blocks - 1) * r / (RAND_MAX+1.0)); + r = os_random_long(&td->random_state); + b = ((max_blocks - 1) * r / (unsigned long long) (RAND_MAX+1.0)); rb = b + (td->file_offset / td->min_bs); loops--; } while (!random_map_free(td, rb) && loops); @@ -316,7 +208,7 @@ static unsigned int get_next_buflen(struct thread_data *td) if (td->min_bs == td->max_bs) buflen = td->min_bs; else { - lrand48_r(&td->bsrange_state, &r); + r = os_random_long(&td->bsrange_state); buflen = (1 + (double) (td->max_bs - 1) * r / (RAND_MAX + 1.0)); buflen = (buflen + td->min_bs - 1) & ~(td->min_bs - 1); } @@ -328,69 +220,8 @@ static unsigned int get_next_buflen(struct thread_data *td) } /* - * busy looping version for the last few usec + * Check if we are above the minimum rate given. */ -static void __usec_sleep(unsigned int usec) -{ - struct timeval start; - - gettimeofday(&start, NULL); - while (utime_since_now(&start) < usec) - nop; -} - -static void usec_sleep(struct thread_data *td, unsigned long usec) -{ - struct timespec req, rem; - - req.tv_sec = usec / 1000000; - req.tv_nsec = usec * 1000 - req.tv_sec * 1000000; - - do { - if (usec < 5000) { - __usec_sleep(usec); - break; - } - - rem.tv_sec = rem.tv_nsec = 0; - if (nanosleep(&req, &rem) < 0) - break; - - if ((rem.tv_sec + rem.tv_nsec) == 0) - break; - - req.tv_nsec = rem.tv_nsec; - req.tv_sec = rem.tv_sec; - - usec = rem.tv_sec * 1000000 + rem.tv_nsec / 1000; - } while (!td->terminate); -} - -static void rate_throttle(struct thread_data *td, unsigned long time_spent, - unsigned int bytes) -{ - unsigned long usec_cycle; - - if (!td->rate) - return; - - usec_cycle = td->rate_usec_cycle * (bytes / td->min_bs); - - if (time_spent < usec_cycle) { - unsigned long s = usec_cycle - time_spent; - - td->rate_pending_usleep += s; - if (td->rate_pending_usleep >= 100000) { - usec_sleep(td, td->rate_pending_usleep); - td->rate_pending_usleep = 0; - } - } else { - long overtime = time_spent - usec_cycle; - - td->rate_pending_usleep -= overtime; - } -} - static int check_min_rate(struct thread_data *td, struct timeval *now) { unsigned long spent; @@ -413,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("Client%d: min rate %d not met, got %ldKiB/sec\n", td->thread_number, 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; @@ -442,7 +273,7 @@ static void fill_random_bytes(struct thread_data *td, double r; while (len) { - drand48_r(&td->verify_state, &r); + r = os_random_double(&td->verify_state); /* * lrand48_r seems to be broken and only fill the bottom @@ -465,46 +296,44 @@ 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) { unsigned char *p = (unsigned char *) io_u->buf; unsigned long c; - int ret; p += sizeof(*hdr); c = crc32(p, hdr->len - sizeof(*hdr)); - ret = c != hdr->crc32; - if (ret) { - 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); + if (c != hdr->crc32) { + 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; } - return ret; + return 0; } static int verify_io_u_md5(struct verify_header *hdr, struct io_u *io_u) { unsigned char *p = (unsigned char *) io_u->buf; struct md5_ctx md5_ctx; - int ret; memset(&md5_ctx, 0, sizeof(md5_ctx)); p += sizeof(*hdr); md5_update(&md5_ctx, p, hdr->len - sizeof(*hdr)); - ret = memcmp(hdr->md5_digest, md5_ctx.hash, sizeof(md5_ctx.hash)); - if (ret) { - fprintf(stderr, "md5: verify failed at %llu/%u\n", io_u->offset, io_u->buflen); + if (memcmp(hdr->md5_digest, md5_ctx.hash, sizeof(md5_ctx.hash))) { + 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; } - return ret; + return 0; } static int verify_io_u(struct io_u *io_u) @@ -520,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; } @@ -541,9 +370,45 @@ 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)) { + struct timeval now; + unsigned long elapsed; + + gettimeofday(&now, NULL); + elapsed = mtime_since_now(&td->rwmix_switch); + + /* + * Check if it's time to seed a new data direction. + */ + if (elapsed >= td->rwmixcycle) { + int v; + long r; + + 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 + td->rwmix_ddir = DDIR_WRITE; + memcpy(&td->rwmix_switch, &now, sizeof(now)); + } + return td->rwmix_ddir; + } else if (td_read(td)) + return DDIR_READ; + else + return DDIR_WRITE; +} + /* * fill body of io_u->buf with random data and add a header with the - * (eg) sha1sum of that data. + * crc32 or md5 sum of that data. */ static void populate_io_u(struct thread_data *td, struct io_u *io_u) { @@ -566,13 +431,8 @@ static void populate_io_u(struct thread_data *td, struct io_u *io_u) memcpy(io_u->buf, &hdr, sizeof(hdr)); } -static int td_io_prep(struct thread_data *td, struct io_u *io_u, int read) +static int td_io_prep(struct thread_data *td, struct io_u *io_u) { - if (read) - io_u->ddir = DDIR_READ; - else - io_u->ddir = DDIR_WRITE; - if (td->io_prep && td->io_prep(td, io_u)) return 1; @@ -586,24 +446,59 @@ void put_io_u(struct thread_data *td, struct io_u *io_u) td->cur_depth--; } -#define queue_full(td) (list_empty(&(td)->io_u_freelist)) +static int fill_io_u(struct thread_data *td, struct io_u *io_u) +{ + /* + * If using an iolog, grab next piece if any available. + */ + if (td->read_iolog) + return read_iolog_get(td, io_u); + + /* + * No log, let the seq/rand engine retrieve the next position. + */ + if (!get_next_offset(td, &io_u->offset)) { + io_u->buflen = get_next_buflen(td); + + if (io_u->buflen) { + io_u->ddir = get_rw_ddir(td); + + /* + * If using a write iolog, store this entry. + */ + if (td->write_iolog) + write_iolog_put(td, io_u); + + return 0; + } + } + + return 1; +} + +#define queue_full(td) list_empty(&(td)->io_u_freelist) struct io_u *__get_io_u(struct thread_data *td) { - struct io_u *io_u; + struct io_u *io_u = NULL; - if (queue_full(td)) - return NULL; + if (!queue_full(td)) { + io_u = list_entry(td->io_u_freelist.next, struct io_u, list); + + io_u->error = 0; + io_u->resid = 0; + list_del(&io_u->list); + list_add(&io_u->list, &td->io_u_busylist); + td->cur_depth++; + } - io_u = list_entry(td->io_u_freelist.next, struct io_u, list); - io_u->error = 0; - io_u->resid = 0; - list_del(&io_u->list); - list_add(&io_u->list, &td->io_u_busylist); - td->cur_depth++; 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; @@ -617,13 +512,7 @@ static struct io_u *get_io_u(struct thread_data *td) td->last_pos += td->zone_skip; } - if (get_next_offset(td, &io_u->offset)) { - put_io_u(td, io_u); - return NULL; - } - - io_u->buflen = get_next_buflen(td); - if (!io_u->buflen) { + if (fill_io_u(td, io_u)) { put_io_u(td, io_u); return NULL; } @@ -636,7 +525,7 @@ static struct io_u *get_io_u(struct thread_data *td) return NULL; } - if (!td->sequential) + if (!td->read_iolog && !td->sequential) mark_random_map(td, io_u); td->last_pos += io_u->buflen; @@ -644,7 +533,7 @@ static struct io_u *get_io_u(struct thread_data *td) if (td->verify != VERIFY_NONE) populate_io_u(td, io_u); - if (td_io_prep(td, io_u, td_read(td))) { + if (td_io_prep(td, io_u)) { put_io_u(td, io_u); return NULL; } @@ -655,73 +544,26 @@ 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; } -static int get_next_verify(struct thread_data *td, - unsigned long long *offset, unsigned int *len) -{ - struct io_piece *ipo; - - if (list_empty(&td->io_hist_list)) - return 1; - - ipo = list_entry(td->io_hist_list.next, struct io_piece, list); - list_del(&ipo->list); - - *offset = ipo->offset; - *len = ipo->len; - free(ipo); - return 0; -} - -static void prune_io_piece_log(struct thread_data *td) +static int get_next_verify(struct thread_data *td, struct io_u *io_u) { struct io_piece *ipo; - while (!list_empty(&td->io_hist_list)) { + if (!list_empty(&td->io_hist_list)) { ipo = list_entry(td->io_hist_list.next, struct io_piece, list); list_del(&ipo->list); - free(ipo); - } -} - -/* - * log a succesful write, so we can unwind the log for verify - */ -static void log_io_piece(struct thread_data *td, struct io_u *io_u) -{ - struct io_piece *ipo = malloc(sizeof(struct io_piece)); - struct list_head *entry; - - INIT_LIST_HEAD(&ipo->list); - ipo->offset = io_u->offset; - ipo->len = io_u->buflen; - - /* - * for random io where the writes extend the file, it will typically - * be laid out with the block scattered as written. it's faster to - * read them in in that order again, so don't sort - */ - if (td->sequential || !td->overwrite) { - list_add_tail(&ipo->list, &td->io_hist_list); - return; - } - - /* - * for random io, sort the list so verify will run faster - */ - entry = &td->io_hist_list; - while ((entry = entry->prev) != &td->io_hist_list) { - struct io_piece *__ipo = list_entry(entry, struct io_piece, list); - if (__ipo->offset < ipo->offset) - break; + io_u->offset = ipo->offset; + io_u->buflen = ipo->len; + io_u->ddir = DDIR_READ; + free(ipo); + return 0; } - list_add(&ipo->list, entry); + return 1; } static int sync_td(struct thread_data *td) @@ -757,7 +599,7 @@ static void io_completed(struct thread_data *td, struct io_u *io_u, if (!io_u->error) { unsigned int bytes = io_u->buflen - io_u->resid; - int idx = io_u->ddir; + const int idx = io_u->ddir; td->io_blocks[idx]++; td->io_bytes[idx] += bytes; @@ -766,10 +608,10 @@ static void io_completed(struct thread_data *td, struct io_u *io_u, msec = mtime_since(&io_u->issue_time, &e); - add_clat_sample(td, io_u->ddir, msec); - add_bw_sample(td, io_u->ddir); + add_clat_sample(td, idx, msec); + add_bw_sample(td, idx); - if (td_write(td) && io_u->ddir == DDIR_WRITE) + if ((td_rw(td) || td_write(td)) && idx == DDIR_WRITE) log_io_piece(td, io_u); icd->bytes_done[idx] += bytes; @@ -793,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}; @@ -846,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; @@ -867,12 +717,12 @@ static void do_verify(struct thread_data *td) if (!io_u) break; - if (get_next_verify(td, &io_u->offset, &io_u->buflen)) { + if (get_next_verify(td, io_u)) { put_io_u(td, io_u); break; } - if (td_io_prep(td, io_u, 1)) { + if (td_io_prep(td, io_u)) { put_io_u(td, io_u); break; } @@ -926,12 +776,18 @@ static void do_verify(struct thread_data *td) td_set_runstate(td, TD_RUNNING); } +/* + * 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) { struct io_completion_data icd; 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; @@ -1007,8 +863,10 @@ static void do_io(struct thread_data *td) if (td->cur_depth) cleanup_pending_aio(td); - if (should_fsync(td)) + if (should_fsync(td) && td->end_fsync) { + td_set_runstate(td, TD_FSYNCING); sync_td(td); + } } static void cleanup_io(struct thread_data *td) @@ -1029,8 +887,10 @@ static int init_io(struct thread_data *td) return fio_posixaio_init(td); else if (td->io_engine == FIO_SGIO) return fio_sgio_init(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; } } @@ -1057,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; } @@ -1102,10 +962,6 @@ static int init_io_u(struct thread_data *td) } } - INIT_LIST_HEAD(&td->io_u_freelist); - INIT_LIST_HEAD(&td->io_u_busylist); - INIT_LIST_HEAD(&td->io_hist_list); - p = ALIGN(td->orig_buffer); for (i = 0; i < max_units; i++) { io_u = malloc(sizeof(*io_u)); @@ -1120,43 +976,39 @@ static int init_io_u(struct thread_data *td) return 0; } -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("Client%d: Laying out IO file (%LuMiB)\n", td->thread_number, size >> 20); - } else { - oflags = O_APPEND; - printf("Client%d: Extending IO file (%Lu -> %LuMiB)\n", td->thread_number, (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; @@ -1189,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; } @@ -1199,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; @@ -1251,13 +1108,13 @@ static int get_file_size(struct thread_data *td) return ret; if (td->file_offset > td->real_file_size) { - fprintf(stderr, "Client%d: offset extends end (%Lu > %Lu)\n", td->thread_number, 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, "Client%d: no io blocks\n", td->thread_number); + log_err("%s: no io blocks\n", td->name); td_verror(td, EINVAL); return 1; } @@ -1273,14 +1130,15 @@ static int setup_file_mmap(struct thread_data *td) { int flags; - if (td_read(td)) - flags = PROT_READ; - else { + if (td_rw(td)) + flags = PROT_READ | PROT_WRITE; + else if (td_write(td)) { flags = PROT_WRITE; if (td->verify != VERIFY_NONE) flags |= PROT_READ; - } + } else + flags = PROT_READ; td->mmap = mmap(NULL, td->file_size, flags, MAP_SHARED, td->fd, td->file_offset); if (td->mmap == MAP_FAILED) { @@ -1349,26 +1207,18 @@ 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; - - if (td_read(td)) { - if (td->filetype == FIO_TYPE_CHAR) - flags |= O_RDWR; - else - flags |= O_RDONLY; + flags |= OS_O_DIRECT; - td->fd = open(td->file_name, flags); - } else { + if (td_write(td) || td_rw(td)) { if (td->filetype == FIO_TYPE_FILE) { if (!td->overwrite) flags |= O_TRUNC; @@ -1381,6 +1231,13 @@ static int setup_file(struct thread_data *td) flags |= O_RDWR; td->fd = open(td->file_name, flags, 0600); + } else { + if (td->filetype == FIO_TYPE_CHAR) + flags |= O_RDWR; + else + flags |= O_RDONLY; + + td->fd = open(td->file_name, flags); } if (td->fd == -1) { @@ -1397,251 +1254,58 @@ static int setup_file(struct thread_data *td) return setup_file_mmap(td); } -static int check_dev_match(dev_t dev, char *path) +static int switch_ioscheduler(struct thread_data *td) { - unsigned int major, minor; - char line[256], *p; + char tmp[256], tmp2[128]; FILE *f; + int ret; + + sprintf(tmp, "%s/queue/scheduler", td->sysfs_root); - f = fopen(path, "r"); + f = fopen(tmp, "r+"); if (!f) { - perror("open path"); + td_verror(td, errno); return 1; } - p = fgets(line, sizeof(line), f); - if (!p) { + /* + * Set io scheduler. + */ + ret = fwrite(td->ioscheduler, strlen(td->ioscheduler), 1, f); + if (ferror(f) || ret != 1) { + td_verror(td, errno); fclose(f); return 1; } - if (sscanf(p, "%u:%u", &major, &minor) != 2) { + rewind(f); + + /* + * Read back and check that the selected scheduler is now the default. + */ + ret = fread(tmp, 1, sizeof(tmp), f); + if (ferror(f) || ret < 0) { + td_verror(td, errno); fclose(f); return 1; } - if (((major << 8) | minor) == dev) { + sprintf(tmp2, "[%s]", td->ioscheduler); + if (!strstr(tmp, tmp2)) { + log_err("fio: io scheduler %s not found\n", td->ioscheduler); + td_verror(td, EINVAL); fclose(f); - return 0; + return 1; } fclose(f); - return 1; + return 0; } -static int find_block_dir(dev_t dev, char *path) +static void clear_io_state(struct thread_data *td) { - struct dirent *dir; - struct stat st; - int found = 0; - DIR *D; - - D = opendir(path); - if (!D) - return 0; - - while ((dir = readdir(D)) != NULL) { - char full_path[256]; - - if (!strcmp(dir->d_name, ".") || !strcmp(dir->d_name, "..")) - continue; - if (!strcmp(dir->d_name, "device")) - continue; - - sprintf(full_path, "%s/%s", path, dir->d_name); - - if (!strcmp(dir->d_name, "dev")) { - if (!check_dev_match(dev, full_path)) { - found = 1; - break; - } - } - - if (stat(full_path, &st) == -1) { - perror("stat"); - break; - } - - if (!S_ISDIR(st.st_mode) || S_ISLNK(st.st_mode)) - continue; - - found = find_block_dir(dev, full_path); - if (found) { - strcpy(path, full_path); - break; - } - } - - closedir(D); - return found; -} - -static int get_io_ticks(struct disk_util *du, struct disk_util_stat *dus) -{ - unsigned in_flight; - char line[256]; - FILE *f; - char *p; - - f = fopen(du->path, "r"); - if (!f) - return 1; - - p = fgets(line, sizeof(line), f); - if (!p) { - fclose(f); - return 1; - } - - if (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) != 11) { - fclose(f); - return 1; - } - - fclose(f); - return 0; -} - -static void update_io_tick_disk(struct disk_util *du) -{ - struct disk_util_stat __dus, *dus, *ldus; - struct timeval t; - - if (get_io_ticks(du, &__dus)) - return; - - dus = &du->dus; - ldus = &du->last_dus; - - dus->sectors[0] += (__dus.sectors[0] - ldus->sectors[0]); - dus->sectors[1] += (__dus.sectors[1] - ldus->sectors[1]); - dus->ios[0] += (__dus.ios[0] - ldus->ios[0]); - dus->ios[1] += (__dus.ios[1] - ldus->ios[1]); - dus->merges[0] += (__dus.merges[0] - ldus->merges[0]); - dus->merges[1] += (__dus.merges[1] - ldus->merges[1]); - dus->ticks[0] += (__dus.ticks[0] - ldus->ticks[0]); - dus->ticks[1] += (__dus.ticks[1] - ldus->ticks[1]); - dus->io_ticks += (__dus.io_ticks - ldus->io_ticks); - dus->time_in_queue += (__dus.time_in_queue - ldus->time_in_queue); - - gettimeofday(&t, NULL); - du->msec += mtime_since(&du->time, &t); - memcpy(&du->time, &t, sizeof(t)); - memcpy(ldus, &__dus, sizeof(__dus)); -} - -static void update_io_ticks(void) -{ - struct list_head *entry; - struct disk_util *du; - - list_for_each(entry, &disk_list) { - du = list_entry(entry, struct disk_util, list); - update_io_tick_disk(du); - } -} - -static int disk_util_exists(dev_t dev) -{ - struct list_head *entry; - struct disk_util *du; - - list_for_each(entry, &disk_list) { - du = list_entry(entry, struct disk_util, list); - - if (du->dev == dev) - return 1; - } - - return 0; -} - -static void disk_util_add(dev_t dev, char *path) -{ - struct disk_util *du = malloc(sizeof(*du)); - - memset(du, 0, sizeof(*du)); - INIT_LIST_HEAD(&du->list); - sprintf(du->path, "%s/stat", path); - du->name = strdup(basename(path)); - du->dev = dev; - - gettimeofday(&du->time, NULL); - get_io_ticks(du, &du->last_dus); - - list_add_tail(&du->list, &disk_list); -} - -static void init_disk_util(struct thread_data *td) -{ - struct stat st; - char foo[256], tmp[256]; - dev_t dev; - char *p; - - if (!td->do_disk_util) - return; - - if (!stat(td->file_name, &st)) { - if (S_ISBLK(st.st_mode)) - dev = st.st_rdev; - else - dev = st.st_dev; - } else { - /* - * must be a file, open "." in that path - */ - strcpy(foo, td->file_name); - p = dirname(foo); - if (stat(p, &st)) { - perror("disk util stat"); - return; - } - - dev = st.st_dev; - } - - if (disk_util_exists(dev)) - return; - - sprintf(foo, "/sys/block"); - if (!find_block_dir(dev, foo)) - return; - - /* - * for md/dm, there's no queue dir. we already have the right place - */ - sprintf(tmp, "%s/stat", foo); - if (stat(tmp, &st)) { - /* - * if this is inside a partition dir, jump back to parent - */ - sprintf(tmp, "%s/queue", foo); - if (stat(tmp, &st)) { - p = dirname(foo); - sprintf(tmp, "%s/queue", p); - if (stat(tmp, &st)) { - fprintf(stderr, "unknown sysfs layout\n"); - return; - } - sprintf(foo, "%s", p); - } - } - - disk_util_add(dev, foo); -} - -static void disk_util_timer_arm(void) -{ - itimer.it_value.tv_sec = 0; - itimer.it_value.tv_usec = DISK_UTIL_MSEC * 1000; - setitimer(ITIMER_REAL, &itimer, NULL); -} - -static void clear_io_state(struct thread_data *td) -{ - if (td->io_engine == FIO_SYNCIO) - lseek(td->fd, SEEK_SET, 0); + if (td->io_engine == FIO_SYNCIO) + lseek(td->fd, SEEK_SET, 0); td->last_pos = 0; td->stat_io_bytes[0] = td->stat_io_bytes[1] = 0; @@ -1652,31 +1316,24 @@ static void clear_io_state(struct thread_data *td) memset(td->file_map, 0, td->num_maps * sizeof(long)); } -static void update_rusage_stat(struct thread_data *td) -{ - if (!(td->runtime[0] + td->runtime[1])) - return; - - getrusage(RUSAGE_SELF, &td->ru_end); - - td->usr_time += mtime_since(&td->ru_start.ru_utime, &td->ru_end.ru_utime); - td->sys_time += mtime_since(&td->ru_start.ru_stime, &td->ru_end.ru_stime); - td->ctx += td->ru_end.ru_nvcsw + td->ru_end.ru_nivcsw - (td->ru_start.ru_nvcsw + td->ru_start.ru_nivcsw); - - - memcpy(&td->ru_start, &td->ru_end, sizeof(td->ru_end)); -} - +/* + * 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; - int ret = 1; if (!td->use_thread) setsid(); td->pid = getpid(); + INIT_LIST_HEAD(&td->io_u_freelist); + INIT_LIST_HEAD(&td->io_u_busylist); + INIT_LIST_HEAD(&td->io_hist_list); + INIT_LIST_HEAD(&td->io_log_list); + if (init_io_u(td)) goto err; @@ -1688,6 +1345,9 @@ static void *thread_main(void *data) if (init_io(td)) goto err; + if (init_iolog(td)) + goto err; + if (td->ioprio) { if (ioprio_set(IOPRIO_WHO_PROCESS, 0, td->ioprio) == -1) { td_verror(td, errno); @@ -1695,17 +1355,29 @@ static void *thread_main(void *data) } } - sem_post(&startup_sem); - sem_wait(&td->mutex); - - if (!td->create_serialize && setup_file(td)) + if (nice(td->nice) < 0) { + td_verror(td, errno); goto err; + } if (init_random_state(td)) goto err; + if (td->ioscheduler && switch_ioscheduler(td)) + goto err; + + td_set_runstate(td, TD_INITIALIZED); + fio_sem_up(&startup_sem); + fio_sem_down(&td->mutex); + + if (!td->create_serialize && setup_file(td)) + goto err; + gettimeofday(&td->epoch, NULL); + if (td->exec_prerun) + system(td->exec_prerun); + while (td->loops--) { getrusage(RUSAGE_SELF, &td->ru_start); gettimeofday(&td->start, NULL); @@ -1720,6 +1392,9 @@ static void *thread_main(void *data) do_io(td); td->runtime[td->ddir] += mtime_since_now(&td->start); + if (td_rw(td) && td->io_bytes[td->ddir ^ 1]) + td->runtime[td->ddir ^ 1] = td->runtime[td->ddir]; + update_rusage_stat(td); if (td->error || td->terminate) @@ -1739,14 +1414,16 @@ static void *thread_main(void *data) break; } - ret = 0; - if (td->bw_log) finish_log(td, td->bw_log, "bw"); if (td->slat_log) finish_log(td, td->slat_log, "slat"); if (td->clat_log) finish_log(td, td->clat_log, "clat"); + if (td->write_iolog) + write_iolog_close(td); + if (td->exec_postrun) + system(td->exec_postrun); if (exitall_on_terminate) terminate_threads(td->groupid); @@ -1760,15 +1437,15 @@ err: munmap(td->mmap, td->file_size); cleanup_io(td); cleanup_io_u(td); - if (ret) { - sem_post(&startup_sem); - sem_wait(&td->mutex); - } td_set_runstate(td, TD_EXITED); return NULL; } +/* + * 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; @@ -1786,86 +1463,13 @@ static void *fork_main(int shmid, int offset) return NULL; } -static int calc_lat(struct io_stat *is, unsigned long *min, unsigned long *max, - double *mean, double *dev) -{ - double n; - - if (is->samples == 0) - return 0; - - *min = is->min_val; - *max = is->max_val; - - n = (double) is->samples; - *mean = (double) is->val / n; - *dev = sqrt(((double) is->val_sq - (*mean * *mean) / n) / (n - 1)); - if (!(*min + *max) && !(*mean + *dev)) - return 0; - - return 1; -} - -static void show_ddir_status(struct thread_data *td, struct group_run_stats *rs, - int ddir) -{ - char *ddir_str[] = { "read ", "write" }; - unsigned long min, max, bw; - double mean, dev; - - if (!td->runtime[ddir]) - return; - - bw = td->io_bytes[ddir] / td->runtime[ddir]; - printf(" %s: io=%6lluMiB, bw=%6luKiB/s, runt=%6lumsec\n", ddir_str[ddir], td->io_bytes[ddir] >> 20, bw, td->runtime[ddir]); - - if (calc_lat(&td->slat_stat[ddir], &min, &max, &mean, &dev)) - printf(" slat (msec): min=%5lu, max=%5lu, avg=%5.02f, dev=%5.02f\n", min, max, mean, dev); - - if (calc_lat(&td->clat_stat[ddir], &min, &max, &mean, &dev)) - printf(" clat (msec): min=%5lu, max=%5lu, avg=%5.02f, dev=%5.02f\n", min, max, mean, dev); - - if (calc_lat(&td->bw_stat[ddir], &min, &max, &mean, &dev)) { - double p_of_agg; - - p_of_agg = mean * 100 / (double) rs->agg[ddir]; - printf(" bw (KiB/s) : min=%5lu, max=%5lu, per=%3.2f%%, avg=%5.02f, dev=%5.02f\n", min, max, p_of_agg, mean, dev); - } -} - -static void show_thread_status(struct thread_data *td, - struct group_run_stats *rs) -{ - double usr_cpu, sys_cpu; - - if (!(td->io_bytes[0] + td->io_bytes[1]) && !td->error) - return; - - printf("Client%d (groupid=%d): err=%2d:\n", td->thread_number, td->groupid, td->error); - - show_ddir_status(td, rs, td->ddir); - show_ddir_status(td, rs, td->ddir ^ 1); - - if (td->runtime[0] + td->runtime[1]) { - double runt = td->runtime[0] + td->runtime[1]; - - usr_cpu = (double) td->usr_time * 100 / runt; - sys_cpu = (double) td->sys_time * 100 / runt; - } else { - usr_cpu = 0; - sys_cpu = 0; - } - - printf(" cpu : usr=%3.2f%%, sys=%3.2f%%, ctx=%lu\n", usr_cpu, sys_cpu, td->ctx); -} - +/* + * 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 = '_'; @@ -1874,7 +1478,12 @@ static void check_str_update(struct thread_data *td) c = 'E'; break; case TD_RUNNING: - if (td_read(td)) { + if (td_rw(td)) { + if (td->sequential) + c = 'M'; + else + c = 'm'; + } else if (td_read(td)) { if (td->sequential) c = 'R'; else @@ -1889,20 +1498,28 @@ 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; + case TD_INITIALIZED: + c = 'I'; + break; case TD_NOT_CREATED: 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; @@ -1931,19 +1548,32 @@ 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; unsigned int eta_sec = 0; bytes_total = td->total_io_size; - if (td->verify) - bytes_total <<= 1; + + /* + * if writing, bytes_total will be twice the size. If mixing, + * assume a 50/50 split and thus bytes_total will be 50% larger. + */ + if (td->verify) { + if (td_rw(td)) + bytes_total = bytes_total * 3 / 2; + else + bytes_total <<= 1; + } if (td->zone_size && td->zone_skip) bytes_total /= (td->zone_skip / td->zone_size); if (td->runstate == TD_RUNNING || td->runstate == TD_VERIFYING) { double perc; + bytes_done = td->io_bytes[DDIR_READ] + td->io_bytes[DDIR_WRITE]; perc = (double) bytes_done / (double) bytes_total; if (perc > 1.0) @@ -1951,9 +1581,10 @@ static int thread_eta(struct thread_data *td, unsigned long elapsed) eta_sec = (elapsed * (1.0 / perc)) - elapsed; - if (eta_sec > (td->timeout - elapsed)) + if (td->timeout && eta_sec > (td->timeout - elapsed)) eta_sec = td->timeout - elapsed; - } else if (td->runstate == TD_NOT_CREATED || td->runstate == TD_CREATED) { + } else if (td->runstate == TD_NOT_CREATED || td->runstate == TD_CREATED + || td->runstate == TD_INITIALIZED) { int t_eta = 0, r_eta = 0; /* @@ -1974,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; } @@ -1985,28 +1616,39 @@ 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); + else + eta_secs[i] = INT_MAX; check_str_update(td); } @@ -2026,18 +1668,18 @@ static void print_thread_status(void) } } - if (eta_sec == INT_MAX) - eta_sec = 0; - - if (eta_sec) { + if (eta_sec != INT_MAX && elapsed) { perc = (double) elapsed / (double) (elapsed + eta_sec); 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) { + if (eta_sec != INT_MAX) { perc *= 100.0; printf(": [%s] [%3.2f%% done] [eta %s]", run_str, perc,eta_str); } @@ -2046,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; @@ -2075,14 +1720,64 @@ static void reap_threads(int *nr_running, int *t_rate, int *m_rate) } } +static void fio_unpin_memory(void *pinned) +{ + if (pinned) { + if (munlock(pinned, mlock_size) < 0) + perror("munlock"); + munmap(pinned, mlock_size); + } +} + +static void *fio_pin_memory(void) +{ + unsigned long long phys_mem; + void *ptr; + + if (!mlock_size) + return NULL; + + /* + * Don't allow mlock of more than real_mem-128MB + */ + phys_mem = os_phys_mem(); + if (phys_mem) { + if ((mlock_size + 128 * 1024 * 1024) > phys_mem) { + mlock_size = phys_mem - 128 * 1024 * 1024; + fprintf(f_out, "fio: limiting mlocked memory to %lluMiB\n", mlock_size >> 20); + } + } + + ptr = mmap(NULL, mlock_size, PROT_READ | PROT_WRITE, MAP_PRIVATE | OS_MAP_ANON, 0, 0); + if (!ptr) { + perror("malloc locked mem"); + return NULL; + } + if (mlock(ptr, mlock_size) < 0) { + munmap(ptr, mlock_size); + perror("mlock"); + return NULL; + } + + return ptr; +} + +/* + * Main function for kicking off and reaping jobs, as needed. + */ static void run_threads(void) { struct thread_data *td; unsigned long spent; int i, todo, nr_running, m_rate, t_rate, nr_started; + void *mlocked_mem; - printf("Starting %d thread%s\n", thread_number, thread_number > 1 ? "s" : ""); - fflush(stdout); + mlocked_mem = fio_pin_memory(); + + 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); @@ -2116,6 +1811,10 @@ static void run_threads(void) gettimeofday(&genesis, NULL); while (todo) { + struct thread_data *map[MAX_JOBS]; + struct timeval this_start; + int this_jobs = 0, left; + /* * create threads (TD_NOT_CREATED -> TD_CREATED) */ @@ -2144,9 +1843,13 @@ static void run_threads(void) if (td->stonewall && (nr_started || nr_running)) break; + /* + * Set state to created. Thread will transition + * to TD_INITIALIZED when it's done setting up. + */ td_set_runstate(td, TD_CREATED); - sem_init(&startup_sem, 0, 1); - todo--; + map[this_jobs++] = td; + fio_sem_init(&startup_sem, 1); nr_started++; if (td->use_thread) { @@ -2156,7 +1859,7 @@ static void run_threads(void) } } else { if (fork()) - sem_wait(&startup_sem); + fio_sem_down(&startup_sem); else { fork_main(shm_id, i); exit(0); @@ -2165,12 +1868,51 @@ static void run_threads(void) } /* - * start created threads (TD_CREATED -> TD_RUNNING) + * Wait for the started threads to transition to + * TD_INITIALIZED. + */ + gettimeofday(&this_start, NULL); + left = this_jobs; + while (left) { + if (mtime_since_now(&this_start) > JOB_START_TIMEOUT) + break; + + usleep(100000); + + for (i = 0; i < this_jobs; i++) { + td = map[i]; + if (!td) + continue; + if (td->runstate == TD_INITIALIZED) { + map[i] = NULL; + left--; + } else if (td->runstate >= TD_EXITED) { + map[i] = NULL; + left--; + todo--; + nr_running++; /* work-around... */ + } + } + } + + if (left) { + log_err("fio: %d jobs failed to start\n", left); + for (i = 0; i < this_jobs; i++) { + td = map[i]; + if (!td) + continue; + kill(td->pid, SIGTERM); + } + break; + } + + /* + * start created threads (TD_INITIALIZED -> TD_RUNNING). */ for (i = 0; i < thread_number; i++) { td = &threads[i]; - if (td->runstate != TD_CREATED) + if (td->runstate != TD_INITIALIZED) continue; td_set_runstate(td, TD_RUNNING); @@ -2178,7 +1920,8 @@ static void run_threads(void) nr_started--; m_rate += td->ratemin; t_rate += td->rate; - sem_post(&td->mutex); + todo--; + fio_sem_up(&td->mutex); } reap_threads(&nr_running, &t_rate, &m_rate); @@ -2193,120 +1936,7 @@ static void run_threads(void) } update_io_ticks(); -} - -static void show_group_stats(struct group_run_stats *rs, int id) -{ - printf("\nRun status group %d (all jobs):\n", id); - - if (rs->max_run[DDIR_READ]) - printf(" READ: io=%lluMiB, aggrb=%llu, minb=%llu, maxb=%llu, mint=%llumsec, maxt=%llumsec\n", rs->io_mb[0], rs->agg[0], rs->min_bw[0], rs->max_bw[0], rs->min_run[0], rs->max_run[0]); - if (rs->max_run[DDIR_WRITE]) - printf(" WRITE: io=%lluMiB, aggrb=%llu, minb=%llu, maxb=%llu, mint=%llumsec, maxt=%llumsec\n", rs->io_mb[1], rs->agg[1], rs->min_bw[1], rs->max_bw[1], rs->min_run[1], rs->max_run[1]); -} - -static void show_disk_util(void) -{ - struct disk_util_stat *dus; - struct list_head *entry; - struct disk_util *du; - double util; - - printf("\nDisk stats (read/write):\n"); - - list_for_each(entry, &disk_list) { - du = list_entry(entry, struct disk_util, list); - dus = &du->dus; - - util = (double) 100 * du->dus.io_ticks / (double) du->msec; - if (util > 100.0) - util = 100.0; - - printf(" %s: ios=%u/%u, merge=%u/%u, ticks=%u/%u, in_queue=%u, util=%3.2f%%\n", du->name, dus->ios[0], dus->ios[1], dus->merges[0], dus->merges[1], dus->ticks[0], dus->ticks[1], dus->time_in_queue, util); - } -} - -static void show_run_stats(void) -{ - struct group_run_stats *runstats, *rs; - struct thread_data *td; - int i; - - runstats = malloc(sizeof(struct group_run_stats) * (groupid + 1)); - - for (i = 0; i < groupid + 1; i++) { - rs = &runstats[i]; - - memset(rs, 0, sizeof(*rs)); - rs->min_bw[0] = rs->min_run[0] = ~0UL; - rs->min_bw[1] = rs->min_run[1] = ~0UL; - } - - for (i = 0; i < thread_number; i++) { - unsigned long rbw, wbw; - - td = &threads[i]; - - if (td->error) { - printf("Client%d: %s\n", td->thread_number, td->verror); - continue; - } - - rs = &runstats[td->groupid]; - - if (td->runtime[0] < rs->min_run[0] || !rs->min_run[0]) - rs->min_run[0] = td->runtime[0]; - if (td->runtime[0] > rs->max_run[0]) - rs->max_run[0] = td->runtime[0]; - if (td->runtime[1] < rs->min_run[1] || !rs->min_run[1]) - rs->min_run[1] = td->runtime[1]; - if (td->runtime[1] > rs->max_run[1]) - rs->max_run[1] = td->runtime[1]; - - rbw = wbw = 0; - if (td->runtime[0]) - rbw = td->io_bytes[0] / td->runtime[0]; - if (td->runtime[1]) - wbw = td->io_bytes[1] / td->runtime[1]; - - if (rbw < rs->min_bw[0]) - rs->min_bw[0] = rbw; - if (wbw < rs->min_bw[1]) - rs->min_bw[1] = wbw; - if (rbw > rs->max_bw[0]) - rs->max_bw[0] = rbw; - if (wbw > rs->max_bw[1]) - rs->max_bw[1] = wbw; - - rs->io_mb[0] += td->io_bytes[0] >> 20; - rs->io_mb[1] += td->io_bytes[1] >> 20; - } - - for (i = 0; i < groupid + 1; i++) { - rs = &runstats[i]; - - if (rs->max_run[0]) - rs->agg[0] = (rs->io_mb[0]*1024*1000) / rs->max_run[0]; - if (rs->max_run[1]) - rs->agg[1] = (rs->io_mb[1]*1024*1000) / rs->max_run[1]; - } - - /* - * don't overwrite last signal output - */ - printf("\n"); - - for (i = 0; i < thread_number; i++) { - td = &threads[i]; - rs = &runstats[td->groupid]; - - show_thread_status(td, rs); - } - - for (i = 0; i < groupid + 1; i++) - show_group_stats(&runstats[i], i); - - show_disk_util(); + fio_unpin_memory(mlocked_mem); } int main(int argc, char *argv[]) @@ -2315,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; }