A text search OOM-killed the whole tmux pane

· 10 min read
Contents

22:57:55: eight lines of Python start searching a scratch directory for one log line.

23:01:49: the kernel kills them. They hold 15.3 GiB of RAM and another 1.4 GiB of swap.

By 23:01:51, systemd has stopped everything else in that tmux pane: the interactive session, a context probe nearly four minutes into a 262k-token request, a go test -count=100.

All of it to find one log line.

The search, and what it walked into#

for root,ds,fs in os.walk('agent-work'):
    if 'review-cutting' in root or 'client-research' in root: continue
    for f in fs:
        p=os.path.join(root,f)
        try: t=open(p,errors='replace').read()
        except: continue
        for l in t.splitlines():
            if 'host a9: engine' in l and 'up after' in l: print(p, l[:200])

It was checking a single fact for a blog post: which log lines said when a GPU box's engine had come up. The command eight seconds before it had filtered by extension, .log .txt .out .err. This one didn't. It walked the whole scratch tree, which held, among the logs, a 2.7 GB GGUF model downloaded that evening for another job.

open(p, errors='replace') is the careful choice for files you aren't sure are text. It never raises on bytes that aren't UTF-8. On a model file it didn't raise either.

Why 2.7 GB doesn't stay 2.7 GB#

errors='replace' turns every invalid byte sequence into U+FFFD, the replacement character, and carries on. The bytes that do decode come along as whatever characters they spell. I decoded the first 64 MiB of the same model, inside a memory-capped scope this time, and counted:

chars 62,590,761  U+FFFD 22,946,748  above U+FFFF 9,851  max 0x10ff1e
bytes per char: 4.00
same length, ASCII only: 60 MiB vs 239 MiB

37 % of the characters are U+FFFD. The line that matters is the third count. Since PEP 393, CPython stores each string at one, two or four bytes per character, "depending on the character with the largest Unicode ordinal". Quantised weights are close enough to random bytes that some of them form valid four-byte UTF-8 sequences, characters above U+FFFF. Here 9,851 of them, 0.016 % of the string, set the width for the other 62.6 million. The string is four times the size it would be in ASCII, and 3.73 times the bytes it came from.

That is the string. The call in the search makes more than one of it. open(p, errors='replace') opens in text mode, and text mode's default is universal newlines: \r and \r\n are "translated into \n before being returned to the caller", as the open() docs put it. So read() holds the raw bytes, the decoded string and a translated copy of the string, all at once. The search's own two calls, open(p, errors='replace').read() and splitlines(), on three 64 MiB slices of the model, cut into files from the start, 1 GiB in and 2 GiB in, each run in a capped scope:

slice-at-0x64MiB.bin (UTF-8, 64 MiB): read() peak x8.46, after read() x3.73; after splitlines() x7.12
slice-at-16x64MiB.bin (UTF-8, 64 MiB): read() peak x8.58, after read() x3.79; after splitlines() x6.88
slice-at-32x64MiB.bin (UTF-8, 64 MiB): read() peak x8.60, after read() x3.80; after splitlines() x7.05

read() peaks at ×8.5 of the bytes it reads, then lets go of the bytes and the first string and returns the copy, ×3.8. splitlines() then splits on more than \n: \v, \f, \x1c to \x1e, \x85 and two Unicode separators all count (text mode has already turned every \r into \n), random bytes are full of them, and every line is a new string object, back up to ×7.

For the whole model, read() alone needed about 23.2 to 23.6 GB. The kernel's report, below, has the process at 23,275,612 kB of address space (kernel kB are KiB: 23.8 GB), which is about what the bytes, the string and the copy add up to, with 17.9 GB (16.7 GiB) of it in RAM or swap. The numbers fit a kill inside read(), with the translated copy about half filled in. splitlines() most likely never ran.

The kernel killed one process#

From the kernel log, hostname replaced:

2026-10-24T23:01:49+03:00 host kernel: Out of memory: Killed process 3071963 (python3) total-vm:23275612kB, anon-rss:16074688kB, file-rss:16kB, shmem-rss:0kB, UID:1000 pgtables:34408kB oom_score_adj:200

anon-rss:16074688kB is 15.33 GiB, and the process table in the same report puts another 363,200 pages, 1.39 GiB, in swap. The box has 31 GiB of RAM and 8 GiB of swap, and the report shows 244 kB of swap left. The same report marks it global_oom: no cgroup limit fired, the whole machine was out. The kernel picked the right process. The allocation that tipped it over came from a desktop accessibility daemon (at-spi2-registr invoked oom-killer), but the OOM killer picks by memory footprint, and the search was by far the biggest thing on the box.

If that were the end, one bad command would have died after dragging the box through a bout of swapping.

systemd stopped everything else#

From the user's systemd journal (hostname and address replaced):

2026-10-24T23:01:49+03:00 host llm-router-proxy[2967363]: 2026/10/24 23:01:49 POST /v1/chat/completions model="3090-ornith15-35b-256k" host=3090 status=200 bytes=0 dur=3m48.878s from=192.0.2.10 ua="Python-urllib/3.14"
2026-10-24T23:01:49+03:00 host systemd[1397]: tmux-spawn-49963594-2a6f-48ee-9d54-57494c9d5823.scope: The kernel OOM killer killed some processes in this unit.
[…]
2026-10-24T23:01:51+03:00 host systemd[1397]: tmux-spawn-49963594-2a6f-48ee-9d54-57494c9d5823.scope: Failed with result 'oom-kill'.
2026-10-24T23:01:51+03:00 host systemd[1397]: tmux-spawn-49963594-2a6f-48ee-9d54-57494c9d5823.scope: Consumed 1h 17min 17.504s CPU time over 23h 22min 44.904s wall clock time, 17.4G memory peak, 3.6G memory swap peak.

