Re: BUG #19488: Standby connection fails after dropping on login event trigger enabled always

Hi,

On Fri, 9 Oct 2026 at 09:30, Alexander Lakhin <exclusion(at)gmail(dot)com> wrote:
>
> Hello Alexander,
>
> 25.05.2026 11:53, Alexander Korotkov wrote:
>
> On Thu, May 21, 2026 at 2:48 PM Ayush Tiwari
> <ayushtiwari(dot)slg01(at)gmail(dot)com> wrote:
>
> I agree the approach you are suggesting is better.
>
> Patch looks good to me!
>
> Thank you. I'm going to push and backpatch it if no objections.
>
>
> Please look at a failure of 053_standby_login_event_trigger.pl produced
> recently by skink [1]:
> [05:59:54.150](0.000s) ok 4 - no AccessExclusiveLock FATAL on standby login
> [05:59:59.905](5.755s) not ok 5 - primary clears dathasloginevt on next login after DROP
> [05:59:59.906](0.000s) # Failed test 'primary clears dathasloginevt on next login after DROP'
> # at /home/bf/bf-build/skink/REL_19_STABLE/pgsql/src/test/recovery/t/053_standby_login_event_trigger.pl line 109.
> [05:59:59.906](0.000s) # got: 't'
> # expected: 'f'
> Waiting for replication conn standby's replay_lsn to pass 0/04000060 on primary
> done
> [06:00:11.434](11.528s) not ok 6 - cleared dathasloginevt replicates to standby
> [06:00:11.434](0.000s) # Failed test 'cleared dathasloginevt replicates to standby'
> # at /home/bf/bf-build/skink/REL_19_STABLE/pgsql/src/test/recovery/t/053_standby_login_event_trigger.pl line 118.
> [06:00:11.434](0.000s) # got: 't'
> # expected: 'f'
> ...
> [06:00:12.023](0.588s) # Looks like you failed 2 tests of 6.
>
> I've reproduced this locally when running 5 concurrent test instances
> against Valgrind-instrumented build, with the following TEMP_CONFIG:
> log_autovacuum_min_duration = 0
> autovacuum_naptime = 1
> log_min_messages = DEBUG3
> log_line_prefix = '%m [%p][%b][%v:%x] '
> log_connections = on
> log_disconnections = on
>
> and diagnostic logging:
> --- a/src/backend/commands/event_trigger.c
> +++ b/src/backend/commands/event_trigger.c
> @@ -945,9 +945,12 @@ EventTriggerOnLogin(void)
> * pg_database flag ourselves; it will be cleared via WAL replay once the
> * primary's next login event trigger run clears it on the primary.
> */
> - else if (!RecoveryInProgress() &&
> - ConditionalLockSharedObject(DatabaseRelationId, MyDatabaseId,
> + else if (!RecoveryInProgress())
> +{
> +if (!ConditionalLockSharedObject(DatabaseRelationId, MyDatabaseId,
> 0, AccessExclusiveLock))
> +elog(LOG, "!!!EventTriggerOnLogin| could not lock database %u", MyDatabaseId);
> +else
> {
> /*
> * The lock is held. Now we need to recheck that login event triggers
> @@ -1002,6 +1005,7 @@ EventTriggerOnLogin(void)
> list_free(runlist);
> }
> }
> +}
> CommitTransactionCommand();
> }
>
>
> I'm getting:
> [23:03:51.341](0.000s) ok 4 - no AccessExclusiveLock FATAL on standby login
> [23:03:52.951](1.610s) not ok 5 - primary clears dathasloginevt on next login after DROP
> [23:03:52.951](0.000s)
> [23:03:52.951](0.000s) # Failed test 'primary clears dathasloginevt on next login after DROP'
> # at t/053_standby_login_event_trigger.pl line 109.
> [23:03:52.951](0.000s) # got: 't'
> # expected: 'f'
> Waiting for replication conn standby's replay_lsn to pass 0/04000000 on primary
> done
> [23:03:56.084](3.134s) not ok 6 - cleared dathasloginevt replicates to standby
> [23:03:56.085](0.000s)
> [23:03:56.085](0.000s) # Failed test 'cleared dathasloginevt replicates to standby'
> # at t/053_standby_login_event_trigger.pl line 118.
> [23:03:56.085](0.000s) # got: 't'
> # expected: 'f'
> [23:03:56.085](0.000s) 1..6
>
> 053_standby_login_event_trigger_primary.log contains:
> 2026-10-08 23:03:51.618 EDT [3254910][postmaster][:0] DEBUG: assigned pm child slot 1 for client backend
> 2026-10-08 23:03:51.619 EDT [3254910][postmaster][:0] DEBUG: forked new client backend, pid=3255516 socket=8
> 2026-10-08 23:03:51.626 EDT [3255516][client backend][:0] LOG: connection received: host=[local]
> 2026-10-08 23:03:51.641 EDT [3255516][client backend][5/0:0] DEBUG: InitPostgres
> ...
> 2026-10-08 23:03:51.756 EDT [3254910][postmaster][:0] DEBUG: postmaster received pmsignal signal
> 2026-10-08 23:03:51.756 EDT [3254910][postmaster][:0] DEBUG: assigned pm child slot 42 for autovacuum worker
> 2026-10-08 23:03:51.757 EDT [3255516][client backend][5/1:0] LOG: connection authenticated: user="u2" method=trust (.../src/test/recovery_4/tmp_check/t_053_standby_login_event_trigger_primary_data/pgdata/pg_hba.conf:117)
> 2026-10-08 23:03:51.759 EDT [3255516][client backend][5/1:0] LOG: connection authorized: user=u2 database=regress_login_evt application_name=053_standby_login_event_trigger.pl
> ...
> 2026-10-08 23:03:51.852 EDT [3255516][client backend][5/2:0] LOG: !!!EventTriggerOnLogin| could not lock database 16386
> 2026-10-08 23:03:51.935 EDT [3255522][autovacuum worker][13/0:0] DEBUG: autovacuum: processing database "regress_login_evt"
>
> So it looks like the test might fail due to autovacuum activity.
>
> [1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=skink&dt=2026-10-05%2002%3A20%3A34

Thanks for tracking this down. Since the cleanup deliberately doesn't wait
for the database lock, I think the test should allow another attempt
instead of assuming that the first login clears the flag?

The attached patch retries fresh connections to regress_login_evt until
the flag is cleared.

Regards,
Ayush