Hi!
My colleagues found that a queries like that:
\timing
DROP TABLE IF EXISTS t;
CREATE TABLE t (
id int,
a int,
b int,
g text GENERATED ALWAYS AS (
lpad((CASE WHEN a <> 0 THEN a ELSE b END)::text, 10, '0') ||
lpad((CASE WHEN a <> 0 THEN a ELSE b END)::text, 10, '0') ||
lpad((CASE WHEN a <> 0 THEN a ELSE b END)::text, 10, '0') ||
lpad((CASE WHEN a <> 0 THEN a ELSE b END)::text, 10, '0') ||
lpad((CASE WHEN a <> 0 THEN a ELSE b END)::text, 10, '0') ||
lpad((CASE WHEN a <> 0 THEN a ELSE b END)::text, 10, '0') ||
lpad((CASE WHEN a <> 0 THEN a ELSE b END)::text, 10, '0') ||
lpad((CASE WHEN a <> 0 THEN a ELSE b END)::text, 10, '0') ||
lpad((CASE WHEN a <> 0 THEN a ELSE b END)::text, 10, '0') ||
lpad((CASE WHEN a <> 0 THEN a ELSE b END)::text, 10, '0')
) STORED
);
INSERT INTO t
SELECT 1, 100, 0
FROM generate_series(1, 1000000);
UPDATE t SET id = 2; -- < problem query
lead to excessive memory consumption up to 10Gb in this example and
query execution time up to ~1,5min.
Bisect shows that the problem appeared after commit 83ea6c540
(Virtual generated columns).
Before this commit the update query took only ~8s and the memory
consumption did not exceed 150Mb for this backend.
MemoryContextStats reports only a small amount of memory usage, while
malloc_stats() confirms large allocations outside PostgreSQL memory
contexts.
With help of massif tool i found repeated allocations originating from:
ExecInitGenerated
→ build_column_default
→ stringToNode
This indicates that generated expressions are reparsed multiple times,
once per row to be updated instead of being reused.
There is a problem call stack during UPDATE t SET id = 2;
execution: see attached bt.txt, please.
Before the above-mentioned commit, ExecInitGenerated() was effectively
invoked once per ResultRelInfo, so this behavior was not observable.
I would like to propose a fix that add a caching of the the parsed
expression trees (Node *) in ResultRelInfo, so that build_column_default()
and stringToNode() are executed at most once per attribute per query.
With this fix, the query execution time
and memory consumption return to normal:
postgres=# UPDATE t SET id = 2;
UPDATE 1000000
Time: 11522,621 ms (00:11,523)
A patch for this approach for current master is attached here.
Would be glad for any feedback.
Best regards,
--
Anton A. Melnikov
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company(gdb) bt full
#0 ExecInitGenerated (resultRelInfo=0x556c9d23fa48, estate=0x556c9d23f500,
cmdtype=CMD_UPDATE) at nodeModifyTable.c:488
expr = 0x66dea1c0
attgenerated = 115 's'
i = 3
rel = 0x7f6fca5024f8
tupdesc = 0x7f6fca502708
natts = 4
ri_GeneratedExprs = 0x556c9d2212a8
ri_NumGeneratedNeeded = 0
updatedCols = 0x556c9d11c258
oldContext = 0x556c9d23f400
#1 0x0000556c720bb1d9 in ExecComputeStoredGenerated
(resultRelInfo=0x556c9d23fa48, estate=0x556c9d23f500, slot=0x556c9d220948,
cmdtype=CMD_UPDATE) at nodeModifyTable.c:579
rel = 0x7f6fca5024f8
tupdesc = 0x7f6fca502708
natts = 4
econtext = 0x556c9d221198
ri_GeneratedExprs = 0x556c9d2209c0
oldContext = 0x7f6fca502708
values = 0x0
nulls = 0x0
#2 0x0000556c720c39ed in ExecUpdatePrepareSlot (resultRelInfo=0x556c9d23fa48,
slot=0x556c9d220948, estate=0x556c9d23f500) at nodeModifyTable.c:2181
resultRelationDesc = 0x7f6fca5024f8
#3 0x0000556c720c327e in ExecUpdateAct (context=0x7fff66dea550,
resultRelInfo=0x556c9d23fa48, tupleid=0x7fff66dea51a, oldtuple=0x0,
slot=0x556c9d220948, canSetTag=true, updateCxt=0x7fff66dea404) at
nodeModifyTable.c:2218
estate = 0x556c9d23f500
resultRelationDesc = 0x7f6fca5024f8
partition_constraint_failed = false
result = 2636255368
#4 0x0000556c720c0758 in ExecUpdate (context=0x7fff66dea550,
resultRelInfo=0x556c9d23fa48, tupleid=0x7fff66dea51a, oldtuple=0x0,
oldSlot=0x556c9d220838, slot=0x556c9d220948, canSetTag=true) at
nodeModifyTable.c:2560
lockedtid = {ip_blkid = {bi_hi = 0, bi_lo = 0}, ip_posid = 6}
estate = 0x556c9d23f500
resultRelationDesc = 0x7f6fca5024f8
updateCxt = {crossPartUpdate = false, updateIndexes = TU_None, lockmode
= LockTupleKeyShare}
result = 2636253512
#5 0x0000556c720bdcd7 in ExecModifyTable (pstate=0x556c9d23f838) at
nodeModifyTable.c:4727
node = 0x556c9d23f838
context = {mtstate = 0x556c9d23f838, epqstate = 0x556c9d23f920, estate
= 0x556c9d23f500, planSlot = 0x556c9d241358, tmfd = {ctid = {ip_blkid = {bi_hi
= 24, bi_lo = 0}, ip_posid = 0}, xmax = 2636379920, cmax = 21868, traversed =
226}, cpDeletedSlot = 0x0, cpUpdateReturningSlot = 0x7fff66dea5b0}
estate = 0x556c9d23f500
operation = CMD_UPDATE
resultRelInfo = 0x556c9d23fa48
subplanstate = 0x556c9d23fd28
slot = 0x556c9d220948
oldSlot = 0x556c9d220838
tuple_ctid = {ip_blkid = {bi_hi = 0, bi_lo = 0}, ip_posid = 6}
oldtupdata = {t_len = 8, t_self = {ip_blkid = {bi_hi = 0, bi_lo = 0},
ip_posid = 7328}, t_tableOid = 0, t_data = 0x0}
oldtuple = 0x0
tupleid = 0x7fff66dea51a
tuplock = false
#6 0x0000556c72078de2 in ExecProcNodeFirst (node=0x556c9d23f838) at
execProcnode.c:470
No locals.
#7 0x0000556c72070082 in ExecProcNode (node=0x556c9d23f838) at
../../../src/include/executor/executor.h:320
No locals.
#8 0x0000556c7206ad93 in ExecutePlan (queryDesc=0x556c9d2388d0,
operation=CMD_UPDATE, sendTuples=false, numberTuples=0,
direction=ForwardScanDirection, dest=0x556c9d242ab0) at execMain.c:1726
estate = 0x556c9d23f500
planstate = 0x556c9d23f838
use_parallel_mode = false
slot = 0x556c9d15e428
current_tuple_count = 0
#9 0x0000556c7206ac22 in standard_ExecutorRun (queryDesc=0x556c9d2388d0,
direction=ForwardScanDirection, count=0) at execMain.c:368
estate = 0x556c9d23f500
operation = CMD_UPDATE
dest = 0x556c9d242ab0
sendTuples = false
oldcontext = 0x556c9d2387d0
#10 0x0000556c7206aa7a in ExecutorRun (queryDesc=0x556c9d2388d0,
direction=ForwardScanDirection, count=0) at execMain.c:305
No locals.
#11 0x0000556c723bee23 in ProcessQuery (plan=0x556c9d241a88,
sourceText=0x556c9d11ad50 "UPDATE t SET id = 2;", params=0x0, queryEnv=0x0,
dest=0x556c9d242ab0, qc=0x7fff66dea9a8) at pquery.c:161
queryDesc = 0x556c9d2388d0
#12 0x0000556c723bde66 in PortalRunMulti (portal=0x556c9d1bd8b0,
isTopLevel=true, setHoldSnapshot=false, dest=0x556c9d242ab0,
altdest=0x556c9d242ab0, qc=0x7fff66dea9a8) at pquery.c:1268
pstmt = 0x556c9d241a88
stmtlist_item__state = {l = 0x556c9d242a60, i = 0}
active_snapshot_set = true
stmtlist_item = 0x556c9d242a78
#13 0x0000556c723bd4f3 in PortalRun (portal=0x556c9d1bd8b0,
count=9223372036854775807, isTopLevel=true, dest=0x556c9d242ab0,
altdest=0x556c9d242ab0, qc=0x7fff66dea9a8) at pquery.c:783
_save_exception_stack = 0x7fff66deab50
_save_context_stack = 0x0
_local_sigjmp_buf = {{__jmpbuf = {93924264249040, 5807493733627851093,
93924254207184, 140734919259808, 0, 0, 5807493733992755541,
413896871259795797}, __mask_was_saved = 0, __saved_mask = {__val =
{93924263862225, 5807493733990658389, 413896870674035029, 2416, 128,
19815728600, 0, 93924981216272, 93924980010064, 2635856208, 112,
93924980010064, 93924981222064, 140734919256288, 93924263927232,
140734919256288}}}}
_do_rethrow = false
result = false
nprocessed = 93924981222064
saveTopTransactionResourceOwner = 0x556c9d15aa38
saveTopTransactionContext = 0x556c9d1cfcd0
saveActivePortal = 0x0
saveResourceOwner = 0x556c9d15aa38
savePortalContext = 0x0
saveMemoryContext = 0x556c9d1cfcd0
#14 0x0000556c723b8216 in exec_simple_query (query_string=0x556c9d11ad50
"UPDATE t SET id = 2;") at postgres.c:1278
cmdtaglen = 6
snapshot_set = true
per_parsetree_context = 0x0
plantree_list = 0x556c9d242a60
parsetree = 0x556c9d11b8b8
commandTag = CMDTAG_UPDATE
qc = {commandTag = CMDTAG_UNKNOWN, nprocessed = 0}
querytree_list = 0x556c9d11c378
portal = 0x556c9d1bd8b0
receiver = 0x556c9d242ab0
format = 0
cmdtagname = 0x556c727b651a "UPDATE"
parsetree_item__state = {l = 0x556c9d11b8e8, i = 0}
dest = DestRemote
oldcontext = 0x556c9d1cfcd0
parsetree_list = 0x556c9d11b8e8
parsetree_item = 0x556c9d11b900
save_log_statement_stats = false
was_logged = false
use_implicit_block = false
msec_str = "\000\252\336f\377\177\000\000\065W`rlU\000\000
\252\336f\024\000\000\000P\255\021\235lU\000"
#15 0x0000556c723b7449 in PostgresMain (dbname=0x556c9d159058 "postgres",
username=0x556c9d159038 "postgres") at postgres.c:4810
query_string = 0x556c9d11ad50 "UPDATE t SET id = 2;"
firstchar = 81
input_message = {data = 0x556c9d11ad50 "UPDATE t SET id = 2;", len =
21, maxlen = 1024, cursor = 21}
local_sigjmp_buf = {{__jmpbuf = {93924264249040, 5807493733795623253,
93924254207184, 140734919259808, 0, 0, 5807493733604782421,
413896873920295253}, __mask_was_saved = 1, __saved_mask = {__val = {4194304,
93924979975808, 93924980289560, 140734919257056, 93924263926944,
140734919257136, 93924979975808, 93924979975808, 93924979975808,
140734919257088, 93924261123494, 0, 93924979975808, 140734919257136,
93924261236879, 71354625712}}}}
send_ready_for_query = false
idle_in_transaction_timeout_enabled = false
idle_session_timeout_enabled = false
#16 0x0000556c723af2e3 in BackendMain (startup_data=0x7fff66deacc8,
startup_data_len=24) at backend_startup.c:124
bsdata = 0x7fff66deacc8
#17 0x0000556c7228a1d9 in postmaster_child_launch (child_type=B_BACKEND,
child_slot=1, startup_data=0x7fff66deacc8, startup_data_len=24,
client_sock=0x7fff66dead28) at launch_backend.c:263
pid = 0
#18 0x0000556c72291482 in BackendStartup (client_sock=0x7fff66dead28) at
postmaster.c:3606
bn = 0x556c9d149e08
pid = 64
startup_data = {canAcceptConnections = CAC_OK, socket_created =
828192736536497, fork_started = 828192736536500}
cac = CAC_OK
#19 0x0000556c7228f399 in ServerLoop () at postmaster.c:1713
s = {sock = 9, raddr = {addr = {ss_family = 1, __ss_padding =
"\000\000\000\000\000\000Y\320z\326o\177\000\000`\256\336f", '\000' <repeats 12
times>,
"\377\377\377\377\000\000\000\000\356\310\347Y\000\000\000\000\250wF\327o\177\000\000\250\256\336f\377\177\000\000z\360\006\327o\177\000\000\000\256\336f\377\177\000\000\020\256\336f\377\177\000\000\361!I\327o\177\000\000\f\000\000\000\000\000\000\000\030\343\370\323o\177\000\000\001\000\000\000\000\000\000",
__ss_align = 0}, salen = 2}}
i = 0
now = 1774877531
last_lockfile_recheck_time = 1774877525
last_touch_time = 1774876384
events = {{pos = 2, events = 2, fd = 7, user_data = 0x0}, {pos = 0,
events = 0, fd = 1, user_data = 0x0}, {pos = -1, events = 0, fd = 1725869624,
user_data = 0x7f6fd671f4a8}, {pos = -687470336, events = 32623, fd = 32816,
user_data = 0xffffffffffffffb0}, {pos = 1725871776, events = 32767, fd = 0,
user_data = 0x0}, {pos = -696561324, events = 32623, fd = 32768, user_data =
0x7f6fd70890f8 <[email protected]>}, {pos = 1725870896, events = 32767, fd =
1909378256, user_data = 0x7fff66deb6a0}, {pos = 0, events = 0, fd = 0,
user_data = 0x7f6fd7497197 <_dl_fixup+215>}, {pos = 1, events = 0, fd = 0,
user_data = 0x1000}, {pos = -697174872, events = 32623, fd = 1725870672,
user_data = 0x7f6fd749ec3e <_dl_runtime_resolve_xsavec+126>}, {pos = 0, events
= 0, fd = 0, user_data = 0x7fff66deb2a0}, {pos = 1923292504, events = 21868, fd
= 2, user_data = 0x556c72a31d58 <BlockSig>}, {pos = 1725923456, events = 32767,
fd = 0, user_data = 0x0}, {pos = -696282847, events = 32623, fd = 1725869888,
user_data = 0x2ffff00001fa0}, {pos = 1919420112, events = 21868, fd = 2,
user_data = 0x71ceccd0}, {pos = -696568333, events = 32623, fd = -1659558320,
user_data = 0x7f6fd6907be0 <main_arena+96>}, {pos = 7, events = 0, fd =
-1660034546, user_data = 0x1000}, {pos = 99, events = 0, fd = -1660033016,
user_data = 0x1030}, {pos = 64, events = 0, fd = 257, user_data = 0x0}, {pos =
0, events = 0, fd = 0, user_data = 0x0}, {pos = 0, events = 0, fd = 0,
user_data = 0xffffffffffffffff}, {pos = -1, events = 4294967295, fd =
1935764781, user_data = 0x3737310a61746164}, {pos = 0, events = 0, fd = 0,
user_data = 0x7f6fd6907be0 <main_arena+96>}, {pos = 0, events = 0, fd = 2,
user_data = 0x0}, {pos = 0, events = 0, fd = 0, user_data = 0x0}, {pos = 0,
events = 0, fd = 0, user_data = 0x0}, {pos = 0, events = 0, fd = 0, user_data =
0x2}, {pos = 2, events = 0, fd = 16449785, user_data = 0x0}, {pos = 16646394,
events = 0, fd = 16711931, user_data = 0x0}, {pos = 0, events = 0, fd = 0,
user_data = 0x0}, {pos = 16, events = 0, fd = -1659594464, user_data =
0x556c9d153670}, {pos = -1659595456, events = 1, fd = 4, user_data = 0x2d0},
{pos = 784, events = 0, fd = -1701897728, user_data = 0x1400}, {pos =
1919420112, events = 21868, fd = 1725870448, user_data = 0x556c72621ad7
<wipe_mem+39>}, {pos = 2, events = 0, fd = 6, user_data = 0x0}, {pos = 0,
events = 0, fd = 0, user_data = 0x0}, {pos = 0, events = 0, fd = 0, user_data =
0x4}, {pos = -1659595280, events = 21868, fd = 1024, user_data = 0x0}, {pos =
-1659595456, events = 21868, fd = -1659595456, user_data = 0x7fff66deb190},
{pos = 1919090397, events = 21868, fd = -1659595456, user_data =
0x556c9d149540}, {pos = 1725870560, events = 32767, fd = 1919032236, user_data
= 0x400}, {pos = -1659599512, events = 21868, fd = 0, user_data =
0x556c72a4b2a0 <context_freelists+16>}, {pos = 1024, events = 0, fd =
-1659554192, user_data = 0x556c9d149540}, {pos = -1659595456, events = 21868,
fd = 1725870592, user_data = 0x7f6fd67adc5a <_IO_flush_all_lockp+554>}, {pos =
1725871776, events = 1, fd = -1659595456, user_data = 0x7f6fd67abfb0
<flush_cleanup>}, {pos = 0, events = 0, fd = 0, user_data = 0x7f6fd67adc5a
<_IO_flush_all_lockp+554>}, {pos = -1659595456, events = 1, fd = -1701897728,
user_data = 0x7f6fd67abfb0 <flush_cleanup>}, {pos = 0, events = 0, fd = 0,
user_data = 0x0}, {pos = 1725870896, events = 32767, fd = -1701897728,
user_data = 0x556c726806d0 <__libc_csu_init>}, {pos = 0, events = 0, fd = 0,
user_data = 0x7f6fd67fe00d <__libc_fork+285>}, {pos = 1725870944, events =
32767, fd = -1701897728, user_data = 0x7fff66deb6a0}, {pos = 1915264797, events
= 21868, fd = 4194304, user_data = 0x556c72621b51 <AllocSetDelete+97>}, {pos =
0, events = 0, fd = -696660285, user_data = 0x13726806d0}, {pos = 13, events =
21868, fd = 4194304, user_data = 0x556c725e4c18 <should_output_to_server+40>},
{pos = -1659604656, events = 21868, fd = 13, user_data = 0x1366deb330}, {pos =
13, events = 21868, fd = 1725870880, user_data = 0x556c725e4c18
<should_output_to_server+40>}, {pos = 1725870896, events = 32767, fd = 13,
user_data = 0x7fff66deb360}, {pos = 1918782979, events = 21868, fd =
1725870960, user_data = 0x556c9d14d2d8}, {pos = 1725870944, events = 32767, fd
= 1915273988, user_data = 0x0}, {pos = 13, events = 372808, fd = 1725871008,
user_data = 0x556c7228a0c0 <postmaster_child_launch+128>}, {pos = 1725871024,
events = 32767, fd = 1915285345, user_data = 0x1}, {pos = 2, events = 0, fd =
1725871072, user_data = 0x556c7228f1c0 <maybe_start_bgworkers+400>}, {pos =
-1659783720, events = 21868, fd = 1915285345, user_data = 0x556c9d11b000}, {pos
= 1923181696, events = 21868, fd = -1659783720, user_data = 0x556c72a16c80
<BackgroundWorkerList>}}
nevents = 1
#20 0x0000556c7228e0b5 in PostmasterMain (argc=3, argv=0x556c9d1125f0) at
postmaster.c:1403
opt = -1
status = 0
userDoption = 0x556c9d119ba0 "/usr/local/pgvan-master/data"
listen_addr_saved = true
output_config_variable = 0x0
#21 0x0000556c72114136 in main (argc=3, argv=0x556c9d1125f0) at main.c:231
do_check_root = true
dispatch_option = DISPATCH_POSTMASTER
From fc0e4763fd44c1e1571387c39b9cb5a0c8167730 Mon Sep 17 00:00:00 2001
From: "Anton A. Melnikov" <[email protected]>
Date: Fri, 27 Mar 2026 11:32:25 +0300
Subject: [PATCH] Avoid repeated parsing of generated column expressions.
After commit 83ea6c54, execution paths were introduced
where ExecInitGenerated() can be invoked per row
for the same ResultRelInfo during a single query.
Because the parsed expression trees are allocated
in es_query_cxt, each call results in additional
allocations that are not freed until query end.
Fix it by caching the parsed expression trees
(Node *) in ResultRelInfo,
ensuring that build_column_default() and stringToNode()
are executed only once per attribute per query
and subsequent calls reuse the cached parse trees.
This restores the old behavior where expression parsing
is done once per query and prevents unbounded memory growth.
---
src/backend/executor/execMain.c | 1 +
src/backend/executor/nodeModifyTable.c | 14 +++++++++++++-
src/include/nodes/execnodes.h | 3 +++
3 files changed, 17 insertions(+), 1 deletion(-)
diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index 58b84955c2b..b3d2304624e 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -1311,6 +1311,7 @@ InitResultRelInfo(ResultRelInfo *resultRelInfo,
resultRelInfo->ri_GenVirtualNotNullConstraintExprs = NULL;
resultRelInfo->ri_GeneratedExprsI = NULL;
resultRelInfo->ri_GeneratedExprsU = NULL;
+ resultRelInfo->ri_GeneratedExprsParsed = NULL;
resultRelInfo->ri_projectReturning = NULL;
resultRelInfo->ri_onConflictArbiterIndexes = NIL;
resultRelInfo->ri_onConflict = NULL;
diff --git a/src/backend/executor/nodeModifyTable.c b/src/backend/executor/nodeModifyTable.c
index 4cd5e262e0f..451a38bc7c9 100644
--- a/src/backend/executor/nodeModifyTable.c
+++ b/src/backend/executor/nodeModifyTable.c
@@ -485,7 +485,19 @@ ExecInitGenerated(ResultRelInfo *resultRelInfo,
Expr *expr;
/* Fetch the GENERATED AS expression tree */
- expr = (Expr *) build_column_default(rel, i + 1);
+ if (resultRelInfo->ri_GeneratedExprsParsed == NULL)
+ resultRelInfo->ri_GeneratedExprsParsed = palloc0(natts * sizeof(Node *));
+
+ if (resultRelInfo->ri_GeneratedExprsParsed[i] == NULL)
+ {
+ expr = (Expr *) build_column_default(rel, i + 1);
+ resultRelInfo->ri_GeneratedExprsParsed[i] = (Node *) expr;
+ }
+ else
+ {
+ expr = (Expr *) resultRelInfo->ri_GeneratedExprsParsed[i];
+ }
+
if (expr == NULL)
elog(ERROR, "no generation expression found for column number %d of table \"%s\"",
i + 1, RelationGetRelationName(rel));
diff --git a/src/include/nodes/execnodes.h b/src/include/nodes/execnodes.h
index 684e398f824..ca30137a308 100644
--- a/src/include/nodes/execnodes.h
+++ b/src/include/nodes/execnodes.h
@@ -582,6 +582,9 @@ typedef struct ResultRelInfo
int ri_NumGeneratedNeededI;
int ri_NumGeneratedNeededU;
+ /* Cached parsed GENERATED expressions */
+ Node **ri_GeneratedExprsParsed;
+
/* list of RETURNING expressions */
List *ri_returningList;
--
2.50.1
