Re: BUG #19488: Standby connection fails after dropping on login event trigger enabled always - Mailing list pgsql-bugs
| From | Alexander Lakhin |
|---|---|
| Subject | Re: BUG #19488: Standby connection fails after dropping on login event trigger enabled always |
| Date | |
| Msg-id | 09561429-50c1-4d06-a262-300c7a845175@gmail.com Whole thread |
| In response to | Re: BUG #19488: Standby connection fails after dropping on login event trigger enabled always (Alexander Korotkov <aekorotkov@gmail.com>) |
| Responses |
Re: BUG #19488: Standby connection fails after dropping on login event trigger enabled always
|
| List | pgsql-bugs |
Hello Alexander,
25.05.2026 11:53, Alexander Korotkov wrote:
25.05.2026 11:53, Alexander Korotkov wrote:
On Thu, May 21, 2026 at 2:48 PM Ayush Tiwari <ayushtiwari.slg01@gmail.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
Best regards,
Alexander
pgsql-bugs by date: