The Quiet Terminal

← Practical Tips

Retiring print(): a ten-minute migration to logging

2026-05-08 · 3 min read

I used to have a sync script that ran overnight and printed its progress. One morning it had died partway through, and all print() could tell me was that a terminal window I'd long since closed had once shown something. Which step, what time, what error: no idea. That was the morning print() stopped being my logging system, and the migration to the real thing took about ten minutes.

The whole migration: one function call

import logging

logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s %(levelname)s %(message)s",
)

Then change print("synced 128 files") to logging.info(...) wherever progress is being reported. The output now looks like:

2026-05-08 03:12:41,207 INFO synced 128 files in 3.1s
2026-05-08 03:12:41,209 WARNING skipping malformed line 42

That one format string buys the two things print never had: a timestamp, which turns "it died at some point overnight" into "it died three minutes in, right after step 2", and a level, which makes the important line stand out from the chatter.

The levels, one example each

logging.debug("cache miss for key %s", "user:42")
logging.info("synced 128 files in 3.1s")
logging.warning("skipping malformed line 42")
logging.error("upload failed after 3 tries")

The conventions are short: DEBUG is detail you want only while hunting a bug, INFO is the normal heartbeat, WARNING means "kept going but you should know", ERROR means "this step failed". The level= in basicConfig is the gate — at INFO, the debug line stays quiet. When something breaks, you change one word to level=logging.DEBUG, rerun, and the detail appears. No hunting through the code switching print statements back on, one by one.

A detail that looks like laziness but isn't: the %s placeholders mean logging only formats the message if that level is actually being shown, so debug lines left in the code cost nothing in the normal case.

And the reason 3am matters: filename=

logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s %(levelname)s %(message)s",
    filename="sync.log",
)

Same code, but the output lands in a file instead of a terminal that's gone by morning. This single argument is most of the migration's value — my dead sync script would have left a log file ending with the error instead of nothing at all.

When the script grows past one file, there's one more move: each module gets logger = logging.getLogger(__name__) and calls logger.info(...) instead of the module-level functions, and you add %(name)s to the format. Now every line says which file it came from, and basicConfig stays in exactly one place — the entry point — instead of being imported around like a rumor.

Keep print for the real output

Here's the split I landed on, and it's the point of the whole exercise. The sync script's final summary — the thing the user actually asked the program for — is still print() in my code. If a line is the program talking to the user, print; if it's the program talking to itself, logging. Diagnostics in the log, results on the screen, and neither one apologizing for the other.