Repository navigation
fix: a cancelled remote parallel export aborts the uploads its workers left open (#1743) - #1755
Conversation
OffgridwithJD
left a comment
There was a problem hiding this comment.
@jdatcmd Changes requested on #1755 at 80ee33e4, for one blocker. Under a second cancel, the new cleanup is never reached, so the uploads stay open and the export reports XX000. Everything I measured inside the new cleanup itself holds.
All runs are on PG17 (~/pg/17-z, release build, no cassert here) unless stated. "Main" is 9ab6a4cf with this PR's two test files and fixture server copied in.
Reproduced
| run | shell | twin |
|---|---|---|
| main, PR's tests | 19 + 4 failed: parts, cancel and terminate: no upload of this export is left open (got [4] want [0]), and silent listing: the cleanup asked the store for its open uploads (got [0] want [1]) |
the same 4 names |
| head, PG15 / 17 / 19 | 23/23 each | 23/23 each |
Blocker: a second cancel during the part DELETEs skips the new cleanup
The guarded region still runs pexport_cleanup from PG_ENSURE_ERROR_CLEANUP's catch, with the first cancel's error on the stack and interrupts not held. pexport_remove_outputs DELETEs each part through the module, whose best-effort catch calls FlushErrorState(). So a second cancel inside one of those DELETEs empties the stack: that's #1741. The macro's PG_RE_THROW then lands in this PR's new outer PG_CATCH with no error on the stack. pexport_abort_own_uploads_and_rethrow's CopyErrorData() raises "errstart was not called", which leaves the catch before pexport_abort_own_uploads ever runs.
Probe: the fixture holds each object DELETE for 3 s (a local __delete_delay__ hook, not committed). Cancel while every worker sends parts, then cancel again once the first part DELETE has arrived:
| head | main | |
|---|---|---|
| error | XX000: errstart was not called |
the same |
| this export's uploads left open | 4 | 4 |
| "errstart was not called" in the server log | +1 | +1 |
It isn't a regression, but it's this PR's own scenario (a cancelled export to s3://) leaving every upload open. The error loss is the same hole #1744 closes. Two ways out:
- Land #1744 first and rebase onto it. Its
PgColumnarCleanupAndRethrowcopies the error out beforepexport_cleanupruns, so a second cancel only cuts short the DELETE it lands in.pexport_abort_own_uploadsthen runs after the cleanup, either as part of the cleanup callback or after the helper's cleanup and before its re-throw, and your outerPG_TRYand its own copy-flush-rethrow go away. - Or, here: run
pexport_cleanupitself under the copy-out-first rule, i.e. dropPG_ENSURE_ERROR_CLEANUP's catch for the ERROR path and keep itsbefore_shmem_exitfor FATAL, as #1744 does.
Either way, please add this double cancel as an arm: red on this head, with the first cancel's 57014 and no upload left.
Measured and fine
- A double cancel during the listing (the listing held 4 s, the second cancel 0.5 s into it): the first cancel's
57014, 0 uploads left, no errstart, no crash. Holding interrupts there does what it should. AfterwardsSET statement_timeout='300ms'; SELECT pg_sleep(3)still cancels at 0.31 s on the same server, so nothing stays held. The same holds after the P2 probe above. - The holdoff restore.
heldandcancelHeldare read afterHOLD_INTERRUPTS, so any count the caller holds is restored too.errfinishzeroes both before the longjmp, so putting them back beforeRESUME_INTERRUPTSbalances it on both paths: from the catch (count 0, so held = 1) and from the worker-failed path.CritSectionCountcan't be non-zero there (an ERROR inside one is a PANIC). I have no cassert build here, so I couldn't repeat your TRAP check. - Key matching is exact:
pexport_part_indexplus a byte compare against the rebuiltpart-%04d.parquetname.nkeysisworkersfor a single table andnpartfor a partitioned table, the same expression the workers' names use (:308,:734,:988).part-00001.parquetandpart-0004.parquet(beyond nkeys) are skipped, and your seeded foreign uploads show it.
- Pagination.
key-markerandupload-id-markerare sent together and only together, as S3 requires, so the same key split across pages continues by id. The no-progress guard matcheslist_objects. The canonical query order (key-marker < prefix < upload-id-marker < uploads=) is right for SigV4. - ABI 5 → 6. Head's extension with main's v5
pgcolumnar_objstore.sogivesWARNING: columnar: ignoring object-store module with ABI version 5/expects ABI version 6, then the existing "requires the object-store module" error. No crash.
Not blocking: the store going silent before your cleanup
With the fixture SIGSTOPped right after the workers' POST ?uploads, one cancel doesn't return within 45 s, on head or on main: it waits in pexport_remove_outputs's first DELETE, before the listing. Every further cancel skips one DELETE (the module's best-effort catch), and the last one ends in errstart, as above. pg_ctl stop -m fast with a silent store fails at 90 s on both. Your bounded listing and aborts never get that far. #1727's WL_TIMEOUT in os_wait bounds each of those DELETEs at the 60 s quiet limit. The PR body's "every wait bounded" holds for the new cleanup, not for the error path as a whole; worth one sentence.
Overlap with #1727 and #1744
os_wait, with #1727 (914c9742). Both edit the sameWaitLatchOrSocketcall. #1727 always addsWL_TIMEOUTwithOS_WAIT_SLICE_MS, which makes the module's own 60 s quiet limit work for every caller. This PR addsWL_TIMEOUTonly when a handle has a deadline. They compose: alwaysWL_TIMEOUT, with the slice cut to the time left when a deadline is set, and your before/after deadline checks kept. Whichever lands second takes that merge, and the comment "os_wait passes no WL_TIMEOUT" goes once #1727 is in.- The export's error path, with #1744 (
57bfa709). Both rewrite thePG_ENSURE_ERROR_CLEANUPblock inpgcolumnar_parallel_export_parquet: #1744 spells it out, and this PR moves it intopexport_spawn_and_wait. Both add a copy-flush-cleanup-rethrow helper (PgColumnarCleanupAndRethrowincolumnar_sink.c, andpexport_abort_own_uploads_and_rethrow). That's a textual conflict, and two helpers for one rule. - Suggested order: #1744, then this PR on it, using #1744's helper with
pexport_abort_own_uploadsadded to the cleanup. That also fixes the blocker. #1727 can land before or after either.
Logs and probe scripts are in my scratch (rv1755/): head.*.sh.log, main.17.sh.log, probeb.head.17.log, probeb.main.17.log, probe1755b.sh and objstore_http_server_p.py (the delete-delay hook).
🤖 Generated with Claude Code
80ee33e to
a9c09bb
Compare
|
@OffgridwithJD Reworked as you suggested. a9c09bb is one commit on #1744's head d023de3, and this PR now targets #1744's branch, so its diff is only this change. It merges after #1744. Design. Your double cancel, as an arm. It has 7 checks, the same names in the shell suite and the twin. One change from your probe: on this base, #1727's exit callback already aborts a worker that is sending parts. ( Red on the plain rebase of v1, PG17 (shell 27 + 3; the twin fails the same three): Green: 30/30 in shell and twin on PG15-19. I re-ran PG17 myself on the pushed commit: shell Mutants, PG17, same names in both harnesses:
#1727 makes two old datings moot. Regression, PG17:
Gates: ledger gate rc 0 against d023de3, census 4506. Guards 837 passed. compare_to_bash: every bash property covered. Body: updated. It now says that with a silent store the part DELETEs wait up to the module's 60 s quiet limit each, not this cleanup's 10 s. Not verified:
|
OffgridwithJD
left a comment
There was a problem hiding this comment.
@jdatcmd Approved at a9c09bb6. The blocker from my last review is closed.
All runs on PG17 unless stated, my own prefix copy, as a normal user, with lib.sh building each tree.
My blocker: a double cancel during the part DELETEs
I re-ran my own probe from the last review (each DELETE held 3 s via the fixture's __delete_delay__, workers sending parts, second cancel once the DELETEs start) on this head:
| probe | 80ee33e4 (last review) |
a9c09bb6 |
|---|---|---|
| double cancel during the part DELETEs | XX000: errstart was not called, 4 own uploads open, 1 new "errstart" line |
57014: canceling statement due to user request, 0 open, 0 new "errstart" lines, server up |
then statement_timeout in the same session |
fired at 0.31 s | fired at 0.31 s |
| double cancel during the listing | (green then too) | 57014, 0 open, no "errstart"; the cancel returned in 8.1 s; a later statement_timeout still fires at 0.32 s, so the holdoff restore balances |
pg_ctl stop -m fast with the store SIGSTOPped |
rc=1 after 90 s | rc=0 after 45 s |
Head
objstore_export_open_uploads: shell 30 passed + 0 failed and twin 30 passed, on each of PG15, 17 and 19.
Your mutants, PG17
Every mutant reddens the same names in the shell and the twin. I compared the name lists file against file.
| mutant | reds |
|---|---|
nolist (return before the listing) |
4: cancel, terminate and double cancel no upload of this export is left open, plus silent listing: the cleanup asked the store for its open uploads |
everykey (abort every key under the prefix) |
4: <arm>: the foreign uploads under the prefix are left open for cancel, double cancel, parts and terminate |
offbyone (idx > nkeys) |
the same 4 |
nodeadline (os_set_deadline never sets one) |
1: silent listing: the export returned within 30 s of the cancel (74 s twin run) |
nocopy (the catch calls pexport_cleanup_in_catch then PG_RE_THROW()) |
3: double cancel: the export reports its own cancel (57014), double cancel: the server log has no 'errstart was not called', silent listing: the export reports its own cancel (57014) |
Ledger
The 30 new rows are sorted, and the tsv counts 7778 rows (4506 never, 3272 dated), matching the budget. The gate against d023de30 gives rc=0, with census 4506 agreeing and the ceiling holding at 34 → 34. Each dated row matches a red in the table above. parts: no upload of this export is left open as never is honest on this base: nolist leaves it green, because #1727's exit callback aborts a worker that's sending parts.
Non-blocking
- One path can still skip the aborts.
pexport_cleanup_in_catchrunspexport_cleanupand thenpexport_abort_own_uploads, both insidePgColumnarCleanupAndRethrow'sPG_TRY, so anythingpexport_cleanupraises ends the cleanup before the aborts. The module's DELETE swallows its own request errors, butobjstore_delete_objectbuilds its handle (os_write_handle→os_resolve_s3, plus the URL refusals) outside itsPG_TRY. That build passed at the export's start for the same URL, so only an OOM or a settings change mid-statement would reach it. Cheap hardening: wrap thepexport_cleanupcall inpexport_cleanup_in_catchin its ownPG_TRY/FlushErrorState, aspexport_abort_own_uploadsdoes, so the aborts always run. - Pointer before the bounds check.
base = keys[i] + strlen(prefix)is computed before thestrncmpthat shows the key is at least that long. It's only dereferenced after the check, so it's harmless, but moving the assignment after the check removes the out-of-range pointer. - A silent store still makes a single cancel slow: 46.6 s, in the part DELETEs at the module's 60 s quiet limit each, before the bounded listing. The PR body now says so.
- Rebase heads-up:
d023de30(#1744) changes when my chain's restate ontoc7f0de45reaches #1744, now in progress. This PR then needs a trivial rebase onto #1744's new head. Its own diff shouldn't change.
🤖 Generated with Claude Code
d023de3 to
5743c3c
Compare
…ostgreSQL's casts (#1706) Item 2 of #1706, decided there as option (a). The reader skipped the TimestampType's isAdjustedToUTC flag and returned the raw microseconds for either target type. In a New York session a naive (wall-time) column read into timestamptz came back as 08:00-04 instead of 12:00-04, and an adjusted column read into timestamp kept its UTC wall time instead of 08:00. The reader now keeps the flag (the legacy TIMESTAMP_* converted types are defined as adjusted) and, in those two mixed cases only, converts as timestamp_timestamptz and timestamptz_timestamp do, in the session zone. It is written from timestamp2tm, DetermineTimeZoneOffset and tm2timestamp, so it is the same on every major: PG19 renamed the exported helper, and PG15-18 export none for timestamptz -> timestamp. Same-kind reads, and any read in a UTC session, are unchanged. A wall time is not monotonic in its instant across a spring-forward gap: in New York on 2024-03-10, 02:00, 02:30 and 03:00 become 07:00Z, 07:30Z and 07:00Z. Converted row-group statistics need not bound the converted rows, so the foreign table no longer skips row groups of a column read this way. Measured: with skipping left on, `t > '07:15Z'` over such a group returned 0 rows instead of 1. The Iceberg foreign table's year(), month(), day() and hour() pruning compared a constant with partition cells the writer computed in the source field's own kind, while the reader now converts a mixed-kind column's rows. PgColumnarIcebergTemporalMap now leaves out a field whose Iceberg source type is the other timestamp kind than its column, so nothing prunes on it. Measured on PG17 before the guard, in New York: byhour declared timestamptz with `ts >= '2021-03-01 06:00+00'` returned no rows where iceberg_scan returned 2,3, and byhour_tz declared timestamp with `tt <= '2021-02-28 20:00'` returned none where it returned 1,2. #1707 (merged) is a prerequisite: with the reader honouring the flag and the old exporter marking timestamp adjusted, a timestamp exported and re-imported in a New York session came back 08:00 (measured). An arm pins that round trip. New suite test/parquet_timestamp_zone.sh and its twin, 16 checks, including the naive file read in a second zone (Tokyo), the repeated hour of the 2024-11-03 fall-back, and test/fixtures/parquet/legacy_timestamp_micros.parquet, written by main's exporter before #1707 (0c5e924) with only the TIMESTAMP_MICROS converted type. Two arms in test/iceberg_fdw.sh and its twin. docs/user-guide.md states the rule; CHANGELOG under Changed. Measured on PG17: - Red, the head before the Iceberg guard: both new iceberg_fdw checks, in shell and twin ("got [] want [2,3]", "got [] want [1,2]"). - Mutants, the same names in shell and twin: the flag ignored (6), no instant-to-wall shift (2), skipping on converted stats (1), main's exporter before #1707 (the round trip, 1), the conversion pinned to New York (the Tokyo pair, 2), legacy converted types read as naive (the legacy pair, 2), the zone offset taken at the wall time read as UTC (the fall-back hour and the two gap checks, 3), no Iceberg kind guard (2). - Green: parquet_timestamp_zone 16/16 and iceberg_fdw 76/76, shell; 16/16 and 80/80, twin; on each of PG15 to PG19. - Without pyarrow the twin declines by the shell's skip name. - docs_style 53/53, harness_selftest 1248/1248, shellcheck clean. Ledger: 6951 rows, 2811 dated by the mutations and 4140 never. suites_not_covered 75 -> 75 (a new suite, registered and covered together; iceberg_fdw is not yet seeded, so its two new checks add no rows), cluster_tests 3222 -> 3240, TESTS.md section 296. The ledger gate, guards (804 passed), name grading and the self-test pass over 9ab6a4c. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…e operator family (#1712) The foreign table's group-exclusion check refused any constant whose type was not the column's. A bare integer literal is int4, so the most ordinary filter on a bigint column, `WHERE id > 150000`, read every row group; only `150000::int8` skipped. Answers were correct; reads were not saved. The check now compares the statistics with the constant through the operator family's comparison function for (column type, constant type), as the native zone-map path already did (OffgridwithJD's measurement on #1712). A family with no such function means no skip. Two details the old code would have got wrong for a cross-type constant: the NaN check read the constant as the column's float type (it now reads it by its own type), and equality called the comparison with the constant first (the column's value is now always the first argument). New suite test/parquet_skip_cross_type.sh and its twin, 9 checks, over a 200,000-row file in 4 row groups: int4 constants on an int8 column (>, =, and on the left), a negative float4 constant on a float8 column, the answers against the same-type query, and a float4 NaN that must still find the NaN row its group's statistics leave out. parquet_export_stats measured the old refusal in six arms ("a cross-type constant skips nothing", and five like it). Those assertions are now wrong by design: each is renamed for what it asserts, the skip its same-type twin gets, keeps its ledger row, and is re-dated by the pre-#1712 reader, which fails exactly those six in both harnesses. Three soundness arms are added for the changed predicates that had none ([i8 < 5::int], [i8 < 5], [f4 < 0.4]); every oracle arm passes. docs/limitations.md states the new rule. Measured on PG17: - Red: the pre-#1712 reader fails the four cross-type skip arms of the new suite, in shell and twin. - Green: 9/9 shell and twin on each of PG15 to PG19; parquet_export_stats 165/165 shell and twin on each of PG15 to PG19. - Mutants, the same names in shell and twin: the comparison called with the constant first (4, the same-type control among them); the column type's own function used for a constant of another type (the negative float4 arm); the NaN constant read as the column's type (the NaN arm). - 47 parquet, iceberg and arrow suites on PG17: only parquet_export_stats's six refusal arms failed, before they were rewritten; 1044 checks. - docs_style passes. Guards 476 passed. cluster_tests 2763 -> 2775 (collected 2775). Ledger 6180 + 12 = 6192 rows, 3886 -> 3892 never, 2294 -> 2300 dated; the gate passes, ceiling 102. - Rebased onto #1736 at a93f14b, the registry re-derived there: cluster_tests 3240 -> 3252 (collected 3252). Ledger 6951 + 12 = 6963 rows, 4140 -> 4146 never, 2811 -> 2817 dated. The gate is run on the commit after this one. Stacked on #1736 (and #1707), which touch the same function. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…amptz constant (#1712) OffgridwithJD's review of #1737 measured a wrong answer. For a timestamp column and a timestamptz constant, timestamp_cmp_timestamptz turns each statistic, a wall time, into an instant in the session zone, and that is not monotonic across a spring-forward gap. In New York a row group holding 2024-03-10 02:00, 02:30 and 03:00 has a converted max of 07:00Z but holds 02:30, which is 07:30Z. So `ts > '2024-03-10 07:15+00'::timestamptz` skipped the group and returned no row; a heap copy returns row 1. The same held for >= 07:15Z and = 07:30Z. The group-exclusion check now refuses that pair before choosing the comparison function. A timestamp constant on a timestamp column still skips, and a timestamptz column with a timestamp constant is unchanged. docs/limitations.md and the CHANGELOG entry say so. parquet_skip_cross_type and its twin gain 7 checks over a naive timestamp file in 2 row groups, every session in New York: the three predicates against the heap copy, a same-type control that still skips 1 group, its answer against the heap, and two premises. Measured: - Red: on the rebased head without the guard, PG17, the >, >= and = arms fail by the same names in shell (13 passed + 3 failed = 16) and twin (3 failed, 13 passed), each "got none want 1". - Mutant: deleting the guard line reddens the same three names in both harnesses, which dates their ledger rows. - Green: parquet_skip_cross_type 16/16 and parquet_export_stats 165/165, shell and twin, on each of PG15 to PG19. parquet_timestamp_zone 16/16 shell and twin on PG17. - Guards 804 passed. docs_style passes. cluster_tests 3252 -> 3259 (collected 3259). Ledger 6963 + 7 = 6970 rows, 4146 -> 4150 never, 2817 -> 2820 dated; the gate passes against origin/main, ceiling 75. compare_to_bash: every bash property is covered. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…er collide (#1742) A twin that starts its own S3 or HTTP fixture server takes the port from pick_port(slot) in a module fixture. Under -n, a module's tests are split across workers, so every worker runs that fixture. The port depended on the slot only, so two workers probed the same free port at the same moment and the second bind failed with "Address already in use" (#1635, #1714, #1721). CI runs the cluster files serially, so CI stayed green; the guard job and developers run -n. pick_port now starts each worker in its own block of 64 ports (WORKER_STRIDE), with the slot as an offset inside it. The worker comes from PYTEST_XDIST_WORKER, so no fixture changes. Slot 0 is the worker's own cluster, which make_cluster now asks for through the same function. A slot that does not fit in a block is refused. The walk on a busy port, the AUX band and the ephemeral-floor contract are unchanged. test_runshape.py gains test_two_workers_taking_a_fixture_port_do_not_collide: an inner -n 2 run where each worker takes pick_port(27), waits until the other has a port, then binds it. On main it is red: "the two workers were given two different ports: got 1 want 2", and the inner bind fails with [Errno 98] Address already in use. With the fix it is green. Measured on PG17 (a copy of the prefix): - test_iceberg_objstore.py under -n 2: main 3 of 3 red ("premise: sigv4 fixture server is up: got '0' want '1'"; "Connection refused"); fixed 16 passed 3 of 3, and 16 passed serially. - test_objstore_listing.py from #1714 under -n 2: as is, 13 failed ("the private cluster did not start"); with this pgc_cluster.py, 15 passed 3 of 3 and serially. - test_connection.py and test_hardening.py under -n 2: 20 passed. guard_tests 476 -> 477, by collection over NO_CLUSTER; TESTS.md section 10 gains a row. The guards (477), test_harness_deps.py and test_capability_decline.py with --pg-config pass over 21182d0. Review (OffgridwithJD): a 64-port block holds slots 0 to 31, and main's twins already ask for 32 to 35 (the stack for up to 41), so slot 32 raised at fixture time: test_iceberg_rest.py "14 errors", ValueError "slot 32 does not fit in a worker's block of 64 ports". WORKER_STRIDE is now 96 (slots 0 to 47; the AUX band's 2000 ports still give 20 workers). Two guards keep the stride and the corpus from drifting apart, red first on the 64 stride: every literal pick_port slot fits a worker's block (it named the 32-35 files), and the corpus's highest slot (35) gets a port in the band. Green: test_runshape.py 18 passed; the five twins that errored pass serially (14, 11, 29, 10, 8); iceberg_rest + iceberg_objstore under -n 2, 30 passed; guards 807 passed on main 9ab6a4c (guard_tests 804 -> 807). Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…le, pinned reader, and a crash no longer passes as a refusal (#1341) test/pytest/test_parquet_export.py ports all 14 checks of test/parquet_export.sh by name. Five kinds of shell check could pass with nothing measured, or vanish; all are fixed in both twins. - "reject non-columnar table" and "reject unsupported type" passed on any error. With the columnar check removed, exporting a heap failed on "unsupported columnar format version" and passed; with the type refusal formatting the typmod, it failed on "cache lookup failed" and passed. Each refusal now needs its own message. - "parquet values match heap oracle" and "extended values match heap oracle" agreed on two empty readings: with the generator's rows never inserted, both passed. They now need the generator's ids on both sides and the file's row count. - "duckdb non-null count(b)" compared DuckDB's count with t_col, the table under test: with half of t_col deleted before the export, it passed. It is now held to the generator's 80002, by check_num. - Without the duckdb CLI the shell left its four DuckDB checks out without a word (10 = 10). It now skips them by name (10 passed + 4 skipped = 14). A skip, not check_unrunnable: the suites job installs no DuckDB CLI, and an INCOMPLETE suite fails its major there. DuckDB in the twin, as decided on #1341 (option 1 with option 2's mechanism): the duckdb Python package is pinned at 1.5.6 in requirements-test.txt; duckdb joins pyarrow in DECLINABLE_CAPABILITIES, held by four new tests in test_capability_decline.py, written red first; and the cluster job sets PGC_REQUIRE=pyarrow,duckdb. The twin reaches duckdb only through require_module, under the shell's check names. Measured, PG17, shell and twin: - duckdb absent: the four DuckDB tests decline by name and the run is green (10 pass + 4 declined); with PGC_REQUIRE=duckdb the same four fail. - the columnar check removed, and the type refusal formatting the typmod: the refusal red in both; main's shell passed 14 of 14. - the generator's rows never inserted: 8 red in both; main's shell 5. - half of t_col deleted: 4 red in both; main's shell 3. - the type check removed (the backend aborts): the refusal red in both, with the same 5 collateral reds in both. - nine more mutations of src/columnar_parquet.c: each red set identical in both twins and in main's shell. DECIMAL written little-endian and a negative int4 written as null are red in both readers, pyarrow and DuckDB; row-group num_rows one high is red in DuckDB only. - clean: 14 of 14 on PG15 to PG19 in both twins. Ledger: 14 rows, 14 dated by the 11 mutations and 0 never. suites_not_covered 75 -> 74, cluster_tests 3222 -> 3236, guard_tests 804 -> 808, TESTS.md section 296. The ledger gate, guards (808), name grading and the self-test pass over 4adb2e7. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…ails no longer reads as a fast one (#1341) Ports test/planner_choice_quality.sh to test/pytest/test_planner_choice_quality.py, all 11 checks by the shell's name, one test per check, on a private database with serial planning as the shell's cluster runs. Each arm's EXPLAIN, warming run and timed run share one session, so the plan named is the plan timed. Two holes in the shell, each measured on PG17 against main and fixed in both twins: - psql prints "Time:" after a statement that errored, and run_plan only looked for a timeout. So a chosen plan that raised an error was read as a fast plan. With PgColumnarBeginCustomScan raising at execution, or PgColumnarBeginGroupAggScan, main's shell PASSED every check (the grouped query "chose Custom Scan=1.911ms", 0.01x). run_plan now reads psql's exit status under ON_ERROR_STOP, and tells the statement-timeout cancel apart by its own message. A new check, "[$label] the chosen plan ran to completion", fails by name; a forced alternative that fails fails the ratio check as "nothing to compare" instead of standing in as the fastest plan (main read it as 15.94x over the bound). - The ratio check's name carried the bound and the node that won the comparison, so it was "... alternative (Index Scan)" when green and "... alternative (Custom Scan (PgColumnarScan))" when red: a red no green run had named. The names now carry only the query's label, and the values are in the display line. "forcing produced a different plan" loses its premise prefix (#1339): with pgcolumnar.enable_custom_scan ignored by the planner, it is the check that goes red. PGC_SKIP_TIMING: CI's suites job sets it, and run_all_versions.sh does not run the suite at all under it (is_timing_suite), which is why CI reports it skipped. Run directly under the flag, the shell builds 20,000 rows, runs the plan-shape checks and records the two measured checks per query as SKIP. The twin reads the same flag: it builds the same fixture, and declares the same two checks per query unrunnable under the shell's names, so the session ends INCOMPLETE (67), never green. Five mutations on PG17, each reddening the same names in shell and twin: scan100x (refined scan cost x100, the planner picks the index scan; 2 ratio checks, 23.3x-25.4x over three shell runs and 23.6x-36.7x over three twin runs), scanerrors 2, fetcherrors 2, gucignored 2, groupaggerrors 2. Clean, the ratio is 0.02x-0.05x on every run. 11/11 in shell and twin on each of 15-19. Ledger: 11 rows, 6 dated by the 5 mutations and 5 never. suites_not_covered 75 -> 74, cluster_tests 3222 -> 3233, TESTS.md section 296. The ledger gate, guards (804), name grading and the self-test pass over 4adb2e7. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
…s left open (#1743) A worker of parallel_export_parquet learns its multipart upload id only from the answer to CreateMultipartUpload (POST ?uploads), and the store creates the upload when the request arrives. A worker that ended while it waited for that answer left an upload open that nothing could abort. #1727's exit callback (in this base) aborts an upload a terminated worker holds the id of; it cannot help a worker that never got the id. The dispatcher's cleanup now lists the uploads under the export's prefix (ListMultipartUploads) and aborts each one whose key is exactly one of the export's part names, part-0000.parquet to part-(nkeys-1).parquet. Any other key under the prefix is left alone. - On a cancel or other error the aborts run inside #1744's PgColumnarCleanupAndRethrow, in the cleanup callback after pexport_cleanup. The helper has copied the handled error out and emptied the stack, so a second cancel that lands in a part DELETE cuts short only that DELETE: the aborts still run and the first cancel is re-thrown. They also run after a worker failed (for example, the workers were terminated). - Interrupts are held only around bounded waits: 5 s on a timed latch for the terminated workers to stop, then 10 s for the listing and aborts. - New module entries list_uploads and abort_upload, which take a timeout that sets a deadline on the handle; ABI 5 -> 6. - os_wait: this builds on #1727's WL_TIMEOUT (4dc63aa, in this base through #1744's stack, not on main). It keeps WL_TIMEOUT for every wait and cuts the slice to the time left when a handle has a deadline. The first version's comment "os_wait passes no WL_TIMEOUT" is gone; this hunk depends on #1727 landing. - The fixture server already wrote __open_uploads__ (#1721) and had __delete_delay__ (#1744). One copy of each is kept; the __open_uploads__ writer is the module function _write_open_uploads, which --seed-upload also uses. Review of the first version (80ee33e): a second cancel during pexport_remove_outputs' part DELETEs emptied the error stack (#1741), the first version's outer PG_CATCH then raised "errstart was not called", and the aborts never ran. That outer PG_TRY, its copy-flush-rethrow helper and pexport_spawn_and_wait are removed. Test: new suite objstore_export_open_uploads and its twin, 30 checks each, identical names. The fixture server gains ListMultipartUploads, delay hooks on POST ?uploads, part PUTs and the listing, and --seed-upload. Five arms: cancel while parts are sent; cancel while every CreateMultipartUpload is held; the workers terminated there; cancel there, then cancel again once the first part DELETE has arrived (__delete_delay__ 3 s); and cancel there while the listing is held. The double-cancel arm was red first on the rebased first version, PG17, shell and twin alike: "XX000: errstart was not called", one more errstart line in the server log, and 4 uploads left open. With the rework: 30/30 on PG15-19, shell and twin. Ledger: 30 rows, 12 dated by four mutations that redden the same names in both twins on PG17 (no listing; every listed key aborted; the part match off by one; the cleanup run with the handled error on the stack), 18 never. "parts: no upload of this export is left open" is never: on this base #1727 also closes it, so no single mutation reddens it. never 4488 -> 4506, dated 3260 -> 3272, rows 7748 -> 7778; suites_not_covered stays 34; cluster_tests 4027 -> 4057; TESTS.md section 338. Restated onto main 4500efd, stacked on #1752. main's #1745 added a test named test_double_cancel_reports_the_first_cancel to test_parallel_flush_optin.py, so the corpus defined that name twice and two guards in test_docs_cover_the_corpus.py failed. This twin's test is renamed test_double_cancel_reports_the_exports_own_cancel, with its TESTS.md row; the check name it records is unchanged. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
a9c09bb to
2ceeeb6
Compare
|
Restated onto main 4500efd as 2ceeeb6, in one linear stack (this PR sits on #1752), so these eight merge without voiding each other. Every non-registry file carries the same change as before; the registries are re-derived on the new base, and each census agrees with a recount. One change beyond the registries: the twin function |
OffgridwithJD
left a comment
There was a problem hiding this comment.
@jdatcmd Re-approved at 2ceeeb63, restated onto main 4500efdd in the linear stack. Outside the ledger, the budget, expected_tests and TESTS.md, the commit's diff matches the approved a9c09bb6. The one difference outside the bookkeeping is the twin function renamed to test_double_cancel_reports_the_exports_own_cancel (#1745's twin owns the old name). The check name it records is unchanged, and the rest is hunk context and CHANGELOG position. The tsv is sorted, and its census (8070/4571/3499 rows/never/dated) matches the budget.
🤖 Generated with Claude Code
@OffgridwithJD Fixes #1743. Second version, after your review of
80ee33e4. One commit,a9c09bb6, on #1744's headd023de30, so this PR's diff against #1744 is only this change. Land #1744 first.What changed since
80ee33e4PgColumnarCleanupAndRethrow, as part of the cleanup callbackpexport_cleanup_in_catch: firstpexport_cleanup(terminate the workers, delete the part keys), thenpexport_abort_own_uploads. The helper copies the first cancel's error out and empties the stack before the callback runs. A second cancel that lands in a part DELETE is swallowed by the module's best-effort catch and cuts short only that DELETE. The aborts then run, and the helper re-throws the first cancel.PG_TRY,pexport_abort_own_uploads_and_rethrow(its copy-flush-rethrow helper), andpexport_spawn_and_wait. The guarded region is fix: a second cancel during a remote export's cleanup keeps the export's own error (#1741) #1744's again, with one comment sentence added.double cancel, in the shell suite and the twin, with identical check names (details below).os_wait. fix: a second cancel during a remote export's cleanup keeps the export's own error (#1741) #1744's stack carries fix: a cancelled remote parallel export aborts its workers' uploads (#1722) #1727'sWL_TIMEOUT(4dc63aae), so the mergedos_waitalways passesWL_TIMEOUTwith the 5 s slice, and cuts the slice to the time left when a handle has a deadline. The v1 comment "os_wait passes no WL_TIMEOUT" is gone.__open_uploads__(test: objstore_sink_write gains its pytest twin, and multipart is read as S3 does it (#1341) #1721) and has__delete_delay__(fix: a second cancel during a remote export's cleanup keeps the export's own error (#1741) #1744). One copy of each is kept: the__open_uploads__writer is one module function,_write_open_uploads, which--seed-uploadalso needs.The bug
A worker of
parallel_export_parquetlearns its multipart upload id only from the answer to CreateMultipartUpload (POST ?uploads), and the store creates the upload when the request arrives. A worker that ends while it waits for that answer leaves an upload open that nothing on the worker's side can abort. #1727 (in this base) makes a terminated worker abort an upload it holds the id of; it cannot help a worker that never got the id.The fix
The dispatcher's cleanup lists the uploads under the export's prefix (ListMultipartUploads) and aborts each one whose key is exactly one of the export's part names,
part-0000.parquettopart-(nkeys-1).parquet. Any other key under the prefix is left alone.pexport_cleanup. On the path where a worker failed (for example, the workers were terminated), afterpexport_remove_outputs.pexport_remove_outputs' part DELETEs run before the listing, and each one waits up to the module's 60 s quiet limit, not this cleanup's 10 s.list_uploadsandabort_upload. The module ABI goes from 5 to 6, so a stale module is refused with the existing warning.errfinishzeroesInterruptHoldoffCountbefore the longjmp, so the catch inpexport_abort_own_uploadsrestores the count beforeRESUME_INTERRUPTS.Test: suite
objstore_export_open_uploads, and its twinEach prefix gets two foreign uploads:
part-0004.parquet, one past a 4-worker export's last part, andnotes.parquet.POST ?uploadsis held after the upload exists__delete_delay__holds each DELETE 3 s, and is removed after the second cancel so the aborts are answered at onceThe double-cancel arm cancels while every
POST ?uploadsis held, not while parts are sent. On this base, #1727's exit callback aborts a sending worker's own upload: with the listing removed (nolist), the single-cancelpartsarm still leaves 0 uploads open. So a double cancel during parts could not show whether the dispatcher's aborts ran.Red first, then green (PG17; the same names in the shell suite and the twin)
The rebased first version (#1755 v1's outer
PG_TRYover #1744's base, taking v1's side of the conflict) with the new arm: shell 27 + 3, twin 27 + 3.With the rework: 30/30 in the shell suite and 30/30 in the twin on each of PG15 to PG19.
Mutants (PG17; each reddens the same names in both)
nolist(the listing never runs)cancel:,terminate:anddouble cancel: no upload of this export is left open(got [4]);silent listing: the cleanup asked the store for its open uploads(got [0])everykey(every listed key aborted)the foreign uploads under the prefix are left openchecks (got [])offbyone(idx > nkeys)part-0004aborted)nodeadline(timeout_ms0)silent listing: the export returned within 30 s of the cancel(got [no, after 60 s]; twin 59 s)nocopy(thePG_CATCHcallspexport_cleanup_in_catchwith the handled error on the stack, thenPG_RE_THROW)double cancel:57014 and errstart checks, andsilent listing: the export reports its own cancel (57014)(got [ERROR: XX000: errstart was not called])On this base,
nolistno longer reddensparts: no upload of this export is left open, because #1727 closes that case too, andnodeadlineno longer reddens the listing-count check, because #1727's 60 s quiet limit now ends the silent listing. That row is nownever, and the listing-count row is dated bynolistalone.Regression, PG17
export_sinkparallel_export_parquetobjstore_sink_writeobjstore_moduleobjstore_export_double_cancel(#1744)Bookkeeping
suites_not_coveredstays 34.cluster_tests4027 → 4057 by collection; TESTS.md §338; a CHANGELOG entry.d023de30over the PG16 and PG18 shell logs; guards 837 passed (rc=0);compare_to_bash.py: 30 literal matches, "every bash property is covered";shellcheck -S errorclean;docs_style53/53; no build warnings on PG15, 17 and 19.Not verified
POST ?uploadsthat reached the store after the listing would still leak.getaddrinfoin connect is not bounded by the deadline. The suite uses a numeric host.pexport_cleanupraises outside the module's catch would end the callback before the aborts. I found no way to reach one with a cancel, so no test covers it.🤖 Generated with Claude Code