circular wait not triggering deadlock ? - Mailing list pgsql-general

Running pg10.2, I have a handful of maintenance jobs run in the middle of the
night, which appear to have gotten stuck waiting on each other..

 . reindex - loop around pg_repack or psql -c REINDEX $table for those which can't
   be repacked)
 . vacuum - mostly runs ANALYZE, like on empty parent tables

I believe I've come across something similar before, but hadn't previously
stopped to dig into it.

ts=# SELECT * FROM pg_stat_activity WHERE pid=20488;
-[ RECORD 1
]----+------------------------------------------------------------------------------------------------------------------------------------------
datid            | 16402
datname          | ts
pid              | 20488
usesysid         | 10
usename          | postgres
application_name | pg_repack
client_addr      | 
client_hostname  | 
client_port      | -1
backend_start    | 2018-03-07 01:00:15.72433-07
xact_start       | 2018-03-07 01:00:15.747619-07
query_start      | 2018-03-07 01:00:15.747619-07
state_change     | 2018-03-07 01:00:15.74762-07
wait_event_type  | Lock
wait_event       | virtualxid
state            | active
backend_xid      | 
backend_xmin     | 
query            | CREATE INDEX CONCURRENTLY index_1113966210 ON eric_enodeb_cell_20180304 USING btree (site_id) WITH
(fillfactor='100')TABLESPACE oldindex
 
backend_type     | client backend

ts=# SELECT * FROM pg_stat_activity WHERE pid=530;
-[ RECORD 1 ]----+--------------------------------------------------------------------------
datid            | 16402
datname          | ts
pid              | 530
usesysid         | 10
usename          | postgres
application_name | psql
client_addr      | 
client_hostname  | 
client_port      | -1
backend_start    | 2018-03-07 02:11:59.00832-07
xact_start       | 2018-03-07 02:11:59.009855-07
query_start      | 2018-03-07 02:11:59.009855-07
state_change     | 2018-03-07 02:11:59.009861-07
wait_event_type  | Lock
wait_event       | relation
state            | active
backend_xid      | 
backend_xmin     | 67578467
query            | ALTER TABLE eric_enodeb_cell_metrics* ALTER start_time SET STATISTICS 400
backend_type     | client backend

ts=# SELECT relation::regclass, granted, * FROM pg_locks WHERE (pid=530 AND NOT granted) OR
relation='eric_enodeb_cell_20180304'::regclass;--  virtualxid='16/38159763' OR
relation='eric_enodeb_cell_metrics'::regclassORDER BY 1,2,3;
 
         relation          | granted | locktype | database |  relation  | page | tuple | virtualxid | transactionid |
classid| objid | objsubid | virtualtransaction |  pid  |           mode           | granted | fastpath 
 

---------------------------+---------+----------+----------+------------+------+-------+------------+---------------+---------+-------+----------+--------------------+-------+--------------------------+---------+----------
 eric_enodeb_cell_20180304 | t       | relation |    16402 | 1113966172 |      |       |            |               |
     |       |          | 19/28401734        | 20488 | ShareUpdateExclusiveLock | t       | f
 
 eric_enodeb_cell_20180304 | f       | relation |    16402 | 1113966172 |      |       |            |               |
     |       |          | 16/38159763        |   530 | ShareUpdateExclusiveLock | f       | f
 

I see PID 530 has ShareUpdateExclusiveLock on many child tables.
..but NOT on eric_enodeb_cell_20180304 , which #20488 is trying to reindex.

ts=# SELECT granted, relation::regclass, * FROM pg_locks WHERE pid=530 OR relation='eric_enodeb_cell_metrics'::regclass
ORDERBY 1, 2, 3;
 
 granted |         relation          |  locktype  | database |  relation  | page | tuple | virtualxid  | transactionid
|classid | objid | objsubid | virtualtransaction |  pid  |           mode           | granted | fastpath 
 

---------+---------------------------+------------+----------+------------+------+-------+-------------+---------------+---------+-------+----------+--------------------+-------+--------------------------+---------+----------
 f       | eric_enodeb_cell_metrics  | relation   |    16402 |  948644697 |      |       |             |
|        |       |          | 32/838769          | 18941 | AccessShareLock          | f       | f
 
 f       | eric_enodeb_cell_metrics  | relation   |    16402 |  948644697 |      |       |             |
|        |       |          | 18/38156962        | 16592 | AccessExclusiveLock      | f       | f
 
 f       | eric_enodeb_cell_metrics  | relation   |    16402 |  948644697 |      |       |             |
