Use log_info() throughout
[fio.git] / fio.c
diff --git a/fio.c b/fio.c
index c5b85aeb8c88ca2ef732135fc74ffb8d789325c1..b5fada8983e90c2caeb4ca7c4c9ed1bed9a63e5a 100644 (file)
--- a/fio.c
+++ b/fio.c
 #include "fio.h"
 #include "os.h"
 
-static unsigned long page_mask;
+unsigned long page_mask;
+unsigned long page_size;
 #define ALIGN(buf)     \
        (char *) (((unsigned long) (buf) + page_mask) & ~page_mask)
 
 int groupid = 0;
 int thread_number = 0;
+int nr_process = 0;
+int nr_thread = 0;
 int shm_id = 0;
 int temp_stall_ts;
 
-static volatile int startup_sem;
+static struct fio_sem *startup_sem;
 static volatile int fio_abort;
 static int exit_value;
 
@@ -60,17 +63,20 @@ static inline void td_set_runstate(struct thread_data *td, int runstate)
        td->runstate = runstate;
 }
 
-static void terminate_threads(int group_id, int forced_kill)
+static void terminate_threads(int group_id)
 {
        struct thread_data *td;
        int i;
 
        for_each_td(td, i) {
                if (group_id == TERMINATE_ALL || groupid == td->groupid) {
+                       /*
+                        * if the thread is running, just let it exit
+                        */
+                       if (td->runstate < TD_RUNNING)
+                               kill(td->pid, SIGQUIT);
                        td->terminate = 1;
                        td->start_delay = 0;
-                       if (forced_kill)
-                               td_set_runstate(td, TD_EXITED);
                }
        }
 }
@@ -86,7 +92,7 @@ static void sig_handler(int sig)
                default:
                        printf("\nfio: terminating on signal %d\n", sig);
                        fflush(stdout);
-                       terminate_threads(TERMINATE_ALL, 0);
+                       terminate_threads(TERMINATE_ALL);
                        break;
        }
 }
@@ -100,6 +106,12 @@ static int check_min_rate(struct thread_data *td, struct timeval *now)
        unsigned long spent;
        unsigned long rate;
 
+       /*
+        * No minimum rate set, always ok
+        */
+       if (!td->ratemin)
+               return 0;
+
        /*
         * allow a 2 second settle period in the beginning
         */
@@ -120,12 +132,12 @@ static int check_min_rate(struct thread_data *td, struct timeval *now)
                        return 0;
 
                if (bytes < td->rate_bytes) {
-                       fprintf(f_out, "%s: min rate %u not met\n", td->name, td->ratemin);
+                       log_err("%s: min rate %u not met\n", td->name, td->ratemin);
                        return 1;
                } else {
                        rate = (bytes - td->rate_bytes) / spent;
                        if (rate < td->ratemin || bytes < td->rate_bytes) {
-                               fprintf(f_out, "%s: min rate %u not met, got %luKiB/sec\n", td->name, td->ratemin, rate);
+                               log_err("%s: min rate %u not met, got %luKiB/sec\n", td->name, td->ratemin, rate);
                                return 1;
                        }
                }
