Thread: Why does VACUUM FULL pg_class sometimes wait for ShareLock on another transaction after getting AccessExclusiveLock on pg_class?

Why does VACUUM FULL pg_class sometimes wait for ShareLock on another transaction after getting AccessExclusiveLock on pg_class?

From

Marcin Barczynski

Date:

22 July 2021, 13:55:58

There was a long-running transaction consisting of two queries:

CREATE TEMPORARY TABLE abc AS SELECT * FROM def_view;
INSERT INTO xyz_table SELECT * FROM abc;

When I ran VACUUM FULL pg_class, it waited for ShareLock on that transaction:

postgres=# select * from pg_locks where pid = 29563;
locktype | database | relation | page | tuple | virtualxid | transactionid | classid | objid | objsubid | virtualtransaction | pid | mode | granted | fastpath
---------------+----------+------------+------+-------+------------+---------------+---------+-------+----------+--------------------+-------+---------------------+---------+----------
virtualxid | | | | | 414/5739 | | | | | 414/5739 | 29563 | ExclusiveLock | t | t
relation | 16517 | 1259 | | | | | | | | 414/5739 | 29563 | ShareLock | t | f
relation | 16517 | 1259 | | | | | | | | 414/5739 | 29563 | AccessExclusiveLock | t | f
relation | 16517 | 1325035831 | | | | | | | | 414/5739 | 29563 | AccessExclusiveLock | t | f
transactionid | | | | | | 113559773 | | | | 414/5739 | 29563 | ExclusiveLock | t | f
transactionid | | | | | | 113551212 | | | | 414/5739 | 29563 | ShareLock | f | f
relation | 16517 | 2662 | | | | | | | | 414/5739 | 29563 | AccessExclusiveLock | t | f
(7 rows)

Why?
What's more interesting is that from time to time vacuum succeeded despite the fact that the long-running transaction was still running.

I tried to reproduce it by simulating the long-running transaction, and running VACUUM FULL pg_class in another transaction, but to no avail:

psql #1:
q=# CREATE TABLE demo AS SELECT generate_series(1, 1000);
SELECT 1000
q=# CREATE VIEW demo_view AS SELECT * FROM demo;
CREATE VIEW
q=# CREATE TABLE result (val BIGINT);
CREATE TABLE

q=# BEGIN;
BEGIN
q=*# CREATE TEMP TABLE abc AS SELECT * FROM demo_view;
SELECT 1000
q=*# INSERT INTO result SELECT * FROM abc;
INSERT 0 1000
q=*#

psql #2:
q=# VACUUM FULL pg_class;
VACUUM

--
Regards,
Marcin Barczynski

Re: Why does VACUUM FULL pg_class sometimes wait for ShareLock on another transaction after getting AccessExclusiveLock on pg_class?

From

Marcin Barczynski

Date:

22 July 2021, 18:08:25

On Thu, Jul 22, 2021 at 3:51 PM Laurenz Albe <laurenz.albe@cybertec.at> wrote:
>
> On Thu, 2021-07-22 at 12:55 +0200, Marcin Barczynski wrote:
> > There was a long-running transaction consisting of two queries:
> >
> > CREATE TEMPORARY TABLE abc AS SELECT * FROM def_view;
> > INSERT INTO xyz_table SELECT * FROM abc;
> >
> > When I ran VACUUM FULL pg_class, it waited for ShareLock on that transaction:
>
> There must have been something else using "pg_class", since the above
> won't take any permament locks on "pg_class", nor should it block VACUUM.

Thanks for your reply. I dugged a bit deeper, and it turned out that VACUUM FULL hung in heapam_index_build_range_scan.
It's PostgreSQL 13.3. Comments around heapam_handler.c:1482:

/*
* Since caller should hold ShareLock or better, normally
* the only way to see this is if it was inserted earlier
* in our own transaction. However, it can happen in
* system catalogs, since we tend to release write lock
* before commit there. Give a warning if neither case
* applies.
*/

/*
* If we are performing uniqueness checks, indexing
* such a tuple could lead to a bogus uniqueness
* failure. In that case we wait for the inserting
* transaction to finish and check again.
*/

Not sure how to interpret those comments, as:
- on the one hand, the long running transaction created a temporary table, so it had to update pg_class,

- but on the other hand pg_locks showed no sign of lock on any of 3 indexes of pg_class, and locks once obtained are kept till the end of transaction.

