Re: 2 new contributions to pgdg

Dear Christoph,

Thank you for the review and I'm sorry for this nuisance. I have tagged a
new release version 1.5.1 which should fix this issue.

I missed this bug due to my own old extension files still existing and not
removed via make uninstall because they had already been removed from my
Makefile. I am hoping this should cover all the errors you had not only
with 11 but with 9.5+.

Thanks!
Jeremy

On Wed, Nov 21, 2018 at 5:31 AM Christoph Berg <myon(at)debian(dot)org> wrote:

> 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
>