Every log line is written for one reader: someone at two in the morning, with customers who cannot pay, trying to find out why. Too often what that reader finds is Error occurred. Several hundred times, and nothing else.
Logging is the one part of a system written entirely for a future emergency, usually by someone who is not having one. Most of it goes in to chase a bug one afternoon and is never looked at again. Below are a few typical lines rewritten for the person who will really read them, then the principles behind the rewrites.
Before and after
An error with nothing attached
# before
ERROR Error occurred
# after
2025-12-04T02:14:36Z ERROR req=7f3a9c payment.charge failed: gateway timeout after 30s, attempt=3/3, order=10482 left unpaidThe second line answers what you would otherwise have to ask: when, which request, which operation, why, and what it left behind. "Left unpaid" is the part people forget. It tells the reader whether anything needs cleaning up.
A step with no decision in it
# before
INFO Processing order 10482
INFO Done
# after
INFO req=7f3a9c order=10482 invoice email not sent: customer has opted out of email"Done" tells you the code reached the end of a function. The rewrite tells you what the system chose to do and why, which is exactly what you need when a customer says they never got their invoice.
A line that should not exist
# before
DEBUG login user=someone@example.com password=letmein1 token=eyJhbGciOi...
# after
INFO req=c41e07 login failed: wrong password, user_id=3317The first version writes a password and a session token into a file that will be copied, backed up and read by people who should never see either. The second says what happened, and to whom, through an id that means nothing outside the system.
One request, one thread
02:13:05 INFO req=7f3a9c POST /checkout user_id=3317 items=2
02:13:05 INFO req=7f3a9c stock reserved for 2 items
02:13:06 INFO req=7f3a9c payment.charge started, gateway=primary
02:13:36 WARN req=7f3a9c payment.charge timed out after 30s, retrying (2/3)
02:14:06 WARN req=7f3a9c payment.charge timed out after 30s, retrying (3/3)
02:14:36 ERROR req=7f3a9c payment.charge failed, order=10482 left unpaid, stock releasedOn a busy system these six lines are scattered among thousands of others. Searching for req=7f3a9c pulls them back into one story, in order.
The principles behind the rewrites
Log decisions, not just errors
The most useful line in a log is often not an error at all. It is the moment the system chose something: skipped an email, applied a discount, retried, fell back to a second provider, treated two records as duplicates. Errors tell you something broke. Decisions tell you why the outcome is what it is, and most support questions are about outcomes. "Why was this customer charged twice?" is rarely answered by a stack trace.
Give every request an id
Generate it once, where the work enters the system: the web request, the queued job, the scheduled run. Put it on every line that work writes, and pass it along when the work hands off to something else. Show it on the error page as well. A customer who reads you six characters over the phone has just told you exactly where to look.
Let the logging setup add it, so nobody has to remember. In Python, a small filter does the job:
import logging
import uuid
from contextvars import ContextVar
request_id = ContextVar("request_id", default="-")
class RequestIdFilter(logging.Filter):
def filter(self, record):
record.req = request_id.get() # stamp every line
return True
handler = logging.StreamHandler()
handler.addFilter(RequestIdFilter())
handler.setFormatter(logging.Formatter(
"%(asctime)s %(levelname)s req=%(req)s %(message)s"))
log = logging.getLogger("shop")
log.addHandler(handler)
log.setLevel(logging.INFO)
def handle_checkout(order_id):
request_id.set(uuid.uuid4().hex[:6]) # once, where the work enters
log.info("checkout started order=%s", order_id)Make the levels mean something
Agree what each level is for, and hold to it. ERROR: someone should act, probably today. WARN: something unusual happened and the system coped, for now. INFO: the normal story, in terms the business would recognise, such as order placed, invoice sent, import finished. DEBUG: detail for whoever is developing it, off in production unless you are chasing something.
An ERROR that fires forty times a day and gets ignored teaches everyone to ignore ERROR. Fix the cause or downgrade the line. Either is better than noise.
Never log secrets or personal data
Passwords, API keys, card numbers, session tokens: never, not even at DEBUG, because DEBUG gets switched on in a hurry and forgotten. Treat personal data with the same suspicion. Log the customer's id, not their name, email address or phone number. Logs get pasted into support tickets and chats and kept far longer than anyone intended; the id is enough to look someone up, with the right access, in the system built to hold their details.
Keep logs where you can search them
A log file on one server, readable by one person and rotated away after three days, will not help at two in the morning. Write lines a machine can filter (consistent key=value pairs, or JSON), send them somewhere you can search by request id, time and level, and decide on purpose how long to keep them. For a small system that can be as plain as files kept for a sensible period and someone who knows grep. What matters is that it was decided, not left to the defaults.
Searching only helps once someone knows to look, so an ERROR should reach a person rather than wait to be found. When I build an automation, logging and failure alerts go into the handover alongside the runbook, so nobody finds out in March that something stopped in January.
Try it on yesterday
There is a ten-minute test for all of this. Pick one real request from yesterday (an order, a login, an import) and, using nothing but the logs, tell its story: what came in, what the system decided, what it did and how it ended. If you can, your logs will hold up at two in the morning. If you cannot, the time to fix them is now, while nobody is waiting on the answer.
