pg.ddx.io  pgsql-bugs@postgresql.org mailing list archive  
help / color / mirror / Atom feed
BUG #18415: Logical replication errors.
5+ messages / 4 participants
[nested] [flat]

* BUG #18415: Logical replication errors.
@ 2024-03-28 16:16 PG Bug reporting form <noreply@postgresql.org>
  2024-03-28 17:02 ` Re: BUG #18415: Logical replication errors. David G. Johnston <david.g.johnston@gmail.com>
  0 siblings, 1 reply; 5+ messages in thread

From: PG Bug reporting form @ 2024-03-28 16:16 UTC (permalink / raw)
  To: pgsql-bugs@lists.postgresql.org; +Cc: koderan@yandex.ru

The following bug has been logged on the website:

Bug reference:      18415
Logged by:          Andy Kosheen
Email address:      koderan@yandex.ru
PostgreSQL version: 15.4
Operating system:   Oracle Linux Server 8.4
Description:        

In the process of logical replication from version 13.3 (on Ubuntu 16.04.6
LTS) to version 15.4 (on Oracle Linux Server 8.4), when most of the data has
already been transferred, the following errors begin to occur, appearing
endlessly until you stop the replication process (this situation occurs on
databases larger than at least 50GB, even if there is a small number of
transactions on the source database):
2024-03-20 03:19:41.410 +07 [3433858] LOG:  logical replication apply worker
for subscription "log_rep_sub" has started
2024-03-20 03:19:41.425 +07 [3433858] ERROR:  could not start WAL streaming:
ERROR:  replication slot "log_rep_sub" does not exist
2024-03-20 03:19:41.426 +07 [1597281] LOG:  background worker "logical
replication worker" (PID 3433858) exited with exit code 1
2024-03-20 03:19:46.434 +07 [3433865] LOG:  logical replication apply worker
for subscription "log_rep_sub" has started
2024-03-20 03:19:46.449 +07 [3433865] ERROR:  could not start WAL streaming:
ERROR:  replication slot "log_rep_sub" does not exist
2024-03-20 03:19:46.450 +07 [1597281] LOG:  background worker "logical
replication worker" (PID 3433865) exited with exit code 1
2024-03-20 03:19:51.459 +07 [3433914] LOG:  logical replication apply worker
for subscription "log_rep_sub" has started
2024-03-20 03:19:51.481 +07 [3433914] ERROR:  could not start WAL streaming:
ERROR:  replication slot "log_rep_sub" does not exist
2024-03-20 03:19:51.484 +07 [1597281] LOG:  background worker "logical
replication worker" (PID 3433914) exited with exit code 1
2024-03-20 03:19:56.493 +07 [3433921] LOG:  logical replication apply worker
for subscription "log_rep_sub" has started
2024-03-20 03:19:56.514 +07 [3433921] ERROR:  could not start WAL streaming:
ERROR:  replication slot "log_rep_sub" does not exist
2024-03-20 03:19:56.517 +07 [1597281] LOG:  background worker "logical
replication worker" (PID 3433921) exited with exit code 1
2024-03-20 03:20:01.525 +07 [3433976] LOG:  logical replication apply worker
for subscription "log_rep_sub" has started
2024-03-20 03:20:01.548 +07 [3433976] ERROR:  could not start WAL streaming:
ERROR:  replication slot "log_rep_sub" does not exist
2024-03-20 03:20:01.551 +07 [1597281] LOG:  background worker "logical
replication worker" (PID 3433976) exited with exit code 1
2024-03-20 03:20:06.559 +07 [3434036] LOG:  logical replication apply worker
for subscription "log_rep_sub" has started
2024-03-20 03:20:06.580 +07 [3434036] ERROR:  could not start WAL streaming:
ERROR:  replication slot "log_rep_sub" does not exist
2024-03-20 03:20:06.583 +07 [1597281] LOG:  background worker "logical
replication worker" (PID 3434036) exited with exit code 1
2024-03-20 03:20:11.591 +07 [3434087] LOG:  logical replication apply worker
for subscription "log_rep_sub" has started
2024-03-20 03:20:11.613 +07 [3434087] ERROR:  could not start WAL streaming:
ERROR:  replication slot "log_rep_sub" does not exist
2024-03-20 03:20:11.616 +07 [1597281] LOG:  background worker "logical
replication worker" (PID 3434087) exited with exit code 1
2024-03-20 03:20:16.624 +07 [3434103] LOG:  logical replication apply worker
for subscription "log_rep_sub" has started
2024-03-20 03:20:16.645 +07 [3434103] ERROR:  could not start WAL streaming:
ERROR:  replication slot "log_rep_sub" does not exist
2024-03-20 03:20:16.648 +07 [1597281] LOG:  background worker "logical
replication worker" (PID 3434103) exited with exit code 1
2024-03-20 03:20:21.656 +07 [3434157] LOG:  logical replication apply worker
for subscription "log_rep_sub" has started
2024-03-20 03:20:21.671 +07 [3434157] ERROR:  could not start WAL streaming:
ERROR:  replication slot "log_rep_sub" does not exist



^ permalink  raw  reply  [nested|flat] 5+ messages in thread

* Re: BUG #18415: Logical replication errors.
  2024-03-28 16:16 BUG #18415: Logical replication errors. PG Bug reporting form <noreply@postgresql.org>
@ 2024-03-28 17:02 ` David G. Johnston <david.g.johnston@gmail.com>
  2024-03-28 19:40   ` Re: BUG #18415: Logical replication errors. koderan <koderan@yandex.ru>
  2024-03-29 08:59   ` Re: BUG #18415: Logical replication errors. koderan <koderan@yandex.ru>
  0 siblings, 2 replies; 5+ messages in thread

