[prev in list] [next in list] [prev in thread] [next in thread] 

List:       pgsql-bugs
Subject:    Re: BUG #17438: Logical replication hangs on master after huge DB load
From:       Sergey Belyashov <sergey.belyashov () gmail ! com>
Date:       2022-03-31 12:53:27
Message-ID: CAOe0RDwJsLHAjs+XfCPYFz4Uy3_nZtCj9SnOCQ1JLM6PgwxeTA () mail ! gmail ! com
[Download RAW message or body]


=D0=B2=D1=82, 29 =D0=BC=D0=B0=D1=80. 2022 =D0=B3. =D0=B2 15:03, Amit Kapila=
 <amit.kapila16@gmail.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@DB DEBUG:  serializing
snapshot to pg_logical/snapshots/57B-C88EF210.snap
2022-03-31 13:05:43.567 MSK [894781] node@DB DEBUG:  serializing
snapshot to pg_logical/snapshots/57B-C88EF210.snap
2022-03-31 13:05:43.567 MSK [893220] node@DB DEBUG:  serializing
snapshot to pg_logical/snapshots/57B-C88EF210.snap
2022-03-31 13:05:43.567 MSK [894670] node@DB DEBUG:  serializing
snapshot to pg_logical/snapshots/57B-C88EF210.snap
2022-03-31 13:05:43.567 MSK [894873] node@DB DEBUG:  serializing
snapshot to pg_logical/snapshots/57B-C88EF210.snap
2022-03-31 13:05:43.569 MSK [891054] node@DB DEBUG:  serializing
snapshot to pg_logical/snapshots/57B-C88EF210.snap
2022-03-31 13:05:43.582 MSK [894781] node@DB DEBUG:  updated xmin: 1 restar=
t: 0
2022-03-31 13:05:43.583 MSK [894781] node@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@DB DEBUG:  updated xmin: 1 restar=
t: 0
2022-03-31 13:05:43.584 MSK [894778] node@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@DB DEBUG:  updated xmin: 1 restar=
t: 0
2022-03-31 13:05:43.584 MSK [894670] node@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@DB DEBUG:  updated xmin: 1 restar=
t: 0
2022-03-31 13:05:43.586 MSK [894873] node@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@DB DEBUG:  updated xmin: 1 restar=
t: 0
2022-03-31 13:05:43.586 MSK [893220] node@DB DEBUG:  updated xmin: 1 restar=
t: 0
2022-03-31 13:05:43.586 MSK [891054] node@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@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@DB DEBUG:  updated xmin: 0 restar=
t: 1
2022-03-31 13:05:43.591 MSK [894778] node@DB DEBUG:  updated xmin: 0 restar=
t: 1
2022-03-31 13:05:43.591 MSK [894670] node@DB DEBUG:  updated xmin: 0 restar=
t: 1
2022-03-31 13:05:43.592 MSK [893220] node@DB DEBUG:  updated xmin: 0 restar=
t: 1
2022-03-31 13:05:43.592 MSK [891054] node@DB DEBUG:  updated xmin: 0 restar=
t: 1
2022-03-31 13:05:43.592 MSK [894873] node@DB DEBUG:  updated xmin: 0 restar=
t: 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@DB DEBUG:  serializing
snapshot to pg_logical/snapshots/57B-C8925660.snap
2022-03-31 13:06:02.044 MSK [894873] node@DB DEBUG:  serializing
snapshot to pg_logical/snapshots/57B-C8925660.snap
2022-03-31 13:06:02.044 MSK [891054] node@DB DEBUG:  serializing
snapshot to pg_logical/snapshots/57B-C8925660.snap
2022-03-31 13:06:02.044 MSK [894670] node@DB DEBUG:  serializing
snapshot to pg_logical/snapshots/57B-C8925660.snap
2022-03-31 13:06:02.044 MSK [894778] node@DB DEBUG:  serializing
snapshot to pg_logical/snapshots/57B-C8925660.snap
2022-03-31 13:06:02.045 MSK [894781] node@DB DEBUG:  serializing
snapshot to pg_logical/snapshots/57B-C8925660.snap
2022-03-31 13:06:02.051 MSK [894778] node@DB DEBUG:  got new restart
lsn 57B/C88EF210 at 57B/C8925660
2022-03-31 13:06:02.052 MSK [894670] node@DB DEBUG:  got new restart
lsn 57B/C88EF210 at 57B/C8925660
2022-03-31 13:06:02.052 MSK [894781] node@DB DEBUG:  got new restart
lsn 57B/C88EF210 at 57B/C8925660
2022-03-31 13:06:02.052 MSK [893220] node@DB DEBUG:  got new restart
lsn 57B/C88EF210 at 57B/C8925660
2022-03-31 13:06:02.052 MSK [891054] node@DB DEBUG:  got new restart
lsn 57B/C88EF210 at 57B/C8925660
2022-03-31 13:06:02.052 MSK [894873] node@DB DEBUG:  got new restart
lsn 57B/C88EF210 at 57B/C8925660
2022-03-31 13:06:02.055 MSK [894778] node@DB DEBUG:  updated xmin: 0 restar=
t: 1
2022-03-31 13:06:02.059 MSK [894873] node@DB DEBUG:  updated xmin: 0 restar=
t: 1
2022-03-31 13:06:02.065 MSK [894781] node@DB DEBUG:  updated xmin: 0 restar=
t: 1
2022-03-31 13:06:02.065 MSK [891054] node@DB DEBUG:  updated xmin: 0 restar=
t: 1
2022-03-31 13:06:02.066 MSK [894670] node@DB DEBUG:  updated xmin: 0 restar=
t: 1
2022-03-31 13:06:02.081 MSK [893220] node@DB DEBUG:  updated xmin: 0 restar=
t: 1

log file is attached.


Sergey Belyashov

["log.zip" (application/zip)]

[prev in list] [next in list] [prev in thread] [next in thread]