https://prefect.io logo
Join Slack
Powered by
<@ULVA73B9P> I have an on-prem setup where the flo...
# ask-marvin
t
@Marvin I have an on-prem setup where the flows run in a kubernetes work pool. the flow image has opentelemetry zero-code auto instrumentation and the logs are supposed to be overwritten with
Copy code
OTEL_PYTHON_LOGGING_AUTO_INSTRUMENTATION_ENABLED=true 
OTEL_PYTHON_LOG_FORMAT="%(asctime)s %(levelname)s %(name)s [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s] ‣ %(message)s"
OTEL_PYTHON_LOG_CORRELATION=true
but what I observed is that the flow starts correctly with the log formatting I’ve set, but then right after the log changes its formatting:
Copy code
2025-12-01 15:11:36,252 INFO prefect.flow_runs.runner [trace_id=0 span_id=0] ‣ Opening process...                                                                                                            
15:11:37.886 | INFO    | Flow run 'sage-cobra' -  > Running set_working_directory step...                                                                                                                    
15:11:38.034 | INFO    | Flow run 'sage-cobra' - Beginning flow run 'sage-cobra' for flow 'Picanha-666'
how do I make sure the configuration I’ve set in the docker image is retained in all the flow’s lifetime?
m
✅ thought for 274.1 seconds
Thanks for the details — this is a classic “order of logging setup” issue. What you’re seeing: - Your container starts with OTel’s logging auto‑instrumentation format - When the Prefect flow process starts, Prefect configures logging and replaces the console formatter/handler - From that point on, logs use Prefect’s default format In Prefect 3.x, logging is configured when the flow process starts. If Prefect sees no user-defined root handlers, it applies its own console handler/formatter. That’s why your OTel format “flips” partway through. You have three reliable ways to keep your OTel format for the entire lifetime: Option A (recommended): Give Prefect a logging config that uses your OTel format - Bake a logging.yml into your image and point Prefect to it with 
PREFECT_LOGGING_SETTINGS_PATH
- Use either a standard formatter with your OTel fields or Prefect’s formatter with OTel fields included - Example logging.yml (keeps Prefect’s flow/task context, adds your OTel fields/format)
Copy code
version: 1
disable_existing_loggers: False

formatters:
  standard:
    (): prefect.logging.formatters.PrefectFormatter
    format: "%(asctime)s %(levelname)s %(name)s [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s] ‣ %(message)s"
    flow_run_fmt: "%(asctime)s %(levelname)s %(name)s [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s] ‣ Flow run '%(flow_run_name)s' - %(message)s"
    task_run_fmt: "%(asctime)s %(levelname)s %(name)s [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s] ‣ Task run '%(task_run_name)s' - %(message)s"

handlers:
  console:
    class: prefect.logging.handlers.PrefectConsoleHandler
    formatter: standard
  api:
    class: prefect.logging.handlers.APILogHandler

loggers:
  prefect:
    level: INFO
    handlers: [console]
  prefect.flow_runs:
    level: INFO
    handlers: [api, console]
    propagate: False
  prefect.task_runs:
    level: INFO
    handlers: [api, console]
    propagate: False

root:
  level: INFO
  handlers: [console]
