MIME-Version: 1.0
References: <17268-d2fb426e0895abd4@postgresql.org>
 <CAH2-Wznen2nOrUB32LrsuF4uGfDF1s_VZzDjhOYfLKo5H1g8Yw@mail.gmail.com>
 <CAK-MWwQBMWOwEJx+DCTnXOrqjg00wMbXwc60hkZD=Q9WmUsChg@mail.gmail.com>
 <CAH2-Wz=Sk=5WCt1T+7cReAuDoggJkiNxeCD73ODm6jfrLu4y1w@mail.gmail.com>
 <CAK-MWwTFEPE+9VJVh_T4HQa5ZH28MgOfHiznk05-Zj+ZnZn2RQ@mail.gmail.com>
In-Reply-To: 
 <CAK-MWwTFEPE+9VJVh_T4HQa5ZH28MgOfHiznk05-Zj+ZnZn2RQ@mail.gmail.com>
From: Maxim Boguk <maxim.boguk@gmail.com>
Date: Thu, 4 Nov 2021 22:01:44 +0200
Message-ID: 
 <CAK-MWwTEWO2zzV-1ddm2mpurdv_3wAXwB3u_eh5W7xHM+SrsMQ@mail.gmail.com>
Subject: Re: BUG #17268: Possible corruption in toast index after reindex
 index concurrently
To: Peter Geoghegan <pg@bowt.ie>
Cc: Alexey Ermakov <alexey.ermakov@dataegret.com>,
	PostgreSQL mailing lists <pgsql-bugs@lists.postgresql.org>,
 Michael Paquier <michael@paquier.xyz>
Content-Type: text/plain; charset="UTF-8"
Content-Transfer-Encoding: quoted-printable
Archived-At: 
 <https://www.postgresql.org/message-id/CAK-MWwTEWO2zzV-1ddm2mpurdv_3wAXwB3u_eh5W7xHM%2BSrsMQ%40mail.gmail.com>
Precedence: bulk

On Thu, Nov 4, 2021 at 9:47 PM Maxim Boguk <maxim.boguk@gmail.com> wrote:
>
> On Thu, Nov 4, 2021 at 8:18 PM Peter Geoghegan <pg@bowt.ie> wrote:
> >
> > On Thu, Nov 4, 2021 at 11:08 AM Maxim Boguk <maxim.boguk@gmail.com> wro=
te:
> > > select bt_index_check('pg_toast.pg_toast_2624976286_index', true);
> > > DEBUG:  verifying consistency of tree structure for index
> > > "pg_toast_2624976286_index"
> > > DEBUG:  verifying level 3 (true root level)
> > > DEBUG:  verifying level 2
> > > DEBUG:  verifying level 1
> > > DEBUG:  verifying level 0 (leaf level)
> > > DEBUG:  leaf block 715360 of index "pg_toast_2624976286_index" has no
> > > first data item
> > > DEBUG:  verifying that tuples from index "pg_toast_2624976286_index"
> > > are present in "pg_toast_2624976286"
> > > ERROR:  heap tuple (59561917,1) from table "pg_toast_2624976286" lack=
s
> > > matching index tuple within index "pg_toast_2624976286_index"
> > > HINT:  Retrying verification using the function
> > > bt_index_parent_check() might provide a more specific error.
> >
> > That's an unusually large TOAST table. It's at least ~454.42GiB, based
> > on this error. Is the block number 59561917 near the end of the table?
>
> select pg_size_pretty(pg_relation_size('pg_toast.pg_toast_2624976286'));
>  pg_size_pretty
> ----------------
>  473 GB
> now... and yes during the time of error page 59561917 was very close
> to the end of the table.
> There was a high chance (but not 100%) that the corresponding main
> table entry had been inserted during reindex CONCURRENTLY of the toast
> index run.

UPDATE: the problem base table entry which had erroneous toast data
definitely had been created during the REINDEX run of toast idx.

2021-11-02 13:15:45.469 UTC 2379 postgres@*** from [local] [vxid:24/0
txid:0] [REINDEX] LOG:  duration: 1719120.441 ms  statement: REINDEX
INDEX CONCURRENTLY pg_toast.pg_toast_2624976286_index
and the problem entry had been created at 2021-11-02 13:04:22.192125 UTC.

So there seems some subtle bug with indexing new toast data during
REINDEX INDEX CONCURRENTLY of the toast index.
--=20
Maxim Boguk
Senior Postgresql DBA
https://dataegret.com/

Phone RU: +7  985 433 0000
Phone UA: +380 99 143 0000
Phone AU: +61  45 218 5678

LinkedIn: http://www.linkedin.com/pub/maksym-boguk/80/b99/b1b
Skype: maxim.boguk

"=D0=94=D0=BE=D0=BA=D1=82=D0=BE=D1=80, =D0=B2=D1=8B =D0=BC=D0=BD=D0=B5 =D1=
=81=D0=BE=D0=B2=D0=B5=D1=82=D0=BE=D0=B2=D0=B0=D0=BB=D0=B8 =D1=82=D0=B0=D0=
=BA =D0=BD=D0=B5 =D0=B4=D0=B5=D0=BB=D0=B0=D1=82=D1=8C, =D0=BD=D0=BE =D0=BF=
=D0=BE=D1=87=D0=B5=D0=BC=D1=83 =D0=BC=D0=BD=D0=B5 =D0=BF=D0=BE-=D0=BF=D1=80=
=D0=B5=D0=B6=D0=BD=D0=B5=D0=BC=D1=83
=D0=B1=D0=BE=D0=BB=D1=8C=D0=BD=D0=BE =D0=BA=D0=BE=D0=B3=D0=B4=D0=B0 =D1=8F =
=D1=82=D0=B0=D0=BA =D0=B4=D0=B5=D0=BB=D0=B0=D1=8E =D0=B5=D1=89=D1=91 =D1=80=
=D0=B0=D0=B7?"