fix(code-runtime-python): bill a merged open entry incrementally on both sides

The review's critical: the open-merge branch re-joined and re-walked the whole
held text per frame, so k tiny open frames cost O(k * budget) (thousands of
1-byte frames against a near-64 MiB budget would re-traverse hundreds of GB and
block the host event loop). The host now holds a fragment ARRAY with an
incrementally billed cost — each fragment's jsonStringCostUpTo walks only its
own text — and the closing frame bills only its own content, so the merged
entry's wire cost is charged exactly once, split across the fragments. The
child bills symmetrically: the first open fragment pays quotes+separator, each
continuation pays only its content, matching the host ledger (the review's
warning: per-fragment full billing truncated a 16-char merged entry under
maxLogBytes: 64 that costs only 19 bytes as one entry).

Regression cases: 16 single-character flushes merge to one whole entry; a
closing frame that overflows the remaining budget truncates to the marker; a
closing frame after an open flood already truncated the ledger is a no-op; and
a forged open-frame flood stays bounded by the ledger. The closing-frame
post-truncation guard is an invariant-false branch (an open frame that would
trip the ledger resets openParts, so a non-empty hold implies no truncation)
and carries a v8 ignore with that reason.
This commit is contained in:
Chinesezjc
2026-08-31 15:03:20 +08:00
committed by Tianyi Cui
parent ea1d28a068
commit 4fd0068fb7
3 changed files with 131 additions and 21 deletions
@@ -117,6 +117,12 @@ class LogBuffer:
# configured value for the marker's message text).
self._remaining = max_bytes - 1
self._truncated = False
# True while an `open` (unterminated-flush) entry is being accumulated:
# continuation fragments bill only their CONTENT (no quotes — they ride
# on the first fragment — and no separator), so a merged entry's wire
# cost is billed exactly once, split across its fragments, matching the
# host ledger.
self._open_started = False
# Re-entrant so a caller may hold it across a compound read-modify-write
# (``_LogStream.write`` reads ``remaining`` several times and then calls
# ``push`` while still holding it). One lock is shared by this buffer and
@@ -161,7 +167,7 @@ class LogBuffer:
# above the budget truncates without ever encoding it — the full encode
# would allocate a second equally large string and could turn a
# truncatable log into an RLIMIT_AS death.
if len(text) + 3 > self._remaining:
if (len(text) + 3 if not open or not self._open_started else len(text) + 1) > self._remaining:
self._truncated = True
self._sink(log_truncation_marker(self._max_bytes), truncated=True)
return
@@ -187,12 +193,25 @@ class LogBuffer:
# instead of emitting the truncation marker. The +1 also floors an empty
# entry above zero, so a flood of blank ``print()`` lines exhausts the
# budget instead of emitting unbounded zero-cost log frames.
cost = _json_string_cost(raw) + 1
# Split billing for an `open` entry: the first fragment pays the full
# JSON-string cost plus the separator; each continuation pays only its
# content (the quotes and the separator were billed on the first
# fragment). A closed entry pays the full cost as before.
if open and self._open_started:
cost = _json_string_cost(raw) - 2
if cost < 0:
cost = 0
else:
cost = _json_string_cost(raw) + 1
if cost > self._remaining:
self._truncated = True
self._sink(log_truncation_marker(self._max_bytes), truncated=True)
return
self._remaining -= cost
if open:
self._open_started = True
else:
self._open_started = False
self._sink(text, open=open)
@@ -1026,9 +1026,13 @@ export class PythonCodeRuntime extends CodeRuntime {
let settled = false
const logs: string[] = []
// An unterminated line flushed with the `open` flag: the next log frame
// appends to it (no fake newline between entries), and finish() admits
// the residual if the run ends with it still open.
let openLog: string | undefined
// appends to it (no fake newline between entries), and finish() pushes
// the residual if the run ends with it still open. Held as a fragment
// ARRAY with an incrementally billed content cost, so k tiny open frames
// cost O(k) — re-joining and re-walking the whole held text per frame
// would be O(k * budget) (jsonStringCostUpTo re-walks from the start).
let openParts: string[] = []
let openCost = 0
// One host-side ledger covers normal frames, forged frames, and stray stdout bytes.
// The ledger starts one byte below maxLogBytes: each entry is charged its
@@ -1504,27 +1508,55 @@ export class PythonCodeRuntime extends CodeRuntime {
// An explicit flush of an unterminated line: hold it so the next
// frame appends to the SAME entry (print('a', end='', flush=True)
// followed by print('b') reads back as one 'ab' entry, not a fake
// newline). The held fragment is BOUNDED by the ledger budget via
// the exact-cost walk (a forged open flood would otherwise grow
// openLog without touching logBudget — the same unbounded-retention
// attack the ledger exists to stop). The cost is NOT billed here:
// the closing frame's admit() bills the whole merged entry once.
// newline). Billed INCREMENTALLY so k tiny frames cost O(k), not
// O(k * budget) (re-walking the whole held text per frame): the
// first fragment is charged the full JSON-string cost plus the
// separator (quotes + content + newline), each continuation only
// its content (jsonStringCostUpTo includes the two quotes), and
// the closing frame only its own content — the merged entry's
// wire cost is billed exactly once, split across the fragments.
if (!logsTruncated) {
const merged = (openLog ?? '') + message.text
if (jsonStringCostUpTo(merged, logBudget - 1) === undefined) {
const cost = jsonStringCostUpTo(message.text, logBudget - openCost)
if (cost === undefined) {
logsTruncated = true
logs.push(logTruncationMarker(this.config.maxLogBytes))
clearStray(strayOut)
clearStray(strayErr)
openLog = undefined
openParts = []
openCost = 0
} else {
openLog = merged
const bill = openParts.length === 0 ? cost + 1 : Math.max(cost - 2, 0)
logBudget -= bill
openParts.push(message.text)
openCost += bill
}
}
return
}
admit((openLog ?? '') + message.text)
openLog = undefined
if (openParts.length > 0) {
// Closing frame: the held fragments are already billed; bill only
// this frame's own content (the quotes and separator ride on the
// first fragment) and push the merged entry once.
/* v8 ignore next -- logsTruncated is an invariant false here: an open
* frame that would trip the ledger resets openParts, so a non-empty
* hold implies the ledger never truncated. The guard is defensive. */
if (!logsTruncated) {
const cost = jsonStringCostUpTo(message.text, logBudget - openCost)
if (cost === undefined) {
logsTruncated = true
logs.push(logTruncationMarker(this.config.maxLogBytes))
clearStray(strayOut)
clearStray(strayErr)
} else {
logBudget -= Math.max(cost - 2, 0)
logs.push(openParts.join('') + message.text)
}
}
openParts = []
openCost = 0
return
}
admit(message.text)
return
case 'done': {
if (message.error) {
@@ -1904,12 +1936,13 @@ export class PythonCodeRuntime extends CodeRuntime {
// A spawn failure (ENOENT, EACCES) never produced a pid, so there is no
// process to kill: settle now. Its `close` still fires later and reaches
// the idempotent settle() again as a no-op.
// An unterminated flushed line never got a closing frame; admit it so
// the committed flush is not lost from logs.
if (openLog !== undefined) {
admit(openLog)
openLog = undefined
// An unterminated flushed line never got a closing frame; it was
// billed incrementally, so push it directly (admit would re-bill).
if (openParts.length > 0 && !logsTruncated) {
logs.push(openParts.join(''))
}
openParts = []
openCost = 0
if (child.pid === undefined) {
settle(result)
return
@@ -1898,6 +1898,64 @@ describe('PythonCodeRuntime — programs and bindings', () => {
expect(result.logs).toEqual([logTruncationMarker(64)])
}, 15_000)
it('no-ops a closing frame once an open flood already truncated the ledger', async () => {
// The closing-frame branch's post-truncation arm: an open flood exhausts
// the ledger (logsTruncated set, marker pushed), then a closing frame
// arrives — it must be a no-op, not append content past the marker.
const { runtime } = await setup({ maxLogBytes: 64 })
const result = await runtime.run({
program: [
'import os',
'for _ in range(2000):',
" os.write(3, b'{\"type\":\"log\",\"text\":\"a\",\"open\":true}\\n')",
"os.write(3, b'{\"type\":\"log\",\"text\":\"b\"}\\n')",
'return "done"',
].join('\n'),
bindings: [],
})
expect(result.error).toBeUndefined()
expect(result.logs).toEqual([logTruncationMarker(64)])
}, 15_000)
it('bills a merged open entry once, not per fragment', async () => {
// A merged entry's wire cost is billed ONCE, split across its fragments
// (first fragment pays quotes+separator, continuations pay only content).
// Under maxLogBytes: 64, 16 single-character flushes merge to one 16-char
// entry (2 quotes + 16 content + 1 separator = 19), which fits; per-
// fragment billing (each charged quotes+separator, ~4 bytes) would truncate
// at 16 x 4 = 64.
const { runtime } = await setup({ maxLogBytes: 64 })
const result = await runtime.run({
program: [
'for _ in range(16):',
" print('x', end='', flush=True)",
"print('')",
'return "done"',
].join('\n'),
bindings: [],
})
expect(result.error).toBeUndefined()
expect(result.logs).toEqual(['x'.repeat(16)])
}, 15_000)
it('truncates when the closing frame of a merged entry overflows the budget', async () => {
// The merged entry's billed-once cost: an open fragment that nearly
// exhausts the budget, then a closing frame whose content no longer fits —
// the closing frame's exact-cost walk trips and the marker replaces the
// entry, exactly like any other over-budget log traffic.
const { runtime } = await setup({ maxLogBytes: 64 })
const result = await runtime.run({
program: [
"print('x' * 40, end='', flush=True)",
"print('y' * 40)",
'return "done"',
].join('\n'),
bindings: [],
})
expect(result.error).toBeUndefined()
expect(result.logs).toEqual([logTruncationMarker(64)])
}, 15_000)
it('keeps a float completion exact when the program mutates the decimal context', async () => {
// The float encoder's Decimal(repr(value)).normalize() used the process
// GLOBAL decimal context: a legitimate program setting