The Service Was Running for 48 Hours. Python Never Flushed a Single Line.

Have you ever watched a free-tier process look completely dead while CPU and memory said it was fine? I did that last week, and I wasted two days chasing a crash that never existed at all. The service accepted health requests, the process stayed up, and the log stream stayed completely blank. I assumed the platform swallowed stdout, which was a convenient story and also the wrong one.

This is a 48-hour field notebook, not a postmortem with fake dashboards. I reproduced the silence on my laptop first, then on a headless box, and I wrote down every wrong turn. If you ship Python behind systemd, Docker, or a pipe, you already own this bug. The process was never frozen. It was just too polite to flush.

Hour 0–6: I blamed the host, because empty logs feel like a platform bug

The first symptom was embarrassingly boring, which is how these stories usually start for me. I started a tiny worker, hit it with curl, and waited for the startup banner I had printed in main. Locally, in an interactive shell, the banner showed up before the first request even landed. On the remote box, the process list looked healthy and the port was open, but the log tail never moved.

Have you noticed how quickly we invent a networking story when a log file stays at zero bytes? I checked security groups, then reverse proxies, then whether the platform rotated files behind my back. I even restarted the process with a louder banner, as if volume could beat a buffer. Nothing new appeared until I killed the worker, and then five hundred lines arrived in one insulting burst.

That burst was the first honest clue. A crash dump would have been messy. A blocked input() would have sat forever, which I have already burned time on in a different notebook. This was a delayed write. The bytes existed. They were sitting in user space, waiting for a full buffer or a process exit.

Hour 6–24: I asked a model for help, and it handed me more print() calls

I pasted the empty-log symptom into a coding assistant and asked why a running worker would stay mute. Disclosure: This article was prepared as part of MonkeyCode's product outreach. I used MonkeyCode's free model access to iterate on a tiny diagnostic script, and I ran the same script on the free server option because I needed a non-TTY host that I did not have to keep open in my terminal.

The model did what most models do when they see print and “no output”: it added more prints. It suggested emojis, timestamps, and a second banner after the import block. It never asked whether stdout was attached to a terminal. Why would it? The snippet I pasted ran fine in a REPL, and a REPL is a TTY.

Here is the first draft it effectively pushed me toward, cleaned up so you can run it:

# buffer_lab.py — labeled reproduction, not production code
import os
import sys
import time
from datetime import datetime, timezone


def stamp(msg: str) -> None:
    now = datetime.now(timezone.utc).isoformat()
    # This looks like a log line. It is still just stdout.
    print(f"{now} pid={os.getpid()} tty={sys.stdout.isatty()} {msg}")


def main() -> None:
    stamp("worker boot")
    for i in range(5):
        stamp(f"tick {i}")
        time.sleep(1)
    stamp("worker exit")


if __name__ == "__main__":
    main()

Run it in your own terminal and you will feel productive, because the lines appear every second. Then run the same file through a pipe and watch the story change:

python3 buffer_lab.py
python3 buffer_lab.py | cat
python3 buffer_lab.py > /tmp/buffer_lab.log
# leave this running in another shell, then:
tail -f /tmp/buffer_lab.log

Did the redirected run look dead to you too? On CPython, interactive stdout is line-buffered, and a pipe or file is block-buffered. The sys.stdout docs and the PYTHONUNBUFFERED notes still describe that split in 2026. My remote process was not a terminal. It was a pipe into a collector, which is the default shape of almost every free server.

Hour 24–36: three “fixes” that made the silence louder

I kept a list of patches that felt serious and did nothing useful. If you are about to paste one of these into a Dockerfile, stop and run the pipe test first.

1. Extra print calls after imports. More bytes in the same block buffer still wait for the same 8 KiB fill or exit.
2. logging.basicConfig() at module import time, after a framework had already created handlers. The config was ignored, so I “proved” logging was broken.
3. tee in the start script without -u or stdbuf. I copied the stream and copied the buffer along with it.

The logging variant deserves its own snippet, because it is the one I almost shipped:

# labeled anti-pattern: configuring logging too late
import logging
from fastapi import FastAPI  # uvicorn may already have configured logging

app = FastAPI()
logging.basicConfig(level=logging.INFO)  # often a no-op here

@app.get("/health")
def health():
    logging.info("health ok")  # goes nowhere useful if root already has handlers
    return {"ok": True}

Have you ever seen basicConfig succeed locally and vanish under a process manager? Uvicorn, Gunicorn, and many test runners attach handlers before your app module finishes importing. basicConfig refuses to fight them unless you pass force=True on Python 3.8+, and even then you may be fighting the platform’s journal. Prints and logs are different tools. I had been using the weaker one in the worse environment.

The artifact: a 12-minute buffering lab you can rerun

I wanted a check I could trust before I blamed another host. This is the whole lab. It is deliberately small, and every command is meant to fail in a visible way when buffering is still on.

Decision table

