py-spy in Azure Batch

Today, I was debugging a hanging task in Azure Batch. This short post records how I used py-spy to investigate the problem.

Background

Azure Batch is a compute service that we use to run container workloads. In this case, we start up a container that processes a bunch of GOES-GLM data to create STAC items for the Planetary Computer . The workflow is essentially a big

for url in urls:
    local_file = download_url(url)
    stac.create_item(local_file)

We noticed that some Azure Batch tasks were hanging. Based on our logs, we knew it was somewhere in that for loop, but couldn’t determine exactly where things were hanging. The goes-glm stactools package we used does read a NetCDF file, and my experience with Dask biased me towards thinking the netcdf library (or the HDF5 reader it uses) was hanging. But I wanted to confirm that before trying to implement a fix.

Debugging

I wasn’t able to reproduce the hanging locally, so I needed some way to debug the actual hanging process itself. My go-to tool for this type of task is py-spy. It does a lot, but in this case we’ll use py-spy dump to get something like a traceback for what’s currently running (and hanging) in the process.

Azure Batch has a handy feature for SSH-ing into the running task nodes. With an auto-generated user and password, I had a shell on the node with the hanging process.

The only wrinkle here is that we’re using containerized workloads, so the actual process was in a Docker container and not in the host’s process list (I’ll try to follow Jacob Tomlinson’s lead and be intentional about container terminology). The py-spy documentation has some details on how to use py-spy with docker. This comment in particular has some more details on how to run py-spy on the host to detect a process running in a container. The upshot is a command like this, run on the Azure Batch node:

$ root@...:/home/yqjjaq/# docker run -it --pid=container:244fdfc65349 --rm --privileged --cap-add SYS_PTRACE python /bin/bash

where 244fdfc65349 is the ID of the container with the hanging process. I used the python image and then pip installed py-spy in that debugging container (you could also use some container image with py-spy already installed). Finally, I was able to run py-spy dump inside that running container to get the trace:

root@306ad36c7ae3:/# py-spy dump --pid 1
Process 1: /opt/conda/bin/python /opt/conda/bin/pctasks task run blob://pctaskscommon/taskio/run/827e3fa4-be68-49c9-b8c3-3d63b31962ba/process-chunk/3/create-items/input --sas-token ... --account-url https://pctaskscommon.blob.core.windows.net/
Python v3.8.16 (/opt/conda/bin/python3.8)

Thread 0x7F8C69A78740 (active): "MainThread"
    read (ssl.py:1099)
    recv_into (ssl.py:1241)
    readinto (socket.py:669)
    _read_status (http/client.py:277)
    begin (http/client.py:316)
    getresponse (http/client.py:1348)
    _make_request (urllib3/connectionpool.py:444)
    urlopen (urllib3/connectionpool.py:703)
    send (requests/adapters.py:489)
    send (requests/sessions.py:701)
    request (requests/sessions.py:587)
    send (core/pipeline/transport/_requests_basic.py:338)
    send (blob/_shared/base_client.py:333)
    send (blob/_shared/base_client.py:333)
    send (core/pipeline/_base.py:100)
    send (core/pipeline/_base.py:69)
    send (core/pipeline/_base.py:69)
    send (blob/_shared/policies.py:290)
    send (core/pipeline/_base.py:69)
    send (core/pipeline/_base.py:69)
    send (core/pipeline/_base.py:69)
    send (blob/_shared/policies.py:489)
    send (core/pipeline/_base.py:69)
    send (core/pipeline/policies/_redirect.py:160)
    send (core/pipeline/_base.py:69)
    send (core/pipeline/_base.py:69)
    send (core/pipeline/_base.py:69)
    send (core/pipeline/_base.py:69)
    send (core/pipeline/_base.py:69)
    run (core/pipeline/_base.py:205)
    download (blob/_generated/operations/_blob_operations.py:180)
    _initial_request (blob/_download.py:386)
    __init__ (blob/_download.py:349)
    download_blob (blob/_blob_client.py:848)
    wrapper_use_tracer (core/tracing/decorator.py:78)
    <lambda> (core/storage/blob.py:514)
    with_backoff (core/utils/backoff.py:136)
    download_file (core/storage/blob.py:513)
    create_item (goes_glm.py:32)
    create_items (dataset/items/task.py:117)
    run (dataset/items/task.py:153)
    parse_and_run (task/task.py:53)
    run_task (task/run.py:138)
    run_cmd (task/_cli.py:32)
    run_cmd (task/cli.py:50)
    new_func (click/decorators.py:26)
    invoke (click/core.py:760)
    invoke (click/core.py:1404)
    invoke (click/core.py:1657)
    invoke (click/core.py:1657)
    main (click/core.py:1055)
    __call__ (click/core.py:1130)
    cli (cli/cli.py:140)
    <module> (pctasks:8)
Thread 0x7F8C4A84F700 (idle): "fsspecIO"
    select (selectors.py:468)
    _run_once (asyncio/base_events.py:1823)
    run_forever (asyncio/base_events.py:570)
    run (threading.py:870)
    _bootstrap_inner (threading.py:932)
    _bootstrap (threading.py:890)
Thread 0x7F8C4A00E700 (active): "ThreadPoolExecutor-0_0"
    _worker (concurrent/futures/thread.py:78)
    run (threading.py:870)
    _bootstrap_inner (threading.py:932)
    _bootstrap (threading.py:890)

And we’ve found our culprit! The line

download_file (core/storage/blob.py:513)

and everything above it indicates that the process is hanging in the download stage, not the NetCDF reading stage!

This fix

“Fixing” this is pretty easy. The Python SDK for Azure Blob Storage includes the option to set a read_timeout when creating the connection client. Now if the download hangs it should raise a TimeoutError. Then our handler will automatically catch and retry it, and hopefully succeed. It doesn’t address the actual cause of something deep inside the networking stack hanging, but it’s good enough for our purposes.

Update: 2023-02-28. Turns out, the “fix” wasn’t actually a fix. The process hung again the next day. Naturally, I turned to this blog post to find the incantations to run (which is why I wrote it in the first place).

As for getting closer to an actual cause of the hang, a colleague suggested upgrading Python versions since there were some fixes in that area between 3.8 and 3.11. After about a week, there have been zero hangs on Python 3.11.

Background#

Debugging#

This fix#

Background

Debugging

This fix