pglogical subscriptions in down status for no apparent reasson

[jcasanov]

I'm using pg 16.6 and pglogical 2.4.5 (both provider and subscriber)

The provider has 3 subscribers and it was working just fine and then suddenly show_subscription_status() reports on all the three suscriptions are down.

Extract from the log is attached (log generated with debug2 because standard level of information said nothing).
log_pglogical.txt

The first that I notice is the committed timestamp, the wal has correct timestamps (2025-01-05), also the "unknown action" is suspicios but other versions also show it.

Anything else I can do to help debug this?

[jcasanov]

Btw, the message in the log is:

LOG:  starting apply for subscription sub_shared_tables_hub_50_mmil7
ERROR:  no data left in message
LOG:  apply worker [7840] at slot 1 generation 206 exiting with error
LOG:  background worker "pglogical apply 16406:4069541401" (PID 7840) exited with exit code 1

This is taken from another node failing

[leoamigood]

Looks like similar issue:

2025-01-21 12:55:28.491 CET [46479] LOG:  starting apply for subscription subscription_name
2025-01-21 12:55:28.492 CET [46479] ERROR:  subscriber subscription_name initialization failed during nonrecoverable step (d), please try the setup again
2025-01-21 12:55:28.492 CET [46479] LOG:  apply worker [46479] at slot 1 generation 82 exiting with error
2025-01-21 12:55:28.494 CET [24807] LOG:  background worker "pglogical apply 40964:170921473" (PID 46479) exited with exit code 1

[luss]

when a node fails in the middle of sending a message, the receiving node (likely) only receives a partial message (that does not match the message length in it's header. IMHO, the receiving node should log this as a warning and definitely keep going.

…

On Tue, Jan 21, 2025 at 6:57 AM Leo Amigood ***@***.***> wrote: Looks like similar issue: 2025-01-21 12:55:28.491 CET [46479] LOG: starting apply for subscription subscription_name 2025-01-21 12:55:28.492 CET [46479] ERROR: subscriber subscription_name initialization failed during nonrecoverable step (d), please try the setup again 2025-01-21 12:55:28.492 CET [46479] LOG: apply worker [46479] at slot 1 generation 82 exiting with error 2025-01-21 12:55:28.494 CET [24807] LOG: background worker "pglogical apply 40964:170921473" (PID 46479) exited with exit code 1 — Reply to this email directly, view it on GitHub <#494 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAMWOHXRMJKQPFDMXLPFZ7D2LYY25AVCNFSM6AAAAABUVCN3YOVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDMMBUGUZDKNZXGA> . You are receiving this because you are subscribed to this thread.Message ID: ***@***.***>

[jcasanov]

I noted sometime ago that everytime I got a down subscription with that message, I set log_min_messages to DEBUG I get a message saying the upstream server is 16.4 but I know there is no 16.4 servers involved since at least mid-january. All servers are currently 16.6.

2025-02-13 22:21:41.792 -05 [app=pglogical apply 57344:1890004017;user=[unknown];db=mm023;host=;pid=14007;l=16;tx=0] DEBUG: upstream Pg version is 16.4 (Ubuntu 16.4-1.pgdg24.04+2)