Re: WAL usage calculation patch

Hi,

I'm replying here to all reviews that have been sent, thanks a lot!

On Wed, Apr 01, 2020 at 04:29:16PM +0530, Amit Kapila wrote:
> On Wed, Apr 1, 2020 at 1:32 PM Julien Rouhaud <rjuju123(at)gmail(dot)com> wrote:
> >
> > So here's a v9, rebased on top of the latest versions of Sawada-san's bug fixes
> > (Amit's v6 for vacuum and Sawada-san's v2 for create index), with all
> > previously mentionned changes.
> >
>
> Few other comments:
> v9-0003-Add-infrastructure-to-track-WAL-usage
> 1.
> static void BufferUsageAdd(BufferUsage *dst, const BufferUsage *add);
> -
> +static void WalUsageAdd(WalUsage *dst, WalUsage *add);
>
> Looks like a spurious line removal

Fixed.

> 2.
> + /* Report a full page imsage constructed for the WAL record */
> + *num_fpw += 1;
>
> Typo. /imsage/image

Ah sorry I though I fixed it previously, fixed.

> 3. Doing some testing with and without parallelism to ensure WAL usage
> data is correct would be great and if possible, share the results?

I just saw that Dilip did some testing, but just in case here is some
additional one

- vacuum, after a truncate, loading 1M row and a "UPDATE t1 SET id = id"

=# select query, calls, wal_bytes, wal_records, wal_num_fpw from pg_stat_statements where query ilike '%vacuum%';
query | calls | wal_bytes | wal_records | wal_num_fpw
------------------------+-------+-----------+-------------+-------------
vacuum (parallel 3) t1 | 1 | 20098962 | 34104 | 2
vacuum (parallel 0) t1 | 1 | 20098962 | 34104 | 2
(2 rows)

- create index, overload t1's parallel_workers, using the 1M line just
vacuumed:

=# alter table t1 set (parallel_workers = 2);
ALTER TABLE

=# create index t1_parallel_2 on t1(id);
CREATE INDEX

=# alter table t1 set (parallel_workers = 0);
ALTER TABLE

=# create index t1_parallel_0 on t1(id);
CREATE INDEX

=# select query, calls, wal_bytes, wal_records, wal_num_fpw from pg_stat_statements where query ilike '%create index%';
query | calls | wal_bytes | wal_records | wal_num_fpw
--------------------------------------+-------+-----------+-------------+-------------
create index t1_parallel_0 on t1(id) | 1 | 20355540 | 2762 | 2745
create index t1_parallel_2 on t1(id) | 1 | 20406811 | 2762 | 2758
(2 rows)

It all looks good to me.

> v9-0005-Keep-track-of-WAL-usage-in-pg_stat_statements
> 4.
> +-- SELECT usage data, check WAL usage is reported, wal_records equal
> rows count for INSERT/UPDATE/DELETE
> +SELECT query, calls, rows,
> +wal_bytes > 0 as wal_bytes_generated,
> +wal_records > 0 as wal_records_generated,
> +wal_records = rows as wal_records_as_rows
> +FROM pg_stat_statements ORDER BY query COLLATE "C";
> + query |
> calls | rows | wal_bytes_generated | wal_records_generated |
> wal_records_as_rows
> +------------------------------------------------------------------+-------+------+---------------------+-----------------------+---------------------
> + DELETE FROM pgss_test WHERE a > $1 |
> 1 | 1 | t | t | t
> + DROP TABLE pgss_test |
> 1 | 0 | t | t | f
> + INSERT INTO pgss_test (a, b) VALUES ($1, $2), ($3, $4), ($5, $6) |
> 1 | 3 | t | t | t
> + INSERT INTO pgss_test VALUES(generate_series($1, $2), $3) |
> 1 | 10 | t | t | t
> + SELECT * FROM pgss_test ORDER BY a |
> 1 | 12 | f | f | f
> + SELECT * FROM pgss_test WHERE a > $1 ORDER BY a |
> 2 | 4 | f | f | f
> + SELECT * FROM pgss_test WHERE a IN ($1, $2, $3, $4, $5) |
> 1 | 8 | f | f | f
> + SELECT pg_stat_statements_reset() |
> 1 | 1 | f | f | f
> + SET pg_stat_statements.track_utility = FALSE |
> 1 | 0 | f | f | t
> + UPDATE pgss_test SET b = $1 WHERE a = $2 |
> 6 | 6 | t | t | t
> + UPDATE pgss_test SET b = $1 WHERE a > $2 |
> 1 | 3 | t | t | t
> +(11 rows)
> +
>
> I am not sure if the above tests make much sense as they are just
> testing that if WAL is generated for these commands. I understand it
> is not easy to make these tests reliable but in that case, we can
> think of some simple tests. It seems to me that the difficulty is due
> to full_page_writes as that depends on the checkpoint. Can we make
> full_page_writes = off for these tests and check some simple
> Insert/Update/Delete cases? Alternatively, if you can present the
> reason why that is unstable or are tricky to write, then we can simply
> get rid of these tests because I don't see tests for BufferUsage. Let
> not write tests for the sake of writing it unless they can detect bugs
> in the future or are meaningfully covering the new code added.

