DEV Community

Taylor Wang
Taylor Wang

Posted on

I Watched Empty Logs for 48 Hours. The Pipe Was Holding Every Print.

Have you ever tailed a remote job through an entire afternoon, waiting for a print that never arrived? I did that for 48 hours, and I blamed the network, the agent, and the box before I blamed Python. The script was not hanging in the way I first assumed during those long quiet reruns. It was writing into a block buffer that nobody flushed until exit, a full buffer, or a hard kill.

This writeup is a set of field notes, not a claim that a production fleet was on fire. I am going to show what I tried, what actually broke, and the reproduction I now run first. Keep the notes cruelly specific, because empty logs invite the same three wrong stories every time.

The question I should have asked first

Was the process attached to a real terminal, or was stdout a pipe that Python treats as block-buffered? That single question would have saved me a messy stretch of reruns, patches, and false kills. My laptop printed every heartbeat because a terminal is line-buffered for ordinary text stdout in CPython. The remote job looked dead because a pipe is block-buffered, and my heartbeat prints were tiny.

I kept asking the wrong follow-up question, which still embarrasses me when I reread those notes. If the logs are empty, is the code wrong, or is the file descriptor quietly lying to you? Those two questions look similar in a chat thread, and they are not similar at all.

What I tried during the 48 hours

I did the usual panicky loop, and none of it was completely stupid on its face. It was aimed at the wrong layer, which is how you burn 48 hours with a straight face. Here is the short list, copied out of the notebook with only a light cleanup pass.

  1. I reran the job with extra print("checkpoint") calls, then waited, then added still more prints.
  2. I asked a coding agent to add logging, and it sprinkled print across six functions without flush=True.
  3. I checked whether the remote working directory existed, because empty output also looks like a cwd miss.
  4. I compared python -c "import sys; print(sys.executable)" on both machines, which never explained the silence.
  5. I tailed the platform log stream, assumed the runner had stalled, and killed processes that were still healthy.

Would you have jumped to buffering on hour one, before touching the application code again? I would like to say yes, and I did not. The agent was decent at generating diffs and terrible at noticing that every new print still landed in the same buffered pipe. More code was not more signal in that situation. It was a larger buffer repeating the same lie.

What actually broke

Python's text stdout is line-buffered when it is a TTY, and block-buffered when it is not. That is documented interpreter behavior, not a mysterious remote-server bug hiding in the scheduler. stderr is usually unbuffered, which is why my exceptions sometimes appeared while the alive-checks stayed invisible. A process can be healthy, compute for minutes, and still look dead if you only watch stdout.

I also mixed two different empty-log stories, which made the notebook worse instead of sharper:

  • The process had not started, so there was truly nothing on the file descriptor.
  • The process had started, and print had written bytes that the buffer still held.

Those two failures demand opposite moves, and I treated them as the same ghost. One needs a launch receipt that does not depend on a later print. The other needs an explicit flush policy before anybody adds more logging.

A reproduction you can run locally

I now keep a tiny script that makes the lie obvious on any laptop. Treat this as a labeled local reproduction, not as a production incident report with fake timestamps.

# save as heartbeat.py — unlabeled sleep is the point
import sys
import time

def main() -> None:
    print("start tty=", sys.stdout.isatty())
    for i in range(5):
        print(f"heartbeat {i}")
        time.sleep(2)
    print("done")

if __name__ == "__main__":
    main()
Enter fullscreen mode Exit fullscreen mode

Run it three ways and write the wall-clock behavior into the notes, not into chat.

# 1) real TTY: each heartbeat should appear after about two seconds
python heartbeat.py

# 2) piped stdout: many CPython builds hold the lines until exit or a full buffer
python heartbeat.py | cat

# 3) captured the way a runner or an agent tool often captures output
python heartbeat.py > /tmp/heartbeat.log
sleep 6
wc -c /tmp/heartbeat.log
cat /tmp/heartbeat.log
Enter fullscreen mode Exit fullscreen mode

Then force the policy you actually want, before you change product code.

python -u heartbeat.py | cat
PYTHONUNBUFFERED=1 python heartbeat.py | cat
Enter fullscreen mode Exit fullscreen mode

And the code-level version, which I prefer inside long jobs that must stay readable:

print(f"heartbeat {i}", flush=True)
# or once at process start, after you confirm you are on a recent enough CPython
sys.stdout.reconfigure(line_buffering=True)
Enter fullscreen mode Exit fullscreen mode

