diff --git a/CHANGELOG.md b/CHANGELOG.md index c36a9984ba..0afa4a9fba 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,8 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## Unreleased +- OTLP exporters now log partial success responses at `debug` level when `OTEL_LOG_LEVEL` is set to `debug` or `verbose`. + ([#4805](https://github.com/open-telemetry/opentelemetry-python/pull/4805)) - docs: Added sqlcommenter example ([#4734](https://github.com/open-telemetry/opentelemetry-python/pull/4734)) - build: bump ruff to 0.14.1 diff --git a/exporter/opentelemetry-exporter-otlp-proto-grpc/src/opentelemetry/exporter/otlp/proto/grpc/_log_exporter/__init__.py b/exporter/opentelemetry-exporter-otlp-proto-grpc/src/opentelemetry/exporter/otlp/proto/grpc/_log_exporter/__init__.py index fd0009b152..9c144eda3e 100644 --- a/exporter/opentelemetry-exporter-otlp-proto-grpc/src/opentelemetry/exporter/otlp/proto/grpc/_log_exporter/__init__.py +++ b/exporter/opentelemetry-exporter-otlp-proto-grpc/src/opentelemetry/exporter/otlp/proto/grpc/_log_exporter/__init__.py @@ -11,6 +11,7 @@ # See the License for the specific language governing permissions and # limitations under the License. +import sys from os import environ from typing import Dict, Literal, Optional, Sequence, Tuple, Union from typing import Sequence as TypingSequence @@ -109,6 +110,11 @@ def _translate_data( ) -> ExportLogsServiceRequest: return encode_logs(data) + def _log_partial_success(self, partial_success): + # Override that skips the "logging" module due to the possibility + # of circular logic (logging -> OTLP logs export). + sys.stderr.write(f"Partial success:\n{partial_success}\n") + def export( # type: ignore [reportIncompatibleMethodOverride] self, batch: Sequence[ReadableLogRecord], diff --git a/exporter/opentelemetry-exporter-otlp-proto-grpc/src/opentelemetry/exporter/otlp/proto/grpc/exporter.py b/exporter/opentelemetry-exporter-otlp-proto-grpc/src/opentelemetry/exporter/otlp/proto/grpc/exporter.py index 461ea0aee7..3c917b3116 100644 --- a/exporter/opentelemetry-exporter-otlp-proto-grpc/src/opentelemetry/exporter/otlp/proto/grpc/exporter.py +++ b/exporter/opentelemetry-exporter-otlp-proto-grpc/src/opentelemetry/exporter/otlp/proto/grpc/exporter.py @@ -93,6 +93,7 @@ OTEL_EXPORTER_OTLP_HEADERS, OTEL_EXPORTER_OTLP_INSECURE, OTEL_EXPORTER_OTLP_TIMEOUT, + OTEL_LOG_LEVEL, ) from opentelemetry.sdk.metrics.export import MetricExportResult, MetricsData from opentelemetry.sdk.resources import Resource as SDKResource @@ -257,6 +258,11 @@ def _get_credentials( return ssl_channel_credentials() +def _should_log_partial_responses(): + otel_log_level = environ.get(OTEL_LOG_LEVEL, "info").lower() + return otel_log_level in ["verbose", "debug"] + + # pylint: disable=no-member class OTLPExporterMixin( ABC, Generic[SDKDataT, ExportServiceRequestT, ExportResultT, ExportStubT] @@ -293,6 +299,9 @@ def __init__( self._endpoint = endpoint or environ.get( OTEL_EXPORTER_OTLP_ENDPOINT, "http://localhost:4317" ) + self._partial_response_logging_enabled = ( + _should_log_partial_responses() + ) parsed_url = urlparse(self._endpoint) @@ -374,6 +383,15 @@ def _translate_data( ) -> ExportServiceRequestT: pass + def _log_partial_success(self, partial_success): + logger.debug("Partial success:\n%s", partial_success) + + def _process_response(self, response): + if self._partial_response_logging_enabled and response.HasField( + "partial_success" + ): + self._log_partial_success(response.partial_success) + def _export( self, data: SDKDataT, @@ -388,11 +406,12 @@ def _export( deadline_sec = time() + self._timeout for retry_num in range(_MAX_RETRYS): try: - self._client.Export( + response = self._client.Export( request=self._translate_data(data), metadata=self._headers, timeout=deadline_sec - time(), ) + self._process_response(response) return self._result.SUCCESS # type: ignore [reportReturnType] except RpcError as error: retry_info_bin = dict(error.trailing_metadata()).get( # type: ignore [reportAttributeAccessIssue] diff --git a/exporter/opentelemetry-exporter-otlp-proto-grpc/tests/logs/test_otlp_logs_exporter.py b/exporter/opentelemetry-exporter-otlp-proto-grpc/tests/logs/test_otlp_logs_exporter.py index 94e8cc944c..5c3222222e 100644 --- a/exporter/opentelemetry-exporter-otlp-proto-grpc/tests/logs/test_otlp_logs_exporter.py +++ b/exporter/opentelemetry-exporter-otlp-proto-grpc/tests/logs/test_otlp_logs_exporter.py @@ -15,6 +15,7 @@ # pylint: disable=too-many-lines import time +from io import StringIO from os.path import dirname from unittest import TestCase from unittest.mock import Mock, patch @@ -28,7 +29,9 @@ OTLPLogExporter, ) from opentelemetry.proto.collector.logs.v1.logs_service_pb2 import ( + ExportLogsPartialSuccess, ExportLogsServiceRequest, + ExportLogsServiceResponse, ) from opentelemetry.proto.common.v1.common_pb2 import AnyValue, KeyValue from opentelemetry.proto.common.v1.common_pb2 import ( @@ -48,6 +51,7 @@ OTEL_EXPORTER_OTLP_LOGS_ENDPOINT, OTEL_EXPORTER_OTLP_LOGS_HEADERS, OTEL_EXPORTER_OTLP_LOGS_TIMEOUT, + OTEL_LOG_LEVEL, ) from opentelemetry.sdk.resources import Resource as SDKResource from opentelemetry.sdk.util.instrumentation import InstrumentationScope @@ -316,6 +320,27 @@ def export_log_and_deserialize(self, log_data): ) return log_records + @patch.dict("os.environ", {OTEL_LOG_LEVEL: "debug"}) + @patch("sys.stderr", new_callable=StringIO) + def test_partial_success_recorded_directly_to_stderr(self, mock_stderr): + # pylint: disable=protected-access + exporter = OTLPLogExporter() + exporter._client = Mock() + exporter._client.Export.return_value = ExportLogsServiceResponse( + partial_success=ExportLogsPartialSuccess( + rejected_log_records=1, + error_message="Log record dropped", + ) + ) + + exporter.export([self.log_data_1]) + + self.assertIn("Partial success:\n", mock_stderr.getvalue()) + self.assertIn("rejected_log_records: 1\n", mock_stderr.getvalue()) + self.assertIn( + 'error_message: "Log record dropped"\n', mock_stderr.getvalue() + ) + def test_exported_log_without_trace_id(self): log_records = self.export_log_and_deserialize(self.log_data_4) if log_records: diff --git a/exporter/opentelemetry-exporter-otlp-proto-grpc/tests/test_otlp_exporter_mixin.py b/exporter/opentelemetry-exporter-otlp-proto-grpc/tests/test_otlp_exporter_mixin.py index d64a601bbb..eb7d867532 100644 --- a/exporter/opentelemetry-exporter-otlp-proto-grpc/tests/test_otlp_exporter_mixin.py +++ b/exporter/opentelemetry-exporter-otlp-proto-grpc/tests/test_otlp_exporter_mixin.py @@ -40,6 +40,7 @@ ) from opentelemetry.exporter.otlp.proto.grpc.version import __version__ from opentelemetry.proto.collector.trace.v1.trace_service_pb2 import ( + ExportTracePartialSuccess, ExportTraceServiceRequest, ExportTraceServiceResponse, ) @@ -51,6 +52,7 @@ from opentelemetry.sdk.environment_variables import ( _OTEL_PYTHON_EXPORTER_OTLP_GRPC_CREDENTIAL_PROVIDER, OTEL_EXPORTER_OTLP_COMPRESSION, + OTEL_LOG_LEVEL, ) from opentelemetry.sdk.trace import ReadableSpan, _Span from opentelemetry.sdk.trace.export import ( @@ -534,3 +536,67 @@ def test_permanent_failure(self): warning.records[-1].message, "Failed to export traces to localhost:4317, error code: StatusCode.ALREADY_EXISTS", ) + + @patch("logging.Logger.debug") + def test_records_partial_success_if_log_level_enabled( + self, mock_logger_debug + ): + test_cases = ["verbose", "debug"] + + for log_level_value in test_cases: + with self.subTest(name=f"log_level_{log_level_value}"): + with patch.dict( + "os.environ", + {OTEL_LOG_LEVEL: log_level_value}, + clear=True, + ): + exporter = OTLPSpanExporterForTesting(insecure=True) + # pylint: disable=protected-access + exporter._client = Mock() + partial_success = ExportTracePartialSuccess( + rejected_spans=1, + error_message="Span dropped", + ) + exporter._client.Export.return_value = ( + ExportTraceServiceResponse( + partial_success=partial_success + ) + ) + exporter.export([self.span]) + + mock_logger_debug.assert_called_once_with( + "Partial success:\n%s", partial_success + ) + mock_logger_debug.reset_mock() + + @patch("logging.Logger.debug") + def test_does_not_record_partial_success_if_log_level_disabled( + self, mock_logger_debug + ): + test_cases = [None, "off", "error", "info"] + + for log_level_value in test_cases: + with self.subTest(name=f"log_level_{log_level_value or 'unset'}"): + with patch.dict( + "os.environ", + {OTEL_LOG_LEVEL: log_level_value} + if log_level_value is not None + else {}, + clear=True, + ): + exporter = OTLPSpanExporterForTesting(insecure=True) + # pylint: disable=protected-access + exporter._client = Mock() + partial_success = ExportTracePartialSuccess( + rejected_spans=1, + error_message="Span dropped", + ) + exporter._client.Export.return_value = ( + ExportTraceServiceResponse( + partial_success=partial_success + ) + ) + exporter.export([self.span]) + + mock_logger_debug.assert_not_called() + mock_logger_debug.reset_mock()