Date: Fri, 30 Jul 2021 14:41:26 -0400
From: Noah Misch <noah@leadboat.com>
To: Andrey Borodin <x4mmm@yandex-team.ru>
Cc: Michael Paquier <michael@paquier.xyz>, Tom Lane <tgl@sss.pgh.pa.us>,
	pgsql-bugs@lists.postgresql.org
Subject: Re: CREATE INDEX CONCURRENTLY does not index prepared xact's data
Message-ID: <20210730184126.GA2018234@gust.leadboat.com>
References: <20210720214936.GA1040253@gust.leadboat.com>
 <E50B139F-5B6B-41F2-8F6D-CC474290CCBA@yandex-team.ru>
 <20210721175530.GA1090577@gust.leadboat.com>
 <946242CB-D63A-4D7B-A5A5-485165F5B78A@yandex-team.ru>
 <20210723223021.GA1354601@gust.leadboat.com>
 <845C714B-DBCF-49E9-9F95-238DB042F926@yandex-team.ru>
 <B8B5720D-B325-42B1-A5EF-ED01725503FA@yandex-team.ru>
 <ABABD793-1438-445B-879E-457499C2FC11@yandex-team.ru>
 <20210730022548.GA1940096@gust.leadboat.com>
 <A345A2B4-5041-4C95-9084-DC1BA83E3328@yandex-team.ru>
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Disposition: inline
Content-Transfer-Encoding: 8bit
In-Reply-To: <A345A2B4-5041-4C95-9084-DC1BA83E3328@yandex-team.ru>
Archived-At: 
 <https://www.postgresql.org/message-id/20210730184126.GA2018234%40gust.leadboat.com>
Precedence: bulk

On Fri, Jul 30, 2021 at 03:42:10PM +0500, Andrey Borodin wrote:
> > 30 июля 2021 г., в 07:25, Noah Misch <noah@leadboat.com> написал(а):
> > What alternative fix designs should we consider?
> 
> I observe that provided patch fixes CIC under normal transactions, but test with 2PC still fails similarly.
> Unindexed tuple was committed somewhere at the end of Phase 3 or 4.
> 2021-07-30 15:35:31.806 +05 [25987] 002_cic_2pc.pl LOG:  statement: REINDEX INDEX CONCURRENTLY idx;
> 2021-07-30 15:35:31.806 +05 [25987] 002_cic_2pc.pl WARNING:  Phase 1
> 2021-07-30 15:35:31.806 +05 [25987] 002_cic_2pc.pl WARNING:  Phase 2
> 2021-07-30 15:35:31.806 +05 [25987] 002_cic_2pc.pl WARNING:  XXX: VirtualXactLock vxid -1/6735
> 2021-07-30 15:35:31.807 +05 [25987] 002_cic_2pc.pl WARNING:  XXX: VirtualXactLock vxid -1/6736
> 2021-07-30 15:35:31.808 +05 [25987] 002_cic_2pc.pl WARNING:  Phase 3
> 2021-07-30 15:35:31.808 +05 [25987] 002_cic_2pc.pl WARNING:  XXX: VirtualXactLock vxid -1/6750
> 2021-07-30 15:35:31.809 +05 [25987] 002_cic_2pc.pl WARNING:  Phase 4
> 2021-07-30 15:35:31.809 +05 [25987] 002_cic_2pc.pl WARNING:  Phase 5
> 2021-07-30 15:35:31.809 +05 [25987] 002_cic_2pc.pl WARNING:  XXX: VirtualXactLock vxid -1/6762
> 2021-07-30 15:35:31.809 +05 [25987] 002_cic_2pc.pl WARNING:  XXX: VirtualXactLock vxid -1/6763
> 2021-07-30 15:35:31.810 +05 [25987] 002_cic_2pc.pl WARNING:  Phase 6
> 2021-07-30 15:35:31.810 +05 [25987] 002_cic_2pc.pl WARNING:  XXX: VirtualXactLock vxid 6/2166
> 2021-07-30 15:35:31.810 +05 [25987] 002_cic_2pc.pl WARNING:  XXX: VirtualXactLock vxid -1/6767
> 2021-07-30 15:35:31.810 +05 [25987] 002_cic_2pc.pl WARNING:  XXX: VirtualXactLock vxid -1/6764
> 2021-07-30 15:35:31.810 +05 [25987] 002_cic_2pc.pl WARNING:  XXX: VirtualXactLock vxid -1/6765
> 2021-07-30 15:35:31.811 +05 [25987] 002_cic_2pc.pl WARNING:  Phase Final
> 2021-07-30 15:35:31.811 +05 [25987] 002_cic_2pc.pl LOG:  statement: SELECT bt_index_check('idx',true);
> 2021-07-30 15:35:31.813 +05 [25987] 002_cic_2pc.pl ERROR:  heap tuple (46,16) from table "tbl" lacks matching index tuple within index "idx" xmin 6751 xmax 0

I see a failure, too.  Once again, "i:" lines are events within the INSERT
backend, and "r:" lines are events within the REINDEX CONCURRENTLY backend:

r: Phase 2 begins.
i: INSERT.  Start PREPARE.
r: Phase 2 commits indisready=t for idx_ccnew.
r: Start waiting for the INSERT to finish.
i: PREPARE finishes.
r: Wake up and start validate_index().  This is a problem.  It needed to wait
   for COMMIT PREPARED to finish.

This may have a different explanation than the failure you saw, because my
INSERT transaction already had a permanent XID before the start of phase 3.  I
won't have time to study this further in the next several days.  Can you find
out where things go wrong?  The next thing I would study is VirtualXactLock(),
specifically what happens if the lock holder is a normal backend (with or
without an XID) when VirtualXactLock() starts but becomes a prepared
transaction (w/ different PGPROC) before VirtualXactLock() ends.