DEV Community

Taylor Wang
Taylor Wang

Posted on

The Remote Job Printed Nothing for 48 Hours. stdout Had No TTY.

I spent forty-eight hours convinced a worker was deadlocked, because the remote log never showed the first print. Have you ever rerun the same Python file on your laptop and watched it chatter, then watched a server swallow every line? That gap is easy to blame on locks, agents, or a hung HTTP client that never returns. The quieter explanation is that CPython block-buffers stdout whenever the stream is not attached to a TTY.

Hour 0 to 4: the empty log looked like a hang

The job was a small batch script, not a service, and it was supposed to print a checkpoint before each expensive step. I started it on a remote shell that captured output through a pipe, then I waited, then I waited more. Why would a simple starting-batch print vanish while the process was still listed in ps? I assumed the interpreter never reached that line, so I started hunting for an import deadlock that did not exist.

Locally the same file was noisy in a good way, which made the remote silence feel like a different codebase. I compared SHAs, and I compared sys.version, and I still did not have a story that fit. I even compared os.getcwd() because I have already been burned by working-directory surprises on remote runners. None of those checks explained a print that existed in the file and never arrived in the captured log.

Hour 4 to 12: I blamed a lock I could not name

I added more prints, then I added logging.warning, then I added a file write sitting beside the print. The file write showed up on disk almost immediately, and that should have been the only clue I needed. The print did not appear until the process crashed, and then every delayed line arrived together. Does that sound like a deadlock to you, or like two streams following different flush rules?

I still wasted a morning on threading.Lock, a join that never returned, and a queue that was never actually empty. The process was running, the disk checkpoint was running, and only stdout was being polite. Here is the shape of the script I was running, simplified so you can reproduce the silence without any of my business logic.

# reproduce_buffer.py
import sys
import time

def work() -> None:
    print("starting batch")
    time.sleep(8)
    raise RuntimeError("boom after the silence")

if __name__ == "__main__":
    print(f"stdout.isatty={sys.stdout.isatty()}", file=sys.stderr)
    print(f"stderr.isatty={sys.stderr.isatty()}", file=sys.stderr)
    work()
Enter fullscreen mode Exit fullscreen mode

Run it two ways before you touch pytest, Docker files, or an agent prompt.

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

On a laptop TTY, the first command prints starting batch immediately, then sleeps, then raises RuntimeError. Piped through cat, that same print often stays hidden until the crash unwinds and the buffer finally flushes. stderr still speaks during the sleep, which is why my proof that the process was alive kept coming from the wrong stream.

Hour 12 to 24: I asked a model, then I verified without a TTY

I did not want another laptop-only green run, because a laptop TTY will lie about buffering every single time. Disclosure: This article was prepared as part of MonkeyCode's product outreach. I used MonkeyCode's free model access to list the real buffering knobs I should measure. Then I ran the same script on the free server option, where stdout was not my terminal. That pairing mattered more than any generated explanation: the model named candidates, and the non-TTY server made the failure visible.

The checklist I kept was short, and I refused to accept any item I had not measured on the stream itself.

  • python -u
  • PYTHONUNBUFFERED=1
  • print(..., flush=True)
  • sys.stdout.reconfigure(line_buffering=True)
  • move heartbeats to stderr or to a FileHandler

The model was a checklist generator, not an oracle for my process table, and that distinction saved another wrong patch. I still printed isatty() on stderr, because a confident story you never measured is just fan fiction with syntax highlighting. If your remote runner allocates a pseudo-TTY, you will not see this bug, and you will distrust people who claim it exists. Ask the stream, not the dashboard, before you start renaming locks.

Hour 24 to 36: what actually broke

Three things broke during those two days, and only one of them was CPython's default policy for pipes.

  1. I treated print as a log line. It is a write to a buffered stream, and the policy depends on isatty().
  2. I captured stdout through a pipe. CI, nohup, docker logs without a TTY, and subprocess.PIPE all take that path.
  3. I trusted a local terminal session. My laptop was line-buffered, while the remote job was block-buffered.

CPython's usual rule is simple enough to memorize, and I still forgot it the moment the log looked empty.

  • Interactive stdout attached to a TTY is line-buffered, so a newline often appears right now.
  • stdout attached to a pipe or a file is block-buffered, so you wait for a flush, a full buffer, or exit.
  • stderr is typically unbuffered, which is why tracebacks arrive while ordinary prints do not.
  • python -u or PYTHONUNBUFFERED=1 keeps stdin, stdout, and stderr unbuffered for that process.

Current CPython also lets you be explicit without changing the entire process personality.

import sys

sys.stdout.reconfigure(line_buffering=True)
print("starting batch")
Enter fullscreen mode Exit fullscreen mode

