Re: 2 new contributions to pgdg

Re: Jeremy Finzel 2018-11-14 <CAMa1XUiwpTZxZpywXJk8ueCiNhgT+2ARMGwu_HcEaRTKG+6uVQ(at)mail(dot)gmail(dot)com>
> Hello again -
>
> I have just tagged releases:
> v1.3.0 pglogical_ticker

So here's the promised update.

pglogical_ticker is basically fine, but the regression tests seem
flaky. Re-running fixed the problems, so I put the package live now.

Two builds were failing (each with 6 PG versions, testing stops on the
first problem):

https://pgdgbuild.dus.dg-i.net/job/pglogical-ticker-binaries/1/architecture=i386,distribution=stretch/console

10:39:54 /usr/lib/postgresql/11/lib/pgxs/src/makefiles/../../src/test/regress/pg_regress --inputdir=./ --bindir='/usr/lib/postgresql/11/bin' --dbname=contrib_regression 01_create_ext 02_setup 03_deploy 04_add_to_rep 05_tick 06_worker 07_handlers 08_reentrance 09_1_2_tests 99_cleanup
10:39:54 (using postmaster on localhost, port 5432)
10:39:54 ============== dropping database "contrib_regression" ==============
10:39:54 NOTICE: database "contrib_regression" does not exist, skipping
10:39:54 DROP DATABASE
10:39:54 ============== creating database "contrib_regression" ==============
10:39:54 CREATE DATABASE
10:39:54 ALTER DATABASE
10:39:54 ============== running regression test queries ==============
10:39:54 test 01_create_ext ... ok
10:39:55 test 02_setup ... ok
10:39:55 test 03_deploy ... ok
10:39:55 test 04_add_to_rep ... ok
10:39:55 test 05_tick ... ok
10:40:10 test 06_worker ... ok
10:40:12 test 07_handlers ... FAILED
10:40:12 test 08_reentrance ... ok
10:40:12 test 09_1_2_tests ... ok
10:40:12 test 99_cleanup ... ok
10:40:12
10:40:12 =======================
10:40:12 1 of 10 tests failed.
10:40:12 =======================
10:40:12
10:40:12 The differences that caused some tests to fail can be viewed in the
10:40:12 file "/tmp/autopkgtest.SdZHJC/tree/regression.diffs". A copy of the test summary that you see
10:40:12 above is saved in the file "/tmp/autopkgtest.SdZHJC/tree/regression.out".
10:40:12
10:40:12 make: *** [installcheck] Error 1
10:40:12 /usr/lib/postgresql/11/lib/pgxs/src/makefiles/pgxs.mk:396: recipe for target 'installcheck' failed
10:40:12 *** /tmp/pg_virtualenv.I2s8KW/log/postgresql-11-regress.log (last 100 lines) ***
10:40:12 2018-11-21 09:39:52.574 UTC [6361] LOG: listening on IPv6 address "::1", port 5432
10:40:12 2018-11-21 09:39:52.574 UTC [6361] LOG: listening on IPv4 address "127.0.0.1", port 5432
10:40:12 2018-11-21 09:39:52.574 UTC [6361] LOG: listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
10:40:12 2018-11-21 09:39:52.586 UTC [6362] LOG: database system was shut down at 2018-11-21 09:39:52 UTC
10:40:12 2018-11-21 09:39:52.590 UTC [6361] LOG: database system is ready to accept connections
10:40:12 2018-11-21 09:39:52.590 UTC [6368] LOG: starting pglogical supervisor
10:40:12 2018-11-21 09:39:52.596 UTC [6370] [unknown](at)postgres LOG: manager worker [6370] at slot 0 generation 1 detaching cleanly
10:40:12 2018-11-21 09:39:52.603 UTC [6371] [unknown](at)template1 LOG: manager worker [6371] at slot 0 generation 2 detaching cleanly
10:40:12 2018-11-21 09:39:53.164 UTC [6372] [unknown](at)[unknown] LOG: incomplete startup packet
10:40:12 2018-11-21 09:39:54.998 UTC [6416] [unknown](at)postgres LOG: manager worker [6416] at slot 0 generation 3 detaching cleanly
10:40:12 2018-11-21 09:39:55.002 UTC [6418] [unknown](at)contrib_regression LOG: starting pglogical database manager for database contrib_regression
10:40:12 2018-11-21 09:39:55.152 UTC [6434] LOG: pglogical_ticker worker initialized
10:40:12 2018-11-21 09:39:56.004 UTC [6435] [unknown](at)template1 LOG: manager worker [6435] at slot 1 generation 1 detaching cleanly
10:40:12 2018-11-21 09:40:08.163 UTC [6434] ERROR: canceling statement due to user request
10:40:12 2018-11-21 09:40:08.166 UTC [6361] LOG: background worker "pglogical_ticker" (PID 6434) exited with exit code 1
10:40:12 2018-11-21 09:40:08.177 UTC [6436] LOG: pglogical_ticker worker initialized
10:40:12 2018-11-21 09:40:10.179 UTC [6436] ERROR: canceling statement due to user request
10:40:12 2018-11-21 09:40:10.181 UTC [6361] LOG: background worker "pglogical_ticker" (PID 6436) exited with exit code 1
10:40:12 2018-11-21 09:40:10.222 UTC [6441] FATAL: database 9999999 does not exist
10:40:12 2018-11-21 09:40:10.223 UTC [6442] LOG: pglogical_ticker worker initialized
10:40:12 2018-11-21 09:40:10.224 UTC [6361] LOG: background worker "pglogical_ticker" (PID 6441) exited with exit code 1
10:40:12 2018-11-21 09:40:11.227 UTC [6442] ERROR: canceling statement due to user request
10:40:12 2018-11-21 09:40:11.229 UTC [6361] LOG: background worker "pglogical_ticker" (PID 6442) exited with exit code 1
10:40:12 2018-11-21 09:40:12.360 UTC [6453] postgres(at)contrib_regression ERROR: cannot drop table pglogical_ticker.test1 because extension pglogical_ticker requires it
10:40:12 2018-11-21 09:40:12.360 UTC [6453] postgres(at)contrib_regression HINT: You can drop extension pglogical_ticker instead.
10:40:12 2018-11-21 09:40:12.360 UTC [6453] postgres(at)contrib_regression STATEMENT: DROP TABLE pglogical_ticker.test1;
10:40:12 2018-11-21 09:40:12.434 UTC [6418] [unknown](at)contrib_regression LOG: manager worker [6418] at slot 0 generation 4 detaching cleanly
10:40:12 Dropping cluster 11/regress ...
10:40:12 **** regression.diffs ****
10:40:12 *** /tmp/autopkgtest.SdZHJC/tree/expected/07_handlers.out 2018-11-13 18:43:54.000000000 +0000
10:40:12 --- /tmp/autopkgtest.SdZHJC/tree/results/07_handlers.out 2018-11-21 09:40:12.228123205 +0000
10:40:12 ***************
10:40:12 *** 26,32 ****
10:40:12 SELECT pglogical_ticker.launch() IS NULL AS pid;
10:40:12 pid
10:40:12 -----
10:40:12 ! f
10:40:12 (1 row)
10:40:12
10:40:12 SELECT pg_sleep(1);
10:40:12 --- 26,32 ----
10:40:12 SELECT pglogical_ticker.launch() IS NULL AS pid;
10:40:12 pid
10:40:12 -----
10:40:12 ! t
10:40:12 (1 row)
10:40:12
10:40:12 SELECT pg_sleep(1);
10:40:12

