test: seven #1339 projection findings, each red-first in both twins (#1339)

test/check_ledger_budget.txt

@@ -15,7 +15,7 @@
 #
 #   Adding a check to a suite that is already covered does not move it, which is
 #   what makes it safe to bound.
-suites_not_covered 75
+suites_not_covered 74
 #
 # checks_never_observed_red -- A CENSUS. NOT a ceiling, and it must not become
 #   one.
@@ -5957,4 +5957,34 @@ suites_not_covered 75
 #     never         4129 + 8 = 4137
 #     dated         2791 + 7 = 2798
 #     4137 + 2798 == 6935
-checks_never_observed_red 4137
+#
+# #1339, a batch of projection checks (jdatcmd): 4137 -> 4132, and suites_not_covered
+# 75 -> 74. Seven findings, each shown green on main under its mutation in both
+# twins and red by name after the fix. projection_drop_column is seeded: it had no
+# rows, and it enters with 11 checks from five-major runs (11/11 on each of 15-19,
+# twin green on each). Its stranger arms read only 42501, so deleting the unlocked
+# ownership check passed; a stranger is now asked while the owner holds SHARE, and
+# queues to 55P03 under that mutation. Its "two refusals are the same" check lost its
+# premise: prefix, joined the shell suite, and moved ahead of the two constant arms
+# so it can fail. projection_parallel's two worker-count checks lost their premise:
+# prefix: parallel_workers = 1 reddens both. projection_privilege's read_projection
+# arms each asserted one SQLSTATE twice; the first now asks only "refused", as the
+# shell suite does, and the shell's reconstruct arms read the SQLSTATE, as the twin
+# does. projection_scan_io gains a check that an empty projection is not priced at
+# zero pages. projections gains two: an EXPLAIN ANALYZE reading that the executor
+# opened the projection, and that the old-snapshot count plans it. Its twin's two
+# session-A timeout arms now read whether A answered, not the count again, and the
+# shell's poll no longer takes an ERROR that echoes the token for an answer. 19 rows
+# are dated by ten mutations, each reddening its target by the same name in both
+# twins (the pytest twin stops at a test's first red): the unlocked ownership check
+# deleted, both deleted, parallel_workers = 1, each function's aclcheck_error
+# replaced by elog, the RLS refusal raised as 42501, the one-page floor deleted, the
+# executor never opening the projection, projection pages multiplied by 1000000,
+# and the projection scan and liveness cache both on GetLatestSnapshot(). 8 arrive
+# never: one premise and seven drop_column checks no mutation here reached.
+#
+#     ledger rows   6935 + 14 = 6949
+#     never         4137 + 8 - 13 = 4132
+#     dated         2798 + 6 + 13 = 2817
+#     4132 + 2817 == 6949
+checks_never_observed_red 4132

test/projection_drop_column.sh

@@ -39,10 +39,39 @@ psql_run "INSERT INTO pdc
 # The pre-statement dependency check must not tell a stranger which column the
 # projection covers, or let that role take the lock retained by the owner path.
 psql_run "CREATE ROLE pdc_nobody LOGIN;"
-check "a non-owner learns nothing from a projected column" \
-	"$(sqlstate_as pdc_nobody 'ALTER TABLE pdc DROP COLUMN sort_key;')" "42501"
+proj_state="$(sqlstate_as pdc_nobody 'ALTER TABLE pdc DROP COLUMN sort_key;')"
+plain_state="$(sqlstate_as pdc_nobody 'ALTER TABLE pdc DROP COLUMN payload;')"
+# The property is that the two refusals are INDISTINGUISHABLE, so it is compared
+# first: with both ownership checks deleted, the stranger gets 2BP01 for the
+# projected column and 42501 for the other, and this is the check that names it.
+check "and the two refusals are the same error, so neither leaks" \
+	"$proj_state" "$plain_state"
+check "a non-owner learns nothing from a projected column" "$proj_state" "42501"
 check "the same non-owner error is returned for an unprojected column" \
