diff --git a/CHANGELOG.md b/CHANGELOG.md index a990471daa..9f72a99a22 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -21,6 +21,9 @@ Increment the: cmake when using C++20 [#1852](https://github.com/open-telemetry/opentelemetry-cpp/pull/1852) * [SEMANTIC CONVENTIONS] Upgrade to version 1.16.0 [#1854](https://github.com/open-telemetry/opentelemetry-cpp/pull/1854) +* [SDK] BatchSpanProcessor now logs a warning when dropping a span because the + queue is full + [1871](https://github.com/open-telemetry/opentelemetry-cpp/pull/1871) ## [1.8.1] 2022-12-04 diff --git a/sdk/src/trace/batch_span_processor.cc b/sdk/src/trace/batch_span_processor.cc index 4609eae95f..de6c457da7 100644 --- a/sdk/src/trace/batch_span_processor.cc +++ b/sdk/src/trace/batch_span_processor.cc @@ -3,6 +3,7 @@ #include "opentelemetry/sdk/trace/batch_span_processor.h" #include "opentelemetry/common/spin_lock_mutex.h" +#include "opentelemetry/sdk/common/global_log_handler.h" #include using opentelemetry::sdk::common::AtomicUniquePtr; @@ -51,6 +52,7 @@ void BatchSpanProcessor::OnEnd(std::unique_ptr &&span) noexcept if (buffer_.Add(span) == false) { + OTEL_INTERNAL_LOG_WARN("BatchSpanProcessor queue is full - dropping span."); return; } diff --git a/sdk/test/trace/batch_span_processor_test.cc b/sdk/test/trace/batch_span_processor_test.cc index ad981cafb6..744d80775d 100644 --- a/sdk/test/trace/batch_span_processor_test.cc +++ b/sdk/test/trace/batch_span_processor_test.cc @@ -2,10 +2,12 @@ // SPDX-License-Identifier: Apache-2.0 #include "opentelemetry/sdk/trace/batch_span_processor.h" +#include "opentelemetry/sdk/common/global_log_handler.h" #include "opentelemetry/sdk/trace/span_data.h" #include "opentelemetry/sdk/trace/tracer.h" #include +#include #include #include #include @@ -182,10 +184,31 @@ TEST_F(BatchSpanProcessorTestPeer, TestForceFlush) } } +// A mock log handler to check whether log messages with a specific level were emitted. +struct MockLogHandler : public sdk::common::internal_log::LogHandler +{ + using Message = std::pair; + + void Handle(sdk::common::internal_log::LogLevel level, + const char * /*file*/, + int /*line*/, + const char *msg, + const sdk::common::AttributeMap & /*attributes*/) noexcept override + { + messages.emplace_back(level, msg); + } + + std::vector messages; +}; + TEST_F(BatchSpanProcessorTestPeer, TestManySpansLoss) { /* Test that when exporting more than max_queue_size spans, some are most likely lost*/ + // Set up a log handler to verify a warning is generated. + auto log_handler = nostd::shared_ptr(new MockLogHandler()); + sdk::common::internal_log::GlobalLogHandler::SetLogHandler(log_handler); + std::shared_ptr> is_shutdown(new std::atomic(false)); std::shared_ptr>> spans_received( new std::vector>); @@ -211,6 +234,25 @@ TEST_F(BatchSpanProcessorTestPeer, TestManySpansLoss) // Span should be exported by now EXPECT_GE(max_queue_size, spans_received->size()); + + // If we haven't received all spans, some must have dropped, verify a warning was logged. + // Only do this when the log level is warning or above. +#if OTEL_INTERNAL_LOG_LEVEL >= OTEL_INTERNAL_LOG_LEVEL_WARN + if (max_queue_size > spans_received->size()) + { + auto &messages = static_cast(log_handler.get())->messages; + EXPECT_TRUE( + std::find(messages.begin(), messages.end(), + MockLogHandler::Message(sdk::common::internal_log::LogLevel::Warning, + "BatchSpanProcessor queue is full - dropping span.")) != + messages.end()); + } +#endif + + // Reinstate the default log handler. + sdk::common::internal_log::GlobalLogHandler::SetLogHandler( + nostd::shared_ptr( + new sdk::common::internal_log::DefaultLogHandler())); } TEST_F(BatchSpanProcessorTestPeer, TestManySpansLossLess)