Don't silently terminate td when no I/O performed due to error
[fio.git] / backend.c
index c3ad8312de67f13d48e5e67ee9ae117945ba9a22..fb027440711e2128f0acae11805f35fca9b81072 100644 (file)
--- a/backend.c
+++ b/backend.c
@@ -76,9 +76,6 @@ int shm_id = 0;
 int temp_stall_ts;
 unsigned long done_secs = 0;
 
-#define PAGE_ALIGN(buf)        \
-       (char *) (((uintptr_t) (buf) + page_mask) & ~page_mask)
-
 #define JOB_START_TIMEOUT      (5 * 1000)
 
 static void sig_int(int sig)
@@ -180,8 +177,8 @@ static bool __check_min_rate(struct thread_data *td, struct timeval *now,
                         * check bandwidth specified rate
                         */
                        if (bytes < td->rate_bytes[ddir]) {
-                               log_err("%s: min rate %u not met\n", td->o.name,
-                                                               ratemin);
+                               log_err("%s: rate_min=%uB/s not met, only transferred %lluB\n",
+                                       td->o.name, ratemin, bytes);
                                return true;
                        } else {
                                if (spent)
@@ -191,9 +188,8 @@ static bool __check_min_rate(struct thread_data *td, struct timeval *now,
 
                                if (rate < ratemin ||
                                    bytes < td->rate_bytes[ddir]) {
-                                       log_err("%s: min rate %u not met, got"
-                                               " %luKB/sec\n", td->o.name,
-                                                       ratemin, rate);
+                                       log_err("%s: rate_min=%uB/s not met, got %luB/s\n",
+                                               td->o.name, ratemin, rate);
                                        return true;
                                }
                        }
@@ -202,8 +198,8 @@ static bool __check_min_rate(struct thread_data *td, struct timeval *now,
                         * checks iops specified rate
                         */
                        if (iops < rate_iops) {
-                               log_err("%s: min iops rate %u not met\n",
-                                               td->o.name, rate_iops);
+                               log_err("%s: rate_iops_min=%u not met, only performed %lu IOs\n",
+                                               td->o.name, rate_iops, iops);
                                return true;
                        } else {
                                if (spent)
@@ -213,9 +209,8 @@ static bool __check_min_rate(struct thread_data *td, struct timeval *now,
 
                                if (rate < rate_iops_min ||
                                    iops < td->rate_blocks[ddir]) {
-                                       log_err("%s: min iops rate %u not met,"
-                                               " got %lu\n", td->o.name,
-                                                       rate_iops_min, rate);
+                                       log_err("%s: rate_iops_min=%u not met, got %lu IOPS\n",
+                                               td->o.name, rate_iops_min, rate);
                                        return true;
                                }
                        }
@@ -441,11 +436,8 @@ static int wait_for_completions(struct thread_data *td, struct timeval *time)
        int min_evts = 0;
        int ret;
 
-       if (td->flags & TD_F_REGROW_LOGS) {
-               ret = io_u_quiesce(td);
-               regrow_logs(td);
-               return ret;
-       }
+       if (td->flags & TD_F_REGROW_LOGS)
+               return io_u_quiesce(td);
 
        /*
         * if the queue is full, we MUST reap at least 1 event
@@ -571,6 +563,28 @@ static inline bool io_in_polling(struct thread_data *td)
        return !td->o.iodepth_batch_complete_min &&
                   !td->o.iodepth_batch_complete_max;
 }
+/*
+ * Unlinks files from thread data fio_file structure
+ */
+static int unlink_all_files(struct thread_data *td)
+{
+       struct fio_file *f;
+       unsigned int i;
+       int ret = 0;
+
+       for_each_file(td, f, i) {
+               if (f->filetype != FIO_TYPE_FILE)
+                       continue;
+               ret = td_io_unlink_file(td, f);
+               if (ret)
+                       break;
+       }
+
+       if (ret)
+               td_verror(td, ret, "unlink_all_files");
+
+       return ret;
+}
 
 /*
  * The main verify engine. Runs over the writes we previously submitted,
@@ -673,7 +687,7 @@ static void do_verify(struct thread_data *td, uint64_t verify_bytes)
                                        continue;
                                } else if (io_u->ddir == DDIR_TRIM) {
                                        io_u->ddir = DDIR_READ;
-                                       io_u_set(io_u, IO_U_F_TRIMMED);
+                                       io_u_set(td, io_u, IO_U_F_TRIMMED);
                                        break;
                                } else if (io_u->ddir == DDIR_WRITE) {
                                        io_u->ddir = DDIR_READ;
@@ -749,21 +763,21 @@ static bool exceeds_number_ios(struct thread_data *td)
        return number_ios >= (td->o.number_ios * td->loops);
 }
 
-static bool io_issue_bytes_exceeded(struct thread_data *td)
+static bool io_bytes_exceeded(struct thread_data *td, uint64_t *this_bytes)
 {
        unsigned long long bytes, limit;
 
        if (td_rw(td))
-               bytes = td->io_issue_bytes[DDIR_READ] + td->io_issue_bytes[DDIR_WRITE];
+               bytes = this_bytes[DDIR_READ] + this_bytes[DDIR_WRITE];
        else if (td_write(td))
-               bytes = td->io_issue_bytes[DDIR_WRITE];
+               bytes = this_bytes[DDIR_WRITE];
        else if (td_read(td))
-               bytes = td->io_issue_bytes[DDIR_READ];
+               bytes = this_bytes[DDIR_READ];
        else
-               bytes = td->io_issue_bytes[DDIR_TRIM];
+               bytes = this_bytes[DDIR_TRIM];
 
-       if (td->o.io_limit)
-               limit = td->o.io_limit;
+       if (td->o.io_size)
+               limit = td->o.io_size;
        else
                limit = td->o.size;
 
@@ -771,26 +785,14 @@ static bool io_issue_bytes_exceeded(struct thread_data *td)
        return bytes >= limit || exceeds_number_ios(td);
 }
 
-static bool io_complete_bytes_exceeded(struct thread_data *td)
+static bool io_issue_bytes_exceeded(struct thread_data *td)
 {
-       unsigned long long bytes, limit;
-
-       if (td_rw(td))
-               bytes = td->this_io_bytes[DDIR_READ] + td->this_io_bytes[DDIR_WRITE];
-       else if (td_write(td))
-               bytes = td->this_io_bytes[DDIR_WRITE];
-       else if (td_read(td))
-               bytes = td->this_io_bytes[DDIR_READ];
-       else
-               bytes = td->this_io_bytes[DDIR_TRIM];
-
-       if (td->o.io_limit)
-               limit = td->o.io_limit;
-       else
-               limit = td->o.size;
+       return io_bytes_exceeded(td, td->io_issue_bytes);
+}
 
-       limit *= td->loops;
-       return bytes >= limit || exceeds_number_ios(td);
+static bool io_complete_bytes_exceeded(struct thread_data *td)
+{
+       return io_bytes_exceeded(td, td->this_io_bytes);
 }
 
 /*
@@ -809,13 +811,14 @@ static long long usec_for_io(struct thread_data *td, enum fio_ddir ddir)
                uint64_t val;
                iops = bps / td->o.bs[ddir];
                val = (int64_t) (1000000 / iops) *
-                               -logf(__rand_0_1(&td->poisson_state));
+                               -logf(__rand_0_1(&td->poisson_state[ddir]));
                if (val) {
-                       dprint(FD_RATE, "poisson rate iops=%llu\n",
-                                       (unsigned long long) 1000000 / val);
+                       dprint(FD_RATE, "poisson rate iops=%llu, ddir=%d\n",
+                                       (unsigned long long) 1000000 / val,
+                                       ddir);
                }
-               td->last_usec += val;
-               return td->last_usec;
+               td->last_usec[ddir] += val;
+               return td->last_usec[ddir];
        } else if (bps) {
                secs = bytes / bps;
                remainder = bytes % bps;
@@ -849,11 +852,11 @@ static void do_io(struct thread_data *td, uint64_t *bytes_done)
 
        total_bytes = td->o.size;
        /*
-       * Allow random overwrite workloads to write up to io_limit
+       * Allow random overwrite workloads to write up to io_size
        * before starting verification phase as 'size' doesn't apply.
        */
        if (td_write(td) && td_random(td) && td->o.norandommap)
-               total_bytes = max(total_bytes, (uint64_t) td->o.io_limit);
+               total_bytes = max(total_bytes, (uint64_t) td->o.io_size);
        /*
         * If verify_backlog is enabled, we'll run the verify in this
         * handler as well. For that case, we may need up to twice the
@@ -1002,7 +1005,7 @@ reap:
                if (ret < 0)
                        break;
                if (!ddir_rw_sum(td->bytes_done) &&
-                   !(td->io_ops->flags & FIO_NOIO))
+                   !td_ioengine_flagged(td, FIO_NOIO))
                        continue;
 
                if (!in_ramp_time(td) && should_check_rate(td)) {
@@ -1153,7 +1156,7 @@ static int init_io_u(struct thread_data *td)
        td->orig_buffer_size = (unsigned long long) max_bs
                                        * (unsigned long long) max_units;
 
-       if ((td->io_ops->flags & FIO_NOIO) || !(td_read(td) || td_write(td)))
+       if (td_ioengine_flagged(td, FIO_NOIO) || !(td_read(td) || td_write(td)))
                data_xfer = 0;
 
        err = 0;
@@ -1173,7 +1176,7 @@ static int init_io_u(struct thread_data *td)
         * lucky and the allocator gives us an aligned address.
         */
        if (td->o.odirect || td->o.mem_align || td->o.oatomic ||
-           (td->io_ops->flags & FIO_RAWIO))
+           td_ioengine_flagged(td, FIO_RAWIO))
                td->orig_buffer_size += page_mask + td->o.mem_align;
 
        if (td->o.mem_type == MEM_SHMHUGE || td->o.mem_type == MEM_MMAPHUGE) {
@@ -1192,8 +1195,8 @@ static int init_io_u(struct thread_data *td)
                return 1;
 
        if (td->o.odirect || td->o.mem_align || td->o.oatomic ||
-           (td->io_ops->flags & FIO_RAWIO))
-               p = PAGE_ALIGN(td->orig_buffer) + td->o.mem_align;
+           td_ioengine_flagged(td, FIO_RAWIO))
+               p = PTR_ALIGN(td->orig_buffer, page_mask) + td->o.mem_align;
        else
                p = td->orig_buffer;
 
@@ -1259,6 +1262,10 @@ static int init_io_u(struct thread_data *td)
        return 0;
 }
 
+/*
+ * This function is Linux specific.
+ * FIO_HAVE_IOSCHED_SWITCH enabled currently means it's Linux.
+ */
 static int switch_ioscheduler(struct thread_data *td)
 {
 #ifdef FIO_HAVE_IOSCHED_SWITCH
@@ -1266,10 +1273,11 @@ static int switch_ioscheduler(struct thread_data *td)
        FILE *f;
        int ret;
 
-       if (td->io_ops->flags & FIO_DISKLESSIO)
+       if (td_ioengine_flagged(td, FIO_DISKLESSIO))
                return 0;
 
-       sprintf(tmp, "%s/queue/scheduler", td->sysfs_root);
+       assert(td->files && td->files[0]);
+       sprintf(tmp, "%s/queue/scheduler", td->files[0]->du->sysfs_root);
 
        f = fopen(tmp, "r+");
        if (!f) {
@@ -1309,6 +1317,14 @@ static int switch_ioscheduler(struct thread_data *td)
         */
        tmp[strlen(tmp) - 1] = '\0';
 
+       /*
+        * Write to "none" entry doesn't fail, so check the result here.
+        */
+       if (!strcmp(tmp, "none")) {
+               log_err("fio: io scheduler is not tunable\n");
+               fclose(f);
+               return 0;
+       }
 
        sprintf(tmp2, "[%s]", td->o.ioscheduler);
        if (!strstr(tmp, tmp2)) {
@@ -1340,8 +1356,8 @@ static bool keep_running(struct thread_data *td)
        if (exceeds_number_ios(td))
                return false;
 
-       if (td->o.io_limit)
-               limit = td->o.io_limit;
+       if (td->o.io_size)
+               limit = td->o.io_size;
        else
                limit = td->o.size;
 
@@ -1349,14 +1365,14 @@ static bool keep_running(struct thread_data *td)
                uint64_t diff;
 
                /*
-                * If the difference is less than the minimum IO size, we
+                * If the difference is less than the maximum IO size, we
                 * are done.
                 */
                diff = limit - ddir_rw_sum(td->io_bytes);
                if (diff < td_max_bs(td))
                        return false;
 
-               if (fio_files_done(td) && !td->o.io_limit)
+               if (fio_files_done(td) && !td->o.io_size)
                        return false;
 
                return true;
@@ -1402,7 +1418,7 @@ static uint64_t do_dry_run(struct thread_data *td)
                if (IS_ERR_OR_NULL(io_u))
                        break;
 
-               io_u_set(io_u, IO_U_F_FLIGHT);
+               io_u_set(td, io_u, IO_U_F_FLIGHT);
                io_u->error = 0;
                io_u->resid = 0;
                if (ddir_rw(acct_ddir(io_u)))
@@ -1441,6 +1457,8 @@ static void *thread_main(void *data)
        struct thread_data *td = fd->td;
        struct thread_options *o = &td->o;
        struct sk_out *sk_out = fd->sk_out;
+       uint64_t bytes_done[DDIR_RWDIR_CNT];
+       int deadlock_loop_cnt;
        int clear_state;
        int ret;
 
@@ -1645,10 +1663,11 @@ static void *thread_main(void *data)
        if (rate_submit_init(td, sk_out))
                goto err;
 
-       fio_gettime(&td->epoch, NULL);
+       set_epoch_time(td, o->log_unix_epoch);
        fio_getrusage(&td->ru_start);
        memcpy(&td->bw_sample_time, &td->epoch, sizeof(td->epoch));
        memcpy(&td->iops_sample_time, &td->epoch, sizeof(td->epoch));
+       memcpy(&td->ss.prev_time, &td->epoch, sizeof(td->epoch));
 
        if (o->ratemin[DDIR_READ] || o->ratemin[DDIR_WRITE] ||
                        o->ratemin[DDIR_TRIM]) {
@@ -1660,23 +1679,27 @@ static void *thread_main(void *data)
                                        sizeof(td->bw_sample_time));
        }
 
+       memset(bytes_done, 0, sizeof(bytes_done));
        clear_state = 0;
+
        while (keep_running(td)) {
                uint64_t verify_bytes;
 
                fio_gettime(&td->start, NULL);
                memcpy(&td->tv_cache, &td->start, sizeof(td->start));
 
-               if (clear_state)
+               if (clear_state) {
                        clear_io_state(td, 0);
 
+                       if (o->unlink_each_loop && unlink_all_files(td))
+                               break;
+               }
+
                prune_io_piece_log(td);
 
-               if (td->o.verify_only && (td_write(td) || td_rw(td)))
+               if (td->o.verify_only && td_write(td))
                        verify_bytes = do_dry_run(td);
                else {
-                       uint64_t bytes_done[DDIR_RWDIR_CNT];
-
                        do_io(td, bytes_done);
 
                        if (!ddir_rw_sum(bytes_done)) {
@@ -1688,6 +1711,14 @@ static void *thread_main(void *data)
                        }
                }
 
+               /*
+                * If we took too long to shut down, the main thread could
+                * already consider us reaped/exited. If that happens, break
+                * out and clean up.
+                */
+               if (td->runstate >= TD_EXITED)
+                       break;
+
                clear_state = 1;
 
                /*
@@ -1697,9 +1728,19 @@ static void *thread_main(void *data)
                 * the rusage_sem, which would never get upped because
                 * this thread is waiting for the stat mutex.
                 */
-               check_update_rusage(td);
+               deadlock_loop_cnt = 0;
+               do {
+                       check_update_rusage(td);
+                       if (!fio_mutex_down_trylock(stat_mutex))
+                               break;
+                       usleep(1000);
+                       if (deadlock_loop_cnt++ > 5000) {
+                               log_err("fio seems to be stuck grabbing stat_mutex, forcibly exiting\n");
+                               td->error = EDEADLK;
+                               goto err;
+                       }
+               } while (1);
 
-               fio_mutex_down(stat_mutex);
                if (td_read(td) && td->io_bytes[DDIR_READ])
                        update_runtime(td, elapsed_us, DDIR_READ);
                if (td_write(td) && td->io_bytes[DDIR_WRITE])
@@ -1714,7 +1755,7 @@ static void *thread_main(void *data)
 
                if (!o->do_verify ||
                    o->verify == VERIFY_NONE ||
-                   (td->io_ops->flags & FIO_UNIDIR))
+                   td_ioengine_flagged(td, FIO_UNIDIR))
                        continue;
 
                clear_io_state(td, 0);
@@ -1737,6 +1778,18 @@ static void *thread_main(void *data)
                        break;
        }
 
+       /*
+        * If td ended up with no I/O when it should have had,
+        * then something went wrong unless FIO_NOIO or FIO_DISKLESSIO.
+        * (Are we not missing other flags that can be ignored ?)
+        */
+       if ((td->o.size || td->o.io_size) && !ddir_rw_sum(bytes_done) &&
+           !(td_ioengine_flagged(td, FIO_NOIO) ||
+             td_ioengine_flagged(td, FIO_DISKLESSIO)))
+               log_err("%s: No I/O performed by %s, "
+                        "perhaps try --debug=io option for details?\n",
+                        td->o.name, td->io_ops->name);
+
        td_set_runstate(td, TD_FINISHING);
 
        update_rusage_stat(td);
@@ -1797,9 +1850,6 @@ err:
        if (o->write_iolog_file)
                write_iolog_close(td);
 
-       fio_mutex_remove(td->mutex);
-       td->mutex = NULL;
-
        td_set_runstate(td, TD_EXITED);
 
        /*
@@ -1823,8 +1873,8 @@ static void dump_td_info(struct thread_data *td)
 /*
  * Run over the job map and reap the threads that have exited, if any.
  */
-static void reap_threads(unsigned int *nr_running, unsigned int *t_rate,
-                        unsigned int *m_rate)
+static void reap_threads(unsigned int *nr_running, uint64_t *t_rate,
+                        uint64_t *m_rate)
 {
        struct thread_data *td;
        unsigned int cputhreads, realthreads, pending;
@@ -2017,8 +2067,16 @@ static bool check_mount_writes(struct thread_data *td)
        if (!td_write(td) || td->o.allow_mounted_write)
                return false;
 
+       /*
+        * If FIO_HAVE_CHARDEV_SIZE is defined, it's likely that chrdevs
+        * are mkfs'd and mounted.
+        */
        for_each_file(td, f, i) {
-               if (f->filetype != FIO_TYPE_BD)
+#ifdef FIO_HAVE_CHARDEV_SIZE
+               if (f->filetype != FIO_TYPE_BLOCK && f->filetype != FIO_TYPE_CHAR)
+#else
+               if (f->filetype != FIO_TYPE_BLOCK)
+#endif
                        continue;
                if (device_is_mounted(f->file_name))
                        goto mounted;
@@ -2026,7 +2084,7 @@ static bool check_mount_writes(struct thread_data *td)
 
        return false;
 mounted:
-       log_err("fio: %s appears mounted, and 'allow_mounted_write' isn't set. Aborting.", f->file_name);
+       log_err("fio: %s appears mounted, and 'allow_mounted_write' isn't set. Aborting.\n", f->file_name);
        return true;
 }
 
@@ -2062,7 +2120,8 @@ static bool waitee_running(struct thread_data *me)
 static void run_threads(struct sk_out *sk_out)
 {
        struct thread_data *td;
-       unsigned int i, todo, nr_running, m_rate, t_rate, nr_started;
+       unsigned int i, todo, nr_running, nr_started;
+       uint64_t m_rate, t_rate;
        uint64_t spent;
 
        if (fio_gtod_offload && fio_start_gtod_thread())
@@ -2376,11 +2435,19 @@ int fio_backend(struct sk_out *sk_out)
        }
 
        for_each_td(td, i) {
+               if (td->ss.dur) {
+                       if (td->ss.iops_data != NULL) {
+                               free(td->ss.iops_data);
+                               free(td->ss.bw_data);
+                       }
+               }
                fio_options_free(td);
                if (td->rusage_sem) {
                        fio_mutex_remove(td->rusage_sem);
                        td->rusage_sem = NULL;
                }
+               fio_mutex_remove(td->mutex);
+               td->mutex = NULL;
        }
 
        free_disk_util();