@@ -237,20 +249,23 @@ requeue:
 }
 
 /*
- * The main verify engine. Runs over the writes we previusly submitted,
+ * The main verify engine. Runs over the writes we previously submitted,
  * reads the blocks back in, and checks the crc/md5 of the data.
  */
 static void do_verify(struct thread_data *td)
 {
        struct fio_file *f;
        struct io_u *io_u;
-       int ret, i, min_events;
+       int ret, min_events;
+       unsigned int i;
 
        /*
         * sync io first and invalidate cache, to make sure we really
         * read from disk.
         */
        for_each_file(td, f, i) {
+               if (!(f->flags & FIO_FILE_OPEN))
+                       continue;
                if (fio_io_sync(td, f))
                        break;
                if (file_invalidate_cache(td, f))
@@ -264,6 +279,8 @@ static void do_verify(struct thread_data *td)
 
        io_u = NULL;
        while (!td->terminate) {
+               int ret2;
+
                io_u = __get_io_u(td);
                if (!io_u)
                        break;
@@ -284,29 +301,39 @@ static void do_verify(struct thread_data *td)
                }
 
                io_u->end_io = verify_io_u;
-requeue:
-               ret = td_io_queue(td, io_u);
 
+               ret = td_io_queue(td, io_u);
                switch (ret) {
                case FIO_Q_COMPLETED:
                        if (io_u->error)
                                ret = -io_u->error;
-                       if (io_u->xfer_buflen != io_u->resid && io_u->resid) {
+                       else if (io_u->resid) {
                                int bytes = io_u->xfer_buflen - io_u->resid;
 
+                               /*
+                                * zero read, fail
+                                */
+                               if (!bytes) {
+                                       td_verror(td, ENODATA, "full resid");
+                                       put_io_u(td, io_u);
+                                       break;
+                               }
                                io_u->xfer_buflen = io_u->resid;
                                io_u->xfer_buf += bytes;
-                               goto requeue;
+                               requeue_io_u(td, &io_u);
+                       } else {
+                               ret = io_u_sync_complete(td, io_u);
+                               if (ret < 0)
+                                       break;
                        }
-                       ret = io_u_sync_complete(td, io_u);
-                       if (ret < 0)
-                               break;
                        continue;
                case FIO_Q_QUEUED:
                        break;
                case FIO_Q_BUSY:
                        requeue_io_u(td, &io_u);
-                       ret = td_io_commit(td);
+                       ret2 = td_io_commit(td);
+                       if (ret2 < 0)
+                               ret = ret2;
                        break;
                default:
                        assert(ret < 0);
@@ -348,31 +375,6 @@ requeue:
        td_set_runstate(td, TD_RUNNING);
 }
 
-/*
- * Not really an io thread, all it does is burn CPU cycles in the specified
- * manner.
- */
-static void do_cpuio(struct thread_data *td)
-{
-       struct timeval e;
-       int split = 100 / td->cpuload;
-       int i = 0;
-
-       while (!td->terminate) {
-               fio_gettime(&e, NULL);
-
-               if (runtime_exceeded(td, &e))
-                       break;
-
-               if (!(i % split))
-                       __usec_sleep(10000);
-               else
-                       usec_sleep(td, 10000);
-
-               i++;
-       }
-}
-
 /*
  * Main IO worker function. It retrieves io_u's to process and queues
  * and reaps them, checking for rate and errors along the way.
@@ -381,7 +383,8 @@ static void do_io(struct thread_data *td)
 {
        struct timeval s;
        unsigned long usec;
-       int i, ret = 0;
+       unsigned int i;
+       int ret = 0;
 
        td_set_runstate(td, TD_RUNNING);
 
@@ -390,6 +393,7 @@ static void do_io(struct thread_data *td)
                long bytes_done = 0;
                int min_evts = 0;
                struct io_u *io_u;
+               int ret2;
 
                if (td->terminate)
                        break;
@@ -404,26 +408,33 @@ static void do_io(struct thread_data *td)
                        put_io_u(td, io_u);
                        break;
                }
-requeue:
-               ret = td_io_queue(td, io_u);
 
+               ret = td_io_queue(td, io_u);
                switch (ret) {
                case FIO_Q_COMPLETED:
-                       if (io_u->error) {
-                               ret = io_u->error;
-                               break;
-                       }
-                       if (io_u->xfer_buflen != io_u->resid && io_u->resid) {
+                       if (io_u->error)
+                               ret = -io_u->error;
+                       else if (io_u->resid) {
                                int bytes = io_u->xfer_buflen - io_u->resid;
 
+                               /*
+                                * zero read, fail
+                                */
+                               if (!bytes) {
+                                       td_verror(td, ENODATA, "full resid");
+                                       put_io_u(td, io_u);
+                                       break;
+                               }
+
                                io_u->xfer_buflen = io_u->resid;
                                io_u->xfer_buf += bytes;
-                               goto requeue;
+                               requeue_io_u(td, &io_u);
+                       } else {
+                               fio_gettime(&comp_time, NULL);
+                               bytes_done = io_u_sync_complete(td, io_u);
+                               if (bytes_done < 0)
+                                       ret = bytes_done;
                        }
-                       fio_gettime(&comp_time, NULL);
-                       bytes_done = io_u_sync_complete(td, io_u);
-                       if (bytes_done < 0)
-                               ret = bytes_done;
                        break;
                case FIO_Q_QUEUED:
                        /*
@@ -433,12 +444,12 @@ requeue:
                         */
                        if (td->io_ops->commit == NULL)
                                io_u_queued(td, io_u);
-                       else if (td->io_u_queued >= td->iodepth_batch)
-                               ret = td_io_commit(td);
                        break;
                case FIO_Q_BUSY:
                        requeue_io_u(td, &io_u);
-                       ret = td_io_commit(td);
+                       ret2 = td_io_commit(td);
+                       if (ret2 < 0)
+                               ret = ret2;
                        break;
                default:
                        assert(ret < 0);
@@ -481,7 +492,7 @@ requeue:
 
                if (check_min_rate(td, &comp_time)) {
                        if (exitall_on_terminate)
-                               terminate_threads(td->groupid, 0);
+                               terminate_threads(td->groupid);
                        td_verror(td, ENODATA, "check_min_rate");
                        break;
                }
@@ -512,8 +523,12 @@ requeue:
 
                if (should_fsync(td) && td->end_fsync) {
                        td_set_runstate(td, TD_FSYNCING);
-                       for_each_file(td, f, i)
+
+                       for_each_file(td, f, i) {
+                               if (!(f->flags & FIO_FILE_OPEN))
+                                       continue;
                                fio_io_sync(td, f);
+                       }
                }
        } else
                cleanup_pending_aio(td);
@@ -554,9 +569,6 @@ static int init_io_u(struct thread_data *td)
        int i, max_units;
        char *p;
 
-       if (td->io_ops->flags & FIO_CPUIO)
-               return 0;
-
        if (td->io_ops->flags & FIO_SYNCIO)
                max_units = 1;
        else
@@ -599,7 +611,7 @@ static int switch_ioscheduler(struct thread_data *td)
        FILE *f;
        int ret;
 
-       if (td->io_ops->flags & FIO_CPUIO)
+       if (td->io_ops->flags & FIO_DISKLESSIO)
                return 0;
 
        sprintf(tmp, "%s/queue/scheduler", td->sysfs_root);
@@ -644,27 +656,30 @@ static int switch_ioscheduler(struct thread_data *td)
        return 0;
 }
 
