Report the time taken by pgbench initialization steps.

Author: Fabien Coelho
Reviewed-by: Ibrar Ahmed
Discussion: https://postgr.es/m/alpine.DEB.2.21.1904061810510.3678%40lancre

diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c
index 8b84658ccdacd3d2967a46ac49241dd7ded4d153..23087ef0a246d38cebd813b220d13a1307b95e5b 100644 (file)
--- a/src/bin/pgbench/pgbench.c
+++ b/src/bin/pgbench/pgbench.c
@@ -3931,32 +3931,48 @@ checkInitSteps(const char *initialize_steps)
 static void
 runInitSteps(const char *initialize_steps)
 {
+       PQExpBufferData stats;
        PGconn     *con;
        const char *step;
+       double          run_time = 0.0;
+       bool            first = true;
+
+       initPQExpBuffer(&stats);
 
        if ((con = doConnect()) == NULL)
                exit(1);
 
        for (step = initialize_steps; *step != '\0'; step++)
        {
+               instr_time      start;
+               char       *op = NULL;
+
+               INSTR_TIME_SET_CURRENT(start);
+
                switch (*step)
                {
                        case 'd':
+                               op = "drop tables";
                                initDropTables(con);
                                break;
                        case 't':
+                               op = "create tables";
                                initCreateTables(con);
                                break;
                        case 'g':
+                               op = "generate";
                                initGenerateData(con);
                                break;
                        case 'v':
+                               op = "vacuum";
                                initVacuum(con);
                                break;
                        case 'p':
+                               op = "primary keys";
                                initCreatePKeys(con);
                                break;
                        case 'f':
+                               op = "foreign keys";
                                initCreateFKeys(con);
                                break;
                        case ' ':
@@ -3967,10 +3983,30 @@ runInitSteps(const char *initialize_steps)
                                PQfinish(con);
                                exit(1);
                }
+
+               if (op != NULL)
+               {
+                       instr_time      diff;
+                       double          elapsed_sec;
+
+                       INSTR_TIME_SET_CURRENT(diff);
+                       INSTR_TIME_SUBTRACT(diff, start);
+                       elapsed_sec = INSTR_TIME_GET_DOUBLE(diff);
+
+                       if (!first)
+                               appendPQExpBufferStr(&stats, ", ");
+                       else
+                               first = false;
+
+                       appendPQExpBuffer(&stats, "%s %.2f s", op, elapsed_sec);
+
+                       run_time += elapsed_sec;
+               }
        }
 
-       fprintf(stderr, "done.\n");
+       fprintf(stderr, "done in %.2f s (%s).\n", run_time, stats.data);
        PQfinish(con);
+       termPQExpBuffer(&stats);
 }
 
 /*

diff --git a/src/bin/pgbench/t/001_pgbench_with_server.pl b/src/bin/pgbench/t/001_pgbench_with_server.pl
index 3b097a91b28c44a81840710f777bbfc4522631a6..5a2fdb9acb948615762d324a0b0d9f7f6880abb9 100644 (file)
--- a/src/bin/pgbench/t/001_pgbench_with_server.pl
+++ b/src/bin/pgbench/t/001_pgbench_with_server.pl
@@ -94,7 +94,7 @@ pgbench(
        [qr{^$}],
        [
                qr{creating tables},       qr{vacuuming},
-               qr{creating primary keys}, qr{done\.}
+               qr{creating primary keys}, qr{done in \d+\.\d\d s }
        ],
        'pgbench scale 1 initialization',);
 
@@ -109,7 +109,8 @@ pgbench(
                qr{vacuuming},
                qr{creating primary keys},
                qr{creating foreign keys},
-               qr{done\.}
+               qr{(?!vacuuming)}, # no vacuum
+               qr{done in \d+\.\d\d s }
        ],
        'pgbench scale 1 initialization');
 
@@ -124,7 +125,8 @@ pgbench(
                qr{creating primary keys},
                qr{.* of .* tuples \(.*\) done},
                qr{creating foreign keys},
-               qr{done\.}
+               qr{(?!vacuuming)}, # no vacuum
+               qr{done in \d+\.\d\d s }
        ],
        'pgbench --init-steps');