<@ULVA73B9P> I have process worker, which is runni...
# ask-marvin
r
@Marvin I have process worker, which is running and periodically calling
Starting run of 'get_and_submit_flow_runs'.
It is also executing flows, but queue in pool has status "Not Ready". Why ?
m
thought for 75.3 seconds
Not Ready
for a work queue usually does not mean it cannot run work. If your process worker is: - running - logging
Starting run of 'get_and_submit_flow_runs'
- and actually executing flow runs then the queue status is most likely just a readiness/heartbeat indicator, not an execution blocker. What
Not Ready
means
A queue is marked
Not Ready
when Prefect thinks it has not been polled recently enough. In Prefect 3.x, this is based on the queue’s
last_polled
timestamp. So this status generally means: - Prefect UI/server believes the queue has not been checked recently - not that the queue is unusable - not that runs cannot be submitted Why this can happen even while flows are running A few common reasons: 1. Polling timestamp update lag The worker may be polling, but the server-side update to
last_polled
can lag a bit. 2. Race/timing issue The service that marks queues `Ready`/`Not Ready` runs on its own interval. It can temporarily mark a queue
Not Ready
even though a worker is actively polling. 3. Background/server load If the server is busy, status updates may be delayed while actual work submission still succeeds. 4. Worker is polling the pool, but not that exact queue as expected Less common, but worth checking if you have multiple queues in the same pool. Important point If runs are being picked up and executed, the
Not Ready
status is usually cosmetic/observational rather than a real problem. What to check - Confirm the worker is pointed at the expected work pool / queue - Check whether the queue status flips back to
Ready
after a little time - If self-hosted, inspect server health/logs for delays in background services - If this stays
Not Ready
for a long time, check for clock skew or server load issues If you’re self-hosting There is a timeout used to decide when a queue becomes
Not Ready
, and a periodic service reevaluates queue readiness. If your environment is slow or under load, that can make this more visible. If you want, I can help you narrow it down further. Please share: - whether this is Prefect Cloud or self-hosted server - your Prefect version - whether you are using one queue or multiple queues in that pool
r
@Marvin slef hosted server, 3.7.1, one queue
m
thought for 11.7 seconds
Thanks — with self-hosted Prefect 3.7.1 and one queue, this is most likely a status/heartbeat timing issue rather than a real execution issue, especially since the worker is actually running flows. What’s happening In self-hosted Prefect, the queue readiness status is derived from when the server thinks the queue was last polled. A server service periodically marks queues
Not Ready
if that poll timestamp looks too old. So you can get this situation: - worker is polling - runs are being submitted/executed - but the UI still shows the queue as
Not Ready
That usually points to delayed or missed updates of the queue’s
last_polled
status on the server side. Most likely causes in your case 1. Server-side timing lag The worker poll happened, but the server had not yet updated the queue heartbeat/readiness state. 2. Foreman/background services delay In self-hosted mode, the service that evaluates queue readiness can get slightly out of sync with the worker polling cycle. 3. A bug / edge case in 3.7.1 Since execution is working, this may just be an inaccurate UI/server status state rather than a scheduling failure. What I’d check first 1. Worker command / configuration Make sure the worker is definitely attached to the intended pool. You can inspect the worker and pool in the UI or via CLI. 2. Server logs Look for errors in the API/server process around work queues, background services, or foreman services. 3. Time synchronization Ensure the machine running the server and the machine running the worker have synchronized clocks. Even modest clock skew can affect “last polled” logic. 4. Does the status ever flip to Ready? If it occasionally flips back, that strongly suggests timing lag rather than configuration error. Likely conclusion If: - there is only one queue, - flows are executing, - and the worker keeps polling, then the
Not Ready
label is probably safe to ignore operationally unless you also see missed scheduled runs. Possible next step Since you're on 3.7.1, I’d also consider upgrading to the latest 3.x release in case this has already been improved. You can check current release notes here: Prefect releases If you want, I can help you with a more precise diagnosis by checking: - the exact worker startup command - relevant server logs - whether this is running via Docker / Kubernetes / bare metal
r
@Marvin worker is started using
prefect worker start --pool default_pool
. In server log I can see :
15:42:22.575 | INFO | uvicorn.access - 10.212.143.210:0 - "POST /api/work_pools/default_pool/get_scheduled_flow_runs HTTP/1.1" 200
But also :
Copy code
15:43:09.191 | DEBUG | uvicorn.error - % sending keepalive ping
15:43:09.191 | DEBUG | uvicorn.error - > PING 8d bc db 4c [binary, 4 bytes]
15:43:09.192 | DEBUG | uvicorn.error - < PONG 8d bc db 4c [binary, 4 bytes]
15:43:09.192 | DEBUG | uvicorn.error - % received keepalive pong
Field last_polled in pg work_queue table was updated before 4 hours.
m
thought for 146.8 seconds
Thanks — this is much more specific now. Given: - worker started with
prefect worker start --pool default_pool
- server logs show successful
POST /api/work_pools/default_pool/get_scheduled_flow_runs
- flows are actually executing - but
work_queue.last_polled
has not changed for 4 hours - queue stays
Not Ready
this looks like a server-side state update problem, not a worker polling problem. Key point The worker is polling the pool successfully. The broken part is that the server is not updating the queue heartbeat (
work_queue.last_polled
) after those polls. What should normally happen When the worker calls:
Copy code
/api/work_pools/default_pool/get_scheduled_flow_runs
Prefect should: 1. load the queue(s) in that pool 2. return scheduled runs 3. update
work_queue.last_polled
4. if needed, change the queue status back to
Ready
Since step 1 and 2 are clearly happening, but 3 is not, the issue is likely in the server background bookkeeping path. Most likely explanation in your setup In Prefect 3.7.1, the
last_polled
update is done asynchronously on the server side after the polling request. So you can have: - API request succeeds with
200
- worker gets runs and executes them - but the follow-up queue status update never happens That strongly suggests one of these: 1. Background/docket task is not executing properly 2. A bug in 3.7.1 related to queue poll recording 3. A server process/configuration issue where queue poll updates are not being committed Why I don’t think this is worker misconfiguration Your worker command is valid, and without
--work-queue
, it should poll all queues in that pool. With one queue only, that should definitely include the default queue. I verified the CLI syntax for
prefect worker start
and
--pool
is correct. What I would check next 1. Confirm whether
status
is also stale in DB
Please check the row in Postgres for that queue:
Copy code
sql
select id, name, status, last_polled, work_pool_id
from work_queue
where name = 'default';
If
status = NOT_READY
and
last_polled
is old, that confirms the server is not recording polls. 2. Check server container/process logs for background-task errors Search the API/server logs for terms like: -
mark_work_queues_ready
-
record_work_queue_polls
-
docket
-
exception
-
traceback
If you can grep logs:
Copy code
bash
grep -Ei "mark_work_queues_ready|record_work_queue_polls|docket|traceback|exception" <server-log-file>
3. Check if this is reproducible after server restart If you restart the Prefect server/API process, does
last_polled
begin updating again for a while? That would support a stuck background task/service state. 4. Check clock sync Since this is self-hosted, make sure the server host and worker host clocks are synced. This is less likely here because
last_polled
is not updating at all, but still worth checking. 5. Upgrade from 3.7.1 if possible This really smells like a bug/edge case in that release. Since actual scheduling works, but queue metadata does not, upgrading to the latest 3.x is a very reasonable next step. Release notes: Prefect releases My current conclusion Based on everything you shared, I would treat this as: - not an operational queue failure - very likely a bug or broken server-side queue poll bookkeeping in 3.7.1 Because: - polling endpoint is hit - response is
200
- flows run - DB
last_polled
stays stale That combination should not happen in the healthy path. Suggested practical next action If this is not causing missed runs, the fastest path is: 1. ignore the
Not Ready
label temporarily 2. upgrade server + worker to the latest Prefect 3.x 3. re-check whether
work_queue.last_polled
starts updating If you want, I can help you with a targeted diagnostic checklist for your deployment style: - Docker Compose - Kubernetes - systemd / bare metal
If you tell me how your self-hosted server is deployed, I can suggest exactly which process/log/component to inspect.
r
@Marvin Prefect is in local OCP cluster. Here is grep from logs : grep -Ei "mark_work_queues_ready|record_work_queue_polls|docket|traceback|exception" prefect-background-68c9c46cff-6qfm9-prefect-background.log 140050.938 | WARNING | docket.worker - Redis connection error in cancellation listener, reconnecting... 150051.949 | WARNING | docket.worker - Redis connection error in cancellation listener, reconnecting... grep -Ei "mark_work_queues_ready|record_work_queue_polls|docket|traceback|exception" prefect-api-77c47ddbd8-zwckt-prefect.log 140217.915 | WARNING | docket.worker - Redis connection error in cancellation listener, reconnecting... 150218.927 | WARNING | docket.worker - Redis connection error in cancellation listener, reconnecting...
m
thought for 17.8 seconds
That log is very suggestive. Short answer: your queue is likely
Not Ready
because the server-side docket/Redis background path is unhealthy, so the poll bookkeeping is not being recorded even though the worker can still fetch and execute runs. The important part is this warning:
Copy code
Redis connection error in cancellation listener, reconnecting...
from both: -
prefect-background
-
prefect-api
Why this matters In your case, the worker’s polling request reaches the API and returns
200
, so flow retrieval works. But updating queue readiness /
last_polled
is a server-side background operation. If the background infrastructure that relies on Redis/docket is having connection problems, Prefect can still: - accept API requests - return scheduled flow runs - let workers execute flows while failing to update queue metadata like
last_polled
. That matches your symptoms very closely. What I think is happening Likely sequence: 1. worker calls:
Copy code
/api/work_pools/default_pool/get_scheduled_flow_runs
2. API returns runs successfully 3. API/background tries to enqueue or process the queue-poll bookkeeping 4. Redis/docket is unhealthy or intermittently disconnected 5.
work_queue.last_polled
never gets updated 6. Foreman later sees stale
last_polled
and marks queue
Not Ready
Important nuance The specific log mentions the cancellation listener, not explicitly
mark_work_queues_ready
, so it does not prove that every docket function is broken. But it does prove Redis connectivity problems in the components responsible for background coordination, and that is enough to make this the primary suspect. What to check next in OCP 1. Check Redis health first Inspect the Redis pod/service that Prefect uses. Look for: - restarts - readiness/liveness failures - connection refusals - OOMKilled - network policy issues - DNS/service resolution issues Typical OCP checks:
Copy code
bash
oc get pods -n <namespace>
oc describe pod <redis-pod> -n <namespace>
oc logs <redis-pod> -n <namespace>
oc get svc -n <namespace>
If using a StatefulSet:
Copy code
bash
oc get statefulset -n <namespace>
oc describe statefulset <redis-sts> -n <namespace>
2. Verify Prefect points to the correct Redis endpoint Check the Prefect API/background env vars and confirm Redis URL/host/port are correct. For example, inspect deployment env:
Copy code
bash
oc describe deployment prefect-api -n <namespace>
oc describe deployment prefect-background -n <namespace>
Look for Redis-related settings. Depending on your setup, these may be explicit env vars or chart values. 3. Check whether API/background pods can reach Redis From the Prefect pods, test DNS/connectivity to the Redis service. If your image has shell tools:
Copy code
bash
oc rsh <prefect-api-pod> -n <namespace>
Then test resolution/connectivity to the Redis hostname used in config. Even a simple:
Copy code
bash
getent hosts <redis-service-name>
or similar can help if available. 4. Check for intermittent network issues Because the warning says
reconnecting
, this may be intermittent rather than fully down. In OCP, possible causes: - NetworkPolicies - service endpoint flapping - pod rescheduling - short Redis timeouts - overloaded Redis pod 5. Restarting Prefect pods may temporarily clear it Not a root fix, but if the docket workers re-establish a clean Redis connection after restart, you may see
last_polled
begin updating again. What I’d expect after fixing Redis/docket Once Redis connectivity is stable: -
work_queue.last_polled
should start updating again - queue status should return to
Ready
-
Not Ready
should disappear without changing the worker command Why this fits better than other theories If this were: - wrong worker pool config → flows likely would not run - wrong queue selection → with one queue, unlikely - UI-only bug → DB
last_polled
would still update - worker issue → API poll requests would not be visible
But your evidence shows: - worker is healthy - API endpoint is hit - DB field is stale - docket/Redis warnings exist That points most strongly to server background state sync failing due to Redis issues. Recommended next action order 1. stabilize Redis connectivity in OCP 2. restart
prefect-api
and
prefect-background
after Redis is healthy 3. watch
work_queue.last_polled
in Postgres 4. confirm queue flips to
Ready
Useful references - Prefect server repo/releases: Prefect releases - Prefect docs home: Prefect docs If you want, I can help you build a very focused OCP troubleshooting checklist for: - Prefect API/background deployments - Redis service/endpoints - network policy checks - exact
oc
commands to validate connectivity end-to-end
r
@Marvin Looks, that some problem is in backgound services. But: 1. There is no error in background services log 2. I assume that some functionalities of background services are OK 3. There some reconnectings to Redis, but they occures once per hour Question : How to find real cause in background services ? Or how to turn on detailed logging. I have DEBUG on, but current detail is not sufficient. Is it possible to turn DEBUG logs for sqlalchemy, readis connections, etc .. ?
m
thought for 130.0 seconds
Yes — you can turn on much more detailed logging, including for SQLAlchemy and Redis-related loggers. And based on what you’ve found so far, that’s the right next step. Big picture Prefect 3.x uses standard Python logging, so there are 2 practical ways to get more detail: 1. set environment variables for specific loggers 2. mount a custom
logging.yml
and point Prefect to it For OCP/Kubernetes, env vars are usually the easiest first step. Recommended first pass For both
prefect-api
and
prefect-background
, add these env vars:
Copy code
yaml
- name: PREFECT_LOGGING_LEVEL
  value: "DEBUG"
