48 小時故障筆記：每次 write() 均成功返回，close() 報 ENOSPC，記錄檔末筆遭截斷

48-Hour Field Notes: Every write() Returned, close() Raised ENOSPC, and My Ledger Ended Mid-Record

The boring loop that turned into a two-day investigation

For most of last week I ran a small harness: take a prompt, ask a model for a patch suggestion, apply it to a scratch checkout, and append one JSON line per attempt to a ledger file. I used MonkeyCode's free model access for the suggestions and its free server option for the scratch host, both of which were available to me during the window described here.

Disclosure: This article was prepared as part of MonkeyCode's product outreach.

I am not going to quote quotas, limits, or hardware for either of those, because I never measured them and I will not guess. What I can describe precisely is what the ledger did on a small scratch host, and why the first version of it told me a comfortable lie for about nineteen hours.

What the timeline actually looked like

• Hours 0–3. The loop worked. Each attempt appended one line, the file grew, and I watched df -h like a tourist.
• Hours 3–19. I stopped watching. Attempts kept "succeeding," because write() kept returning, and nothing in my code ever asked whether those bytes had reached the disk.
• Hour 19. A later process tried to read the ledger and crashed inside json.loads on the final line. The last record was cut in half, mid-string, with no trailing newline.
• Hours 19–24. I reproduced the failure on purpose by filling a tiny filesystem and rerunning the loop. The error surfaced at close(), not at write().
• Hours 24–48. I rebuilt the writer, added a headroom guard, and added a verifier that can tell me a log is short instead of pretending it is complete.

So which of those five time slices would you have spent debugging the wrong layer? I spent roughly four hours of hour 19 blaming my parser.

Why "No space left on device" arrived at close()

CPython's text-mode files are buffered, and the default buffer size is 8192 bytes. When you call write(), you have only copied bytes into a buffer inside your own process. The real write(2) syscall happens later, during a flush or a close, and that is where ENOSPC appears.

That gives you three very different failure points:

1. write() raises — the record was larger than the buffer, or the buffer was already full.
2. flush() raises — you can name the exact record that never landed.
3. close() raises — the process already believed everything was fine, and the last record on disk may be truncated.

One extra trap is worth knowing. Calling tell() on a text stream flushes the buffer in order to compute an accurate position. If you call tell() after every append, you move the error earlier and lose the clean attribution between "record 61 failed" and "the file was already broken before record 61."

Another nuance cost me time: on ext4, running out of inodes also reports ENOSPC, so "disk full" can mean "no more directory entries." My first version wrote one patch file and one log file per attempt, which is exactly the workload that hits that wall while df -h still shows gigabytes free.

Primary references I checked before writing this: the Python documentation for os.fsync and os.statvfs at docs.python.org, and the Linux manual pages for write(2) and fsync(2).

Step 1: Probe headroom in bytes and in inodes

Run this before the loop, not after it. Both numbers matter, and they fail independently.

mkdir -p /tmp/runs
df -h /tmp
df -i /tmp
findmnt -no SOURCE,FSTYPE,OPTIONS --target /tmp
python3 - <<'PY'
import json, os
st = os.statvfs("/tmp")
print(json.dumps({"free_bytes": st.f_bavail * st.f_frsize, "free_inodes": st.f_favail}))
PY

If your box is a container, treat that output as an optimistic upper bound rather than a promise. statvfs may be describing the underlying filesystem instead of the quota your process actually lives under.

Step 2: A ledger writer that refuses to lie

This is the second version of the writer I used after hour 24. It checks headroom before opening and before each record, flushes and fsyncs per record so a failure names the record, and counts bytes manually instead of calling tell().

#!/usr/bin/env python3
"""ledger.py - append-only JSONL writer for model-run records.

v2 of the writer from a 48-hour field-notes run:
- checks headroom before opening and before each record
- flush + fsync per record, so a failure can name the record
- never calls tell() on a text stream (that flushes and hides attribution)
"""
from __future__ import annotations

import errno
import json
import os
import time

MIN_FREE_BYTES = 64 * 1024 * 1024
MIN_FREE_INODES = 1000

HINTS = {
    errno.ENOSPC: "filesystem or quota is full (inodes count too)",
    errno.EDQUOT: "container or user quota exceeded",
    errno.EFBIG: "file size limit reached",
}


def headroom(path):
    st = os.statvfs(path)
    return {"free_bytes": st.f_bavail * st.f_frsize, "free_inodes": st.f_favail}


def assert_headroom(path, tag):
    h = headroom(path)
    if h["free_bytes"] < MIN_FREE_BYTES or h["free_inodes"] < MIN_FREE_INODES:
        raise SystemExit(f"[{tag}] refusing to write: {h}")