Or keep the process defaults and only flush the checkpoints you actually need to see.

print("starting batch", flush=True)
Enter fullscreen mode Exit fullscreen mode

I would not sprinkle flush=True on every debug line inside a hot inner loop that writes thousands of records. I would move those checkpoints to logging with a StreamHandler on stderr, or a FileHandler whose flush behavior I control. print() is a convenience for a TTY session, and I had been using it as infrastructure.

A decision table I wish I had at hour one

How you run it stdout.isatty() Default stdout behavior What you observe
Interactive terminal True Line-buffered Checkpoint prints appear
python script.py piped to cat False Block-buffered Silence until flush or exit
CI or most containers without a TTY False Block-buffered Hung-looking jobs with empty logs
python -u or PYTHONUNBUFFERED=1 either Unbuffered Prints appear, more syscalls
print(..., flush=True) either That line flushes One checkpoint is visible
Messages on stderr often irrelevant Usually unbuffered Heartbeats arrive, stdout still lies

Copy that table into the runbook before you open a deadlock ticket against code that is merely quiet. The table is not a personality test for your service. It is a launch-environment checklist.

A tiny test plan you can keep in the repo

I do not unit-test CPython buffering itself, because that contract belongs to the interpreter and to the launch environment. I do test that a checkpoint I claim is durable cannot vanish into a pipe. The snippet below is a regression tripwire, not a proof that production logging is complete.

# test_checkpoint_stream.py
import subprocess
import sys

SCRIPT = r"""
import sys
print("checkpoint")
sys.stdout.flush()
print("after-flush")
"""

def test_checkpoint_survives_a_pipe():
    proc = subprocess.run(
        [sys.executable, "-c", SCRIPT],
        stdout=subprocess.PIPE,
        stderr=subprocess.PIPE,
        text=True,
        check=True,
    )
    assert proc.stdout.splitlines()[0] == "checkpoint"
Enter fullscreen mode Exit fullscreen mode

Pair that test with a manual pipe run whenever somebody changes how the job is launched.

python -c "import sys; print(sys.stdout.isatty())"
python -c "import sys; print(sys.stdout.isatty())" | cat
Enter fullscreen mode Exit fullscreen mode

If those two commands disagree, your mental model of the log is already wrong, and you should stop arguing from a laptop screenshot. Ask the stream. Do not ask the dashboard. A green local run with a TTY is not evidence that CI will ever see the same bytes.

What I would repeat, and what I would not

I would repeat the isatty() probe on stderr before I touch locks, retries, or an agent loop that looks stuck. I would repeat running the job under a pipe on purpose, because that is what CI will do later. I would repeat putting heartbeats on stderr or into a file, not into buffered stdout. I would not repeat waiting two days for a buffer to fill.

Should you export PYTHONUNBUFFERED=1 in every Dockerfile and every systemd unit as a new house style? Not if the process writes large binary payloads to stdout and you care about syscall cost. Not if a downstream consumer assumes block-sized writes and you just changed the framing. Not if you already have structured logging and you are only avoiding the migration. Unbuffered mode is a debugging lever, not a personality trait for every Python process.

Limitations you should actually respect when you copy this notebook:

  • This write-up is about missing text checkpoints, not about a real deadlock if mutexes are involved.
  • sys.stdout.reconfigure is a CPython convenience, so do not assume every interpreter you support implements it.
  • A remote server without a TTY is a good reproduction box, not a substitute for your production log pipeline.
  • Language models will invent a hung-thread story if you paste an empty log and ask them why.

Who should not use this approach? Anyone whose stdout is a protocol rather than a log, including tools that emit length-prefixed binary frames. Also skip the unbuffered hammer if your runtime already wraps the process with a PTY and you have measured isatty() as True.

Closing the notebook

The remote job was not frozen for forty-eight hours, because the interpreter was only being polite to a pipe. I was reading that politeness as death, which is an expensive way to learn about block buffering. Next time the log is empty and ps still shows Python, I will print isatty() on stderr before I name a villain. If you need a second machine that is not your laptop TTY, MonkeyCode's free server option can reproduce this silence.

Top comments (1)

Collapse
 
systemcraftdev profile image
SystemCraftDev

This exact mechanism is also why docker logs -f or kubectl logs -f sometimes look stuck on a perfectly healthy container - same isatty()-driven block buffering, just one layer removed from python -u. One detail worth adding: sys.stdout.reconfigure(line_buffering=True) only flushes on a newline, so it's a good match for print() but won't help if something writes partial lines without a trailing \n (progress bars, spinners, sys.stdout.write() without a newline). For that case, sys.stdout.reconfigure(write_through=True) flushes on every write() call regardless of newlines, which is closer to what people actually mean by "just show me the output now."