From: David G. Johnston @ 2024-03-28 17:02 UTC (permalink / raw)
  To: koderan@yandex.ru; pgsql-bugs@lists.postgresql.org

On Thu, Mar 28, 2024 at 9:59 AM PG Bug reporting form <
noreply@postgresql.org> wrote:

> The following bug has been logged on the website:
>
> Bug reference:      18415
> Logged by:          Andy Kosheen
> Email address:      koderan@yandex.ru
> PostgreSQL version: 15.4
> Operating system:   Oracle Linux Server 8.4
> Description:
>
> In the process of logical replication from version 13.3 (on Ubuntu 16.04.6
> LTS) to version 15.4 (on Oracle Linux Server 8.4), when most of the data
> has
> already been transferred, the following errors begin to occur, appearing
> endlessly until you stop the replication process (this situation occurs on
> databases larger than at least 50GB, even if there is a small number of
> transactions on the source database):
> 2024-03-20 03:19:41.410 +07 [3433858] LOG:  logical replication apply
> worker
> for subscription "log_rep_sub" has started
> 2024-03-20 03:19:41.425 +07 [3433858] ERROR:  could not start WAL
> streaming:
> ERROR:  replication slot "log_rep_sub" does not exist
>
>
Suggest you check the publisher logs and see why the replication slot went
away.

David J.

^ permalink  raw  reply  [nested|flat] 5+ messages in thread

