Collect startup output before logging it
authorJens Axboe <axboe@kernel.dk>
Fri, 7 Sep 2018 18:02:39 +0000 (12:02 -0600)
committerJens Axboe <axboe@kernel.dk>
Fri, 7 Sep 2018 18:02:39 +0000 (12:02 -0600)
We currently do the startup logging in separate chunks. This is
inefficient in terms of network trafic for client/server, and
it also causes output to be potentially mingled together:

<x1> Starting <x1> Starting 1 process1 process

Fix this by logging to a buffer, then transmitting that buffer
in one piece.

Signed-off-by: Jens Axboe <axboe@kernel.dk>
backend.c
init.c

index 8fec1ce3141f4f5b3f910784c75f5f6a200c88d9..00fc29a4b15452778b38f4d9a0c3bee6a574e8ba 100644 (file)
--- a/backend.c
+++ b/backend.c
@@ -2213,18 +2213,21 @@ static void run_threads(struct sk_out *sk_out)
        }
 
        if (output_format & FIO_OUTPUT_NORMAL) {
        }
 
        if (output_format & FIO_OUTPUT_NORMAL) {
-               log_info("Starting ");
+               struct buf_output out;
+
+               buf_output_init(&out);
+               log_buf(&out, "Starting ");
                if (nr_thread)
                if (nr_thread)
-                       log_info("%d thread%s", nr_thread,
+                       log_buf(&out, "%d thread%s", nr_thread,
                                                nr_thread > 1 ? "s" : "");
                if (nr_process) {
                        if (nr_thread)
                                                nr_thread > 1 ? "s" : "");
                if (nr_process) {
                        if (nr_thread)
-                               log_info(" and ");
-                       log_info("%d process%s", nr_process,
+                               log_buf(&out, " and ");
+                       log_buf(&out, "%d process%s", nr_process,
                                                nr_process > 1 ? "es" : "");
                }
                                                nr_process > 1 ? "es" : "");
                }
-               log_info("\n");
-               log_info_flush();
+               log_buf(&out, "\n");
+               log_info_buf(out.buf, out.buflen);
        }
 
        todo = thread_number;
        }
 
        todo = thread_number;
diff --git a/init.c b/init.c
index 09f58a3538d4c4b28974bfc64b384ab111420e19..eff2dea9562d0122e67ed6110b48e67899ed58c0 100644 (file)
--- a/init.c
+++ b/init.c
@@ -1681,6 +1681,7 @@ static int add_job(struct thread_data *td, const char *jobname, int job_add_num,
                                char *c1, *c2, *c3, *c4;
                                char *c5 = NULL, *c6 = NULL;
                                int i2p = is_power_of_2(o->kb_base);
                                char *c1, *c2, *c3, *c4;
                                char *c5 = NULL, *c6 = NULL;
                                int i2p = is_power_of_2(o->kb_base);
+                               struct buf_output out;
 
                                c1 = num2str(o->min_bs[DDIR_READ], o->sig_figs, 1, i2p, N2S_BYTE);
                                c2 = num2str(o->max_bs[DDIR_READ], o->sig_figs, 1, i2p, N2S_BYTE);
 
                                c1 = num2str(o->min_bs[DDIR_READ], o->sig_figs, 1, i2p, N2S_BYTE);
                                c2 = num2str(o->max_bs[DDIR_READ], o->sig_figs, 1, i2p, N2S_BYTE);
@@ -1692,19 +1693,21 @@ static int add_job(struct thread_data *td, const char *jobname, int job_add_num,
                                        c6 = num2str(o->max_bs[DDIR_TRIM], o->sig_figs, 1, i2p, N2S_BYTE);
                                }
 
                                        c6 = num2str(o->max_bs[DDIR_TRIM], o->sig_figs, 1, i2p, N2S_BYTE);
                                }
 
-                               log_info("%s: (g=%d): rw=%s, ", td->o.name,
+                               buf_output_init(&out);
+                               log_buf(&out, "%s: (g=%d): rw=%s, ", td->o.name,
                                                        td->groupid,
                                                        ddir_str(o->td_ddir));
 
                                if (o->bs_is_seq_rand)
                                                        td->groupid,
                                                        ddir_str(o->td_ddir));
 
                                if (o->bs_is_seq_rand)
-                                       log_info("bs=(R) %s-%s, (W) %s-%s, bs_is_seq_rand, ",
+                                       log_buf(&out, "bs=(R) %s-%s, (W) %s-%s, bs_is_seq_rand, ",
                                                        c1, c2, c3, c4);
                                else
                                                        c1, c2, c3, c4);
                                else
-                                       log_info("bs=(R) %s-%s, (W) %s-%s, (T) %s-%s, ",
+                                       log_buf(&out, "bs=(R) %s-%s, (W) %s-%s, (T) %s-%s, ",
                                                        c1, c2, c3, c4, c5, c6);
 
                                                        c1, c2, c3, c4, c5, c6);
 
-                               log_info("ioengine=%s, iodepth=%u\n",
+                               log_buf(&out, "ioengine=%s, iodepth=%u\n",
                                                td->io_ops->name, o->iodepth);
                                                td->io_ops->name, o->iodepth);
+                               log_info_buf(out.buf, out.buflen);
 
                                free(c1);
                                free(c2);
 
                                free(c1);
                                free(c2);