https://pgdgbuild.dus.dg-i.net/job/pglogical-ticker-binaries/1/architecture=ppc64el,distribution=xenial/console

10:41:00 /usr/lib/postgresql/9.5/lib/pgxs/src/makefiles/../../src/test/regress/pg_regress --inputdir=./ --bindir='/usr/lib/postgresql/9.5/bin' --dbname=contrib_regression 01_create_ext 02_setup 03_deploy 04_add_to_rep 05_tick 06_worker 07_handlers 08_reentrance 09_1_2_tests 99_cleanup
10:41:00 (using postmaster on localhost, port 5432)
10:41:00 ============== dropping database "contrib_regression" ==============
10:41:00 NOTICE: database "contrib_regression" does not exist, skipping
10:41:00 DROP DATABASE
10:41:00 ============== creating database "contrib_regression" ==============
10:41:01 CREATE DATABASE
10:41:01 ALTER DATABASE
10:41:01 ============== running regression test queries ==============
10:41:01 test 01_create_ext ... ok
10:41:01 test 02_setup ... ok
10:41:01 test 03_deploy ... ok
10:41:01 test 04_add_to_rep ... ok
10:41:01 test 05_tick ... ok
10:41:16 test 06_worker ... FAILED
10:41:18 test 07_handlers ... ok
10:41:18 test 08_reentrance ... ok
10:41:18 test 09_1_2_tests ... ok
10:41:18 test 99_cleanup ... ok
10:41:18
10:41:18 =======================
10:41:18 1 of 10 tests failed.
10:41:18 =======================
10:41:18
10:41:18 The differences that caused some tests to fail can be viewed in the
10:41:18 file "/tmp/adt-run.Ctjy5G/tree/regression.diffs". A copy of the test summary that you see
10:41:18 above is saved in the file "/tmp/adt-run.Ctjy5G/tree/regression.out".
10:41:18
10:41:18 /usr/lib/postgresql/9.5/lib/pgxs/src/makefiles/pgxs.mk:274: recipe for target 'installcheck' failed
10:41:18 make: *** [installcheck] Error 1
10:41:18 *** /tmp/pg_virtualenv.AKgntO/log/postgresql-9.5-regress.log (last 100 lines) ***
10:41:18 2018-11-21 09:40:58.638 UTC [5679] LOG: database system was shut down at 2018-11-21 09:40:58 UTC
10:41:18 2018-11-21 09:40:58.639 UTC [5679] LOG: MultiXact member wraparound protections are now enabled
10:41:18 2018-11-21 09:40:58.645 UTC [5683] LOG: autovacuum launcher started
10:41:18 2018-11-21 09:40:58.647 UTC [5678] LOG: database system is ready to accept connections
10:41:18 2018-11-21 09:40:58.648 UTC [5685] LOG: starting pglogical supervisor
10:41:18 2018-11-21 09:40:58.656 UTC [5686] [unknown](at)template1 LOG: manager worker [5686] at slot 0 generation 1 detaching cleanly
10:41:18 2018-11-21 09:40:59.122 UTC [5687] [unknown](at)[unknown] LOG: incomplete startup packet
10:41:18 2018-11-21 09:40:59.653 UTC [5691] [unknown](at)postgres LOG: manager worker [5691] at slot 0 generation 2 detaching cleanly
10:41:18 2018-11-21 09:41:01.367 UTC [5732] [unknown](at)template1 LOG: manager worker [5732] at slot 0 generation 3 detaching cleanly
10:41:18 2018-11-21 09:41:01.614 UTC [5749] LOG: pglogical_ticker worker initialized
10:41:18 2018-11-21 09:41:02.380 UTC [5750] [unknown](at)postgres LOG: manager worker [5750] at slot 0 generation 4 detaching cleanly
10:41:18 2018-11-21 09:41:03.373 UTC [5751] [unknown](at)contrib_regression LOG: starting pglogical database manager for database contrib_regression
10:41:18 2018-11-21 09:41:14.635 UTC [5749] ERROR: canceling statement due to user request
10:41:18 2018-11-21 09:41:14.638 UTC [5678] LOG: worker process: pglogical_ticker worker (PID 5749) exited with exit code 1
10:41:18 2018-11-21 09:41:16.700 UTC [5758] FATAL: database 9999999 does not exist
10:41:18 2018-11-21 09:41:16.703 UTC [5678] LOG: worker process: pglogical_ticker worker (PID 5758) exited with exit code 1
10:41:18 2018-11-21 09:41:16.705 UTC [5759] LOG: pglogical_ticker worker initialized
10:41:18 2018-11-21 09:41:16.706 UTC [5760] LOG: pglogical_ticker worker initialized
10:41:18 2018-11-21 09:41:17.709 UTC [5759] ERROR: canceling statement due to user request
10:41:18 2018-11-21 09:41:17.709 UTC [5760] ERROR: canceling statement due to user request
10:41:18 2018-11-21 09:41:17.712 UTC [5678] LOG: worker process: pglogical_ticker worker (PID 5759) exited with exit code 1
10:41:18 2018-11-21 09:41:17.712 UTC [5678] LOG: worker process: pglogical_ticker worker (PID 5760) exited with exit code 1
10:41:18 2018-11-21 09:41:18.841 UTC [5769] postgres(at)contrib_regression ERROR: cannot drop table pglogical_ticker.test1 because extension pglogical_ticker requires it
10:41:18 2018-11-21 09:41:18.841 UTC [5769] postgres(at)contrib_regression HINT: You can drop extension pglogical_ticker instead.
10:41:18 2018-11-21 09:41:18.841 UTC [5769] postgres(at)contrib_regression STATEMENT: DROP TABLE pglogical_ticker.test1;
10:41:18 Dropping cluster 9.5/regress ...
10:41:20 **** regression.diffs ****
10:41:20 *** /tmp/adt-run.Ctjy5G/tree/expected/06_worker.out 2018-11-13 18:43:54.000000000 +0000
10:41:20 --- /tmp/adt-run.Ctjy5G/tree/results/06_worker.out 2018-11-21 09:41:16.641272199 +0000
10:41:20 ***************
10:41:20 *** 47,60 ****
10:41:20 SELECT COUNT(1) FROM worker_pid WHERE pid IS NOT NULL;
10:41:20 count
10:41:20 -------
10:41:20 ! 1
10:41:20 (1 row)
10:41:20
10:41:20 SELECT pg_cancel_backend(pid)
10:41:20 FROM worker_pid;
10:41:20 pg_cancel_backend
10:41:20 -------------------
10:41:20 ! t
10:41:20 (1 row)
10:41:20
10:41:20 --Test it does nothing with no tables
10:41:20 --- 47,60 ----
10:41:20 SELECT COUNT(1) FROM worker_pid WHERE pid IS NOT NULL;
10:41:20 count
10:41:20 -------
10:41:20 ! 0
10:41:20 (1 row)
10:41:20
10:41:20 SELECT pg_cancel_backend(pid)
10:41:20 FROM worker_pid;
10:41:20 pg_cancel_backend
10:41:20 -------------------
10:41:20 !
10:41:20 (1 row)
10:41:20
10:41:20 --Test it does nothing with no tables
10:41:20

