Improve logging accuracy
[fio.git] / iolog.c
diff --git a/iolog.c b/iolog.c
index b29684a85eb69c30d219b95eff122c33df9ce5f6..71afe86c29a1e50847128591be9bb10adbcea70b 100644 (file)
--- a/iolog.c
+++ b/iolog.c
@@ -18,7 +18,7 @@
 #include "verify.h"
 #include "trim.h"
 #include "filelock.h"
-#include "lib/tp.h"
+#include "smalloc.h"
 
 static const char iolog_ver2[] = "fio version 2 iolog";
 
@@ -575,14 +575,12 @@ void setup_log(struct io_log **log, struct log_params *p,
 {
        struct io_log *l;
 
-       l = calloc(1, sizeof(*l));
+       l = smalloc(sizeof(*l));
        l->nr_samples = 0;
-       l->max_samples = 1024;
        l->log_type = p->log_type;
        l->log_offset = p->log_offset;
        l->log_gz = p->log_gz;
        l->log_gz_store = p->log_gz_store;
-       l->log = malloc(l->max_samples * log_entry_sz(l));
        l->avg_msec = p->avg_msec;
        l->filename = strdup(filename);
        l->td = p->td;
@@ -594,7 +592,7 @@ void setup_log(struct io_log **log, struct log_params *p,
 
        if (l->log_gz && !p->td)
                l->log_gz = 0;
-       else if (l->log_gz) {
+       else if (l->log_gz || l->log_gz_store) {
                pthread_mutex_init(&l->chunk_lock, NULL);
                p->td->flags |= TD_F_COMPRESS_LOG;
        }
@@ -632,10 +630,10 @@ void free_log(struct io_log *log)
 {
        free(log->log);
        free(log->filename);
-       free(log);
+       sfree(log);
 }
 
-static void flush_samples(FILE *f, void *samples, uint64_t sample_size)
+void flush_samples(FILE *f, void *samples, uint64_t sample_size)
 {
        struct io_sample *s;
        int log_offset;
@@ -672,19 +670,12 @@ static void flush_samples(FILE *f, void *samples, uint64_t sample_size)
 #ifdef CONFIG_ZLIB
 
 struct iolog_flush_data {
-       struct tp_work work;
+       struct workqueue_work work;
        struct io_log *log;
        void *samples;
        uint64_t nr_samples;
 };
 
-struct iolog_compress {
-       struct flist_head list;
-       void *buf;
-       size_t len;
-       unsigned int seq;
-};
-
 #define GZ_CHUNK       131072
 
 static struct iolog_compress *get_new_chunk(unsigned int seq)
@@ -945,12 +936,15 @@ int iolog_file_inflate(const char *file)
 
 #endif
 
-void flush_log(struct io_log *log)
+void flush_log(struct io_log *log, int do_append)
 {
        void *buf;
        FILE *f;
 
-       f = fopen(log->filename, "w");
+       if (!do_append)
+               f = fopen(log->filename, "w");
+       else
+               f = fopen(log->filename, "a");
        if (!f) {
                perror("fopen log");
                return;
@@ -968,7 +962,7 @@ void flush_log(struct io_log *log)
 
 static int finish_log(struct thread_data *td, struct io_log *log, int trylock)
 {
-       if (td->tp_data)
+       if (td->flags & TD_F_COMPRESS_LOG)
                iolog_flush(log, 1);
 
        if (trylock) {
@@ -977,26 +971,40 @@ static int finish_log(struct thread_data *td, struct io_log *log, int trylock)
        } else
                fio_lock_file(log->filename);
 
-       if (td->client_type == FIO_CLIENT_TYPE_GUI)
+       if (td->client_type == FIO_CLIENT_TYPE_GUI || is_backend)
                fio_send_iolog(td, log, log->filename);
        else
-               flush_log(log);
+               flush_log(log, !td->o.per_job_logs);
 
        fio_unlock_file(log->filename);
        free_log(log);
        return 0;
 }
 
+size_t log_chunk_sizes(struct io_log *log)
+{
+       struct flist_head *entry;
+       size_t ret;
+
+       if (flist_empty(&log->chunk_list))
+               return 0;
+
+       ret = 0;
+       pthread_mutex_lock(&log->chunk_lock);
+       flist_for_each(entry, &log->chunk_list) {
+               struct iolog_compress *c;
+
+               c = flist_entry(entry, struct iolog_compress, list);
+               ret += c->len;
+       }
+       pthread_mutex_unlock(&log->chunk_lock);
+       return ret;
+}
+
 #ifdef CONFIG_ZLIB
 
-/*
- * Invoked from our compress helper thread, when logging would have exceeded
- * the specified memory limitation. Compresses the previously stored
- * entries.
- */
-static int gz_work(struct tp_work *work)
+static int gz_work(struct iolog_flush_data *data)
 {
-       struct iolog_flush_data *data;
        struct iolog_compress *c;
        struct flist_head list;
        unsigned int seq;
@@ -1006,8 +1014,6 @@ static int gz_work(struct tp_work *work)
 
        INIT_FLIST_HEAD(&list);
 
-       data = container_of(work, struct iolog_flush_data, work);
-
        stream.zalloc = Z_NULL;
        stream.zfree = Z_NULL;
        stream.opaque = Z_NULL;
@@ -1015,7 +1021,7 @@ static int gz_work(struct tp_work *work)
        ret = deflateInit(&stream, Z_DEFAULT_COMPRESSION);
        if (ret != Z_OK) {
                log_err("fio: failed to init gz stream\n");
-               return 0;
+               goto err;
        }
 
        seq = ++data->log->chunk_seq;
@@ -1075,12 +1081,7 @@ static int gz_work(struct tp_work *work)
 
        ret = 0;
 done:
-       if (work->wait) {
-               work->done = 1;
-               pthread_cond_signal(&work->cv);
-       } else
-               free(data);
-
+       free(data);
        return ret;
 err:
        while (!flist_empty(&list)) {
@@ -1093,16 +1094,65 @@ err:
 }
 
 /*
- * Queue work item to compress the existing log entries. We copy the
- * samples, and reset the log sample count to 0 (so the logging will
- * continue to use the memory associated with the log). If called with
- * wait == 1, will not return until the log compression has completed.
+ * Invoked from our compress helper thread, when logging would have exceeded
+ * the specified memory limitation. Compresses the previously stored
+ * entries.
+ */
+static int gz_work_async(struct submit_worker *sw, struct workqueue_work *work)
+{
+       return gz_work(container_of(work, struct iolog_flush_data, work));
+}
+
+static int gz_init_worker(struct submit_worker *sw)
+{
+       struct thread_data *td = sw->wq->td;
+
+       if (!fio_option_is_set(&td->o, log_gz_cpumask))
+               return 0;
+
+       if (fio_setaffinity(gettid(), td->o.log_gz_cpumask) == -1) {
+               log_err("gz: failed to set CPU affinity\n");
+               return 1;
+       }
+
+       return 0;
+}
+
+static struct workqueue_ops log_compress_wq_ops = {
+       .fn             = gz_work_async,
+       .init_worker_fn = gz_init_worker,
+       .nice           = 1,
+};
+
+int iolog_compress_init(struct thread_data *td, struct sk_out *sk_out)
+{
+       if (!(td->flags & TD_F_COMPRESS_LOG))
+               return 0;
+
+       workqueue_init(td, &td->log_compress_wq, &log_compress_wq_ops, 1, sk_out);
+       return 0;
+}
+
+void iolog_compress_exit(struct thread_data *td)
+{
+       if (!(td->flags & TD_F_COMPRESS_LOG))
+               return;
+
+       workqueue_exit(&td->log_compress_wq);
+}
+
+/*
+ * Queue work item to compress the existing log entries. We reset the
+ * current log to a small size, and reference the existing log in the
+ * data that we queue for compression. Once compression has been done,
+ * this old log is freed. If called with wait == 1, will not return until
+ * the log compression has completed.
  */
 int iolog_flush(struct io_log *log, int wait)
 {
-       struct tp_data *tdat = log->td->tp_data;
        struct iolog_flush_data *data;
-       size_t sample_size;
+
+       io_u_quiesce(log->td);
 
        data = malloc(sizeof(*data));
        if (!data)
@@ -1110,35 +1160,17 @@ int iolog_flush(struct io_log *log, int wait)
 
        data->log = log;
 
-       sample_size = log->nr_samples * log_entry_sz(log);
-       data->samples = malloc(sample_size);
-       if (!data->samples) {
-               free(data);
-               return 1;
-       }
-
-       memcpy(data->samples, log->log, sample_size);
+       data->samples = log->log;
        data->nr_samples = log->nr_samples;
-       data->work.fn = gz_work;
-       log->nr_samples = 0;
 
-       if (wait) {
-               pthread_mutex_init(&data->work.lock, NULL);
-               pthread_cond_init(&data->work.cv, NULL);
-               data->work.wait = 1;
-       } else
-               data->work.wait = 0;
-
-       data->work.prio = 1;
-       tp_queue_work(tdat, &data->work);
+       log->nr_samples = 0;
+       log->max_samples = DEF_LOG_ENTRIES;
+       log->log = malloc(log->max_samples * log_entry_sz(log));
 
-       if (wait) {
-               pthread_mutex_lock(&data->work.lock);
-               while (!data->work.done)
-                       pthread_cond_wait(&data->work.cv, &data->work.lock);
-               pthread_mutex_unlock(&data->work.lock);
-               free(data);
-       }
+       if (!wait)
+               workqueue_enqueue(&log->td->log_compress_wq, &data->work);
+       else
+               gz_work(data);
 
        return 0;
 }
@@ -1150,56 +1182,93 @@ int iolog_flush(struct io_log *log, int wait)
        return 1;
 }
 
+int iolog_compress_init(struct thread_data *td, struct sk_out *sk_out)
+{
+       return 0;
+}
+
+void iolog_compress_exit(struct thread_data *td)
+{
+}
+
 #endif
 
-static int write_iops_log(struct thread_data *td, int try)
+static int __write_log(struct thread_data *td, struct io_log *log, int try)
 {
-       struct io_log *log = td->iops_log;
+       if (log)
+               return finish_log(td, log, try);
 
-       if (!log)
+       return 0;
+}
+
+static int write_iops_log(struct thread_data *td, int try, bool unit_log)
+{
+       int ret;
+
+       if (per_unit_log(td->iops_log) != unit_log)
                return 0;
 
-       return finish_log(td, log, try);
+       ret = __write_log(td, td->iops_log, try);
+       if (!ret)
+               td->iops_log = NULL;
+
+       return ret;
 }
 
-static int write_slat_log(struct thread_data *td, int try)
+static int write_slat_log(struct thread_data *td, int try, bool unit_log)
 {
-       struct io_log *log = td->slat_log;
+       int ret;
 
-       if (!log)
+       if (!unit_log)
                return 0;
 
-       return finish_log(td, log, try);
+       ret = __write_log(td, td->slat_log, try);
+       if (!ret)
+               td->slat_log = NULL;
+
+       return ret;
 }
 
-static int write_clat_log(struct thread_data *td, int try)
+static int write_clat_log(struct thread_data *td, int try, bool unit_log)
 {
-       struct io_log *log = td->clat_log;
+       int ret;
 
-       if (!log)
+       if (!unit_log)
                return 0;
 
-       return finish_log(td, log, try);
+       ret = __write_log(td, td->clat_log, try);
+       if (!ret)
+               td->clat_log = NULL;
+
+       return ret;
 }
 
-static int write_lat_log(struct thread_data *td, int try)
+static int write_lat_log(struct thread_data *td, int try, bool unit_log)
 {
-       struct io_log *log = td->lat_log;
+       int ret;
 
-       if (!log)
+       if (!unit_log)
                return 0;
 
-       return finish_log(td, log, try);
+       ret = __write_log(td, td->lat_log, try);
+       if (!ret)
+               td->lat_log = NULL;
+
+       return ret;
 }
 
-static int write_bandw_log(struct thread_data *td, int try)
+static int write_bandw_log(struct thread_data *td, int try, bool unit_log)
 {
-       struct io_log *log = td->bw_log;
+       int ret;
 
-       if (!log)
+       if (per_unit_log(td->bw_log) != unit_log)
                return 0;
 
-       return finish_log(td, log, try);
+       ret = __write_log(td, td->bw_log, try);
+       if (!ret)
+               td->bw_log = NULL;
+
+       return ret;
 }
 
 enum {
@@ -1214,7 +1283,7 @@ enum {
 
 struct log_type {
        unsigned int mask;
-       int (*fn)(struct thread_data *, int);
+       int (*fn)(struct thread_data *, int, bool);
 };
 
 static struct log_type log_types[] = {
@@ -1240,7 +1309,7 @@ static struct log_type log_types[] = {
        },
 };
 
-void fio_writeout_logs(struct thread_data *td)
+void td_writeout_logs(struct thread_data *td, bool unit_logs)
 {
        unsigned int log_mask = 0;
        unsigned int log_left = ALL_LOG_NR;
@@ -1248,7 +1317,7 @@ void fio_writeout_logs(struct thread_data *td)
 
        old_state = td_bump_runstate(td, TD_FINISHING);
 
-       finalize_logs(td);
+       finalize_logs(td, unit_logs);
 
        while (log_left) {
                int prev_log_left = log_left;
@@ -1258,7 +1327,7 @@ void fio_writeout_logs(struct thread_data *td)
                        int ret;
 
                        if (!(log_mask & lt->mask)) {
-                               ret = lt->fn(td, log_left != 1);
+                               ret = lt->fn(td, log_left != 1, unit_logs);
                                if (!ret) {
                                        log_left--;
                                        log_mask |= lt->mask;
@@ -1272,3 +1341,12 @@ void fio_writeout_logs(struct thread_data *td)
 
        td_restore_runstate(td, old_state);
 }
+
+void fio_writeout_logs(bool unit_logs)
+{
+       struct thread_data *td;
+       int i;
+
+       for_each_td(td, i)
+               td_writeout_logs(td, unit_logs);
+}