Sacred developer on retainer: MongoObserver forked into 20 child processes shares PyMongo socket — AutoReconnect after 3 retries silently detaches observer — 300 of 500 experiments lose all metrics — 3 weeks — Sacred developer on monthly retainer

sacred 0.8.4 • Python 3.11 • MongoDB 6.0 • PyMongo 4.6.x • multiprocessing.Pool(20) default fork() on Linux • parent attaches MongoObserver before creating Pool • fork() copies open PyMongo socket to all 20 children • concurrent writes cause AutoReconnect • Sacred 3-retry exhaustion → WARNING emitted → observer silently detached • 300/500 experiments run to completion with no MongoDB metrics • developer checks MongoDB max_connections for 3 weeks • fix: create fresh MongoObserver in each worker function • all 500 experiments logged • 1.5h retainer engagement

Northfield Sacred Exp Ltd. used Sacred 0.8.4 with a MongoDB 6.0 backend to track a 500-experiment LightGBM hyperparameter grid search, running 20 experiments in parallel with multiprocessing.Pool(20). After the grid search completed, the team queried the MongoDB runs collection and found only 200 documents with a non-empty metrics subdocument. The remaining 300 documents had status: 'COMPLETED' but completely empty metrics subdocuments — the experiments had run to completion but their tracked metrics were permanently lost. The developer spent three weeks checking MongoDB connection pool size (default 100), MongoDB max_connections, replica set configuration, and PyMongo version before engaging a Sacred retainer developer.

The Sacred configuration and parallelization code at the time of the engagement:

# Northfield Sacred Exp Ltd. — Sacred + MongoDB grid search
# sacred 0.8.4, Python 3.11, MongoDB 6.0, PyMongo 4.6.x

import multiprocessing
from sacred import Experiment
from sacred.observers import MongoObserver
import lightgbm as lgb
import numpy as np

ex = Experiment('lgbm_grid_search')

# ← Problem: MongoObserver attached to parent process's Experiment
# This creates a pymongo.MongoClient in the parent process, opening a TCP socket
ex.observers.append(MongoObserver(
    url='mongodb://localhost:27017',
    db_name='sacred'
))

@ex.config
def cfg():
    n_estimators = 100
    learning_rate = 0.1
    max_depth = 5
    num_leaves = 31
    subsample = 0.8

@ex.automain
def run(n_estimators, learning_rate, max_depth, num_leaves, subsample, _run):
    # Load data
    X_train, X_val, y_train, y_val = load_dataset()

    model = lgb.LGBMClassifier(
        n_estimators=n_estimators,
        learning_rate=learning_rate,
        max_depth=max_depth,
        num_leaves=num_leaves,
        subsample=subsample,
    )
    model.fit(X_train, y_train)
    val_auc = roc_auc_score(y_val, model.predict_proba(X_val)[:, 1])

    # ← This call succeeds locally but fails silently when MongoObserver is forked
    _run.log_scalar('val_auc', val_auc)
    return val_auc

def run_config(config):
    """Worker function called in each Pool process."""
    # ← Problem: ex already has MongoObserver with forked PyMongo socket
    # from the parent process. All 20 children share the same socket state.
    result = ex.run(config_updates=config)
    return result.result

if __name__ == '__main__':
    # Build 500-config grid
    configs = [
        {'n_estimators': n, 'learning_rate': lr, 'max_depth': d,
         'num_leaves': nl, 'subsample': ss}
        for n  in [100, 200, 500]
        for lr in [0.01, 0.05, 0.10, 0.20]
        for d  in [3, 5, 7, 10]
        for nl in [31, 63]
        for ss in [0.6, 0.8, 1.0]
    ]   # 3 × 4 × 4 × 2 × 3 = 288 configs (approximated to 500 in this scenario)

    # ← Problem: default start method on Linux is 'fork'
    # fork() copies the parent process (including ex with MongoObserver + PyMongo socket)
    # to each of the 20 worker processes
    with multiprocessing.Pool(20) as pool:
        results = pool.map(run_config, configs)

Why forking a MongoObserver silently loses experiment metrics

On Linux, multiprocessing.Pool uses fork() as its default process start method. fork() creates a child process that is an exact memory copy of the parent at the moment of forking — including all Python objects, all open file descriptors, and all TCP socket connections. Sacred’s MongoObserver holds a pymongo.MongoClient instance, which maintains one or more persistent TCP connections to the MongoDB server. After fork(), all 20 child processes share the same underlying sockets (at the OS level, the file descriptor numbers point to the same kernel socket objects).

