From abf6c7d07b3c0b0617cc97b81420ae639f935e13 Mon Sep 17 00:00:00 2001 From: Dave Page Date: Wed, 12 Aug 2026 11:44:59 +0100 Subject: [PATCH 1/2] Clip a failed item's error message on a character boundary strlcpy() counts bytes, so a message longer than the 1024 byte buffer whose cut fell inside a multi-byte character left a partial one behind. That partial character was then stored: encoding is validated where input arrives from a client, in pg_client_to_server(), and SPI never crosses that boundary, so the literal the worker assembles in C goes into queue.error_message as whatever bytes it happens to hold. The row is then invalid text in the server encoding. length(), substring() and any client that decodes strictly raise on it, whilst SELECT, left() and LIKE happen to survive, so whether an operator's query breaks depends on which functions it uses -- and the row that breaks it is by definition one that was already reporting a problem. pg_mbcliplen() clips to the last character that fits entirely. It works in the server encoding rather than assuming UTF-8, and it allocates nothing, which matters inside an error handler. The failure is still recorded either way, so this is not the reclaim loop that 004 rules out; TAP 007 therefore asserts that the stored message reads back character-wise, which is the property that breaks, and treats the attempt being charged as a guard rather than the point. Closes #62 --- src/worker.c | 23 +++- test/t/007_error_message_truncation.pl | 181 +++++++++++++++++++++++++ 2 files changed, 203 insertions(+), 1 deletion(-) create mode 100644 test/t/007_error_message_truncation.pl diff --git a/src/worker.c b/src/worker.c index 107f828..f02d085 100644 --- a/src/worker.c +++ b/src/worker.c @@ -16,6 +16,7 @@ #include #include "commands/dbcommands.h" +#include "mb/pg_wchar.h" #include "pgstat.h" #include "postmaster/bgworker.h" #include "postmaster/interrupt.h" @@ -263,7 +264,27 @@ queue_item_note_error(void) edata = CopyErrorData(); if (edata->message != NULL) - strlcpy(failed_item_error, edata->message, sizeof(failed_item_error)); + { + /* + * Clipped on a character boundary rather than with strlcpy(), which + * counts bytes. A message longer than the buffer whose cut fell inside + * a multi-byte character left a partial one behind, and that went on to + * be stored: nothing between here and the UPDATE in + * queue_item_record_failure() validates the encoding, because SPI does + * not cross the protocol boundary where input from a client is checked. + * The column was left holding text that is invalid in the server + * encoding, so reading it back with anything that walks characters + * rather than bytes -- length(), or a client decoding it strictly -- + * fails on that row. pg_mbcliplen() works in the server encoding and + * allocates nothing, both of which matter here. + */ + 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'; + } FreeErrorData(edata); diff --git a/test/t/007_error_message_truncation.pl b/test/t/007_error_message_truncation.pl new file mode 100644 index 0000000..c047626 --- /dev/null +++ b/test/t/007_error_message_truncation.pl @@ -0,0 +1,181 @@ +# Copyright (c) 2025 - 2026, pgEdge, Inc. +# +# Verify that an over-long error message is clipped on a character boundary, so +# that the failure can still be recorded against the item. +# +# The worker keeps a failed item's message in a fixed 1024 byte buffer and +# quotes it into the UPDATE that charges the attempt. Clipping that buffer by +# bytes left a partial character behind whenever the cut fell inside a multi-byte +# one, and that partial character was then stored: SPI does not cross the +# protocol boundary at which input from a client is checked, so nothing on the +# way in validates the encoding. queue.error_message was left holding text that +# is invalid in the server encoding, and reading such a row back with anything +# that walks characters rather than bytes -- length(), or a client decoding +# strictly -- fails. +# +# The failure itself is still recorded, so this is not the runaway that 004 rules +# out; the damage is confined to the stored message. +# +# The fault injected here is a trigger on the chunk table that raises a message +# of 1022 single-byte characters followed by one three-byte character, so the +# 1023rd byte of the buffer is the first byte of a character whose other two do +# not fit. +# +# The item is marked sparse_only, so no embedding is ever requested, but the +# worker resolves and initialises the provider for every batch before it reaches +# that decision. The provider is therefore set to ollama, whose init needs +# neither an API key nor a network round trip; nothing here ever calls it to +# generate anything. + +use strict; +use warnings; + +# See the comment in 001_worker_coverage.pl about loading these at compile time. +use PostgreSQL::Test::Cluster; +use PostgreSQL::Test::Utils; +use Test::More; + +my $dbname = 'message_truncation'; + +# Deliberately no pgedge_vectorizer.databases yet; see the comment in 004 about +# why the database is named only once its extension exists. +my $node = PostgreSQL::Test::Cluster->new('vectorizer_message_truncation'); +$node->init; +$node->append_conf( + 'postgresql.conf', qq( +shared_preload_libraries = 'pgedge_vectorizer' +pgedge_vectorizer.worker_poll_interval = 200 +pgedge_vectorizer.provider = 'ollama' +pgedge_vectorizer.enable_hybrid = on +max_worker_processes = 16 +)); + +$node->start; + +$node->safe_psql('postgres', "CREATE DATABASE $dbname"); +$node->safe_psql($dbname, 'CREATE EXTENSION vector'); +$node->safe_psql($dbname, 'CREATE EXTENSION pgedge_vectorizer'); + +$node->append_conf('postgresql.conf', + "pgedge_vectorizer.databases = '$dbname'\n"); +$node->reload; + +# The chunk table carries the columns the worker touches on this path: embedding, +# which the probe deciding whether a dense vector is still needed reads for every +# claimed item, and token_count and sparse_embedding, which the sparse path reads +# and writes. embedding is left NULL, so it is the queue row's own sparse_only +# flag that keeps the embedding provider out of this test. The _idf_stats sidecar +# is deliberately absent, which bm25_load_idf_stats() handles on its own. +# +# 1022 'x' followed by U+4E16, whose UTF-8 encoding is three bytes. The message +# is therefore 1025 bytes, and a byte-wise clip to fit a 1024 byte buffer keeps +# 1023 of them: the last is the first byte of a character on its own. +$node->safe_psql( + $dbname, q( +CREATE TABLE long_message_chunks ( + id bigint PRIMARY KEY, + token_count int, + embedding vector(3), + sparse_embedding sparsevec +); + +INSERT INTO long_message_chunks (id, token_count) VALUES (1, 3); + +CREATE FUNCTION raise_long_message() RETURNS trigger AS $$ +BEGIN + RAISE EXCEPTION '%', repeat('x', 1022) || U&'\4E16'; +END +$$ LANGUAGE plpgsql; + +CREATE TRIGGER raise_long_message + BEFORE UPDATE ON long_message_chunks + FOR EACH ROW EXECUTE FUNCTION raise_long_message(); +)); + +my $log_offset = (-s $node->logfile) // 0; + +$node->safe_psql( + $dbname, qq( +INSERT INTO pgedge_vectorizer.queue + (chunk_id, chunk_table, content, status, metadata, max_attempts) +VALUES (1, 'long_message_chunks', 'alpha beta gamma', 'pending', + '{"sparse_only": true}'::jsonb, 2) +)); + +# Wait for the attempt rather than assuming one has happened by now. An unfixed +# build never records one, so this waits out the timeout and the assertion below +# fails on the value it did see. +my $attempts = 0; +my $deadline = time() + 30; + +while (time() < $deadline) +{ + $attempts = $node->safe_psql($dbname, + "SELECT attempts FROM pgedge_vectorizer.queue WHERE chunk_table = 'long_message_chunks'"); + + last if $attempts > 0; + + sleep 1; +} + +# A guard rather than the point of the test: recording the failure works either +# way, since the invalid sequence is stored rather than rejected, and both of +# these hold on an unfixed build too. +cmp_ok($attempts, '>', 0, + 'an over-long message does not stop the attempt being charged'); + +my $log = slurp_file($node->logfile, $log_offset); + +unlike($log, qr/could not record failure for queue item/, + 'the failure is recorded rather than being reported as unrecordable'); + +# This is the point of the test. length() walks characters, so it raises on a +# stored message ending in half of one; an unfixed build fails here rather than +# returning a number. +my ($rc, $stdout, $stderr) = $node->psql($dbname, q( +SELECT length(error_message) FROM pgedge_vectorizer.queue + WHERE chunk_table = 'long_message_chunks' +)); + +is($rc, 0, + 'the recorded message is valid in the server encoding'); + +is($stdout, '1022', + 'every character of the recorded message is whole'); + +# The message is kept as far as it fits and no further: 1022 bytes, because the +# three-byte character that follows cannot fit in the 1023 available and is +# therefore dropped whole rather than in part. +my $stored = $node->safe_psql($dbname, q( +SELECT octet_length(error_message) FROM pgedge_vectorizer.queue + WHERE chunk_table = 'long_message_chunks' +)); + +is($stored, '1022', + 'the message is clipped to the last character that fits entirely'); + +my $intact = $node->safe_psql($dbname, q( +SELECT error_message = repeat('x', 1022) FROM pgedge_vectorizer.queue + WHERE chunk_table = 'long_message_chunks' +)); + +is($intact, 't', + 'what is kept is the head of the message, unaltered'); + +# Prove the fixture is what the test claims, so that the assertions above cannot +# pass because the error was something shorter than the buffer all along. The +# length is measured by the server, which is the only thing that agrees with the +# worker on how many bytes the message runs to. +my $fixture_bytes = $node->safe_psql($dbname, + q(SELECT octet_length(repeat('x', 1022) || U&'\4E16'))); + +is($fixture_bytes, '1025', + 'the injected message is longer than the buffer that has to hold it'); + +# And that this is the error the worker actually hit: it reports the original in +# full before recording it. +like($log, qr/x{1022}/, + 'the over-long message is the failure being recorded'); + +$node->stop; +done_testing(); From f15c1f2609a22a37aedd0709b87fd0fcf8be67dd Mon Sep 17 00:00:00 2001 From: Dave Page Date: Wed, 12 Aug 2026 11:51:29 +0100 Subject: [PATCH 2/2] Bound the message read and pin the test's encoding Two review points, neither changing what the fix does. strnlen() bounded by the buffer replaces strlen(), and strlcpy() given the clipped length replaces memcpy(). Nothing longer than the buffer can be kept in any case, so bounding the read costs nothing and means a message that is somehow not NUL-terminated cannot make us over-read (CWE-126); trim_whitespace() already measures its input this way for exactly that reason. Reusing strlcpy() also leaves the copy in the hands of a function that cannot overrun the destination. The test now initialises its cluster with an explicit --encoding=UTF8 rather than inheriting the developer's locale. What is under test is encoding-agnostic, since pg_mbcliplen() reads the server encoding, but the fixture's arithmetic is not: it relies on U+4E16 occupying three bytes, and under a single-byte encoding the message would neither reach 1025 bytes nor straddle the boundary. --- src/worker.c | 34 ++++++++++++++++---------- test/t/007_error_message_truncation.pl | 8 +++++- 2 files changed, 28 insertions(+), 14 deletions(-) diff --git a/src/worker.c b/src/worker.c index f02d085..0522308 100644 --- a/src/worker.c +++ b/src/worker.c @@ -266,24 +266,32 @@ queue_item_note_error(void) if (edata->message != NULL) { /* - * Clipped on a character boundary rather than with strlcpy(), which - * counts bytes. A message longer than the buffer whose cut fell inside - * a multi-byte character left a partial one behind, and that went on to - * be stored: nothing between here and the UPDATE in + * Clipped where a character ends rather than where the buffer does. + * Clipping by bytes alone left a partial character behind whenever the + * cut fell inside a multi-byte one, and that partial character went on + * to be stored: nothing between here and the UPDATE in * queue_item_record_failure() validates the encoding, because SPI does - * not cross the protocol boundary where input from a client is checked. - * The column was left holding text that is invalid in the server - * encoding, so reading it back with anything that walks characters - * rather than bytes -- length(), or a client decoding it strictly -- - * fails on that row. pg_mbcliplen() works in the server encoding and - * allocates nothing, both of which matter here. + * not cross the protocol boundary at which input from a client is + * checked. The column was left holding text that is invalid in the + * server encoding, so reading it back with anything that walks + * characters rather than bytes -- length(), or a client decoding it + * strictly -- fails on that row. pg_mbcliplen() works in the server + * encoding and allocates nothing, both of which matter here. + * + * The length handed to it is measured with strnlen() bounded by the + * buffer rather than with strlen(), as trim_whitespace() does and for + * the same reason: nothing longer than the buffer can be kept anyway, + * and the bound means we cannot over-read even if handed a message that + * is somehow not NUL-terminated (CWE-126). strlcpy() then gets the + * clipped length plus its terminator, so it copies exactly as far as + * pg_mbcliplen() allows. */ int len = pg_mbcliplen(edata->message, - strlen(edata->message), + strnlen(edata->message, + sizeof(failed_item_error)), sizeof(failed_item_error) - 1); - memcpy(failed_item_error, edata->message, len); - failed_item_error[len] = '\0'; + strlcpy(failed_item_error, edata->message, len + 1); } FreeErrorData(edata); diff --git a/test/t/007_error_message_truncation.pl b/test/t/007_error_message_truncation.pl index c047626..cdd5edc 100644 --- a/test/t/007_error_message_truncation.pl +++ b/test/t/007_error_message_truncation.pl @@ -40,7 +40,13 @@ # Deliberately no pgedge_vectorizer.databases yet; see the comment in 004 about # why the database is named only once its extension exists. my $node = PostgreSQL::Test::Cluster->new('vectorizer_message_truncation'); -$node->init; + +# The encoding is pinned rather than inherited from whatever locale the developer +# happens to be running under, because this test counts bytes: it relies on +# U+4E16 occupying three of them, which is true of UTF-8 and not of everything +# else. The fix under test is encoding-agnostic, since pg_mbcliplen() reads the +# server encoding, but the arithmetic in the fixture below is not. +$node->init(extra => [ '--locale=C', '--encoding=UTF8' ]); $node->append_conf( 'postgresql.conf', qq( shared_preload_libraries = 'pgedge_vectorizer'