Worker clips error messages byte-wise, so a multibyte message stops the failure ever being recorded

[dpage]

Corrected. The first version of this issue claimed the truncation makes the failure impossible to record, and so puts the item into a reclaim loop. That is wrong, and the correction is in the comments below. The defect is real but narrower: the invalid sequence is stored rather than rejected, so the damage is a corrupt value in queue.error_message rather than a runaway. The text below is the corrected version.

The worker clips a failed item's error message to its 1024 byte buffer with strlcpy(), which counts bytes and knows nothing about character boundaries. When the cut lands in the middle of a multi-byte character the buffer is left holding a partial one, and that partial character is then written to queue.error_message, because nothing on the way in validates it. The column ends up holding text that is invalid in the server encoding, and any read that walks characters rather than bytes fails on that row.

I noticed this whilst reviewing #61 and it is unrelated to that change; it came in with 9ab3625.

The mechanism

failed_item_error is a fixed 1024 byte buffer (src/worker.c:65 and src/worker.c:70), and queue_item_note_error() fills it with

strlcpy(failed_item_error, edata->message, sizeof(failed_item_error));

at src/worker.c:266. strlcpy() copies at most 1023 bytes and NUL-terminates, with no regard for where characters begin and end, so a message longer than that whose 1023 byte cut falls inside a multi-byte sequence leaves a partial character at the end of the buffer.

queue_item_record_failure() then passes that buffer through quote_literal_cstr() at src/worker.c:332 and interpolates the result into the UPDATE at src/worker.c:347-366, which goes to SPI_execute(). That statement succeeds. Encoding validation happens where input arrives from a client, in pg_client_to_server(), and SPI never crosses that boundary, so a string literal assembled in C and executed through SPI is stored as the bytes it happens to contain.

What actually goes wrong

The row is left holding an invalid text value. Driving the real worker into a 1025 byte message ending in a three-byte character, against an unfixed build, stores 1023 bytes, of which the last is a lead byte with nothing following it. Reading it back:

=> SELECT octet_length(error_message) FROM pgedge_vectorizer.queue;
 1023

=> SELECT length(error_message) FROM pgedge_vectorizer.queue;
ERROR:  invalid byte sequence for encoding "UTF8": 0xe4

=> SELECT convert_from(error_message::bytea, 'UTF8') FROM pgedge_vectorizer.queue;
ERROR:  invalid byte sequence for encoding "UTF8": 0xe4

So length(), substring() and anything else that counts characters raise on that row, as does any client that decodes the column strictly rather than handing back raw bytes. A plain SELECT, left() and LIKE happen to survive, which is what makes this quietly unpleasant: whether an operator's monitoring query breaks depends on which functions it uses, and the row that breaks it is by definition one that was already reporting a problem.

Two things this is not, both of which I checked before writing them off:

• It does not stop the failure being recorded. The attempt is charged, next_retry_at is set, and the item backs off and retires normally, so there is no reclaim loop and Crash fix: copy the error message out of ErrorContext before taking it #61's sibling test 004 is not in play.
• It does not affect dump and restore. pgedge_vectorizer.queue is an extension-owned table, so pg_dump does not carry its data at all.

Reachability

Any error whose message runs past 1023 bytes and contains non-ASCII text near the cut will do it. Provider failures that echo a response body, errors quoting a data value, and user-defined triggers on the chunk table that RAISE are all plausible sources, and none requires anything exotic beyond non-ASCII content, which for a vectorisation extension is thoroughly ordinary.

Suggested fix

Clip on a character boundary with pg_mbcliplen(), which is what PostgreSQL provides for exactly this and what core uses to truncate varchar:

if (edata->message != NULL)
{
    int  len = pg_mbcliplen(edata->message, strlen(edata->message),
                            sizeof(failed_item_error) - 1);

    memcpy(failed_item_error, edata->message, len);
    failed_item_error[len] = '\0';
}

It works in the server encoding rather than assuming UTF-8, so it is correct whatever the server is running, and it allocates nothing, which matters given that this runs inside an error handler.

A regression test wants to drive the real worker into a failure whose message straddles the boundary and then assert that the stored message can be read back character-wise, since that is the property that breaks. Asserting that the attempt was charged would pass on an unfixed build, because it is charged either way.

[dpage]

Correcting myself on the consequence, before anyone acts on the original text.

I claimed the truncated message makes the recording UPDATE unparseable, so the attempt is never charged and the item loops. Having now driven the real worker into it, that is wrong. The UPDATE succeeds and the invalid byte sequence is stored: encoding validation happens in pg_client_to_server(), where input arrives from a client, and SPI never crosses that boundary, so a literal assembled in C goes in as whatever bytes it holds. On an unfixed build the attempt is charged, the item backs off and retires normally, and octet_length(error_message) comes back as 1023 with a lead byte stranded at the end.

What misled me was my own probe rather than the code. I built an invalid value with convert_from(..., 'SQL_ASCII') and passed it through plpgsql EXECUTE, saw SQLSTATE 22021, and attributed it to the UPDATE. In fact convert_from itself raised, at the line before, and my exception handler's message said "UPDATE failed" because that was the only failure I had thought to expect. The first NOTICE never printed, which I should have noticed at the time.

The defect is still real, just narrower than advertised: queue.error_message is left holding text that is invalid in the server encoding, so length(), substring() and any client decoding strictly raise on that row, whilst SELECT, left() and LIKE happen to survive. The fix and the test are unchanged in substance, though the test now asserts the property that actually breaks rather than the one I thought did. I have also checked, and ruled out, any dump and restore consequence: the queue is extension-owned, so its data is never dumped.

The body above has been rewritten accordingly, with the original claim marked as corrected rather than quietly deleted.