Re: pg_stat_statements issue with parallel maintenance (Was Re: WAL usage calculation patch)
Dilip Kumar <dilipbalaut@gmail.com>
Commits
GET /api/v1/messages/:b64id/commits
the thread's linked commits as JSON, with link sources.
API reference →
-
Change the display of WAL usage statistics in Explain.
- 69bfaf2e1de4 13.0 landed
-
Cosmetic fixups for WAL usage work.
- ef08ca113fe3 13.0 landed
-
Allow parallel create index to accumulate buffer usage stats.
- 5c71362174eb 13.0 landed
- f179e9f01b65 11.8 landed
- 13823ad3b012 12.3 landed
-
Allow autovacuum to log WAL usage statistics.
- b7ce6de93b59 13.0 landed
-
Add the option to report WAL usage in EXPLAIN and auto_explain.
- 33e05f89c53e 13.0 landed
-
Allow pg_stat_statements to track WAL usage statistics.
- 6b466bf5f2be 13.0 landed
-
Add infrastructure to track WAL usage.
- df3b181499b4 13.0 landed
-
Include information on buffer usage during planning phase, in EXPLAIN output, take two.
- ce77abe63cfc 13.0 cited
-
Include information on buffer usage during planning phase, in EXPLAIN output.
- ed7a5095716e 13.0 cited
-
Allow parallel vacuum to accumulate buffer usage.
- 3a5e22138a8d 13.0 landed
-
Allow pg_stat_statements to track planning statistics.
- 17e03282241c 13.0 cited
On Wed, Apr 1, 2020 at 8:51 AM Dilip Kumar <dilipbalaut@gmail.com> wrote:
>
> On Wed, Apr 1, 2020 at 8:26 AM Masahiko Sawada
> <masahiko.sawada@2ndquadrant.com> wrote:
> >
> > On Wed, 1 Apr 2020 at 11:46, Amit Kapila <amit.kapila16@gmail.com> wrote:
> > >
> > > On Tue, Mar 31, 2020 at 7:32 PM Dilip Kumar <dilipbalaut@gmail.com> wrote:
> > > >
> > > > While testing I have found one issue. Basically, during a parallel
> > > > vacuum, it was showing more number of
> > > > shared_blk_hits+shared_blks_read. After, some investigation, I found
> > > > that during the cleanup phase nworkers are -1, and because of this we
> > > > didn't try to launch worker but "lps->pcxt->nworkers_launched" had the
> > > > old launched worker count and shared memory also had old buffer read
> > > > data which was never updated as we did not try to launch the worker.
> > > >
> > > > diff --git a/src/backend/access/heap/vacuumlazy.c
> > > > b/src/backend/access/heap/vacuumlazy.c
> > > > index b97b678..5dfaf4d 100644
> > > > --- a/src/backend/access/heap/vacuumlazy.c
> > > > +++ b/src/backend/access/heap/vacuumlazy.c
> > > > @@ -2150,7 +2150,8 @@ lazy_parallel_vacuum_indexes(Relation *Irel,
> > > > IndexBulkDeleteResult **stats,
> > > > * Next, accumulate buffer usage. (This must wait for the workers to
> > > > * finish, or we might get incomplete data.)
> > > > */
> > > > - for (i = 0; i < lps->pcxt->nworkers_launched; i++)
> > > > + nworkers = Min(nworkers, lps->pcxt->nworkers_launched);
> > > > + for (i = 0; i < nworkers; i++)
> > > > InstrAccumParallelQuery(&lps->buffer_usage[i]);
> > > >
> > > > It worked after the above fix.
> > > >
> > >
> > > Good catch. I think we should not even call
> > > WaitForParallelWorkersToFinish for such a case. So, I guess the fix
> > > could be,
> > >
> > > if (workers > 0)
> > > {
> > > WaitForParallelWorkersToFinish();
> > > for (i = 0; i < lps->pcxt->nworkers_launched; i++)
> > > InstrAccumParallelQuery(&lps->buffer_usage[i]);
> > > }
> > >
> >
> > Agreed. I've attached the updated patch.
> >
> > Thank you for testing, Dilip!
>
> Thanks! One hunk is failing on the latest head. And, I have rebased
> the patch for my testing so posting the same. I have done some more
> testing to test multi-pass vacuum.
>
> postgres[114321]=# show maintenance_work_mem ;
> maintenance_work_mem
> ----------------------
> 1MB
> (1 row)
>
> --Test case
> select pg_stat_statements_reset();
> drop table test;
> CREATE TABLE test (a int, b int);
> CREATE INDEX idx1 on test(a);
> CREATE INDEX idx2 on test(b);
> INSERT INTO test SELECT i, i FROM GENERATE_SERIES(1,2000000) as i;
> DELETE FROM test where a%2=0;
> VACUUM (PARALLEL n) test;
> select query, total_time, shared_blks_hit, shared_blks_read,
> shared_blks_hit + shared_blks_read as total_read_blks,
> shared_blks_dirtied, shared_blks_written from pg_stat_statements where
> query like 'VACUUM%';
>
> query | total_time | shared_blks_hit |
> shared_blks_read | total_read_blks | shared_blks_dirtied |
> shared_blks_written
> --------------------------+-------------+-----------------+------------------+-----------------+---------------------+---------------------
> VACUUM (PARALLEL 0) test | 5964.282408 | 92447 |
> 6 | 92453 | 19789 | 0
>
>
> query | total_time | shared_blks_hit |
> shared_blks_read | total_read_blks | shared_blks_dirtied |
> shared_blks_written
> --------------------------+--------------------+-----------------+------------------+-----------------+---------------------+---------------------
> VACUUM (PARALLEL 1) test | 3957.7658810000003 | 92447 |
> 6 | 92453 | 19789 |
> 0
> (1 row)
>
> So I am getting correct results with the multi-pass vacuum.
I have done some testing for the parallel "create index".
postgres[99536]=# show maintenance_work_mem ;
maintenance_work_mem
----------------------
1MB
(1 row)
CREATE TABLE test (a int, b int);
INSERT INTO test SELECT i, i FROM GENERATE_SERIES(1,2000000) as i;
CREATE INDEX idx1 on test(a);
select query, total_time, shared_blks_hit, shared_blks_read,
shared_blks_hit + shared_blks_read as total_read_blks,
shared_blks_dirtied, shared_blks_written from pg_stat_statements where
query like 'CREATE INDEX%';
SET max_parallel_maintenance_workers TO 0;
query | total_time | shared_blks_hit |
shared_blks_read | total_read_blks | shared_blks_dirtied |
shared_blks_written
------------------------------+--------------------+-----------------+------------------+-----------------+---------------------+---------------------
CREATE INDEX idx1 on test(a) | 1947.4959979999999 | 8947 |
11 | 8958 | 5 |
0
SET max_parallel_maintenance_workers TO 2;
query | total_time | shared_blks_hit |
shared_blks_read | total_read_blks | shared_blks_dirtied |
shared_blks_written
------------------------------+--------------------+-----------------+------------------+-----------------+---------------------+---------------------
CREATE INDEX idx1 on test(a) | 1942.1426040000001 | 8960 |
14 | 8974 | 5 |
0
(1 row)
I have noticed that the total_read_blks, with the parallel, create
index is more compared to non-parallel one. I have created a fresh
database before each run. I am not much aware of the internal code of
parallel create an index so I am not sure whether it is expected to
read extra blocks with the parallel create an index. I guess maybe
because multiple workers are inserting int the btree they might need
to visit some btree nodes multiple times while traversing the tree
down. But, it's better if someone who have more idea with this code
can confirm this.
--
Regards,
Dilip Kumar
EnterpriseDB: http://www.enterprisedb.com