Repository navigation
Cooperative cancellation for metric collection during bounded PeriodicExportingMetricReader shutdown #4746
Description
Is your feature request related to a problem?
Location (open-telemetry/opentelemetry-cpp @ default branch 3ee38aa):
sdk/src/metrics/export/periodic_exporting_metric_reader.cc:291-343:OnShutDown()spends the budget onOnForceFlush(timeout), then joins the worker with no time limit.sdk/src/metrics/export/periodic_exporting_metric_reader.cc:167-179: the collection timeout inCollectAndExportOnce()is checked only after collection returns.sdk/include/opentelemetry/sdk/metrics/export/metric_producer.h:112-116:MetricProducer::Produce()takes no deadline or stop signal.
// PeriodicExportingMetricReader::OnShutDown()
if (has_worker_thread)
{
flush_status = OnForceFlush(timeout);
}
...
if (has_worker_thread)
{
worker_thread_.join();
} // MetricProducer
virtual Result Produce() noexcept = 0;Problem
A host application that must finish graceful shutdown within a fixed budget (for example a SIGTERM grace period) calls MeterProvider::Shutdown(timeout) / PeriodicExportingMetricReader::Shutdown(timeout). If the reader's worker thread is inside a collection cycle at that moment, the call cannot return until that cycle finishes, however small timeout is. Only the exporter's Shutdown() receives the remaining time, and a producer that wants to stop early has no way to learn that a shutdown is waiting for it.
This is a request for cooperative cancellation. A callback or exporter that does not cooperate can still make Shutdown() exceed its budget, because C++ has no safe way to abort arbitrary user code.
Reproduction
Example: a MetricProducer whose Produce() takes 3 s, and Shutdown(200ms) called while the worker is inside Produce(). Shutdown() returned after about 3000 ms:
[Error] File: .../sdk/src/metrics/export/periodic_exporting_metric_reader.cc:173 [Periodic Exporting Metric Reader] Collect took longer configured time: 200 ms, and timed out
[Warning] File: .../sdk/src/metrics/metric_reader.cc:59 MetricReader::OnShutDown Shutdown failed. Will not be tried again!
.../periodic_exporting_metric_reader_shutdown_timeout_test.cc:120: Failure
Expected: (elapsed) < (std::chrono::milliseconds(1000)), actual: ... vs ...
Shutdown() took 3000 ms but should have respected the 200 ms timeout
This producer sleeps on purpose. I am not claiming that any in-tree exporter or producer blocks for this long in practice.
Test used (public SDK API, gtest)
#include <gtest/gtest.h>
#include <chrono>
#include <condition_variable>
#include <memory>
#include <mutex>
#include <thread>
#include "opentelemetry/sdk/common/exporter_utils.h"
#include "opentelemetry/sdk/metrics/export/metric_producer.h"
#include "opentelemetry/sdk/metrics/export/periodic_exporting_metric_reader.h"
#include "opentelemetry/sdk/metrics/export/periodic_exporting_metric_reader_options.h"
#include "opentelemetry/sdk/metrics/instruments.h"
#include "opentelemetry/sdk/metrics/push_metric_exporter.h"
using namespace opentelemetry;
using namespace opentelemetry::sdk::metrics;
class SlowBlockingMetricProducer : public MetricProducer
{
public:
explicit SlowBlockingMetricProducer(std::chrono::milliseconds d) : block_duration_(d) {}
MetricProducer::Result Produce() noexcept override
{
{
std::lock_guard<std::mutex> lock(mutex_);
producing_ = true;
}
cv_.notify_all();
std::this_thread::sleep_for(block_duration_);
ResourceMetrics data;
return {data, MetricProducer::Status::kSuccess};
}
void WaitUntilProducing()
{
std::unique_lock<std::mutex> lock(mutex_);
cv_.wait(lock, [this]() { return producing_; });
}
private:
std::chrono::milliseconds block_duration_;
bool producing_ = false;
std::mutex mutex_;
std::condition_variable cv_;
};
class NoOpTestMetricExporter : public PushMetricExporter
{
public:
opentelemetry::sdk::common::ExportResult Export(const ResourceMetrics &) noexcept override
{
return opentelemetry::sdk::common::ExportResult::kSuccess;
}
AggregationTemporality GetAggregationTemporality(InstrumentType) const noexcept override
{
return AggregationTemporality::kCumulative;
}
bool ForceFlush(std::chrono::microseconds) noexcept override { return true; }
bool Shutdown(std::chrono::microseconds) noexcept override { return true; }
};
TEST(PeriodicExportingMetricReaderShutdownTimeout, ShutdownRespectsTimeoutDuringSlowProduce)
{
SlowBlockingMetricProducer producer(std::chrono::milliseconds(3000));
PeriodicExportingMetricReaderOptions options;
options.export_interval_millis = std::chrono::milliseconds(5000);
options.export_timeout_millis = std::chrono::milliseconds(200);
auto reader = std::make_shared<PeriodicExportingMetricReader>(
std::unique_ptr<PushMetricExporter>(new NoOpTestMetricExporter()), options);
reader->SetMetricProducer(&producer); // starts the worker thread
producer.WaitUntilProducing();
const auto shutdown_timeout = std::chrono::microseconds(200000);
auto start = std::chrono::steady_clock::now();
reader->Shutdown(shutdown_timeout);
auto elapsed = std::chrono::steady_clock::now() - start;
EXPECT_LT(elapsed, std::chrono::milliseconds(1000))
<< "Shutdown() took "
<< std::chrono::duration_cast<std::chrono::milliseconds>(elapsed).count()
<< " ms but should have respected the "
<< std::chrono::duration_cast<std::chrono::milliseconds>(shutdown_timeout).count()
<< " ms timeout";
}The test was added as sdk/test/metrics/periodic_exporting_metric_reader_shutdown_timeout_test.cc, registered in the foreach list of sdk/test/metrics/CMakeLists.txt, and run with ctest -R ShutdownRespectsTimeoutDuringSlowProduce.
Environment:
- Commit:
e854d29.periodic_exporting_metric_reader.cc,metric_reader.cc, andmetric_producer.hare byte-identical on currentmain(3ee38aa), but I did not re-run the test there. - Toolchain: GCC 11.5.0, CMake 3.18.4, googletest 1.10
Describe the solution you'd like
A design for cooperative cancellation of metric collection when a bounded shutdown is in progress. The spec (v1.62.0, MetricReader Shutdown) says "Shutdown SHOULD complete or abort within some timeout." It also allows SDK authors to add a timeout parameter to Produce and says the implementation SHOULD use a timeout to prevent indefinite callback execution.
Out of scope:
- Detaching the worker thread or otherwise letting it outlive
this. That risks the same kind of use-after-destroy race as PeriodicExportingMetricReader: missing destructor causes use-after-destroy race (ThreadSanitizer) #4007. - Forcibly interrupting arbitrary callbacks.
- Any guarantee that
Shutdown()returns withintimeoutwhen user code does not cooperate.
The default behavior for existing producers and exporters stays the same.
Already implemented in open-telemetry/opentelemetry-go
PR: open-telemetry/opentelemetry-go#4356 — "PeriodicReader.Shutdown now applies the periodic reader's timeout by default" (merged 2023-07-25T09:00:17Z, merge commit c1a644a10c1). PeriodicReader.Shutdown now bounds its context with the reader's timeout, and because Produce and Export already take that context, a producer that honors it stops early. This is cooperative too: the producer has to check ctx, and the PR's tests show exactly that.
How opentelemetry-go fixed it:
--- a/sdk/metric/periodic_reader.go
+++ b/sdk/metric/periodic_reader.go
@@ -323,6 +324,8 @@ func (r *PeriodicReader) ForceFlush(ctx context.Context) error {
func (r *PeriodicReader) Shutdown(ctx context.Context) error {
err := ErrReaderShutdown
r.shutdownOnce.Do(func() {
+ ctx, cancel := context.WithTimeout(ctx, r.timeout)
+ defer cancel()
// Stop the run loop.
r.cancel()
<-r.done--- a/sdk/metric/periodic_reader_test.go
+++ b/sdk/metric/periodic_reader_test.go
@@ -337,6 +337,46 @@ func TestPeriodicReaderFlushesPending(t *testing.T) {
...
+ t.Run("Shutdown timeout on producer", func(t *testing.T) {
+ exp, called := expFunc(t)
+ timeout := time.Millisecond
+ r := NewPeriodicReader(exp, WithTimeout(timeout))
+ r.register(testSDKProducer{
+ produceFunc: func(ctx context.Context, rm *metricdata.ResourceMetrics) error {
+ select {
+ case <-time.After(timeout + time.Second):
+ *rm = testResourceMetricsA
+ case <-ctx.Done():
+ // we timed out before we could collect metrics
+ return ctx.Err()
+ }
+ return nil
+ }})
+ r.RegisterProducer(testExternalProducer{})
+ assert.Equal(t, context.DeadlineExceeded, r.Shutdown(context.Background()), "timeout error not returned")
+ assert.False(t, *called, "exporter Export method called when it should have failed before export")
+ })
...Suggested fix
Add a CollectionCancellation::IsRequested() query that is true on the worker thread once OnShutDown() has used up its flush budget and set is_stop_requested_. It reaches Produce(), observable callbacks and Export() without changing any signature, and code that does not call it behaves as before:
diff --git a/sdk/include/opentelemetry/sdk/metrics/export/collection_cancellation.h b/sdk/include/opentelemetry/sdk/metrics/export/collection_cancellation.h
new file mode 100644
--- /dev/null
+++ b/sdk/include/opentelemetry/sdk/metrics/export/collection_cancellation.h
@@ -0,0 +1,52 @@
+// Copyright The OpenTelemetry Authors
+// SPDX-License-Identifier: Apache-2.0
+
+#pragma once
+
+#include <atomic>
+
+#include "opentelemetry/version.h"
+
+OPENTELEMETRY_BEGIN_NAMESPACE
+namespace sdk
+{
+namespace metrics
+{
+
+/**
+ * Lets code running inside a PeriodicExportingMetricReader collection cycle (a MetricProducer,
+ * an observable instrument callback or PushMetricExporter::Export) learn that a shutdown is
+ * waiting for the cycle, so it can return early, for example with MetricProducer::Status::kTimeout
+ * or a partial batch.
+ *
+ * Cancellation is cooperative: code that does not check it runs to completion, and Shutdown() then
+ * waits for it regardless of its timeout.
+ */
+class CollectionCancellation
+{
+public:
+ /**
+ * @return true if the calling thread is running a collection cycle whose reader has stopped
+ * waiting for it. Always false on other threads, so work handed off to another thread must
+ * capture the result itself.
+ */
+ static bool IsRequested() noexcept;
+
+ /** Publishes stop_requested to IsRequested() on this thread for the lifetime of the scope. */
+ class Scope
+ {
+ public:
+ explicit Scope(const std::atomic<bool> &stop_requested) noexcept;
+ ~Scope() noexcept;
+
+ Scope(const Scope &) = delete;
+ Scope &operator=(const Scope &) = delete;
+
+ private:
+ const std::atomic<bool> *previous_;
+ };
+};
+
+} // namespace metrics
+} // namespace sdk
+OPENTELEMETRY_END_NAMESPACE
diff --git a/sdk/src/metrics/CMakeLists.txt b/sdk/src/metrics/CMakeLists.txt
--- a/sdk/src/metrics/CMakeLists.txt
+++ b/sdk/src/metrics/CMakeLists.txt
@@ -14,6 +14,7 @@ add_library(
metric_reader.cc
multi_observer_result.cc
instrument_metadata_validator.cc
+ export/collection_cancellation.cc
export/periodic_exporting_metric_reader.cc
export/periodic_exporting_metric_reader_factory.cc
export/periodic_exporting_metric_reader_options.cc
diff --git a/sdk/src/metrics/export/collection_cancellation.cc b/sdk/src/metrics/export/collection_cancellation.cc
new file mode 100644
--- /dev/null
+++ b/sdk/src/metrics/export/collection_cancellation.cc
@@ -0,0 +1,39 @@
+// Copyright The OpenTelemetry Authors
+// SPDX-License-Identifier: Apache-2.0
+
+#include <atomic>
+
+#include "opentelemetry/sdk/metrics/export/collection_cancellation.h"
+#include "opentelemetry/version.h"
+
+OPENTELEMETRY_BEGIN_NAMESPACE
+namespace sdk
+{
+namespace metrics
+{
+
+namespace
+{
+thread_local const std::atomic<bool> *current_stop_requested = nullptr;
+} // namespace
+
+bool CollectionCancellation::IsRequested() noexcept
+{
+ return current_stop_requested != nullptr &&
+ current_stop_requested->load(std::memory_order_acquire);
+}
+
+CollectionCancellation::Scope::Scope(const std::atomic<bool> &stop_requested) noexcept
+ : previous_(current_stop_requested)
+{
+ current_stop_requested = &stop_requested;
+}
+
+CollectionCancellation::Scope::~Scope() noexcept
+{
+ current_stop_requested = previous_;
+}
+
+} // namespace metrics
+} // namespace sdk
+OPENTELEMETRY_END_NAMESPACE
diff --git a/sdk/src/metrics/export/periodic_exporting_metric_reader.cc b/sdk/src/metrics/export/periodic_exporting_metric_reader.cc
--- a/sdk/src/metrics/export/periodic_exporting_metric_reader.cc
+++ b/sdk/src/metrics/export/periodic_exporting_metric_reader.cc
@@ -14,6 +14,7 @@
#include "opentelemetry/common/timestamp.h"
#include "opentelemetry/nostd/function_ref.h"
#include "opentelemetry/sdk/common/global_log_handler.h"
+#include "opentelemetry/sdk/metrics/export/collection_cancellation.h"
#include "opentelemetry/sdk/metrics/export/metric_producer.h"
#include "opentelemetry/sdk/metrics/export/periodic_exporting_metric_reader.h"
#include "opentelemetry/sdk/metrics/export/periodic_exporting_metric_reader_options.h"
@@ -161,6 +162,8 @@ void PeriodicExportingMetricReader::DoBackgroundWork()
bool PeriodicExportingMetricReader::CollectAndExportOnce()
{
std::uint64_t notify_force_flush = force_flush_pending_sequence_.load(std::memory_order_acquire);
+ // is_stop_requested_ is set once OnShutDown() has used up its flush budget.
+ const CollectionCancellation::Scope cancellation_scope(is_stop_requested_);
#if OPENTELEMETRY_HAVE_EXCEPTIONS
try
{Verified on e854d29 (GCC 11.4.0, googletest 1.14.0, SDK and tests compiled directly with g++): with the producer in the test above changed to poll CollectionCancellation::IsRequested() and return kTimeout, Shutdown(200ms) returns in under 1 s, and periodic_exporting_metric_reader_test passes. A producer that sleeps without checking, like the one in the test above, is by design not interrupted, as described above.
I can submit a PR for this.
Describe alternatives you've considered
- Doing a timed join and abandoning the worker when the budget runs out. This is unsafe as long as the worker uses reader-owned state, and [BUG] BatchSpanProcessor::Shutdown ignores its timeout when the worker thread is blocked in Export() #4532 discusses the same ownership problem.
- Having each application make its own producers deadline-aware through private side channels. This works for code the application owns, but it is not discoverable and cannot reach SDK-owned collection.
Additional context
Checked: #4532 (open) covers the untimed join() in BatchSpanProcessor/BatchLogRecordProcessor, and a maintainer comment there notes the same join in PeriodicExportingMetricReader::OnShutDown; this request is the other half, telling code inside collection to stop, and can be moved there if you prefer. #4550, #4536/#4548 and #4007 do not propagate a deadline or stop signal into collection.
Activity