Re: BUG #17586: Look like there are an another bug in REINDEX INDEX CONCURRENTLY of pg_toast indexes

Hi,

On 2022-08-16 10:34:14 +0200, Maxim Boguk wrote:
> On Tue, Aug 16, 2022 at 1:01 AM Andres Freund <andres@anarazel.de> wrote:
> > On 2022-08-15 11:36:52 +0000, PG Bug reporting form wrote:
> > > Bug reference:      17586
> > > Logged by:          Maxim Boguk
> > > Email address:      maxim.boguk@gmail.com
> > > PostgreSQL version: 14.4
> > > Operating system:   Ubuntu Linux
> > > Description:
> > >
> > > Details about the data structure
> > > pg_toast.pg_toast_2502234687_index is index toast of exports_new_2022_32w
> > > partition of exports_new table (Partition key: RANGE (epoch))
> > >
> > > During the reindex job there were quite a lot new inserts into
> > > exports_new_2022_32w table via partition head.
> > >
> >
> > > 2022-08-11 02:46:16.972 UTC 1175180 ***_push@***_exports from [local]
> > > [vxid:12/63545267 txid:354388805] [INSERT] LOG:  duration: 2711.995 ms
> > >  statement: INSERT INTO exports_new(field_board_id, field_id_mod_256,
> > epoch,
> > > field_ids)
> > >                 (SELECT field_board_id, (field_id % 256)::int
> > > field_id_mod_256, epoch, ARRAY_AGG(field_id) AS field_ids FROM (SELECT
> > > field_board_id, epoch, unnest(field_ids) AS field_id FROM
> > temp_export_ids)
> > > t
> > >                 GROUP BY 1,2,3)
> > >
> > >
> > > 2022-08-11 02:47:28.927 UTC 1187482 postgres@***_exports from [local]
> > > [vxid:14/66875173 txid:0] [REINDEX] LOG:  temporary file: path
> > > "base/pgsql_tmp/pgsql_tmp1187482.1.sharedfileset/2.0", size 8192
> >
> >
> >
> > > [vxid:10/63478386 txid:0] [SELECT] ERROR:  missing chunk number 0 for
> > toast
> > > value 2546878653 in pg_toast_2502234687
> > > 2022-08-11 02:48:49.512 UTC 1184504 ***_field_sync@***_exports from
> > [local]
> > > [vxid:10/63478386 txid:0] [SELECT] STATEMENT:  SELECT field_ids FROM
> > > exports_new WHERE field_board_id = $1 AND field_id_mod_256 = $2 AND
> > epoch =
> > > $3
> >
> > Hm. What is the setup of this system? Do you have a hot_standby_feedback
> > enabled replica? Does it use replication slots? Did it reconnect at the
> > time?
> >
> > This issue could be due to the xmin horizon going backward, rather than a
> > bug
> > in reindex concurrently itself.
> >
> >
> > Too bad we don't have an errcontext set up for this, it'd be quite helpful
> > to
> > know what row the missing toast value is in, so we could check its
> > visibility.
> >
> 
> Hi,
> hot_standby_feedback enabled replica - yes (but with minimal activity)
> use replication slots - no and no other apps with replication slots
> Did it reconnect at the time - most definitely no, pg_stat_replication
> shows
> backend_start    | 2022-06-30 07:36:51.095073+00
> for replication connection.
> Also I have log_replication_commands enabled and nothing about replication
> logged during the last week.

Hm. How often does this occur? And could you run a server with a bit of added
debugging? Otherwise I don't see how we can narrow this down, unfortunately.

Greetings,

Andres Freund