-static void clear_io_state(struct thread_data *td)
+static int clear_io_state(struct thread_data *td)
 {
        struct fio_file *f;
-       int i;
+       unsigned int i;
+       int ret;
 
        td->ts.stat_io_bytes[0] = td->ts.stat_io_bytes[1] = 0;
        td->this_io_bytes[0] = td->this_io_bytes[1] = 0;
        td->zone_bytes = 0;
+       td->rate_bytes = 0;
 
        td->last_was_sync = 0;
 
-       for_each_file(td, f, i) {
-               f->last_completed_pos = 0;
-
-               f->last_pos = 0;
-               if (td->io_ops->flags & FIO_SYNCIO)
-                       lseek(f->fd, SEEK_SET, 0);
+       for_each_file(td, f, i)
+               td_io_close_file(td, f);
 
-               if (f->file_map)
-                       memset(f->file_map, 0, f->num_maps * sizeof(long));
+       ret = 0;
+       for_each_file(td, f, i) {
+               ret = td_io_open_file(td, f);
+               if (ret)
+                       break;
        }
+
+       return ret;
 }
 
 /*
@@ -675,6 +690,7 @@ static void *thread_main(void *data)
 {
        unsigned long long runtime[2];
        struct thread_data *td = data;
+       int clear_state;
 
        if (!td->use_thread)
                setsid();
@@ -688,50 +704,50 @@ static void *thread_main(void *data)
        INIT_LIST_HEAD(&td->io_log_list);
 
        if (init_io_u(td))
-               goto err;
+               goto err_sem;
 
        if (fio_setaffinity(td) == -1) {
                td_verror(td, errno, "cpu_set_affinity");
-               goto err;
+               goto err_sem;
        }
 
        if (init_iolog(td))
-               goto err;
+               goto err_sem;
 
        if (td->ioprio) {
                if (ioprio_set(IOPRIO_WHO_PROCESS, 0, td->ioprio) == -1) {
                        td_verror(td, errno, "ioprio_set");
-                       goto err;
+                       goto err_sem;
                }
        }
 
        if (nice(td->nice) == -1) {
                td_verror(td, errno, "nice");
-               goto err;
+               goto err_sem;
        }
 
-       if (init_random_state(td))
-               goto err;
-
        if (td->ioscheduler && switch_ioscheduler(td))
-               goto err;
+               goto err_sem;
 
        td_set_runstate(td, TD_INITIALIZED);
-       fio_sem_up(&startup_sem);
-       fio_sem_down(&td->mutex);
+       fio_sem_up(startup_sem);
+       fio_sem_down(td->mutex);
+
+       /*
+        * the ->mutex semaphore is now no longer used, close it to avoid
+        * eating a file descriptor
+        */
+       fio_sem_remove(td->mutex);
 
        if (!td->create_serialize && setup_files(td))
                goto err;
-       if (open_files(td))
-               goto err;
 
-       /*
-        * Do this late, as some IO engines would like to have the
-        * files setup prior to initializing structures.
-        */
        if (td_io_init(td))
                goto err;
 
+       if (open_files(td))
+               goto err;
+
        if (td->exec_prerun) {
                if (system(td->exec_prerun) < 0)
                        goto err;
@@ -742,6 +758,7 @@ static void *thread_main(void *data)
        getrusage(RUSAGE_SELF, &td->ts.ru_start);
 
        runtime[0] = runtime[1] = 0;
+       clear_state = 0;
        while (td->loops--) {
                fio_gettime(&td->start, NULL);
                memcpy(&td->ts.stat_sample_time, &td->start, sizeof(td->start));
@@ -749,13 +766,14 @@ static void *thread_main(void *data)
                if (td->ratemin)
                        memcpy(&td->lastrate, &td->ts.stat_sample_time, sizeof(td->lastrate));
 
-               clear_io_state(td);
+               if (clear_state && clear_io_state(td))
+                       break;
+
                prune_io_piece_log(td);
 
-               if (td->io_ops->flags & FIO_CPUIO)
-                       do_cpuio(td);
-               else
-                       do_io(td);
+               do_io(td);
+
+               clear_state = 1;
 
                if (td_read(td) && td->io_bytes[DDIR_READ])
                        runtime[DDIR_READ] += utime_since_now(&td->start);
@@ -768,7 +786,9 @@ static void *thread_main(void *data)
                if (td->verify == VERIFY_NONE)
                        continue;
 
-               clear_io_state(td);
+               if (clear_io_state(td))
+                       break;
+
                fio_gettime(&td->start, NULL);
 
                do_verify(td);
@@ -780,9 +800,11 @@ static void *thread_main(void *data)
        }
 
        update_rusage_stat(td);
-       fio_gettime(&td->end_time, NULL);
-       td->runtime[0] = runtime[0] / 1000;
-       td->runtime[1] = runtime[1] / 1000;
+       td->ts.runtime[0] = runtime[0] / 1000;
+       td->ts.runtime[1] = runtime[1] / 1000;
+       td->ts.total_run_time = mtime_since_now(&td->epoch);
+       td->ts.io_bytes[0] = td->io_bytes[0];
+       td->ts.io_bytes[1] = td->io_bytes[1];
 
        if (td->ts.bw_log)
                finish_log(td, td->ts.bw_log, "bw");
@@ -798,7 +820,7 @@ static void *thread_main(void *data)
        }
 
        if (exitall_on_terminate)
-               terminate_threads(td->groupid, 0);
+               terminate_threads(td->groupid);
 
 err:
        if (td->error)
@@ -808,6 +830,9 @@ err:
        cleanup_io_u(td);
        td_set_runstate(td, TD_EXITED);
        return (void *) (unsigned long) td->error;
+err_sem:
+       fio_sem_up(startup_sem);
+       goto err;
 }
 
 /*
@@ -852,7 +877,7 @@ static void reap_threads(int *nr_running, int *t_rate, int *m_rate)
                 * ->io_ops is NULL for a thread that has closed its
                 * io engine
                 */
