Worker drops jobs intermittently: startup race, env drift, schema skew

The reported symptom is almost always the same sentence: 'the worker is flaky, sometimes it processes jobs and sometimes it doesn't, and the logs don't really say why.' That sentence hides three separate bugs that compound. We rank them by the order we actually find them, not by how loud they are in the log:

• 1. Startup race. Worker container comes up before Redis (or the backend that populates Redis) is ready: accepting connections and done loading its data. Retries are missing or set to a value that gives up in under 2 seconds. Roughly 60% of the incidents we see.
• 2. Environment variable drift. The backend sets REDIS_URL, the worker reads CACHE_URL, and with CACHE_URL unset the worker falls back to its default, redis://localhost:6379. Inside a container, localhost is the container's own network namespace (on Kubernetes, the whole pod's), so unless something there listens on 6379, every attempt fails. The error has the race's shape, Error <n> connecting to localhost:6379, but names localhost instead of the service; the number and wording vary (111, Connection refused, or 99, Cannot assign requested address, where /etc/hosts lists ::1 but the loopback has no IPv6, as on Docker engines before 26). It looks intermittent when only one code path, one worker type, or the pods of one rollout read the wrong name. Roughly 25%.
• 3. Schema skew after a rename. Someone renamed job_id to id on the producer side and missed one .get('job_id') on the consumer. .get returns None instead of raising, the code downstream can fail on the None, the worker's outer except Exception swallows that failure, the job is skipped, and no error is logged. Roughly 15%, and the hardest to see.

The cause everyone blames first, and which is almost never it: 'Redis is slow' or 'the worker needs more memory'. We have not once found this to be the actual cause in this failure shape. If you are already sizing up the Redis instance, stop and read the next section first.

There is also a fourth cause that shows up as a hard PermissionError: [Errno 13] Permission denied: '/app/output/result.json' when the worker finally does try to write. It is real, but it names the file it could not write. This guide is about the three that get mistaken for each other.

Before you restart, redeploy, or scale anything, capture the current state. Restarting the worker throws away the evidence that tells you which of the three you are dealing with. On docker compose, snapshot the worker's, the backend's and Redis's logs to disk. On Kubernetes, capture the worker pod's status, its logs and kubectl logs --previous (in CrashLoopBackOff both return the same crashed container), kubectl describe pod for its events, and the same for the Redis pod. Do this first.

# capture before you touch anything. Run the docker compose lines or the k8s
# lines, not both: both write the same files.
docker compose logs --no-color --no-log-prefix --timestamps worker  > /tmp/worker.log
docker compose logs --no-color --no-log-prefix --timestamps backend > /tmp/backend.log
docker compose logs --no-color --no-log-prefix --timestamps redis   > /tmp/redis.log

