Re: 2 new contributions to pgdg

Re: Jeremy Finzel 2018-11-14 <CAMa1XUiwpTZxZpywXJk8ueCiNhgT+2ARMGwu_HcEaRTKG+6uVQ@mail.gmail.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]@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]@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]@[unknown] LOG:  incomplete startup packet
10:40:12 2018-11-21 09:39:54.998 UTC [6416] [unknown]@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]@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]@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@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@contrib_regression HINT:  You can drop extension pglogical_ticker instead.
10:40:12 2018-11-21 09:40:12.360 UTC [6453] postgres@contrib_regression STATEMENT:  DROP TABLE pglogical_ticker.test1;
10:40:12 2018-11-21 09:40:12.434 UTC [6418] [unknown]@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]@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]@[unknown] LOG:  incomplete startup packet
10:41:18 2018-11-21 09:40:59.653 UTC [5691] [unknown]@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]@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]@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]@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@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@contrib_regression HINT:  You can drop extension pglogical_ticker instead.
10:41:18 2018-11-21 09:41:18.841 UTC [5769] postgres@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