Re: pgbench - add minimal stats on initialization
On Fri, Apr 12, 2019 at 12:44 AM Ibrar Ahmed 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 tested > > Patch 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
Re: pgbench - add minimal stats on initialization
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
Re: pgbench - add minimal stats on initialization
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.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; + doublerun_time = 0.0; + boolfirst = true; + + initPQExpBuffer(); 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(, ", "); + else +first = false; + + appendPQExpBuffer(, "%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(); } /* 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');
Re: pgbench - add minimal stats on initialization
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 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 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 -- Ibrar Ahmed
Re: pgbench - add minimal stats on initialization
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
Re: pgbench - add minimal stats on initialization
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
Re: pgbench - add minimal stats on initialization
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.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; + doublerun_time = 0.0; + boolfirst = true; + + initPQExpBuffer(); 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(, ", "); + + first = false; + appendPQExpBuffer(, "%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(); } /* 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');
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... 10 of 30 tuples (33%) done (elapsed 0.09 s, remaining 0.18 s) 20 of 30 tuples (66%) done (elapsed 0.20 s, remaining 0.10 s) 30 of 30 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.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; + doublerun_time = 0.0; + boolfirst = true; + + initPQExpBuffer(); 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(, ", "); + + first = false; + appendPQExpBuffer(, "%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(); } /*