Re: On login trigger: take three

Alexander Law <exclusion@gmail.com>

From: Alexander Lakhin <exclusion@gmail.com>
To: Alexander Korotkov <aekorotkov@gmail.com>, Tom Lane <tgl@sss.pgh.pa.us>
Cc: Mikhail Gribkov <youzhick@gmail.com>, Michael Paquier <michael@paquier.xyz>, Robert Haas <robertmhaas@gmail.com>, Daniel Gustafsson <daniel@yesql.se>, Andres Freund <andres@anarazel.de>, Greg Nancarrow <gregn4422@gmail.com>, Ivan Panchenko <wao@mail.ru>, Teodor Sigaev <teodor@sigaev.ru>, Ibrar Ahmed <ibrar.ahmad@gmail.com>, vignesh C <vignesh21@gmail.com>, Pavel Stehule <pavel.stehule@gmail.com>, PostgreSQL Hackers <pgsql-hackers@postgresql.org>, Amit Kapila <amit.kapila16@gmail.com>, Masahiko Sawada <sawada.mshk@gmail.com>
Date: 2024-01-13T16:00:01Z
Lists: pgsql-hackers
Hello Alexander,

I've discovered one more instability in the event_trigger_login test.
Please look for example at case [1]:
ok 213       + event_trigger                           28946 ms
not ok 214   - event_trigger_login                      6430 ms
ok 215       - fast_default                            19349 ms
ok 216       - tablespace                              44789 ms
1..216
# 1 of 216 tests failed.

--- /home/bf/bf-build/skink-master/HEAD/pgsql/src/test/regress/expected/event_trigger_login.out 2023-10-27 
22:55:12.574139524 +0000
+++ /home/bf/bf-build/skink-master/HEAD/pgsql.build/src/test/regress/results/event_trigger_login.out 2024-01-03 
23:49:50.177461816 +0000
@@ -40,6 +40,6 @@
  SELECT dathasloginevt FROM pg_database WHERE datname= :'DBNAME';
   dathasloginevt
  ----------------
- f
+ t
  (1 row)

2024-01-03 23:49:40.378 UTC [2235175][client backend][3/5949:0] STATEMENT:  REINDEX INDEX CONCURRENTLY concur_reindex_ind;
...
2024-01-03 23:49:50.340 UTC [2260974][autovacuum worker][5/5439:18812] LOG:  automatic vacuum of table 
"regression.pg_catalog.pg_statistic": index scans: 1
(operations logged around 23:49:50.177461816)

I suspected that this failure was caused by autovacuum, and I've managed to
reproduce it without Valgrind or slowing down a machine.
With /tmp/extra.config:
log_autovacuum_min_duration = 0
autovacuum_naptime = 1
autovacuum = on

I run:
for ((i=1;i<10;i++)); do echo "ITERATION $i"; \
TEMP_CONFIG=/tmp/extra.config \
TESTS=$(printf 'event_trigger_login %.0s' `seq 1000`) \
make -s check-tests || break; done
and get failures on iterations 1, 2, 1...
ok 693       - event_trigger_login                        15 ms
not ok 694   - event_trigger_login                        15 ms
ok 695       - event_trigger_login                        21 ms

Also, I've observed an anomaly after dropping a login event trigger:
CREATE FUNCTION on_login_proc() RETURNS event_trigger AS $$
BEGIN RAISE NOTICE 'You are welcome!'; END; $$ LANGUAGE plpgsql;
CREATE EVENT TRIGGER olt ON login EXECUTE PROCEDURE on_login_proc();
SELECT dathasloginevt FROM pg_database WHERE datname= current_database();
  dathasloginevt
----------------
  t
(1 row)

DROP EVENT TRIGGER olt;
SELECT dathasloginevt FROM pg_database WHERE datname= current_database();
  dathasloginevt
----------------
  t
(1 row)

Although after reconnection (\c, as done in the event_trigger_login test),
this query returns 'f'.

[1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=skink&dt=2024-01-03%2023%3A04%3A20
[2] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=skink&dt=2023-12-26%2019%3A33%3A02

Best regards,
Alexander



Commits

  1. Fix some typos in event trigger docs

  2. Use heap_inplace_update() to unset pg_database.dathasloginevt

  3. Remove the flaky check in event_trigger_login regression test

  4. Fix instable 006_login_trigger.pl test

  5. Add support event triggers on authenticated login

  6. Add GUC for temporarily disabling event triggers

  7. Fix typo in reference to __FreeBSD__.

  8. Restore robustness of TAP tests that wait for postmaster restart.

  9. Restore the portal-level snapshot after procedure COMMIT/ROLLBACK.