# k8s equivalent. The pod status first: CrashLoopBackOff means it is still
# failing. RESTARTS above 0 with STATUS Running is not a verdict on its own:
# run kubectl get pod again a little over five minutes later (the restart
# backoff caps at five minutes by default). STATUS still Running with the same
# count means it failed and recovered, which is what the race looks like; a
# grown count, or STATUS CrashLoopBackOff at that second look, means it is
# still failing. Read Last State and Events in the describe output: Reason
# Error with an exit code other than 137 or 143, seconds after Started, fits
# the race or the drift (the host in the log decides); OOMKilled, exit 137 or
# 143, or a Liveness probe failed event does not, unless the worker's own
# liveness probe checks Redis. Init:0/1 means a readiness gate is still
# waiting, and Init:Error or Init:CrashLoopBackOff that it gave up (timed out,
# or the script failed); read it with:
#   kubectl logs -n jobs worker-7c9d8f5b6-x2k4m -c <init container name>
kubectl get pod -n jobs worker-7c9d8f5b6-x2k4m                      > /tmp/worker-pod.txt
kubectl describe pod -n jobs worker-7c9d8f5b6-x2k4m                 > /tmp/worker-describe.txt
# The current container, plus the previous one if it crashed. --previous fails
# and leaves an empty file when nothing has restarted, and in CrashLoopBackOff
# both return the same crashed container, so the cmp line empties the copy.
kubectl logs -n jobs worker-7c9d8f5b6-x2k4m --timestamps            > /tmp/worker.log
kubectl logs -n jobs worker-7c9d8f5b6-x2k4m --timestamps --previous > /tmp/worker-previous.log
cmp -s /tmp/worker.log /tmp/worker-previous.log && : > /tmp/worker-previous.log
# Redis too (redis-0 here; use your Redis pod and its namespace). kubectl logs
# returns one container instance (the crashed one while it is in
# CrashLoopBackOff), so a Redis restart shows in its pod status, its describe
# output and --previous. If the pod was recreated instead, only an AGE younger
# than the incident shows it.
kubectl get pod -n jobs redis-0                                     > /tmp/redis-pod.txt
kubectl describe pod -n jobs redis-0                                > /tmp/redis-describe.txt
kubectl logs -n jobs redis-0 --timestamps                           > /tmp/redis.log
kubectl logs -n jobs redis-0 --timestamps --previous                > /tmp/redis-previous.log

# then the discriminating check: which host does each connection error name,
# how often (lines, not attempts), and did Redis report it was still loading?
sort /tmp/worker*.log | grep -E 'Error .*connecting to ' | grep -oE 'connecting to [^ ]+:[0-9]+' | sort | uniq -c
sort /tmp/worker*.log | grep -c 'Redis is loading'
# first and last connection error: only in the first seconds, or every attempt?
# (the usual connect-timeout form names no host, so it is matched on its own)
sort /tmp/worker*.log | grep -E 'Error .*connecting to [^ ]+:[0-9]+|Redis is loading|Timeout connecting to server' | sed -n '1p;$p' | uniq

# and compare per-job counts. Match the whole per-job line your worker writes,
# here 'job <id> received' and 'job <id> processed', not a bare word that a
# summary line also contains.
sort /tmp/worker*.log | tr -d '\r' | grep -cxE '.*job [^ ]+ received'
sort /tmp/worker*.log | tr -d '\r' | grep -cxE '.*job [^ ]+ processed'

Snapshot first, grep second. Anything that recreates the container (`docker compose up --force-recreate worker`, or a `down` followed by an `up`) discards the previous container's stdout under the default json-file driver. A plain `restart` keeps the log file, but it costs you the live process state that made the failure reproducible.

The grep output tells you which cause you have, in this order:

• If the connection errors name the service (redis:6379), whatever their wording (Connection refused, Connect call failed, Temporary failure in name resolution), or Redis reports it is loading the dataset, and they stop within the first seconds, it is the startup race. The worker gave up before Redis was ready. If they never stop, Redis itself is down or unreachable, unless they are LOADING replies, which mean Redis is up but still loading its data: size the gate (Compose start_period, the initContainer timeout on Kubernetes) and the client's retry window to the load, but first rule out a Redis that was killed mid-load. On Compose that shows as two Redis is starting lines in its log with no Ready to accept connections between them; on Kubernetes, as a Redis restart inside the incident window. OOMKilled or Exit Code 137 in its Last State means it needs more memory. A probe that killed it mid-load shows as a Liveness probe failed or Startup probe failed event (events are kept for an hour by default) or as Received shutdown signal during loading near the end of its --previous log, and needs a probe whose failureThreshold times periodSeconds covers the load. Neither is fixed by a longer gate. If the worker exits after its first error, timing proves nothing: on Kubernetes read the pod status twice, a little over five minutes apart, or on Compose compare the worker's error timestamps with the Ready to accept connections line in Redis's log.
• If the connection error names localhost:6379 (or 127.0.0.1, ::1, None, or a host that matches none of your Redis endpoints) instead of the service, whatever its number or wording, it is env drift. The worker never got the right URL and fell back to its default. Unlike the race, it fails on every attempt. With Sentinel or Cluster, errors name the node addresses the client discovered, which can be 127.0.0.1 too: if the URL the worker resolved at boot is right, check what Sentinel or Cluster announces instead.
• A connect timeout usually names no host: redis-py reports it as Timeout connecting to server, and only on Python 3.9 and older can the kernel's own timeout read Error 110 connecting to redis:6379. Connection timed out. instead. Either form on every attempt points at NetworkPolicy, a firewall, or the URL the worker resolved. If nothing errors and the worker received no jobs at all, check which URL the worker resolved at boot (a drifted URL can reach a different Redis, such as something listening on 6379 inside the same Kubernetes pod) and whether the backend had queued anything before the worker started.
• If the connection logs are clean, the worker is clearly consuming messages, but the count of 'processed' log lines is lower than the count of 'received' lines and no error accounts for the difference, it is schema skew. The worker is silently dropping jobs whose payload does not match its expected shape. Confirm it before fixing: inspect one dropped job's payload keys, or log the exception in the broad except for one run.