- name: PREFECT_SERVER_LOGGING_LEVEL
  value: "DEBUG"
- name: PREFECT_INTERNAL_LOGGING_LEVEL
  value: "DEBUG"

- name: PREFECT_API_DATABASE_ECHO
  value: "true"

- name: PREFECT_LOGGING_LOGGERS_SQLALCHEMY_ENGINE_LEVEL
  value: "INFO"
- name: PREFECT_LOGGING_LOGGERS_SQLALCHEMY_POOL_LEVEL
  value: "DEBUG"

- name: PREFECT_LOGGING_LOGGERS_DOCKET_LEVEL
  value: "DEBUG"
- name: PREFECT_LOGGING_LOGGERS_DOCKET_WORKER_LEVEL
  value: "DEBUG"

- name: PREFECT_LOGGING_LOGGERS_REDIS_LEVEL
  value: "DEBUG"

- name: PREFECT_LOGGING_LOGGERS_PREFECT_SERVER_LEVEL
  value: "DEBUG"
- name: PREFECT_LOGGING_LOGGERS_PREFECT_SERVER_SERVICES_LEVEL
  value: "DEBUG"
- name: PREFECT_LOGGING_LOGGERS_PREFECT_SERVER_SERVICES_FOREMAN_LEVEL
  value: "DEBUG"

