fix: ADDON-90004 change observability log level - #461
Conversation
Add three private helper functions (_sanitize_for_log, _safe_exception_repr, _safe_exception_str) to safely render exception messages and type names before logging them. These functions strip CR/LF, replace unpaired Unicode surrogates, truncate long text, and provide fallbacks for rendering failures. Co-Authored-By: Claude <noreply@anthropic.com>
Implements Task 3 of the ADDON-90004 plan: adds _DowngradeToInfoFilter class that downgrades WARNING/ERROR/CRITICAL records to INFO, plus tuples of logger names for OTel SDK internals that will be attached in Tasks 4-5. Co-Authored-By: Claude <noreply@anthropic.com>
Attach the _downgrade_to_info_filter to the 5 metrics-SDK loggers (opentelemetry.sdk.metrics.*) inside ObservabilityService.__init__. This suppresses WARNING/ERROR level log entries from the SDK and converts them to INFO, reducing observability noise. Co-Authored-By: Claude <noreply@anthropic.com>
…r noise
- Set GRPC_VERBOSITY=NONE at start of _create_otlp_exporter to suppress C-core
handshake diagnostics to stderr unless explicitly overridden by caller
- Attach _downgrade_to_info_filter to 4 _OTLP_LOGGERS before OTLPMetricExporter
construction to downgrade WARNING/ERROR logs from opentelemetry exporter and
utilities to INFO level, matching the filtering already applied to the 5
metrics SDK loggers during ObservabilityService.__init__
- Add comprehensive tests:
- test_create_otlp_exporter_sets_grpc_verbosity_when_absent: verifies NONE is set
- test_create_otlp_exporter_respects_existing_grpc_verbosity: verifies caller's
value is preserved
- test_create_otlp_exporter_attaches_filter_to_otlp_loggers: verifies filters
are present on the logger objects
- test_create_otlp_exporter_does_not_attach_filter_on_missing_port: verifies
filters only attached on the success path
- test_filters_are_attached_before_construction_logs_occur: regression guard
ensuring filter attachment happens before OTLPMetricExporter() runs, using
real grpc + malformed env vars to trigger actual WARNING logs
- TestGrpcTlsHandshakeStderrSuppression integration test: verifies that gRPC
C-core stderr is actually suppressed with GRPC_VERBOSITY=NONE
![chatgpt-codex-connector[bot]](https://avatars.githubusercontent.com/in/1144995?s=60&v=4){kind=small}
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 12f8676c75
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| timeout_millis: float = 10_000, | ||
| **kwargs, | ||
| ) -> MetricExportResult: | ||
| with self._lock: |
There was a problem hiding this comment.
When an OTLP export is blocked or waiting through retries while the process is shutting down, this lock remains held across _inner.export(), so shutdown() cannot acquire it and call the inner OTLP exporter's shutdown signaling until the export finishes naturally. This can stall modular-input termination for the full retry/export timeout; use the lock only for breaker-state checks and updates, not while calling the potentially blocking inner exporter.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
Fixed in 572db48. The breaker lock now protects only breaker-state reads and writes; calls to _inner.export(), force_flush(), and shutdown() run outside the lock. The regression test test_shutdown_is_not_blocked_by_in_flight_export verifies that shutdown() completes while an export remains in flight.
Add _CircuitBreakerExporter class that wraps an inner MetricExporter and stops calling it after 3 consecutive failed exports (via MetricExportResult.FAILURE or exception) within the same process. Once tripped, the exporter silently returns SUCCESS without calling the inner exporter or logging further messages. This eliminates WARNING/ERROR log noise from OTLP export failures while still recording that the 3rd failure occurred. Co-Authored-By: Claude <noreply@anthropic.com>
… access Add threading.Lock() to _CircuitBreakerExporter to prevent unsynchronized mutations of _tripped, _consecutive_failures, and _shutdown_called while concurrent threads may be accessing these fields. Wrap entire method bodies (export, force_flush, shutdown) to ensure atomicity of state checks and delegations to the inner exporter. Add deterministic concurrency test proving export() and shutdown() are now mutually exclusive: export blocks on a threading.Event, and shutdown() is demonstrated to block while the export holds the lock, then proceed normally after release. Co-Authored-By: Claude <noreply@anthropic.com>
Modified _create_otlp_exporter() to return the OTLP exporter wrapped in _CircuitBreakerExporter instead of returning it directly. This enables the circuit breaker to stop calling the inner exporter after 3 consecutive failed exports, eliminating WARNING/ERROR log noise from solnlib.observability when the Spotlight collector becomes unavailable. Updated test_create_otlp_exporter_returns_exporter_when_cert_present to verify the wrapper is returned. Added test_create_otlp_exporter_wrapper_forwards_shutdown to verify the wrapper properly delegates shutdown calls to the inner exporter. Co-Authored-By: Claude <noreply@anthropic.com>
Add input validation for event_count and byte_count arguments to StanzaObservabilityRecorder.record() to reject invalid values (negative numbers, non-ints, out-of-int64-range values) and log them at INFO level instead of raising or silently forwarding to the OTel SDK. Co-Authored-By: Claude <noreply@anthropic.com>
Add _attr_key_error and _attr_value_error helper functions to validate OpenTelemetry attribute keys and values per OTEL spec (string keys, bool/int/float/string values). Modify StanzaObservabilityRecorder.record to validate and filter extra_attrs, dropping invalid entries and preventing override of splunk.modinput.name. Co-Authored-By: Claude <noreply@anthropic.com>
Add validation in StanzaObservabilityRecorder.__init__ to reject modinput_type and stanza_name that are not strings or contain CR/LF. Raise TypeError before cache lookup to prevent invalid entries. Replace all 5 self._service._logger.info(...) calls in the record() method with self._logger.info(...) so the recorder logs on its own behalf rather than reaching into the service's logger. Co-Authored-By: Claude <noreply@anthropic.com>
…ce callers Co-Authored-By: Claude <noreply@anthropic.com>
Code-quality review of the modinput_type graceful-degrade test flagged that it only checked logger.info was called, not that warning/error were absent -- the actual contract this ticket is about. Co-Authored-By: Claude <noreply@anthropic.com>
…own calls _CircuitBreakerExporter.export()/force_flush()/shutdown() held the state lock across the blocking calls into the inner OTLP exporter, so shutdown() could be blocked for the full duration of an in-flight export instead of promptly reaching the inner exporter's own shutdown-triggered retry interruption.
12f8676 to
572db48
Compare
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 572db4804c
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| "opentelemetry.sdk.metrics._internal", | ||
| "opentelemetry.sdk.metrics._internal.instrument", | ||
| "opentelemetry.metrics._internal", | ||
| "opentelemetry.attributes", |
There was a problem hiding this comment.
Remove shared OpenTelemetry modules such as opentelemetry.attributes from this blanket filter list, or filter only the specific metrics messages. Once any ObservabilityService is constructed, the filter is installed globally for the rest of the process, and opentelemetry.attributes is also used by tracing, logging, and resource handling; warnings or errors from those unrelated signals are therefore relabeled as INFO and may be discarded by handlers, hiding genuine telemetry configuration or data problems.
Useful? React with 👍 / 👎.
There was a problem hiding this comment.
This is intentional. Observability is non-critical auxiliary functionality, and our policy is that OpenTelemetry SDK/exporter diagnostics must never exceed INFO, regardless of signal type. The process currently emits metrics only; future logs/traces integrations are expected to follow the same policy. We preserve the diagnostic message while preventing observability failures from surfacing as add-on WARNING/ERROR events. The intentional process-wide scope is now documented inline in b43e4f3.
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: b43e4f3aea
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| - Any other exception occurs during exporter construction (including a | ||
| missing ``grpcio`` package). | ||
| """ | ||
| os.environ.setdefault("GRPC_VERBOSITY", "NONE") |
There was a problem hiding this comment.
When an add-on also uses gRPC for its primary collection path and gRPC has not yet initialized, setting GRPC_VERBOSITY=NONE here suppresses C-core diagnostics for every gRPC channel in the process, not just the observability exporter. This happens even when Spotlight has no configured port or certificate because the environment is changed and grpc is imported before either condition is checked, potentially hiding actionable failures from the add-on's main workload; avoid changing the process-wide setting or make this suppression explicitly opt-in and defer it until OTLP is actually configured.
Useful? React with 👍 / 👎.
3 participants
Summary
solnlib.observability's own log calls at INFO and downgrade known OpenTelemetry OTLP/metrics-SDK logger output to INFO as well, so export failures no longer spam ERROR/WARNING into add-on logs — this preserves the diagnostic message rather than discarding it.GRPC_VERBOSITY, and add safe exception rendering helpers (_safe_exception_str/_safe_exception_repr/_sanitize_for_log) so caught errors can never raise, leak unpaired surrogates, or inject extra log lines.PeriodicExportingMetricReader, and preserves temporality/aggregation preferences through the wrapper.event_count/byte_count,extra_attrskeys/values, and recorder identity strings (raisesTypeErrorforStanzaObservabilityRecorder, gracefully degrades for directObservabilityService(modinput_type=...)callers instead of crashing or silently corrupting metrics)._CircuitBreakerExporter: the state lock was held across the blockingexport()/force_flush()/shutdown()calls into the inner exporter, soshutdown()could be blocked for the full duration of an in-flight export instead of promptly reaching the inner exporter's own retry-interrupt signaling. The lock now only guards breaker-state reads/writes.Ticket
ADDON-90004
Known, intentional trade-off
An external review flagged that
_DowngradeToInfoFilterdoesn't re-check the logger's effective level after downgrading a record to INFO, so a downgraded record can still be written even when the add-on has explicitly raised its log level above INFO to suppress noise. This was investigated and left as-is: fixing it would drop these OTel diagnostics by default for every add-on that never explicitly configures logging (root defaults to WARNING) — Python's logging module can't distinguish "WARNING by default" from "WARNING by deliberateLogs().set_level()call," so honoring the latter necessarily breaks the former. That default-visibility behavior is an explicit goal of the design and is covered bytest_filters_are_attached_before_construction_logs_occur. Revisit only as a deliberate design change, not a bugfix.Test plan
pytest tests/unit -v— 339 passedpre-commit run --files solnlib/observability.py tests/unit/test_observability.py— clean