Full stack trace below:

#0 0x00007f3537b52e43 in ?? () from /lib64/libc.so.6
#1 0x000000000076d0ae in WaitEventSetWaitBlock (nevents=1, occurred_events=0x7ffd7bae7620, cur_timeout=-1, set=0x26c2570) at latch.c:1295
#2 WaitEventSetWait (set=set@entry=0x26c2570, timeout=timeout@entry=-1, occurred_events=occurred_events@entry=0x7ffd7bae7620, nevents=nevents@entry=1, wait_event_info=wait_event_info@entry=50331653) at latch.c:1247
#3 0x000000000076d52d in WaitLatchOrSocket (latch=0x2aacc9ed95e4, wakeEvents=wakeEvents@entry=33, sock=sock@entry=-1, timeout=-1, timeout@entry=0, wait_event_info=50331653) at latch.c:428
#4 0x000000000076d600 in WaitLatch (latch=<optimized out>, wakeEvents=wakeEvents@entry=33, timeout=timeout@entry=0, wait_event_info=<optimized out>) at latch.c:368
#5 0x000000000078625f in ProcSleep (locallock=locallock@entry=0x25c4c90, lockMethodTable=lockMethodTable@entry=0x9fa160 <default_lockmethod>) at proc.c:1292
#6 0x000000000077a4a2 in WaitOnLock (locallock=locallock@entry=0x25c4c90, owner=owner@entry=0x261cf58) at lock.c:1859
#7 0x000000000077b7cf in LockAcquireExtended (locktag=locktag@entry=0x7ffd7bae79a0, lockmode=lockmode@entry=5, sessionLock=sessionLock@entry=false, dontWait=dontWait@entry=false, reportMemoryError=reportMemoryError@entry=true, locallockp=locallockp@entry=0x0) at lock.c:1101
#8 0x000000000077c024 in LockAcquire (locktag=locktag@entry=0x7ffd7bae79a0, lockmode=lockmode@entry=5, sessionLock=sessionLock@entry=false, dontWait=dontWait@entry=false) at lock.c:752
#9 0x0000000000779758 in XactLockTableWait (xid=xid@entry=113551215, rel=rel@entry=0x7f353a2bcdd8, ctid=ctid@entry=0x26c2194, oper=oper@entry=XLTW_InsertIndexUnique) at lmgr.c:673
#10 0x00000000004ce843 in heapam_index_build_range_scan (heapRelation=0x7f353a2bcdd8, indexRelation=0x7f353a387678, indexInfo=0x26c2030, allow_sync=<optimized out>, anyvisible=false, progress=true, start_blockno=0, numblocks=4294967295, callback=0x4e80e0 <_bt_build_callback>,
callback_state=0x7ffd7bae7e70, scan=0x26c2140) at heapam_handler.c:1482
#11 0x00000000004e828a in table_index_build_scan (scan=<optimized out>, callback_state=0x7ffd7bae7e70, callback=0x4e80e0 <_bt_build_callback>, progress=true, allow_sync=true, index_info=0x26c2030, index_rel=<optimized out>, table_rel=<optimized out>)
at ../../../../src/include/access/tableam.h:1536
#12 _bt_parallel_scan_and_sort (btspool=btspool@entry=0x26c1fe0, btspool2=0x0, btshared=0x7f353a3fa300, sharedsort=0x7f353a3fa2a0, sharedsort2=0x0, sortmem=<optimized out>, progress=progress@entry=true) at nbtsort.c:1970
#13 0x00000000004e9017 in _bt_leader_participate_as_worker (buildstate=<optimized out>, buildstate=<optimized out>) at nbtsort.c:1778
#14 _bt_begin_parallel (request=<optimized out>, isconcurrent=<optimized out>, buildstate=0x7ffd7bae7fb0) at nbtsort.c:1650
#15 _bt_spools_heapscan (indexInfo=0x26bf158, buildstate=0x7ffd7bae7fb0, index=..., heap=0x7f353a2bcdd8) at nbtsort.c:394
#16 btbuild (heap=0x7f353a2bcdd8, index=0x7f353a387678, indexInfo=0x26bf158) at nbtsort.c:326
#17 0x000000000053f3e6 in index_build (heapRelation=heapRelation@entry=0x7f353a2bcdd8, indexRelation=indexRelation@entry=0x7f353a387678, indexInfo=indexInfo@entry=0x26bf158, isreindex=isreindex@entry=true, parallel=parallel@entry=true) at index.c:2962
#18 0x0000000000541c73 in reindex_index (indexId=indexId@entry=2662, skip_constraint_checks=<optimized out>, persistence=persistence@entry=112 'p', options=options@entry=0) at index.c:3598
#19 0x0000000000542127 in reindex_relation (relid=relid@entry=1259, flags=flags@entry=18, options=options@entry=0) at index.c:3821
#20 0x00000000005ae37f in finish_heap_swap (OIDOldHeap=OIDOldHeap@entry=1259, OIDNewHeap=OIDNewHeap@entry=1325070585, is_system_catalog=is_system_catalog@entry=true, swap_toast_by_content=swap_toast_by_content@entry=false, check_constraints=check_constraints@entry=false,
is_internal=is_internal@entry=true, frozenXid=frozenXid@entry=113424494, cutoffMulti=cutoffMulti@entry=10214958, newrelpersistence=newrelpersistence@entry=112 'p') at cluster.c:1393
#21 0x00000000005aeb1d in rebuild_relation (verbose=<optimized out>, indexOid=0, OldHeap=<optimized out>) at cluster.c:587
#22 cluster_rel (tableOid=tableOid@entry=1259, indexOid=indexOid@entry=0, options=<optimized out>) at cluster.c:403
#23 0x000000000061d60b in vacuum_rel (relid=1259, relation=<optimized out>, params=params@entry=0x7ffd7bae87c0) at vacuum.c:1890