- name: PREFECT_LOGGING_LOGGERS_UVICORN_LEVEL
  value: "DEBUG"
- name: PREFECT_LOGGING_LOGGERS_FASTAPI_LEVEL
  value: "DEBUG"
Why these matter -
PREFECT_API_DATABASE_ECHO=true
turns on SQL statement logging -
sqlalchemy.engine
shows executed SQL -
sqlalchemy.pool
shows DB connection pool behavior -
docket
/
docket.worker
should increase background-task coordination detail -
redis
may expose connection retries / disconnect patterns -
foreman
is directly relevant because it marks queues
Not Ready
Very important note
PREFECT_API_DATABASE_ECHO=true
can generate a lot of logs. I’d use it temporarily. What to look for after enabling this You want to catch the path around queue polling and queue status recording. Specifically, after a request like:
Copy code
POST /api/work_pools/default_pool/get_scheduled_flow_runs
look for: - SQL
UPDATE
on
work_queue
- any exception around queue poll recording - any docket task scheduling/execution messages - any Redis publish/subscribe or reconnect warnings near the same timestamp What may be happening A very plausible failure mode is: - API gets the poll request - it schedules background bookkeeping - no visible exception reaches standard logs - the bookkeeping task gets dropped/stalled/retried silently enough that you only see the stale queue So increasing
docket
,
redis
, and
sqlalchemy
logs is the best way to expose the missing link. If env vars are not enough Then use a custom logging config. You can mount a
logging.yml
and set:
Copy code
yaml
- name: PREFECT_LOGGING_SETTINGS_PATH
  value: "/etc/prefect/logging.yml"
