pg.ddx.io pgsql-bugs@postgresql.org mailing list archive
help / color / mirror / Atom feedBUG #17586: Look like there are an another bug in REINDEX INDEX CONCURRENTLY of pg_toast indexes
4+ messages / 3 participants
[nested] [flat]
* BUG #17586: Look like there are an another bug in REINDEX INDEX CONCURRENTLY of pg_toast indexes
@ 2022-08-15 11:36 PG Bug reporting form <noreply@postgresql.org>
0 siblings, 1 reply; 4+ messages in thread
From: PG Bug reporting form @ 2022-08-15 11:36 UTC (permalink / raw)
To: pgsql-bugs@lists.postgresql.org; +Cc: maxim.boguk@gmail.com
The following bug has been logged on the website:
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
2022-08-11 02:47:28.927 UTC 1187482 postgres@***_exports from [local]
[vxid:14/66875173 txid:0] [REINDEX] STATEMENT: REINDEX INDEX CONCURRENTLY
pg_toast.pg_toast_2502234687_index
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/1.0", size 8192
2022-08-11 02:47:28.927 UTC 1187482 postgres@***_exports from [local]
[vxid:14/66875173 txid:0] [REINDEX] STATEMENT: REINDEX INDEX CONCURRENTLY
pg_toast.pg_toast_2502234687_index
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/0.0", size 8192
2022-08-11 02:47:28.927 UTC 1187482 postgres@***_exports from [local]
[vxid:14/66875173 txid:0] [REINDEX] STATEMENT: REINDEX INDEX CONCURRENTLY
pg_toast.pg_toast_2502234687_index
2022-08-11 02:47:28.965 UTC 1187482 postgres@***_exports from [local]
[vxid:14/66875173 txid:0] [REINDEX] LOG: temporary file: path
"base/pgsql_tmp/pgsql_tmp1187482.0.sharedfileset/2.0", size 252370944
2022-08-11 02:47:28.965 UTC 1187482 postgres@***_exports from [local]
[vxid:14/66875173 txid:0] [REINDEX] STATEMENT: REINDEX INDEX CONCURRENTLY
pg_toast.pg_toast_2502234687_index
2022-08-11 02:47:29.003 UTC 1187482 postgres@***_exports from [local]
[vxid:14/66875173 txid:0] [REINDEX] LOG: temporary file: path
"base/pgsql_tmp/pgsql_tmp1187482.0.sharedfileset/1.0", size 253599744
2022-08-11 02:47:29.003 UTC 1187482 postgres@***_exports from [local]
[vxid:14/66875173 txid:0] [REINDEX] STATEMENT: REINDEX INDEX CONCURRENTLY
pg_toast.pg_toast_2502234687_index
2022-08-11 02:47:29.041 UTC 1187482 postgres@***_exports from [local]
[vxid:14/66875173 txid:0] [REINDEX] LOG: temporary file: path
"base/pgsql_tmp/pgsql_tmp1187482.0.sharedfileset/0.0", size 251535360
2022-08-11 02:47:29.041 UTC 1187482 postgres@***_exports from [local]
[vxid:14/66875173 txid:0] [REINDEX] STATEMENT: REINDEX INDEX CONCURRENTLY
pg_toast.pg_toast_2502234687_index
2022-08-11 02:47:30.023 UTC 1175180 ***_push@***_exports from [local]
[vxid:12/63545272 txid:354389107] [INSERT] LOG: duration: 1991.666 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:55.962 UTC 1175180 ***_push@***_exports from [local]
[vxid:12/63545274 txid:354389164] [INSERT] LOG: duration: 4027.248 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:48:02.883 UTC 1175180 ***_push@***_exports from [local]
[vxid:12/63545275 txid:354389277] [INSERT] LOG: duration: 1055.236 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:48:24.914 UTC 1175180 ***_push@***_exports from [local]
[vxid:12/63545278 txid:354389390] [INSERT] LOG: duration: 2020.759 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:48:49.512 UTC 1184504 ***_field_sync@***_exports from [local]
[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
2022-08-11 02:48:49.651 UTC 1187482 postgres@***_exports from [local]
[vxid:14/0 txid:0] [REINDEX] LOG: duration: 187669.153 ms statement:
REINDEX INDEX CONCURRENTLY pg_toast.pg_toast_2502234687_index
2022-08-11 02:48:50.048 UTC 1184504 ***_field_sync@***_exports from [local]
[vxid:10/63478398 txid:0] [SELECT] ERROR: missing chunk number 0 for toast
value 2546878502 in pg_toast_2502234687
2022-08-11 02:48:50.048 UTC 1184504 ***_field_sync@***_exports from [local]
[vxid:10/63478398 txid:0] [SELECT] STATEMENT: SELECT field_ids FROM
exports_new WHERE field_board_id = $1 AND field_id_mod_256 = $2 AND epoch =
$3
and so on...
A follow-up secondary manual REINDEX INDEX CONCURRENTLY
pg_toast.pg_toast_2502234687_index resolved the problem with damaged
toast.
Problems do not always happen (rarely) and I cannot build a quick reproducer
so far.
Kind Regards,
Maxim
^ permalink raw reply [nested|flat] 4+ messages in thread
* Re: BUG #17586: Look like there are an another bug in REINDEX INDEX CONCURRENTLY of pg_toast indexes
@ 2022-08-15 23:01 Andres Freund <andres@anarazel.de>
parent: PG Bug reporting form <noreply@postgresql.org>
0 siblings, 1 reply; 4+ messages in thread
From: Andres Freund @ 2022-08-15 23:01 UTC (permalink / raw)
To: maxim.boguk@gmail.com; pgsql-bugs@lists.postgresql.org
Hi,
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.
Greetings,
Andres Freund
^ permalink raw reply [nested|flat] 4+ messages in thread
* Re: BUG #17586: Look like there are an another bug in REINDEX INDEX CONCURRENTLY of pg_toast indexes
@ 2022-08-16 08:34 Maxim Boguk <maxim.boguk@gmail.com>
parent: Andres Freund <andres@anarazel.de>
0 siblings, 1 reply; 4+ messages in thread
From: Maxim Boguk @ 2022-08-16 08:34 UTC (permalink / raw)
To: Andres Freund <andres@anarazel.de>; +Cc: pgsql-bugs@lists.postgresql.org
On Tue, Aug 16, 2022 at 1:01 AM Andres Freund <andres@anarazel.de> wrote:
> Hi,
>
> 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.
--
Maxim Boguk
Senior Postgresql DBA
https://dataegret.com/
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
"Доктор, вы мне советовали так не делать, но почему мне по-прежнему больно
когда я так делаю ещё раз?"
^ permalink raw reply [nested|flat] 4+ messages in thread
* Re: BUG #17586: Look like there are an another bug in REINDEX INDEX CONCURRENTLY of pg_toast indexes
@ 2022-08-17 01:18 Andres Freund <andres@anarazel.de>
parent: Maxim Boguk <maxim.boguk@gmail.com>
0 siblings, 0 replies; 4+ messages in thread
From: Andres Freund @ 2022-08-17 01:18 UTC (permalink / raw)
To: Maxim Boguk <maxim.boguk@gmail.com>; +Cc: pgsql-bugs@lists.postgresql.org
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
^ permalink raw reply [nested|flat] 4+ messages in thread
end of thread, other threads:[~2022-08-17 01:18 UTC | newest]
Thread overview: 4+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2022-08-15 11:36 BUG #17586: Look like there are an another bug in REINDEX INDEX CONCURRENTLY of pg_toast indexes PG Bug reporting form <noreply@postgresql.org>
2022-08-15 23:01 ` Andres Freund <andres@anarazel.de>
2022-08-16 08:34 ` Maxim Boguk <maxim.boguk@gmail.com>
2022-08-17 01:18 ` Andres Freund <andres@anarazel.de>
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox