From 884708b55f6644cba143aafb5990928dc64d3983 Mon Sep 17 00:00:00 2001 From: razbroc Date: Mon, 27 Jul 2026 16:00:01 +0300 Subject: [PATCH 1/4] refactor(otel): build providers in _init_telemetry() with a postfork hook Move the TracerProvider/MeterProvider construction out of import scope into _init_telemetry(), and dispatch on uwsgi.worker_id() at the bottom of the module to decide when to call it: - imported in the uWSGI master (lazy-app = false) -> defer via postfork - imported in a worker (lazy-app = true) -> initialise eagerly - not under uWSGI at all -> initialise eagerly Instrumentors are installed at import time and bind to ProxyTracer objects, which resolve once a real provider is set, so the explicit tracer_provider= kwargs are no longer needed and were removed. Both providers are flushed from an atexit handler so the final batch is exported when a worker recycles. This commit is behaviour-preserving under the chart's current lazy-app = true: the module is imported in the worker, so telemetry initialises eagerly exactly as before. Flipping lazy-app is a separate change. Also corrects the readme's claim that a master-initialised BatchSpanProcessor has its export thread die silently on fork. Verified false against SDK 1.44.0, where BatchSpanProcessor delegates to BatchProcessor in opentelemetry.sdk._shared_internal and an at-fork handler restarts the thread in the child. Refs: MAPCO-11222, MAPCO-11221 --- readme.md | 17 ++++- src/app.py | 217 +++++++++++++++++++++++++++++++++++++++-------------- 2 files changed, 176 insertions(+), 58 deletions(-) diff --git a/readme.md b/readme.md index 845af0a..d483b5e 100644 --- a/readme.md +++ b/readme.md @@ -271,7 +271,20 @@ docker compose up -d Every inbound HTTP request is wrapped in a span by `OpenTelemetryMiddleware` (outermost layer, inside CORS). Spans are exported in OTLP gRPC format to `OTEL_EXPORTER_OTLP_ENDPOINT`. -The `BatchSpanProcessor` is initialised **after** uWSGI forks workers (`--lazy-app`). This is required — initialising the processor in the master process causes its background export thread to die silently on fork. +The providers are built **after** uWSGI forks workers, via a `postfork` hook. `app.py` installs instrumentation at import time against `ProxyTracer` objects and builds the providers per worker, resolving those proxies at that point. The dispatch block at the bottom of `app.py` detects which process imported the module (`uwsgi.worker_id()`) and initialises at the right moment, so telemetry works under either `lazy-app` setting and outside uWSGI entirely. + +Why per-worker rather than in the master: + +- **The exporters' gRPC channels are not fork-safe.** grpc-python does not support forking with live channels. This is the binding constraint — the SDK's at-fork handling restarts export threads but does *not* rebuild an inherited channel. +- **It avoids depending on private SDK internals.** The at-fork machinery has already moved between versions, so relying on it for correctness is fragile even where it works. + +> **Correction.** Earlier revisions of this document claimed a master-initialised `BatchSpanProcessor` has its export thread "die silently on fork". That is **not** accurate. Verified against the SDK pinned in this image (1.44.0): `BatchSpanProcessor` delegates to `BatchProcessor` in `opentelemetry.sdk._shared_internal`, which registers an `os.register_at_fork` handler that restarts the export thread in the child — a span emitted in a forked child was exported with no `force_flush`. `PeriodicExportingMetricReader` is protected the same way, and proxy metric instruments (`_ProxyHistogram`) were confirmed to resolve post-fork too. +> +> Beware when checking this yourself: in SDK 1.7.1 the handler lived in `opentelemetry.sdk.trace.export`, so grepping that module on a current SDK reports zero and makes the protection look absent. +> +> The reasons to build post-fork are the two above, not export-thread death. + +Both providers are flushed via an `atexit` handler so the final batch is exported when a worker recycles. The gRPC channel uses a **bare `host:port`** with `insecure=True`. Passing an `http://` or `https://` prefix causes silent TLS negotiation failure. @@ -345,7 +358,7 @@ The container starts uWSGI with the following fixed flags (not configurable at r | `--socket 0.0.0.0:3031` | uwsgi binary protocol — use as nginx upstream | | `--http-socket 0.0.0.0:8080` | plain HTTP — use for liveness probes and direct access | | `--master` | master process manages workers | -| `--lazy-app` | workers load `app.py` **after** fork — required for OTel thread safety | +| `--lazy-app` | workers load `app.py` **after** fork — telemetry initialises per worker via the dispatch in `app.py` | | `--harakiri 120` | kill workers that take > 120 s | | `--max-requests 1000` | recycle worker after 1000 requests | | `--reload-on-rss 2048` | recycle worker if RSS exceeds 2 GB | diff --git a/src/app.py b/src/app.py index 8bd1adc..5ade3d2 100644 --- a/src/app.py +++ b/src/app.py @@ -1,6 +1,13 @@ """ MapProxy WSGI application wrapped with OpenTelemetry instrumentation. +Load order matters here. The OTel providers own gRPC channels that are not +fork-safe, so they are built by _init_telemetry() in the worker rather than at +import time. Instrumentation is installed at import against ProxyTracers that +resolve when that call lands. The dispatch block at the bottom of this module +picks the right moment for both lazy-app settings; read it before moving +anything across that boundary. + Override the behaviour with environment variables: OTEL_SERVICE_NAME - service name reported to the collector TELEMETRY_TRACING_ENDPOINT - OTLP gRPC collector endpoint @@ -36,6 +43,7 @@ # crashes the whole app at worker startup. from mapproxy.wsgiapp import make_wsgi_app +import atexit import os import socket import logging @@ -113,63 +121,130 @@ def _probe_collector(endpoint: str) -> None: endpoint, type(exc).__name__, exc, ) -_probe_collector(_OTLP_ENDPOINT) - # ── Resource ────────────────────────────────────────────────────────────────── resource = Resource.create({ "service.name": os.getenv("OTEL_SERVICE_NAME", "mapproxy"), "service.version": _SERVICE_VERSION, }) -# ── Tracing ─────────────────────────────────────────────────────────────────── -# Sample 1-in-N requests (default 1/10 = 10%) — tune via TELEMETRY_TRACING_SAMPLING_RATIO_DENOMINATOR. -# OTLPSpanExporter (gRPC) requires a bare host:port — strip http:// and set -# insecure=True explicitly, otherwise the channel defaults to TLS and the -# handshake fails silently against a plaintext collector endpoint. -try: - _grpc_endpoint = _OTLP_ENDPOINT.replace("https://", "").replace("http://", "").rstrip("/") - _otel_log.info("[otel-trace] gRPC endpoint: %s insecure=True sampling=1/%s", - _grpc_endpoint, _SAMPLE_DENOM) - tracer_provider = TracerProvider( - resource=resource, - sampler=TraceIdRatioBased(1 / _SAMPLE_DENOM) if _TRACING_ENABLED else TraceIdRatioBased(0), - ) - tracer_provider.add_span_processor( - BatchSpanProcessor( - OTLPSpanExporter(endpoint=_grpc_endpoint, insecure=True), - max_export_batch_size=512, - export_timeout_millis=10_000, +# ── Telemetry providers ─────────────────────────────────────────────────────── +# Populated by _init_telemetry(), which MUST run post-fork. See the dispatch +# block at the bottom of this module for how that is arranged. +# +# Nothing at import scope may call trace.set_tracer_provider() / +# metrics.set_meter_provider(). Until the first such call the OTel API hands +# out ProxyTracer / proxy-instrument objects that resolve lazily on first use, +# and that indirection is what lets the instrumentors below be installed +# pre-fork while the providers they end up using are built per worker. The +# first set-provider call wins and later ones are a no-op, so a master-side +# call would permanently bind every proxy to the master's provider — including +# its fork-unsafe gRPC channels — defeating the arrangement below. +tracer_provider = None +meter_provider = None + + +def _shutdown_telemetry() -> None: + """Flush both providers so the final batch is exported before we exit. + + Workers recycle often (max-requests, reload-on-rss). Without this the spans + and metrics still sitting in the BatchSpanProcessor / PeriodicExporting- + MetricReader queues are discarded on every recycle. + """ + if tracer_provider is not None: + try: + tracer_provider.shutdown() + _otel_log.info("[otel-trace] TracerProvider shut down — final batch flushed") + except Exception: + _otel_log.exception("[otel-trace] TracerProvider shutdown FAILED — spans may be lost") + if meter_provider is not None: + try: + meter_provider.shutdown() + _otel_log.info("[otel-metrics] MeterProvider shut down — final batch flushed") + except Exception: + _otel_log.exception("[otel-metrics] MeterProvider shutdown FAILED — metrics may be lost") + + +def _init_telemetry() -> None: + """Build the providers, their gRPC exporters, and the export threads. + + Runs post-fork. Two reasons, in order of weight: + + 1. The OTLP exporters hold gRPC channels, and grpc-python does not support + forking with live channels. The SDK's at-fork handling restarts export + threads but does NOT rebuild those channels, so this is not covered. + 2. It avoids depending on private SDK internals for correctness — that + machinery has already moved between versions (see below). + + Do NOT reintroduce the claim that a master-built provider loses its export + threads on fork. Verified against the SDK pinned in this image (1.44.0): + BatchSpanProcessor delegates to BatchProcessor in + opentelemetry.sdk._shared_internal, which registers an os.register_at_fork + handler that restarts the export thread in the child; + PeriodicExportingMetricReader registers one as well. A span emitted in a + forked child was exported with no force_flush. Note the module: in SDK + 1.7.1 that handler lived in opentelemetry.sdk.trace.export, which is why + grepping the old location reports zero and looks like it is missing. + + Calling this resolves every ProxyTracer handed out at import time. + """ + global tracer_provider, meter_provider + + _probe_collector(_OTLP_ENDPOINT) + + # ── Tracing ─────────────────────────────────────────────────────────────── + # Sample 1-in-N requests — tune via TELEMETRY_TRACING_SAMPLING_RATIO_DENOMINATOR. + # OTLPSpanExporter (gRPC) requires a bare host:port — strip http:// and set + # insecure=True explicitly, otherwise the channel defaults to TLS and the + # handshake fails silently against a plaintext collector endpoint. + try: + _grpc_endpoint = _OTLP_ENDPOINT.replace("https://", "").replace("http://", "").rstrip("/") + _otel_log.info("[otel-trace] gRPC endpoint: %s insecure=True sampling=1/%s", + _grpc_endpoint, _SAMPLE_DENOM) + tracer_provider = TracerProvider( + resource=resource, + sampler=TraceIdRatioBased(1 / _SAMPLE_DENOM) if _TRACING_ENABLED else TraceIdRatioBased(0), ) - ) - # OTEL_TRACE_DEBUG=true → also print every span to stdout so you can - # confirm spans are being created independently of collector connectivity. - if _TRACE_DEBUG: - _otel_log.warning("[otel-trace] OTEL_TRACE_DEBUG=true — ConsoleSpanExporter active (not for production)") - tracer_provider.add_span_processor(SimpleSpanProcessor(ConsoleSpanExporter())) - trace.set_tracer_provider(tracer_provider) - _otel_log.info("[otel-trace] TracerProvider ready") -except Exception: - _otel_log.exception("[otel-trace] FAILED to initialise — tracing disabled") - tracer_provider = TracerProvider(resource=resource, sampler=TraceIdRatioBased(0)) - trace.set_tracer_provider(tracer_provider) - -# ── Metrics ─────────────────────────────────────────────────────────────────── -try: - _grpc_endpoint = _OTLP_ENDPOINT.replace("https://", "").replace("http://", "").rstrip("/") - meter_provider = MeterProvider( - resource=resource, - metric_readers=[ - PeriodicExportingMetricReader( - OTLPMetricExporter(endpoint=_grpc_endpoint, insecure=True), - export_interval_millis=60_000, + tracer_provider.add_span_processor( + BatchSpanProcessor( + OTLPSpanExporter(endpoint=_grpc_endpoint, insecure=True), + max_export_batch_size=512, + export_timeout_millis=10_000, ) - ], - ) - metrics.set_meter_provider(meter_provider) - _otel_log.info("[otel-metrics] MeterProvider ready → %s", _grpc_endpoint) -except Exception: - _otel_log.exception("[otel-metrics] FAILED to initialise — metrics disabled") - metrics.set_meter_provider(MeterProvider(resource=resource)) + ) + # OTEL_TRACE_DEBUG=true → also print every span to stdout so you can + # confirm spans are being created independently of collector connectivity. + if _TRACE_DEBUG: + _otel_log.warning("[otel-trace] OTEL_TRACE_DEBUG=true — ConsoleSpanExporter active (not for production)") + tracer_provider.add_span_processor(SimpleSpanProcessor(ConsoleSpanExporter())) + trace.set_tracer_provider(tracer_provider) + _otel_log.info("[otel-trace] TracerProvider ready") + except Exception: + _otel_log.exception("[otel-trace] FAILED to initialise — tracing disabled") + tracer_provider = TracerProvider(resource=resource, sampler=TraceIdRatioBased(0)) + trace.set_tracer_provider(tracer_provider) + + # ── Metrics ─────────────────────────────────────────────────────────────── + try: + _grpc_endpoint = _OTLP_ENDPOINT.replace("https://", "").replace("http://", "").rstrip("/") + meter_provider = MeterProvider( + resource=resource, + metric_readers=[ + PeriodicExportingMetricReader( + OTLPMetricExporter(endpoint=_grpc_endpoint, insecure=True), + export_interval_millis=60_000, + ) + ], + ) + metrics.set_meter_provider(meter_provider) + _otel_log.info("[otel-metrics] MeterProvider ready → %s", _grpc_endpoint) + except Exception: + _otel_log.exception("[otel-metrics] FAILED to initialise — metrics disabled") + meter_provider = MeterProvider(resource=resource) + metrics.set_meter_provider(meter_provider) + + # Registered here rather than at import scope so it only ever runs in a + # process that actually owns providers. + atexit.register(_shutdown_telemetry) # ── Redis instrumentation ──────────────────────────────────────────────────────────── # request_hook enriches every Redis span with the command name and the first @@ -184,7 +259,6 @@ def _redis_request_hook(span, instance, args, kwargs): try: RedisInstrumentor().instrument( - tracer_provider=tracer_provider, request_hook=_redis_request_hook, ) _otel_log.info("[otel-redis] RedisInstrumentor active (command+key hooks enabled)") @@ -199,14 +273,13 @@ def _redis_request_hook(span, instance, args, kwargs): # Disable all three with TELEMETRY_SQL_ENABLED=false. if _SQL_ENABLED: try: - SQLite3Instrumentor().instrument(tracer_provider=tracer_provider) + SQLite3Instrumentor().instrument() _otel_log.info("[otel-sql] SQLite3Instrumentor active") except Exception: _otel_log.exception("[otel-sql] SQLite3Instrumentor FAILED to initialise") try: from opentelemetry.instrumentation.sqlalchemy import SQLAlchemyInstrumentor SQLAlchemyInstrumentor().instrument( - tracer_provider=tracer_provider, enable_commenter=True, commenter_options={}, ) @@ -216,7 +289,6 @@ def _redis_request_hook(span, instance, args, kwargs): try: from opentelemetry.instrumentation.psycopg2 import Psycopg2Instrumentor Psycopg2Instrumentor().instrument( - tracer_provider=tracer_provider, skip_dep_check=True, enable_commenter=True, ) @@ -279,7 +351,6 @@ def _boto_response_hook(span, service_name, operation_name, result): try: from opentelemetry.instrumentation.botocore import BotocoreInstrumentor BotocoreInstrumentor().instrument( - tracer_provider=tracer_provider, request_hook=_boto_request_hook, response_hook=_boto_response_hook, ) @@ -298,8 +369,8 @@ def _boto_response_hook(span, service_name, operation_name, result): try: from opentelemetry.instrumentation.requests import RequestsInstrumentor from opentelemetry.instrumentation.urllib3 import URLLib3Instrumentor - RequestsInstrumentor().instrument(tracer_provider=tracer_provider) - URLLib3Instrumentor().instrument(tracer_provider=tracer_provider) + RequestsInstrumentor().instrument() + URLLib3Instrumentor().instrument() _otel_log.info("[otel-http] RequestsInstrumentor + URLLib3Instrumentor active") except Exception: _otel_log.exception("[otel-http] HTTP instrumentors FAILED to initialise") @@ -324,6 +395,8 @@ def _boto_response_hook(span, service_name, operation_name, result): if _TILE_CACHE_TRACING: try: from mapproxy.cache.file import FileCache as _FileCache + # Runs at import, i.e. possibly pre-fork, so this is a ProxyTracer that + # resolves once _init_telemetry() sets the real provider in the worker. _tile_tracer = trace.get_tracer("mapproxy.cache.file") _orig_load_tile = _FileCache.load_tile _orig_load_tiles = _FileCache.load_tiles @@ -426,3 +499,35 @@ def _start_response(status, headers, exc_info=None): return start_response(status, filtered, exc_info) return _inner(environ, _start_response) + +# ── Telemetry initialisation (must land post-fork) ──────────────────────────── +# Everything above this point is fork-safe: instrumentors hold ProxyTracers, the +# FileCache patch is plain attribute assignment, and make_wsgi_app() builds an +# object graph that copies cleanly. The providers are not fork-safe, so where +# _init_telemetry() runs depends on which process imported this module: +# +# lazy-app = false → imported by the master, pre-fork. Defer to the postfork +# hook so each worker builds its own export threads. +# lazy-app = true → imported by the worker, i.e. after the fork already +# happened. A postfork hook would register too late and +# never fire, so initialise immediately instead. +# no uWSGI → dev server or docker-compose. Initialise immediately. +# +# The worker_id() check is what makes this module correct under either lazy-app +# setting rather than only the one currently configured. +try: + import uwsgi + from uwsgidecorators import postfork +except ImportError: + _otel_log.info("[otel] not running under uWSGI — initialising telemetry eagerly") + _init_telemetry() +else: + _worker_id = uwsgi.worker_id() + if _worker_id > 0: + _otel_log.info("[otel] imported inside worker %s (lazy-app=true) — " + "fork already happened, initialising telemetry now", _worker_id) + _init_telemetry() + else: + postfork(_init_telemetry) + _otel_log.info("[otel] imported in uWSGI master (lazy-app=false) — " + "telemetry deferred to postfork hook") From 2c750f27536acac5bb2c2705cbb5aa73030e0d5d Mon Sep 17 00:00:00 2001 From: razbroc Date: Mon, 27 Jul 2026 16:28:14 +0300 Subject: [PATCH 2/4] fix(otel): guard uwsgidecorators import and correct the atexit flush claim MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Three review findings from PR #88. 1. uwsgidecorators raises a bare Exception, not ImportError, when the uWSGI master is disabled: if uwsgi.masterpid() == 0: raise Exception("you have to enable the uWSGI master process ...") The dispatch caught only ImportError, so any uWSGI run without `master = true` died while importing app.py — and with `need-app = true` uWSGI then refuses to boot. Before this refactor the module never imported uwsgi at all, so this was a regression. The deployed chart sets master = true, so dev and prod were unaffected; debug runs and consumer-supplied inis were not. It was also imported unconditionally, including on the worker branch where postfork is never used. Now imported only in the master branch, wrapped in `except Exception`, falling back to eager init so a masterless worker gets telemetry rather than none. 2. The atexit flush was documented as guaranteeing the final batch is exported on worker recycle. It does not. uWSGI's python plugin skips Py_Finalize(), and therefore all atexit handlers, when the worker is hijacked, is busy in a request, or runs async; SIGKILL paths (harakiri, worker-reload-mercy expiry) bypass it entirely. Softened to best-effort in both the readme and the _shutdown_telemetry docstring, with the conditions spelled out. 3. The readme described the postfork hook as the shipped path, which is not true while the chart has lazy-app = true. Reworded to lead with the worker_id dispatch and to stay accurate under either setting. Refs: MAPCO-11221, MAPCO-11222 --- readme.md | 16 ++++++++++++++-- src/app.py | 32 ++++++++++++++++++++++++++++---- 2 files changed, 42 insertions(+), 6 deletions(-) diff --git a/readme.md b/readme.md index d483b5e..007d965 100644 --- a/readme.md +++ b/readme.md @@ -271,7 +271,17 @@ docker compose up -d Every inbound HTTP request is wrapped in a span by `OpenTelemetryMiddleware` (outermost layer, inside CORS). Spans are exported in OTLP gRPC format to `OTEL_EXPORTER_OTLP_ENDPOINT`. -The providers are built **after** uWSGI forks workers, via a `postfork` hook. `app.py` installs instrumentation at import time against `ProxyTracer` objects and builds the providers per worker, resolving those proxies at that point. The dispatch block at the bottom of `app.py` detects which process imported the module (`uwsgi.worker_id()`) and initialises at the right moment, so telemetry works under either `lazy-app` setting and outside uWSGI entirely. +The providers are always built **per worker, after the fork** — never in the uWSGI master. `app.py` installs instrumentation at import time against `ProxyTracer` objects, which resolve once a real provider is set. + +*When* that happens is decided by the dispatch block at the bottom of `app.py`, from `uwsgi.worker_id()`: + +| Import context | Behaviour | +| --- | --- | +| uWSGI worker — `lazy-app = true` | initialise immediately; the fork already happened | +| uWSGI master — `lazy-app = false` | defer to a `postfork` hook | +| no uWSGI (compose, tests) | initialise immediately | + +So the module is correct under either `lazy-app` setting and outside uWSGI entirely. Check `helm/config/mapProxyUwsgi.ini` for which path a given deployment actually takes. Why per-worker rather than in the master: @@ -284,7 +294,9 @@ Why per-worker rather than in the master: > > The reasons to build post-fork are the two above, not export-thread death. -Both providers are flushed via an `atexit` handler so the final batch is exported when a worker recycles. +Both providers are flushed via an `atexit` handler, so the final batch is exported on a clean interpreter shutdown. + +> **This is best-effort, not a guarantee.** uWSGI's python plugin skips `Py_Finalize()` — and therefore every Python `atexit` handler — when the worker is hijacked, when the worker is still busy serving a request, or when running in async mode. A `max-requests` or `reload-on-rss` recycle that lands while a sibling thread is mid-request will drop whatever is still queued, exactly as before this handler existed. Harakiri kills and `worker-reload-mercy` expiry (`SIGKILL`) bypass it too. Deterministic flushing on recycle would need a uWSGI-level shutdown hook rather than Python `atexit`. The gRPC channel uses a **bare `host:port`** with `insecure=True`. Passing an `http://` or `https://` prefix causes silent TLS negotiation failure. diff --git a/src/app.py b/src/app.py index 5ade3d2..0d7f152 100644 --- a/src/app.py +++ b/src/app.py @@ -149,6 +149,14 @@ def _shutdown_telemetry() -> None: Workers recycle often (max-requests, reload-on-rss). Without this the spans and metrics still sitting in the BatchSpanProcessor / PeriodicExporting- MetricReader queues are discarded on every recycle. + + Registered via atexit, which under uWSGI is BEST-EFFORT ONLY. The python + plugin returns from uwsgi_python_atexit() without reaching Py_Finalize() -- + so without running any atexit handler -- if the worker is hijacked, is still + busy in a request, or is running async. Recycles that land while a sibling + thread is mid-request therefore still drop the queue. SIGKILL paths + (harakiri, worker-reload-mercy expiry) skip it outright. Do not treat this + as a guarantee; a uWSGI-level shutdown hook would be needed for that. """ if tracer_provider is not None: try: @@ -515,9 +523,15 @@ def _start_response(status, headers, exc_info=None): # # The worker_id() check is what makes this module correct under either lazy-app # setting rather than only the one currently configured. +# +# uwsgidecorators is imported only on the branch that actually needs it. It does +# more than expose decorators at import time: it raises a bare Exception (NOT an +# ImportError) when the master process is disabled, so importing it up front +# would take down every uWSGI run without `master = true` — and `need-app = true` +# turns that into a refusal to boot. Hence the narrow placement and the broad +# except. try: import uwsgi - from uwsgidecorators import postfork except ImportError: _otel_log.info("[otel] not running under uWSGI — initialising telemetry eagerly") _init_telemetry() @@ -528,6 +542,16 @@ def _start_response(status, headers, exc_info=None): "fork already happened, initialising telemetry now", _worker_id) _init_telemetry() else: - postfork(_init_telemetry) - _otel_log.info("[otel] imported in uWSGI master (lazy-app=false) — " - "telemetry deferred to postfork hook") + try: + from uwsgidecorators import postfork + except Exception: + # No master process, so there is no fork to hook and nothing will + # register the providers later. Initialise now rather than boot a + # worker with telemetry silently absent. + _otel_log.warning("[otel] uwsgidecorators unavailable (uWSGI master " + "disabled?) — initialising telemetry eagerly") + _init_telemetry() + else: + postfork(_init_telemetry) + _otel_log.info("[otel] imported in uWSGI master (lazy-app=false) — " + "telemetry deferred to postfork hook") From 2d2282c64db598985e40424de41581a096d33faf Mon Sep 17 00:00:00 2001 From: razbroc Date: Mon, 27 Jul 2026 16:34:35 +0300 Subject: [PATCH 3/4] fix(otel): bind provider globals to the installed provider, not the built one _init_telemetry() assigned the module global before calling set_tracer_provider / set_meter_provider, then reassigned it to a fresh fallback provider in the except handler. Both setters are FIRST-WINS -- a second call logs "Overriding of current TracerProvider is not allowed" and does nothing (verified against the SDK in the image). So if anything raised *after* the set succeeded -- a broken log handler from log.ini is the realistic trigger, since an _otel_log call sits between the set and the end of the block -- the global ended up pointing at an inert fallback while the real provider stayed globally installed. _shutdown_telemetry() then shut down the orphan and never flushed the live BatchSpanProcessor queue: the exact opposite of what the atexit handler exists to do. Both blocks now build into a local, and a finally clause binds the global from trace.get_tracer_provider() / metrics.get_meter_provider() so it always tracks whatever is actually installed. A Proxy*Provider means nothing was installed and has no shutdown(), so the global is left None -- which _shutdown_telemetry already skips. Reproduced against the image's SDK: under the old pattern the global was not the live provider; under the new one it is, and calling shutdown() on it flushes a span that the orphan would have dropped. Refs: MAPCO-11221, MAPCO-11222 --- src/app.py | 40 ++++++++++++++++++++++++++++++---------- 1 file changed, 30 insertions(+), 10 deletions(-) diff --git a/src/app.py b/src/app.py index 0d7f152..f597d27 100644 --- a/src/app.py +++ b/src/app.py @@ -208,11 +208,11 @@ def _init_telemetry() -> None: _grpc_endpoint = _OTLP_ENDPOINT.replace("https://", "").replace("http://", "").rstrip("/") _otel_log.info("[otel-trace] gRPC endpoint: %s insecure=True sampling=1/%s", _grpc_endpoint, _SAMPLE_DENOM) - tracer_provider = TracerProvider( + _provider = TracerProvider( resource=resource, sampler=TraceIdRatioBased(1 / _SAMPLE_DENOM) if _TRACING_ENABLED else TraceIdRatioBased(0), ) - tracer_provider.add_span_processor( + _provider.add_span_processor( BatchSpanProcessor( OTLPSpanExporter(endpoint=_grpc_endpoint, insecure=True), max_export_batch_size=512, @@ -223,18 +223,32 @@ def _init_telemetry() -> None: # confirm spans are being created independently of collector connectivity. if _TRACE_DEBUG: _otel_log.warning("[otel-trace] OTEL_TRACE_DEBUG=true — ConsoleSpanExporter active (not for production)") - tracer_provider.add_span_processor(SimpleSpanProcessor(ConsoleSpanExporter())) - trace.set_tracer_provider(tracer_provider) + _provider.add_span_processor(SimpleSpanProcessor(ConsoleSpanExporter())) + trace.set_tracer_provider(_provider) _otel_log.info("[otel-trace] TracerProvider ready") except Exception: _otel_log.exception("[otel-trace] FAILED to initialise — tracing disabled") - tracer_provider = TracerProvider(resource=resource, sampler=TraceIdRatioBased(0)) - trace.set_tracer_provider(tracer_provider) + try: + trace.set_tracer_provider(TracerProvider(resource=resource, sampler=TraceIdRatioBased(0))) + except Exception: + _otel_log.exception("[otel-trace] fallback provider also FAILED") + finally: + # Bind the global to what the API actually holds, never to the object we + # built. set_tracer_provider is FIRST-WINS: a second call logs + # "Overriding of current TracerProvider is not allowed" and does nothing. + # So if the block above raised *after* the set succeeded, the fallback + # provider is inert while the real one stays installed — and shutting + # down the object we built would flush an orphan and leave the live + # provider's queue unexported, the exact opposite of the intent. + # A ProxyTracerProvider (nothing installed) is not an SDK provider and + # has no shutdown(), so leave the global None in that case. + _installed = trace.get_tracer_provider() + tracer_provider = _installed if isinstance(_installed, TracerProvider) else None # ── Metrics ─────────────────────────────────────────────────────────────── try: _grpc_endpoint = _OTLP_ENDPOINT.replace("https://", "").replace("http://", "").rstrip("/") - meter_provider = MeterProvider( + _provider = MeterProvider( resource=resource, metric_readers=[ PeriodicExportingMetricReader( @@ -243,12 +257,18 @@ def _init_telemetry() -> None: ) ], ) - metrics.set_meter_provider(meter_provider) + metrics.set_meter_provider(_provider) _otel_log.info("[otel-metrics] MeterProvider ready → %s", _grpc_endpoint) except Exception: _otel_log.exception("[otel-metrics] FAILED to initialise — metrics disabled") - meter_provider = MeterProvider(resource=resource) - metrics.set_meter_provider(meter_provider) + try: + metrics.set_meter_provider(MeterProvider(resource=resource)) + except Exception: + _otel_log.exception("[otel-metrics] fallback provider also FAILED") + finally: + # Same first-wins hazard as the tracer provider above — see that comment. + _installed = metrics.get_meter_provider() + meter_provider = _installed if isinstance(_installed, MeterProvider) else None # Registered here rather than at import scope so it only ever runs in a # process that actually owns providers. From 4236052b33271f424f27d4582d217d8bc13ca76b Mon Sep 17 00:00:00 2001 From: razbroc <77406876+razbroc@users.noreply.github.com> Date: Sun, 2 Aug 2026 11:31:34 +0300 Subject: [PATCH 4/4] perf(uwsgi): set lazy-app = false so the master preforks the app (MAPCO-11223) (#89) * perf(uwsgi): set lazy-app = false so the master preforks the app Flip the chart's uwsgi ini to load mapproxy.yaml once in the master and fork workers from it, so the parsed config is shared copy-on-write instead of being parsed once per worker. Safe only on top of the _init_telemetry() dispatch: app.py detects that it was imported in the master and defers provider construction to a postfork hook, so each worker still gets its own export threads and its own gRPC channels. The replaced comment claimed the opposite of the value it annotated ("Fork workers after app load (required for OTel)" on lazy-app = true) and carried a stale todo. Refs: MAPCO-11223, MAPCO-11221 * Update helm/config/mapProxyUwsgi.ini Co-authored-by: Shlomi k <65117898+CL-SHLOMIKONCHA@users.noreply.github.com> --------- Co-authored-by: Shlomi k <65117898+CL-SHLOMIKONCHA@users.noreply.github.com> --- helm/config/mapProxyUwsgi.ini | 5 ++++- readme.md | 2 +- 2 files changed, 5 insertions(+), 2 deletions(-) diff --git a/helm/config/mapProxyUwsgi.ini b/helm/config/mapProxyUwsgi.ini index 7474272..27d4838 100644 --- a/helm/config/mapProxyUwsgi.ini +++ b/helm/config/mapProxyUwsgi.ini @@ -13,7 +13,10 @@ processes = {{ .Values.mapproxy.uwsgi.processes }} ; Maximum number of workers a threads = {{ .Values.mapproxy.uwsgi.threads }} enable-threads = true master = true -lazy-app = true ; Fork workers after app load (required for OTel) todo check this variable effect +; Load the app once in the master, then fork. Workers share the parsed mapproxy.yaml +; copy-on-write. app.py builds the OTel providers in a postfork hook so their export +; threads and gRPC channels are still created per worker — see src/app.py. +; lazy-app = false py-callos-afterfork = true ; allow workers to trap signals ; cheaper = 2 ; Minimum number of workers allowed disable-logging = {{ .Values.mapproxy.uwsgi.disableLogging }} diff --git a/readme.md b/readme.md index 007d965..a231a32 100644 --- a/readme.md +++ b/readme.md @@ -370,7 +370,7 @@ The container starts uWSGI with the following fixed flags (not configurable at r | `--socket 0.0.0.0:3031` | uwsgi binary protocol — use as nginx upstream | | `--http-socket 0.0.0.0:8080` | plain HTTP — use for liveness probes and direct access | | `--master` | master process manages workers | -| `--lazy-app` | workers load `app.py` **after** fork — telemetry initialises per worker via the dispatch in `app.py` | +| `lazy-app = false` | master loads `app.py` once, then forks — workers share the parsed config copy-on-write | | `--harakiri 120` | kill workers that take > 120 s | | `--max-requests 1000` | recycle worker after 1000 requests | | `--reload-on-rss 2048` | recycle worker if RSS exceeds 2 GB |