Hi Hannu,
I re-tested v3 on your base (061065e28f) and on today's master HEAD; it
applies cleanly to both. All eight points from the v2 review are
addressed and reproduce here -- plain mode is byte-identical to master
(startup 459 B, 'Z' 66 B), the extra ParameterStatus is gone, P is now
session-local, 'l' decodes to the COMMIT record's end_lsn, compat is
back (unpatched libpq completes in plain, rejects rich with the
documented length error), and check-world is clean under cassert (the
new module's 42 subtests, libpq_pipeline 24/24).
> 5. O(1) With-Hold Cursors ('H')
Confirmed, and it is a real win: the per-'Z' cost in rich went from
+41,703 instructions at 1000 open cursors in v2 to a flat +861 in v3.
Measuring the indicators against SQL in the same session, four edge
cases still report a state that does not match the catalog. Full
sequences are in the attached file; in short:
- T = 0 with a live temp table, two ways: (a) BEGIN; SET LOCAL
ready_for_query_message = plain; CREATE TEMP TABLE; COMMIT -- the
pre-commit check runs while the setting is plain, and the assign hook
rechecks only when IsTransactionState(); (b) switching to rich via
ALTER SYSTEM + pg_reload_conf() -- the SIGHUP is handled between
statements, so the hook skips the check. A plain SET does recheck.
- H = 1 with no cursors, after a procedure that COMMITs inside a FOR
loop: HoldPinnedPortals() -> HoldPortal() increments the counter, but
that portal has no CURSOR_OPT_HOLD, so PortalDrop() never decrements.
- H = 0 with a WITH HOLD cursor still open, if another WITH HOLD cursor
errors while materializing at COMMIT: the failed portal already has a
holdStore, so PortalDrop() decrements for it although HoldPortal()
never counted it.
Three of these (the two T cases and the last H case) are false
negatives -- a pooler would read the session as clean while it still
has state -- so they seem worth closing before the indicators are
relied on.
Two more, not contradicting any claim:
- Rich costs nothing extra when a transaction touches no temp objects,
as you say (-S prepared: within noise). When every transaction does
touch a temp table, rich is ~13-15% slower (two runs, both CIs below
zero), from the pg_depend scan at each pre-commit. Might be worth a
note that the 'T' bookkeeping has a cost under temp-heavy workloads.
- 'l' advances outside a commit. A read-only SELECT after a checkpoint
moved 'l' forward; pg_waldump shows only FPI_FOR_HINT and
PRUNE_ON_ACCESS records (xid 0) in that range. RecordTransactionCommit()
sets XactLastCommitEnd from XactLastRecEnd even for an xid-less
transaction that wrote WAL, so 'l' is never behind the last commit
(fine for read-your-writes) but is not exactly "the last commit LSN"
the docs describe. This is master's behaviour, not v3's.
Attached: the exact reproductions, and the wire client updated to
decode 'l'.
Regards,
Manu
Edge cases in v3 rich mode (master 061065e28f + v3, --enable-cassert)
=====================================================================
Each case is a sequence of simple Query messages on ONE connection, run
with the raw client:
python3 rfq-wire-client.py script <sockdir> <port> '-c
ready_for_query_message=rich' -- 'sql1' 'sql2' ...
and the value shown is the key in the 'Z' that closes that statement.
No assertion failure and no crash in any of them.
1. 'T' is 0 while a temporary table exists (SET LOCAL)
------------------------------------------------------
BEGIN
SET LOCAL ready_for_query_message = plain
CREATE TEMP TABLE loc(a int)
COMMIT -> T=0 (expected 1)
SELECT 1 -> T=0
SELECT count(*) FROM pg_class
WHERE relname = 'loc' AND relpersistence = 't' -> 1
PreCommit_Namespace() runs while the setting is still plain, so it does not
call CheckSessionTempTables(). The setting goes back to rich during commit,
but assign_ready_for_query_message() only rechecks when IsTransactionState()
is true, and it is not at that point.
2. 'T' is 0 after the setting becomes rich through a reload
-----------------------------------------------------------
Connect WITHOUT the options parameter (the setting comes from the config):
CREATE TEMP TABLE rel(a int)
ALTER SYSTEM SET ready_for_query_message = rich
SELECT pg_reload_conf()
SELECT pg_sleep(0.5)
SHOW ready_for_query_message -> rich, T=0 (expected 1)
SELECT 1 -> T=0
The SIGHUP is processed between commands, outside a transaction, so the
assign hook skips the check. A plain SET does recheck, and gets T=1.
3. 'H' stays 1 after a procedure that commits inside a FOR loop
---------------------------------------------------------------
CREATE PROCEDURE p_loop() LANGUAGE plpgsql AS $$
DECLARE r record;
BEGIN FOR r IN SELECT g FROM generate_series(1, 3) g LOOP COMMIT; END LOOP;
END $$
CALL p_loop() -> H=1 (expected 0)
SELECT count(*) FROM pg_cursors -> 0, and H=1
SELECT 1 -> H=1, until CLOSE ALL or DISCARD
ALL
The COMMIT inside the loop goes through HoldPinnedPortals() -> HoldPortal(),
which increments active_with_hold_portal_count. That portal does not have
CURSOR_OPT_HOLD, so PortalDrop() never decrements it.
4. 'H' is 0 while a WITH HOLD cursor is open
--------------------------------------------
DECLARE alive CURSOR WITH HOLD FOR SELECT 42
BEGIN
DECLARE bad CURSOR WITH HOLD FOR SELECT 1 / (g - 3) FROM generate_series(1,
5) g
COMMIT -> ERROR: division by zero, H=0
(expected 1)
SELECT count(*) FROM pg_cursors WHERE name = 'alive' -> 1
SELECT 1 -> H=0
HoldPortal() increments the counter only after PersistHoldablePortal()
returns. Here that call fails, but the portal already has a holdStore, so
PortalDrop() decrements for it during cleanup: 1 -> 0 with 'alive' still open.
5. 'l' moves without a commit record
------------------------------------
On a cluster with data checksums (the initdb default):
CREATE TABLE hb AS SELECT g FROM generate_series(1, 20000) g
-> l = 0/019CDE98, equal to the end_lsn of its COMMIT
record (pg_walinspect)
CHECKPOINT (from another session)
SELECT count(*) FROM hb
-> l = 0/01A85E10
pg_waldump between those two positions shows 91 FPI_FOR_HINT and 88
PRUNE_ON_ACCESS records, all with tx: 0, written by that read-only SELECT.
RecordTransactionCommit() sets XactLastCommitEnd = XactLastRecEnd also for a
transaction without an xid that wrote WAL (xact.c, after the
!markXidCommitted branch). So 'l' is never lower than the last commit, but
it is not always "the last commit LSN" the docs describe. If 'l' is meant
for read-your-writes on a standby, the effect is waiting a bit longer, not
reading stale data.
What does match: right after a commit with an xid, 'l' equals the end_lsn of
that COMMIT record; a ROLLBACK and another session's commit leave it alone;
and with the WAL position moved above 32 bits (pg_resetwal -l), 'l' decodes
to AB/CD01FA50, equal to pg_current_wal_insert_lsn().
6. Cost of rich mode when every transaction touches a temporary table
---------------------------------------------------------------------
pgbench, 8 clients, 10 s per sample, 10 samples per variant, all variants
interleaved and rotated, builds without asserts, pinned to one CCX; two
independent runs. Workload file (one statement per transaction):
CREATE TEMP TABLE IF NOT EXISTS tt(a int);
SELECT count(*) FROM tt;
v3 plain vs v3 rich, this workload: run 1 -14.6% [95% CI -16.3..-13.3]
run 2 -13.0% [95% CI -15.4..-11.5]
Each of those commits sets XACT_FLAGS_ACCESSEDTEMPNAMESPACE, so in rich mode
PreCommit_Namespace() runs the pg_depend index scan on every commit. Without
temporary tables there is no measurable cost: pgbench -S -M prepared, v3
plain vs v3 rich, -0.4% [95% CI -3.1..+1.6] and -1.4% [95% CI -5.0..+2.1];
master vs v3 plain, +0.8% [95% CI -1.3..+3.5] and +0.9% [95% CI -2.6..+4.8].
7. Smaller observations
-----------------------
- Inside an explicit transaction, 'T' does not change until COMMIT:
BEGIN; CREATE TEMP TABLE t(a int) -> that 'Z' (status T) still has T=0.
- Any temporary object sets 'T', not only tables: CREATE TEMP VIEW -> T=1.
- With PGOPTIONS='-c ready_for_query_message=rich', libpq_pipeline fails 7
of 24, all "trace match": the new fe-trace.c output is correct (no
"mismatched message length" any more), but the expected trace files have
the plain 5-byte ReadyForQuery.
#!/usr/bin/env python3
"""Raw protocol v3 client (no libpq). It records the exact bytes of every
message the server sends, i.e. what is on the socket, with no dissector in
between.
rfq_wire_client.py capture <sockdir> <port> [options]
-> JSON with every server message for three phases: startup, a simple
Query 'SELECT 1', and an extended Parse/Bind/Execute/Sync 'SELECT 1'.
rfq_wire_client.py script <sockdir> <port> [options] -- 'sql1' 'sql2' ...
-> for each statement (sent as a simple Query), the 'Z' message that
closes it, raw and decoded, plus the first row and any error.
[options] is the value of the startup 'options' parameter,
e.g. '-c ready_for_query_message=rich'.
Connects over a Unix socket as user postgres and expects trust authentication.
"""
import json
import socket
import struct
import sys
class Conn:
def __init__(self, sockdir, port, options=None, user="postgres",
db="postgres"):
self.s = socket.socket(socket.AF_UNIX)
self.s.connect(f"{sockdir}/.s.PGSQL.{port}")
self.buf = b""
params = [b"user", user.encode(), b"database", db.encode()]
if options:
params += [b"options", options.encode()]
body = struct.pack("!I", 196608) + b"".join(p + b"\0" for p in params)
+ b"\0"
self.s.sendall(struct.pack("!I", len(body) + 4) + body)
def _read(self, n):
while len(self.buf) < n:
chunk = self.s.recv(65536)
if not chunk:
raise EOFError("server closed the connection")
self.buf += chunk
out, self.buf = self.buf[:n], self.buf[n:]
return out
def msg(self):
head = self._read(5)
typ, length = head[:1], struct.unpack("!I", head[1:])[0]
return typ, head + self._read(length - 4)
def until_z(self):
msgs = []
while True:
t, raw = self.msg()
msgs.append((t, raw))
if t == b"R" and struct.unpack("!I", raw[5:9])[0] != 0:
raise RuntimeError("server asks for authentication; use trust")
if t == b"Z":
return msgs
def send(self, typ, body):
self.s.sendall(typ + struct.pack("!I", len(body) + 4) + body)
def query(self, sql):
self.send(b"Q", sql.encode() + b"\0")
return self.until_z()
def extended(self, sql):
self.send(b"P", b"\0" + sql.encode() + b"\0" + struct.pack("!H", 0))
self.send(b"B", b"\0\0" + struct.pack("!HHH", 0, 0, 0))
self.send(b"E", b"\0" + struct.pack("!I", 0))
self.send(b"S", b"")
return self.until_z()
def decode_z(raw):
"""Raw 'Z' -> {len, status, kv: [(key, value)], unparsed}."""
length = struct.unpack("!I", raw[1:5])[0]
body = raw[5:]
out = {"len": length, "status": body[:1].decode(), "kv": []}
off = 1
while off < len(body):
klen = body[off]; off += 1
k = body[off:off + klen]; off += klen
if off >= len(body):
out["unparsed"] = body[off - klen - 1:].hex(); break
vlen = body[off]; off += 1
v = body[off:off + vlen]; off += vlen
out["kv"].append([k.decode(), decode_value(k, v)])
return out
def decode_value(key, v):
"""Values are text, except 'l' (v3): the last commit LSN as a uint64 in
network byte order. Shown as 'hi/lo' like pg_lsn::text, plus the raw hex.
Anything else that is not printable ASCII is shown as hex."""
if key == b"l":
if len(v) != 8:
return f"BAD-LENGTH:{len(v)}:{v.hex()}"
n = struct.unpack("!Q", v)[0]
return f"{n >> 32:X}/{n & 0xFFFFFFFF:08X} (0x{v.hex()})"
try:
s = v.decode("ascii")
if s.isprintable():
return s
except UnicodeDecodeError:
pass
return "0x" + v.hex()
def describe(t, raw):
d = {"type": t.decode(), "len": len(raw), "hex": raw.hex()}
if t == b"S":
k, v, _ = raw[5:].split(b"\0", 2)
d["param"] = [k.decode(), v.decode()]
if t == b"K":
d["note"] = "BackendKeyData: differs on every connection, ignore when
comparing"
if t == b"Z":
d["z"] = decode_z(raw)
return d
def main():
mode, sockdir, port = sys.argv[1], sys.argv[2], sys.argv[3]
rest = sys.argv[4:]
options = None
if rest and rest[0] != "--":
options = rest.pop(0)
c = Conn(sockdir, port, options)
if mode == "capture":
phases = {"startup": c.until_z(), "simple_select_1": c.query("SELECT
1"),
"extended_select_1": c.extended("SELECT 1")}
print(json.dumps({p: [describe(t, r) for t, r in m] for p, m in
phases.items()}, indent=1))
elif mode == "script":
sqls = rest[1:] if rest and rest[0] == "--" else rest
res = [{"sql": "(startup)", "z": decode_z(c.until_z()[-1][1])}]
for sql in sqls:
msgs = c.query(sql)
err = [r[5:].split(b"\0M")[1].split(b"\0")[0].decode() for t, r in
msgs if t == b"E"]
rows = [r for t, r in msgs if t == b"D"]
row = None
if rows:
r = rows[0]; n = struct.unpack("!H", r[5:7])[0]; off = 7; vals
= []
for _ in range(n):
vlen = struct.unpack("!i", r[off:off + 4])[0]; off += 4
vals.append(None if vlen < 0 else r[off:off +
vlen].decode()); off += max(vlen, 0)
row = vals
res.append({"sql": sql, "row": row, "error": err or None,
"z_hex": msgs[-1][1].hex(), "z": decode_z(msgs[-1][1])})
print(json.dumps(res, indent=1))
else:
sys.exit(__doc__)
if __name__ == "__main__":
main()
