Re: Exit walsender before confirming remote flush in logical replication

Dear Kuroda-san,

01.06.2026 06:57, Hayato Kuroda (Fujitsu) wrote:
>> 038_walsnd_shutdown_timeout_subscriber.log doesn't really contain the
>> expected warning:
>> 2026-05-29 21:11:58.777 CEST [2273817][logical replication apply worker][124/2:0] LOG:  logical replication apply worker for subscription "test_sub" has started
>> 2026-05-29 21:12:03.232 CEST [2271870][client backend][4/6:0] LOG:  statement: BEGIN;
>> 2026-05-29 21:12:03.232 CEST [2271870][client backend][4/6:0] LOG:  statement: LOCK TABLE test_tab IN EXCLUSIVE MODE;
> ...
>
> To confirm; IIUC the warning should be contained on the publisher log, not the
> subscriber side. And below log appeared on the publisher;
>
> ```
> 2026-05-29 21:12:03.426 CEST [2275591][walsender][26/1:0] FATAL: canceling authentication due to timeout
> 2026-05-29 21:12:03.432 CEST [2273580][checkpointer][:0] LOG: shutting down
> ```

I'm sorry. I switched to the wrong log file during my investigation.

>
> Is there a possibility that walsender was shut down during the authentication,
> especially in-between BackendInitialize() and end of PerformAuthentication()?
>
>> I think this can be explained by the fact that walrcv->ready_to_display
>> is set before WalReceiverMain's loop reached. I've reproduced this test
>> failure with:
> Verified it could reproduce the failure, but there were no "canceling authentication
> due to timeout" in the publisher log on my env.

I think the original failure can be reproduced with:
--- a/src/backend/libpq/auth.c
+++ b/src/backend/libpq/auth.c
@@ -645,6 +645,7 @@ ClientAuthentication(Port *port)
 #endif
     }

+if (am_walsender) pg_usleep(500 * 1000);
     if ((log_connections & LOG_CONNECTION_AUTHENTICATION) &&
         status == STATUS_OK &&
         !MyClientConnectionInfo.authn_id)

With this modification, I can see:
#   Failed test 'walsender exits due to wal_sender_shutdown_timeout even when both physical and logical replication are
stalled'
#   at t/038_walsnd_shutdown_timeout.pl line 189.
# Looks like you failed 1 test of 4.
t/038_walsnd_shutdown_timeout.pl .. Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/4 subtests

038_walsnd_shutdown_timeout_publisher.log contains:
2026-06-01 22:32:35.166 EEST [1851879][client backend][0/0:0] FATAL:  terminating connection due to administrator command
2026-06-01 22:32:35.166 EEST [1851879][client backend][0/0:0] DETAIL:  Signal sent by PID 1851819, UID 1000.
2026-06-01 22:32:35.166 EEST [1851878][walsender][26/1:0] FATAL: canceling authentication due to timeout

Best regards,
Alexander