class Ledger:
    def __init__(self, path):
        self.path = path
        self.directory = os.path.dirname(os.path.abspath(path)) or "."
        assert_headroom(self.directory, "open")
        self.fh = open(path, "a", encoding="utf-8")
        self.seq = 0
        self.offset = os.path.getsize(path)

    def append(self, **record):
        self.seq += 1
        payload = {"seq": self.seq, "ts": time.time(), **record}
        line = json.dumps(payload, ensure_ascii=False) + '\n'
        blob = line.encode("utf-8")
        try:
            self.fh.write(line)
            self.fh.flush()
            os.fsync(self.fh.fileno())
        except OSError as exc:
            hint = HINTS.get(exc.errno, "unexpected")
            raise SystemExit(
                f"record {self.seq} failed at offset {self.offset}: "
                f"errno={exc.errno} ({hint})"
            ) from exc
        self.offset += len(blob)

    def close(self):
        self.fh.close()

Usage inside the harness is deliberately dull, because a ledger should never be the clever part of your pipeline:

lg = Ledger("/tmp/runs/ledger.jsonl")
for attempt, suggestion in enumerate(suggestions, start=1):
    lg.append(attempt=attempt, status="applied", bytes_out=len(suggestion))
lg.close()

Note the trade-off honestly: one fsync per record is not free, and I did not benchmark it for this article. Before you adopt it in a hot path, time a 10,000-append loop with and without the fsync call on your own filesystem and decide from your own numbers.

Step 3: A verifier that tells you the log is short

A writer that fails loudly is only half the defense. The other half is a checker that runs before your replay script trusts the file.

#!/usr/bin/env python3
"""verify_ledger.py - is this JSONL complete, or did it die mid-flush?"""
import json
import sys


def verify(path):
    with open(path, "rb") as fh:
        data = fh.read()
    if data and not data.endswith(b'\n'):
        print(f"INCOMPLETE: final record has no newline ({len(data)} bytes)")
        return 2
    count = 0
    for lineno, raw in enumerate(data.splitlines(), 1):
        try:
            rec = json.loads(raw)
        except json.JSONDecodeError as exc:
            print(f"line {lineno}: unparsable ({exc})")
            return 3
        if rec.get("seq") != lineno:
            print(f"line {lineno}: seq={rec.get('seq')} out of order")
            return 4
        count = lineno
    print(f"OK: {count} records, contiguous and newline-terminated")
    return 0


if __name__ == "__main__":
    sys.exit(verify(sys.argv[1]))

The distinct exit codes are the point. A wrapper can branch on 2 (truncated tail, discard the last record), 3 (corruption, stop), or 4 (ordering broken, stop) instead of guessing from a stack trace.

How I reproduced the failure on purpose

Waiting for a real box to fill up is not a test plan. On a machine where loopback mounts are allowed, I made a tiny filesystem and filled it deliberately:

dd if=/dev/zero of=/tmp/small.img bs=1M count=8
mkfs.ext4 -q /tmp/small.img
sudo mkdir -p /mnt/tiny && sudo mount -o loop /tmp/small.img /mnt/tiny
python3 -c 'open("/mnt/tiny/fill", "wb").write(b"x" * (9 * 1024 * 1024))' || true
python3 verify_ledger.py /tmp/runs/ledger.jsonl

If you cannot use loopback mounts, a container with a small writable layer or a deliberately low quota gives you the same classroom. The lesson is identical either way: you want to watch the truncation happen once, on purpose, before it happens to a run you cared about.

The decision table I now use

Limitations, and who should not use this

• os.statvfs may report the host filesystem rather than your container quota, so the guard is an optimistic bound and not a discovery mechanism.
• The only ground truth is an errno from a real write or fsync. The guard reduces damage; it does not tell you what your true ceiling is.
• Per-record fsync costs latency, and I have not benchmarked it here. On network filesystems it can be much worse than on local disk, so batch and verify at the end instead.
• If you already ship logs to a managed collector, or you emit thousands of records per second, skip this entirely. A real log shipper beats a hand-rolled ledger on every axis.
• Do not use any of this to justify a scratch host that is simply too small for your workload. The guard is a smoke detector, not a bigger house.

What I would repeat, and what I would not

I would repeat counting bytes myself instead of calling tell(), writing the verifier on day one rather than day two, and rehearsing the failure on a throwaway filesystem before trusting the happy path. I would not repeat writing one file per attempt on a small box, and I would not repeat watching df -h while ignoring df -i.

Field notes are only useful if they change a habit, so here is mine: the ledger is now allowed to refuse work, and the verifier is allowed to veto a replay. If you have a scratch-host story where the errno and the error message disagreed, I would like to compare notes, especially about which failure your box reports first when the free space runs out.