Primary sources I keep beside the notebook: PYTHONUNBUFFERED / -u, print(..., flush=True), and sys.stdout.isatty(). If your runner disagrees with my table, trust the runner in front of you.

Decision table I wish I had on hour one

What you see stdout.isatty() Likely cause First move
Lines appear live in your terminal True Line buffering on a TTY Do not "fix" application code yet
Lines appear only after process exit under a pipe False Block-buffered stdout python -u or flush=True
Tracebacks appear, heartbeats do not mixed stderr policy differs from stdout Split the streams in the notes
Zero bytes and a very short runtime either Process never reached main Print pid, cwd, and argv first
An agent retries because "there was no output" False A scraper treated silence as death Require a launch receipt, not a print

If the table says block buffering, stop adding checkpoints for a minute. Change the flush policy, then add checkpoints that can actually escape the pipe.

Field notes I would repeat

These are the commands I now paste before I let an agent rerun anything that looks hung.

python -c "import sys; print('stdout_tty', sys.stdout.isatty(), 'stderr_tty', sys.stderr.isatty())"
ps -o pid,etime,stat,cmd -p "$PID"
Enter fullscreen mode Exit fullscreen mode

On Linux I also peek at the fds, because the notes should say pipe versus socket versus terminal.

ls -l /proc/$PID/fd/1 /proc/$PID/fd/2
Enter fullscreen mode Exit fullscreen mode

On macOS those /proc lines will not exist, so I fall back to lsof -p "$PID" and I write that limitation into the same paragraph. I stamp heartbeat lines with flush=True and a monotonic timestamp, because empty and late are different bugs wearing the same coat.

Numbered loop I actually reuse:

  1. Record isatty() for stdout and stderr in the first lines that are allowed to print.
  2. Record pid, start time, and the exact argv, even if the rest of the job stays quiet.
  3. Run once with PYTHONUNBUFFERED=1 before changing product code or prompting an agent.
  4. Only then add prints, logging config, or a generated patch, and only on the flushed path.

Would I still use an agent to draft the tracing snippet after that probe exists? Yes, but I would not let it decide the job is hung from a quiet pipe.

Where a free remote box actually helped

I needed a non-interactive shell that looked more like CI than my laptop terminal, because my laptop kept hiding the bug. Disclosure: This article was prepared as part of MonkeyCode's product outreach. I used MonkeyCode's free server option as that non-TTY box, and free model access only to draft the isatty snippet, then I ran the snippet myself.

The useful part was not a model lecture about buffering. The useful part was reproducing the pipe on a box that was never a terminal. If your laptop is a TTY, you will keep shipping prints that vanish the moment CI captures stdout. If you already have a spare VM or a CI dry-run, use that box and skip the product. If you want a non-TTY shell without standing up extra CI, that free server option is one way I reach for the mismatch, then I still require the probe.

What I would not repeat

I would not ask a model to add more logging until I know whether stdout is a TTY. I would not kill a process solely because a scraper saw silence during a long compute loop. I would not teach a wrapper to treat empty stdout as failure when the job is supposed to be quiet for minutes.

I also would not pretend python -u is free in every hot path. Unbuffered output can slow a loop that prints too often, and it can flood a log pipeline that you actually care about. Flush the heartbeats on purpose. Do not unbuffer a tight inner print just because an agent likes noisy traces.

Limitations, and who should skip this

This workflow is for people who debug Python jobs through pipes, agents, and CI log streams. It is not a performance guide, and it is not a claim about any hosted model's accuracy on your codebase. The buffering rules above are CPython-oriented; other runtimes need their own probe.

Skip it, or at least distrust it, if any of these are true:

  • you cannot run a three-line isatty() probe on the same runner that executes the job
  • your empty-log problem is crash-before-import, and you still have no pid receipt
  • you are on Windows consoles, where TTY and pipe behavior need a separate notebook page
  • you need a guaranteed hosted environment, which a free server option is not
  • you print inside a tight loop and cannot afford unbuffered I/O on that path

The reproduction above is something you should run, not something I am asking you to believe because a blog post sounded confident. If your timings disagree with my table, keep your timings.

Closing the notebook

Empty logs are a symptom with at least two causes, and I spent 48 hours mixing them like they were one bug. The process can be dead, or the process can be fine and polite, holding a buffer because nobody gave it a terminal. Ask isatty() first, flush on purpose, and keep a launch receipt that does not depend on a print surviving a pipe.

That is the whole lesson, and it still fits on one sticky note. Would I start with more logging next time? Not until the file descriptor has a name.

Top comments (0)