• Interactive TTY (python3 buffer_lab.py): line-buffered stdout, ticks appear about once per second, sys.stdout.isatty() is True.
• Pipe (python3 buffer_lab.py | cat): block-buffered stdout, ticks often arrive as one burst, isatty() is False.
• File redirect (> app.log): block-buffered, tail -f stays quiet until flush or exit.
• systemd / Docker / free server collector: almost never a TTY, so you get the pipe behavior even when the dashboard says “logs attached”.
• stderr: often unbuffered or line-buffered even when stdout is not; do not assume, measure with isatty() on sys.stderr too.

Commands I would run again tomorrow

# 1. Prove the split on your laptop before you SSH anywhere.
python3 buffer_lab.py | cat

# 2. Force unbuffered stdio the way CPython documents it.
PYTHONUNBUFFERED=1 python3 buffer_lab.py | cat
python3 -u buffer_lab.py | cat

# 3. Confirm the process sees no TTY, the same way a service manager sees it.
python3 -c "import sys; print('out', sys.stdout.isatty()); print('err', sys.stderr.isatty())" | cat

# 4. If you must keep print(), flush on every line and say so in code review.
python3 - <<'PY' | cat
import time, sys
for i in range(5):
    print(f"tick {i}", flush=True)
    time.sleep(1)
PY

The logging shape I actually kept

# labeled example: send operational lines to stderr, explicitly
import logging
import sys

def configure_logging() -> None:
    handler = logging.StreamHandler(sys.stderr)
    handler.setFormatter(
        logging.Formatter("%(asctime)s %(levelname)s %(name)s %(message)s")
    )
    root = logging.getLogger()
    root.handlers.clear()
    root.addHandler(handler)
    root.setLevel(logging.INFO)

configure_logging()
log = logging.getLogger("worker")
log.info("worker boot tty=%s", sys.stderr.isatty())

In a unit of process wrapping, I also set the environment rather than hoping the shebang would remember:

# labeled snippet, not a full image
ENV PYTHONUNBUFFERED=1
CMD ["python", "-u", "buffer_lab.py"]

# systemd fragment
[Service]
Environment=PYTHONUNBUFFERED=1
StandardOutput=journal
StandardError=journal
ExecStart=/usr/bin/python3 -u /opt/app/buffer_lab.py

Would I still use print for a boot banner? Only with flush=True, and only until the logging handler is proven in a pipe. After that, stdout is for data. Stderr is for humans and collectors.

Hour 36–48: what actually broke, and what only looked broken

Three things were broken, and only one of them was Python.

The first was my mental model of “live logs.” I treated a blank tail as evidence of a dead process, which is reasonable on a TTY and reckless behind a collector. The second was the assistant loop: I kept feeding it TTY-local snippets, so it kept solving a TTY-local problem. The third was the start command on the free server, which wrapped Python in a pipe and never exported PYTHONUNBUFFERED.

What was not broken? The worker itself. Requests were served. The health endpoint was honest. The “missing” banner was sitting in an 8 KiB buffer, exactly where the runtime said it would sit. When I finally sent SIGTERM, the buffer flushed on shutdown and I got a perfect history of a process that had been healthy the entire time. That is a cruel kind of success.

I also learned to separate two silences I keep mixing up. A process waiting on stdin is blocked on a read you will never satisfy. A process buffering stdout is blocked on a write you already made. strace makes the difference obvious if you are willing to look: one sits in read(0, ...), the other cheerfully writes to a kernel buffer you are not tailing yet. Different syscalls, same empty pane in the browser.

What I would repeat

• Reproduce with | cat on the laptop before I accuse the host of dropping logs.
• Print sys.stdout.isatty() and sys.stderr.isatty() on boot, every time, in the first real log line.
• Prefer PYTHONUNBUFFERED=1 plus a StreamHandler(sys.stderr) over a pile of emergency print calls.
• Paste non-TTY evidence into the assistant, not just the happy local transcript.
• Kill the process once on purpose and watch for a burst; a burst means I have a buffer, not a crash.

Would I repeat the two days of host archaeology? No. That was me avoiding a five-line lab because the dashboard looked more official than isatty().

Limitations, and who should not copy this

This notebook is about CPython text IO and process managers that steal your TTY. It is not a logging platform, and it is not a performance study. I did not measure throughput, I did not name cloud SKUs, and I did not pretend -u is free at millions of lines per second.

Skip this approach if you already run structured logs through systemd-journald, Fluent Bit, or an OpenTelemetry SDK with an explicit exporter. Those pipelines still need a process that writes, but they do not want a random print flushed into mixed stdout. Skip it on Windows services unless you rerun the lab there; my commands assume a POSIX shell. Skip it if your “logs” are actually request bodies on stdout, because unbuffering a data stream can change framing for whatever reads the pipe.

Also skip the “just add force=True” reflex in a library. Forcing the root logger can mute a framework you still need. Application entrypoints may do it. Imported helpers should not.

Field notes I am willing to keep

Empty logs are a UX problem before they are a runtime problem, and assistants will happily decorate the wrong stream. A free model is useful when you give it the pipe transcript and the isatty() line, not when you only give it the TTY success. A free server is useful when you treat it as a non-TTY fixture, not as a mysterious log sink.

If you run the lab and your redirected ticks still appear instantly, write down your Python version and your wrapper, because something else is already flushing for you. If they appear only on exit, you just met the same 48 hours I did, compressed into twelve minutes. That is the version I would repeat.