Log Python Excel Script Output to a File
print() is fine while you are writing a script and useless the moment it runs unattended: no timestamps, no severity, and output that disappears wherever the scheduler sends it. Python's logging module fixes all three in about fifteen lines. This guide, part of Error Handling and Logging in Excel Automation, sets it up and covers what an Excel job should actually record.
Prerequisites
Only the standard library is needed for logging itself:
pip install pandas openpyxl
A setup function you can reuse
import logging
from logging.handlers import RotatingFileHandler
from pathlib import Path
def setup_logging(name="report", logdir="logs", level=logging.INFO, console=True):
Path(logdir).mkdir(parents=True, exist_ok=True)
logger = logging.getLogger(name)
logger.setLevel(level)
logger.handlers.clear() # safe to call twice, e.g. from tests
logger.propagate = False # do not double-log through the root logger
fmt = logging.Formatter(
"%(asctime)s %(levelname)-8s %(name)s %(message)s",
datefmt="%Y-%m-%d %H:%M:%S",
)
file_handler = RotatingFileHandler(
Path(logdir) / f"{name}.log", maxBytes=5_000_000, backupCount=5, encoding="utf-8"
)
file_handler.setFormatter(fmt)
logger.addHandler(file_handler)
if console:
stream = logging.StreamHandler()
stream.setFormatter(fmt)
logger.addHandler(stream)
return logger
log = setup_logging()
log.info("logging ready")
Three lines earn their place. handlers.clear() makes the function idempotent, so importing the module twice does not produce doubled output. propagate = False stops messages also reaching the root logger, which is what causes each line to appear twice when a library has configured logging as well. And encoding="utf-8" avoids a UnicodeEncodeError the first time a customer name with an accent reaches the log on Windows.
What an Excel job should record
Log the boundaries — every point where data enters, changes shape, or leaves:
import time
from pathlib import Path
import pandas as pd
def build_report(source, target):
started = time.perf_counter()
log.info("run started source=%s target=%s", source, target)
df = pd.read_excel(source, sheet_name="Orders")
log.info("read rows=%d columns=%d sheet=%s", len(df), len(df.columns), "Orders")
before = len(df)
df = df.dropna(subset=["Order_ID"])
log.info("validated rows=%d dropped=%d", len(df), before - len(df))
summary = df.groupby("Region", observed=True)["Quantity"].sum()
log.info("aggregated groups=%d total=%s", len(summary), int(summary.sum()))
summary.to_frame().to_excel(target)
size_kb = Path(target).stat().st_size / 1024
log.info("wrote %s size=%.1fKB elapsed=%.1fs",
target, size_kb, time.perf_counter() - started)
return target
Each line carries a number, and the numbers are what make a log useful weeks later. "read rows=48211 … dropped=0 … groups=4" reconstructs a run without the source file; "read rows=12" on the following day identifies the problem instantly. Using %s placeholders rather than f-strings means the formatting cost is only paid if the level is enabled, which matters for DEBUG lines inside loops.
Levels, and when to use each
| Level | Use for | Example |
|---|---|---|
DEBUG | Detail you would only want while investigating | per-file paths in a batch of 300 |
INFO | The narrative of a normal run | rows read, groups aggregated, file written |
WARNING | Something unexpected the job handled | fallback filename used, 3 rows quarantined |
ERROR | The job could not do what it was asked | output validation failed, source missing |
CRITICAL | Rare — the process cannot continue at all | disk full, credentials rejected |
The line between INFO and DEBUG decides whether the log is readable. A daily report should produce perhaps twenty INFO lines: enough to tell the story, few enough to scan. Anything per-row or per-file belongs at DEBUG, where raising the level in an emergency gives you more detail without changing the code.
Tracebacks and library warnings
Two things routinely go missing from a log and are exactly what you need after a failure:
import logging
import warnings
logging.captureWarnings(True) # route warnings.warn into logging
logging.getLogger("py.warnings").addHandler(log.handlers[0])
try:
df = pd.read_excel("missing.xlsx")
except Exception:
log.exception("failed to read the source workbook") # ERROR + full traceback
raise
log.exception may only be called inside an except block, and it appends the traceback automatically — there is no need to format the exception yourself. captureWarnings(True) matters more than it sounds for spreadsheet work: openpyxl warns about unsupported extensions, and pandas warns about inconsistent date parsing, and both are usually the first sign that a source file has changed.
Add context without repeating yourself
When a job processes many units, put the unit in every line automatically rather than threading it through each call:
import logging
class RunContext(logging.LoggerAdapter):
def process(self, msg, kwargs):
return f"[{self.extra['unit']}] {msg}", kwargs
for region in ["North", "South", "West"]:
rlog = RunContext(log, {"unit": region})
rlog.info("started")
rlog.info("rows=%d", 1200)
Every line now begins with [North], so grep North logs/report.log gives you one region's entire story. On a batch job this is the difference between a readable log and an interleaved one where three regions' messages are shuffled together.
Rotation: by size or by day?
Both keep the log bounded; they suit different investigations. A scheduled report is almost always easier to debug with one file per day, because that is how the question arrives — "what happened on the 3rd?":
from logging.handlers import TimedRotatingFileHandler
handler = TimedRotatingFileHandler(
"logs/report.log", when="midnight", backupCount=30, encoding="utf-8"
)
Thirty daily files is a month of history for a few megabytes, and the date in the filename means no searching at all for the common question. Where a job runs many times a day, keep time-based rotation and add the run key to each line — the file still bounds the search, and the key separates the runs inside it.
Common pitfalls and gotchas
| Symptom | Cause | Fix |
|---|---|---|
| Every line appears twice | Handlers added twice, or propagation to root | handlers.clear() and propagate = False |
| Log file is empty | Level set above the calls being made | Check logger.setLevel and the handler level |
UnicodeEncodeError writing a name | Default encoding on Windows | encoding="utf-8" on the handler |
| Log grows without limit | Plain FileHandler | Use RotatingFileHandler or the timed variant |
| Traceback missing | log.error(exc) instead of log.exception | Call log.exception inside the except |
| pandas warnings invisible | Warnings not routed to logging | logging.captureWarnings(True) |
| Nothing captured by the scheduler | Only a file handler configured | Keep the StreamHandler too |
Make the log machine-readable too
A human reads the text; a monitoring system wants fields. Emitting a second, structured line per run gives you both without complicating the narrative:
import json
import logging
class JsonLine(logging.Formatter):
def format(self, record):
payload = {
"ts": self.formatTime(record, "%Y-%m-%dT%H:%M:%S"),
"level": record.levelname,
"message": record.getMessage(),
}
payload.update(getattr(record, "fields", {}))
return json.dumps(payload, ensure_ascii=False)
metrics = logging.getLogger("report.metrics")
metrics.propagate = False
handler = logging.FileHandler("logs/report.jsonl", encoding="utf-8")
handler.setFormatter(JsonLine())
metrics.addHandler(handler)
metrics.setLevel(logging.INFO)
metrics.info("run finished", extra={"fields": {"rows": 48211, "seconds": 12.4, "status": "ok"}})
One JSON object per line — .jsonl — is the format every log shipper and half the command-line tools already understand, and jq turns a month of runs into a table in one command. Keeping it in a separate logger means the readable log stays readable, and neither format has to compromise for the other.
Performance and scale notes
Logging costs a formatted string and a write per line, so twenty INFO lines per run are free. The pattern that does cost is logging inside a per-row loop: at 400,000 rows even a suppressed DEBUG call adds up, because the arguments are still evaluated. Use %s placeholders so formatting is deferred, guard genuinely expensive messages with if log.isEnabledFor(logging.DEBUG), and prefer one summary line per chunk over one line per row. On a network share, keep the log on local disk — a blocked write to a mounted drive can stall the job it was meant to document.
Conclusion
Replace every print in a scheduled job with a logger that writes to both a rotating file and the console, and record the boundaries of the job with counts attached. Keep INFO to the narrative and push detail to DEBUG, use log.exception so tracebacks land in the file, route library warnings into the same place, and add per-unit context with a LoggerAdapter when the job handles many things. The result is a log that answers questions without a re-run.
Frequently asked questions
Why not just use print and redirect the output?print has no levels, no timestamps and no way to send the same message to two places. Redirecting also loses everything if the scheduler discards stdout, which many do.
Should I log to one file or one per run?
One rotating file is easier to search and keeps history bounded. Add the run's date or key to each line rather than to the filename, so a single grep spans several runs.
How do I record a traceback?
Call logger.exception inside the except block. It logs at ERROR level and appends the full traceback automatically.
How do I stop pandas warnings vanishing?
Call logging.captureWarnings(True) so warnings.warn output is routed through the logging system into the same file.
Related
Up to the parent guide:
- Error Handling and Logging in Excel Automation — the failure classes these lines describe.
Related guides:
- Retry a Failed Excel Report Job in Python — what to log around each attempt.
- Handle Permission Denied When Writing Excel in Python — the diagnosis worth recording.
- Scheduling Python Excel Scripts with cron — where the console handler's output ends up.
- Run a Python Excel Script on Windows Task Scheduler — logging when there is no terminal at all.