--
Regards,
Marcin Barczynski

Re: Why does VACUUM FULL pg_class sometimes wait for ShareLock on another transaction after getting AccessExclusiveLock on pg_class?

From

Marcin Barczynski

Date:

23 July 2021, 09:09:18

On Thu, Jul 22, 2021 at 5:08 PM Marcin Barczynski <mbarczynski@starfishstorage.com> wrote:

On Thu, Jul 22, 2021 at 3:51 PM Laurenz Albe <laurenz.albe@cybertec.at> wrote:
>
> On Thu, 2021-07-22 at 12:55 +0200, Marcin Barczynski wrote:
> > There was a long-running transaction consisting of two queries:
> >
> > CREATE TEMPORARY TABLE abc AS SELECT * FROM def_view;
> > INSERT INTO xyz_table SELECT * FROM abc;
> >
> > When I ran VACUUM FULL pg_class, it waited for ShareLock on that transaction:
>
> There must have been something else using "pg_class", since the above
> won't take any permament locks on "pg_class", nor should it block VACUUM.

Thanks for your reply. I dugged a bit deeper, and it turned out that VACUUM FULL hung in heapam_index_build_range_scan.
It's PostgreSQL 13.3. Comments around heapam_handler.c:1482:

What's more, running VACUUM FULL pg_class sometimes causes a deadlock with transactions using temp tables. For example:

DETAIL: Process 6703 waits for ShareLock on transaction 108850229; blocked by process 6591.
Process 6591 waits for AccessShareLock on relation 1259 of database 16517; blocked by process 6703.
Process 6703: VACUUM (FULL, VERBOSE, ANALYZE) pg_class
Process 6591: SELECT * FROM stored_procedure()

Isn't it a bug?
Is there any way to safely run VACUUM FULL pg_class?
My workload involves lots of temp tables, and I need to get rid of the bloat regularly.

--
Regards,
Marcin Barczynski

Re: Why does VACUUM FULL pg_class sometimes wait for ShareLock on another transaction after getting AccessExclusiveLock on pg_class?

From

Ninad Shah

Date:

23 July 2021, 17:46:43

Question 1 : What's a need to perform a VACUUM FULL operation on pg_class?

Question 2 : Ideally, a VACUUM FULL operation seeks an exclusive lock on a table, while I can see it waiting for a shared lock here. Why? (Not asking you)

Additionally, The situation you have described should be termed a "deadlock". Do you see any transaction getting rolled back?

Regards,

Ninad Shah

On Fri, 23 Jul 2021 at 11:39, Marcin Barczynski <mbarczynski@starfishstorage.com> wrote:

