Re: 2 new contributions to pgdg

Hello again -

I have just tagged releases:
v1.3.0 pglogical_ticker
v1.5.0 pg_fact_loader

Hoping everything checks out. Let me know if anything is amiss.

Thanks,
Jeremy

On Tue, Nov 13, 2018 at 3:55 PM Jeremy Finzel <finzelj(at)gmail(dot)com> wrote:

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