* Re: BUG #18415: Logical replication errors.
  2024-03-28 16:16 BUG #18415: Logical replication errors. PG Bug reporting form <noreply@postgresql.org>
  2024-03-28 17:02 ` Re: BUG #18415: Logical replication errors. David G. Johnston <david.g.johnston@gmail.com>
@ 2024-03-28 19:40   ` koderan <koderan@yandex.ru>
  2024-03-29 12:19     ` Re: BUG #18415: Logical replication errors. vignesh C <vignesh21@gmail.com>
  1 sibling, 1 reply; 5+ messages in thread

From: koderan @ 2024-03-28 19:40 UTC (permalink / raw)
  To: David G. Johnston <david.g.johnston@gmail.com>; pgsql-bugs@lists.postgresql.org <pgsql-bugs@lists.postgresql.org>

<div><div><div>There is publisher and subscriber logs, but the logs on both nodes did not give me clarity.</div></div><div>Master (time when errors start to appear):</div><div> </div><div>2024-03-28 22:26:08.459 +07 [1004642] ERROR:  could not start WAL streaming: ERROR:  replication slot "pg_975006_sync_972467_7293549148661379912" does not exist</div><div>2024-03-28 22:26:08.462 +07 [1597281] LOG:  background worker "logical replication worker" (PID 1004642) exited with exit code 1</div><div>2024-03-28 22:26:08.466 +07 [1048261] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "scan_type_i18n" has started</div><div>2024-03-28 22:26:08.542 +07 [1048261] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "scan_type_i18n" has finished</div><div>2024-03-28 22:26:08.548 +07 [1048263] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "phone_type_i18n" has started</div><div>2024-03-28 22:26:08.641 +07 [1048263] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "phone_type_i18n" has finished</div><div>2024-03-28 22:26:08.644 +07 [1048264] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "reply_status_type_i18n" has started</div><div>2024-03-28 22:26:08.690 +07 [1048264] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "reply_status_type_i18n" has finished</div><div>2024-03-28 22:26:08.693 +07 [1048265] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "user" has started</div><div>2024-03-28 22:26:09.054 +07 [1048265] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "user" has finished</div><div>2024-03-28 22:26:09.059 +07 [1048267] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "queue_event" has started</div><div>2024-03-28 22:26:09.141 +07 [1048267] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "queue_event" has finished</div><div>2024-03-28 22:26:09.146 +07 [1048274] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "credit" has started</div><div>2024-03-28 22:26:09.163 +07 [1048274] ERROR:  could not start WAL streaming: ERROR:  replication slot "pg_975006_sync_972243_7293549148661379912" does not exist</div><div>2024-03-28 22:26:09.165 +07 [1597281] LOG:  background worker "logical replication worker" (PID 1048274) exited with exit code 1</div><div>2024-03-28 22:26:09.167 +07 [1048281] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "requisite_value_contragent" has started</div><div>2024-03-28 22:26:09.184 +07 [1048281] ERROR:  could not start WAL streaming: ERROR:  replication slot "pg_975006_sync_972563_7293549148661379912" does not exist</div><div>2024-03-28 22:26:09.186 +07 [1597281] LOG:  background worker "logical replication worker" (PID 1048281) exited with exit code 1</div><div>2024-03-28 22:26:09.189 +07 [1048282] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "order_registry_np" has started</div><div> </div><div>The same time on replica:</div><div> </div><div>2024-03-28 22:26:07.967 +07 [25424] postgres@claims LOG:  duration: 2406278.201 ms  statement: COPY public.orders (id, order_number, order_date, order_amount, payment_info_code, payer_code, payer_name, receiver_code, receiver_name, sender_code, sender_name, cargo_description, cargo_volume_weight, cargo_weight, declared_price, currency_code, internet_store_number, subdivision_code, cfo_code, active, date_created, date_updated, delay) TO STDOUT</div><div>2024-03-28 22:26:08.426 +07 [25424] postgres@claims ERROR:  replication slot "pg_975006_sync_972467_7293549148661379912" does not exist</div><div>2024-03-28 22:26:08.466 +07 [1170] postgres@claims LOG:  logical decoding found initial starting point at B1C5/BFBA3410</div><div>2024-03-28 22:26:08.466 +07 [1170] postgres@claims DETAIL:  Waiting for transactions (approximately 1) older than 2998665818 to end.</div><div>2024-03-28 22:26:08.469 +07 [1165] [unknown]@[unknown] LOG:  could not accept SSL connection: EOF detected</div><div>2024-03-28 22:26:08.496 +07 [1170] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBA4580</div><div>2024-03-28 22:26:08.496 +07 [1170] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:08.507 +07 [1170] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_971138_7293549148661379912"</div><div>2024-03-28 22:26:08.507 +07 [1170] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBA45B8, reading WAL from B1C5/BFBA3290.</div><div>2024-03-28 22:26:08.507 +07 [1170] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBA3410</div><div>2024-03-28 22:26:08.507 +07 [1170] postgres@claims DETAIL:  Logical decoding will begin using saved snapshot.</div><div>2024-03-28 22:26:08.546 +07 [1172] postgres@claims LOG:  logical decoding found initial starting point at B1C5/BFBAA200</div><div>2024-03-28 22:26:08.546 +07 [1172] postgres@claims DETAIL:  Waiting for transactions (approximately 2) older than 2998665822 to end.</div><div>2024-03-28 22:26:08.594 +07 [1172] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBB5E80</div><div>2024-03-28 22:26:08.594 +07 [1172] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:08.602 +07 [1172] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_970776_7293549148661379912"</div><div>2024-03-28 22:26:08.602 +07 [1172] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBB5EB8, reading WAL from B1C5/BFBA5290.</div><div>2024-03-28 22:26:08.602 +07 [1172] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBAA200</div><div>2024-03-28 22:26:08.602 +07 [1172] postgres@claims DETAIL:  Logical decoding will begin using saved snapshot.</div><div>2024-03-28 22:26:08.645 +07 [1173] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBB8E28</div><div>2024-03-28 22:26:08.645 +07 [1173] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:08.652 +07 [1173] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_971808_7293549148661379912"</div><div>2024-03-28 22:26:08.652 +07 [1173] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBB8E60, reading WAL from B1C5/BFBB8E28.</div><div>2024-03-28 22:26:08.652 +07 [1173] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBB8E28</div><div>2024-03-28 22:26:08.652 +07 [1173] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:08.697 +07 [1174] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBBE588</div><div>2024-03-28 22:26:08.697 +07 [1174] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:09.019 +07 [1174] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_971995_7293549148661379912"</div><div>2024-03-28 22:26:09.019 +07 [1174] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBBE5C0, reading WAL from B1C5/BFBBE588.</div><div>2024-03-28 22:26:09.019 +07 [1174] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBBE588</div><div>2024-03-28 22:26:09.019 +07 [1174] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:09.056 +07 [1180] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBE0C88</div><div>2024-03-28 22:26:09.056 +07 [1180] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:09.105 +07 [1180] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_972492_7293549148661379912"</div><div>2024-03-28 22:26:09.105 +07 [1180] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBE0CC0, reading WAL from B1C5/BFBE0C88.</div><div>2024-03-28 22:26:09.105 +07 [1180] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBE0C88</div><div>2024-03-28 22:26:09.105 +07 [1180] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:09.129 +07 [1181] postgres@claims ERROR:  replication slot "pg_975006_sync_972243_7293549148661379912" does not exist</div><div>2024-03-28 22:26:09.151 +07 [1182] postgres@claims ERROR:  replication slot "pg_975006_sync_972563_7293549148661379912" does not exist</div><div>2024-03-28 22:26:09.172 +07 [1184] postgres@claims ERROR:  replication slot "pg_975006_sync_972454_7293549148661379912" does not exist</div><div>2024-03-28 22:26:09.196 +07 [1185] postgres@claims ERROR:  replication slot "pg_975006_sync_972467_7293549148661379912" does not exist</div><div> </div></div><div> </div><div>28.03.2024, 20:03, "David G. Johnston" &lt;david.g.johnston@gmail.com&gt;:</div><blockquote><div><div><div style="font-family:'arial' , 'helvetica' , sans-serif"><span style="font-family:'arial' , 'helvetica' , sans-serif">On Thu, Mar 28, 2024 at 9:59 AM PG Bug reporting form &lt;<a href="mailto:noreply@postgresql.org" rel="noopener noreferrer">noreply@postgresql.org</a>&gt; wrote:</span></div></div><div><blockquote style="border-left-color:rgb( 204 , 204 , 204 );border-left-style:solid;border-left-width:1px;margin:0px 0px 0px 0.8ex;padding-left:1ex">The following bug has been logged on the website:<br /><br />Bug reference:      18415<br />Logged by:          Andy Kosheen<br />Email address:      <a href="mailto:koderan@yandex.ru" rel="noopener noreferrer" target="_blank">koderan@yandex.ru</a><br />PostgreSQL version: 15.4<br />Operating system:   Oracle Linux Server 8.4<br />Description:       <br /><br />In the process of logical replication from version 13.3 (on Ubuntu 16.04.6<br />LTS) to version 15.4 (on Oracle Linux Server 8.4), when most of the data has<br />already been transferred, the following errors begin to occur, appearing<br />endlessly until you stop the replication process (this situation occurs on<br />databases larger than at least 50GB, even if there is a small number of<br />transactions on the source database):<br />2024-03-20 03:19:41.410 +07 [3433858] LOG:  logical replication apply worker<br />for subscription "log_rep_sub" has started<br />2024-03-20 03:19:41.425 +07 [3433858] ERROR:  could not start WAL streaming:<br />ERROR:  replication slot "log_rep_sub" does not exist<br /> </blockquote><div> </div><div style="font-family:'arial' , 'helvetica' , sans-serif">Suggest you check the publisher logs and see why the replication slot went away.</div><div style="font-family:'arial' , 'helvetica' , sans-serif"> </div><div style="font-family:'arial' , 'helvetica' , sans-serif">David J.</div><div style="font-family:'arial' , 'helvetica' , sans-serif"> </div></div></div></blockquote>

^ permalink  raw  reply  [nested|flat] 5+ messages in thread

* Re: BUG #18415: Logical replication errors.
  2024-03-28 16:16 BUG #18415: Logical replication errors. PG Bug reporting form <noreply@postgresql.org>
  2024-03-28 17:02 ` Re: BUG #18415: Logical replication errors. David G. Johnston <david.g.johnston@gmail.com>
  2024-03-28 19:40   ` Re: BUG #18415: Logical replication errors. koderan <koderan@yandex.ru>
@ 2024-03-29 12:19     ` vignesh C <vignesh21@gmail.com>
  0 siblings, 0 replies; 5+ messages in thread

