Re: BUG #17438: Logical replication hangs on master after huge DB load

вт, 29 мар. 2022 г. в 15:03, Amit Kapila <amit(dot)kapila16(at)gmail(dot)com>:
> Is my understanding correct that this problem occurs only when you are
> doing large operations of tables that are not published (like C or D)
> in your case?

I do not try to do anything on published tables, because I do it on
partitions and I detach them first from published tables.

> It is difficult for me to deduce anything from the errors given. I
> think we need some more information from the logs to find the reason.
> One idea could be that we run the subscriber with log_min_messages as
> debug1 as that might give some more information in logs.

Most of errors are:
2022-03-31 13:05:22.228 MSK [993] LOG: received SIGHUP, reloading
configuration files
2022-03-31 13:05:22.233 MSK [993] LOG: parameter "log_min_messages"
changed to "debug1"
2022-03-31 13:05:34.393 MSK [1158752] DEBUG: autovacuum: processing
database "DB3"
2022-03-31 13:05:43.567 MSK [894778] node(at)DB DEBUG: serializing
snapshot to pg_logical/snapshots/57B-C88EF210.snap
2022-03-31 13:05:43.567 MSK [894781] node(at)DB DEBUG: serializing
snapshot to pg_logical/snapshots/57B-C88EF210.snap
2022-03-31 13:05:43.567 MSK [893220] node(at)DB DEBUG: serializing
snapshot to pg_logical/snapshots/57B-C88EF210.snap
2022-03-31 13:05:43.567 MSK [894670] node(at)DB DEBUG: serializing
snapshot to pg_logical/snapshots/57B-C88EF210.snap
2022-03-31 13:05:43.567 MSK [894873] node(at)DB DEBUG: serializing
snapshot to pg_logical/snapshots/57B-C88EF210.snap
2022-03-31 13:05:43.569 MSK [891054] node(at)DB DEBUG: serializing
snapshot to pg_logical/snapshots/57B-C88EF210.snap
2022-03-31 13:05:43.582 MSK [894781] node(at)DB DEBUG: updated xmin: 1 restart: 0
2022-03-31 13:05:43.583 MSK [894781] node(at)DB DEBUG: failed to
increase restart lsn: proposed 57B/C88EF210, after 57B/C88EF210,
current candidate 57B/C88EF210, current after 57B/C88EF210, flushed up
to 57B/C88EF210
2022-03-31 13:05:43.584 MSK [894778] node(at)DB DEBUG: updated xmin: 1 restart: 0
2022-03-31 13:05:43.584 MSK [894778] node(at)DB DEBUG: failed to
increase restart lsn: proposed 57B/C88EF210, after 57B/C88EF210,
current candidate 57B/C88EF210, current after 57B/C88EF210, flushed up
to 57B/C88EF210
2022-03-31 13:05:43.584 MSK [894670] node(at)DB DEBUG: updated xmin: 1 restart: 0
2022-03-31 13:05:43.584 MSK [894670] node(at)DB DEBUG: failed to
increase restart lsn: proposed 57B/C88EF210, after 57B/C88EF210,
current candidate 57B/C88EF210, current after 57B/C88EF210, flushed up
to 57B/C88EF210
2022-03-31 13:05:43.585 MSK [894873] node(at)DB DEBUG: updated xmin: 1 restart: 0
2022-03-31 13:05:43.586 MSK [894873] node(at)DB DEBUG: failed to
increase restart lsn: proposed 57B/C88EF210, after 57B/C88EF210,
current candidate 57B/C88EF210, current after 57B/C88EF210, flushed up
to 57B/C88EF210
2022-03-31 13:05:43.586 MSK [891054] node(at)DB DEBUG: updated xmin: 1 restart: 0
2022-03-31 13:05:43.586 MSK [893220] node(at)DB DEBUG: updated xmin: 1 restart: 0
2022-03-31 13:05:43.586 MSK [891054] node(at)DB DEBUG: failed to
increase restart lsn: proposed 57B/C88EF210, after 57B/C88EF210,
current candidate 57B/C88EF210, current after 57B/C88EF210, flushed up
to 57B/C88EF210
2022-03-31 13:05:43.586 MSK [893220] node(at)DB DEBUG: failed to
increase restart lsn: proposed 57B/C88EF210, after 57B/C88EF210,
current candidate 57B/C88EF210, current after 57B/C88EF210, flushed up
to 57B/C88EF210
2022-03-31 13:05:43.588 MSK [894781] node(at)DB DEBUG: updated xmin: 0 restart: 1
2022-03-31 13:05:43.591 MSK [894778] node(at)DB DEBUG: updated xmin: 0 restart: 1
2022-03-31 13:05:43.591 MSK [894670] node(at)DB DEBUG: updated xmin: 0 restart: 1
2022-03-31 13:05:43.592 MSK [893220] node(at)DB DEBUG: updated xmin: 0 restart: 1
2022-03-31 13:05:43.592 MSK [891054] node(at)DB DEBUG: updated xmin: 0 restart: 1
2022-03-31 13:05:43.592 MSK [894873] node(at)DB DEBUG: updated xmin: 0 restart: 1
2022-03-31 13:05:46.393 MSK [1158756] DEBUG: autovacuum: processing
database "DB"
2022-03-31 13:05:58.396 MSK [1158759] DEBUG: autovacuum: processing
database "postgres"
2022-03-31 13:06:02.044 MSK [893220] node(at)DB DEBUG: serializing
snapshot to pg_logical/snapshots/57B-C8925660.snap
2022-03-31 13:06:02.044 MSK [894873] node(at)DB DEBUG: serializing
snapshot to pg_logical/snapshots/57B-C8925660.snap
2022-03-31 13:06:02.044 MSK [891054] node(at)DB DEBUG: serializing
snapshot to pg_logical/snapshots/57B-C8925660.snap
2022-03-31 13:06:02.044 MSK [894670] node(at)DB DEBUG: serializing
snapshot to pg_logical/snapshots/57B-C8925660.snap
2022-03-31 13:06:02.044 MSK [894778] node(at)DB DEBUG: serializing
snapshot to pg_logical/snapshots/57B-C8925660.snap
2022-03-31 13:06:02.045 MSK [894781] node(at)DB DEBUG: serializing
snapshot to pg_logical/snapshots/57B-C8925660.snap
2022-03-31 13:06:02.051 MSK [894778] node(at)DB DEBUG: got new restart
lsn 57B/C88EF210 at 57B/C8925660
2022-03-31 13:06:02.052 MSK [894670] node(at)DB DEBUG: got new restart
lsn 57B/C88EF210 at 57B/C8925660
2022-03-31 13:06:02.052 MSK [894781] node(at)DB DEBUG: got new restart
lsn 57B/C88EF210 at 57B/C8925660
2022-03-31 13:06:02.052 MSK [893220] node(at)DB DEBUG: got new restart
lsn 57B/C88EF210 at 57B/C8925660
2022-03-31 13:06:02.052 MSK [891054] node(at)DB DEBUG: got new restart
lsn 57B/C88EF210 at 57B/C8925660
2022-03-31 13:06:02.052 MSK [894873] node(at)DB DEBUG: got new restart
lsn 57B/C88EF210 at 57B/C8925660
2022-03-31 13:06:02.055 MSK [894778] node(at)DB DEBUG: updated xmin: 0 restart: 1
2022-03-31 13:06:02.059 MSK [894873] node(at)DB DEBUG: updated xmin: 0 restart: 1
2022-03-31 13:06:02.065 MSK [894781] node(at)DB DEBUG: updated xmin: 0 restart: 1
2022-03-31 13:06:02.065 MSK [891054] node(at)DB DEBUG: updated xmin: 0 restart: 1
2022-03-31 13:06:02.066 MSK [894670] node(at)DB DEBUG: updated xmin: 0 restart: 1
2022-03-31 13:06:02.081 MSK [893220] node(at)DB DEBUG: updated xmin: 0 restart: 1

log file is attached.

Sergey Belyashov