flowchart TD
  A[Worker logs captured] --> B{"Error ... connecting to host:port,<br/>Timeout connecting to server,<br/>or Redis is loading?"}
  B -- yes --> C{Which host does<br/>the error name?}
  C -->|"your Redis service or LOADING,<br/>first seconds only"| D[Startup race]
  C -->|"your Redis service,<br/>every attempt"| X[Redis down, restarting, unreachable,<br/>or blocked by NetworkPolicy]
  C -->|"LOADING on every attempt"| L[Redis up, still loading:<br/>rule out a mid-load restart,<br/>then size the gate and retries]
  C -->|"none: Timeout connecting to server"| T[NetworkPolicy or firewall,<br/>or the URL the worker resolved]
  C -->|"localhost, 127.0.0.1, ::1, None,<br/>or none of your Redis endpoints"| E[Env var drift]
  C -->|"an address Sentinel or Cluster<br/>announced, URL right at boot"| N[Check what Sentinel<br/>or Cluster announces]
  B -- no --> R{Any jobs<br/>received?}
  R -- no --> S[Check the URL the worker resolved<br/>and when the backend enqueued]
  R -- yes --> F{received count ><br/>processed count?}
  F -- yes --> G[Schema skew, silent drop]
  F -- no --> H[Look at permissions and paths]

Order matters. The race and the drift look alike until you read which host the error names, and both hide the schema skew, because a worker that cannot connect never receives a job. If the log holds a single attempt, timing proves nothing: read the pod status twice, a little over five minutes apart, on Kubernetes, or on Compose compare the worker's error timestamp with Redis's `Ready to accept connections` line. Fix them in the order they surface.

Fix each cause with the smallest change that discriminates against the others. Do not batch the three fixes into one PR; you will not know which one worked, and the next incident will look identical. Ship them separately, verify each one, then move on.

One thing to name explicitly: the tempting single-line fix of adding sleep 15 to the worker's entrypoint 'solves' the startup race in staging and leaves the race in place for production, where a restart or a slower load outlasts any fixed sleep. We have watched this exact patch get merged, celebrated, and then paged the same team six weeks later when Redis restarted during a maintenance window and the sleep was not long enough. The cost of the right fix (a healthcheck plus retry) is roughly 40 lines of yaml and one afternoon. Pay it.

# docker-compose.yml, the readiness gate that actually works
services:
  redis:
    image: redis:7.2-alpine
    healthcheck:
      # redis-cli exits 0 on an error reply such as LOADING, so match the PONG
      test: ["CMD-SHELL", "redis-cli ping | grep -q PONG"]
      interval: 2s
      timeout: 1s
      retries: 15
      start_period: 60s   # size it to how long your dataset takes to load

  backend:
    depends_on:
      redis:
        condition: service_healthy

  worker:
    depends_on:
      backend:
        condition: service_started   # ordering only, see below
      redis:
        condition: service_healthy
    environment:
      REDIS_URL: redis://redis:6379/0    # one name, both sides
    # no sleep, no CACHE_URL fallback