-	"$(sqlstate_as pdc_nobody 'ALTER TABLE pdc DROP COLUMN payload;')" "42501"
+	"$plain_state" "42501"
+
+# THE LOCK HALF OF THE COMMENT ABOVE (#1339). The ownership check runs twice:
+# once with no lock, then again after ShareUpdateExclusiveLock. The two checks
+# above cannot tell them apart, because both raise 42501. Contention can: while
+# the owner holds SHARE on pdc, which conflicts with ShareUpdateExclusiveLock, a
+# stranger refused by the unlocked check gets 42501 at once, and one that reaches
+# the lock first waits out its lock_timeout (55P03).
+holder_log="$PGC_WORKDIR/pdc_holder.log"
+env PATH="$PGC_BINDIR:$PATH" psql -h 127.0.0.1 -p "$PGC_PORT" -U postgres -d "$PGC_DB" \
+	-Atq -v ON_ERROR_STOP=0 -c "BEGIN;" -c "LOCK TABLE pdc IN SHARE MODE;" \
+	-c "SELECT pg_sleep(3600) /* pdc_holder */;" -c "ROLLBACK;" > "$holder_log" 2>&1 &
+holder_pid=$!
+held=0
+for _ in $(seq 1 40); do
+	held="$(q "SELECT count(*) FROM pg_locks WHERE relation = 'pdc'::regclass AND mode = 'ShareLock' AND granted;")"
+	[ "${held:-0}" -ge 1 ] && break
+	sleep 0.25
+done
+check "premise: the owner holds SHARE on pdc before the stranger asks" "${held:-0}" "1"
+check "a non-owner is refused before it waits for the table lock" \
+	"$(sqlstate_as pdc_nobody "SET lock_timeout = '2s'; ALTER TABLE pdc DROP COLUMN sort_key;")" "42501"
+psql_run "SELECT pg_terminate_backend(pid) FROM pg_stat_activity WHERE query LIKE '%pdc_holder%' AND pid <> pg_backend_pid();" >/dev/null
+wait "$holder_pid" 2>/dev/null || true
 
 # Red before the fix: PostgreSQL accepts this (00000), and the next INSERT
 # reaches the projection writer with a type OID of zero.

test/projection_parallel.sh

@@ -277,10 +277,13 @@ check "premise: the covering plan is parallel at the default page cost" \
 check "a page cost that makes I/O dominate costs the parallel covering path" \
 	"$(shape "$(explain_cov_spc $SPC_HI)")" "projection-only"
 
-check "premise: EXPLAIN ANALYZE launched two workers" \
+# NOT PREMISES (#1339, #1236). The worker count is the projection path's own
+# parallel_workers: with it set to 1, Workers Launched reads 1 and both of these
+# go red. A check a pgcolumnar change can redden is an arm.
+check "EXPLAIN ANALYZE launched two workers" \
 	"$(echo "$par_on_ana" | grep -oE 'Workers Launched: [0-9]+' | head -1 | grep -oE '[0-9]+')" "2"
 
-check "premise: ANALYZE printed a rows= line per launched worker" \
+check "ANALYZE printed a rows= line per launched worker" \
 	"$n_lines" "2"
 
 # THE DEFECT the plan-shape arms cannot see: Gather is present and the count

test/projection_privilege.sh

@@ -191,8 +191,12 @@ check "premise: t_prjexec can open a session, so a refusal below is a refusal" \
 	"$(as t_prjexec 'SELECT 1;' | head -1)" "1"
 check "a role with EXECUTE but no SELECT is refused read_projection" \
 	"$(count_as t_prjexec read_projection)" "refused"
+# The SQLSTATE, not merely "refused", as the pytest twin asserts (#1339): this
+# function has no second arm reading the code, so "refused" alone accepted any
+# error at all, a login FATAL included.
 check "and is refused reconstruct_via_projection, which leaks non-covered columns" \
-	"$(count_as t_prjexec reconstruct_via_projection)" "refused"
+	"$(state_as t_prjexec "SELECT count(*) FROM pgcolumnar.reconstruct_via_projection('secret','p1');")" \
+	"42501"
 check "and THAT refusal is the C check, which raises 42501 from aclcheck_error" \
 	"$(state_as t_prjexec "SELECT count(*) FROM pgcolumnar.read_projection('secret','p1');")" \
 	"42501"
@@ -241,7 +245,8 @@ check_num "the policy is in force for ordinary SQL" \
 check "read_projection now refuses a policy-restricted caller (#563)" \
 	"$(count_as t_prjsel read_projection)" "refused"
 check "and so does reconstruct_via_projection" \
-	"$(count_as t_prjsel reconstruct_via_projection)" "refused"
+	"$(state_as t_prjsel "SELECT count(*) FROM pgcolumnar.reconstruct_via_projection('secret','p1');")" \
+	"0A000"
 # 0A000, not a phrase. PgColumnarRequireNoRowSecurity raises
 # ERRCODE_FEATURE_NOT_SUPPORTED, which is a different SQLSTATE CLASS from either
 # ACL refusal -- 0A against 42 -- so no rewording of any message can confuse them.

test/projection_scan_io.sh

@@ -200,8 +200,21 @@ check "premise: the empty projection is found and its storage holds no row group
 	      GROUP BY p.proj_storage_id;")" \
 	"true/0"
 