From: vignesh C @ 2024-03-29 12:19 UTC (permalink / raw)
  To: koderan <koderan@yandex.ru>; +Cc: David G. Johnston <david.g.johnston@gmail.com>; pgsql-bugs@lists.postgresql.org <pgsql-bugs@lists.postgresql.org>

On Fri, 29 Mar 2024 at 05:50, koderan <koderan@yandex.ru> wrote:
>
> There is publisher and subscriber logs, but the logs on both nodes did not give me clarity.
> Master (time when errors start to appear):
>
> 2024-03-28 22:26:08.459 +07 [1004642] ERROR:  could not start WAL streaming: ERROR:  replication slot "pg_975006_sync_972467_7293549148661379912" does not exist
> 2024-03-28 22:26:08.462 +07 [1597281] LOG:  background worker "logical replication worker" (PID 1004642) exited with exit code 1
> 2024-03-28 22:26:08.466 +07 [1048261] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "scan_type_i18n" has started
> 2024-03-28 22:26:08.542 +07 [1048261] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "scan_type_i18n" has finished
> 2024-03-28 22:26:08.548 +07 [1048263] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "phone_type_i18n" has started
> 2024-03-28 22:26:08.641 +07 [1048263] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "phone_type_i18n" has finished
> 2024-03-28 22:26:08.644 +07 [1048264] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "reply_status_type_i18n" has started
> 2024-03-28 22:26:08.690 +07 [1048264] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "reply_status_type_i18n" has finished
> 2024-03-28 22:26:08.693 +07 [1048265] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "user" has started
> 2024-03-28 22:26:09.054 +07 [1048265] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "user" has finished
> 2024-03-28 22:26:09.059 +07 [1048267] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "queue_event" has started
> 2024-03-28 22:26:09.141 +07 [1048267] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "queue_event" has finished
> 2024-03-28 22:26:09.146 +07 [1048274] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "credit" has started
> 2024-03-28 22:26:09.163 +07 [1048274] ERROR:  could not start WAL streaming: ERROR:  replication slot "pg_975006_sync_972243_7293549148661379912" does not exist
> 2024-03-28 22:26:09.165 +07 [1597281] LOG:  background worker "logical replication worker" (PID 1048274) exited with exit code 1
> 2024-03-28 22:26:09.167 +07 [1048281] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "requisite_value_contragent" has started
> 2024-03-28 22:26:09.184 +07 [1048281] ERROR:  could not start WAL streaming: ERROR:  replication slot "pg_975006_sync_972563_7293549148661379912" does not exist
> 2024-03-28 22:26:09.186 +07 [1597281] LOG:  background worker "logical replication worker" (PID 1048281) exited with exit code 1
> 2024-03-28 22:26:09.189 +07 [1048282] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "order_registry_np" has started
>
> The same time on replica:
>
> 2024-03-28 22:26:07.967 +07 [25424] postgres@claims LOG:  duration: 2406278.201 ms  statement: COPY public.orders (id, order_number, order_date, order_amount, payment_info_code, payer_code, payer_name, receiver_code, receiver_name, sender_code, sender_name, cargo_description, cargo_volume_weight, cargo_weight, declared_price, currency_code, internet_store_number, subdivision_code, cfo_code, active, date_created, date_updated, delay) TO STDOUT
> 2024-03-28 22:26:08.426 +07 [25424] postgres@claims ERROR:  replication slot "pg_975006_sync_972467_7293549148661379912" does not exist
> 2024-03-28 22:26:08.466 +07 [1170] postgres@claims LOG:  logical decoding found initial starting point at B1C5/BFBA3410
> 2024-03-28 22:26:08.466 +07 [1170] postgres@claims DETAIL:  Waiting for transactions (approximately 1) older than 2998665818 to end.
> 2024-03-28 22:26:08.469 +07 [1165] [unknown]@[unknown] LOG:  could not accept SSL connection: EOF detected
> 2024-03-28 22:26:08.496 +07 [1170] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBA4580
> 2024-03-28 22:26:08.496 +07 [1170] postgres@claims DETAIL:  There are no running transactions.
> 2024-03-28 22:26:08.507 +07 [1170] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_971138_7293549148661379912"
> 2024-03-28 22:26:08.507 +07 [1170] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBA45B8, reading WAL from B1C5/BFBA3290.
> 2024-03-28 22:26:08.507 +07 [1170] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBA3410
> 2024-03-28 22:26:08.507 +07 [1170] postgres@claims DETAIL:  Logical decoding will begin using saved snapshot.
> 2024-03-28 22:26:08.546 +07 [1172] postgres@claims LOG:  logical decoding found initial starting point at B1C5/BFBAA200
> 2024-03-28 22:26:08.546 +07 [1172] postgres@claims DETAIL:  Waiting for transactions (approximately 2) older than 2998665822 to end.
> 2024-03-28 22:26:08.594 +07 [1172] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBB5E80
> 2024-03-28 22:26:08.594 +07 [1172] postgres@claims DETAIL:  There are no running transactions.
> 2024-03-28 22:26:08.602 +07 [1172] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_970776_7293549148661379912"
> 2024-03-28 22:26:08.602 +07 [1172] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBB5EB8, reading WAL from B1C5/BFBA5290.
> 2024-03-28 22:26:08.602 +07 [1172] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBAA200
> 2024-03-28 22:26:08.602 +07 [1172] postgres@claims DETAIL:  Logical decoding will begin using saved snapshot.
> 2024-03-28 22:26:08.645 +07 [1173] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBB8E28
> 2024-03-28 22:26:08.645 +07 [1173] postgres@claims DETAIL:  There are no running transactions.
> 2024-03-28 22:26:08.652 +07 [1173] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_971808_7293549148661379912"
> 2024-03-28 22:26:08.652 +07 [1173] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBB8E60, reading WAL from B1C5/BFBB8E28.
> 2024-03-28 22:26:08.652 +07 [1173] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBB8E28
> 2024-03-28 22:26:08.652 +07 [1173] postgres@claims DETAIL:  There are no running transactions.
> 2024-03-28 22:26:08.697 +07 [1174] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBBE588
> 2024-03-28 22:26:08.697 +07 [1174] postgres@claims DETAIL:  There are no running transactions.
> 2024-03-28 22:26:09.019 +07 [1174] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_971995_7293549148661379912"
> 2024-03-28 22:26:09.019 +07 [1174] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBBE5C0, reading WAL from B1C5/BFBBE588.
> 2024-03-28 22:26:09.019 +07 [1174] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBBE588
> 2024-03-28 22:26:09.019 +07 [1174] postgres@claims DETAIL:  There are no running transactions.
> 2024-03-28 22:26:09.056 +07 [1180] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBE0C88
> 2024-03-28 22:26:09.056 +07 [1180] postgres@claims DETAIL:  There are no running transactions.
> 2024-03-28 22:26:09.105 +07 [1180] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_972492_7293549148661379912"
> 2024-03-28 22:26:09.105 +07 [1180] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBE0CC0, reading WAL from B1C5/BFBE0C88.
> 2024-03-28 22:26:09.105 +07 [1180] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBE0C88
> 2024-03-28 22:26:09.105 +07 [1180] postgres@claims DETAIL:  There are no running transactions.
> 2024-03-28 22:26:09.129 +07 [1181] postgres@claims ERROR:  replication slot "pg_975006_sync_972243_7293549148661379912" does not exist
> 2024-03-28 22:26:09.151 +07 [1182] postgres@claims ERROR:  replication slot "pg_975006_sync_972563_7293549148661379912" does not exist
> 2024-03-28 22:26:09.172 +07 [1184] postgres@claims ERROR:  replication slot "pg_975006_sync_972454_7293549148661379912" does not exist
> 2024-03-28 22:26:09.196 +07 [1185] postgres@claims ERROR:  replication slot "pg_975006_sync_972467_7293549148661379912" does not exist
>
>
> 28.03.2024, 20:03, "David G. Johnston" <david.g.johnston@gmail.com>:
>
> On Thu, Mar 28, 2024 at 9:59 AM PG Bug reporting form <noreply@postgresql.org> wrote:
>
> The following bug has been logged on the website:
>
> Bug reference:      18415
> Logged by:          Andy Kosheen
> Email address:      koderan@yandex.ru
> PostgreSQL version: 15.4
> Operating system:   Oracle Linux Server 8.4
> Description:
>
> In the process of logical replication from version 13.3 (on Ubuntu 16.04.6
> LTS) to version 15.4 (on Oracle Linux Server 8.4), when most of the data has
> already been transferred, the following errors begin to occur, appearing
> endlessly until you stop the replication process (this situation occurs on
> databases larger than at least 50GB, even if there is a small number of
> transactions on the source database):
> 2024-03-20 03:19:41.410 +07 [3433858] LOG:  logical replication apply worker
> for subscription "log_rep_sub" has started
> 2024-03-20 03:19:41.425 +07 [3433858] ERROR:  could not start WAL streaming:
> ERROR:  replication slot "log_rep_sub" does not exist