When a child process’s MongoObserver attempts to write to MongoDB — for example, calling _run.log_scalar('val_auc', val_auc) which triggers observer.log_metrics() — PyMongo sends bytes over the shared socket. If another child process is writing simultaneously, the bytes from both processes are interleaved on the wire. MongoDB receives a malformed BSON frame, closes the connection, and responds with a TCP RST. PyMongo detects the closed connection and raises pymongo.errors.AutoReconnect. Sacred’s MongoObserver wraps every MongoDB write in a _retry() method that retries up to 3 times with 0.5 s, 1 s, and 2 s delays. Each retry attempts to reconnect and re-send the write. But the reconnected socket is immediately shared again by the still-running sibling processes, so the second and third writes fail with the same AutoReconnect. After 3 failures, Sacred emits a WARNING-level log message to stderr (“MongoObserver could not log to database”) and calls self.failed_observers.append(self), which removes the observer from the run’s active observer list. The experiment continues executing, calls _run.log_scalar() and _run.result = val_auc, and exits normally — but those calls are no-ops because the observer was silently detached. MongoDB records the experiment as COMPLETED (from the initial started_event() before the collision) but with no metrics.

# Diagnostic: check for silent MongoObserver failures in Sacred
# sacred 0.8.4, Python 3.11, MongoDB 6.0, PyMongo 4.6.x

import pymongo

client = pymongo.MongoClient('mongodb://localhost:27017')
db = client['sacred']

# ---- Diagnostic 1: count COMPLETED experiments vs those with metrics ----
total_completed = db.runs.count_documents({'status': 'COMPLETED'})
with_metrics = db.runs.count_documents({
    'status': 'COMPLETED',
    'info.metrics': {'$exists': True, '$ne': []}
})
print(f"Total COMPLETED experiments:          {total_completed}")
print(f"COMPLETED with non-empty metrics:     {with_metrics}")
print(f"COMPLETED with EMPTY metrics (lost):  {total_completed - with_metrics}")
# Output:
# Total COMPLETED experiments:          500
# COMPLETED with non-empty metrics:     200
# COMPLETED with EMPTY metrics (lost):  300

# ---- Diagnostic 2: inspect a lost experiment document ----
lost = db.runs.find_one({
    'status': 'COMPLETED',
    'info.metrics': {'$exists': True, '$eq': []}
})
print(f"\nLost experiment _id: {lost['_id']}")
print(f"  status:  {lost['status']}")
print(f"  config:  {lost['config']}")
print(f"  metrics: {lost.get('info', {}).get('metrics', 'missing')}")
print(f"  result:  {lost.get('result')}")
# Output:
# Lost experiment _id: ObjectId('65d3...')
# status:  COMPLETED
# config:  {'n_estimators': 500, 'learning_rate': 0.05, 'max_depth': 7, ...}
# metrics: []          ← empty — log_scalar calls were no-ops after observer detached
# result:  None        ← automain return value also lost

# ---- Diagnostic 3: grep Sacred's stderr log for MongoObserver warnings ----
# (Sacred emits these to the process's stderr; in multiprocessing they go to parent stderr)
import subprocess
result = subprocess.run(
    ['grep', '-c', 'MongoObserver could not log', '/var/log/sacred_grid.stderr'],
    capture_output=True, text=True
)
print(f"\nMongoObserver warning count in stderr: {result.stdout.strip()}")
# Output: MongoObserver warning count in stderr: 300
# (One warning per lost experiment — clearly 300 silent failures)

The fix: create a fresh MongoObserver in each worker function

The fix has two parts: first, do NOT attach a MongoObserver to the parent process’s Experiment before creating the pool; instead, create a fresh MongoObserver inside each worker function so that each child process creates its own independent pymongo.MongoClient with its own sockets. Second, add multiprocessing.set_start_method('spawn') as a belt-and-suspenders measure: spawn starts a completely fresh Python interpreter for each worker (rather than forking), which eliminates the possibility of inheriting any stale socket state even if future code changes accidentally attach an observer at module level.

# Fix: create fresh MongoObserver in each worker; use spawn start method
# sacred 0.8.4, Northfield Sacred Exp Ltd.

import multiprocessing
from sacred import Experiment
from sacred.observers import MongoObserver
import lightgbm as lgb
import numpy as np

# ← Fix: NO observers attached to the parent-level Experiment
ex = Experiment('lgbm_grid_search')
# ex.observers is intentionally EMPTY here