+psio_e_plan="$(explain_scan on "SELECT ik FROM psio_e WHERE ik BETWEEN 1 AND 50")"
 check "an empty covering projection is still priced as one page, so it is chosen" \
-	"$(explain_scan on "SELECT ik FROM psio_e WHERE ik BETWEEN 1 AND 50" | grep -c 'Columnar Projection: byik')" \
+	"$(printf '%s\n' "$psio_e_plan" | grep -c 'Columnar Projection: byik')" \
 	"1"
 
+# THE OTHER DIRECTION (#1339). The arm above catches over-pricing only: priced
+# at 0 pages instead of 1, the projection is cheaper still and stays chosen.
+# With every CPU cost set to 0 by explain_scan, the projection scan's whole cost
+# is its page cost, so a total of zero means it was priced at zero pages.
+# Measured on PG17: 5.00 with the clamp, 0.00 with `if (pages < 1) pages = 1;`
+# deleted, and the projection chosen both times.
+psio_e_cost="$(printf '%s\n' "$psio_e_plan" | grep -m1 'Custom Scan' |
+	sed -n 's/.*cost=[0-9.]*\.\.\([0-9.]*\) .*/\1/p')"
+check "and its scan is not priced at zero pages" \
+	"$(awk -v c="${psio_e_cost:-none}" 'BEGIN { if (c ~ /^[0-9]+(\.[0-9]+)?$/) print (c + 0 > 0 ? "priced" : "free at " c); else print "unread: " c }')" \
+	"priced"
+
 pgc_summary

test/projections.sh

@@ -194,6 +194,19 @@ check "projection-scan results match heap oracle" \
 check "aggregate over projection scan matches oracle" \
 	"$(q "SELECT count(*), sum(a) FROM ps WHERE c BETWEEN 100 AND 200;")" \
 	"$(q "SELECT count(*), sum(a) FROM ps_h WHERE c BETWEEN 100 AND 200;")"
+# THE EXECUTOR, NOT THE PLANNER (#1339). The first arm reads the name from
+# EXPLAIN, which takes it before the executor decides what to open, and the two
+# oracle arms pass whichever storage is read. So a scan that EXPLAINs as `pc` and
+# reads the base passed all three. Executed, the sorted projection lets the
+# reader skip the vectors outside 100..200 and the filter sees only part of the
+# table; the base, unsorted on c, sends every row to the filter.
+pj_removed="$(q "EXPLAIN (ANALYZE, COSTS OFF, TIMING OFF, SUMMARY OFF) SELECT a, c FROM ps WHERE c BETWEEN 100 AND 200;" |
+	grep -m1 'Rows Removed by Filter:' | grep -oE '[0-9.]+$')"
+pj_outside="$(q "SELECT count(*) FROM ps_h WHERE NOT (c BETWEEN 100 AND 200);")"
+check "executing it reads the projection, so the filter sees fewer rows than the base holds" \
+	"$(if pgc_is_number "$pj_removed" && pgc_is_number "$pj_outside"; then
+		awk -v r="$pj_removed" -v o="$pj_outside" 'BEGIN { print (r + 0 < o + 0 ? "fewer" : "all " r " of " o) }'
+	else echo "unread: [$pj_removed] [$pj_outside]"; fi)" "fewer"
 
 check "GUC off: no projection scan" \
 	"$(q "SET pgcolumnar.enable_projection_scan=off; EXPLAIN (COSTS OFF) SELECT a, c FROM ps WHERE c BETWEEN 100 AND 200;" | grep -c 'Columnar Projection')" "0"
@@ -266,14 +279,23 @@ psql_run "CREATE TABLE pm (a int, c int) USING pgcolumnar;"
 psql_run "SELECT pgcolumnar.add_projection('pm', 'pmp', ARRAY['a','c'], ARRAY['c']);"
 psql_run "INSERT INTO pm SELECT g, g FROM generate_series(1,10000) g;"   # batch 1
 
+# THE PLAN THE ARMS BELOW NAME (#1339). Four of them say "via projection" or
+# "projection scan", and nothing asked how this count plans. Planned on the base,
+# every one of them passes whatever the projection scan does with the snapshot.
+check "the old-snapshot count is planned as a projection scan" \
+	"$(q "SET pgcolumnar.enable_projection_scan = on; EXPLAIN (COSTS OFF) SELECT count(a) FROM pm WHERE c BETWEEN 1 AND 20000;" | grep -c 'Columnar Projection: pmp')" "1"
+
 A_IN="$PGC_WORKDIR/pmA.in"; A_OUT="$PGC_WORKDIR/pmA.out"
 mkfifo "$A_IN"; : > "$A_OUT"
 env PATH="$PGC_BINDIR:$PATH" psql -h 127.0.0.1 -p "$PGC_PORT" -U postgres \
 	-d "$PGC_DB" -At -f "$A_IN" >> "$A_OUT" 2>&1 &
 A_PID=$!
 exec 9> "$A_IN"
 pa_send() { printf '%s\n' "$*" >&9; }