The gate is `condition: service_healthy` plus a real healthcheck on the dependency. A bare `redis-cli ping` passes while Redis is still loading its dataset, because PING gets a LOADING error and redis-cli exits 0 on error replies unless run with -e. `condition: service_started` only waits for the container to start, not for the service in it to be ready, so if the worker must not run before the backend has queued work, give the backend a healthcheck that proves that and gate on `service_healthy` there too, or on `service_completed_successfully` if the backend is a one-shot job that enqueues and exits. If Redis requires a password, set `REDISCLI_AUTH` in the redis service's environment, or the check gets NOAUTH and never passes.

Confirm the fix by running the stack from cold at least ten times in a row and checking that the processed count equals the received count on every run. If nine out of ten pass, you have not fixed it; you have improved it. Race conditions do not get 90% fixed. For deeper patterns on this kind of intermittent K8s failure, we have written up Kubernetes release failure recovery separately.

Is it safe to just add `restart: always` and let the worker crash-loop until Redis is up? It works, but it makes your logs noisier, it costs you real seconds on every boot, and it hides the underlying dependency graph from anyone reading the compose file later. Use a healthcheck. Save restart: always for actual transient failures in steady state.

Does this apply to RabbitMQ, NATS, or Kafka workers too? Yes, the shape is identical. The verbatim error string changes (Connection refused on RabbitMQ; nats: no servers available for connection on NATS, which names no server, so log the URL the worker resolved at boot; NoBrokersAvailable on kafka-python 2.x, which also names no broker, and KafkaTimeoutError: Unable to bootstrap from ..., which names the servers, on 3.x), but the three causes and the fix order are the same. The env var drift bug is especially common on Kafka clients because KAFKA_BROKERS vs BOOTSTRAP_SERVERS is a coin flip in the ecosystem.

Can I skip the healthcheck if I use Kubernetes with readiness probes? No, readiness probes gate traffic to a pod, not startup order between pods. You still need an initContainer or an application-level retry loop for the worker to wait on its dependency. Readiness alone will not save you.

Why not just fix the broad `except Exception: pass` and call it a day? Because removing it in isolation will surface the schema skew as a hard crash on production traffic, and if you have not fixed the startup race first, you will not be able to tell which crash is which. Fix in the order the causes appear at boot: connectivity, config, contract.

How do I stop this from recurring? Three things, in order of ROI: (1) a boot-time assertion in every service that fails fast if a required env var is missing or resolves to localhost, (2) a schema check at the consumer boundary that rejects malformed messages loudly instead of silently, (3) a pre-merge integration test that starts the stack from cold and asserts processed == received on 100 test jobs. That third one is the single highest-value test we recommend for job-processing systems.

What makes this class of failure genuinely hard is not any single one of the three bugs. It is that they compound: the race and the drift both surface as connection errors at boot, so unless you read which host each one names, the drift reads as more of the race, and by the time you have fixed both, the schema skew is dropping the recovery jobs you are firing to catch up. Untangling that under time pressure is where teams get stuck at 2 in the morning.

We have spent a lot of engineering hours in exactly this shape of incident, on Redis, RabbitMQ, and Kafka, across docker compose and Kubernetes. The pattern above is what we run on the call: capture logs first, grep to rank the causes, fix in dependency order, verify with cold-start runs. If you want a second set of eyes on it while it is happening, book a same-day infrastructure review and we will get on a bridge with your on-call engineer inside a few hours and work the sequence together. If the fires are already out and you want the pre-merge integration test and boot-time assertions in place before the next one, our platform reliability engagements cover exactly that.