Then set (in your image or job env):
Copy code
PREFECT_LOGGING_SETTINGS_PATH=/opt/prefect/logging.yml
PREFECT_LOGGING_COLORS=false
PREFECT_LOGGING_MARKUP=false
Notes: - With 
OTEL_PYTHON_LOG_CORRELATION=true
, OTel injects 
otelTraceID
and 
otelSpanID
attributes into log records; the formatter above renders them. - Prefect’s API log handler formats independently for the UI; console/stdout will follow your formatter. Option B: Use env vars to override Prefect’s formatter strings If you don’t want to ship a yml, you can override the default formatter keys Prefect uses:
Copy code
PREFECT_LOGGING_FORMATTERS_STANDARD_FORMAT="%(asctime)s %(levelname)s %(name)s [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s] ‣ %(message)s"
PREFECT_LOGGING_FORMATTERS_STANDARD_FLOW_RUN_FMT="%(asctime)s %(levelname)s %(name)s [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s] ‣ Flow run '%(flow_run_name)s' - %(message)s"
PREFECT_LOGGING_FORMATTERS_STANDARD_TASK_RUN_FMT="%(asctime)s %(levelname)s %(name)s [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s] ‣ Task run '%(task_run_name)s' - %(message)s"
PREFECT_LOGGING_COLORS=false
PREFECT_LOGGING_MARKUP=false
Option C: Preconfigure a user handler before Prefect initializes - If a non‑Prefect handler with a formatter is attached to the root logger before Prefect config runs, Prefect will skip reconfiguring the root logger. - In practice, for zero‑code OTel, this can be flaky because Prefect may still attach its own handlers later in the flow process. - The most reliable way to guarantee ordering is to add a tiny 
sitecustomize.py
in your image that sets up your logging/handler; Python auto‑imports it before anything else. Still, Option A is simpler and more explicit. Kubernetes placement tips - Put the logging.yml in your flow image and set 
PREFECT_LOGGING_SETTINGS_PATH
in the image or via the work pool’s base job template env
- Keep your OTel env vars as you have them; they’ll continue to inject the `otelTraceID`/`otelSpanID` fields that your formatter renders Docs for reference - Prefect logging customization: Logging customization (Prefect 3) - OpenTelemetry Python logging: OTel Python logging auto-instrumentation Quick check - Do you want to preserve the exact OTel format line-for-line, or is adding trace/span IDs into Prefect’s flow/task format acceptable? I can tailor the logging.yml accordingly. Also, can you confirm you’re on Prefect 3.x?
t
@Marvin I prefer using the env var approach. But while doing that, I got this error:
Copy code
--- Logging error ---                                                                                                                                                                                        
Traceback (most recent call last):                                                                                                                                                                           
  File "/usr/local/lib/python3.12/logging/__init__.py", line 464, in format                                                                                                                                  
    return self._format(record)                                                                                                                                                                              
           ^^^^^^^^^^^^^^^^^^^^                                                                                                                                                                              
  File "/usr/local/lib/python3.12/logging/__init__.py", line 460, in _format                                                                                                                                 
    return self._fmt % values                                                                                                                                                                                
           ~~~~~~~~~~^~~~~~~~                                                                                                                                                                                
KeyError: 'otelTraceID'                                                                                                                                                                                      
                                                                                                                                                                                                             
During handling of the above exception, another exception occurred:                                                                                                                                          
                                                                                                                                                                                                             
Traceback (most recent call last):                                                                                                                                                                           
  File "/usr/local/lib/python3.12/site-packages/prefect/logging/handlers.py", line 354, in emit                                                                                                              
    message = self.format(record)                                                                                                                                                                            
              ^^^^^^^^^^^^^^^^^^^                                                                                                                                                                            
  File "/usr/local/lib/python3.12/logging/__init__.py", line 999, in format                                                                                                                                  
    return fmt.format(record)                                                                                                                                                                                
           ^^^^^^^^^^^^^^^^^^                                                                                                                                                                                
  File "/usr/local/lib/python3.12/logging/__init__.py", line 706, in format                                                                                                                                  
    s = self.formatMessage(record)                                                                                                                                                                           
        ^^^^^^^^^^^^^^^^^^^^^^^^^^                                                                                                                                                                           
  File "/usr/local/lib/python3.12/site-packages/prefect/logging/formatters.py", line 133, in formatMessage                                                                                                   
    return style.format(record)                                                                                                                                                                              
           ^^^^^^^^^^^^^^^^^^^^                                                                                                                                                                              
  File "/usr/local/lib/python3.12/logging/__init__.py", line 466, in format                                                                                                                                  
    raise ValueError('Formatting field not found in record: %s' % e)                                                                                                                                         