Example minimal custom config: ```yaml version: 1 disable_existing_loggers: false formatters: standard: (): prefect.logging.formatters.PrefectFormatter format: "%(asctime)s.%(msecs)03d | %(levelname)-7s | %(name)s - %(message)s" datefmt: "%H:%M:%S" handlers: console: class: prefect.logging.handlers.PrefectConsoleHandler formatter: standard stream: ext://sys.stderr loggers: prefect.server: level: DEBUG handlers: [console] propagate: false prefect.server.services: level: DEBUG handlers: [console] propagate: false prefect.server.services.foreman: level: DEBUG handlers: [console] propagate: false docket: level: DEBUG handlers: [console] propagate: false docket.worker: level: DEBUG handlers: [console] propagate: false redis: level: DEBUG handlers: [console] propagate: false sqlalchemy.engine: level: INFO handlers: [console] propagate: false sqlalchemy.pool: level: DEBUG
handlers: [console] propagate: false uvicorn: level: DEBUG handlers: [console] propagate: false root: level: INFO handlers: [console] ``` Good targeted debugging strategy Rather than turning on everything forever, I’d do this in stages: Stage 1 Enable: -
PREFECT_API_DATABASE_ECHO=true
-
sqlalchemy.engine=INFO
-
docket.worker=DEBUG
-
redis=DEBUG
-
prefect.server.services.foreman=DEBUG
Stage 2 Trigger or wait for one worker poll, then inspect: - whether there is an
UPDATE work_queue ... last_polled=...
- whether any background task was scheduled/executed - whether Redis errors happen at the same moment Stage 3 If still unclear, use full custom
logging.yml
Answering your specific question directly
Is it possible to turn DEBUG logs for sqlalchemy, readis connections, etc .. ?
Yes, absolutely: - SQLAlchemy:
PREFECT_API_DATABASE_ECHO=true
, plus logger levels for
sqlalchemy.engine
and
sqlalchemy.pool
- Redis: logger level for
redis
- Docket: logger levels for
docket
and
docket.worker
One caution Redis Python client logging is sometimes less verbose than people expect unless the relevant code path emits logs. So SQLAlchemy logging is usually more reliable for proving whether the queue update query is or is not happening. Most useful evidence to collect next The single most valuable proof would be: After one
get_scheduled_flow_runs
request, do you see or not see an SQL statement updating
work_queue.last_polled
? If no update SQL appears at all, the issue is before DB write: - task scheduling - task execution - code path not reached If update SQL appears but DB row does not change, then it points to: - transaction/commit issue - wrong DB/session/path - rollback after update References - Prefect releases: Prefect releases - Prefect docs: Prefect docs If you want, I can help you prepare: 1. a minimal OCP env patch for
prefect-api
and
prefect-background
, or 2. a custom
logging.yml
ConfigMap
ready to apply.
r
@Marvin I got : /home/prefect/venv/lib64/python3.12/site-packages/prefect/settings/profiles.py47 UserWarning: Setting 'PREFECT_LOGGING _LOGGERS_DOCKET_WORKER_LEVEL' is not recognized when I set env var : PREFECT_LOGGING_LOGGERS_DOCKET_WORKER_LEVEL=DEBUG Why ?
m
thought for 12.7 seconds
Because that env var is being interpreted as a Prefect setting key, and
docket.worker
is not a declared Prefect settings path. So:
Copy code
bash
PREFECT_LOGGING_LOGGERS_DOCKET_WORKER_LEVEL=DEBUG
looks like a valid logger override, but in your version it is not recognized as a supported Prefect setting, which is why you get:
Copy code
text
UserWarning: Setting 'PREFECT_LOGGING_LOGGERS_DOCKET_WORKER_LEVEL' is not recognized
Why this happens Prefect supports env-based overrides for its known settings schema. That works well for built-in logger paths that exist in Prefect’s logging config/settings model, but not necessarily for arbitrary third-party or ad hoc logger names like: -
docket.worker
- sometimes
redis
- other non-Prefect logger trees Since
docket.worker
is not a native Prefect settings key, Prefect warns about it. What to do instead For non-standard logger names like
docket.worker
, use a custom
logging.yml
rather than env vars. That is the reliable way to configure arbitrary Python loggers. Recommended approach 1. Keep supported env vars for Prefect-native settings, for example:
Copy code
yaml
- name: PREFECT_LOGGING_LEVEL
  value: "DEBUG"