|        |       |          | 31/1337307         | 22961 | AccessShareLock          | f       | f
 
 f       | eric_enodeb_cell_metrics  | relation   |    16402 |  948644697 |      |       |             |
|        |       |          | 27/1755026         | 17248 | AccessShareLock          | f       | f
 
 f       | eric_enodeb_cell_metrics  | relation   |    16402 |  948644697 |      |       |             |
|        |       |          | 28/1118276         | 28357 | AccessShareLock          | f       | f
 
 f       | eric_enodeb_cell_metrics  | relation   |    16402 |  948644697 |      |       |             |
|        |       |          | 29/830016          | 21846 | AccessExclusiveLock      | f       | f
 
 f       | eric_enodeb_cell_20180304 | relation   |    16402 | 1113966172 |      |       |             |
|        |       |          | 16/38159763        |   530 | ShareUpdateExclusiveLock | f       | f
 
 t       | eric_enodeb_cell_201609   | relation   |    16402 |  193318232 |      |       |             |
|        |       |          | 16/38159763        |   530 | ShareUpdateExclusiveLock | t       | f
 
 t       | eric_enodeb_cell_201610   | relation   |    16402 |  193318241 |      |       |             |
|        |       |          | 16/38159763        |   530 | ShareUpdateExclusiveLock | t       | f
 
 t       | eric_enodeb_cell_201611   | relation   |    16402 |  206004215 |      |       |             |
|        |       |          | 16/38159763        |   530 | ShareUpdateExclusiveLock | t       | f
 
 t       | eric_enodeb_cell_201612   | relation   |    16402 |  232980573 |      |       |             |
|        |       |          | 16/38159763        |   530 | ShareUpdateExclusiveLock | t       | f
 
 t       | eric_enodeb_cell_201701   | relation   |    16402 |  259721731 |      |       |             |
|        |       |          | 16/38159763        |   530 | ShareUpdateExclusiveLock | t       | f
 
 t       | eric_enodeb_cell_201702   | relation   |    16402 |  291841516 |      |       |             |
|        |       |          | 16/38159763        |   530 | ShareUpdateExclusiveLock | t       | f
 
 t       | eric_enodeb_cell_20170301 | relation   |    16402 |  384321707 |      |       |             |
|        |       |          | 16/38159763        |   530 | ShareUpdateExclusiveLock | t       | f
 
 t       | eric_enodeb_cell_20170302 | relation   |    16402 |  385254657 |      |       |             |
|        |       |          | 16/38159763        |   530 | ShareUpdateExclusiveLock | t       | f
 
 t       | eric_enodeb_cell_20170303 | relation   |    16402 |  386180686 |      |       |             |
|        |       |          | 16/38159763        |   530 | ShareUpdateExclusiveLock | t       | f
 
...

ts=# SELECT granted, relation::regclass, * FROM pg_locks WHERE pid=20488 ORDER BY 1,2,3;
-[ RECORD 1 ]------+--------------------------
granted            | f
locktype           | virtualxid
virtualxid         | 22/4317099
virtualtransaction | 19/28401734
pid                | 20488
mode               | ShareLock
granted            | f
fastpath           | f

ts=# SELECT granted, pid, mode, virtualtransaction, virtualxid FROM pg_locks WHERE virtualxid='22/4317099' ORDER BY
1,2,3;
 granted |  pid  |     mode      | virtualtransaction | virtualxid 
---------+-------+---------------+--------------------+------------
 f       | 20488 | ShareLock     | 19/28401734        | 22/4317099
 t       |  6471 | ExclusiveLock | 22/4317099         | 22/4317099

[pryzbyj@database ~]$ ps -O lstart -C reindex,pg_repack
  PID                  STARTED S TTY          TIME COMMAND
20038 Wed Mar  7 01:00:00 2018 S ?        00:00:00 /bin/sh /usr/local/sbin/reindex
20484 Wed Mar  7 01:00:14 2018 S ?        00:00:00 /bin/sh /usr/local/sbin/reindex
20485 Wed Mar  7 01:00:14 2018 S ?        00:00:00 /usr/pgsql-10/bin/pg_repack -E warning --no-kill-backend -d ts -i
eric_enodeb_cell_20180304_site_idx-Ss oldindex
 

Note, I believe last night our backup job would've run for longer and processed
(many) more tables than usual, looping around pg_dump --snapshot.

Is it a bug that this isn't caught by a deadlock detector and cancelled?

Thanks,
Justin