> v1.5.0 pg_fact_loader

07_launch_worker.out fails:

7 | 0001234567 | 35 | | 0 |
8 | 0001234568 | 35 | | 0 |
9 | 0001234569 | 35 | | 0 |
! 10 | 0001234577 | 35 | | 0 |
(10 rows)

UPDATE fact_loader.fact_tables SET force_worker_priority = FALSE WHERE fact_table_relid = 'test_fact.customers_fact'::REGCLASS;
--- 35,41 ----
7 | 0001234567 | 35 | | 0 |
8 | 0001234568 | 35 | | 0 |
9 | 0001234569 | 35 | | 0 |
! 10 | 0001234560 | 35 | | 0 |
(10 rows)

UPDATE fact_loader.fact_tables SET force_worker_priority = FALSE WHERE fact_table_relid = 'test_fact.customers_fact'::REGCLASS;

The regression tests need the extension version adjusted:

--- /tmp/autopkgtest.7mlirf/tree/results/17_1_3_features.out 2018-11-21 10:37:51.174647317 +0100
CREATE EXTENSION pg_fact_loader VERSION '1.2';
+ ERROR: extension "pg_fact_loader" has no installation script nor update path for version "1.2"

--- /tmp/autopkgtest.7mlirf/tree/results/18_alter_update_features.out
CREATE EXTENSION pg_fact_loader VERSION '1.2';
+ ERROR: extension "pg_fact_loader" has no installation script nor update path for version "1.2"

That's on 11, the 9.5 log is worse: https://pgdgbuild.dus.dg-i.net/job/pg-fact-loader-binaries/2/architecture=amd64,distribution=sid/console
Not sure how much of that is cause by hstore missing, you'll need to
add postgresql-contrib-PGVERSION to debian/tests/control.in. (For
PG10, -contrib is included in the main server package.)

Christoph