I don't think that we can have any hope in a stable amount of WAL bytes
generated, so testing a positive number looks sensible to me. Then testing
that each 1-line-write query generates a WAL record also looks sensible, so I
kept this. I realized that Kirill used an existing set of queries that were
previously added to validate the multi queries commands behavior, so there's no
need to have all of them again. I just kept one of each (insert, update,
delete, select) to make sure that we do record WAL activity there, but I don't
think that more can really be done. I still think that this is better than
nothing, but if you disagree feel free to drop those tests.

> 5.
> -SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C";
> - query | calls | rows
> ------------------------------------+-------+------
> - SELECT $1::TEXT | 1 | 1
> - SELECT PLUS_ONE($1) | 2 | 2
> - SELECT PLUS_TWO($1) | 2 | 2
> - SELECT pg_stat_statements_reset() | 1 | 1
> +SELECT query, calls, rows, wal_bytes, wal_records FROM
> pg_stat_statements ORDER BY query COLLATE "C";
> + query | calls | rows | wal_bytes | wal_records
> +-----------------------------------+-------+------+-----------+-------------
> + SELECT $1::TEXT | 1 | 1 | 0 | 0
> + SELECT PLUS_ONE($1) | 2 | 2 | 0 | 0
> + SELECT PLUS_TWO($1) | 2 | 2 | 0 | 0
> + SELECT pg_stat_statements_reset() | 1 | 1 | 0 | 0
> (4 rows)
>
> Again, I am not sure if these modifications make much sense?

Those are queries that were previously executed. As those are read-only query,
that are pretty much guaranteed to not cause any WAL activity, I don't see how
it hurts to test at the same time that that's we indeed record with
pg_stat_statements, just to be safe. Once again, feel free to drop the extra
wal_* columns from the output if you disagree.

> 6.
> static void pgss_shmem_startup(void);
> @@ -313,6 +318,7 @@ static void pgss_store(const char *query, uint64 queryId,
> int query_location, int query_len,
> double total_time, uint64 rows,
> const BufferUsage *bufusage,
> + const WalUsage* walusage,
> pgssJumbleState *jstate);
>
> The alignment for walusage doesn't seem to be correct. Running
> pgindent will fix this.

Indeed, fixed.

> 7.
> + values[i++] = Int64GetDatumFast(tmp.wal_records);
> + values[i++] = UInt64GetDatum(tmp.wal_num_fpw);
>
> Why are they different? I think we should use the same *GetDatum API
> (probably Int64GetDatumFast) for these.

Oops, that's a mistake from when I was working on the wal_bytes output, fixed.

> > v9-0005-Keep-track-of-WAL-usage-in-pg_stat_statements
> >
>
> One more comment related to this patch.
> +
> + snprintf(buf, sizeof buf, UINT64_FORMAT, tmp.wal_bytes);
> +
> + /* Convert to numeric. */
> + wal_bytes = DirectFunctionCall3(numeric_in,
> + CStringGetDatum(buf),
> + ObjectIdGetDatum(0),
> + Int32GetDatum(-1));
> +
> + values[i++] = wal_bytes;
>
> I see that other places that display uint64 values use BIGINT datatype
> in SQL, so why can't we do the same here? See the usage of queryid in
> pg_stat_statements or internal_pages, *_pages exposed via
> pgstatindex.c.