On Thu, Jul 22, 2021 at 5:08 PM Marcin Barczynski <mbarczynski@starfishstorage.com> wrote:
On Thu, Jul 22, 2021 at 3:51 PM Laurenz Albe <laurenz.albe@cybertec.at> wrote:
>
> On Thu, 2021-07-22 at 12:55 +0200, Marcin Barczynski wrote:
> > There was a long-running transaction consisting of two queries:
> >
> > CREATE TEMPORARY TABLE abc AS SELECT * FROM def_view;
> > INSERT INTO xyz_table SELECT * FROM abc;
> >
> > When I ran VACUUM FULL pg_class, it waited for ShareLock on that transaction:
>
> There must have been something else using "pg_class", since the above
> won't take any permament locks on "pg_class", nor should it block VACUUM.

Thanks for your reply. I dugged a bit deeper, and it turned out that VACUUM FULL hung in heapam_index_build_range_scan.
It's PostgreSQL 13.3. Comments around heapam_handler.c:1482:

What's more, running VACUUM FULL pg_class sometimes causes a deadlock with transactions using temp tables. For example:

DETAIL: Process 6703 waits for ShareLock on transaction 108850229; blocked by process 6591.
Process 6591 waits for AccessShareLock on relation 1259 of database 16517; blocked by process 6703.
Process 6703: VACUUM (FULL, VERBOSE, ANALYZE) pg_class
Process 6591: SELECT * FROM stored_procedure()

Isn't it a bug?
Is there any way to safely run VACUUM FULL pg_class?
My workload involves lots of temp tables, and I need to get rid of the bloat regularly.

--
Regards,
Marcin Barczynski

Re: Why does VACUUM FULL pg_class sometimes wait for ShareLock on another transaction after getting AccessExclusiveLock on pg_class?

From

Marcin Barczynski

Date:

26 July 2021, 18:41:44

On Fri, Jul 23, 2021 at 4:46 PM Ninad Shah <nshah.postgres@gmail.com> wrote:

Question 1 : What's a need to perform a VACUUM FULL operation on pg_class?

Workload requires many temp tables which cause huge bloat on pg_class - it sometimes has more than 2 GB.

Question 2 : Ideally, a VACUUM FULL operation seeks an exclusive lock on a table, while I can see it waiting for a shared lock here. Why? (Not asking you)

That's my question. I expected that once VACUUM FULL gets exclusive lock, it can finish. But that's not the case with pg_class.

Additionally, The situation you have described should be termed a "deadlock". Do you see any transaction getting rolled back?

Regards,
Ninad Shah

On Fri, 23 Jul 2021 at 11:39, Marcin Barczynski <mbarczynski@starfishstorage.com> wrote:
On Thu, Jul 22, 2021 at 5:08 PM Marcin Barczynski <mbarczynski@starfishstorage.com> wrote:
On Thu, Jul 22, 2021 at 3:51 PM Laurenz Albe <laurenz.albe@cybertec.at> wrote:
>
> On Thu, 2021-07-22 at 12:55 +0200, Marcin Barczynski wrote:
> > There was a long-running transaction consisting of two queries:
> >
> > CREATE TEMPORARY TABLE abc AS SELECT * FROM def_view;
> > INSERT INTO xyz_table SELECT * FROM abc;
> >
> > When I ran VACUUM FULL pg_class, it waited for ShareLock on that transaction:
>
> There must have been something else using "pg_class", since the above
> won't take any permament locks on "pg_class", nor should it block VACUUM.

Thanks for your reply. I dugged a bit deeper, and it turned out that VACUUM FULL hung in heapam_index_build_range_scan.
It's PostgreSQL 13.3. Comments around heapam_handler.c:1482:

What's more, running VACUUM FULL pg_class sometimes causes a deadlock with transactions using temp tables. For example:

DETAIL: Process 6703 waits for ShareLock on transaction 108850229; blocked by process 6591.
Process 6591 waits for AccessShareLock on relation 1259 of database 16517; blocked by process 6703.
Process 6703: VACUUM (FULL, VERBOSE, ANALYZE) pg_class
Process 6591: SELECT * FROM stored_procedure()

Isn't it a bug?
Is there any way to safely run VACUUM FULL pg_class?
My workload involves lots of temp tables, and I need to get rid of the bloat regularly.

--
Regards,
Marcin Barczynski

Marcin Barczyński | Senior Software Engineer  |

mbarczynski@starfishstorage.com | http://www.starfishstorage.com