ValueError: Formatting field not found in record: 'otelTraceID'
m
✅ thought for 60.9 seconds
That traceback means some LogRecords don’t have the otelTraceID/otelSpanID attributes when the Prefect formatter runs, so the % formatter raises a KeyError. Why it happens: - OTel’s log correlation only injects otelTraceID/otelSpanID when there’s an active span and after OTel logging is initialized. - Prefect emits some records before/around span activation (and from components that don’t carry those attrs), including the APILogHandler path you see in the stack. - If your format string references a missing key, Python logging throws. Three ways to fix this with your “env var only” preference: Option 1 (safest): Use Prefect’s built‑in trace fields instead of OTel field names Prefect’s formatter can derive trace/span from the current span and safely defaults to 0 when no span is present. Swap to these in your env vars:
Copy code
PREFECT_LOGGING_FORMATTERS_STANDARD_FORMAT="%(asctime)s %(levelname)s %(name)s [trace_id=%(trace_id)s span_id=%(span_id)s] ‣ %(message)s"
PREFECT_LOGGING_FORMATTERS_STANDARD_FLOW_RUN_FMT="%(asctime)s %(levelname)s %(name)s [trace_id=%(trace_id)s span_id=%(span_id)s] ‣ %(message)s"
PREFECT_LOGGING_FORMATTERS_STANDARD_TASK_RUN_FMT="%(asctime)s %(levelname)s %(name)s [trace_id=%(trace_id)s span_id=%(span_id)s] ‣ %(message)s"
PREFECT_LOGGING_COLORS=false
PREFECT_LOGGING_MARKUP=false
This preserves your format and avoids KeyErrors even for early logs. Option 2: Only include OTel fields in flow/task formats; keep the base format “safe” Leave the base format without OTel fields (covers early, non‑span logs), and put them only where spans are guaranteed:
Copy code
PREFECT_LOGGING_FORMATTERS_STANDARD_FORMAT="%(asctime)s %(levelname)s %(name)s ‣ %(message)s"
PREFECT_LOGGING_FORMATTERS_STANDARD_FLOW_RUN_FMT="%(asctime)s %(levelname)s %(name)s [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s] ‣ %(message)s"
PREFECT_LOGGING_FORMATTERS_STANDARD_TASK_RUN_FMT="%(asctime)s %(levelname)s %(name)s [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s] ‣ %(message)s"
PREFECT_LOGGING_COLORS=false
PREFECT_LOGGING_MARKUP=false
This assumes your OTel auto‑instr is active by the time flow/task run logs are emitted. If not, you may still hit missing fields; Option 1 is more robust. Option 3 (if you must use otelTraceID everywhere): Provide defaults via a logging Filter Python logging can add a filter that sets missing attributes to empty/0. That requires a logging.yml (env vars cannot declare filters/handlers). Example concept (requires switching to a YAML file):
Copy code
filters:
  add_otel_defaults:
    (): your_module.AddOtelDefaultsFilter  # sets record.otelTraceID / otelSpanID if missing

handlers:
  console:
    class: prefect.logging.handlers.PrefectConsoleHandler
    formatter: standard
    filters: [add_otel_defaults]
