Improve logging accuracy
[fio.git] / iolog.c
diff --git a/iolog.c b/iolog.c
index 0d4d26a599ab6c493af2efdd9096e087c8963d2b..71afe86c29a1e50847128591be9bb10adbcea70b 100644 (file)
--- a/iolog.c
+++ b/iolog.c
@@ -18,6 +18,7 @@
 #include "verify.h"
 #include "trim.h"
 #include "filelock.h"
+#include "smalloc.h"
 
 static const char iolog_ver2[] = "fio version 2 iolog";
 
@@ -574,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;
@@ -631,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,23 +671,11 @@ static void flush_samples(FILE *f, void *samples, uint64_t sample_size)
 
 struct iolog_flush_data {
        struct workqueue_work work;
-       pthread_mutex_t lock;
-       pthread_cond_t cv;
-       int wait;
-       volatile int done;
-       volatile int refs;
        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)
@@ -984,7 +971,7 @@ 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, !td->o.per_job_logs);
@@ -994,25 +981,30 @@ static int finish_log(struct thread_data *td, struct io_log *log, int trylock)
        return 0;
 }
 
-#ifdef CONFIG_ZLIB
-
-static void drop_data(struct iolog_flush_data *data, int refs)
+size_t log_chunk_sizes(struct io_log *log)
 {
-       if (!refs) {
-               free(data);
-               pthread_mutex_destroy(&data->lock);
-               pthread_cond_destroy(&data->cv);
+       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;
 }
 
-/*
- * 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 submit_worker *sw, struct workqueue_work *work)
+#ifdef CONFIG_ZLIB
+
+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;
@@ -1022,8 +1014,6 @@ static int gz_work(struct submit_worker *sw, struct workqueue_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;
@@ -1031,7 +1021,7 @@ static int gz_work(struct submit_worker *sw, struct workqueue_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;
@@ -1091,17 +1081,7 @@ static int gz_work(struct submit_worker *sw, struct workqueue_work *work)
 
        ret = 0;
 done:
-       if (data->wait) {
-               int refs;
-
-               pthread_mutex_lock(&data->lock);
-               data->done = 1;
-               pthread_cond_signal(&data->cv);
-               refs = --data->refs;
-               pthread_mutex_unlock(&data->lock);
-               drop_data(data, refs);
-       } else
-               free(data);
+       free(data);
        return ret;
 err:
        while (!flist_empty(&list)) {
@@ -1113,17 +1093,43 @@ err:
        goto done;
 }
 
+/*
+ * 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,
-       .nice   = 1,
+       .fn             = gz_work_async,
+       .init_worker_fn = gz_init_worker,
+       .nice           = 1,
 };
 
-int iolog_compress_init(struct thread_data *td)
+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);
+       workqueue_init(td, &td->log_compress_wq, &log_compress_wq_ops, 1, sk_out);
        return 0;
 }
 
@@ -1136,15 +1142,17 @@ void iolog_compress_exit(struct thread_data *td)
 }
 
 /*
- * 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.
+ * 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 iolog_flush_data *data;
-       size_t sample_size;
+
+       io_u_quiesce(log->td);
 
        data = malloc(sizeof(*data));
        if (!data)
@@ -1152,37 +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;
-       log->nr_samples = 0;
 
-       data->wait = wait;
-       if (data->wait) {
-               pthread_mutex_init(&data->lock, NULL);
-               pthread_cond_init(&data->cv, NULL);
-               data->done = 0;
-               data->refs = 2;
-       }
-
-       workqueue_enqueue(&log->td->log_compress_wq, &data->work);
-
-       if (wait) {
-               int refs;
+       log->nr_samples = 0;
+       log->max_samples = DEF_LOG_ENTRIES;
+       log->log = malloc(log->max_samples * log_entry_sz(log));
 
-               pthread_mutex_lock(&data->lock);
-               while (!data->done)
-                       pthread_cond_wait(&data->cv, &data->lock);
-               refs = --data->refs;
-               pthread_mutex_unlock(&data->lock);
-               drop_data(data, refs);
-       }
+       if (!wait)
+               workqueue_enqueue(&log->td->log_compress_wq, &data->work);
+       else
+               gz_work(data);
 
        return 0;
 }
@@ -1194,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);
+
+       return 0;
+}
 
-       if (!log)
+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 {
@@ -1258,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[] = {
@@ -1284,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;
@@ -1292,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;
@@ -1302,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;
@@ -1316,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);
+}