On this machine tmux 3.7c starts each pane in its own transient scope, tmux-spawn-<uuid>.scope, and a scope's OOMPolicy= defaults to stop. The systemd docs spell out what that means: "If set to stop the event is logged and the unit's processes are terminated cleanly by the service manager." Every process in the pane. The kernel had killed one; systemd finished the job for the rest.

The first line above is my LAN LLM proxy noticing that one of them had vanished. It was a context probe, a Python client sending a 262k-token prompt through the proxy to a GPU box, 3 minutes 48 seconds into the request. The proxy logged it as status 200 with 0 bytes when its client disappeared. The pane also had a go test -count=100 running, and the interactive session that had started all of them. Other panes were untouched; each has its own scope.

The search was the only process that had done anything wrong, and it was the one whose death cost nothing.

Searching a tree that holds binaries#

rg and grep -I both treat a file with NUL bytes in it as binary and skip it. On this machine plain rg has a second filter worth knowing about. A small test tree, with a 70-byte log, a 1 MiB binary with a NUL at byte 100, and a 20 MiB text file, each holding one matching line:

$ rg -n 'up after' tree
tree/models/big.txt:2:engine x up after 2s
$ rg -u -n 'up after' tree
tree/logs/proxy.log:1:2026/10/24 10:49:46 host 3090: engine mainline up after 8s
tree/models/big.txt:2:engine x up after 2s
$ grep -rIn 'up after' tree
tree/logs/proxy.log:1:2026/10/24 10:49:46 host 3090: engine mainline up after 8s
tree/models/big.txt:2:engine x up after 2s

Plain rg never found the log. It honours ignore files, and my global git excludes file lists *.log. rg -u turns ignore files off and still skips the binary; grep -rI never read ignore files in the first place.

In Python, the same rules fit in a short script: read bytes, cap the size, look for NUL in the first 8 KiB, and iterate the file instead of reading it:

import os
import sys


def search(top, needle, max_bytes=8 << 20):
    needle = needle.encode()
    for root, dirs, files in os.walk(top):
        for name in files:
            path = os.path.join(root, name)
            try:
                if os.path.getsize(path) > max_bytes:
                    continue  # model weights, core dumps, tarballs
                with open(path, "rb") as f:
                    if b"\0" in f.read(8192):
                        continue  # NUL byte: treat as binary, like rg and grep -I
                    f.seek(0)
                    for n, line in enumerate(f, 1):  # one line at a time
                        if needle in line:
                            text = line[:200].decode(errors="replace").rstrip()
                            print(f"{path}:{n}: {text}")
            except OSError:
                continue


if __name__ == "__main__":
    search(sys.argv[1], sys.argv[2])

On the test tree it prints the log line and nothing else; the 20 MiB file is over its cap, the binary fails the NUL test:

tree/logs/proxy.log:1: 2026/10/24 10:49:46 host 3090: engine mainline up after 8s

A scratch tree is exactly where the things that break naive searches end up: model weights, core dumps, compiled test binaries, tarballs. Searching "all of it" means searching those too, so scope the search to the directories that hold what you're looking for.

A tmux pane is not a sandbox#

A job that has to survive the next mistake in the same pane belongs in its own unit. systemd-run --user --scope puts a command in a scope of its own, and -p MemoryMax= gives that scope a limit the kernel enforces before the machine runs out. Every measurement in this post ran that way. To show what happens when the limit is hit, a script asks for 400 MiB inside 200 and then reports back:

systemd-run --user --scope --unit=oom-demo-2 -p MemoryMax=200M -p MemorySwapMax=0 \
    /usr/bin/python3 -I -c 'x = bytearray(400 * 2**20); print("allocated")'
echo "exit status $?"
echo "this shell is still here"

Running as unit: oom-demo-2.scope; invocation ID: 6814cad29d1b47dcae6f0d7979469e40
demo.sh: line 2: 3192783 Killed                     systemd-run --user --scope --unit=oom-demo-2 -p MemoryMax=200M -p MemorySwapMax=0 /usr/bin/python3 -I -c 'x = bytearray(400 * 2**20); print("allocated")'
exit status 137
this shell is still here

The journal:

2026-10-24T23:33:28+03:00 host systemd[1397]: oom-demo-2.scope: The kernel OOM killer killed some processes in this unit.
2026-10-24T23:33:28+03:00 host systemd[1397]: oom-demo-2.scope: Failed with result 'oom-kill'.
2026-10-24T23:33:28+03:00 host systemd[1397]: oom-demo-2.scope: Consumed 247ms CPU time over 251ms wall clock time, 200M memory peak.

Same Failed with result 'oom-kill' as the pane, but this time the kernel log says CONSTRAINT_MEMCG instead of global_oom: the scope's own 200M limit fired, at a 200M memory peak, and nothing outside the scope noticed. That is how the context probe and the go test loop were restarted after the pane went down, each as its own systemd-run service, at 23:07:50 and 23:09:23. Run the long job, a context probe, a benchmark, a test loop, in its own scope, and a neighbour's OOM kill no longer stops it. Run the risky one-off with a MemoryMax, and it can't take the machine there in the first place.

errors='replace' turns "this is not text" into "this is a lot of text".

Filed under: python, linux, systemd, memory, debugging

Sources#