Given you prefer env vars only, I recommend Option 1. Extra tips: - Make sure these env vars are set in the flow container (image or work pool base job template), not just the worker pod. - Keep your existing OTel env vars; Prefect’s formatter will still output real IDs when spans are active, and “0” when not, instead of crashing. Docs: Prefect 3 logging customization If you want, share the exact env var set you applied and I’ll double‑check there aren’t any typos in the keys.
t
@Marvin I think in the 
prefect flow-run execute
entrypoint of the kubernetes job related to the flow run lose all the instrumentation given by the 
opentelemetry-instrument
, because it starts forking to another process. see
Copy code
prefect.flow_runs.runner [trace_id=0 span_id=0] ‣ Opening process...
is there a way to not have this behavior?
m
✅ thought for 224.1 seconds
You’re right: in Prefect 3.x the flow run is executed in a child process. The “Opening process…” log comes from the runner right before it spawns that subprocess. There isn’t a supported flag/setting to force in‑process execution for flow runs; Prefect does this for isolation/cancellation guarantees. How to keep OTel auto‑instrumentation across that subprocess boundary You need the child Python interpreter to start with OTel’s auto‑instrumentation already active. The most reliable options: 1) Wrap the flow container’s command with opentelemetry-instrument (recommended) - Update your Kubernetes work pool’s base job template so the container command is: - command: ["opentelemetry-instrument"] - args: ["python", "-m", "prefect.engine"] - Keep your OTel env vars in the job template or image: - 
OTEL_TRACES_EXPORTER=otlp
- 
OTEL_EXPORTER_OTLP_ENDPOINT=...
- 
OTEL_PYTHON_LOGGING_AUTO_INSTRUMENTATION_ENABLED=true
- 
OTEL_PYTHON_LOG_CORRELATION=true
- 
OTEL_PYTHON_LOG_FORMAT="%(asctime)s %(levelname)s %(name)s [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s] ‣ %(message)s"
Because Prefect launches a fresh Python interpreter for the child, wrapping the command ensures that interpreter loads the OTel sitecustomize hook before Prefect imports/configures logging. 2) Bake auto‑instrumentation into the image via sitecustomize (no wrapper) - Install the OTel distro in the image. - Ensure a sitecustomize hook is available on sys.path so every Python interpreter (including the child) auto‑loads instrumentation on startup. - This is effectively what 
opentelemetry-instrument
does; baking it into the image removes the need to wrap the command, but you must ensure the sitecustomize is importable in every interpreter. Notes and gotchas - Using only the OTel logging env vars is not enough if the child process never loads OTel’s auto‑instrumentation hook; that’s when you’ll see 
trace_id=0 span_id=0
and/or KeyErrors for missing 
otelTraceID
. - Prefect does propagate a traceparent into the child via flow run labels, so once OTel is active in the child, the IDs will be non‑zero and correlate correctly. - If you prefer env‑only log formatting and want to avoid KeyErrors before OTel is active, use Prefect’s safe fields: - 
PREFECT_LOGGING_FORMATTERS_STANDARD_FORMAT="%(asctime)s %(levelname)s %(name)s [trace_id=%(trace_id)s span_id=%(span_id)s] ‣ %(message)s"
- These default to 0 when no span is present and switch to real IDs once OTel is active. If you can share whether you can edit the Kubernetes work pool’s base job template, I can give you a concrete snippet to drop in (command/args/env) for your setup.
t
@Marvin I’m using 
opentelemetry-instrument prefect flow-run execute
to run a flow. Is there any difference over 
opentelemetry-instrument python -m prefect.engine
?
m
✅ thought for 136.4 seconds
Short answer: they’re not equivalent, but they end up doing the same thing for a flow run. - 
prefect flow-run execute
is the canonical CLI that the Kubernetes worker uses by default to start a flow run. It sets up the Runner and kicks off the child process that actually executes your flow. - 
python -m prefect.engine
is the module entrypoint the Runner uses internally for the child process that executes the flow. The parent process launches this module in a fresh Python interpreter. So: - opentelemetry-instrument prefect flow-run execute - Instruments the parent process (the CLI process). The Runner will still spawn the child interpreter for the actual flow, which will not be instrumented unless your child interpreter also starts under OTel auto-instrumentation. - opentelemetry-instrument python -m prefect.engine - Instruments the interpreter that is the child process (the one actually running your flow). This is the one you want instrumented for end-to-end traces/log correlation. In Kubernetes terms, the command/args you put on the flow-run container should wrap the actual execution interpreter with OTel. Two practical patterns: - Set the container command to: - command: ["opentelemetry-instrument"] - args: ["python", "-m", "prefect.engine"] - Or make it your image ENTRYPOINT/CMD: - ENTRYPOINT ["opentelemetry-instrument"] - CMD ["prefect", "flow-run", "execute"] Both work, because the first instruments the child interpreter directly, and the second instruments the parent which then spawns the child via the same already-instrumented interpreter. The key is: the child Python process that runs the flow must start under OTel’s bootstrap. If you can share how you’re setting the command in your work pool/job template, I can suggest the minimal change to ensure the child process is instrumented.
t
@Marvin tried the same diagnostic flow with 
prefect flow-run execute
and 
python -m prefect.engine
and I have different results: with 
python -m prefect.engine
I was able to utilize zero-code instrumentation from 
opentelemetry-instrument
. here’s my diagnostic flow logs:
Copy code
2025-12-02 10:26:10,920 INFO prefect.flow_runs [trace_id=0d185595a29368e5f9d73d20a413357a span_id=2dde4f319d37f310] ‣ ================================================================================       
2025-12-02 10:26:10,920 INFO prefect.flow_runs [trace_id=0d185595a29368e5f9d73d20a413357a span_id=2dde4f319d37f310] ‣ DIAGNOSTIC SUMMARY                                                                     
2025-12-02 10:26:10,920 INFO prefect.flow_runs [trace_id=0d185595a29368e5f9d73d20a413357a span_id=2dde4f319d37f310] ‣ ================================================================================       
2025-12-02 10:26:10,921 INFO prefect.flow_runs [trace_id=0d185595a29368e5f9d73d20a413357a span_id=2dde4f319d37f310] ‣ ✓ No critical issues detected                                                          
2025-12-02 10:26:10,921 INFO prefect.flow_runs [trace_id=0d185595a29368e5f9d73d20a413357a span_id=2dde4f319d37f310] ‣   OpenTelemetry appears to be properly configured                                      
2025-12-02 10:26:10,921 INFO prefect.flow_runs [trace_id=0d185595a29368e5f9d73d20a413357a span_id=2dde4f319d37f310] ‣ ================================================================================
but using 
prefect flow-runs execute
I don’t get the trace id in the logs, which means 
opentelemetry-instrument
patches were not applied:
Copy code
10:49:09.859 | INFO    | Flow run 'skilled-dragon' - ================================================================================                                                                        
10:49:09.859 | INFO    | Flow run 'skilled-dragon' - DIAGNOSTIC SUMMARY                                                                                                                                      
10:49:09.859 | INFO    | Flow run 'skilled-dragon' - ================================================================================                                                                        
10:49:09.860 | ERROR   | Flow run 'skilled-dragon' - ✗ ISSUES FOUND:                                                                                                                                         
10:49:09.860 | ERROR   | Flow run 'skilled-dragon' -   → ProxyTracerProvider detected (SDK may not be initialized)                                                                                           
10:49:09.860 | ERROR   | Flow run 'skilled-dragon' -   → NonRecordingSpan detected (spans are not being recorded)                                                                                            
10:49:09.860 | ERROR   | Flow run 'skilled-dragon' -   → Invalid span context (trace_id/span_id are 0)                                                                                                       
10:49:09.860 | ERROR   | Flow run 'skilled-dragon' -                                                                                                                                                         
10:49:09.860 | ERROR   | Flow run 'skilled-dragon' - SOLUTION:                                                                                                                                               
10:49:09.860 | ERROR   | Flow run 'skilled-dragon' -   The OpenTelemetry SDK is not properly initialized.                                                                                                    
10:49:09.861 | ERROR   | Flow run 'skilled-dragon' -   Possible causes:                                                                                                                                      
10:49:09.861 | ERROR   | Flow run 'skilled-dragon' -   1. 'opentelemetry-instrument' is not working correctly                                                                                                
10:49:09.861 | ERROR   | Flow run 'skilled-dragon' -   2. SDK packages are not installed (opentelemetry-sdk, opentelemetry-exporter-otlp)                                                                    
10:49:09.861 | ERROR   | Flow run 'skilled-dragon' -   3. Environment variables are set but SDK initialization failed                                                                                        
10:49:09.861 | ERROR   | Flow run 'skilled-dragon' -   4. SDK needs to be manually initialized in code                                                                                                       
10:49:09.862 | ERROR   | Flow run 'skilled-dragon' -                                                                                                                                                         
10:49:09.862 | ERROR   | Flow run 'skilled-dragon' -   To fix:                                                                                                                                               
10:49:09.862 | ERROR   | Flow run 'skilled-dragon' -   - Verify 'opentelemetry-instrument' is in ENTRYPOINT                                                                                                  
10:49:09.863 | ERROR   | Flow run 'skilled-dragon' -   - Check that opentelemetry-sdk and opentelemetry-exporter-otlp are installed                                                                          
10:49:09.863 | ERROR   | Flow run 'skilled-dragon' -   - Ensure OTEL_EXPORTER_OTLP_ENDPOINT is accessible                                                                                                    
10:49:09.864 | ERROR   | Flow run 'skilled-dragon' -   - Consider manually initializing SDK if auto-instrumentation fails                                                                                    
10:49:09.864 | INFO    | Flow run 'skilled-dragon' - ================================================================================
Just sharing this here in case someone bump into the same problem as me
m
✅ thought for 115.4 seconds
Super helpful data point — thank you for sharing. Your results make sense: - python -m prefect.engine is the actual interpreter that runs your flow, so wrapping it with opentelemetry-instrument reliably loads the OTel sitecustomize at interpreter startup → instrumentation works. - prefect flow-run execute is a parent CLI that then spawns the child interpreter. Depending on which execution path Prefect chooses (subprocess vs multiprocessing spawn), that child interpreter may not pick up the auto-instrumentation bootstrap — hence the ProxyTracerProvider/NonRecordingSpan symptoms you saw. If you want zero-code instrumentation consistently, the most reliable fix is to instrument the interpreter that actually executes the flow: - In your Kubernetes work pool’s base job template, set the container command to:
Copy code
command: ["opentelemetry-instrument"]
args: ["python", "-m", "prefect.engine"]
or set your image like:
Copy code
ENTRYPOINT ["opentelemetry-instrument"]
CMD ["python", "-m", "prefect.engine"]
Keep your OTel env vars (exporter, endpoint, logging flags) in the image or job template. This mirrors the behavior you observed and ensures the executing interpreter is instrumented no matter how the parent runner was started. Alternatives if you can’t change the command: - Bake auto-instrumentation via sitecustomize in the image so every new interpreter (including any spawned by Prefect) loads OTel on startup. - Manually initialize the OTel SDK at the very start of your flow code as a fallback. If you’d like, I can help adapt your work pool template to use that command and double-check the env, image, and args so you get consistent traces and log correlation.
7 Views
Open in Slack
PreviousNext
Powered by