- name: PREFECT_SERVER_LOGGING_LEVEL
  value: "DEBUG"
- name: PREFECT_INTERNAL_LOGGING_LEVEL
  value: "DEBUG"
- name: PREFECT_API_DATABASE_ECHO
  value: "true"
2. Put custom logger definitions like
docket.worker
,
redis
,
sqlalchemy.pool
, etc. in a mounted
logging.yml
Example:
Copy code
yaml
version: 1
disable_existing_loggers: false

formatters:
  standard:
    (): prefect.logging.formatters.PrefectFormatter
    format: "%(asctime)s.%(msecs)03d | %(levelname)-7s | %(name)s - %(message)s"
    datefmt: "%H:%M:%S"

handlers:
  console:
    class: prefect.logging.handlers.PrefectConsoleHandler
    formatter: standard
    stream: <ext://sys.stderr>

loggers:
  prefect.server:
    level: DEBUG
    handlers: [console]
    propagate: false

  prefect.server.services:
    level: DEBUG
    handlers: [console]
    propagate: false

  prefect.server.services.foreman:
    level: DEBUG
    handlers: [console]
    propagate: false

  docket:
    level: DEBUG
    handlers: [console]
    propagate: false

  docket.worker:
    level: DEBUG
    handlers: [console]
    propagate: false

  redis:
    level: DEBUG
    handlers: [console]
    propagate: false

  sqlalchemy.engine:
    level: INFO
    handlers: [console]
    propagate: false

  sqlalchemy.pool:
    level: DEBUG
    handlers: [console]
    propagate: false

root:
  level: INFO
  handlers: [console]
Then set:
Copy code
yaml
- name: PREFECT_LOGGING_SETTINGS_PATH
  value: "/etc/prefect/logging.yml"
Why env vars still work for some loggers Some logger-related env vars map cleanly onto Prefect’s known config tree, especially Prefect-owned ones like: -
PREFECT_SERVER_LOGGING_LEVEL
-
PREFECT_LOGGING_LEVEL
But arbitrary dotted logger names are not always exposed as settings keys in your installed version. So the short answer
PREFECT_LOGGING_LOGGERS_DOCKET_WORKER_LEVEL
fails because
docket.worker
is not a recognized Prefect setting path
. Use a custom
logging.yml
for that logger. If you want, I can give you an OCP ConfigMap + Deployment patch example for mounting this
logging.yml
into both
prefect-api
and
prefect-background
.