Skip to content

install_capture_streams() makes any pod that names a loguru logger unserializable #253

Description

@brian-arnold

install_capture_streams() makes any pod that names a loguru logger unserializable

Affects: HEAD (f73f539f). Reproducible in ~10 lines.

Summary

After install_capture_streams() runs, any function that references a module-level loguru logger can no longer be cloudpickled. Under RayExecutor that means .remote() raises on the driver:

PicklingError: Cannot pickle files that are not opened for reading: w

The task is never submitted and the pod never runs. Combined with the async path swallowing failures (filed separately), the result is a node that silently does nothing for the lifetime of a deployment. That is exactly what happened to us — two cleanup pods that never once executed.

Mechanism

Three individually reasonable behaviours combine:

  1. loguru binds sys.stderr by object reference into its default handler at import time.
  2. install_capture_streams() replaces sys.stdout / sys.stderr with ContextLocalTeeStream (logging_capture.py:170-172).
  3. cloudpickle's _file_reduce special-cases the standard streams by identity (obj is sys.stderr).

After (2), loguru still holds the original TextIOWrapper, which is no longer sys.stderr. The identity check in (3) misses, _file_reduce falls through to its mode check, and a mode-'w' handle is refused.

RayExecutor ships (fn, kwargs) and cloudpickle serializes fn by value, so every module-level global the function body names is serialized with it. Naming a loguru logger anywhere in a pod body is therefore enough.

The error message names none of the three components involved, which made this expensive to diagnose.

Repro

import sys
from loguru import logger
import ray.cloudpickle as cp

def f():
    logger.warning("hi")

cp.dumps(f)                       # OK

from orcapod.pipeline.logging_capture import install_capture_streams
install_capture_streams()

cp.dumps(f)                       # PicklingError: Cannot pickle files that are
                                  # not opened for reading: w

Related: the existing logging.Logger guard is a no-op under Ray

RayExecutor._ensure_ray_initialized already registers a reducer for stdlib loggers, for what its docstring describes as essentially this problem (executors/ray.py:104-136). In our environment it never fires, for two independent reasons:

import cloudpickle                                  # standalone package
cloudpickle.CloudPickler.dispatch[logging.Logger] = _pickle_logger
  • Ray serializes with its vendored ray.cloudpickle, not the standalone cloudpickle distribution. Registering on one does not affect the other.
  • The standalone package is not installed in our image at all, so the except (ImportError, AttributeError, KeyError): pass swallows it silently.

It also targets the legacy CloudPickler.dispatch attribute rather than _dispatch_table.

The stdlib case happens to be safe anyway — ray.cloudpickle registers logging.Logger_logger_reduce natively (ray/cloudpickle/cloudpickle.py:1161). But the block reads as protection that is not actually in place, and it is the natural home for a fix that is needed.

Suggested fix

Register a reducer for loguru's logger on the pickler Ray actually uses, returning the module-level singleton:

def _get_loguru_logger():
    from loguru import logger
    return logger

try:
    from loguru import logger as _loguru_logger
    from ray.cloudpickle.cloudpickle import Pickler as _RayPickler
    _RayPickler._dispatch_table[type(_loguru_logger)] = (
        lambda _: (_get_loguru_logger, ())
    )
except ImportError:
    pass

Verified against HEAD: with this registered, the repro above pickles, round-trips, and the reconstructed function still logs correctly.

This mirrors the existing intent, and the semantics match the stdlib case — loguru's logger is a process-level singleton, like a named stdlib logger.

One caveat if you take this approach. logger.bind(...) returns a new Logger instance of the same type, carrying its context in _options[-1]:

>>> vars(logger.bind(probe="x"))["_options"][-1]
{'probe': 'x'}

A reducer keyed on type(logger) catches those too and would silently drop the bound context on the worker. Reconstructing via logger.bind(**options[-1]) instead of returning the bare singleton preserves it, and costs nothing for the unbound case.

Worth considering alongside: ContextLocalTeeStream could preserve identity for the stream it wraps, or install_capture_streams could redirect at the file-descriptor level instead of rebinding sys.stdout / sys.stderr. Either would fix this class of problem for any library that caches a stream reference, not just loguru. make_capture_wrapper already takes the fd-level approach on the worker side.

Downstream note

We fixed this on our side by not naming the logger in pod bodies, and added a test that cloudpickles every pod function after install_capture_streams(). That guard belongs downstream regardless, but the underlying trap is orcapod's — any user whose pod body logs will hit it, and the failure mode is a silent no-op rather than an error.


Filed from downstream NPIPE-211 (orcapod-spikesorting).

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions