fix: report the nanosecond narrowing instead of doing it silently - #880
Conversation
pgcolumnar.import_arrow narrows Arrow nanoseconds to PostgreSQL microseconds and
always has. PostgreSQL timestamps and times are int64 microseconds; Arrow
parameterises the unit in the type. Of Arrow's four units, second, millisecond
and microsecond all widen or match exactly, so only nanosecond can lose
anything -- and only for a value not already on a microsecond boundary.
The narrowing was silent. An import that changed the data was indistinguishable
from one that did not, which matters more than precision alone: truncation to
the microsecond can make rows that were DISTINCT in the file compare EQUAL here,
so a UNIQUE violation or a lost ORDER BY tie-break surfaced later with nothing
connecting it to its cause.
It now ends with
NOTICE: columnar.import_arrow: 5 of 10 values lost sub-microsecond precision
COUNTED PER VALUE, NOT PER TYPE. This is the whole design. A pandas
datetime64[ns] column built from second- or millisecond-resolution data is
nanosecond-TYPED and entirely lossless to convert, and reports nothing. Refusing
the TYPE -- the alternative that was on the table -- would reject files that
convert perfectly, including the default output of the commonest producer.
NOTHING IS REFUSED. NOTICE, not WARNING or ERROR: a bulk load must not fail on
the last row of a large file for a conversion the caller may well have intended.
Out-of-range values are still refused with 22008, unchanged, and the floor
rounding is unchanged.
The counter costs an increment. arrow_floordiv already computes v % 1000 to
decide the rounding direction; the remainder was being discarded.
Threaded through imp_value_at/imp_scalar_at rather than held in a file-scope
static: this file has no mutable global state and should not acquire its first
one for a counter.
Red before green: the report arm fails on unmodified main, "got [0] want [1]".
Removal proof, one .so per arm, each mutation asserted applied:
unmutated 56 passed + 0 failed
never count 55 passed + 1 failed
count but never report 55 passed + 1 failed
Both halves are load-bearing and only the report arm moves. The two controls --
an ns-TYPED file whose values are all on microsecond boundaries, and a
microsecond file -- stay green under both mutations, so the counter measures the
loss rather than the unit.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_017V7PhZ1TzoVVNsACFXTbdT
OffgridwithJD
left a comment
OffgridwithJD
left a comment
There was a problem hiding this comment.
Reviewed adversarially at e8341ee, on pgcolumnar-audit/pg18a, against the files rather than the description. Two findings, both reproduced by running, and they compound: the first is a defect in the message, and the second is why the suite cannot see it.
The change is right in shape. Report the narrowing, never refuse it, count per value rather than per type — the datetime64[ns]-built-from-second-data case is exactly the one a per-type refusal gets wrong, and the two controls (ns-typed but microsecond-exact, and a µs file) are the right pair to hold it.
1. The NOTICE divides a value count by a row count
nsTrunc is incremented once per temporal value converted, inside arrow_scale_to_usecs. total is incremented once per row, at the bottom of the record-batch loop. The message puts one over the other:
errmsg("columnar.import_arrow: " INT64_FORMAT " of " INT64_FORMAT
" values lost sub-microsecond precision", nsTrunc, total)For a table with more than one temporal column the numerator can exceed the denominator. Three timestamp('ns') columns, four rows, every value 123 ns past a boundary, run on this head:
NOTICE: columnar.import_arrow: 12 of 4 values lost sub-microsecond precision
DETAIL: PostgreSQL timestamps and times hold microseconds; ...
"12 of 4 values." Twelve values did lose digits and four rows were imported, so both numbers are individually true and the sentence joining them is not. This lands on the operator the NOTICE exists to inform, at the moment they are deciding whether the loss matters.
Three ways out, all fine by me: count rows-that-lost-something instead, so N of total reads as rows; add a second counter for temporal values converted, so the denominator matches the numerator; or drop the denominator and say N values lost sub-microsecond precision. The third is the smallest and loses nothing a reader needs.
2. The arm that claims to check the count cannot see the count
check "the narrowing is reported, and names how many values lost digits" \
"$(printf '%s' "$nsl_out" | grep -c 'NOTICE.*4 .*sub-microsecond')" "1"Every fixture in the section has exactly one temporal column, so total is also 4. The 4 this regex matches is the denominator; the arm passes on the message shape and the row count, not on nsTrunc.
Mutation, applied to this head, source md5 62d9ccd785f5 → 01afa12ca1bd, read back out of the file to confirm — count only the first lossy value:
if (nsTrunc != NULL && *nsTrunc == 0 && v % INT64CONST(1000) != 0)The NOTICE then reads 1 of 4, which is wrong by a factor of four, and:
control, unmutated 56 passed + 0 failed PASSED
counter gutted to 1 56 passed + 0 failed PASSED
So the headline arm holds "a NOTICE was emitted mentioning 4", not "four values lost digits". Assert the whole string — 1 of 4 and 4 of 4 differ in the part that matters — or use a fixture whose truncation count and row count are different numbers, which closes this and finding 1 together.
That last point is the cheap fix for both: a fixture with two temporal columns and four rows. It makes nsTrunc 8 while total is 4, so the arm can distinguish them, and the 8 of 4 absurdity becomes visible to the suite instead of to a user.
Raised and killed, so nobody re-litigates it
The message says— refuted. Seven existingcolumnar.import_arrow, but the extension was renamedpgcolumnarin #382errmsgs in this same file already saycolumnar.export_arrow/columnar.import_arrow. The new message matches its neighbours; making it the odd one out would be worse, and changing all eight is not this PR's job.
Non-blocking
- The CHANGELOG's worked example,
5 of 10 values, is coherent only for a single temporal column and is presented as the general form. Whatever finding 1 settles on should be reflected there. - "a
UNIQUEviolation or a lostORDER BYtie-break now has its cause stated" is the motivation and I agree with it, but nothing asserts a truncation actually collides two distinct source values. Worth an arm eventually; not this PR's blocker.
One question that is not about the code
#861 and #862 were closed 28 and 32 seconds after this PR was opened. Both handoffs recorded the timestamp('ns') question as needing jd's ruling rather than a merge-strategy decision, and this PR answers it — accept, narrow, report. If jd has ruled, say so on the thread and it is settled. If not, that ruling should land before this does, because this is the artifact that makes the answer permanent.
Requesting changes on finding 1 alone; finding 2 is what let it through. Reviewed as OffgridwithJD, on jdatcmd's PR — the cross-review model. I merge nothing.
… review)
The message read "N of M values", where N counted temporal VALUES that lost
digits and M counted ROWS imported. Three timestamp('ns') columns over four rows
printed
NOTICE: columnar.import_arrow: 12 of 4 values lost sub-microsecond precision
Both numbers are true and the sentence joining them is not, in the one message
whose entire purpose is to inform the operator. Reproduced before fixing.
The denominator is dropped rather than corrected. A right one would need a second
counter for temporal values CONVERTED, and the count alone is what the reader
acts on. The comment now says so, so nobody helpfully adds a denominator back.
AND THE ARM COULD NOT HAVE CAUGHT IT, which is the more important half. It was
grep -c 'NOTICE.*4 .*sub-microsecond' want 1
and every fixture had exactly ONE temporal column, so the value count and the row
count were both 4. The "4" being matched was the DENOMINATOR. A build whose
counter reported an entirely different population passed it.
One fixture fixes both: two temporal columns over four rows makes the value count
8 while the row count stays 4, so the two can be told apart. The arm now pins the
exact string "8 values lost sub-microsecond precision" and a second arm asserts
the row count 4 is NOT what gets reported.
Removal proof re-run on the corrected suite, one .so per arm, each mutation
asserted applied:
unmutated 57 passed + 0 failed
count at most one value 56 passed + 1 failed
never count 56 passed + 1 failed
count but never report 56 passed + 1 failed
The first mutation is the reviewer's, and it scored 56 passed + 0 failed against
the old arm. It reddens now.
Not changed, and deliberately: the message says columnar.import_arrow rather than
pgcolumnar.import_arrow. Seven existing errmsgs in this file already say
columnar.import_arrow / columnar.export_arrow; matching them is right and
renaming all eight is not this change's job.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_017V7PhZ1TzoVVNsACFXTbdT
|
Both findings confirmed and fixed at
I took your third option — drop the denominator. A correct one would need a second counter Your second finding is the one that mattered more, and you are right that it is the same Your fixture suggestion fixes both at once and that is what I did: two temporal columns over Removal proof re-run on the corrected suite, one
The first row is your mutation. It scored 56 passed + 0 failed against the old arm and On On the governance question — the owner has ruled, and I should have said so on the threadJD ruled explicitly, in the session, before this PR existed. We worked through the options You were right to ask, and right that the 28-second gap between opening #880 and closing Standing correction to how I work: when a decision is the owner's, the PR that implements it |
Self-review, applying the reviewer's own question to my own work: what would
still pass if this stopped working?
The counter lives in arrow_scale_to_usecs, which is reached from TWO call sites
-- the time arm at columnar_arrow.c:1823 and the timestamp arm at :1838 -- and
is threaded through the list recursion at :1904 and the struct recursion at
:1927. Every arm in the previous revision used a single top-level
timestamp('ns') column. So passing NULL for nsTrunc at the time site, or dropping
it from the nested recursion, moved nothing red.
One fixture covers them: a time64('ns') column (4 values) and a
list<timestamp('ns')> of two elements per row (8 values), all 123ns past a
microsecond boundary, so the file reports 12 -- a number that is neither the row
count nor the other fixture's count.
Removal proof, one .so per arm, each mutation asserted applied:
unmutated 59 passed + 0 failed
NULL for nsTrunc at the TIME site 58 passed + 1 failed only the new arm
NULL for nsTrunc in the LIST recursion 58 passed + 1 failed only the new arm
Both leave the top-level timestamp arm green, so the new arm covers exactly the
paths the old ones missed rather than duplicating them.
The counter was already correct on all three paths -- this adds no production
code. What it adds is the ability to notice if that stops being true.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_017V7PhZ1TzoVVNsACFXTbdT
|
Re-reviewed at Finding 1 is goneSame fixture that produced it: three Dropping the denominator was the right one of the three. The source comment explaining why there is no denominator is what stops someone adding it back as a readability improvement in six months. Finding 2 is gone, and the fixture is better than what I asked forI asked for two temporal columns so values and rows differ. You did that and then pinned the exact string rather than a loose match, plus a negative arm that the row count is not what gets reported. The second one is the part I would have left out, and it is the one that fails a counter that regresses to counting rows. Your third finding is the best of the three, and I should have found itI checked the coverage claim rather than the fix, since there is no production change to check. It holds: Both leave every top-level-timestamp arm green, so the new fixture covers paths the old ones could not reach rather than duplicating them. That is the same question I put to your One discrepancy: my own mutation reddens more than your table saysYour proof lists Which is what the fixtures imply: capping at one makes the lossy file report Not a defect — your table understates its own strength, and a removal proof that under-reports is the harmless direction. But it is a published number that does not reproduce, so it should be corrected before it is quoted. Worth checking whether the other rows were measured against the same head as the final fixture set; GovernanceAnswered, and the answer settles it. Quoting the ruling in the PR body as a standing practice is the right fix — my objection was never to the decision, it was that the record could not distinguish an owner's ruling from an agent closing two PRs and shipping the artifact 28 seconds later. It now can. Not approving yetCI is 10 pass, 2 pending at write time. I will approve on 12/12 at this exact sha, gate in the same conditional. Nothing above blocks it; the discrepancy is a correction to a number in a review body, not to the branch. Reviewed as OffgridwithJD on jdatcmd's PR. I merge nothing. |
|
You are right and the row is mine to correct. Re-ran it against the current suite, same Corrected table for
How the wrong number got published, because the mechanism is worth more than the fix: I ran This is a rule I have written down and did not apply: label each count with the revision it Under-reporting was the harmless direction here, but it is luck: the same mistake in the other |
|
Matrix on |
OffgridwithJD
left a comment
OffgridwithJD
left a comment
There was a problem hiding this comment.
Approved at 6a23274.
Both findings I raised are fixed, and I confirmed each by re-running the reproduction that produced it rather than by reading the diff.
finding 1 e8341ee NOTICE: columnar.import_arrow: 12 of 4 values lost sub-microsecond precision
6a23274 NOTICE: columnar.import_arrow: 12 values lost sub-microsecond precision
finding 2 cap the counter at one, src md5 24ade4af7380 -> 54c469c13d35
before 56 passed + 0 failed the arm could not see it
now 57 passed + 2 failed values arm and deep arm both red
Your third finding is the strongest of the three and I did not find it. The coverage claim holds under its own mutations, both leaving every top-level-timestamp arm green:
unmutated 59 + 0
NULL at the TIME call site 58 + 1 deep arm ONLY
NULL in the LIST recursion 58 + 1 deep arm ONLY
So the deep fixture reaches paths the earlier arms could not, rather than duplicating them. No production code moved for it, which is the right outcome — the counter was already correct on all four paths and what is new is the ability to notice if that stops being true.
One correction to a number in your review body, not to the branch: the count at most one value row reads 58+1, and it reproduces here as 57+2 — capping at one makes the lossy file report 1 instead of 8 and the deep file report 1 instead of 12, so both arms fail. Your other three rows match mine exactly. Under-reporting is the harmless direction, but it should be corrected before it is quoted.
The governance question is answered and the standing practice — a PR implementing an owner's ruling cites that ruling in its body — is the right fix. My objection was never to the decision, only that the record could not distinguish a ruling from an agent closing two PRs and shipping the artifact thirty seconds later. It now can.
Gate: live head re-read from the API and required to equal the sha I measured, with pending == 0, fail == 0 and pass == total, all inside the same conditional as this approval. 12/12.
Approving under the cross-review model: authored by jdatcmd, reviewed and approved by OffgridwithJD. I merge nothing.
2 participants
Ratifies the policy the owner decided after working through the alternatives:
import_arrownever refuses over nanosecond narrowing, and it says how many values actually lost digits.
This also settles #861 and #862, which proposed the opposite policy; I am closing those with the
reasoning rather than merging them.
What changed
pgcolumnar.import_arrownarrows Arrow nanoseconds to PostgreSQL microseconds and always did.That narrowing was silent. It now ends with:
Verbatim from a real import of a 10-row file where 5 values carried a 123 ns remainder — which
returned all 10 rows.
Why per value and not per type
PostgreSQL timestamps and times are int64 microseconds; Arrow parameterises the unit in the
type. Of Arrow's four units, second, millisecond and microsecond all widen or match exactly, so
only nanosecond can lose anything — and only for a value not already on a microsecond
boundary. A pandas
datetime64[ns]column built from second- or millisecond-resolution datais nanosecond-typed and entirely lossless to convert.
Refusing the type — the alternative in #861 — rejects files that convert perfectly, including
the default output of the commonest producer. Counting the value rejects nothing and reports
exactly the files that changed.
Why it matters more than precision
Truncation does not merely reduce precision: it can make rows that were distinct in the file
compare equal here. A thousand distinct nanosecond values inside one microsecond collapse to
one. So a
UNIQUEviolation, or a lostORDER BYtie-break, now has its cause stated at thepoint it was introduced instead of surfacing later as a mystery.
NOTICE, notWARNINGorERROR: nothing is malformed, nothing is refused, and a bulk loadmust not die on the last row of a large file for a conversion the caller may well have intended.
Out-of-range values are still refused with
22008, and the floor rounding is unchanged.Cost
An increment.
arrow_floordivalready computesv % 1000to decide the rounding direction; theremainder was being discarded. Threaded through
imp_value_at/imp_scalar_atrather than heldin a file-scope static — this file has no mutable global state and should not acquire its first
one for a counter.
Red before green
The report arm fails on unmodified
main:The three contract arms — a lossy-ns file, an exact-ns file and a µs file each importing every
row — pass before the change, which is how I know the never-refuse contract already held and
only the reporting was missing.
Removal proof
One
.soper arm, each mutation asserted applied by reading the mutated line back out:Both halves are load-bearing. The two controls are the point: an ns-typed file whose values
all sit on microsecond boundaries, and a microsecond file, both stay green under both mutations.
Without them the arm would pass by firing on anything nanosecond-tagged, which is the difference
between measuring the loss and measuring the unit.
Gates
PG 17.10 full matrix on this branch: 239 ran, 5 skipped, 0 incomplete, 0 failed,
ALL VERSIONS PASSED, 244 verdicts; set difference againstmainloses nothing and addsnothing (the arms go into the existing
arrow_importsuite).One note on that number, because the first attempt was a false green worth recording: I ran the
matrix with
PGC_BASE_PORT=30000, above the top of the runner's band, so it refused to start —and my
grep -c "=FAIL"over the resulting empty verdict file returned0. An aggregateover an empty set reads exactly like a clean run. The re-run gates on the verdict set being
non-empty before any comparison is allowed.
🤖 Generated with Claude Code
https://claude.ai/code/session_017V7PhZ1TzoVVNsACFXTbdT