pgbench - add minimal stats on initialization
Hello devs,
The attached patch adds minimal stats during the initialization phase.
Such a feature was already submitted by Doug Rady two years ago,
https://commitfest.postgresql.org/15/1308/
but it needed to be adapted to the -I custom initialization approach
developed in the same CF, and it ended 'returned with feedback'.
sh> ./pgbench -i -s 3
dropping old tables...
creating tables...
generating data...
100000 of 300000 tuples (33%) done (elapsed 0.09 s, remaining 0.18 s)
200000 of 300000 tuples (66%) done (elapsed 0.20 s, remaining 0.10 s)
300000 of 300000 tuples (100%) done (elapsed 0.32 s, remaining 0.00 s)
vacuuming...
creating primary keys...
done in 0.68 s (drop 0.06 s, create table 0.02 s, generate 0.34 s, vacuum 0.13 s, primary keys 0.13 s).
See the durations on the last line.
The intent is to test the initialization phase more precisely, and
possibly accelerate it. For instance, is it better to do vacuum before or
after primary keys?
--
Fabien.
Attachments:
pgbench-init-stats-1.patchtext/x-diff; charset=us-ascii; name=pgbench-init-stats-1.patchDownload
diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c
index 99529de52a..76a5b87fe8 100644
--- a/src/bin/pgbench/pgbench.c
+++ b/src/bin/pgbench/pgbench.c
@@ -3941,32 +3941,48 @@ checkInitSteps(const char *initialize_steps)
static void
runInitSteps(const char *initialize_steps)
{
- PGconn *con;
- const char *step;
+ 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";
initDropTables(con);
break;
case 't':
+ op = "create table";
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 ' ':
@@ -3977,10 +3993,28 @@ 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, ", ");
+
+ 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);
}
/*
done in 0.68 s (drop 0.06 s, create table 0.02 s, generate 0.34 s, vacuum
0.13 s, primary keys 0.13 s).See the durations on the last line.
It's even better with working TAP tests.
--
Fabien.
Attachments:
pgbench-init-stats-2.patchtext/x-diff; name=pgbench-init-stats-2.patchDownload
diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c
index 99529de52a..76a5b87fe8 100644
--- a/src/bin/pgbench/pgbench.c
+++ b/src/bin/pgbench/pgbench.c
@@ -3941,32 +3941,48 @@ checkInitSteps(const char *initialize_steps)
static void
runInitSteps(const char *initialize_steps)
{
- PGconn *con;
- const char *step;
+ 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";
initDropTables(con);
break;
case 't':
+ op = "create table";
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 ' ':
@@ -3977,10 +3993,28 @@ 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, ", ");
+
+ 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 62906d5e55..696dc2b36c 100644
--- a/src/bin/pgbench/t/001_pgbench_with_server.pl
+++ b/src/bin/pgbench/t/001_pgbench_with_server.pl
@@ -101,7 +101,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',);
@@ -116,7 +116,7 @@ pgbench(
qr{vacuuming},
qr{creating primary keys},
qr{creating foreign keys},
- qr{done\.}
+ qr{done in \d+\.\d\d s }
],
'pgbench scale 1 initialization');
@@ -131,7 +131,7 @@ pgbench(
qr{creating primary keys},
qr{.* of .* tuples \(.*\) done},
qr{creating foreign keys},
- qr{done\.}
+ qr{done in \d+\.\d\d s }
],
'pgbench --init-steps');
The following review has been posted through the commitfest application:
make installcheck-world: tested, failed
Implements feature: tested, failed
Spec compliant: tested, failed
Documentation: not tested
Patch works perfectly and the code is well-written. I have one minor observation that in case of initDropTables you log "drop" and in case of initCreateTables you log "create table". I think you need to be consistent. And why not "drop tables" and "create tables"
The new status of this patch is: Waiting on Author
The following review has been posted through the commitfest application:
make installcheck-world: tested, passed
Implements feature: tested, passed
Spec compliant: tested, passed
Documentation: not tested
Please ignore the last email.
Patch works perfectly and the code is well-written. I have one minor observation that in case of initDropTables you log "drop" and in case of initCreateTables you log "create table". I think you need to be consistent. And why not "drop tables" and "create tables"
The new status of this patch is: Waiting on Author
Hi Fabien,
I have one minor observation that in case of initDropTables you log
'drop' and in case of initCreateTables you log 'create table'. We need
to be consistent. The "drop tables" and "create tables" are the best
fit here. Otherwise, the patch is good.
On Wed, Apr 10, 2019 at 2:18 PM Ibrar Ahmed <ibrar.ahmad@gmail.com> wrote:
The following review has been posted through the commitfest application:
make installcheck-world: tested, passed
Implements feature: tested, passed
Spec compliant: tested, passed
Documentation: not testedPlease ignore the last email.
Patch works perfectly and the code is well-written. I have one minor observation that in case of initDropTables you log "drop" and in case of initCreateTables you log "create table". I think you need to be consistent. And why not "drop tables" and "create tables"
The new status of this patch is: Waiting on Author
--
Ibrar Ahmed
Hello,
Thanks for the feedback.
I have one minor observation that in case of initDropTables you log
'drop' and in case of initCreateTables you log 'create table'. We need
to be consistent. The "drop tables" and "create tables" are the best
fit here.
Ok.
Attached version does that, plus avoids re-assigning "first" on each loop,
plus checks that --no-vacuum indeed removes all vacuums in the TAP test.
--
Fabien.
Attachments:
pgbench-init-stats-3.patchtext/x-diff; name=pgbench-init-stats-3.patchDownload
diff --git a/src/bin/pgbench/pgbench.c b/src/bin/pgbench/pgbench.c
index b67ad5e823..7de0d914f1 100644
--- a/src/bin/pgbench/pgbench.c
+++ b/src/bin/pgbench/pgbench.c
@@ -3929,32 +3929,48 @@ checkInitSteps(const char *initialize_steps)
static void
runInitSteps(const char *initialize_steps)
{
- PGconn *con;
- const char *step;
+ 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 ' ':
@@ -3965,10 +3981,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 62906d5e55..e910c2fc01 100644
--- a/src/bin/pgbench/t/001_pgbench_with_server.pl
+++ b/src/bin/pgbench/t/001_pgbench_with_server.pl
@@ -101,7 +101,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',);
@@ -116,7 +116,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');
@@ -131,7 +132,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');
The following review has been posted through the commitfest application:
make installcheck-world: tested, passed
Implements feature: tested, passed
Spec compliant: tested, passed
Documentation: not tested
Patch works fine on my machine.
The new status of this patch is: Ready for Committer
On Fri, Apr 12, 2019 at 12:44 AM Ibrar Ahmed <ibrar.ahmad@gmail.com> wrote:
The following review has been posted through the commitfest application:
make installcheck-world: tested, passed
Implements feature: tested, passed
Spec compliant: tested, passed
Documentation: not testedPatch works fine on my machine.
The new status of this patch is: Ready for Committer
I spotted one typo, a comma where a semi-colon was wanted:
+ op = "generate",
initGenerateData(con);
break;
I fixed that, ran it through pgindent and committed. Thanks for the
patch and review!
--
Thomas Munro
https://enterprisedb.com