-pa_wait() { local t="$1" i; for i in $(seq 1 200); do grep -q "$t" "$A_OUT" && return 0; sleep 0.1; done; return 1; }
+# The token must carry a count. An ERROR echoes the statement, token included
+# ("LINE 1: SELECT 'PMA_' || ..."), so matching the bare token read a failed
+# query as an answer and the timeout arms below could not fire on it (#1339).
+pa_wait() { local t="$1" i; for i in $(seq 1 200); do grep -qE "${t}[0-9]+" "$A_OUT" && return 0; sleep 0.1; done; return 1; }
 
 # A opens a snapshot that sees batch 1, using a projection scan.
 pa_send "SET pgcolumnar.enable_projection_scan = on;"

test/pytest/test_projection_drop_column.py

@@ -31,11 +31,14 @@
 premise below fails first and names reachability instead of leaving `42501 != 42P01` to
 be interpreted.
 
-ONE THING THIS PORT ASSERTS THAT THE BASH SUITE DOES NOT. The two non-owner arms exist
-to show that a stranger cannot tell a projected column from an unprojected one. The bash
-suite asserts each against the literal `42501` and leaves the reader to notice they are
-the same string. Here they are also compared to each other, so the property -- these two
-are INDISTINGUISHABLE -- is asserted rather than implied by two separate constants.
+THE TWO NON-OWNER REFUSALS ARE COMPARED TO EACH OTHER, in both suites (#1339). The arms
+exist to show that a stranger cannot tell a projected column from an unprojected one, so
+the property -- these two are INDISTINGUISHABLE -- is asserted directly rather than
+implied by two separate constants, and it is asserted before them, so it can fail.
+
+**The lock is tested by contention.** The ownership check runs before the lock and again
+after it, and both raise 42501, so a SQLSTATE alone cannot tell which one refused. While
+the owner holds SHARE on the table, only the unlocked check refuses a stranger at once.
 """
 
 import psycopg
@@ -110,15 +113,43 @@ def test_drop_column_is_refused_while_a_projection_depends_on_it(pgc_conn, expec
         proj_err = _as_nobody(cur, "ALTER TABLE pdc DROP COLUMN sort_key")
         plain_err = _as_nobody(cur, "ALTER TABLE pdc DROP COLUMN payload")
 
+        # The property is that the two are INDISTINGUISHABLE, not that each happens to
+        # equal a constant, so it is compared FIRST. Placed after the two constant arms
+        # it could never run red: `expect` stops at the first failure, and if both
+        # constants hold the two are equal. With both ownership checks deleted, the
+        # stranger gets 2BP01 for the projected column and 42501 for the other, and
+        # this is the check that names it (#1339).
+        expect.text(proj_err.sqlstate if proj_err else "no error",
+                    plain_err.sqlstate if plain_err else "no error",
+                    "and the two refusals are the same error, so neither leaks")
         expect.sqlstate(proj_err, "42501",
                         "a non-owner learns nothing from a projected column")
         expect.sqlstate(plain_err, "42501",
                         "the same non-owner error is returned for an unprojected column")
-        # EXTRA: the property is that the two are INDISTINGUISHABLE, not that each
-        # happens to equal a constant.
-        expect.text(proj_err.sqlstate if proj_err else "no error",
-                    plain_err.sqlstate if plain_err else "no error",
-                    "premise: and the two refusals are the same error, so neither leaks")
+
+        # THE LOCK HALF OF THE PROPERTY (#1339). The ownership check runs twice: once
+        # with no lock, then again after ShareUpdateExclusiveLock. The arms above
+        # cannot tell them apart, because both raise 42501. Contention can: while the
+        # owner holds SHARE on pdc, which conflicts with ShareUpdateExclusiveLock, a
+        # stranger refused by the unlocked check gets 42501 at once, and one that
+        # reaches the lock first waits out its lock_timeout (55P03).
+        holder = psycopg.connect(pgc_conn.info.dsn, autocommit=False)
+        try:
+            holder.execute(f'SET search_path TO "{schema}"')
+            holder.execute("LOCK TABLE pdc IN SHARE MODE")
+            held = _one(cur, "SELECT count(*) FROM pg_locks WHERE relation = 'pdc'::regclass "
+                             "AND mode = 'ShareLock' AND granted")
+            expect.num(held, 1, "premise: the owner holds SHARE on pdc before the stranger asks")
+            cur.execute("SET lock_timeout = '2s'")
+            try:
+                waited_err = _as_nobody(cur, "ALTER TABLE pdc DROP COLUMN sort_key")
+            finally:
+                cur.execute("RESET lock_timeout")
+            expect.sqlstate(waited_err, "42501",
+                            "a non-owner is refused before it waits for the table lock")
+        finally:
+            holder.rollback()
+            holder.close()
 
         # --- the owner is refused as a dependency ---------------------------
         #

test/pytest/test_projection_parallel.py

@@ -232,15 +232,18 @@ def test_projection_parallel(pgc_conn, expect):
         want,
         "a parallel covering projection returns the covering rows once",
     )
+    # NOT PREMISES (#1339, #1236). The worker count is the projection path's own
+    # parallel_workers: with it set to 1, Workers Launched reads 1 and these go red.
+    # A check a pgcolumnar change can redden is an arm.
     expect.num(
         launched,
         2,
-        "premise: EXPLAIN ANALYZE launched two workers",
+        "EXPLAIN ANALYZE launched two workers",
     )
     expect.num(
         len(worker_rows),
         2,
-        "premise: ANALYZE printed a rows= line per launched worker",
+        "ANALYZE printed a rows= line per launched worker",
     )
     expect.num(
         n_busy,

test/pytest/test_projection_privilege.py

@@ -254,11 +254,18 @@ def test_a_role_with_execute_but_no_select_is_refused(pgc_cluster, pgc_conn, exp
         schema = _fixture(cur)
     _, err = _as(pgc_cluster, EXEC,
                  f"SELECT count(*) FROM pgcolumnar.{func}('prj_secret','p1')", schema)
-    expect.sqlstate(err, "42501", name)
     if func == "read_projection":
+        # TWO PROPERTIES, TWO ARMS, as in `projection_privilege.sh` (#1339). The first
+        # asks only that the call was refused; the second asks which code refused it.
+        # Both used to assert 42501 on the same error, so the second could never fail
+        # alone: with read_projection's aclcheck_error replaced by a plain elog
+        # (XX000), the first arm went red under the second's name.
+        expect.text("refused" if err is not None else "noerror", "refused", name)
         expect.sqlstate(
             err, "42501",
             "and THAT refusal is the C check, which raises 42501 from aclcheck_error")
+    else:
+        expect.sqlstate(err, "42501", name)
 
 
 def test_which_layer_refused_without_reading_the_message(pgc_cluster, pgc_conn, expect):
@@ -372,12 +379,16 @@ def test_a_policy_restricted_caller_is_refused(pgc_cluster, pgc_conn, expect, fu
 
     _, err = _as(pgc_cluster, SEL,
                  f"SELECT count(*) FROM pgcolumnar.{func}('prj_secret','p1')", schema)
-    expect.sqlstate(err, "0A000", name)
     if func == "read_projection":
+        # Refused, then WHICH refusal, as in the shell suite (#1339): asserting 0A000
+        # twice on one error left the second arm unable to fail on its own.
+        expect.text("refused" if err is not None else "noerror", "refused", name)
         expect.sqlstate(
             err, "0A000",
             "and the refusal says the feature is not supported, not that a privilege "
             "is missing")
+    else:
+        expect.sqlstate(err, "0A000", name)
 
 
 def test_the_acl_is_checked_before_rls_so_no_privilege_discloses_no_rls_state(

test/pytest/test_projection_scan_io.py

@@ -263,3 +263,14 @@ def test_an_empty_covering_projection_is_priced_as_one_page(pgc_conn, expect):
         "onck",
         "an empty covering projection is still priced as one page, so it is chosen",
     )
+    # THE OTHER DIRECTION (#1339). The arm above catches over-pricing only: priced at
+    # 0 pages instead of 1, the projection is cheaper still and stays chosen. `_plan`
+    # sets every CPU cost to 0, so the scan's whole cost is its page cost, and a total
+    # of zero means it was priced at zero pages. Measured on PG17: 5.0 with the clamp,
+    # 0.0 with `if (pages < 1) pages = 1;` deleted, and the projection chosen both times.
+    cost = (node or {}).get("Total Cost")
+    expect.text(
+        "unread" if cost is None else ("priced" if cost > 0 else f"free at {cost}"),
+        "priced",
+        "and its scan is not priced at zero pages",
+    )