That's because it's harmless to report a signed number for a hash (at least
comapred to the overhead of having it unsigned), while that's certainly not
wanted to report a negative amount of WAL bytes generated if it goes beyond
bigint limit. See the usage of pg_lsn_mi in pg_lsn.c for instance.

On Wed, Apr 01, 2020 at 07:20:31PM +0530, Dilip Kumar wrote:
>
> I have reviewed 0003 and 0004, I have a few comments.
> v9-0003-Add-infrastructure-to-track-WAL-usage
>
> 1.
> /* Points to buffer usage area in DSM */
> BufferUsage *buffer_usage;
> + /* Points to WAL usage area in DSM */
> + WalUsage *wal_usage;
>
> Better to give one blank line between the previous statement/variable
> declaration and the next comment line.

Fixed.

> 2.
> @@ -2154,7 +2157,7 @@ lazy_parallel_vacuum_indexes(Relation *Irel,
> IndexBulkDeleteResult **stats,
> WaitForParallelWorkersToFinish(lps->pcxt);
>
> for (i = 0; i < lps->pcxt->nworkers_launched; i++)
> - InstrAccumParallelQuery(&lps->buffer_usage[i]);
> + InstrAccumParallelQuery(&lps->buffer_usage[i], &lps->wal_usage[i]);
> }
>
> The existing comment above this loop, which just mentions the buffer
> usage, not the wal usage so I guess we need to change that.

Ah indeed, I thought I caught all the comments but missed this one. Fixed.

> v9-0004-Add-option-to-report-WAL-usage-in-EXPLAIN-and-aut
>
> 3.
> + if (usage->wal_num_fpw > 0)
> + appendStringInfo(es->str, " full page records=%ld",
> + usage->wal_num_fpw);
> + if (usage->wal_bytes > 0)
> + appendStringInfo(es->str, " bytes=" UINT64_FORMAT,
> + usage->wal_bytes);
>
> Shall we change to 'full page writes' or 'full page image' instead of
> full page records?

Indeed, I changed it in the (auto)vacuum output but missed this one. Fixed.

> Apart from this, I have some testing to see the wal_usage with the
> parallel vacuum and the results look fine.
>
> postgres[104248]=# CREATE TABLE test (a int, b int);
> CREATE TABLE
> postgres[104248]=# INSERT INTO test SELECT i, i FROM
> GENERATE_SERIES(1,2000000) as i;
> INSERT 0 2000000
> postgres[104248]=# CREATE INDEX idx1 on test(a);
> CREATE INDEX
> postgres[104248]=# VACUUM (PARALLEL 1) test;
> VACUUM
> postgres[104248]=# select query , wal_bytes, wal_records, wal_num_fpw
> from pg_stat_statements where query like 'VACUUM%';
> query | wal_bytes | wal_records | wal_num_fpw
> --------------------------+-----------+-------------+-------------
> VACUUM (PARALLEL 1) test | 72814331 | 8857 | 8855
>
>
>
> postgres[106479]=# CREATE TABLE test (a int, b int);
> CREATE TABLE
> postgres[106479]=# INSERT INTO test SELECT i, i FROM
> GENERATE_SERIES(1,2000000) as i;
> INSERT 0 2000000
> postgres[106479]=# CREATE INDEX idx1 on test(a);
> CREATE INDEX
> postgres[106479]=# VACUUM (PARALLEL 0) test;
> VACUUM
> postgres[106479]=# select query , wal_bytes, wal_records, wal_num_fpw
> from pg_stat_statements where query like 'VACUUM%';
> query | wal_bytes | wal_records | wal_num_fpw
> --------------------------+-----------+-------------+-------------
> VACUUM (PARALLEL 0) test | 72814331 | 8857 | 8855

Thanks! I did some similar testing, with also seq/parallel index creation and
got similar results.

> By tomorrow, I will try to finish reviewing 0005 and 0006.

Thanks!