Everything you wanted to know about Python logging in Databricks

Or: Where are those logs?

It happened again: we got paged on Slack: “We don’t find the logs we’re emitting. We have urgent debugging details in them. What’s going on?” Logs are important. They help us understand the flow of our app; we might use them to debug values in production or to verify if this new experimental job is actually doing something. But unlike logs in our k8s environment, which we know how to configure well, we’ve repeatedly encountered problems and confusion around Python logging inside our Spark jobs. So, once and for all, I present (almost) everything you need to know about Python logging inside a Spark job (in Databricks).

This is a photo of the D-21 computer at Tekniska museet in Stockholm where it was exhibitied in running condition for several years. (Tekniska museet — https://digitaltmuseum.se/021026305322/datamaskin)

Two kinds of logs

An important distinction is that there are two kinds of logs in a Spark job, those emitted within the executors and those emitted in the driver. Executors are where the distributed computing happens, and the driver is where most of the application logic runs. Since most of our logging is “application-level”, it’s usually the driver logs we care about. We’ll revisit executor logs later.

Sane logging in Databricks

The path towards sane logging in Databricks starts with solving two important issues:

1. Forcing Python loggers to respect your logging configuration and logging levels
2. Setting a “log destination” for the cluster

Forcing Python loggers to respect your configuration

You need something like this early in your process:

import logging
import sys
for handler in logging.root.handlers[:]:
logging.root.removeHandler(handler)
console_handler = logging.StreamHandler(stream=sys.stdout)
console_handler.setLevel(logging.DEBUG)
logging.basicConfig(level=logging.INFO,
handlers=[console_handler],
format=
"%(asctime)s:%(name)s:%(lineno)d:%(levelname)s:%(message)s"
)
logging.getLogger("py4j.java_gateway").setLevel(logging.WARNING)
logging.getLogger("py4j.clientserver").setLevel(logging.WARNING)
logging.getLogger("mlflow.tracking.client").setLevel(logging.ERROR)
logging.getLogger("httpx").setLevel(logging.WARNING) # the http library calls
logging.getLogger("other_library_which_spams_the_logs").setLevel(logging.WARNING)
logging.getLogger("project_folder_root_name").setLevel(logging.DEBUG)
And import this configuration very early - before other modules import logging or before noisy libraries are initialized. In our codebase we keep this in a module like logging_base.py and import it at the top of each entry file:
from logging_base import logging
logger = logging.getLogger(__name__)

In this module, we:

1. Remove the existing handlers, if I don’t remove them, Python would IGNORE our custom setup, this is the source of many of the Python logging pain we see. An existing logger is defined somewhere (in this case, somewhere in the Spark of Databricks stack) before our code is imported, and then everything we configure is ignored
2. Set up our own custom logging handler and formatting (again, you might choose differently; I like this format)
3. We control levels for noisy third-party modules so they don’t drown useful logs.
4. Set up the base logging level for our project
5. Important: you must import and use this modified logging (or ensure it runs before others import logging) — otherwise your configuration will be ignored.

Now we’ve set up the logging configuration and got the loggers to output what we want, we need to configure a destination to save them.

Log destination

You also need to configure where logs are stored. In this post I’ll show the simple option: saving logs to object storage (S3).

Get Alon Nisser’s stories in your inbox

Join Medium for free to get updates from this writer.

Remember me for faster sign in

We set a lifecycle policy on the bucket to delete logs automatically after 30 days (you might choose a different retention). You can also send logs to a log aggregation service (Datadog, Coralogix, etc.). A straightforward way to place cluster logs in object storage is via the job/cluster config. Example config snippet (JSON):

"Cluster_log_conf":{
"Volumes":{"destination":/Volumes/catalog_name"/log_volume/job_name"}
}

Note: We utilize Unity catalog volumes for log storage, as this is supported in newer versions and allows us to read the logs easily via a Databricks notebook

But where can we view them?

The easiest place is the Jobs UI — the job execution page shows logs. The problem is it only shows a limited portion of the driver logs and cuts off the rest. This UI truncation is (I assume) intentional for UX reasons, but it causes a lot of confusion. A “see the rest of the logs” link in the job UI would save many support pings.

If you need the whole log, you’ll need to move to the next option.

You can use the Logs link on the Job execution page to open the Spark UI and view the driver logs. A few gotchas:

• There might be more than one file. You may need to download multiple files (they might be gzipped) and open/search them locally.
• Even when there appears to be “one file,” the “Standard output” section in the UI is sometimes limited; downloading the raw files is the only way to search all driver logs reliably (if you use Object storage and not a dedicated logs integration).

Note: if you’ve set up the Logs object storage as a Unity catalog volume, you can also view them via a Notebook, without leaving Databricks, create a post-processing pipeline for logs, or use them as raw data for analytics.

For example:

dbutils.fs.head(‘/Volumes/catalog_name/some_path/logs/ondemand/1125–132327–920k1dkc/executor/stderr’)

Logging in the executor

Mostly, executor stuff happens “behind the curtain” in modern Spark. We use Spark SQL, or built in Spark functions, and Spark magically transforms it to RDDs, partitions, map-reduces and joins back. But sometimes we have our own UDF (user-defined function), probably in the form of `pandas_udf` or `applyInPandas`, what happens when we try to log inside such a function?

It won’t be in the UI logs,

It won’t be in the standard output

It would be (of course, only if you configured the logging module as described above) under “stderr” logs. Why? I’m not sure, there seems to be an override/redirect forcing executor logs to STDERR. It doesn’t override all of our logging config, just the output.

Summary:

Reading your logs in Databricks can be daunting, but it’s manageable if you adopt a simple, consistent setup:

1. Configure Python logging very early and force removal of pre-attached handlers.
2. Route logs to a durable destination (S3, a log service, etc.) and set retention via lifecycle policies.
3. Know where driver vs. executor logs land (driver logs in the Jobs/Spark UI, executor logs often in stderr files).

Now you need to reason about what you want to log (levels, sampling, structured logs, correlation IDs, etc.) — but that’s for another blog post.