By any chance do you have a reproducible test case for this. Also are
there any other abnormalities in the log. What was the
max_replication_slots configuration set in the publisher and what are
the replication slots that were being used in the publisher at that
point(select * from pg_replication_slots).

Regards,
Vignesh





^ permalink  raw  reply  [nested|flat] 5+ messages in thread

* Re: BUG #18415: Logical replication errors.
  2024-03-28 16:16 BUG #18415: Logical replication errors. PG Bug reporting form <noreply@postgresql.org>
  2024-03-28 17:02 ` Re: BUG #18415: Logical replication errors. David G. Johnston <david.g.johnston@gmail.com>
@ 2024-03-29 08:59   ` koderan <koderan@yandex.ru>
  1 sibling, 0 replies; 5+ messages in thread

From: koderan @ 2024-03-29 08:59 UTC (permalink / raw)
  To: pgsql-bugs@lists.postgresql.org <pgsql-bugs@lists.postgresql.org>

<div>- все</div><div> </div><div><div><div>There is publisher and subscriber logs, but the logs on both nodes did not give me clarity.</div><div>Master (time when errors start to appear):</div><div> </div><div>2024-03-28 22:26:08.459 +07 [1004642] ERROR:  could not start WAL streaming: ERROR:  replication slot "pg_975006_sync_972467_7293549148661379912" does not exist</div><div>2024-03-28 22:26:08.462 +07 [1597281] LOG:  background worker "logical replication worker" (PID 1004642) exited with exit code 1</div><div>2024-03-28 22:26:08.466 +07 [1048261] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "scan_type_i18n" has started</div><div>2024-03-28 22:26:08.542 +07 [1048261] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "scan_type_i18n" has finished</div><div>2024-03-28 22:26:08.548 +07 [1048263] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "phone_type_i18n" has started</div><div>2024-03-28 22:26:08.641 +07 [1048263] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "phone_type_i18n" has finished</div><div>2024-03-28 22:26:08.644 +07 [1048264] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "reply_status_type_i18n" has started</div><div>2024-03-28 22:26:08.690 +07 [1048264] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "reply_status_type_i18n" has finished</div><div>2024-03-28 22:26:08.693 +07 [1048265] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "user" has started</div><div>2024-03-28 22:26:09.054 +07 [1048265] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "user" has finished</div><div>2024-03-28 22:26:09.059 +07 [1048267] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "queue_event" has started</div><div>2024-03-28 22:26:09.141 +07 [1048267] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "queue_event" has finished</div><div>2024-03-28 22:26:09.146 +07 [1048274] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "credit" has started</div><div>2024-03-28 22:26:09.163 +07 [1048274] ERROR:  could not start WAL streaming: ERROR:  replication slot "pg_975006_sync_972243_7293549148661379912" does not exist</div><div>2024-03-28 22:26:09.165 +07 [1597281] LOG:  background worker "logical replication worker" (PID 1048274) exited with exit code 1</div><div>2024-03-28 22:26:09.167 +07 [1048281] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "requisite_value_contragent" has started</div><div>2024-03-28 22:26:09.184 +07 [1048281] ERROR:  could not start WAL streaming: ERROR:  replication slot "pg_975006_sync_972563_7293549148661379912" does not exist</div><div>2024-03-28 22:26:09.186 +07 [1597281] LOG:  background worker "logical replication worker" (PID 1048281) exited with exit code 1</div><div>2024-03-28 22:26:09.189 +07 [1048282] LOG:  logical replication table synchronization worker for subscription "log_rep_sub", table "order_registry_np" has started</div><div> </div><div>The same time on replica:</div><div> </div><div>2024-03-28 22:26:07.967 +07 [25424] postgres@claims LOG:  duration: 2406278.201 ms  statement: COPY public.orders (id, order_number, order_date, order_amount, payment_info_code, payer_code, payer_name, receiver_code, receiver_name, sender_code, sender_name, cargo_description, cargo_volume_weight, cargo_weight, declared_price, currency_code, internet_store_number, subdivision_code, cfo_code, active, date_created, date_updated, delay) TO STDOUT</div><div>2024-03-28 22:26:08.426 +07 [25424] postgres@claims ERROR:  replication slot "pg_975006_sync_972467_7293549148661379912" does not exist</div><div>2024-03-28 22:26:08.466 +07 [1170] postgres@claims LOG:  logical decoding found initial starting point at B1C5/BFBA3410</div><div>2024-03-28 22:26:08.466 +07 [1170] postgres@claims DETAIL:  Waiting for transactions (approximately 1) older than 2998665818 to end.</div><div>2024-03-28 22:26:08.469 +07 [1165] [unknown]@[unknown] LOG:  could not accept SSL connection: EOF detected</div><div>2024-03-28 22:26:08.496 +07 [1170] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBA4580</div><div>2024-03-28 22:26:08.496 +07 [1170] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:08.507 +07 [1170] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_971138_7293549148661379912"</div><div>2024-03-28 22:26:08.507 +07 [1170] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBA45B8, reading WAL from B1C5/BFBA3290.</div><div>2024-03-28 22:26:08.507 +07 [1170] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBA3410</div><div>2024-03-28 22:26:08.507 +07 [1170] postgres@claims DETAIL:  Logical decoding will begin using saved snapshot.</div><div>2024-03-28 22:26:08.546 +07 [1172] postgres@claims LOG:  logical decoding found initial starting point at B1C5/BFBAA200</div><div>2024-03-28 22:26:08.546 +07 [1172] postgres@claims DETAIL:  Waiting for transactions (approximately 2) older than 2998665822 to end.</div><div>2024-03-28 22:26:08.594 +07 [1172] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBB5E80</div><div>2024-03-28 22:26:08.594 +07 [1172] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:08.602 +07 [1172] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_970776_7293549148661379912"</div><div>2024-03-28 22:26:08.602 +07 [1172] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBB5EB8, reading WAL from B1C5/BFBA5290.</div><div>2024-03-28 22:26:08.602 +07 [1172] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBAA200</div><div>2024-03-28 22:26:08.602 +07 [1172] postgres@claims DETAIL:  Logical decoding will begin using saved snapshot.</div><div>2024-03-28 22:26:08.645 +07 [1173] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBB8E28</div><div>2024-03-28 22:26:08.645 +07 [1173] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:08.652 +07 [1173] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_971808_7293549148661379912"</div><div>2024-03-28 22:26:08.652 +07 [1173] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBB8E60, reading WAL from B1C5/BFBB8E28.</div><div>2024-03-28 22:26:08.652 +07 [1173] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBB8E28</div><div>2024-03-28 22:26:08.652 +07 [1173] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:08.697 +07 [1174] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBBE588</div><div>2024-03-28 22:26:08.697 +07 [1174] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:09.019 +07 [1174] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_971995_7293549148661379912"</div><div>2024-03-28 22:26:09.019 +07 [1174] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBBE5C0, reading WAL from B1C5/BFBBE588.</div><div>2024-03-28 22:26:09.019 +07 [1174] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBBE588</div><div>2024-03-28 22:26:09.019 +07 [1174] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:09.056 +07 [1180] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBE0C88</div><div>2024-03-28 22:26:09.056 +07 [1180] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:09.105 +07 [1180] postgres@claims LOG:  starting logical decoding for slot "pg_975006_sync_972492_7293549148661379912"</div><div>2024-03-28 22:26:09.105 +07 [1180] postgres@claims DETAIL:  Streaming transactions committing after B1C5/BFBE0CC0, reading WAL from B1C5/BFBE0C88.</div><div>2024-03-28 22:26:09.105 +07 [1180] postgres@claims LOG:  logical decoding found consistent point at B1C5/BFBE0C88</div><div>2024-03-28 22:26:09.105 +07 [1180] postgres@claims DETAIL:  There are no running transactions.</div><div>2024-03-28 22:26:09.129 +07 [1181] postgres@claims ERROR:  replication slot "pg_975006_sync_972243_7293549148661379912" does not exist</div><div>2024-03-28 22:26:09.151 +07 [1182] postgres@claims ERROR:  replication slot "pg_975006_sync_972563_7293549148661379912" does not exist</div><div>2024-03-28 22:26:09.172 +07 [1184] postgres@claims ERROR:  replication slot "pg_975006_sync_972454_7293549148661379912" does not exist</div><div>2024-03-28 22:26:09.196 +07 [1185] postgres@claims ERROR:  replication slot "pg_975006_sync_972467_7293549148661379912" does not exist</div></div></div>

^ permalink  raw  reply  [nested|flat] 5+ messages in thread


end of thread, other threads:[~2024-03-29 12:19 UTC | newest]

Thread overview: 5+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2024-03-28 16:16 BUG #18415: Logical replication errors. PG Bug reporting form <noreply@postgresql.org>
2024-03-28 17:02 ` David G. Johnston <david.g.johnston@gmail.com>
2024-03-28 19:40   ` koderan <koderan@yandex.ru>
2024-03-29 12:19     ` vignesh C <vignesh21@gmail.com>
2024-03-29 08:59   ` koderan <koderan@yandex.ru>

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