-               if (td->io_ops && td->io_ops->flags & FIO_CPUIO)
+               if (td->io_ops && !strcmp(td->io_ops->name, "cpuio"))
                        cputhreads++;
 
                if (!td->pid || td->runstate == TD_REAPED)
@@ -884,7 +909,8 @@ static void reap_threads(int *nr_running, int *t_rate, int *m_rate)
                        if (WIFSIGNALED(status)) {
                                int sig = WTERMSIG(status);
 
-                               log_err("fio: pid=%d, got signal=%d\n", td->pid, sig);
+                               if (sig != SIGQUIT)
+                                       log_err("fio: pid=%d, got signal=%d\n", td->pid, sig);
                                td_set_runstate(td, TD_REAPED);
                                goto reaped;
                        }
@@ -918,7 +944,7 @@ reaped:
        }
 
        if (*nr_running == cputhreads && !pending)
-               terminate_threads(TERMINATE_ALL, 0);
+               terminate_threads(TERMINATE_ALL);
 }
 
 /*
@@ -934,7 +960,15 @@ static void run_threads(void)
                return;
 
        if (!terse_output) {
-               printf("Starting %d thread%s\n", thread_number, thread_number > 1 ? "s" : "");
+               printf("Starting ");
+               if (nr_thread)
+                       printf("%d thread%s", nr_thread, nr_thread > 1 ? "s" : "");
+               if (nr_process) {
+                       if (nr_thread)
+                               printf(" and ");
+                       printf("%d process%s", nr_process, nr_process > 1 ? "es" : "");
+               }
+               printf("\n");
                fflush(stdout);
        }
 
@@ -1009,23 +1043,22 @@ static void run_threads(void)
                         */
                        td_set_runstate(td, TD_CREATED);
                        map[this_jobs++] = td;
