Skip to content

Commit

Permalink
Log a warning when the BatchSpanProcessor queue is full. (#1871)
Browse files Browse the repository at this point in the history
  • Loading branch information
johanpel authored Dec 23, 2022
1 parent 8866c10 commit c0deb40
Show file tree
Hide file tree
Showing 3 changed files with 47 additions and 0 deletions.
3 changes: 3 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,9 @@ Increment the:
cmake when using C++20 [#1852](https:/open-telemetry/opentelemetry-cpp/pull/1852)
* [SEMANTIC CONVENTIONS] Upgrade to version 1.16.0
[#1854](https:/open-telemetry/opentelemetry-cpp/pull/1854)
* [SDK] BatchSpanProcessor now logs a warning when dropping a span because the
queue is full
[1871](https:/open-telemetry/opentelemetry-cpp/pull/1871)

## [1.8.1] 2022-12-04

Expand Down
2 changes: 2 additions & 0 deletions sdk/src/trace/batch_span_processor.cc
Original file line number Diff line number Diff line change
Expand Up @@ -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 <vector>
using opentelemetry::sdk::common::AtomicUniquePtr;
Expand Down Expand Up @@ -51,6 +52,7 @@ void BatchSpanProcessor::OnEnd(std::unique_ptr<Recordable> &&span) noexcept

if (buffer_.Add(span) == false)
{
OTEL_INTERNAL_LOG_WARN("BatchSpanProcessor queue is full - dropping span.");
return;
}

Expand Down
42 changes: 42 additions & 0 deletions sdk/test/trace/batch_span_processor_test.cc
Original file line number Diff line number Diff line change
Expand Up @@ -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 <gtest/gtest.h>
#include <algorithm>
#include <chrono>
#include <list>
#include <memory>
Expand Down Expand Up @@ -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<sdk::common::internal_log::LogLevel, std::string>;

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<Message> 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<sdk::common::internal_log::LogHandler>(new MockLogHandler());
sdk::common::internal_log::GlobalLogHandler::SetLogHandler(log_handler);

std::shared_ptr<std::atomic<bool>> is_shutdown(new std::atomic<bool>(false));
std::shared_ptr<std::vector<std::unique_ptr<sdk::trace::SpanData>>> spans_received(
new std::vector<std::unique_ptr<sdk::trace::SpanData>>);
Expand All @@ -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<MockLogHandler *>(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<sdk::common::internal_log::LogHandler>(
new sdk::common::internal_log::DefaultLogHandler()));
}

TEST_F(BatchSpanProcessorTestPeer, TestManySpansLossLess)
Expand Down

1 comment on commit c0deb40

@github-actions
Copy link

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

⚠️ Performance Alert ⚠️

Possible performance regression was detected for benchmark 'OpenTelemetry-cpp sdk Benchmark'.
Benchmark result of this commit is worse than the previous benchmark result exceeding threshold 2.

Benchmark suite Current: c0deb40 Previous: 8866c10 Ratio
BM_LockFreeBuffer/2 3167043.447494507 ns/iter 1065653.0857086182 ns/iter 2.97

This comment was automatically generated by workflow using github-action-benchmark.

Please sign in to comment.