| From: | PG Bug reporting form <noreply(at)postgresql(dot)org> |
|---|---|
| To: | pgsql-bugs(at)lists(dot)postgresql(dot)org |
| Cc: | yk(dot)verma2000(at)gmail(dot)com |
| Subject: | BUG #19733: Row not visible to a new snapshot after its transactional logical decoding message has been streamed |
| Date: | 2026-09-30 04:30:43 |
| Message-ID: | 19733-5fcd39e85fa221a4@postgresql.org |
| Views: | Whole Thread | Raw Message | Download mbox | Resend email |
| Thread: | |
| Lists: | pgsql-bugs |
The following bug has been logged on the website:
Bug reference: 19733
Logged by: Yash Kumar Verma
Email address: yk(dot)verma2000(at)gmail(dot)com
PostgreSQL version: 18.6
Operating system: Linux 6.10.14 aarch64, Debian 13 (official postg
Description:
A transaction updates a row, calls pg_logical_emit_message(true, ...) with
the row's new version, and commits. A client streaming the slot with
pg_recvlogical receives the message and then runs a SELECT on that row
from a separate ordinary session (READ COMMITTED, autocommit, same server).
Occasionally that SELECT returns the row version from before the update.
So a transaction's changes can be invisible to a new snapshot taken after
the client has received that transaction's decoded output.
We hit this in production, where a service uses transactional logical
messages as an outbox. The consumer re-reads the row when it gets the
message and sometimes reads stale data. Our current workaround is to sleep
100 ms before the read.
Full scripts and results:
https://github.com/YashKumarVerma/postgres-non-linear-reads-report
EXPECTED
Once pg_recvlogical has received the decoded message from transaction X,
a new snapshot taken after that point sees X as committed. The SELECT
should never return a version lower than the one in the message.
ACTUAL
One 30-second run per version, 32 pgbench clients rate-limited to 7000 tps:
16.15 210309 messages 28 stale reads
17.11 210321 messages 14 stale reads
18.6 210108 messages 21 stale reads
19beta4 209800 messages 13 stale reads
Sample output (every stale read is exactly one version behind):
STALE id=9 message_version=497 select_returned=496
STALE id=10 message_version=974 select_returned=973
STALE id=9 message_version=1072 select_returned=1071
A separate Go client (pgx + pglogrepl, pgoutput with messages 'true',
8 writers, 16000 messages per run, 3 runs per version) sees 12-38 stale
reads per run on 16, 17, 18 and 19beta4. The row becomes visible
0.1-5.4 ms after the message arrives. With that client, a single writer
never reproduced it, and reading with SELECT ... FOR SHARE instead of a
plain SELECT never reproduced it.
CONFIGURATION
Official postgres Docker image, default postgresql.conf, plus only
-c wal_level=logical. synchronous_commit = on, synchronous_standby_names
= '' (defaults). No standbys, no other replication clients.
STEPS TO REPRODUCE
docker run -d --name walrace -e POSTGRES_HOST_AUTH_METHOD=trust \
postgres:18 -c wal_level=logical
docker cp sql walrace:/sql # sql/ directory from the repo above
docker exec walrace /sql/repro.sh
--- setup.sql
DROP TABLE IF EXISTS txn;
CREATE TABLE txn (id bigint PRIMARY KEY, version bigint NOT NULL);
INSERT INTO txn SELECT g, 0 FROM generate_series(1, 64) g;
SELECT pg_drop_replication_slot('wal_race') FROM pg_replication_slots WHERE
slot_name = 'wal_race';
SELECT pg_create_logical_replication_slot('wal_race', 'test_decoding');
--- writer.sql (pgbench script; each client owns row client_id + 1)
BEGIN;
UPDATE txn SET version = version + 1 WHERE id = :client_id + 1 RETURNING
version \gset
SELECT pg_logical_emit_message(true, 'wal_race', (:client_id + 1) || ':' ||
:version);
COMMIT;
--- consumer.sh (each streamed message becomes a SELECT in one long-lived
--- psql session; it prints a row only when the version read is older)
pg_recvlogical -U postgres -d postgres -S wal_race --start -f - -F 0 \
| sed -un 's/^message: transactional: 1 prefix: wal_race, sz: [0-9]*
content:\([0-9]*\):\([0-9]*\)$/SELECT '"'"'STALE id=\1 message_version=\2
select_returned='"'"' || version FROM txn WHERE id = \1 AND version < \2;/p'
\
| psql -U postgres -d postgres -At
--- repro.sh
psql -U postgres -d postgres -q -f setup.sql >/dev/null
timeout 36 ./consumer.sh > stale.log 2>&1 &
sleep 1
pgbench -U postgres -d postgres -n -c 32 -j 8 -R 7000 -T 30 -f writer.sql |
grep "actually processed"
wait || true
cat stale.log
echo "stale_reads=$(grep -c STALE stale.log || true)"
pgbench is rate-limited because the single psql session in consumer.sh
cannot keep up with unthrottled pgbench. If psql falls behind, it reads
each row long after the message arrives, and nothing reproduces.
PLATFORM
Host: Apple M4 Pro, 24 GB RAM, macOS 27.0
Docker Desktop 28.3.2; VM: Linux 6.10.14-linuxkit aarch64, 12 CPUs, 8 GB RAM
glibc 2.41 (Debian 13)
Images: postgres:16, :17, :18, :19beta4, pulled 2026-09-29
| From | Date | Subject | |
|---|---|---|---|
| Next Message | Paul Kim | 2026-09-30 04:32:14 | Re: REVOKE's CASCADE protection doesn't work with INHERITed table owners |
| Previous Message | PG Bug reporting form | 2026-09-30 03:34:33 | BUG #19732: first_value/last_value/nth_value return NULL with EXCLUDE TIES when the current row is outside its f |