-                       fio_sem_init(&startup_sem, 1);
                        nr_started++;
 
                        if (td->use_thread) {
                                if (pthread_create(&td->thread, NULL, thread_main, td)) {
                                        perror("thread_create");
                                        nr_started--;
+                                       break;
                                }
                        } else {
-                               if (fork())
-                                       fio_sem_down(&startup_sem);
-                               else {
+                               if (!fork()) {
                                        int ret = fork_main(shm_id, i);
 
                                        exit(ret);
                                }
                        }
+                       fio_sem_down(startup_sem);
                }
 
                /*
@@ -1080,7 +1113,7 @@ static void run_threads(void)
                        m_rate += td->ratemin;
                        t_rate += td->rate;
                        todo--;
-                       fio_sem_up(&td->mutex);
+                       fio_sem_up(td->mutex);
                }
 
                reap_threads(&nr_running, &t_rate, &m_rate);
@@ -1123,6 +1156,7 @@ int main(int argc, char *argv[])
                return 1;
        }
 
+       page_size = ps;
        page_mask = ps - 1;
 
        if (write_bw_log) {
@@ -1130,6 +1164,8 @@ int main(int argc, char *argv[])
                setup_log(&agg_io_log[DDIR_WRITE]);
        }
 
+       startup_sem = fio_sem_init(0);
+
        set_genesis_time();
 
        disk_util_timer_arm();
@@ -1144,5 +1180,6 @@ int main(int argc, char *argv[])
                }
        }
 
+       fio_sem_remove(startup_sem);
        return exit_value;
 }