--- Begin Message ---
Source: pg-fact-loader
Version: 1.7.0-2
Severity: serious
User: debian...@lists.debian.org
Usertags: regression
Dear maintainer(s),
With a recent upload of pg-fact-loader the autopkgtest of pg-fact-loader
fails in testing when that autopkgtest is run with the binary packages
of pg-fact-loader from unstable. It passes when run with only packages
from testing. In tabular form:
pass fail
pg-fact-loader from testing 1.7.0-2
versioned deps [0] from testing from unstable
all others from testing from testing
I copied some of the output at the bottom of this report.
Currently this regression is blocking the migration to testing [1]. Can
you please investigate the situation and fix it?
More information about this bug and the reason for filing it can be found on
https://wiki.debian.org/ContinuousIntegration/RegressionEmailInformation
Paul
[0] You can see what packages were added from the second line of the log
file quoted below. The migration software adds source package from
unstable to the list if they are needed to install packages from
pg-fact-loader/1.7.0-2. I.e. due to versioned dependencies or
breaks/conflicts.
[1] https://qa.debian.org/excuses.php?package=pg-fact-loader
https://ci.debian.net/data/autopkgtest/testing/amd64/p/pg-fact-loader/27687022/log.gz
### PostgreSQL 15 installcheck ###
Creating new PostgreSQL cluster 15/regress ...
echo "+++ regress install-check in +++" &&
/usr/lib/postgresql/15/lib/pgxs/src/makefiles/../../src/test/regress/pg_regress
--inputdir=./ --bindir='/usr/lib/postgresql/15/bin'
--dbname=contrib_regression 01_create_ext 02_schema 03_audit 04_seeds
05_pgl_setup 06_basic_workers 07_launch_worker 08_fact_table_deps
09_purge 10_delete 11_more_data 12_no_proid 13_cutoff_no_dep_on_filter
14_null_key 15_source_change_date 16_1_2_features 17_1_3_features
+++ regress install-check in +++
(using postmaster on localhost, port 5433)
============== dropping database "contrib_regression" ==============
SET
DROP DATABASE
============== creating database "contrib_regression" ==============
CREATE DATABASE
ALTER DATABASE
ALTER DATABASE
ALTER DATABASE
ALTER DATABASE
ALTER DATABASE
ALTER DATABASE
============== running regression test queries ==============
test 01_create_ext ... ok 146 ms
test 02_schema ... ok 92 ms
test 03_audit ... ok 41 ms
test 04_seeds ... ok 64 ms
test 05_pgl_setup ... ok 27 ms
test 06_basic_workers ... ok 8854 ms
test 07_launch_worker ... ok 4031 ms
test 08_fact_table_deps ... ok 2663 ms
test 09_purge ... ok 176 ms
test 10_delete ... ok 13701 ms
test 11_more_data ... ok 6198 ms
test 12_no_proid ... ok 10785 ms
test 13_cutoff_no_dep_on_filter ... ok 36008 ms
test 14_null_key ... ok 238 ms
test 15_source_change_date ... ok 101 ms
test 16_1_2_features ... ok 3220 ms
test 17_1_3_features ... FAILED 8219 ms
=======================
1 of 17 tests failed. =======================
The differences that caused some tests to fail can be viewed in the
file
"/tmp/autopkgtest-lxc.68jcp06n/downtmp/build.L0a/src/regression.diffs".
A copy of the test summary that you see
above is saved in the file
"/tmp/autopkgtest-lxc.68jcp06n/downtmp/build.L0a/src/regression.out".
make: *** [/usr/lib/postgresql/15/lib/pgxs/src/makefiles/pgxs.mk:433:
installcheck] Error 1
*** /tmp/pg_virtualenv.Azz268/log/postgresql-15-regress.log (last 100
lines) ***
, update_key AS (
SELECT qdwr.queue_table_dep_id,
--Cutoff the id to that newly found, otherwise default to last value
COALESCE(mu.last_cutoff_id, qdwr.last_cutoff_id) AS last_cutoff_id,
--This cutoff time must always be the same for all queue tables for
given fact table.
--Even if there are no new records, we move this forward to wherever
the stream is at
qdwr.maximum_cutoff_time AS last_cutoff_source_time
FROM fact_loader.queue_deps_all qdwr
LEFT JOIN new_metadata mu ON mu.queue_table_dep_id =
qdwr.queue_table_dep_id
WHERE qdwr.fact_table_id = 2
--Exclude dependent fact tables from updates directly to
queue_table_deps
AND qdwr.fact_table_dep_id IS NULL
)
/****
This SQL also nearly matches that for the queue_table_deps but would be
a little ugly to try to DRY up
****/
, update_key_fact_dep AS (
SELECT qdwr.fact_table_dep_queue_table_dep_id,
qdwr.fact_table_id,
COALESCE(mu.last_cutoff_id, qdwr.last_cutoff_id) AS last_cutoff_id,
qdwr.maximum_cutoff_time AS last_cutoff_source_time
FROM fact_loader.queue_deps_all qdwr
LEFT JOIN new_metadata_fact_dep mu ON
mu.fact_table_dep_queue_table_dep_id =
qdwr.fact_table_dep_queue_table_dep_id
WHERE qdwr.fact_table_id = 2
--Include dependent fact tables only
AND qdwr.fact_table_dep_id IS NOT NULL
)
, updated_queue_table_deps AS (
UPDATE fact_loader.queue_table_deps qtd
SET last_cutoff_id = uk.last_cutoff_id,
last_cutoff_source_time = uk.last_cutoff_source_time
FROM update_key uk
WHERE qtd.queue_table_dep_id = uk.queue_table_dep_id
RETURNING qtd.*)
, updated_fact_table_deps AS (
UPDATE fact_loader.fact_table_dep_queue_table_deps ftd
SET last_cutoff_id = uk.last_cutoff_id,
last_cutoff_source_time = uk.last_cutoff_source_time
FROM update_key_fact_dep uk
WHERE ftd.fact_table_dep_queue_table_dep_id =
uk.fact_table_dep_queue_table_dep_id
RETURNING uk.*)
UPDATE fact_loader.fact_tables ft
SET last_refresh_source_cutoff = uqtd.last_cutoff_source_time,
last_refresh_attempted_at = now(),
last_refresh_succeeded = TRUE
FROM
(SELECT fact_table_id, last_cutoff_source_time
FROM updated_queue_table_deps
--Must use UNION to get only distinct values
UNION
SELECT fact_table_id, last_cutoff_source_time
FROM updated_fact_table_deps) uqtd
WHERE uqtd.fact_table_id = ft.fact_table_id;
2022-10-31 02:12:34.480 UTC [3119] debci@contrib_regression CONTEXT:
PL/pgSQL function fact_loader.load(integer) line 65 at RAISE
SQL statement "SELECT fact_loader.load(p_fact_table_id)"
PL/pgSQL function fact_loader.try_load(integer) line 40 at PERFORM
PL/pgSQL function fact_loader.worker() line 16 at IF
2022-10-31 02:12:34.505 UTC [3119] debci@contrib_regression DEBUG: time
to inline: 0.000s, opt: 0.007s, emit: 0.000s
2022-10-31 02:12:34.659 UTC [3119] debci@contrib_regression DEBUG: time
to inline: 0.000s, opt: 0.007s, emit: 0.152s
2022-10-31 02:12:34.662 UTC [3119] debci@contrib_regression DEBUG: time
to inline: 0.000s, opt: 0.007s, emit: 0.153s
2022-10-31 02:12:34.683 UTC [3119] debci@contrib_regression DEBUG: time
to inline: 0.000s, opt: 0.005s, emit: 0.000s
2022-10-31 02:12:34.794 UTC [3119] debci@contrib_regression DEBUG: drop
auto-cascades to sequence process_queue_process_queue_id_seq
2022-10-31 02:12:34.794 UTC [3119] debci@contrib_regression CONTEXT:
SQL statement "DISCARD TEMP"
PL/pgSQL function fact_loader.worker() line 19 at SQL statement
2022-10-31 02:12:34.794 UTC [3119] debci@contrib_regression DEBUG: drop
auto-cascades to type process_queue
2022-10-31 02:12:34.794 UTC [3119] debci@contrib_regression CONTEXT:
SQL statement "DISCARD TEMP"
PL/pgSQL function fact_loader.worker() line 19 at SQL statement
2022-10-31 02:12:34.794 UTC [3119] debci@contrib_regression DEBUG: drop
auto-cascades to type process_queue[]
2022-10-31 02:12:34.794 UTC [3119] debci@contrib_regression CONTEXT:
SQL statement "DISCARD TEMP"
PL/pgSQL function fact_loader.worker() line 19 at SQL statement
2022-10-31 02:12:34.794 UTC [3119] debci@contrib_regression DEBUG: drop
auto-cascades to default value for column process_queue_id of table
process_queue
2022-10-31 02:12:34.794 UTC [3119] debci@contrib_regression CONTEXT:
SQL statement "DISCARD TEMP"
PL/pgSQL function fact_loader.worker() line 19 at SQL statement
2022-10-31 02:12:34.794 UTC [3119] debci@contrib_regression DEBUG: drop
auto-cascades to toast table pg_toast_temp_4.pg_toast_17514
2022-10-31 02:12:34.794 UTC [3119] debci@contrib_regression CONTEXT:
SQL statement "DISCARD TEMP"
PL/pgSQL function fact_loader.worker() line 19 at SQL statement
2022-10-31 02:12:34.795 UTC [3119] debci@contrib_regression DEBUG: drop
auto-cascades to index pg_toast_temp_4.pg_toast_17514_index
2022-10-31 02:12:34.795 UTC [3119] debci@contrib_regression CONTEXT:
SQL statement "DISCARD TEMP"
PL/pgSQL function fact_loader.worker() line 19 at SQL statement
2022-10-31 02:12:34.795 UTC [3119] debci@contrib_regression DEBUG: drop
cascades to table process_queue
2022-10-31 02:12:34.795 UTC [3119] debci@contrib_regression CONTEXT:
SQL statement "DISCARD TEMP"
PL/pgSQL function fact_loader.worker() line 19 at SQL statement
2022-10-31 02:12:41.904 UTC [3126] LOG: pg_fact_loader worker initialized
2022-10-31 02:12:44.918 UTC [3052] LOG: background worker
"pg_fact_loader" (PID 3126) exited with exit code 1
2022-10-31 02:13:55.825 UTC [3165] debci@contrib_regression LOG: ADDING
fact_loader_batch_id COLUMN TO queue table
test_fact_audit_raw.orders_fact_audit: ALTER TABLE
test_fact_audit_raw.orders_fact_audit
ADD COLUMN fact_loader_batch_id
BIGINT
DEFAULT nextval('fact_loader.batch_id');
2022-10-31 02:13:55.825 UTC [3165] debci@contrib_regression CONTEXT:
PL/pgSQL function fact_loader.add_batch_id_fields() line 29 at RAISE
2022-10-31 02:13:55.825 UTC [3165] debci@contrib_regression STATEMENT:
SELECT fact_loader.add_batch_id_fields();
2022-10-31 02:13:59.034 UTC [3176] LOG: pg_fact_loader worker initialized
2022-10-31 02:14:00.035 UTC [3177] LOG: pg_fact_loader worker initialized
Dropping cluster 15/regress ...
**** regression.diffs ****
diff -U3
/tmp/autopkgtest-lxc.68jcp06n/downtmp/build.L0a/src/expected/17_1_3_features.out
/tmp/autopkgtest-lxc.68jcp06n/downtmp/build.L0a/src/results/17_1_3_features.out
---
/tmp/autopkgtest-lxc.68jcp06n/downtmp/build.L0a/src/expected/17_1_3_features.out
2022-08-24 17:29:13.000000000 +0000
+++
/tmp/autopkgtest-lxc.68jcp06n/downtmp/build.L0a/src/results/17_1_3_features.out
2022-10-31 02:14:07.224467952 +0000
@@ -15,7 +15,7 @@
FROM fact_loader.safely_terminate_workers();
number_terminated | number_still_live | pids_still_live_ct
-------------------+-------------------+--------------------
- 0 | 2 | 2
+ | | (1 row)
--Should work because the processes should have been idle now for at
least 5 seconds
@@ -31,7 +31,7 @@
FROM fact_loader.safely_terminate_workers();
number_terminated | number_still_live | pids_still_live_ct
-------------------+-------------------+--------------------
- 2 | 0 | +
| | (1 row)
INSERT INTO test.orders (order_id, customer_id, order_date, total)
### End 15 installcheck (FAILED with exit code 1) ###
autopkgtest [02:14:07]: test installcheck
OpenPGP_signature
Description: OpenPGP digital signature
--- End Message ---
