pg.ddx.io pgsql-hackers@postgresql.org mailing list archive help / color / mirror / Atom feed From: Julien Rouhaud <rjuju123@gmail.com>
To: Amit Kapila <amit.kapila16@gmail.com>
Cc: Kuntal Ghosh <kuntalghosh.2007@gmail.com>
Cc: Fujii Masao <masao.fujii@oss.nttdata.com>
Cc: Kirill Bychik <kirill.bychik@gmail.com>
Cc: PostgreSQL Hackers <pgsql-hackers@postgresql.org>
Cc: Thomas Munro <thomas.munro@gmail.com>
Subject: Re: WAL usage calculation patch
Date: Thu, 2 Apr 2020 16:44:38 +0200
Message-ID: <20200402144438.GF64485@nol> (raw )
In-Reply-To: <CAA4eK1LNg7Q6pxrochATMSJmadrzPKJODGAAxbgmgnWbi63UNw@mail.gmail.com >
References: <CAOBaU_YcZ1C72QxY9BKGg96J-EDdmh--nr1oU0tdRWFQ240y2w@mail.gmail.com >
<CAGz5QC+H4idCkRNojT0=VDLYs7mRBM0an6OZwS5NBdbrb6yKJA@mail.gmail.com >
<20200401080152.GA82418@nol >
<CAA4eK1KxT5ckuaiQqhUsNn=S3yQsxgC5aeiUoXxnS-i2W4K+_g@mail.gmail.com >
<20200401142954.GA64485@nol >
<CAA4eK1JULzGi9SrCnnPbKKiLaVnPhU+uUbbghduRNnC-zFeKAQ@mail.gmail.com >
<20200402083035.GB64485@nol >
<CAA4eK1+CDwmKyJeDYHZ4xFftK9TRW5pF+kkPsgGY8UAJqFNJKQ@mail.gmail.com >
<20200402124818.GD64485@nol >
<CAA4eK1LNg7Q6pxrochATMSJmadrzPKJODGAAxbgmgnWbi63UNw@mail.gmail.com >
On Thu, Apr 02, 2020 at 06:40:51PM +0530, Amit Kapila wrote:
> On Thu, Apr 2, 2020 at 6:18 PM Julien Rouhaud <rjuju123@gmail.com> wrote:
> >
> > =# 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_idx_parallel_0 ON t1(id) | 1 | 20389743 | 2762 | 2758
> > create index t1_idx_parallel_0_bis ON t1(id) | 1 | 20394391 | 2762 | 2758
> > create index t1_idx_parallel_0_ter ON t1(id) | 1 | 20395155 | 2762 | 2758
> > create index t1_idx_parallel_1 ON t1(id) | 1 | 20388335 | 2762 | 2758
> > create index t1_idx_parallel_2 ON t1(id) | 1 | 20389091 | 2762 | 2758
> > create index t1_idx_parallel_3 ON t1(id) | 1 | 20389847 | 2762 | 2758
> > create index t1_idx_parallel_4 ON t1(id) | 1 | 20390603 | 2762 | 2758
> > create index t1_idx_parallel_5 ON t1(id) | 1 | 20391359 | 2762 | 2758
> > create index t1_idx_parallel_6 ON t1(id) | 1 | 20392115 | 2762 | 2758
> > create index t1_idx_parallel_7 ON t1(id) | 1 | 20392871 | 2762 | 2758
> > create index t1_idx_parallel_8 ON t1(id) | 1 | 20393627 | 2762 | 2758
> > (11 rows)
> >
> > =# select relname, pg_relation_size(oid) from pg_class where relname like '%t1_id%';
> > relname | pg_relation_size
> > -----------------------+------------------
> > t1_idx_parallel_0 | 22487040
> > t1_idx_parallel_0_bis | 22487040
> > t1_idx_parallel_0_ter | 22487040
> > t1_idx_parallel_2 | 22487040
> > t1_idx_parallel_1 | 22487040
> > t1_idx_parallel_4 | 22487040
> > t1_idx_parallel_3 | 22487040
> > t1_idx_parallel_5 | 22487040
> > t1_idx_parallel_6 | 22487040
> > t1_idx_parallel_7 | 22487040
> > t1_idx_parallel_8 | 22487040
> > (9 rows)
> >
> >
> > So while the number of WAL records and full page images stay constant, we can
> > see some small fluctuations in the total amount of generated WAL data, even for
> > multiple execution of the sequential create index. I'm wondering if the
> > fluctuations are due to some other internal details or if the WalUsage support
> > is just completely broken (although I don't see any obvious issue ATM).
> >
>
> I think we need to know the reason for this. Can you try with small
> size indexes and see if the problem is reproducible? If it is, then it
> will be easier to debug the same.
I did some quick testing using the attached shell script:
- one a 1k line base number of lines, scales 1 10 100 1000 (suffix _s)
- parallel workers from 0 to 8 (suffix _w)
- each index created twice (suffix _pa and _pb)
- with a vacuum;checkpoint;pg_switch_wal executed each time
I get the following results:
query | wal_bytes | wal_records | wal_num_fpw
--------------------------------------------+-----------+-------------+-------------
CREATE INDEX t1_idx_s001_pa_w0 ON t1 (id) | 61871 | 22 | 18
CREATE INDEX t1_idx_s001_pa_w1 ON t1 (id) | 62394 | 21 | 18
CREATE INDEX t1_idx_s001_pa_w2 ON t1 (id) | 63150 | 21 | 18
CREATE INDEX t1_idx_s001_pa_w3 ON t1 (id) | 63906 | 21 | 18
CREATE INDEX t1_idx_s001_pa_w4 ON t1 (id) | 64662 | 21 | 18
CREATE INDEX t1_idx_s001_pa_w5 ON t1 (id) | 65418 | 21 | 18
CREATE INDEX t1_idx_s001_pa_w6 ON t1 (id) | 65450 | 21 | 18
CREATE INDEX t1_idx_s001_pa_w7 ON t1 (id) | 66206 | 21 | 18
CREATE INDEX t1_idx_s001_pa_w8 ON t1 (id) | 66962 | 21 | 18
CREATE INDEX t1_idx_s001_pb_w0 ON t1 (id) | 67718 | 21 | 18
CREATE INDEX t1_idx_s001_pb_w1 ON t1 (id) | 68474 | 21 | 18
CREATE INDEX t1_idx_s001_pb_w2 ON t1 (id) | 68418 | 21 | 18
CREATE INDEX t1_idx_s001_pb_w3 ON t1 (id) | 69174 | 21 | 18
CREATE INDEX t1_idx_s001_pb_w4 ON t1 (id) | 69930 | 21 | 18
CREATE INDEX t1_idx_s001_pb_w5 ON t1 (id) | 70686 | 21 | 18
CREATE INDEX t1_idx_s001_pb_w6 ON t1 (id) | 71442 | 21 | 18
CREATE INDEX t1_idx_s001_pb_w7 ON t1 (id) | 64922 | 21 | 18
CREATE INDEX t1_idx_s001_pb_w8 ON t1 (id) | 65682 | 21 | 18
CREATE INDEX t1_idx_s010_pa_w0 ON t1 (id) | 250460 | 47 | 44
CREATE INDEX t1_idx_s010_pa_w1 ON t1 (id) | 251216 | 47 | 44
CREATE INDEX t1_idx_s010_pa_w2 ON t1 (id) | 251972 | 47 | 44
CREATE INDEX t1_idx_s010_pa_w3 ON t1 (id) | 252728 | 47 | 44
CREATE INDEX t1_idx_s010_pa_w4 ON t1 (id) | 253484 | 47 | 44
CREATE INDEX t1_idx_s010_pa_w5 ON t1 (id) | 254240 | 47 | 44
CREATE INDEX t1_idx_s010_pa_w6 ON t1 (id) | 253552 | 47 | 44
CREATE INDEX t1_idx_s010_pa_w7 ON t1 (id) | 254308 | 47 | 44
CREATE INDEX t1_idx_s010_pa_w8 ON t1 (id) | 255064 | 47 | 44
CREATE INDEX t1_idx_s010_pb_w0 ON t1 (id) | 255820 | 47 | 44
CREATE INDEX t1_idx_s010_pb_w1 ON t1 (id) | 256576 | 47 | 44
CREATE INDEX t1_idx_s010_pb_w2 ON t1 (id) | 257332 | 47 | 44
CREATE INDEX t1_idx_s010_pb_w3 ON t1 (id) | 258088 | 47 | 44
CREATE INDEX t1_idx_s010_pb_w4 ON t1 (id) | 258844 | 47 | 44
CREATE INDEX t1_idx_s010_pb_w5 ON t1 (id) | 259600 | 47 | 44
CREATE INDEX t1_idx_s010_pb_w6 ON t1 (id) | 260356 | 47 | 44
CREATE INDEX t1_idx_s010_pb_w7 ON t1 (id) | 260012 | 47 | 44
CREATE INDEX t1_idx_s010_pb_w8 ON t1 (id) | 260768 | 47 | 44
CREATE INDEX t1_idx_s1000_pa_w0 ON t1 (id) | 20400595 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pa_w1 ON t1 (id) | 20401351 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pa_w2 ON t1 (id) | 20402107 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pa_w3 ON t1 (id) | 20402863 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pa_w4 ON t1 (id) | 20403619 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pa_w5 ON t1 (id) | 20404375 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pa_w6 ON t1 (id) | 20403687 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pa_w7 ON t1 (id) | 20404443 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pa_w8 ON t1 (id) | 20405199 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pb_w0 ON t1 (id) | 20405955 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pb_w1 ON t1 (id) | 20406711 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pb_w2 ON t1 (id) | 20407467 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pb_w3 ON t1 (id) | 20408223 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pb_w4 ON t1 (id) | 20408979 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pb_w5 ON t1 (id) | 20409735 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pb_w6 ON t1 (id) | 20410491 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pb_w7 ON t1 (id) | 20410147 | 2762 | 2759
CREATE INDEX t1_idx_s1000_pb_w8 ON t1 (id) | 20410903 | 2762 | 2759
CREATE INDEX t1_idx_s100_pa_w0 ON t1 (id) | 2082194 | 293 | 290
CREATE INDEX t1_idx_s100_pa_w1 ON t1 (id) | 2082950 | 293 | 290
CREATE INDEX t1_idx_s100_pa_w2 ON t1 (id) | 2083706 | 293 | 290
CREATE INDEX t1_idx_s100_pa_w3 ON t1 (id) | 2084462 | 293 | 290
CREATE INDEX t1_idx_s100_pa_w4 ON t1 (id) | 2085218 | 293 | 290
CREATE INDEX t1_idx_s100_pa_w5 ON t1 (id) | 2085974 | 293 | 290
CREATE INDEX t1_idx_s100_pa_w6 ON t1 (id) | 2085286 | 293 | 290
CREATE INDEX t1_idx_s100_pa_w7 ON t1 (id) | 2086042 | 293 | 290
CREATE INDEX t1_idx_s100_pa_w8 ON t1 (id) | 2086798 | 293 | 290
CREATE INDEX t1_idx_s100_pb_w0 ON t1 (id) | 2087554 | 293 | 290
CREATE INDEX t1_idx_s100_pb_w1 ON t1 (id) | 2088310 | 293 | 290
CREATE INDEX t1_idx_s100_pb_w2 ON t1 (id) | 2089066 | 293 | 290
CREATE INDEX t1_idx_s100_pb_w3 ON t1 (id) | 2089822 | 293 | 290
CREATE INDEX t1_idx_s100_pb_w4 ON t1 (id) | 2090578 | 293 | 290
CREATE INDEX t1_idx_s100_pb_w5 ON t1 (id) | 2091334 | 293 | 290
CREATE INDEX t1_idx_s100_pb_w6 ON t1 (id) | 2092090 | 293 | 290
CREATE INDEX t1_idx_s100_pb_w7 ON t1 (id) | 2091746 | 293 | 290
CREATE INDEX t1_idx_s100_pb_w8 ON t1 (id) | 2092502 | 293 | 290
(72 rows)
The fluctuations exist for all scales, but doesn't seem to depend on the input
size.
Just to be sure I tried to measure the amount of WAL for various INSERT size
using roughly the same approach, and results are stable:
query | wal_bytes | wal_records | wal_num_fpw
-----------------------------------------------------+-----------+-------------+-------------
INSERT INTO t_001_a SELECT generate_series($1, $2) | 59000 | 1000 | 0
INSERT INTO t_001_b SELECT generate_series($1, $2) | 59000 | 1000 | 0
INSERT INTO t_010_a SELECT generate_series($1, $2) | 590000 | 10000 | 0
INSERT INTO t_010_b SELECT generate_series($1, $2) | 590000 | 10000 | 0
INSERT INTO t_1000_a SELECT generate_series($1, $2) | 59000000 | 1000000 | 0
INSERT INTO t_1000_b SELECT generate_series($1, $2) | 59000000 | 1000000 | 0
INSERT INTO t_100_a SELECT generate_series($1, $2) | 5900000 | 100000 | 0
INSERT INTO t_100_b SELECT generate_series($1, $2) | 5900000 | 100000 | 0
(8 rows)
At this point I tend to think that this is somehow due to btbuild specific
behavior, or somewhere nearby.
> Few other minor comments
> ------------------------------------
> pg_stat_statements patch
> 1.
> +--
> +-- CRUD: INSERT SELECT UPDATE DELETE on test non-temp table to
> validate WAL generation metrics
> +--
>
> The word 'non-temp' in the above comment appears out of place. We
> don't need to specify it.
Fixed.
> 2.
> +-- 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";
>
> The comment doesn't seem to match what we are doing in the statement.
> I think we can simplify it to something like "check WAL is generated
> for above statements:
Done.
> 3.
> @@ -185,6 +185,9 @@ typedef struct Counters
> int64 local_blks_written; /* # of local disk blocks written */
> int64 temp_blks_read; /* # of temp blocks read */
> int64 temp_blks_written; /* # of temp blocks written */
> + uint64 wal_bytes; /* total amount of WAL bytes generated */
> + int64 wal_records; /* # of WAL records generated */
> + int64 wal_num_fpw; /* # of WAL full page image generated */
> double blk_read_time; /* time spent reading, in msec */
> double blk_write_time; /* time spent writing, in msec */
> double usage; /* usage factor */
>
> It is better to keep wal_bytes should be after wal_num_fpw as it is in
> the main patch. Also, consider changing at other places in this
> patch. I think we should add these new fields after blk_write_time or
> at the end after usage.
Done.
> 4.
> /* # of WAL full page image generated */
> Can we change it to "/* # of WAL full page image records generated */"?
>
> If you agree, then a similar comment exists in
> v11-0001-Add-infrastructure-to-track-WAL-usage, consider changing that
> as well.
Agreed, and fixed in both place.
> v11-0002-Add-option-to-report-WAL-usage-in-EXPLAIN-and-au
> 5.
> Specifically, include the
> + number of records, full page images and bytes generated.
>
> How about making the above slightly clear? "Specifically, include the
> number of records, number of full page image records and amount of WAL
> bytes generated.
Thanks, that's clearer. Done
From 1ba0a76f3e071c239dd65fe06517ead816922957 Mon Sep 17 00:00:00 2001
From: Kirill Bychik <kirill.bychik@gmail.com>
Date: Tue, 17 Mar 2020 14:41:50 +0100
Subject: [PATCH v13 1/4] Add infrastructure to track WAL usage.
Author: Kirill Bychik, Julien Rouhaud
Reviewed-by: Fuji Masao
Discussion: https://postgr.es/m/CAB-hujrP8ZfUkvL5OYETipQwA=e3n7oqHFU=4ZLxWS_Cza3kQQ@mail.gmail.com
---
src/backend/access/heap/vacuumlazy.c | 37 ++++++++++++-----
src/backend/access/nbtree/nbtsort.c | 40 +++++++++++++++++++
src/backend/access/transam/xlog.c | 12 +++++-
src/backend/access/transam/xloginsert.c | 13 ++++--
src/backend/executor/execParallel.c | 38 +++++++++++++-----
src/backend/executor/instrument.c | 53 ++++++++++++++++++++++---
src/include/access/xlog.h | 3 +-
src/include/executor/execParallel.h | 1 +
src/include/executor/instrument.h | 18 ++++++++-
src/tools/pgindent/typedefs.list | 1 +
10 files changed, 183 insertions(+), 33 deletions(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 9f9596c718..cc7e8521a5 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -139,6 +139,7 @@
#define PARALLEL_VACUUM_KEY_DEAD_TUPLES 2
#define PARALLEL_VACUUM_KEY_QUERY_TEXT 3
#define PARALLEL_VACUUM_KEY_BUFFER_USAGE 4
+#define PARALLEL_VACUUM_KEY_WAL_USAGE 5
/*
* Macro to check if we are in a parallel vacuum. If true, we are in the
@@ -275,6 +276,9 @@ typedef struct LVParallelState
/* Points to buffer usage area in DSM */
BufferUsage *buffer_usage;
+ /* Points to WAL usage area in DSM */
+ WalUsage *wal_usage;
+
/*
* The number of indexes that support parallel index bulk-deletion and
* parallel index cleanup respectively.
@@ -2143,8 +2147,8 @@ lazy_parallel_vacuum_indexes(Relation *Irel, IndexBulkDeleteResult **stats,
vacrelstats->dead_tuples, nindexes, vacrelstats);
/*
- * Next, accumulate buffer usage. (This must wait for the workers to
- * finish, or we might get incomplete data.)
+ * Next, accumulate buffer and WAL usage. (This must wait for the workers
+ * to finish, or we might get incomplete data.)
*/
if (nworkers > 0)
{
@@ -2154,7 +2158,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]);
}
/*
@@ -3171,6 +3175,7 @@ begin_parallel_vacuum(Oid relid, Relation *Irel, LVRelStats *vacrelstats,
LVShared *shared;
LVDeadTuples *dead_tuples;
BufferUsage *buffer_usage;
+ WalUsage *wal_usage;
bool *can_parallel_vacuum;
long maxtuples;
char *sharedquery;
@@ -3255,15 +3260,19 @@ begin_parallel_vacuum(Oid relid, Relation *Irel, LVRelStats *vacrelstats,
shm_toc_estimate_keys(&pcxt->estimator, 1);
/*
- * Estimate space for BufferUsage -- PARALLEL_VACUUM_KEY_BUFFER_USAGE.
+ * Estimate space for BufferUsage and WalUsage --
+ * PARALLEL_VACUUM_KEY_BUFFER_USAGE and PARALLEL_VACUUM_KEY_WAL_USAGE.
*
* If there are no extensions loaded that care, we could skip this. We
- * have no way of knowing whether anyone's looking at pgBufferUsage, so do
- * it unconditionally.
+ * have no way of knowing whether anyone's looking at pgBufferUsage or
+ * pgWalUsage, so do it unconditionally.
*/
shm_toc_estimate_chunk(&pcxt->estimator,
mul_size(sizeof(BufferUsage), pcxt->nworkers));
shm_toc_estimate_keys(&pcxt->estimator, 1);
+ shm_toc_estimate_chunk(&pcxt->estimator,
+ mul_size(sizeof(WalUsage), pcxt->nworkers));
+ shm_toc_estimate_keys(&pcxt->estimator, 1);
/* Finally, estimate PARALLEL_VACUUM_KEY_QUERY_TEXT space */
querylen = strlen(debug_query_string);
@@ -3299,11 +3308,18 @@ begin_parallel_vacuum(Oid relid, Relation *Irel, LVRelStats *vacrelstats,
shm_toc_insert(pcxt->toc, PARALLEL_VACUUM_KEY_DEAD_TUPLES, dead_tuples);
vacrelstats->dead_tuples = dead_tuples;
- /* Allocate space for each worker's BufferUsage; no need to initialize */
+ /*
+ * Allocate space for each worker's BufferUsage and WalUsage; no need to
+ * initialize
+ */
buffer_usage = shm_toc_allocate(pcxt->toc,
mul_size(sizeof(BufferUsage), pcxt->nworkers));
shm_toc_insert(pcxt->toc, PARALLEL_VACUUM_KEY_BUFFER_USAGE, buffer_usage);
lps->buffer_usage = buffer_usage;
+ wal_usage = shm_toc_allocate(pcxt->toc,
+ mul_size(sizeof(WalUsage), pcxt->nworkers));
+ shm_toc_insert(pcxt->toc, PARALLEL_VACUUM_KEY_WAL_USAGE, wal_usage);
+ lps->wal_usage = wal_usage;
/* Store query string for workers */
sharedquery = (char *) shm_toc_allocate(pcxt->toc, querylen + 1);
@@ -3435,6 +3451,7 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc)
LVShared *lvshared;
LVDeadTuples *dead_tuples;
BufferUsage *buffer_usage;
+ WalUsage *wal_usage;
int nindexes;
char *sharedquery;
IndexBulkDeleteResult **stats;
@@ -3511,9 +3528,11 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc)
parallel_vacuum_index(indrels, stats, lvshared, dead_tuples, nindexes,
&vacrelstats);
- /* Report buffer usage during parallel execution */
+ /* Report buffer/WAL usage during parallel execution */
buffer_usage = shm_toc_lookup(toc, PARALLEL_VACUUM_KEY_BUFFER_USAGE, false);
- InstrEndParallelQuery(&buffer_usage[ParallelWorkerNumber]);
+ wal_usage = shm_toc_lookup(toc, PARALLEL_VACUUM_KEY_WAL_USAGE, false);
+ InstrEndParallelQuery(&buffer_usage[ParallelWorkerNumber],
+ &wal_usage[ParallelWorkerNumber]);
/* Pop the error context stack */
error_context_stack = errcallback.previous;
diff --git a/src/backend/access/nbtree/nbtsort.c b/src/backend/access/nbtree/nbtsort.c
index 3924945664..3f4cb7d39e 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -67,6 +67,7 @@
#include "access/xloginsert.h"
#include "catalog/index.h"
#include "commands/progress.h"
+#include "executor/instrument.h"
#include "miscadmin.h"
#include "pgstat.h"
#include "storage/smgr.h"
@@ -81,6 +82,7 @@
#define PARALLEL_KEY_TUPLESORT UINT64CONST(0xA000000000000002)
#define PARALLEL_KEY_TUPLESORT_SPOOL2 UINT64CONST(0xA000000000000003)
#define PARALLEL_KEY_QUERY_TEXT UINT64CONST(0xA000000000000004)
+#define PARALLEL_KEY_WAL_USAGE UINT64CONST(0xA000000000000005)
/*
* DISABLE_LEADER_PARTICIPATION disables the leader's participation in
@@ -203,6 +205,7 @@ typedef struct BTLeader
Sharedsort *sharedsort;
Sharedsort *sharedsort2;
Snapshot snapshot;
+ WalUsage *walusage;
} BTLeader;
/*
@@ -1476,6 +1479,7 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
Sharedsort *sharedsort2;
BTSpool *btspool = buildstate->spool;
BTLeader *btleader = (BTLeader *) palloc0(sizeof(BTLeader));
+ WalUsage *walusage;
bool leaderparticipates = true;
char *sharedquery;
int querylen;
@@ -1528,6 +1532,18 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
shm_toc_estimate_keys(&pcxt->estimator, 3);
}
+ /*
+ * Estimate space for WalUsage -- PARALLEL_KEY_WAL_USAGE
+ *
+ * WalUsage during execution of maintenance command can be used by an
+ * extension that reports the WAL usage, such as pg_stat_statements.
+ * We have no way of knowing whether anyone's looking at pgWalUsage,
+ * so do it unconditionally.
+ */
+ shm_toc_estimate_chunk(&pcxt->estimator,
+ mul_size(sizeof(WalUsage), pcxt->nworkers));
+ shm_toc_estimate_keys(&pcxt->estimator, 1);
+
/* Finally, estimate PARALLEL_KEY_QUERY_TEXT space */
querylen = strlen(debug_query_string);
shm_toc_estimate_chunk(&pcxt->estimator, querylen + 1);
@@ -1599,6 +1615,11 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
memcpy(sharedquery, debug_query_string, querylen + 1);
shm_toc_insert(pcxt->toc, PARALLEL_KEY_QUERY_TEXT, sharedquery);
+ /* Allocate space for each worker's WalUsage; no need to initialize */
+ walusage = shm_toc_allocate(pcxt->toc,
+ mul_size(sizeof(WalUsage), pcxt->nworkers));
+ shm_toc_insert(pcxt->toc, PARALLEL_KEY_WAL_USAGE, walusage);
+
/* Launch workers, saving status for leader/caller */
LaunchParallelWorkers(pcxt);
btleader->pcxt = pcxt;
@@ -1609,6 +1630,7 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
btleader->sharedsort = sharedsort;
btleader->sharedsort2 = sharedsort2;
btleader->snapshot = snapshot;
+ btleader->walusage = walusage;
/* If no workers were successfully launched, back out (do serial build) */
if (pcxt->nworkers_launched == 0)
@@ -1637,8 +1659,18 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
static void
_bt_end_parallel(BTLeader *btleader)
{
+ int i;
+
/* Shutdown worker processes */
WaitForParallelWorkersToFinish(btleader->pcxt);
+
+ /*
+ * Next, accumulate WAL usage. (This must wait for the workers to
+ * finish, or we might get incomplete data.)
+ */
+ for (i = 0; i < btleader->pcxt->nworkers_launched; i++)
+ InstrAccumParallelQuery(NULL, &btleader->walusage[i]);
+
/* Free last reference to MVCC snapshot, if one was used */
if (IsMVCCSnapshot(btleader->snapshot))
UnregisterSnapshot(btleader->snapshot);
@@ -1769,6 +1801,7 @@ _bt_parallel_build_main(dsm_segment *seg, shm_toc *toc)
Relation indexRel;
LOCKMODE heapLockmode;
LOCKMODE indexLockmode;
+ WalUsage *walusage;
int sortmem;
#ifdef BTREE_BUILD_STATS
@@ -1830,11 +1863,18 @@ _bt_parallel_build_main(dsm_segment *seg, shm_toc *toc)
tuplesort_attach_shared(sharedsort2, seg);
}
+ /* Prepare to track buffer usage during parallel execution */
+ InstrStartParallelQuery();
+
/* Perform sorting of spool, and possibly a spool2 */
sortmem = maintenance_work_mem / btshared->scantuplesortstates;
_bt_parallel_scan_and_sort(btspool, btspool2, btshared, sharedsort,
sharedsort2, sortmem, false);
+ /* Report WAL usage during parallel execution */
+ walusage = shm_toc_lookup(toc, PARALLEL_KEY_WAL_USAGE, false);
+ InstrEndParallelQuery(NULL, &walusage[ParallelWorkerNumber]);
+
#ifdef BTREE_BUILD_STATS
if (log_btree_build_stats)
{
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 977d448f50..50b78f3143 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -43,6 +43,7 @@
#include "commands/progress.h"
#include "commands/tablespace.h"
#include "common/controldata_utils.h"
+#include "executor/instrument.h"
#include "miscadmin.h"
#include "pg_trace.h"
#include "pgstat.h"
@@ -996,7 +997,8 @@ static void WALInsertLockUpdateInsertingAt(XLogRecPtr insertingAt);
XLogRecPtr
XLogInsertRecord(XLogRecData *rdata,
XLogRecPtr fpw_lsn,
- uint8 flags)
+ uint8 flags,
+ int num_fpw)
{
XLogCtlInsert *Insert = &XLogCtl->Insert;
pg_crc32c rdata_crc;
@@ -1252,6 +1254,14 @@ XLogInsertRecord(XLogRecData *rdata,
ProcLastRecPtr = StartPos;
XactLastRecEnd = EndPos;
+ /* Report WAL traffic to the instrumentation. */
+ if (inserted)
+ {
+ pgWalUsage.wal_bytes += rechdr->xl_tot_len;
+ pgWalUsage.wal_records++;
+ pgWalUsage.wal_num_fpw += num_fpw;
+ }
+
return EndPos;
}
diff --git a/src/backend/access/transam/xloginsert.c b/src/backend/access/transam/xloginsert.c
index a618dec776..5e032e7042 100644
--- a/src/backend/access/transam/xloginsert.c
+++ b/src/backend/access/transam/xloginsert.c
@@ -25,6 +25,7 @@
#include "access/xloginsert.h"
#include "catalog/pg_control.h"
#include "common/pg_lzcompress.h"
+#include "executor/instrument.h"
#include "miscadmin.h"
#include "pg_trace.h"
#include "replication/origin.h"
@@ -108,7 +109,7 @@ static MemoryContext xloginsert_cxt;
static XLogRecData *XLogRecordAssemble(RmgrId rmid, uint8 info,
XLogRecPtr RedoRecPtr, bool doPageWrites,
- XLogRecPtr *fpw_lsn);
+ XLogRecPtr *fpw_lsn, int *num_fpw);
static bool XLogCompressBackupBlock(char *page, uint16 hole_offset,
uint16 hole_length, char *dest, uint16 *dlen);
@@ -448,6 +449,7 @@ XLogInsert(RmgrId rmid, uint8 info)
bool doPageWrites;
XLogRecPtr fpw_lsn;
XLogRecData *rdt;
+ int num_fpw = 0;
/*
* Get values needed to decide whether to do full-page writes. Since
@@ -457,9 +459,9 @@ XLogInsert(RmgrId rmid, uint8 info)
GetFullPageWriteInfo(&RedoRecPtr, &doPageWrites);
rdt = XLogRecordAssemble(rmid, info, RedoRecPtr, doPageWrites,
- &fpw_lsn);
+ &fpw_lsn, &num_fpw);
- EndPos = XLogInsertRecord(rdt, fpw_lsn, curinsert_flags);
+ EndPos = XLogInsertRecord(rdt, fpw_lsn, curinsert_flags, num_fpw);
} while (EndPos == InvalidXLogRecPtr);
XLogResetInsertion();
@@ -482,7 +484,7 @@ XLogInsert(RmgrId rmid, uint8 info)
static XLogRecData *
XLogRecordAssemble(RmgrId rmid, uint8 info,
XLogRecPtr RedoRecPtr, bool doPageWrites,
- XLogRecPtr *fpw_lsn)
+ XLogRecPtr *fpw_lsn, int *num_fpw)
{
XLogRecData *rdt;
uint32 total_len = 0;
@@ -635,6 +637,9 @@ XLogRecordAssemble(RmgrId rmid, uint8 info,
*/
bkpb.fork_flags |= BKPBLOCK_HAS_IMAGE;
+ /* Report a full page image constructed for the WAL record */
+ *num_fpw += 1;
+
/*
* Construct XLogRecData entries for the page content.
*/
diff --git a/src/backend/executor/execParallel.c b/src/backend/executor/execParallel.c
index a753d6efa0..7d9ca66fc8 100644
--- a/src/backend/executor/execParallel.c
+++ b/src/backend/executor/execParallel.c
@@ -12,7 +12,7 @@
* workers and ensuring that their state generally matches that of the
* leader; see src/backend/access/transam/README.parallel for details.
* However, we must save and restore relevant executor state, such as
- * any ParamListInfo associated with the query, buffer usage info, and
+ * any ParamListInfo associated with the query, buffer/WAL usage info, and
* the actual plan to be passed down to the worker.
*
* IDENTIFICATION
@@ -62,6 +62,7 @@
#define PARALLEL_KEY_DSA UINT64CONST(0xE000000000000007)
#define PARALLEL_KEY_QUERY_TEXT UINT64CONST(0xE000000000000008)
#define PARALLEL_KEY_JIT_INSTRUMENTATION UINT64CONST(0xE000000000000009)
+#define PARALLEL_KEY_WAL_USAGE UINT64CONST(0xE00000000000000A)
#define PARALLEL_TUPLE_QUEUE_SIZE 65536
@@ -573,6 +574,7 @@ ExecInitParallelPlan(PlanState *planstate, EState *estate,
char *pstmt_space;
char *paramlistinfo_space;
BufferUsage *bufusage_space;
+ WalUsage *walusage_space;
SharedExecutorInstrumentation *instrumentation = NULL;
SharedJitInstrumentation *jit_instrumentation = NULL;
int pstmt_len;
@@ -646,6 +648,13 @@ ExecInitParallelPlan(PlanState *planstate, EState *estate,
mul_size(sizeof(BufferUsage), pcxt->nworkers));
shm_toc_estimate_keys(&pcxt->estimator, 1);
+ /*
+ * Same thing for WalUsage.
+ */
+ shm_toc_estimate_chunk(&pcxt->estimator,
+ mul_size(sizeof(WalUsage), pcxt->nworkers));
+ shm_toc_estimate_keys(&pcxt->estimator, 1);
+
/* Estimate space for tuple queues. */
shm_toc_estimate_chunk(&pcxt->estimator,
mul_size(PARALLEL_TUPLE_QUEUE_SIZE, pcxt->nworkers));
@@ -728,6 +737,12 @@ ExecInitParallelPlan(PlanState *planstate, EState *estate,
shm_toc_insert(pcxt->toc, PARALLEL_KEY_BUFFER_USAGE, bufusage_space);
pei->buffer_usage = bufusage_space;
+ /* Same for WalUsage. */
+ walusage_space = shm_toc_allocate(pcxt->toc,
+ mul_size(sizeof(WalUsage), pcxt->nworkers));
+ shm_toc_insert(pcxt->toc, PARALLEL_KEY_WAL_USAGE, walusage_space);
+ pei->wal_usage = walusage_space;
+
/* Set up the tuple queues that the workers will write into. */
pei->tqueue = ExecParallelSetupTupleQueues(pcxt, false);
@@ -1069,7 +1084,7 @@ ExecParallelRetrieveJitInstrumentation(PlanState *planstate,
/*
* Finish parallel execution. We wait for parallel workers to finish, and
- * accumulate their buffer usage.
+ * accumulate their buffer/WAL usage.
*/
void
ExecParallelFinish(ParallelExecutorInfo *pei)
@@ -1109,11 +1124,11 @@ ExecParallelFinish(ParallelExecutorInfo *pei)
WaitForParallelWorkersToFinish(pei->pcxt);
/*
- * Next, accumulate buffer usage. (This must wait for the workers to
- * finish, or we might get incomplete data.)
+ * Next, accumulate buffer/WAL usage. (This must wait for the workers
+ * to finish, or we might get incomplete data.)
*/
for (i = 0; i < nworkers; i++)
- InstrAccumParallelQuery(&pei->buffer_usage[i]);
+ InstrAccumParallelQuery(&pei->buffer_usage[i], &pei->wal_usage[i]);
pei->finished = true;
}
@@ -1333,6 +1348,7 @@ ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
{
FixedParallelExecutorState *fpes;
BufferUsage *buffer_usage;
+ WalUsage *wal_usage;
DestReceiver *receiver;
QueryDesc *queryDesc;
SharedExecutorInstrumentation *instrumentation;
@@ -1386,11 +1402,11 @@ ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
ExecSetTupleBound(fpes->tuples_needed, queryDesc->planstate);
/*
- * Prepare to track buffer usage during query execution.
+ * Prepare to track buffer/WAL usage during query execution.
*
* We do this after starting up the executor to match what happens in the
- * leader, which also doesn't count buffer accesses that occur during
- * executor startup.
+ * leader, which also doesn't count buffer accesses and WAL activity that
+ * occur during executor startup.
*/
InstrStartParallelQuery();
@@ -1406,9 +1422,11 @@ ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
/* Shut down the executor */
ExecutorFinish(queryDesc);
- /* Report buffer usage during parallel execution. */
+ /* Report buffer/WAL usage during parallel execution. */
buffer_usage = shm_toc_lookup(toc, PARALLEL_KEY_BUFFER_USAGE, false);
- InstrEndParallelQuery(&buffer_usage[ParallelWorkerNumber]);
+ wal_usage = shm_toc_lookup (toc, PARALLEL_KEY_WAL_USAGE, false);
+ InstrEndParallelQuery(&buffer_usage[ParallelWorkerNumber],
+ &wal_usage[ParallelWorkerNumber]);
/* Report instrumentation data if any instrumentation options are set. */
if (instrumentation != NULL)
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index 042e10f96b..a77571a895 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -19,8 +19,11 @@
BufferUsage pgBufferUsage;
static BufferUsage save_pgBufferUsage;
+WalUsage pgWalUsage;
+static WalUsage save_pgWalUsage;
static void BufferUsageAdd(BufferUsage *dst, const BufferUsage *add);
+static void WalUsageAdd(WalUsage *dst, WalUsage *add);
/* Allocate new instrumentation structure(s) */
@@ -31,15 +34,17 @@ InstrAlloc(int n, int instrument_options)
/* initialize all fields to zeroes, then modify as needed */
instr = palloc0(n * sizeof(Instrumentation));
- if (instrument_options & (INSTRUMENT_BUFFERS | INSTRUMENT_TIMER))
+ if (instrument_options & (INSTRUMENT_BUFFERS | INSTRUMENT_TIMER | INSTRUMENT_WAL))
{
bool need_buffers = (instrument_options & INSTRUMENT_BUFFERS) != 0;
+ bool need_wal = (instrument_options & INSTRUMENT_WAL) != 0;
bool need_timer = (instrument_options & INSTRUMENT_TIMER) != 0;
int i;
for (i = 0; i < n; i++)
{
instr[i].need_bufusage = need_buffers;
+ instr[i].need_walusage = need_wal;
instr[i].need_timer = need_timer;
}
}
@@ -53,6 +58,7 @@ InstrInit(Instrumentation *instr, int instrument_options)
{
memset(instr, 0, sizeof(Instrumentation));
instr->need_bufusage = (instrument_options & INSTRUMENT_BUFFERS) != 0;
+ instr->need_walusage = (instrument_options & INSTRUMENT_WAL) != 0;
instr->need_timer = (instrument_options & INSTRUMENT_TIMER) != 0;
}
@@ -67,6 +73,9 @@ InstrStartNode(Instrumentation *instr)
/* save buffer usage totals at node entry, if needed */
if (instr->need_bufusage)
instr->bufusage_start = pgBufferUsage;
+
+ if (instr->need_walusage)
+ instr->walusage_start = pgWalUsage;
}
/* Exit from a plan node */
@@ -95,6 +104,10 @@ InstrStopNode(Instrumentation *instr, double nTuples)
BufferUsageAccumDiff(&instr->bufusage,
&pgBufferUsage, &instr->bufusage_start);
+ if (instr->need_walusage)
+ WalUsageAccumDiff(&instr->walusage,
+ &pgWalUsage, &instr->walusage_start);
+
/* Is this the first tuple of this cycle? */
if (!instr->running)
{
@@ -158,6 +171,9 @@ InstrAggNode(Instrumentation *dst, Instrumentation *add)
/* Add delta of buffer usage since entry to node's totals */
if (dst->need_bufusage)
BufferUsageAdd(&dst->bufusage, &add->bufusage);
+
+ if (dst->need_walusage)
+ WalUsageAdd(&dst->walusage, &add->walusage);
}
/* note current values during parallel executor startup */
@@ -165,21 +181,29 @@ void
InstrStartParallelQuery(void)
{
save_pgBufferUsage = pgBufferUsage;
+ save_pgWalUsage = pgWalUsage;
}
/* report usage after parallel executor shutdown */
void
-InstrEndParallelQuery(BufferUsage *result)
+InstrEndParallelQuery(BufferUsage *bufusage, WalUsage *walusage)
{
- memset(result, 0, sizeof(BufferUsage));
- BufferUsageAccumDiff(result, &pgBufferUsage, &save_pgBufferUsage);
+ if (bufusage)
+ {
+ memset(bufusage, 0, sizeof(BufferUsage));
+ BufferUsageAccumDiff(bufusage, &pgBufferUsage, &save_pgBufferUsage);
+ }
+ memset(walusage, 0, sizeof(WalUsage));
+ WalUsageAccumDiff(walusage, &pgWalUsage, &save_pgWalUsage);
}
/* accumulate work done by workers in leader's stats */
void
-InstrAccumParallelQuery(BufferUsage *result)
+InstrAccumParallelQuery(BufferUsage *bufusage, WalUsage *walusage)
{
- BufferUsageAdd(&pgBufferUsage, result);
+ if (bufusage)
+ BufferUsageAdd(&pgBufferUsage, bufusage);
+ WalUsageAdd(&pgWalUsage, walusage);
}
/* dst += add */
@@ -221,3 +245,20 @@ BufferUsageAccumDiff(BufferUsage *dst,
INSTR_TIME_ACCUM_DIFF(dst->blk_write_time,
add->blk_write_time, sub->blk_write_time);
}
+
+/* helper functions for WAL usage accumulation */
+static void
+WalUsageAdd(WalUsage *dst, WalUsage *add)
+{
+ dst->wal_bytes += add->wal_bytes;
+ dst->wal_records += add->wal_records;
+ dst->wal_num_fpw += add->wal_num_fpw;
+}
+
+void
+WalUsageAccumDiff(WalUsage *dst, const WalUsage *add, const WalUsage *sub)
+{
+ dst->wal_bytes += add->wal_bytes - sub->wal_bytes;
+ dst->wal_records += add->wal_records - sub->wal_records;
+ dst->wal_num_fpw += add->wal_num_fpw - sub->wal_num_fpw;
+}
diff --git a/src/include/access/xlog.h b/src/include/access/xlog.h
index 9ec7b31cce..b91e724b2d 100644
--- a/src/include/access/xlog.h
+++ b/src/include/access/xlog.h
@@ -259,7 +259,8 @@ struct XLogRecData;
extern XLogRecPtr XLogInsertRecord(struct XLogRecData *rdata,
XLogRecPtr fpw_lsn,
- uint8 flags);
+ uint8 flags,
+ int num_fpw);
extern void XLogFlush(XLogRecPtr RecPtr);
extern bool XLogBackgroundFlush(void);
extern bool XLogNeedsFlush(XLogRecPtr RecPtr);
diff --git a/src/include/executor/execParallel.h b/src/include/executor/execParallel.h
index 17d07cf020..1cc5b524fd 100644
--- a/src/include/executor/execParallel.h
+++ b/src/include/executor/execParallel.h
@@ -26,6 +26,7 @@ typedef struct ParallelExecutorInfo
PlanState *planstate; /* plan subtree we're running in parallel */
ParallelContext *pcxt; /* parallel context we're using */
BufferUsage *buffer_usage; /* points to bufusage area in DSM */
+ WalUsage *wal_usage; /* walusage area in DSM */
SharedExecutorInstrumentation *instrumentation; /* optional */
struct SharedJitInstrumentation *jit_instrumentation; /* optional */
dsa_area *area; /* points to DSA area in DSM */
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index 3825a5ac1f..f2bf37ae82 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -32,12 +32,20 @@ typedef struct BufferUsage
instr_time blk_write_time; /* time spent writing */
} BufferUsage;
+typedef struct WalUsage
+{
+ long wal_records; /* # of WAL records produced */
+ long wal_num_fpw; /* # of WAL full page image records produced */
+ uint64 wal_bytes; /* size of WAL records produced */
+} WalUsage;
+
/* Flag bits included in InstrAlloc's instrument_options bitmask */
typedef enum InstrumentOption
{
INSTRUMENT_TIMER = 1 << 0, /* needs timer (and row counts) */
INSTRUMENT_BUFFERS = 1 << 1, /* needs buffer usage */
INSTRUMENT_ROWS = 1 << 2, /* needs row count */
+ INSTRUMENT_WAL = 1 << 3, /* needs WAL usage */
INSTRUMENT_ALL = PG_INT32_MAX
} InstrumentOption;
@@ -46,6 +54,7 @@ typedef struct Instrumentation
/* Parameters set at node creation: */
bool need_timer; /* true if we need timer data */
bool need_bufusage; /* true if we need buffer usage data */
+ bool need_walusage; /* true if we need WAL usage data */
/* Info about current plan cycle: */
bool running; /* true if we've completed first tuple */
instr_time starttime; /* start time of current iteration of node */
@@ -53,6 +62,7 @@ typedef struct Instrumentation
double firsttuple; /* time for first tuple of this cycle */
double tuplecount; /* # of tuples emitted so far this cycle */
BufferUsage bufusage_start; /* buffer usage at start */
+ WalUsage walusage_start; /* WAL usage at start */
/* Accumulated statistics across all completed cycles: */
double startup; /* total startup time (in seconds) */
double total; /* total time (in seconds) */
@@ -62,6 +72,7 @@ typedef struct Instrumentation
double nfiltered1; /* # of tuples removed by scanqual or joinqual */
double nfiltered2; /* # of tuples removed by "other" quals */
BufferUsage bufusage; /* total buffer usage */
+ WalUsage walusage; /* total WAL usage */
} Instrumentation;
typedef struct WorkerInstrumentation
@@ -71,6 +82,7 @@ typedef struct WorkerInstrumentation
} WorkerInstrumentation;
extern PGDLLIMPORT BufferUsage pgBufferUsage;
+extern PGDLLIMPORT WalUsage pgWalUsage;
extern Instrumentation *InstrAlloc(int n, int instrument_options);
extern void InstrInit(Instrumentation *instr, int instrument_options);
@@ -79,9 +91,11 @@ extern void InstrStopNode(Instrumentation *instr, double nTuples);
extern void InstrEndLoop(Instrumentation *instr);
extern void InstrAggNode(Instrumentation *dst, Instrumentation *add);
extern void InstrStartParallelQuery(void);
-extern void InstrEndParallelQuery(BufferUsage *result);
-extern void InstrAccumParallelQuery(BufferUsage *result);
+extern void InstrEndParallelQuery(BufferUsage *bufusage, WalUsage *walusage);
+extern void InstrAccumParallelQuery(BufferUsage *bufusage, WalUsage *walusage);
extern void BufferUsageAccumDiff(BufferUsage *dst,
const BufferUsage *add, const BufferUsage *sub);
+extern void WalUsageAccumDiff(WalUsage *dst, const WalUsage *add,
+ const WalUsage *sub);
#endif /* INSTRUMENT_H */
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index 939de985d3..34623523a7 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -2643,6 +2643,7 @@ WalSndCtlData
WalSndSendDataCallback
WalSndState
WalTimeSample
+WalUsage
WalWriteMethod
Walfile
WindowAgg
--
2.20.1
From e0cb25e07c59b4e3947ed781e8794bdd59a30903 Mon Sep 17 00:00:00 2001
From: Julien Rouhaud <julien.rouhaud@free.fr>
Date: Sun, 29 Mar 2020 12:38:14 +0200
Subject: [PATCH v13 2/4] Add option to report WAL usage in EXPLAIN and
auto_explain.
Author: Julien Rouhaud
Reviewed-by:
Discussion: https://postgr.es/m/CAB-hujrP8ZfUkvL5OYETipQwA=e3n7oqHFU=4ZLxWS_Cza3kQQ@mail.gmail.com
---
contrib/auto_explain/auto_explain.c | 15 ++++++
doc/src/sgml/auto-explain.sgml | 20 ++++++++
doc/src/sgml/ref/explain.sgml | 14 ++++++
src/backend/commands/explain.c | 74 +++++++++++++++++++++++++++--
src/bin/psql/tab-complete.c | 4 +-
src/include/commands/explain.h | 3 ++
6 files changed, 124 insertions(+), 6 deletions(-)
diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c
index f69dde876c..56c549d84c 100644
--- a/contrib/auto_explain/auto_explain.c
+++ b/contrib/auto_explain/auto_explain.c
@@ -27,6 +27,7 @@ static int auto_explain_log_min_duration = -1; /* msec or -1 */
static bool auto_explain_log_analyze = false;
static bool auto_explain_log_verbose = false;
static bool auto_explain_log_buffers = false;
+static bool auto_explain_log_wal = false;
static bool auto_explain_log_triggers = false;
static bool auto_explain_log_timing = true;
static bool auto_explain_log_settings = false;
@@ -148,6 +149,17 @@ _PG_init(void)
NULL,
NULL);
+ DefineCustomBoolVariable("auto_explain.log_wal",
+ "Log WAL usage.",
+ NULL,
+ &auto_explain_log_wal,
+ false,
+ PGC_SUSET,
+ 0,
+ NULL,
+ NULL,
+ NULL);
+
DefineCustomBoolVariable("auto_explain.log_triggers",
"Include trigger statistics in plans.",
"This has no effect unless log_analyze is also set.",
@@ -280,6 +292,8 @@ explain_ExecutorStart(QueryDesc *queryDesc, int eflags)
queryDesc->instrument_options |= INSTRUMENT_ROWS;
if (auto_explain_log_buffers)
queryDesc->instrument_options |= INSTRUMENT_BUFFERS;
+ if (auto_explain_log_wal)
+ queryDesc->instrument_options |= INSTRUMENT_WAL;
}
}
@@ -374,6 +388,7 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
es->analyze = (queryDesc->instrument_options && auto_explain_log_analyze);
es->verbose = auto_explain_log_verbose;
es->buffers = (es->analyze && auto_explain_log_buffers);
+ es->wal = (es->analyze && auto_explain_log_wal);
es->timing = (es->analyze && auto_explain_log_timing);
es->summary = es->analyze;
es->format = auto_explain_log_format;
diff --git a/doc/src/sgml/auto-explain.sgml b/doc/src/sgml/auto-explain.sgml
index 3d619d4a3d..d4d29c4a64 100644
--- a/doc/src/sgml/auto-explain.sgml
+++ b/doc/src/sgml/auto-explain.sgml
@@ -109,6 +109,26 @@ LOAD 'auto_explain';
</listitem>
</varlistentry>
+ <varlistentry>
+ <term>
+ <varname>auto_explain.log_wal</varname> (<type>boolean</type>)
+ <indexterm>
+ <primary><varname>auto_explain.log_wal</varname> configuration parameter</primary>
+ </indexterm>
+ </term>
+ <listitem>
+ <para>
+ <varname>auto_explain.log_wal</varname> controls whether WAL
+ usage statistics are printed when an execution plan is logged; it's
+ equivalent to the <literal>WAL</literal> option of <command>EXPLAIN</command>.
+ This parameter has no effect
+ unless <varname>auto_explain.log_analyze</varname> is enabled.
+ This parameter is off by default.
+ Only superusers can change this setting.
+ </para>
+ </listitem>
+ </varlistentry>
+
<varlistentry>
<term>
<varname>auto_explain.log_timing</varname> (<type>boolean</type>)
diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml
index 385d10411f..024ede4a8d 100644
--- a/doc/src/sgml/ref/explain.sgml
+++ b/doc/src/sgml/ref/explain.sgml
@@ -41,6 +41,7 @@ EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replac
COSTS [ <replaceable class="parameter">boolean</replaceable> ]
SETTINGS [ <replaceable class="parameter">boolean</replaceable> ]
BUFFERS [ <replaceable class="parameter">boolean</replaceable> ]
+ WAL [ <replaceable class="parameter">boolean</replaceable> ]
TIMING [ <replaceable class="parameter">boolean</replaceable> ]
SUMMARY [ <replaceable class="parameter">boolean</replaceable> ]
FORMAT { TEXT | XML | JSON | YAML }
@@ -192,6 +193,19 @@ ROLLBACK;
</listitem>
</varlistentry>
+ <varlistentry>
+ <term><literal>WAL</literal></term>
+ <listitem>
+ <para>
+ Include information on WAL record generation. Specifically, include the
+ number of records, number of full page image records and amount of WAL
+ bytes generated. In text format, only non-zero values are printed. This
+ parameter may only be used when <literal>ANALYZE</literal> is also
+ enabled. It defaults to <literal>FALSE</literal>.
+ </para>
+ </listitem>
+ </varlistentry>
+
<varlistentry>
<term><literal>TIMING</literal></term>
<listitem>
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index ee0e638f33..cefe2144e5 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -113,6 +113,7 @@ static void show_foreignscan_info(ForeignScanState *fsstate, ExplainState *es);
static void show_eval_params(Bitmapset *bms_params, ExplainState *es);
static const char *explain_get_index_name(Oid indexId);
static void show_buffer_usage(ExplainState *es, const BufferUsage *usage);
+static void show_wal_usage(ExplainState *es, const WalUsage *usage);
static void ExplainIndexScanDetails(Oid indexid, ScanDirection indexorderdir,
ExplainState *es);
static void ExplainScanTarget(Scan *plan, ExplainState *es);
@@ -175,6 +176,8 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt,
es->costs = defGetBoolean(opt);
else if (strcmp(opt->defname, "buffers") == 0)
es->buffers = defGetBoolean(opt);
+ else if (strcmp(opt->defname, "wal") == 0)
+ es->wal = defGetBoolean(opt);
else if (strcmp(opt->defname, "settings") == 0)
es->settings = defGetBoolean(opt);
else if (strcmp(opt->defname, "timing") == 0)
@@ -219,6 +222,11 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt,
(errcode(ERRCODE_INVALID_PARAMETER_VALUE),
errmsg("EXPLAIN option BUFFERS requires ANALYZE")));
+ if (es->wal && !es->analyze)
+ ereport(ERROR,
+ (errcode(ERRCODE_INVALID_PARAMETER_VALUE),
+ errmsg("EXPLAIN option WAL requires ANALYZE")));
+
/* if the timing was not set explicitly, set default value */
es->timing = (timing_set) ? es->timing : es->analyze;
@@ -494,6 +502,8 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
if (es->buffers)
instrument_option |= INSTRUMENT_BUFFERS;
+ if (es->wal)
+ instrument_option |= INSTRUMENT_WAL;
/*
* We always collect timing for the entire statement, even when node-level
@@ -1942,12 +1952,14 @@ ExplainNode(PlanState *planstate, List *ancestors,
}
}
- /* Show buffer usage */
+ /* Show buffer/WAL usage */
if (es->buffers && planstate->instrument)
show_buffer_usage(es, &planstate->instrument->bufusage);
+ if (es->wal && planstate->instrument)
+ show_wal_usage(es, &planstate->instrument->walusage);
- /* Prepare per-worker buffer usage */
- if (es->workers_state && es->buffers && es->verbose)
+ /* Prepare per-worker buffer/WAL usage */
+ if (es->workers_state && (es->buffers || es->wal) && es->verbose)
{
WorkerInstrumentation *w = planstate->worker_instrument;
@@ -1960,7 +1972,10 @@ ExplainNode(PlanState *planstate, List *ancestors,
continue;
ExplainOpenWorker(n, es);
- show_buffer_usage(es, &instrument->bufusage);
+ if (es->buffers)
+ show_buffer_usage(es, &instrument->bufusage);
+ if (es->wal)
+ show_wal_usage(es, &instrument->walusage);
ExplainCloseWorker(n, es);
}
}
@@ -3059,6 +3074,44 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
}
}
+/*
+ * Show WAL usage details.
+ */
+static void
+show_wal_usage(ExplainState *es, const WalUsage *usage)
+{
+ if (es->format == EXPLAIN_FORMAT_TEXT)
+ {
+ /* Show only positive counter values. */
+ if ((usage->wal_records > 0) || (usage->wal_num_fpw > 0) ||
+ (usage->wal_bytes > 0))
+ {
+ ExplainIndentText(es);
+ appendStringInfoString(es->str, "WAL:");
+
+ if (usage->wal_records > 0)
+ appendStringInfo(es->str, " records=%ld",
+ usage->wal_records);
+ if (usage->wal_num_fpw > 0)
+ appendStringInfo(es->str, " full page writes=%ld",
+ usage->wal_num_fpw);
+ if (usage->wal_bytes > 0)
+ appendStringInfo(es->str, " bytes=" UINT64_FORMAT,
+ usage->wal_bytes);
+ appendStringInfoChar(es->str, '\n');
+ }
+ }
+ else
+ {
+ ExplainPropertyInteger("WAL records", NULL,
+ usage->wal_records, es);
+ ExplainPropertyInteger("WAL full page writes", NULL,
+ usage->wal_num_fpw, es);
+ ExplainPropertyUInteger("WAL bytes", NULL,
+ usage->wal_bytes, es);
+ }
+}
+
/*
* Add some additional details about an IndexScan or IndexOnlyScan
*/
@@ -3843,6 +3896,19 @@ ExplainPropertyInteger(const char *qlabel, const char *unit, int64 value,
ExplainProperty(qlabel, unit, buf, true, es);
}
+/*
+ * Explain an unsigned integer-valued property.
+ */
+void
+ExplainPropertyUInteger(const char *qlabel, const char *unit, uint64 value,
+ ExplainState *es)
+{
+ char buf[32];
+
+ snprintf(buf, sizeof(buf), UINT64_FORMAT, value);
+ ExplainProperty(qlabel, unit, buf, true, es);
+}
+
/*
* Explain a float-valued property, using the specified number of
* fractional digits.
diff --git a/src/bin/psql/tab-complete.c b/src/bin/psql/tab-complete.c
index 5fec59723c..0e7a373caf 100644
--- a/src/bin/psql/tab-complete.c
+++ b/src/bin/psql/tab-complete.c
@@ -3045,8 +3045,8 @@ psql_completion(const char *text, int start, int end)
*/
if (ends_with(prev_wd, '(') || ends_with(prev_wd, ','))
COMPLETE_WITH("ANALYZE", "VERBOSE", "COSTS", "SETTINGS",
- "BUFFERS", "TIMING", "SUMMARY", "FORMAT");
- else if (TailMatches("ANALYZE|VERBOSE|COSTS|SETTINGS|BUFFERS|TIMING|SUMMARY"))
+ "BUFFERS", "WAL", "TIMING", "SUMMARY", "FORMAT");
+ else if (TailMatches("ANALYZE|VERBOSE|COSTS|SETTINGS|BUFFERS|WAL|TIMING|SUMMARY"))
COMPLETE_WITH("ON", "OFF");
else if (TailMatches("FORMAT"))
COMPLETE_WITH("TEXT", "XML", "JSON", "YAML");
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index 54f6240e5e..7b0b0a94a6 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -42,6 +42,7 @@ typedef struct ExplainState
bool analyze; /* print actual times */
bool costs; /* print estimated costs */
bool buffers; /* print buffer usage */
+ bool wal; /* print WAL usage */
bool timing; /* print detailed node timing */
bool summary; /* print total planning and execution timing */
bool settings; /* print modified settings */
@@ -110,6 +111,8 @@ extern void ExplainPropertyText(const char *qlabel, const char *value,
ExplainState *es);
extern void ExplainPropertyInteger(const char *qlabel, const char *unit,
int64 value, ExplainState *es);
+extern void ExplainPropertyUInteger(const char *qlabel, const char *unit,
+ uint64 value, ExplainState *es);
extern void ExplainPropertyFloat(const char *qlabel, const char *unit,
double value, int ndigits, ExplainState *es);
extern void ExplainPropertyBool(const char *qlabel, bool value,
--
2.20.1
From 9cf6ff14f3e34b0cf8f95016ef4a2853e792eab9 Mon Sep 17 00:00:00 2001
From: Kirill Bychik <kirill.bychik@gmail.com>
Date: Tue, 17 Mar 2020 14:42:02 +0100
Subject: [PATCH v13 3/4] Keep track of WAL usage in pg_stat_statements.
Author: Kirill Bychik
Reviewed-by: Julien Rouhaud, Fuji Masao
Discussion: https://postgr.es/m/CAB-hujrP8ZfUkvL5OYETipQwA=e3n7oqHFU=4ZLxWS_Cza3kQQ@mail.gmail.com
---
.../expected/pg_stat_statements.out | 39 +++++++++++++
.../pg_stat_statements--1.7--1.8.sql | 5 +-
.../pg_stat_statements/pg_stat_statements.c | 55 +++++++++++++++++--
.../sql/pg_stat_statements.sql | 23 ++++++++
doc/src/sgml/pgstatstatements.sgml | 27 +++++++++
5 files changed, 144 insertions(+), 5 deletions(-)
diff --git a/contrib/pg_stat_statements/expected/pg_stat_statements.out b/contrib/pg_stat_statements/expected/pg_stat_statements.out
index 45dbe9e677..f615f8c2bf 100644
--- a/contrib/pg_stat_statements/expected/pg_stat_statements.out
+++ b/contrib/pg_stat_statements/expected/pg_stat_statements.out
@@ -211,6 +211,45 @@ SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C";
UPDATE test SET b = $1 WHERE a > $2 | 1 | 3
(10 rows)
+--
+-- INSERT, UPDATE, DELETE on test table to validate WAL generation metrics
+--
+SELECT pg_stat_statements_reset();
+ pg_stat_statements_reset
+--------------------------
+
+(1 row)
+
+-- utility "create table" should not be shown
+CREATE TABLE pgss_test (a int, b char(20));
+INSERT INTO pgss_test VALUES(generate_series(1, 10), 'aaa');
+UPDATE pgss_test SET b = 'bbb' WHERE a > 7;
+DELETE FROM pgss_test WHERE a > 9;
+-- DROP test table
+SET pg_stat_statements.track_utility = TRUE;
+DROP TABLE pgss_test;
+SET pg_stat_statements.track_utility = FALSE;
+-- Check WAL is generated for the above statements
+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 VALUES(generate_series($1, $2), $3) | 1 | 10 | t | t | t
+ SELECT pg_stat_statements_reset() | 1 | 1 | f | f | f
+ SELECT query, calls, rows, +| 0 | 0 | f | f | t
+ wal_bytes > $1 as wal_bytes_generated, +| | | | |
+ wal_records > $2 as wal_records_generated, +| | | | |
+ wal_records = rows as wal_records_as_rows +| | | | |
+ FROM pg_stat_statements ORDER BY query COLLATE "C" | | | | |
+ SET pg_stat_statements.track_utility = FALSE | 1 | 0 | f | f | t
+ UPDATE pgss_test SET b = $1 WHERE a > $2 | 1 | 3 | t | t | t
+(7 rows)
+
--
-- pg_stat_statements.track = none
--
diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql b/contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql
index 60d454db7f..30566574ab 100644
--- a/contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql
+++ b/contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql
@@ -41,7 +41,10 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean,
OUT temp_blks_read int8,
OUT temp_blks_written int8,
OUT blk_read_time float8,
- OUT blk_write_time float8
+ OUT blk_write_time float8,
+ OUT wal_records int8,
+ OUT wal_num_fpw int8,
+ OUT wal_bytes numeric
)
RETURNS SETOF record
AS 'MODULE_PATHNAME', 'pg_stat_statements_1_8'
diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c
index 942922b01f..c42bf62fce 100644
--- a/contrib/pg_stat_statements/pg_stat_statements.c
+++ b/contrib/pg_stat_statements/pg_stat_statements.c
@@ -188,6 +188,9 @@ typedef struct Counters
double blk_read_time; /* time spent reading, in msec */
double blk_write_time; /* time spent writing, in msec */
double usage; /* usage factor */
+ int64 wal_records; /* # of WAL records generated */
+ int64 wal_num_fpw; /* # of WAL full page image records generated */
+ uint64 wal_bytes; /* total amount of WAL bytes generated */
} Counters;
/*
@@ -348,6 +351,7 @@ static void pgss_store(const char *query, uint64 queryId,
pgssStoreKind kind,
double total_time, uint64 rows,
const BufferUsage *bufusage,
+ const WalUsage *walusage,
pgssJumbleState *jstate);
static void pg_stat_statements_internal(FunctionCallInfo fcinfo,
pgssVersion api_version,
@@ -891,6 +895,7 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query)
0,
0,
NULL,
+ NULL,
&jstate);
}
@@ -926,9 +931,16 @@ pgss_planner(Query *parse,
instr_time duration;
BufferUsage bufusage_start,
bufusage;
+ WalUsage walusage_start,
+ walusage;
/* We need to track buffer usage as the planner can access them. */
bufusage_start = pgBufferUsage;
+ /*
+ * Similarly the planner could write some WAL records in some cases
+ * (e.g. setting a hint bit with those being WAL-logged)
+ */
+ walusage_start = pgWalUsage;
INSTR_TIME_SET_CURRENT(start);
plan_nested_level++;
@@ -954,6 +966,10 @@ pgss_planner(Query *parse,
memset(&bufusage, 0, sizeof(BufferUsage));
BufferUsageAccumDiff(&bufusage, &pgBufferUsage, &bufusage_start);
+ /* calc differences of WAL counters. */
+ memset(&walusage, 0, sizeof(WalUsage));
+ WalUsageAccumDiff(&walusage, &pgWalUsage, &walusage_start);
+
pgss_store(query_string,
parse->queryId,
parse->stmt_location,
@@ -962,6 +978,7 @@ pgss_planner(Query *parse,
INSTR_TIME_GET_MILLISEC(duration),
0,
&bufusage,
+ &walusage,
NULL);
}
else
@@ -1079,6 +1096,7 @@ pgss_ExecutorEnd(QueryDesc *queryDesc)
queryDesc->totaltime->total * 1000.0, /* convert to msec */
queryDesc->estate->es_processed,
&queryDesc->totaltime->bufusage,
+ &queryDesc->totaltime->walusage,
NULL);
}
@@ -1123,8 +1141,10 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
uint64 rows;
BufferUsage bufusage_start,
bufusage;
-
+ WalUsage walusage_start,
+ walusage;
bufusage_start = pgBufferUsage;
+ walusage_start = pgWalUsage;
INSTR_TIME_SET_CURRENT(start);
exec_nested_level++;
@@ -1154,6 +1174,10 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
memset(&bufusage, 0, sizeof(BufferUsage));
BufferUsageAccumDiff(&bufusage, &pgBufferUsage, &bufusage_start);
+ /* calc differences of WAL counters. */
+ memset(&walusage, 0, sizeof(WalUsage));
+ WalUsageAccumDiff(&walusage, &pgWalUsage, &walusage_start);
+
pgss_store(queryString,
0, /* signal that it's a utility stmt */
pstmt->stmt_location,
@@ -1162,6 +1186,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
INSTR_TIME_GET_MILLISEC(duration),
rows,
&bufusage,
+ &walusage,
NULL);
}
else
@@ -1197,7 +1222,8 @@ pgss_hash_string(const char *str, int len)
*
* If jstate is not NULL then we're trying to create an entry for which
* we have no statistics as yet; we just want to record the normalized
- * query string. total_time, rows, bufusage are ignored in this case.
+ * query string. total_time, rows, bufusage and walusage are ignored in this
+ * case.
*
* If kind is PGSS_PLAN or PGSS_EXEC, its value is used as the array position
* for the arrays in the Counters field.
@@ -1208,6 +1234,7 @@ pgss_store(const char *query, uint64 queryId,
pgssStoreKind kind,
double total_time, uint64 rows,
const BufferUsage *bufusage,
+ const WalUsage *walusage,
pgssJumbleState *jstate)
{
pgssHashKey key;
@@ -1402,6 +1429,9 @@ pgss_store(const char *query, uint64 queryId,
e->counters.blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->blk_read_time);
e->counters.blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->blk_write_time);
e->counters.usage += USAGE_EXEC(total_time);
+ e->counters.wal_records += walusage->wal_records;
+ e->counters.wal_num_fpw += walusage->wal_num_fpw;
+ e->counters.wal_bytes += walusage->wal_bytes;
SpinLockRelease(&e->mutex);
}
@@ -1449,8 +1479,8 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS)
#define PG_STAT_STATEMENTS_COLS_V1_1 18
#define PG_STAT_STATEMENTS_COLS_V1_2 19
#define PG_STAT_STATEMENTS_COLS_V1_3 23
-#define PG_STAT_STATEMENTS_COLS_V1_8 29
-#define PG_STAT_STATEMENTS_COLS 29 /* maximum of above */
+#define PG_STAT_STATEMENTS_COLS_V1_8 32
+#define PG_STAT_STATEMENTS_COLS 32 /* maximum of above */
/*
* Retrieve statement statistics.
@@ -1786,6 +1816,23 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
values[i++] = Float8GetDatumFast(tmp.blk_read_time);
values[i++] = Float8GetDatumFast(tmp.blk_write_time);
}
+ if (api_version >= PGSS_V1_8)
+ {
+ char buf[256];
+ Datum wal_bytes;
+
+ values[i++] = Int64GetDatumFast(tmp.wal_records);
+ values[i++] = Int64GetDatumFast(tmp.wal_num_fpw);
+
+ 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;
+ }
Assert(i == (api_version == PGSS_V1_0 ? PG_STAT_STATEMENTS_COLS_V1_0 :
api_version == PGSS_V1_1 ? PG_STAT_STATEMENTS_COLS_V1_1 :
diff --git a/contrib/pg_stat_statements/sql/pg_stat_statements.sql b/contrib/pg_stat_statements/sql/pg_stat_statements.sql
index 435d51008f..75c10554a8 100644
--- a/contrib/pg_stat_statements/sql/pg_stat_statements.sql
+++ b/contrib/pg_stat_statements/sql/pg_stat_statements.sql
@@ -101,6 +101,29 @@ SELECT * FROM test WHERE a IN (1, 2, 3, 4, 5);
SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C";
+--
+-- INSERT, UPDATE, DELETE on test table to validate WAL generation metrics
+--
+SELECT pg_stat_statements_reset();
+
+-- utility "create table" should not be shown
+CREATE TABLE pgss_test (a int, b char(20));
+
+INSERT INTO pgss_test VALUES(generate_series(1, 10), 'aaa');
+UPDATE pgss_test SET b = 'bbb' WHERE a > 7;
+DELETE FROM pgss_test WHERE a > 9;
+-- DROP test table
+SET pg_stat_statements.track_utility = TRUE;
+DROP TABLE pgss_test;
+SET pg_stat_statements.track_utility = FALSE;
+
+-- Check WAL is generated for the above statements
+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";
+
--
-- pg_stat_statements.track = none
--
diff --git a/doc/src/sgml/pgstatstatements.sgml b/doc/src/sgml/pgstatstatements.sgml
index b4df84c60b..3d26108649 100644
--- a/doc/src/sgml/pgstatstatements.sgml
+++ b/doc/src/sgml/pgstatstatements.sgml
@@ -264,6 +264,33 @@
</entry>
</row>
+ <row>
+ <entry><structfield>wal_bytes</structfield></entry>
+ <entry><type>numeric</type></entry>
+ <entry></entry>
+ <entry>
+ Total amount of WAL bytes generated by the statement
+ </entry>
+ </row>
+
+ <row>
+ <entry><structfield>wal_records</structfield></entry>
+ <entry><type>bigint</type></entry>
+ <entry></entry>
+ <entry>
+ Total count of WAL records generated by the statement
+ </entry>
+ </row>
+
+ <row>
+ <entry><structfield>wal_num_fpw</structfield></entry>
+ <entry><type>bigint</type></entry>
+ <entry></entry>
+ <entry>
+ Total count of WAL full page writes generated by the statement
+ </entry>
+ </row>
+
</tbody>
</tgroup>
</table>
--
2.20.1
From fc00f3bc115502395d5b10862be013970b3f29c8 Mon Sep 17 00:00:00 2001
From: Julien Rouhaud <julien.rouhaud@free.fr>
Date: Thu, 19 Mar 2020 16:08:47 +0100
Subject: [PATCH v13 4/4] Expose WAL usage counters in verbose (auto)vacuum
output.
Author: Julien Rouhaud
Reviewed-by: Fuji Masao
Discussion: https://postgr.es/m/CAB-hujrP8ZfUkvL5OYETipQwA=e3n7oqHFU=4ZLxWS_Cza3kQQ@mail.gmail.com
---
src/backend/access/heap/vacuumlazy.c | 24 +++++++++++++++++++++++-
1 file changed, 23 insertions(+), 1 deletion(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index cc7e8521a5..735087dd74 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -410,6 +410,8 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params,
int nindexes;
PGRUsage ru0;
TimestampTz starttime = 0;
+ WalUsage walusage_start = pgWalUsage;
+ WalUsage walusage = {0, 0, 0};
long secs;
int usecs;
double read_rate,
@@ -614,6 +616,9 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params,
TimestampDifference(starttime, endtime, &secs, &usecs);
+ memset(&walusage, 0, sizeof(WalUsage));
+ WalUsageAccumDiff(&walusage, &pgWalUsage, &walusage_start);
+
read_rate = 0;
write_rate = 0;
if ((secs > 0) || (usecs > 0))
@@ -666,7 +671,13 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params,
(long long) VacuumPageDirty);
appendStringInfo(&buf, _("avg read rate: %.3f MB/s, avg write rate: %.3f MB/s\n"),
read_rate, write_rate);
- appendStringInfo(&buf, _("system usage: %s"), pg_rusage_show(&ru0));
+ appendStringInfo(&buf, _("system usage: %s\n"), pg_rusage_show(&ru0));
+ appendStringInfo(&buf,
+ _("WAL usage: %ld records, %ld full page writes, "
+ UINT64_FORMAT " bytes"),
+ walusage.wal_records,
+ walusage.wal_num_fpw,
+ walusage.wal_bytes);
ereport(LOG,
(errmsg_internal("%s", buf.data)));
@@ -758,6 +769,8 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
IndexBulkDeleteResult **indstats;
int i;
PGRUsage ru0;
+ WalUsage walusage_start = pgWalUsage;
+ WalUsage walusage = {0, 0, 0};
Buffer vmbuffer = InvalidBuffer;
BlockNumber next_unskippable_block;
bool skipping_blocks;
@@ -1727,6 +1740,15 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
"%u pages are entirely empty.\n",
empty_pages),
empty_pages);
+
+ memset(&walusage, 0, sizeof(WalUsage));
+ WalUsageAccumDiff(&walusage, &pgWalUsage, &walusage_start);
+ appendStringInfo(&buf, _("%ld WAL records, %ld WAL full page writes, "
+ UINT64_FORMAT " WAL bytes\n"),
+ walusage.wal_records,
+ walusage.wal_num_fpw,
+ walusage.wal_bytes);
+
appendStringInfo(&buf, _("%s."), pg_rusage_show(&ru0));
ereport(elevel,
--
2.20.1
Attachments:
[text/plain] v13-0001-Add-infrastructure-to-track-WAL-usage.patch (26.6K, ../20200402144438.GF64485@nol/2-v13-0001-Add-infrastructure-to-track-WAL-usage.patch)
download | inline diff:
From 1ba0a76f3e071c239dd65fe06517ead816922957 Mon Sep 17 00:00:00 2001
From: Kirill Bychik <kirill.bychik@gmail.com>
Date: Tue, 17 Mar 2020 14:41:50 +0100
Subject: [PATCH v13 1/4] Add infrastructure to track WAL usage.
Author: Kirill Bychik, Julien Rouhaud
Reviewed-by: Fuji Masao
Discussion: https://postgr.es/m/CAB-hujrP8ZfUkvL5OYETipQwA=e3n7oqHFU=4ZLxWS_Cza3kQQ@mail.gmail.com
---
src/backend/access/heap/vacuumlazy.c | 37 ++++++++++++-----
src/backend/access/nbtree/nbtsort.c | 40 +++++++++++++++++++
src/backend/access/transam/xlog.c | 12 +++++-
src/backend/access/transam/xloginsert.c | 13 ++++--
src/backend/executor/execParallel.c | 38 +++++++++++++-----
src/backend/executor/instrument.c | 53 ++++++++++++++++++++++---
src/include/access/xlog.h | 3 +-
src/include/executor/execParallel.h | 1 +
src/include/executor/instrument.h | 18 ++++++++-
src/tools/pgindent/typedefs.list | 1 +
10 files changed, 183 insertions(+), 33 deletions(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 9f9596c718..cc7e8521a5 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -139,6 +139,7 @@
#define PARALLEL_VACUUM_KEY_DEAD_TUPLES 2
#define PARALLEL_VACUUM_KEY_QUERY_TEXT 3
#define PARALLEL_VACUUM_KEY_BUFFER_USAGE 4
+#define PARALLEL_VACUUM_KEY_WAL_USAGE 5
/*
* Macro to check if we are in a parallel vacuum. If true, we are in the
@@ -275,6 +276,9 @@ typedef struct LVParallelState
/* Points to buffer usage area in DSM */
BufferUsage *buffer_usage;
+ /* Points to WAL usage area in DSM */
+ WalUsage *wal_usage;
+
/*
* The number of indexes that support parallel index bulk-deletion and
* parallel index cleanup respectively.
@@ -2143,8 +2147,8 @@ lazy_parallel_vacuum_indexes(Relation *Irel, IndexBulkDeleteResult **stats,
vacrelstats->dead_tuples, nindexes, vacrelstats);
/*
- * Next, accumulate buffer usage. (This must wait for the workers to
- * finish, or we might get incomplete data.)
+ * Next, accumulate buffer and WAL usage. (This must wait for the workers
+ * to finish, or we might get incomplete data.)
*/
if (nworkers > 0)
{
@@ -2154,7 +2158,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]);
}
/*
@@ -3171,6 +3175,7 @@ begin_parallel_vacuum(Oid relid, Relation *Irel, LVRelStats *vacrelstats,
LVShared *shared;
LVDeadTuples *dead_tuples;
BufferUsage *buffer_usage;
+ WalUsage *wal_usage;
bool *can_parallel_vacuum;
long maxtuples;
char *sharedquery;
@@ -3255,15 +3260,19 @@ begin_parallel_vacuum(Oid relid, Relation *Irel, LVRelStats *vacrelstats,
shm_toc_estimate_keys(&pcxt->estimator, 1);
/*
- * Estimate space for BufferUsage -- PARALLEL_VACUUM_KEY_BUFFER_USAGE.
+ * Estimate space for BufferUsage and WalUsage --
+ * PARALLEL_VACUUM_KEY_BUFFER_USAGE and PARALLEL_VACUUM_KEY_WAL_USAGE.
*
* If there are no extensions loaded that care, we could skip this. We
- * have no way of knowing whether anyone's looking at pgBufferUsage, so do
- * it unconditionally.
+ * have no way of knowing whether anyone's looking at pgBufferUsage or
+ * pgWalUsage, so do it unconditionally.
*/
shm_toc_estimate_chunk(&pcxt->estimator,
mul_size(sizeof(BufferUsage), pcxt->nworkers));
shm_toc_estimate_keys(&pcxt->estimator, 1);
+ shm_toc_estimate_chunk(&pcxt->estimator,
+ mul_size(sizeof(WalUsage), pcxt->nworkers));
+ shm_toc_estimate_keys(&pcxt->estimator, 1);
/* Finally, estimate PARALLEL_VACUUM_KEY_QUERY_TEXT space */
querylen = strlen(debug_query_string);
@@ -3299,11 +3308,18 @@ begin_parallel_vacuum(Oid relid, Relation *Irel, LVRelStats *vacrelstats,
shm_toc_insert(pcxt->toc, PARALLEL_VACUUM_KEY_DEAD_TUPLES, dead_tuples);
vacrelstats->dead_tuples = dead_tuples;
- /* Allocate space for each worker's BufferUsage; no need to initialize */
+ /*
+ * Allocate space for each worker's BufferUsage and WalUsage; no need to
+ * initialize
+ */
buffer_usage = shm_toc_allocate(pcxt->toc,
mul_size(sizeof(BufferUsage), pcxt->nworkers));
shm_toc_insert(pcxt->toc, PARALLEL_VACUUM_KEY_BUFFER_USAGE, buffer_usage);
lps->buffer_usage = buffer_usage;
+ wal_usage = shm_toc_allocate(pcxt->toc,
+ mul_size(sizeof(WalUsage), pcxt->nworkers));
+ shm_toc_insert(pcxt->toc, PARALLEL_VACUUM_KEY_WAL_USAGE, wal_usage);
+ lps->wal_usage = wal_usage;
/* Store query string for workers */
sharedquery = (char *) shm_toc_allocate(pcxt->toc, querylen + 1);
@@ -3435,6 +3451,7 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc)
LVShared *lvshared;
LVDeadTuples *dead_tuples;
BufferUsage *buffer_usage;
+ WalUsage *wal_usage;
int nindexes;
char *sharedquery;
IndexBulkDeleteResult **stats;
@@ -3511,9 +3528,11 @@ parallel_vacuum_main(dsm_segment *seg, shm_toc *toc)
parallel_vacuum_index(indrels, stats, lvshared, dead_tuples, nindexes,
&vacrelstats);
- /* Report buffer usage during parallel execution */
+ /* Report buffer/WAL usage during parallel execution */
buffer_usage = shm_toc_lookup(toc, PARALLEL_VACUUM_KEY_BUFFER_USAGE, false);
- InstrEndParallelQuery(&buffer_usage[ParallelWorkerNumber]);
+ wal_usage = shm_toc_lookup(toc, PARALLEL_VACUUM_KEY_WAL_USAGE, false);
+ InstrEndParallelQuery(&buffer_usage[ParallelWorkerNumber],
+ &wal_usage[ParallelWorkerNumber]);
/* Pop the error context stack */
error_context_stack = errcallback.previous;
diff --git a/src/backend/access/nbtree/nbtsort.c b/src/backend/access/nbtree/nbtsort.c
index 3924945664..3f4cb7d39e 100644
--- a/src/backend/access/nbtree/nbtsort.c
+++ b/src/backend/access/nbtree/nbtsort.c
@@ -67,6 +67,7 @@
#include "access/xloginsert.h"
#include "catalog/index.h"
#include "commands/progress.h"
+#include "executor/instrument.h"
#include "miscadmin.h"
#include "pgstat.h"
#include "storage/smgr.h"
@@ -81,6 +82,7 @@
#define PARALLEL_KEY_TUPLESORT UINT64CONST(0xA000000000000002)
#define PARALLEL_KEY_TUPLESORT_SPOOL2 UINT64CONST(0xA000000000000003)
#define PARALLEL_KEY_QUERY_TEXT UINT64CONST(0xA000000000000004)
+#define PARALLEL_KEY_WAL_USAGE UINT64CONST(0xA000000000000005)
/*
* DISABLE_LEADER_PARTICIPATION disables the leader's participation in
@@ -203,6 +205,7 @@ typedef struct BTLeader
Sharedsort *sharedsort;
Sharedsort *sharedsort2;
Snapshot snapshot;
+ WalUsage *walusage;
} BTLeader;
/*
@@ -1476,6 +1479,7 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
Sharedsort *sharedsort2;
BTSpool *btspool = buildstate->spool;
BTLeader *btleader = (BTLeader *) palloc0(sizeof(BTLeader));
+ WalUsage *walusage;
bool leaderparticipates = true;
char *sharedquery;
int querylen;
@@ -1528,6 +1532,18 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
shm_toc_estimate_keys(&pcxt->estimator, 3);
}
+ /*
+ * Estimate space for WalUsage -- PARALLEL_KEY_WAL_USAGE
+ *
+ * WalUsage during execution of maintenance command can be used by an
+ * extension that reports the WAL usage, such as pg_stat_statements.
+ * We have no way of knowing whether anyone's looking at pgWalUsage,
+ * so do it unconditionally.
+ */
+ shm_toc_estimate_chunk(&pcxt->estimator,
+ mul_size(sizeof(WalUsage), pcxt->nworkers));
+ shm_toc_estimate_keys(&pcxt->estimator, 1);
+
/* Finally, estimate PARALLEL_KEY_QUERY_TEXT space */
querylen = strlen(debug_query_string);
shm_toc_estimate_chunk(&pcxt->estimator, querylen + 1);
@@ -1599,6 +1615,11 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
memcpy(sharedquery, debug_query_string, querylen + 1);
shm_toc_insert(pcxt->toc, PARALLEL_KEY_QUERY_TEXT, sharedquery);
+ /* Allocate space for each worker's WalUsage; no need to initialize */
+ walusage = shm_toc_allocate(pcxt->toc,
+ mul_size(sizeof(WalUsage), pcxt->nworkers));
+ shm_toc_insert(pcxt->toc, PARALLEL_KEY_WAL_USAGE, walusage);
+
/* Launch workers, saving status for leader/caller */
LaunchParallelWorkers(pcxt);
btleader->pcxt = pcxt;
@@ -1609,6 +1630,7 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
btleader->sharedsort = sharedsort;
btleader->sharedsort2 = sharedsort2;
btleader->snapshot = snapshot;
+ btleader->walusage = walusage;
/* If no workers were successfully launched, back out (do serial build) */
if (pcxt->nworkers_launched == 0)
@@ -1637,8 +1659,18 @@ _bt_begin_parallel(BTBuildState *buildstate, bool isconcurrent, int request)
static void
_bt_end_parallel(BTLeader *btleader)
{
+ int i;
+
/* Shutdown worker processes */
WaitForParallelWorkersToFinish(btleader->pcxt);
+
+ /*
+ * Next, accumulate WAL usage. (This must wait for the workers to
+ * finish, or we might get incomplete data.)
+ */
+ for (i = 0; i < btleader->pcxt->nworkers_launched; i++)
+ InstrAccumParallelQuery(NULL, &btleader->walusage[i]);
+
/* Free last reference to MVCC snapshot, if one was used */
if (IsMVCCSnapshot(btleader->snapshot))
UnregisterSnapshot(btleader->snapshot);
@@ -1769,6 +1801,7 @@ _bt_parallel_build_main(dsm_segment *seg, shm_toc *toc)
Relation indexRel;
LOCKMODE heapLockmode;
LOCKMODE indexLockmode;
+ WalUsage *walusage;
int sortmem;
#ifdef BTREE_BUILD_STATS
@@ -1830,11 +1863,18 @@ _bt_parallel_build_main(dsm_segment *seg, shm_toc *toc)
tuplesort_attach_shared(sharedsort2, seg);
}
+ /* Prepare to track buffer usage during parallel execution */
+ InstrStartParallelQuery();
+
/* Perform sorting of spool, and possibly a spool2 */
sortmem = maintenance_work_mem / btshared->scantuplesortstates;
_bt_parallel_scan_and_sort(btspool, btspool2, btshared, sharedsort,
sharedsort2, sortmem, false);
+ /* Report WAL usage during parallel execution */
+ walusage = shm_toc_lookup(toc, PARALLEL_KEY_WAL_USAGE, false);
+ InstrEndParallelQuery(NULL, &walusage[ParallelWorkerNumber]);
+
#ifdef BTREE_BUILD_STATS
if (log_btree_build_stats)
{
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 977d448f50..50b78f3143 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -43,6 +43,7 @@
#include "commands/progress.h"
#include "commands/tablespace.h"
#include "common/controldata_utils.h"
+#include "executor/instrument.h"
#include "miscadmin.h"
#include "pg_trace.h"
#include "pgstat.h"
@@ -996,7 +997,8 @@ static void WALInsertLockUpdateInsertingAt(XLogRecPtr insertingAt);
XLogRecPtr
XLogInsertRecord(XLogRecData *rdata,
XLogRecPtr fpw_lsn,
- uint8 flags)
+ uint8 flags,
+ int num_fpw)
{
XLogCtlInsert *Insert = &XLogCtl->Insert;
pg_crc32c rdata_crc;
@@ -1252,6 +1254,14 @@ XLogInsertRecord(XLogRecData *rdata,
ProcLastRecPtr = StartPos;
XactLastRecEnd = EndPos;
+ /* Report WAL traffic to the instrumentation. */
+ if (inserted)
+ {
+ pgWalUsage.wal_bytes += rechdr->xl_tot_len;
+ pgWalUsage.wal_records++;
+ pgWalUsage.wal_num_fpw += num_fpw;
+ }
+
return EndPos;
}
diff --git a/src/backend/access/transam/xloginsert.c b/src/backend/access/transam/xloginsert.c
index a618dec776..5e032e7042 100644
--- a/src/backend/access/transam/xloginsert.c
+++ b/src/backend/access/transam/xloginsert.c
@@ -25,6 +25,7 @@
#include "access/xloginsert.h"
#include "catalog/pg_control.h"
#include "common/pg_lzcompress.h"
+#include "executor/instrument.h"
#include "miscadmin.h"
#include "pg_trace.h"
#include "replication/origin.h"
@@ -108,7 +109,7 @@ static MemoryContext xloginsert_cxt;
static XLogRecData *XLogRecordAssemble(RmgrId rmid, uint8 info,
XLogRecPtr RedoRecPtr, bool doPageWrites,
- XLogRecPtr *fpw_lsn);
+ XLogRecPtr *fpw_lsn, int *num_fpw);
static bool XLogCompressBackupBlock(char *page, uint16 hole_offset,
uint16 hole_length, char *dest, uint16 *dlen);
@@ -448,6 +449,7 @@ XLogInsert(RmgrId rmid, uint8 info)
bool doPageWrites;
XLogRecPtr fpw_lsn;
XLogRecData *rdt;
+ int num_fpw = 0;
/*
* Get values needed to decide whether to do full-page writes. Since
@@ -457,9 +459,9 @@ XLogInsert(RmgrId rmid, uint8 info)
GetFullPageWriteInfo(&RedoRecPtr, &doPageWrites);
rdt = XLogRecordAssemble(rmid, info, RedoRecPtr, doPageWrites,
- &fpw_lsn);
+ &fpw_lsn, &num_fpw);
- EndPos = XLogInsertRecord(rdt, fpw_lsn, curinsert_flags);
+ EndPos = XLogInsertRecord(rdt, fpw_lsn, curinsert_flags, num_fpw);
} while (EndPos == InvalidXLogRecPtr);
XLogResetInsertion();
@@ -482,7 +484,7 @@ XLogInsert(RmgrId rmid, uint8 info)
static XLogRecData *
XLogRecordAssemble(RmgrId rmid, uint8 info,
XLogRecPtr RedoRecPtr, bool doPageWrites,
- XLogRecPtr *fpw_lsn)
+ XLogRecPtr *fpw_lsn, int *num_fpw)
{
XLogRecData *rdt;
uint32 total_len = 0;
@@ -635,6 +637,9 @@ XLogRecordAssemble(RmgrId rmid, uint8 info,
*/
bkpb.fork_flags |= BKPBLOCK_HAS_IMAGE;
+ /* Report a full page image constructed for the WAL record */
+ *num_fpw += 1;
+
/*
* Construct XLogRecData entries for the page content.
*/
diff --git a/src/backend/executor/execParallel.c b/src/backend/executor/execParallel.c
index a753d6efa0..7d9ca66fc8 100644
--- a/src/backend/executor/execParallel.c
+++ b/src/backend/executor/execParallel.c
@@ -12,7 +12,7 @@
* workers and ensuring that their state generally matches that of the
* leader; see src/backend/access/transam/README.parallel for details.
* However, we must save and restore relevant executor state, such as
- * any ParamListInfo associated with the query, buffer usage info, and
+ * any ParamListInfo associated with the query, buffer/WAL usage info, and
* the actual plan to be passed down to the worker.
*
* IDENTIFICATION
@@ -62,6 +62,7 @@
#define PARALLEL_KEY_DSA UINT64CONST(0xE000000000000007)
#define PARALLEL_KEY_QUERY_TEXT UINT64CONST(0xE000000000000008)
#define PARALLEL_KEY_JIT_INSTRUMENTATION UINT64CONST(0xE000000000000009)
+#define PARALLEL_KEY_WAL_USAGE UINT64CONST(0xE00000000000000A)
#define PARALLEL_TUPLE_QUEUE_SIZE 65536
@@ -573,6 +574,7 @@ ExecInitParallelPlan(PlanState *planstate, EState *estate,
char *pstmt_space;
char *paramlistinfo_space;
BufferUsage *bufusage_space;
+ WalUsage *walusage_space;
SharedExecutorInstrumentation *instrumentation = NULL;
SharedJitInstrumentation *jit_instrumentation = NULL;
int pstmt_len;
@@ -646,6 +648,13 @@ ExecInitParallelPlan(PlanState *planstate, EState *estate,
mul_size(sizeof(BufferUsage), pcxt->nworkers));
shm_toc_estimate_keys(&pcxt->estimator, 1);
+ /*
+ * Same thing for WalUsage.
+ */
+ shm_toc_estimate_chunk(&pcxt->estimator,
+ mul_size(sizeof(WalUsage), pcxt->nworkers));
+ shm_toc_estimate_keys(&pcxt->estimator, 1);
+
/* Estimate space for tuple queues. */
shm_toc_estimate_chunk(&pcxt->estimator,
mul_size(PARALLEL_TUPLE_QUEUE_SIZE, pcxt->nworkers));
@@ -728,6 +737,12 @@ ExecInitParallelPlan(PlanState *planstate, EState *estate,
shm_toc_insert(pcxt->toc, PARALLEL_KEY_BUFFER_USAGE, bufusage_space);
pei->buffer_usage = bufusage_space;
+ /* Same for WalUsage. */
+ walusage_space = shm_toc_allocate(pcxt->toc,
+ mul_size(sizeof(WalUsage), pcxt->nworkers));
+ shm_toc_insert(pcxt->toc, PARALLEL_KEY_WAL_USAGE, walusage_space);
+ pei->wal_usage = walusage_space;
+
/* Set up the tuple queues that the workers will write into. */
pei->tqueue = ExecParallelSetupTupleQueues(pcxt, false);
@@ -1069,7 +1084,7 @@ ExecParallelRetrieveJitInstrumentation(PlanState *planstate,
/*
* Finish parallel execution. We wait for parallel workers to finish, and
- * accumulate their buffer usage.
+ * accumulate their buffer/WAL usage.
*/
void
ExecParallelFinish(ParallelExecutorInfo *pei)
@@ -1109,11 +1124,11 @@ ExecParallelFinish(ParallelExecutorInfo *pei)
WaitForParallelWorkersToFinish(pei->pcxt);
/*
- * Next, accumulate buffer usage. (This must wait for the workers to
- * finish, or we might get incomplete data.)
+ * Next, accumulate buffer/WAL usage. (This must wait for the workers
+ * to finish, or we might get incomplete data.)
*/
for (i = 0; i < nworkers; i++)
- InstrAccumParallelQuery(&pei->buffer_usage[i]);
+ InstrAccumParallelQuery(&pei->buffer_usage[i], &pei->wal_usage[i]);
pei->finished = true;
}
@@ -1333,6 +1348,7 @@ ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
{
FixedParallelExecutorState *fpes;
BufferUsage *buffer_usage;
+ WalUsage *wal_usage;
DestReceiver *receiver;
QueryDesc *queryDesc;
SharedExecutorInstrumentation *instrumentation;
@@ -1386,11 +1402,11 @@ ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
ExecSetTupleBound(fpes->tuples_needed, queryDesc->planstate);
/*
- * Prepare to track buffer usage during query execution.
+ * Prepare to track buffer/WAL usage during query execution.
*
* We do this after starting up the executor to match what happens in the
- * leader, which also doesn't count buffer accesses that occur during
- * executor startup.
+ * leader, which also doesn't count buffer accesses and WAL activity that
+ * occur during executor startup.
*/
InstrStartParallelQuery();
@@ -1406,9 +1422,11 @@ ParallelQueryMain(dsm_segment *seg, shm_toc *toc)
/* Shut down the executor */
ExecutorFinish(queryDesc);
- /* Report buffer usage during parallel execution. */
+ /* Report buffer/WAL usage during parallel execution. */
buffer_usage = shm_toc_lookup(toc, PARALLEL_KEY_BUFFER_USAGE, false);
- InstrEndParallelQuery(&buffer_usage[ParallelWorkerNumber]);
+ wal_usage = shm_toc_lookup (toc, PARALLEL_KEY_WAL_USAGE, false);
+ InstrEndParallelQuery(&buffer_usage[ParallelWorkerNumber],
+ &wal_usage[ParallelWorkerNumber]);
/* Report instrumentation data if any instrumentation options are set. */
if (instrumentation != NULL)
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index 042e10f96b..a77571a895 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -19,8 +19,11 @@
BufferUsage pgBufferUsage;
static BufferUsage save_pgBufferUsage;
+WalUsage pgWalUsage;
+static WalUsage save_pgWalUsage;
static void BufferUsageAdd(BufferUsage *dst, const BufferUsage *add);
+static void WalUsageAdd(WalUsage *dst, WalUsage *add);
/* Allocate new instrumentation structure(s) */
@@ -31,15 +34,17 @@ InstrAlloc(int n, int instrument_options)
/* initialize all fields to zeroes, then modify as needed */
instr = palloc0(n * sizeof(Instrumentation));
- if (instrument_options & (INSTRUMENT_BUFFERS | INSTRUMENT_TIMER))
+ if (instrument_options & (INSTRUMENT_BUFFERS | INSTRUMENT_TIMER | INSTRUMENT_WAL))
{
bool need_buffers = (instrument_options & INSTRUMENT_BUFFERS) != 0;
+ bool need_wal = (instrument_options & INSTRUMENT_WAL) != 0;
bool need_timer = (instrument_options & INSTRUMENT_TIMER) != 0;
int i;
for (i = 0; i < n; i++)
{
instr[i].need_bufusage = need_buffers;
+ instr[i].need_walusage = need_wal;
instr[i].need_timer = need_timer;
}
}
@@ -53,6 +58,7 @@ InstrInit(Instrumentation *instr, int instrument_options)
{
memset(instr, 0, sizeof(Instrumentation));
instr->need_bufusage = (instrument_options & INSTRUMENT_BUFFERS) != 0;
+ instr->need_walusage = (instrument_options & INSTRUMENT_WAL) != 0;
instr->need_timer = (instrument_options & INSTRUMENT_TIMER) != 0;
}
@@ -67,6 +73,9 @@ InstrStartNode(Instrumentation *instr)
/* save buffer usage totals at node entry, if needed */
if (instr->need_bufusage)
instr->bufusage_start = pgBufferUsage;
+
+ if (instr->need_walusage)
+ instr->walusage_start = pgWalUsage;
}
/* Exit from a plan node */
@@ -95,6 +104,10 @@ InstrStopNode(Instrumentation *instr, double nTuples)
BufferUsageAccumDiff(&instr->bufusage,
&pgBufferUsage, &instr->bufusage_start);
+ if (instr->need_walusage)
+ WalUsageAccumDiff(&instr->walusage,
+ &pgWalUsage, &instr->walusage_start);
+
/* Is this the first tuple of this cycle? */
if (!instr->running)
{
@@ -158,6 +171,9 @@ InstrAggNode(Instrumentation *dst, Instrumentation *add)
/* Add delta of buffer usage since entry to node's totals */
if (dst->need_bufusage)
BufferUsageAdd(&dst->bufusage, &add->bufusage);
+
+ if (dst->need_walusage)
+ WalUsageAdd(&dst->walusage, &add->walusage);
}
/* note current values during parallel executor startup */
@@ -165,21 +181,29 @@ void
InstrStartParallelQuery(void)
{
save_pgBufferUsage = pgBufferUsage;
+ save_pgWalUsage = pgWalUsage;
}
/* report usage after parallel executor shutdown */
void
-InstrEndParallelQuery(BufferUsage *result)
+InstrEndParallelQuery(BufferUsage *bufusage, WalUsage *walusage)
{
- memset(result, 0, sizeof(BufferUsage));
- BufferUsageAccumDiff(result, &pgBufferUsage, &save_pgBufferUsage);
+ if (bufusage)
+ {
+ memset(bufusage, 0, sizeof(BufferUsage));
+ BufferUsageAccumDiff(bufusage, &pgBufferUsage, &save_pgBufferUsage);
+ }
+ memset(walusage, 0, sizeof(WalUsage));
+ WalUsageAccumDiff(walusage, &pgWalUsage, &save_pgWalUsage);
}
/* accumulate work done by workers in leader's stats */
void
-InstrAccumParallelQuery(BufferUsage *result)
+InstrAccumParallelQuery(BufferUsage *bufusage, WalUsage *walusage)
{
- BufferUsageAdd(&pgBufferUsage, result);
+ if (bufusage)
+ BufferUsageAdd(&pgBufferUsage, bufusage);
+ WalUsageAdd(&pgWalUsage, walusage);
}
/* dst += add */
@@ -221,3 +245,20 @@ BufferUsageAccumDiff(BufferUsage *dst,
INSTR_TIME_ACCUM_DIFF(dst->blk_write_time,
add->blk_write_time, sub->blk_write_time);
}
+
+/* helper functions for WAL usage accumulation */
+static void
+WalUsageAdd(WalUsage *dst, WalUsage *add)
+{
+ dst->wal_bytes += add->wal_bytes;
+ dst->wal_records += add->wal_records;
+ dst->wal_num_fpw += add->wal_num_fpw;
+}
+
+void
+WalUsageAccumDiff(WalUsage *dst, const WalUsage *add, const WalUsage *sub)
+{
+ dst->wal_bytes += add->wal_bytes - sub->wal_bytes;
+ dst->wal_records += add->wal_records - sub->wal_records;
+ dst->wal_num_fpw += add->wal_num_fpw - sub->wal_num_fpw;
+}
diff --git a/src/include/access/xlog.h b/src/include/access/xlog.h
index 9ec7b31cce..b91e724b2d 100644
--- a/src/include/access/xlog.h
+++ b/src/include/access/xlog.h
@@ -259,7 +259,8 @@ struct XLogRecData;
extern XLogRecPtr XLogInsertRecord(struct XLogRecData *rdata,
XLogRecPtr fpw_lsn,
- uint8 flags);
+ uint8 flags,
+ int num_fpw);
extern void XLogFlush(XLogRecPtr RecPtr);
extern bool XLogBackgroundFlush(void);
extern bool XLogNeedsFlush(XLogRecPtr RecPtr);
diff --git a/src/include/executor/execParallel.h b/src/include/executor/execParallel.h
index 17d07cf020..1cc5b524fd 100644
--- a/src/include/executor/execParallel.h
+++ b/src/include/executor/execParallel.h
@@ -26,6 +26,7 @@ typedef struct ParallelExecutorInfo
PlanState *planstate; /* plan subtree we're running in parallel */
ParallelContext *pcxt; /* parallel context we're using */
BufferUsage *buffer_usage; /* points to bufusage area in DSM */
+ WalUsage *wal_usage; /* walusage area in DSM */
SharedExecutorInstrumentation *instrumentation; /* optional */
struct SharedJitInstrumentation *jit_instrumentation; /* optional */
dsa_area *area; /* points to DSA area in DSM */
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index 3825a5ac1f..f2bf37ae82 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -32,12 +32,20 @@ typedef struct BufferUsage
instr_time blk_write_time; /* time spent writing */
} BufferUsage;
+typedef struct WalUsage
+{
+ long wal_records; /* # of WAL records produced */
+ long wal_num_fpw; /* # of WAL full page image records produced */
+ uint64 wal_bytes; /* size of WAL records produced */
+} WalUsage;
+
/* Flag bits included in InstrAlloc's instrument_options bitmask */
typedef enum InstrumentOption
{
INSTRUMENT_TIMER = 1 << 0, /* needs timer (and row counts) */
INSTRUMENT_BUFFERS = 1 << 1, /* needs buffer usage */
INSTRUMENT_ROWS = 1 << 2, /* needs row count */
+ INSTRUMENT_WAL = 1 << 3, /* needs WAL usage */
INSTRUMENT_ALL = PG_INT32_MAX
} InstrumentOption;
@@ -46,6 +54,7 @@ typedef struct Instrumentation
/* Parameters set at node creation: */
bool need_timer; /* true if we need timer data */
bool need_bufusage; /* true if we need buffer usage data */
+ bool need_walusage; /* true if we need WAL usage data */
/* Info about current plan cycle: */
bool running; /* true if we've completed first tuple */
instr_time starttime; /* start time of current iteration of node */
@@ -53,6 +62,7 @@ typedef struct Instrumentation
double firsttuple; /* time for first tuple of this cycle */
double tuplecount; /* # of tuples emitted so far this cycle */
BufferUsage bufusage_start; /* buffer usage at start */
+ WalUsage walusage_start; /* WAL usage at start */
/* Accumulated statistics across all completed cycles: */
double startup; /* total startup time (in seconds) */
double total; /* total time (in seconds) */
@@ -62,6 +72,7 @@ typedef struct Instrumentation
double nfiltered1; /* # of tuples removed by scanqual or joinqual */
double nfiltered2; /* # of tuples removed by "other" quals */
BufferUsage bufusage; /* total buffer usage */
+ WalUsage walusage; /* total WAL usage */
} Instrumentation;
typedef struct WorkerInstrumentation
@@ -71,6 +82,7 @@ typedef struct WorkerInstrumentation
} WorkerInstrumentation;
extern PGDLLIMPORT BufferUsage pgBufferUsage;
+extern PGDLLIMPORT WalUsage pgWalUsage;
extern Instrumentation *InstrAlloc(int n, int instrument_options);
extern void InstrInit(Instrumentation *instr, int instrument_options);
@@ -79,9 +91,11 @@ extern void InstrStopNode(Instrumentation *instr, double nTuples);
extern void InstrEndLoop(Instrumentation *instr);
extern void InstrAggNode(Instrumentation *dst, Instrumentation *add);
extern void InstrStartParallelQuery(void);
-extern void InstrEndParallelQuery(BufferUsage *result);
-extern void InstrAccumParallelQuery(BufferUsage *result);
+extern void InstrEndParallelQuery(BufferUsage *bufusage, WalUsage *walusage);
+extern void InstrAccumParallelQuery(BufferUsage *bufusage, WalUsage *walusage);
extern void BufferUsageAccumDiff(BufferUsage *dst,
const BufferUsage *add, const BufferUsage *sub);
+extern void WalUsageAccumDiff(WalUsage *dst, const WalUsage *add,
+ const WalUsage *sub);
#endif /* INSTRUMENT_H */
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index 939de985d3..34623523a7 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -2643,6 +2643,7 @@ WalSndCtlData
WalSndSendDataCallback
WalSndState
WalTimeSample
+WalUsage
WalWriteMethod
Walfile
WindowAgg
--
2.20.1
[text/plain] v13-0002-Add-option-to-report-WAL-usage-in-EXPLAIN-and-au.patch (11.3K, ../20200402144438.GF64485@nol/3-v13-0002-Add-option-to-report-WAL-usage-in-EXPLAIN-and-au.patch)
download | inline diff:
From e0cb25e07c59b4e3947ed781e8794bdd59a30903 Mon Sep 17 00:00:00 2001
From: Julien Rouhaud <julien.rouhaud@free.fr>
Date: Sun, 29 Mar 2020 12:38:14 +0200
Subject: [PATCH v13 2/4] Add option to report WAL usage in EXPLAIN and
auto_explain.
Author: Julien Rouhaud
Reviewed-by:
Discussion: https://postgr.es/m/CAB-hujrP8ZfUkvL5OYETipQwA=e3n7oqHFU=4ZLxWS_Cza3kQQ@mail.gmail.com
---
contrib/auto_explain/auto_explain.c | 15 ++++++
doc/src/sgml/auto-explain.sgml | 20 ++++++++
doc/src/sgml/ref/explain.sgml | 14 ++++++
src/backend/commands/explain.c | 74 +++++++++++++++++++++++++++--
src/bin/psql/tab-complete.c | 4 +-
src/include/commands/explain.h | 3 ++
6 files changed, 124 insertions(+), 6 deletions(-)
diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c
index f69dde876c..56c549d84c 100644
--- a/contrib/auto_explain/auto_explain.c
+++ b/contrib/auto_explain/auto_explain.c
@@ -27,6 +27,7 @@ static int auto_explain_log_min_duration = -1; /* msec or -1 */
static bool auto_explain_log_analyze = false;
static bool auto_explain_log_verbose = false;
static bool auto_explain_log_buffers = false;
+static bool auto_explain_log_wal = false;
static bool auto_explain_log_triggers = false;
static bool auto_explain_log_timing = true;
static bool auto_explain_log_settings = false;
@@ -148,6 +149,17 @@ _PG_init(void)
NULL,
NULL);
+ DefineCustomBoolVariable("auto_explain.log_wal",
+ "Log WAL usage.",
+ NULL,
+ &auto_explain_log_wal,
+ false,
+ PGC_SUSET,
+ 0,
+ NULL,
+ NULL,
+ NULL);
+
DefineCustomBoolVariable("auto_explain.log_triggers",
"Include trigger statistics in plans.",
"This has no effect unless log_analyze is also set.",
@@ -280,6 +292,8 @@ explain_ExecutorStart(QueryDesc *queryDesc, int eflags)
queryDesc->instrument_options |= INSTRUMENT_ROWS;
if (auto_explain_log_buffers)
queryDesc->instrument_options |= INSTRUMENT_BUFFERS;
+ if (auto_explain_log_wal)
+ queryDesc->instrument_options |= INSTRUMENT_WAL;
}
}
@@ -374,6 +388,7 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
es->analyze = (queryDesc->instrument_options && auto_explain_log_analyze);
es->verbose = auto_explain_log_verbose;
es->buffers = (es->analyze && auto_explain_log_buffers);
+ es->wal = (es->analyze && auto_explain_log_wal);
es->timing = (es->analyze && auto_explain_log_timing);
es->summary = es->analyze;
es->format = auto_explain_log_format;
diff --git a/doc/src/sgml/auto-explain.sgml b/doc/src/sgml/auto-explain.sgml
index 3d619d4a3d..d4d29c4a64 100644
--- a/doc/src/sgml/auto-explain.sgml
+++ b/doc/src/sgml/auto-explain.sgml
@@ -109,6 +109,26 @@ LOAD 'auto_explain';
</listitem>
</varlistentry>
+ <varlistentry>
+ <term>
+ <varname>auto_explain.log_wal</varname> (<type>boolean</type>)
+ <indexterm>
+ <primary><varname>auto_explain.log_wal</varname> configuration parameter</primary>
+ </indexterm>
+ </term>
+ <listitem>
+ <para>
+ <varname>auto_explain.log_wal</varname> controls whether WAL
+ usage statistics are printed when an execution plan is logged; it's
+ equivalent to the <literal>WAL</literal> option of <command>EXPLAIN</command>.
+ This parameter has no effect
+ unless <varname>auto_explain.log_analyze</varname> is enabled.
+ This parameter is off by default.
+ Only superusers can change this setting.
+ </para>
+ </listitem>
+ </varlistentry>
+
<varlistentry>
<term>
<varname>auto_explain.log_timing</varname> (<type>boolean</type>)
diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml
index 385d10411f..024ede4a8d 100644
--- a/doc/src/sgml/ref/explain.sgml
+++ b/doc/src/sgml/ref/explain.sgml
@@ -41,6 +41,7 @@ EXPLAIN [ ANALYZE ] [ VERBOSE ] <replaceable class="parameter">statement</replac
COSTS [ <replaceable class="parameter">boolean</replaceable> ]
SETTINGS [ <replaceable class="parameter">boolean</replaceable> ]
BUFFERS [ <replaceable class="parameter">boolean</replaceable> ]
+ WAL [ <replaceable class="parameter">boolean</replaceable> ]
TIMING [ <replaceable class="parameter">boolean</replaceable> ]
SUMMARY [ <replaceable class="parameter">boolean</replaceable> ]
FORMAT { TEXT | XML | JSON | YAML }
@@ -192,6 +193,19 @@ ROLLBACK;
</listitem>
</varlistentry>
+ <varlistentry>
+ <term><literal>WAL</literal></term>
+ <listitem>
+ <para>
+ Include information on WAL record generation. Specifically, include the
+ number of records, number of full page image records and amount of WAL
+ bytes generated. In text format, only non-zero values are printed. This
+ parameter may only be used when <literal>ANALYZE</literal> is also
+ enabled. It defaults to <literal>FALSE</literal>.
+ </para>
+ </listitem>
+ </varlistentry>
+
<varlistentry>
<term><literal>TIMING</literal></term>
<listitem>
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index ee0e638f33..cefe2144e5 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -113,6 +113,7 @@ static void show_foreignscan_info(ForeignScanState *fsstate, ExplainState *es);
static void show_eval_params(Bitmapset *bms_params, ExplainState *es);
static const char *explain_get_index_name(Oid indexId);
static void show_buffer_usage(ExplainState *es, const BufferUsage *usage);
+static void show_wal_usage(ExplainState *es, const WalUsage *usage);
static void ExplainIndexScanDetails(Oid indexid, ScanDirection indexorderdir,
ExplainState *es);
static void ExplainScanTarget(Scan *plan, ExplainState *es);
@@ -175,6 +176,8 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt,
es->costs = defGetBoolean(opt);
else if (strcmp(opt->defname, "buffers") == 0)
es->buffers = defGetBoolean(opt);
+ else if (strcmp(opt->defname, "wal") == 0)
+ es->wal = defGetBoolean(opt);
else if (strcmp(opt->defname, "settings") == 0)
es->settings = defGetBoolean(opt);
else if (strcmp(opt->defname, "timing") == 0)
@@ -219,6 +222,11 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt,
(errcode(ERRCODE_INVALID_PARAMETER_VALUE),
errmsg("EXPLAIN option BUFFERS requires ANALYZE")));
+ if (es->wal && !es->analyze)
+ ereport(ERROR,
+ (errcode(ERRCODE_INVALID_PARAMETER_VALUE),
+ errmsg("EXPLAIN option WAL requires ANALYZE")));
+
/* if the timing was not set explicitly, set default value */
es->timing = (timing_set) ? es->timing : es->analyze;
@@ -494,6 +502,8 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es,
if (es->buffers)
instrument_option |= INSTRUMENT_BUFFERS;
+ if (es->wal)
+ instrument_option |= INSTRUMENT_WAL;
/*
* We always collect timing for the entire statement, even when node-level
@@ -1942,12 +1952,14 @@ ExplainNode(PlanState *planstate, List *ancestors,
}
}
- /* Show buffer usage */
+ /* Show buffer/WAL usage */
if (es->buffers && planstate->instrument)
show_buffer_usage(es, &planstate->instrument->bufusage);
+ if (es->wal && planstate->instrument)
+ show_wal_usage(es, &planstate->instrument->walusage);
- /* Prepare per-worker buffer usage */
- if (es->workers_state && es->buffers && es->verbose)
+ /* Prepare per-worker buffer/WAL usage */
+ if (es->workers_state && (es->buffers || es->wal) && es->verbose)
{
WorkerInstrumentation *w = planstate->worker_instrument;
@@ -1960,7 +1972,10 @@ ExplainNode(PlanState *planstate, List *ancestors,
continue;
ExplainOpenWorker(n, es);
- show_buffer_usage(es, &instrument->bufusage);
+ if (es->buffers)
+ show_buffer_usage(es, &instrument->bufusage);
+ if (es->wal)
+ show_wal_usage(es, &instrument->walusage);
ExplainCloseWorker(n, es);
}
}
@@ -3059,6 +3074,44 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage)
}
}
+/*
+ * Show WAL usage details.
+ */
+static void
+show_wal_usage(ExplainState *es, const WalUsage *usage)
+{
+ if (es->format == EXPLAIN_FORMAT_TEXT)
+ {
+ /* Show only positive counter values. */
+ if ((usage->wal_records > 0) || (usage->wal_num_fpw > 0) ||
+ (usage->wal_bytes > 0))
+ {
+ ExplainIndentText(es);
+ appendStringInfoString(es->str, "WAL:");
+
+ if (usage->wal_records > 0)
+ appendStringInfo(es->str, " records=%ld",
+ usage->wal_records);
+ if (usage->wal_num_fpw > 0)
+ appendStringInfo(es->str, " full page writes=%ld",
+ usage->wal_num_fpw);
+ if (usage->wal_bytes > 0)
+ appendStringInfo(es->str, " bytes=" UINT64_FORMAT,
+ usage->wal_bytes);
+ appendStringInfoChar(es->str, '\n');
+ }
+ }
+ else
+ {
+ ExplainPropertyInteger("WAL records", NULL,
+ usage->wal_records, es);
+ ExplainPropertyInteger("WAL full page writes", NULL,
+ usage->wal_num_fpw, es);
+ ExplainPropertyUInteger("WAL bytes", NULL,
+ usage->wal_bytes, es);
+ }
+}
+
/*
* Add some additional details about an IndexScan or IndexOnlyScan
*/
@@ -3843,6 +3896,19 @@ ExplainPropertyInteger(const char *qlabel, const char *unit, int64 value,
ExplainProperty(qlabel, unit, buf, true, es);
}
+/*
+ * Explain an unsigned integer-valued property.
+ */
+void
+ExplainPropertyUInteger(const char *qlabel, const char *unit, uint64 value,
+ ExplainState *es)
+{
+ char buf[32];
+
+ snprintf(buf, sizeof(buf), UINT64_FORMAT, value);
+ ExplainProperty(qlabel, unit, buf, true, es);
+}
+
/*
* Explain a float-valued property, using the specified number of
* fractional digits.
diff --git a/src/bin/psql/tab-complete.c b/src/bin/psql/tab-complete.c
index 5fec59723c..0e7a373caf 100644
--- a/src/bin/psql/tab-complete.c
+++ b/src/bin/psql/tab-complete.c
@@ -3045,8 +3045,8 @@ psql_completion(const char *text, int start, int end)
*/
if (ends_with(prev_wd, '(') || ends_with(prev_wd, ','))
COMPLETE_WITH("ANALYZE", "VERBOSE", "COSTS", "SETTINGS",
- "BUFFERS", "TIMING", "SUMMARY", "FORMAT");
- else if (TailMatches("ANALYZE|VERBOSE|COSTS|SETTINGS|BUFFERS|TIMING|SUMMARY"))
+ "BUFFERS", "WAL", "TIMING", "SUMMARY", "FORMAT");
+ else if (TailMatches("ANALYZE|VERBOSE|COSTS|SETTINGS|BUFFERS|WAL|TIMING|SUMMARY"))
COMPLETE_WITH("ON", "OFF");
else if (TailMatches("FORMAT"))
COMPLETE_WITH("TEXT", "XML", "JSON", "YAML");
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index 54f6240e5e..7b0b0a94a6 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -42,6 +42,7 @@ typedef struct ExplainState
bool analyze; /* print actual times */
bool costs; /* print estimated costs */
bool buffers; /* print buffer usage */
+ bool wal; /* print WAL usage */
bool timing; /* print detailed node timing */
bool summary; /* print total planning and execution timing */
bool settings; /* print modified settings */
@@ -110,6 +111,8 @@ extern void ExplainPropertyText(const char *qlabel, const char *value,
ExplainState *es);
extern void ExplainPropertyInteger(const char *qlabel, const char *unit,
int64 value, ExplainState *es);
+extern void ExplainPropertyUInteger(const char *qlabel, const char *unit,
+ uint64 value, ExplainState *es);
extern void ExplainPropertyFloat(const char *qlabel, const char *unit,
double value, int ndigits, ExplainState *es);
extern void ExplainPropertyBool(const char *qlabel, bool value,
--
2.20.1
[text/plain] v13-0003-Keep-track-of-WAL-usage-in-pg_stat_statements.patch (12.5K, ../20200402144438.GF64485@nol/4-v13-0003-Keep-track-of-WAL-usage-in-pg_stat_statements.patch)
download | inline diff:
From 9cf6ff14f3e34b0cf8f95016ef4a2853e792eab9 Mon Sep 17 00:00:00 2001
From: Kirill Bychik <kirill.bychik@gmail.com>
Date: Tue, 17 Mar 2020 14:42:02 +0100
Subject: [PATCH v13 3/4] Keep track of WAL usage in pg_stat_statements.
Author: Kirill Bychik
Reviewed-by: Julien Rouhaud, Fuji Masao
Discussion: https://postgr.es/m/CAB-hujrP8ZfUkvL5OYETipQwA=e3n7oqHFU=4ZLxWS_Cza3kQQ@mail.gmail.com
---
.../expected/pg_stat_statements.out | 39 +++++++++++++
.../pg_stat_statements--1.7--1.8.sql | 5 +-
.../pg_stat_statements/pg_stat_statements.c | 55 +++++++++++++++++--
.../sql/pg_stat_statements.sql | 23 ++++++++
doc/src/sgml/pgstatstatements.sgml | 27 +++++++++
5 files changed, 144 insertions(+), 5 deletions(-)
diff --git a/contrib/pg_stat_statements/expected/pg_stat_statements.out b/contrib/pg_stat_statements/expected/pg_stat_statements.out
index 45dbe9e677..f615f8c2bf 100644
--- a/contrib/pg_stat_statements/expected/pg_stat_statements.out
+++ b/contrib/pg_stat_statements/expected/pg_stat_statements.out
@@ -211,6 +211,45 @@ SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C";
UPDATE test SET b = $1 WHERE a > $2 | 1 | 3
(10 rows)
+--
+-- INSERT, UPDATE, DELETE on test table to validate WAL generation metrics
+--
+SELECT pg_stat_statements_reset();
+ pg_stat_statements_reset
+--------------------------
+
+(1 row)
+
+-- utility "create table" should not be shown
+CREATE TABLE pgss_test (a int, b char(20));
+INSERT INTO pgss_test VALUES(generate_series(1, 10), 'aaa');
+UPDATE pgss_test SET b = 'bbb' WHERE a > 7;
+DELETE FROM pgss_test WHERE a > 9;
+-- DROP test table
+SET pg_stat_statements.track_utility = TRUE;
+DROP TABLE pgss_test;
+SET pg_stat_statements.track_utility = FALSE;
+-- Check WAL is generated for the above statements
+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 VALUES(generate_series($1, $2), $3) | 1 | 10 | t | t | t
+ SELECT pg_stat_statements_reset() | 1 | 1 | f | f | f
+ SELECT query, calls, rows, +| 0 | 0 | f | f | t
+ wal_bytes > $1 as wal_bytes_generated, +| | | | |
+ wal_records > $2 as wal_records_generated, +| | | | |
+ wal_records = rows as wal_records_as_rows +| | | | |
+ FROM pg_stat_statements ORDER BY query COLLATE "C" | | | | |
+ SET pg_stat_statements.track_utility = FALSE | 1 | 0 | f | f | t
+ UPDATE pgss_test SET b = $1 WHERE a > $2 | 1 | 3 | t | t | t
+(7 rows)
+
--
-- pg_stat_statements.track = none
--
diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql b/contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql
index 60d454db7f..30566574ab 100644
--- a/contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql
+++ b/contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql
@@ -41,7 +41,10 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean,
OUT temp_blks_read int8,
OUT temp_blks_written int8,
OUT blk_read_time float8,
- OUT blk_write_time float8
+ OUT blk_write_time float8,
+ OUT wal_records int8,
+ OUT wal_num_fpw int8,
+ OUT wal_bytes numeric
)
RETURNS SETOF record
AS 'MODULE_PATHNAME', 'pg_stat_statements_1_8'
diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c
index 942922b01f..c42bf62fce 100644
--- a/contrib/pg_stat_statements/pg_stat_statements.c
+++ b/contrib/pg_stat_statements/pg_stat_statements.c
@@ -188,6 +188,9 @@ typedef struct Counters
double blk_read_time; /* time spent reading, in msec */
double blk_write_time; /* time spent writing, in msec */
double usage; /* usage factor */
+ int64 wal_records; /* # of WAL records generated */
+ int64 wal_num_fpw; /* # of WAL full page image records generated */
+ uint64 wal_bytes; /* total amount of WAL bytes generated */
} Counters;
/*
@@ -348,6 +351,7 @@ static void pgss_store(const char *query, uint64 queryId,
pgssStoreKind kind,
double total_time, uint64 rows,
const BufferUsage *bufusage,
+ const WalUsage *walusage,
pgssJumbleState *jstate);
static void pg_stat_statements_internal(FunctionCallInfo fcinfo,
pgssVersion api_version,
@@ -891,6 +895,7 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query)
0,
0,
NULL,
+ NULL,
&jstate);
}
@@ -926,9 +931,16 @@ pgss_planner(Query *parse,
instr_time duration;
BufferUsage bufusage_start,
bufusage;
+ WalUsage walusage_start,
+ walusage;
/* We need to track buffer usage as the planner can access them. */
bufusage_start = pgBufferUsage;
+ /*
+ * Similarly the planner could write some WAL records in some cases
+ * (e.g. setting a hint bit with those being WAL-logged)
+ */
+ walusage_start = pgWalUsage;
INSTR_TIME_SET_CURRENT(start);
plan_nested_level++;
@@ -954,6 +966,10 @@ pgss_planner(Query *parse,
memset(&bufusage, 0, sizeof(BufferUsage));
BufferUsageAccumDiff(&bufusage, &pgBufferUsage, &bufusage_start);
+ /* calc differences of WAL counters. */
+ memset(&walusage, 0, sizeof(WalUsage));
+ WalUsageAccumDiff(&walusage, &pgWalUsage, &walusage_start);
+
pgss_store(query_string,
parse->queryId,
parse->stmt_location,
@@ -962,6 +978,7 @@ pgss_planner(Query *parse,
INSTR_TIME_GET_MILLISEC(duration),
0,
&bufusage,
+ &walusage,
NULL);
}
else
@@ -1079,6 +1096,7 @@ pgss_ExecutorEnd(QueryDesc *queryDesc)
queryDesc->totaltime->total * 1000.0, /* convert to msec */
queryDesc->estate->es_processed,
&queryDesc->totaltime->bufusage,
+ &queryDesc->totaltime->walusage,
NULL);
}
@@ -1123,8 +1141,10 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
uint64 rows;
BufferUsage bufusage_start,
bufusage;
-
+ WalUsage walusage_start,
+ walusage;
bufusage_start = pgBufferUsage;
+ walusage_start = pgWalUsage;
INSTR_TIME_SET_CURRENT(start);
exec_nested_level++;
@@ -1154,6 +1174,10 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
memset(&bufusage, 0, sizeof(BufferUsage));
BufferUsageAccumDiff(&bufusage, &pgBufferUsage, &bufusage_start);
+ /* calc differences of WAL counters. */
+ memset(&walusage, 0, sizeof(WalUsage));
+ WalUsageAccumDiff(&walusage, &pgWalUsage, &walusage_start);
+
pgss_store(queryString,
0, /* signal that it's a utility stmt */
pstmt->stmt_location,
@@ -1162,6 +1186,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
INSTR_TIME_GET_MILLISEC(duration),
rows,
&bufusage,
+ &walusage,
NULL);
}
else
@@ -1197,7 +1222,8 @@ pgss_hash_string(const char *str, int len)
*
* If jstate is not NULL then we're trying to create an entry for which
* we have no statistics as yet; we just want to record the normalized
- * query string. total_time, rows, bufusage are ignored in this case.
+ * query string. total_time, rows, bufusage and walusage are ignored in this
+ * case.
*
* If kind is PGSS_PLAN or PGSS_EXEC, its value is used as the array position
* for the arrays in the Counters field.
@@ -1208,6 +1234,7 @@ pgss_store(const char *query, uint64 queryId,
pgssStoreKind kind,
double total_time, uint64 rows,
const BufferUsage *bufusage,
+ const WalUsage *walusage,
pgssJumbleState *jstate)
{
pgssHashKey key;
@@ -1402,6 +1429,9 @@ pgss_store(const char *query, uint64 queryId,
e->counters.blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->blk_read_time);
e->counters.blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->blk_write_time);
e->counters.usage += USAGE_EXEC(total_time);
+ e->counters.wal_records += walusage->wal_records;
+ e->counters.wal_num_fpw += walusage->wal_num_fpw;
+ e->counters.wal_bytes += walusage->wal_bytes;
SpinLockRelease(&e->mutex);
}
@@ -1449,8 +1479,8 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS)
#define PG_STAT_STATEMENTS_COLS_V1_1 18
#define PG_STAT_STATEMENTS_COLS_V1_2 19
#define PG_STAT_STATEMENTS_COLS_V1_3 23
-#define PG_STAT_STATEMENTS_COLS_V1_8 29
-#define PG_STAT_STATEMENTS_COLS 29 /* maximum of above */
+#define PG_STAT_STATEMENTS_COLS_V1_8 32
+#define PG_STAT_STATEMENTS_COLS 32 /* maximum of above */
/*
* Retrieve statement statistics.
@@ -1786,6 +1816,23 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
values[i++] = Float8GetDatumFast(tmp.blk_read_time);
values[i++] = Float8GetDatumFast(tmp.blk_write_time);
}
+ if (api_version >= PGSS_V1_8)
+ {
+ char buf[256];
+ Datum wal_bytes;
+
+ values[i++] = Int64GetDatumFast(tmp.wal_records);
+ values[i++] = Int64GetDatumFast(tmp.wal_num_fpw);
+
+ 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;
+ }
Assert(i == (api_version == PGSS_V1_0 ? PG_STAT_STATEMENTS_COLS_V1_0 :
api_version == PGSS_V1_1 ? PG_STAT_STATEMENTS_COLS_V1_1 :
diff --git a/contrib/pg_stat_statements/sql/pg_stat_statements.sql b/contrib/pg_stat_statements/sql/pg_stat_statements.sql
index 435d51008f..75c10554a8 100644
--- a/contrib/pg_stat_statements/sql/pg_stat_statements.sql
+++ b/contrib/pg_stat_statements/sql/pg_stat_statements.sql
@@ -101,6 +101,29 @@ SELECT * FROM test WHERE a IN (1, 2, 3, 4, 5);
SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C";
+--
+-- INSERT, UPDATE, DELETE on test table to validate WAL generation metrics
+--
+SELECT pg_stat_statements_reset();
+
+-- utility "create table" should not be shown
+CREATE TABLE pgss_test (a int, b char(20));
+
+INSERT INTO pgss_test VALUES(generate_series(1, 10), 'aaa');
+UPDATE pgss_test SET b = 'bbb' WHERE a > 7;
+DELETE FROM pgss_test WHERE a > 9;
+-- DROP test table
+SET pg_stat_statements.track_utility = TRUE;
+DROP TABLE pgss_test;
+SET pg_stat_statements.track_utility = FALSE;
+
+-- Check WAL is generated for the above statements
+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";
+
--
-- pg_stat_statements.track = none
--
diff --git a/doc/src/sgml/pgstatstatements.sgml b/doc/src/sgml/pgstatstatements.sgml
index b4df84c60b..3d26108649 100644
--- a/doc/src/sgml/pgstatstatements.sgml
+++ b/doc/src/sgml/pgstatstatements.sgml
@@ -264,6 +264,33 @@
</entry>
</row>
+ <row>
+ <entry><structfield>wal_bytes</structfield></entry>
+ <entry><type>numeric</type></entry>
+ <entry></entry>
+ <entry>
+ Total amount of WAL bytes generated by the statement
+ </entry>
+ </row>
+
+ <row>
+ <entry><structfield>wal_records</structfield></entry>
+ <entry><type>bigint</type></entry>
+ <entry></entry>
+ <entry>
+ Total count of WAL records generated by the statement
+ </entry>
+ </row>
+
+ <row>
+ <entry><structfield>wal_num_fpw</structfield></entry>
+ <entry><type>bigint</type></entry>
+ <entry></entry>
+ <entry>
+ Total count of WAL full page writes generated by the statement
+ </entry>
+ </row>
+
</tbody>
</tgroup>
</table>
--
2.20.1
[text/plain] v13-0004-Expose-WAL-usage-counters-in-verbose-auto-vacuum.patch (2.8K, ../20200402144438.GF64485@nol/5-v13-0004-Expose-WAL-usage-counters-in-verbose-auto-vacuum.patch)
download | inline diff:
From fc00f3bc115502395d5b10862be013970b3f29c8 Mon Sep 17 00:00:00 2001
From: Julien Rouhaud <julien.rouhaud@free.fr>
Date: Thu, 19 Mar 2020 16:08:47 +0100
Subject: [PATCH v13 4/4] Expose WAL usage counters in verbose (auto)vacuum
output.
Author: Julien Rouhaud
Reviewed-by: Fuji Masao
Discussion: https://postgr.es/m/CAB-hujrP8ZfUkvL5OYETipQwA=e3n7oqHFU=4ZLxWS_Cza3kQQ@mail.gmail.com
---
src/backend/access/heap/vacuumlazy.c | 24 +++++++++++++++++++++++-
1 file changed, 23 insertions(+), 1 deletion(-)
diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index cc7e8521a5..735087dd74 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -410,6 +410,8 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params,
int nindexes;
PGRUsage ru0;
TimestampTz starttime = 0;
+ WalUsage walusage_start = pgWalUsage;
+ WalUsage walusage = {0, 0, 0};
long secs;
int usecs;
double read_rate,
@@ -614,6 +616,9 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params,
TimestampDifference(starttime, endtime, &secs, &usecs);
+ memset(&walusage, 0, sizeof(WalUsage));
+ WalUsageAccumDiff(&walusage, &pgWalUsage, &walusage_start);
+
read_rate = 0;
write_rate = 0;
if ((secs > 0) || (usecs > 0))
@@ -666,7 +671,13 @@ heap_vacuum_rel(Relation onerel, VacuumParams *params,
(long long) VacuumPageDirty);
appendStringInfo(&buf, _("avg read rate: %.3f MB/s, avg write rate: %.3f MB/s\n"),
read_rate, write_rate);
- appendStringInfo(&buf, _("system usage: %s"), pg_rusage_show(&ru0));
+ appendStringInfo(&buf, _("system usage: %s\n"), pg_rusage_show(&ru0));
+ appendStringInfo(&buf,
+ _("WAL usage: %ld records, %ld full page writes, "
+ UINT64_FORMAT " bytes"),
+ walusage.wal_records,
+ walusage.wal_num_fpw,
+ walusage.wal_bytes);
ereport(LOG,
(errmsg_internal("%s", buf.data)));
@@ -758,6 +769,8 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
IndexBulkDeleteResult **indstats;
int i;
PGRUsage ru0;
+ WalUsage walusage_start = pgWalUsage;
+ WalUsage walusage = {0, 0, 0};
Buffer vmbuffer = InvalidBuffer;
BlockNumber next_unskippable_block;
bool skipping_blocks;
@@ -1727,6 +1740,15 @@ lazy_scan_heap(Relation onerel, VacuumParams *params, LVRelStats *vacrelstats,
"%u pages are entirely empty.\n",
empty_pages),
empty_pages);
+
+ memset(&walusage, 0, sizeof(WalUsage));
+ WalUsageAccumDiff(&walusage, &pgWalUsage, &walusage_start);
+ appendStringInfo(&buf, _("%ld WAL records, %ld WAL full page writes, "
+ UINT64_FORMAT " WAL bytes\n"),
+ walusage.wal_records,
+ walusage.wal_num_fpw,
+ walusage.wal_bytes);
+
appendStringInfo(&buf, _("%s."), pg_rusage_show(&ru0));
ereport(elevel,
--
2.20.1
[application/x-sh] wal_test.sh (2.2K, ../20200402144438.GF64485@nol/6-wal_test.sh)
download
view thread (130+ messages) latest in thread
Message-ID: <20200402144438.GF64485@nol>
Permalink: ../20200402144438.GF64485@nol/
Also on: postgresql.org/message-id/20200402144438.GF64485@nol
copy link · copy postgr.es · copy git am
reply Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-hackers@postgresql.org
Cc: rjuju123@gmail.com, amit.kapila16@gmail.com, kuntalghosh.2007@gmail.com, masao.fujii@oss.nttdata.com, kirill.bychik@gmail.com, thomas.munro@gmail.com
Subject: Re: WAL usage calculation patch
In-Reply-To: <20200402144438.GF64485@nol>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox