Re: 2 new contributions to pgdg

Dear Christoph,

I have just pushed up commits to fix the regression tests. Please let me
know if it passes, and I will cut releases.

Thank you!
Jeremy

On Fri, Nov 9, 2018 at 5:22 PM Jeremy Finzel <finzelj(at)gmail(dot)com> wrote:

> Dear Christoph,
>
> Regarding the first test failure, it is very interesting. I am still
> seeing the test result differently than you (as well as another co-worker)
> on both 11.0 and 11.1. I see this same result on all of my local 9.5-10
> installs as well.
>
> The test is trying to launch a background worker on an invalid database
> OID. I found that the behavior of that changed on my own machine when I
> moved from debian wheezy to ubuntu xenial, when I also upgraded point
> release versions. In your environment, it looks like you are seeing the
> behavior that I used to see. Here was that post (which received no
> replies):
> https://www.postgresql.org/message-id/CAMa1XUi0g7KRbzcxPwNvBfGU2vh9A9jwHZ4EWTmaJzLrOhHA2Q@mail.gmail.com
>
> I changed that test because it used to do what you are showing - it would
> show an actual pid. But this is what happens in my environment:
>
> ERROR: could not start background process
> HINT: More details may be available in the server log.
>
> Do you have any idea how this could happen? I'm a bit at a loss.
>
> I may ping hackers again to see if anyone has ideas.
>
> Thanks,
> Jeremy
>
>
> On Fri, Nov 9, 2018 at 3:57 PM Christoph Berg <myon(at)debian(dot)org> wrote:
>
>> Re: Jeremy Finzel 2018-11-09 <
>> CAMa1XUhLN8Ur-Fgded0NLiopRrqnwn_vA5Sd-SUqbixTQrr7qg(at)mail(dot)gmail(dot)com>
>> > Dear Christoph,
>> >
>> > I have 2 new packages I would like to contribute to pgdg:
>>
>> Cool :)
>>
>> > pglogical_ticker: https://github.com/enova/pglogical_ticker (Time-based
>> > replication delay for pglogical)
>>
>> The package looks mostly fine, but it fails the regression tests:
>>
>> Ver Cluster Port Status Owner Data directory
>> Log file
>> 11 regress 5433 online postgres
>> /tmp/pg_virtualenv.pURpIq/data/11/regress
>> /tmp/pg_virtualenv.pURpIq/log/postgresql-11-regress.log
>>
>> /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
>> (using postmaster on localhost, port 5433)
>> ============== dropping database "contrib_regression" ==============
>> NOTICE: database "contrib_regression" does not exist, skipping
>> DROP DATABASE
>> ============== creating database "contrib_regression" ==============
>> CREATE DATABASE
>> ALTER DATABASE
>> ============== running regression test queries ==============
>> test 01_create_ext ... ok
>> test 02_setup ... ok
>> test 03_deploy ... ok
>> test 04_add_to_rep ... ok
>> test 05_tick ... ok
>> test 06_worker ... ok
>> test 07_handlers ... FAILED
>> test 08_reentrance ... ok
>> test 09_1_2_tests ... FAILED
>> test 99_cleanup ... ok
>>
>> =======================
>> 2 of 10 tests failed.
>> =======================
>>
>> The differences that caused some tests to fail can be viewed in the
>> file "/tmp/autopkgtest.qWZgMz/tree/regression.diffs". A copy of the test
>> summary that you see
>> above is saved in the file "/tmp/autopkgtest.qWZgMz/tree/regression.out".
>>
>> make: *** [/usr/lib/postgresql/11/lib/pgxs/src/makefiles/pgxs.mk:396:
>> installcheck] Error 1
>> *** /tmp/pg_virtualenv.pURpIq/log/postgresql-11-regress.log (last 100
>> lines) ***
>> 2018-11-09 22:44:53.961 CET [17933] LOG: listening on IPv6 address
>> "::1", port 5433
>> 2018-11-09 22:44:53.961 CET [17933] LOG: listening on IPv4 address
>> "127.0.0.1", port 5433
>> 2018-11-09 22:44:53.961 CET [17933] LOG: listening on Unix socket
>> "/var/run/postgresql/.s.PGSQL.5433"
>> 2018-11-09 22:44:53.968 CET [17934] LOG: database system was shut down
>> at 2018-11-09 22:44:53 CET
>> 2018-11-09 22:44:53.971 CET [17933] LOG: database system is ready to
>> accept connections
>> 2018-11-09 22:44:53.971 CET [17940] LOG: starting pglogical supervisor
>> 2018-11-09 22:44:53.976 CET [17942] [unknown](at)postgres LOG: manager
>> worker [17942] at slot 0 generation 1 detaching cleanly
>> 2018-11-09 22:44:53.982 CET [17943] [unknown](at)template1 LOG: manager
>> worker [17943] at slot 0 generation 2 detaching cleanly
>> 2018-11-09 22:44:54.552 CET [17945] [unknown](at)[unknown] LOG: incomplete
>> startup packet
>> 2018-11-09 22:44:56.563 CET [17989] [unknown](at)postgres LOG: manager
>> worker [17989] at slot 0 generation 3 detaching cleanly
>> 2018-11-09 22:44:56.567 CET [17990] [unknown](at)contrib_regression LOG:
>> starting pglogical database manager for database contrib_regression
>> 2018-11-09 22:44:56.699 CET [18007] LOG: pglogical_ticker worker
>> initialized
>> 2018-11-09 22:44:57.569 CET [18009] [unknown](at)template1 LOG: manager
>> worker [18009] at slot 1 generation 1 detaching cleanly
>> 2018-11-09 22:45:09.725 CET [18007] ERROR: canceling statement due to
>> user request
>> 2018-11-09 22:45:09.727 CET [17933] LOG: background worker
>> "pglogical_ticker" (PID 18007) exited with exit code 1
>> 2018-11-09 22:45:09.732 CET [18017] LOG: pglogical_ticker worker
>> initialized
>> 2018-11-09 22:45:11.734 CET [18017] ERROR: canceling statement due to
>> user request
>> 2018-11-09 22:45:11.736 CET [17933] LOG: background worker
>> "pglogical_ticker" (PID 18017) exited with exit code 1
>> 2018-11-09 22:45:11.760 CET [18022] FATAL: database 9999999 does not
>> exist
>> 2018-11-09 22:45:11.761 CET [17933] LOG: background worker
>> "pglogical_ticker" (PID 18022) exited with exit code 1
>> 2018-11-09 22:45:11.764 CET [18023] LOG: pglogical_ticker worker
>> initialized
>> 2018-11-09 22:45:11.767 CET [18024] LOG: pglogical_ticker worker
>> initialized
>> 2018-11-09 22:45:12.769 CET [18024] ERROR: canceling statement due to
>> user request
>> 2018-11-09 22:45:12.769 CET [18023] ERROR: canceling statement due to
>> user request
>> 2018-11-09 22:45:12.771 CET [17933] LOG: background worker
>> "pglogical_ticker" (PID 18023) exited with exit code 1
>> 2018-11-09 22:45:12.771 CET [17933] LOG: background worker
>> "pglogical_ticker" (PID 18024) exited with exit code 1
>> 2018-11-09 22:45:13.853 CET [18035] postgres(at)contrib_regression ERROR:
>> cannot drop table pglogical_ticker.test1 because extension pglogical_ticker
>> requires it
>> 2018-11-09 22:45:13.853 CET [18035] postgres(at)contrib_regression HINT:
>> You can drop extension pglogical_ticker instead.
>> 2018-11-09 22:45:13.853 CET [18035] postgres(at)contrib_regression
>> STATEMENT: DROP TABLE pglogical_ticker.test1;
>> 2018-11-09 22:45:13.893 CET [17990] [unknown](at)contrib_regression LOG:
>> manager worker [17990] at slot 0 generation 4 detaching cleanly
>> Dropping cluster 11/regress ...
>> **** regression.diffs ****
>> *** /tmp/autopkgtest.qWZgMz/tree/expected/07_handlers.out
>> 2018-11-09 22:42:25.902459886 +0100
>> --- /tmp/autopkgtest.qWZgMz/tree/results/07_handlers.out
>> 2018-11-09 22:45:13.771207281 +0100
>> ***************
>> *** 2,16 ****
>> --The _launch function is not supposed to be used directly
>> --This tests that stupid things don't do something really bad
>> SELECT pglogical_ticker._launch(9999999::OID) AS pid;
>> ! ERROR: could not start background process
>> ! HINT: More details may be available in the server log.
>> --Verify that it exits cleanly if the SQL within the worker errors out
>> --In this case, renaming the function will do it
>> ALTER FUNCTION pglogical_ticker.tick() RENAME TO tick_oops;
>> SELECT pglogical_ticker.launch();
>> ! ERROR: could not start background process
>> ! HINT: More details may be available in the server log.
>> ! CONTEXT: SQL function "launch" statement 1
>> ALTER FUNCTION pglogical_ticker.tick_oops() RENAME TO tick;
>> --Verify we can't start multiple workers - the second attempt should
>> return NULL
>> --We know this is imperfect but so long as pglogical_ticker.launch is
>> not executed
>> --- 2,21 ----
>> --The _launch function is not supposed to be used directly
>> --This tests that stupid things don't do something really bad
>> SELECT pglogical_ticker._launch(9999999::OID) AS pid;
>> ! pid
>> ! -------
>> ! 18022
>> ! (1 row)
>> !
>> --Verify that it exits cleanly if the SQL within the worker errors out
>> --In this case, renaming the function will do it
>> ALTER FUNCTION pglogical_ticker.tick() RENAME TO tick_oops;
>> SELECT pglogical_ticker.launch();
>> ! launch
>> ! --------
>> ! 18023
>> ! (1 row)
>> !
>> ALTER FUNCTION pglogical_ticker.tick_oops() RENAME TO tick;
>> --Verify we can't start multiple workers - the second attempt should
>> return NULL
>> --We know this is imperfect but so long as pglogical_ticker.launch is
>> not executed
>> ***************
>> *** 43,49 ****
>> pg_cancel_backend
>> -------------------
>> t
>> ! (1 row)
>>
>> SELECT pg_sleep(1);
>> pg_sleep
>> --- 48,55 ----
>> pg_cancel_backend
>> -------------------
>> t
>> ! t
>> ! (2 rows)
>>
>> SELECT pg_sleep(1);
>> pg_sleep
>>
>> ======================================================================
>>
>> *** /tmp/autopkgtest.qWZgMz/tree/expected/09_1_2_tests.out
>> 2018-11-09 22:42:25.902459886 +0100
>> --- /tmp/autopkgtest.qWZgMz/tree/results/09_1_2_tests.out
>> 2018-11-09 22:45:13.851207793 +0100
>> ***************
>> *** 98,105 ****
>> ORDER BY set_name, set_reloid::TEXT;
>> set_name | set_reloid
>> ----------+--------------------------------------
>> - test1 | pglogical_ticker.ddl_sql
>> test1 | pglogical_ticker."default"
>> test1 | pglogical_ticker.default_insert_only
>> test1 | pglogical_ticker.test1
>> test1 | pglogical_ticker.test10
>> --- 98,105 ----
>> ORDER BY set_name, set_reloid::TEXT;
>> set_name | set_reloid
>> ----------+--------------------------------------
>> test1 | pglogical_ticker."default"
>> + test1 | pglogical_ticker.ddl_sql
>> test1 | pglogical_ticker.default_insert_only
>> test1 | pglogical_ticker.test1
>> test1 | pglogical_ticker.test10
>>
>> ======================================================================
>>
>> autopkgtest [22:45:14]: test installcheck: -----------------------]
>> autopkgtest [22:45:14]: test installcheck: - - - - - - - - - - results -
>> - - - - - - - - -
>> installcheck FAIL non-zero exit status 1
>>
>>
>> One minor thing: remove debian/files from git, it's a temporary file
>> during build.
>>
>> > pg_fact_loader: https://github.com/enova/pg_fact_loader (Build fact
>> tables
>> > asynchronously with Postgres)
>>
>> (Will try that later.)
>>
>> > pg_fact_loader does not explicitly depend on pglogical_ticker (it can be
>> > used with or without), however, some of the test suite does depend on
>> it.
>> > I'm not sure exactly how that needs to be configured but wanted to
>> point it
>> > out.
>>
>> You can add test dependencies in debian/tests/control:
>>
>> Depends: @, postgresql-server-dev-all
>> Tests: installcheck
>> Restrictions: allow-stderr
>>
>> For dependencies depending on the PG version, use
>> debian/tests/control.in:
>>
>> Depends: @, postgresql-server-dev-all,
>> postgresql-PGVERSION-pglogical-ticker
>> Tests: installcheck
>> Restrictions: allow-stderr
>>
>> > Please let us know if there's anything else you need, and I appreciate
>> your
>> > help with these!
>>
>> There are no releases on Github yet, so the debian/watch files can't
>> find the tarballs.
>>
>> Christoph
>>
>