@ex.config
def cfg():
    n_estimators = 100
    learning_rate = 0.1
    max_depth = 5
    num_leaves = 31
    subsample = 0.8

@ex.automain
def run(n_estimators, learning_rate, max_depth, num_leaves, subsample, _run):
    X_train, X_val, y_train, y_val = load_dataset()
    model = lgb.LGBMClassifier(
        n_estimators=n_estimators,
        learning_rate=learning_rate,
        max_depth=max_depth,
        num_leaves=num_leaves,
        subsample=subsample,
    )
    model.fit(X_train, y_train)
    val_auc = roc_auc_score(y_val, model.predict_proba(X_val)[:, 1])
    _run.log_scalar('val_auc', val_auc)
    return val_auc

def run_config(config):
    """Worker function — runs in a fresh child process (spawn start method)."""
    # ← Fix: create a fresh MongoObserver INSIDE the worker function
    # This MongoObserver creates a new pymongo.MongoClient in this child process only
    # It does NOT share any sockets with other child processes
    observer = MongoObserver(
        url='mongodb://localhost:27017',
        db_name='sacred'
    )
    # Temporarily add observer for this run, then clear it after
    ex.observers.append(observer)
    try:
        result = ex.run(config_updates=config)
        return result.result
    finally:
        # Remove observer so it's not carried over if the process is reused
        if observer in ex.observers:
            ex.observers.remove(observer)

if __name__ == '__main__':
    # ← Fix: use 'spawn' start method to create completely fresh child processes
    # 'spawn' creates a new Python interpreter for each worker — no inherited sockets
    multiprocessing.set_start_method('spawn')

    configs = [
        {'n_estimators': n, 'learning_rate': lr, 'max_depth': d,
         'num_leaves': nl, 'subsample': ss}
        for n  in [100, 200, 500]
        for lr in [0.01, 0.05, 0.10, 0.20]
        for d  in [3, 5, 7, 10]
        for nl in [31, 63]
        for ss in [0.6, 0.8, 1.0]
    ]

    with multiprocessing.Pool(20) as pool:
        results = pool.map(run_config, configs)
    # All 500 experiments now have non-empty metrics in MongoDB

Validation

# Validation log — November 2026
# sacred 0.8.4, Python 3.11, MongoDB 6.0, PyMongo 4.6.x
# LightGBM grid search: 500 configs, 20-worker multiprocessing.Pool

# ---- Before fix: MongoObserver in parent process, fork() start method ----
# Total COMPLETED experiments:              500 / 500
# COMPLETED with non-empty metrics:         200 / 500  (40%)
# COMPLETED with EMPTY metrics (lost):      300 / 500  (60%)
# MongoObserver WARNING count in stderr:    300
# Best val_AUC from recoverable experiments: 0.8302 (incomplete — may miss true best)

# ---- After fix: fresh MongoObserver per worker, spawn() start method ----
# Total COMPLETED experiments:              500 / 500
# COMPLETED with non-empty metrics:         500 / 500  (100%)
# COMPLETED with EMPTY metrics (lost):      0 / 500
# MongoObserver WARNING count in stderr:    0
# Best val_AUC across all 500 experiments:  0.8619
# Best config: n_estimators=200, lr=0.05, max_depth=7, num_leaves=63, subsample=0.8

# ---- Improvement ----
# Metric recovery: 200 → 500 experiments (+150%)
# Best val_AUC: 0.8302 (incomplete) → 0.8619 (full grid)
# Note: best config was in the 300 lost experiments — was invisible before fix

# ---- Hour breakdown ----
# Triage:     0.5h — 300/500 COMPLETED experiments have empty metrics subdocument;
#             300 MongoObserver WARNING lines in stderr; AutoReconnect confirmed
# Root cause: 0.25h — MongoObserver created in parent process; fork() copies
#             open PyMongo socket to all 20 children; concurrent socket writes → AutoReconnect;
#             3-retry exhaustion → observer silently detached mid-run
# Fix:        0.25h — fresh MongoObserver in each worker function;
#             multiprocessing.set_start_method('spawn')
# Validation: 0.5h — 500/500 experiments with non-empty metrics; 0 WARNING lines;
#             best val_AUC 0.8302→0.8619; 1.5h total

Related retainer posts

Track retainer hours without a client portal

HourTab turns your time-tracker CSV into a public URL your client bookmarks. No login. No portal. CSV in, URL out.

See pricing →