Make worker startup logging visible, bound dataset downloads, persist blocked list - #139
Open
maximusunc wants to merge 1 commit into
Open
Make worker startup logging visible, bound dataset downloads, persist blocked list#139maximusunc wants to merge 1 commit into
maximusunc wants to merge 1 commit into
Conversation
… blocked list
Three fixes prompted by an arax_pathfinder deployment that picked up no tasks,
emitted no logs at all, and was terminated after ~8 minutes.
Startup logging was silently discarded. setup_logging attached its handlers to
the `shepherd` logger and left root unconfigured, but every worker logged its
startup phase through `logging.getLogger(STREAM)` ("arax.pathfinder") or a bare
`logging.info`. Those names sit outside the `shepherd` namespace, so records
reached a handler-less root and were dropped by logging's lastResort fallback,
which only emits WARNING+. Dataset downloads, pool sizing and poll-loop errors
were invisible, and a worker wedged before `get_tasks` looked exactly like a
healthy idle one.
Handlers now live on root, and `shepherd` sets only its level and propagates to
them -- so our logging still emits at DEBUG, third-party libraries stay quiet
below WARNING (httpx logs a line per request at INFO), nothing double-logs, and
pytest's caplog keeps working. Workers get their logger from a new
`get_worker_logger` helper that namespaces the stream name, applied across all
21 workers plus the two module-named loggers in data_download and db.
Dataset downloads had no timeout. urllib defaults to none, so a connection that
opens and then stalls -- an egress proxy that swallows the request, a server
that accepts and never responds -- hung worker startup indefinitely, before the
poll loop and before any heartbeat, without ever crashing. They are now bounded
by DATASET_DOWNLOAD_TIMEOUT_SEC (default 60), applied per socket operation so a
multi-GB file still downloads for as long as it keeps making progress. A stall
part-way through the body raises TimeoutError straight out of resp.read()
rather than wrapped in URLError, so it gets its own handler and a message
naming the likely cause.
The ARAX blocked-concept list was written to the worker's working directory,
which is the container's writable layer -- discarded on every restart, so each
new pod re-fetched it from GitHub during startup on that same invisible code
path. It now lives alongside the pathfinder sqlite databases on the mounted
volume, reached through an `arax_blocked_list_path` helper that keeps the
download and read sites in agreement. It is only fetched when absent, so
delete it from the volume to pick up an updated upstream list, and the volume
must be writable for the first run (or the file preloaded).
Also documents the deployment trap behind the original incident: the
"already present" check is an exact match on ARAX_PATHFINDER_DBS_DIR (a
relative path by default, resolved against /app) plus the tier-versioned
filenames, so a mount path or ARAX_PATHFINDER_TIER_VERSION that disagrees
re-downloads the databases onto ephemeral storage instead of using the
mounted copies -- which is what got the pod evicted.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01VqmpAvRW688q7KqX9sQjGX
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Three fixes prompted by an arax_pathfinder deployment that picked up no tasks, emitted no logs at all, and was terminated after ~8 minutes.
Startup logging was silently discarded. setup_logging attached its handlers to the
shepherdlogger and left root unconfigured, but every worker logged its startup phase throughlogging.getLogger(STREAM)("arax.pathfinder") or a barelogging.info. Those names sit outside theshepherdnamespace, so records reached a handler-less root and were dropped by logging's lastResort fallback, which only emits WARNING+. Dataset downloads, pool sizing and poll-loop errors were invisible, and a worker wedged beforeget_taskslooked exactly like a healthy idle one.Handlers now live on root, and
shepherdsets only its level and propagates to them -- so our logging still emits at DEBUG, third-party libraries stay quiet below WARNING (httpx logs a line per request at INFO), nothing double-logs, and pytest's caplog keeps working. Workers get their logger from a newget_worker_loggerhelper that namespaces the stream name, applied across all 21 workers plus the two module-named loggers in data_download and db.Dataset downloads had no timeout. urllib defaults to none, so a connection that opens and then stalls -- an egress proxy that swallows the request, a server that accepts and never responds -- hung worker startup indefinitely, before the poll loop and before any heartbeat, without ever crashing. They are now bounded by DATASET_DOWNLOAD_TIMEOUT_SEC (default 60), applied per socket operation so a multi-GB file still downloads for as long as it keeps making progress. A stall part-way through the body raises TimeoutError straight out of resp.read() rather than wrapped in URLError, so it gets its own handler and a message naming the likely cause.
The ARAX blocked-concept list was written to the worker's working directory, which is the container's writable layer -- discarded on every restart, so each new pod re-fetched it from GitHub during startup on that same invisible code path. It now lives alongside the pathfinder sqlite databases on the mounted volume, reached through an
arax_blocked_list_pathhelper that keeps the download and read sites in agreement. It is only fetched when absent, so delete it from the volume to pick up an updated upstream list, and the volume must be writable for the first run (or the file preloaded).Also documents the deployment trap behind the original incident: the "already present" check is an exact match on ARAX_PATHFINDER_DBS_DIR (a relative path by default, resolved against /app) plus the tier-versioned filenames, so a mount path or ARAX_PATHFINDER_TIER_VERSION that disagrees re-downloads the databases onto ephemeral storage instead of using the mounted copies -- which is what got the pod evicted.
Claude-Session: https://claude.ai/code/session_01VqmpAvRW688q7KqX9sQjGX