Reorder the destructor of members in LoggerProvider and TracerProvider (#1245)

owent · web-flow · commit c96a3e32f0b5 · 2022-03-08T10:17:02.000-08:00
diff --git a/exporters/elasticsearch/include/opentelemetry/exporters/elasticsearch/es_log_recordable.h b/exporters/elasticsearch/include/opentelemetry/exporters/elasticsearch/es_log_recordable.h
@@ -111,9 +111,8 @@ class ElasticSearchRecordable final : public sdk::logs::Recordable
   void SetSeverity(opentelemetry::logs::Severity severity) noexcept override
   {
     // Convert the severity enum to a string
-    int severity_index = static_cast<int>(severity);
-    if (severity_index < 0 ||
-        severity_index >= std::extent<decltype(opentelemetry::logs::SeverityNumToText)>::value)
+    std::uint32_t severity_index = static_cast<std::uint32_t>(severity);
+    if (severity_index >= std::extent<decltype(opentelemetry::logs::SeverityNumToText)>::value)
     {
       std::stringstream sout;
       sout << "Invalid severity(" << severity_index << ")";
diff --git a/exporters/ostream/src/log_exporter.cc b/exporters/ostream/src/log_exporter.cc
@@ -146,12 +146,11 @@ sdk::common::ExportResult OStreamLogExporter::Export(
     // into severity_num and severity_text
     sout_ << "{\n"
           << "  timestamp     : " << log_record->GetTimestamp().time_since_epoch().count() << "\n"
-          << "  severity_num  : " << static_cast<int>(log_record->GetSeverity()) << "\n"
+          << "  severity_num  : " << static_cast<std::uint32_t>(log_record->GetSeverity()) << "\n"
           << "  severity_text : ";
 
-    int severity_index = static_cast<int>(log_record->GetSeverity());
-    if (severity_index < 0 ||
-        severity_index >= std::extent<decltype(opentelemetry::logs::SeverityNumToText)>::value)
+    std::uint32_t severity_index = static_cast<std::uint32_t>(log_record->GetSeverity());
+    if (severity_index >= std::extent<decltype(opentelemetry::logs::SeverityNumToText)>::value)
     {
       sout_ << "Invalid severity(" << severity_index << ")\n";
     }
diff --git a/exporters/otlp/src/otlp_grpc_exporter.cc b/exporters/otlp/src/otlp_grpc_exporter.cc
@@ -110,6 +110,11 @@ sdk::common::ExportResult OtlpGrpcExporter::Export(
                                                      << " span(s) failed, exporter is shutdown");
     return sdk::common::ExportResult::kFailure;
   }
+  if (spans.empty())
+  {
+    return sdk::common::ExportResult::kSuccess;
+  }
+
   proto::collector::trace::v1::ExportTraceServiceRequest request;
   OtlpRecordableUtils::PopulateRequest(spans, &request);
 
diff --git a/exporters/otlp/src/otlp_grpc_log_exporter.cc b/exporters/otlp/src/otlp_grpc_log_exporter.cc
@@ -131,6 +131,11 @@ opentelemetry::sdk::common::ExportResult OtlpGrpcLogExporter::Export(
                                                          << " log(s) failed, exporter is shutdown");
     return sdk::common::ExportResult::kFailure;
   }
+  if (logs.empty())
+  {
+    return sdk::common::ExportResult::kSuccess;
+  }
+
   proto::collector::logs::v1::ExportLogsServiceRequest request;
   OtlpRecordableUtils::PopulateRequest(logs, &request);
 
diff --git a/exporters/otlp/src/otlp_http_exporter.cc b/exporters/otlp/src/otlp_http_exporter.cc
@@ -46,6 +46,11 @@ std::unique_ptr<opentelemetry::sdk::trace::Recordable> OtlpHttpExporter::MakeRec
 opentelemetry::sdk::common::ExportResult OtlpHttpExporter::Export(
     const nostd::span<std::unique_ptr<opentelemetry::sdk::trace::Recordable>> &spans) noexcept
 {
+  if (spans.empty())
+  {
+    return opentelemetry::sdk::common::ExportResult::kSuccess;
+  }
+
   proto::collector::trace::v1::ExportTraceServiceRequest service_request;
   OtlpRecordableUtils::PopulateRequest(spans, &service_request);
   return http_client_->Export(service_request);
diff --git a/exporters/otlp/src/otlp_http_log_exporter.cc b/exporters/otlp/src/otlp_http_log_exporter.cc
@@ -48,6 +48,10 @@ std::unique_ptr<opentelemetry::sdk::logs::Recordable> OtlpHttpLogExporter::MakeR
 opentelemetry::sdk::common::ExportResult OtlpHttpLogExporter::Export(
     const nostd::span<std::unique_ptr<opentelemetry::sdk::logs::Recordable>> &logs) noexcept
 {
+  if (logs.empty())
+  {
+    return opentelemetry::sdk::common::ExportResult::kSuccess;
+  }
   proto::collector::logs::v1::ExportLogsServiceRequest service_request;
   OtlpRecordableUtils::PopulateRequest(logs, &service_request);
   return http_client_->Export(service_request);
diff --git a/exporters/otlp/test/otlp_http_log_exporter_test.cc b/exporters/otlp/test/otlp_http_log_exporter_test.cc
@@ -103,7 +103,7 @@ TEST_F(OtlpHttpLogExporterTestPeer, ExportJsonIntegrationTest)
 
   auto provider = nostd::shared_ptr<sdk::logs::LoggerProvider>(new sdk::logs::LoggerProvider());
   provider->AddProcessor(std::unique_ptr<sdk::logs::LogProcessor>(
-      new sdk::logs::BatchLogProcessor(std::move(exporter), 5, std::chrono::milliseconds(256), 1)));
+      new sdk::logs::BatchLogProcessor(std::move(exporter), 5, std::chrono::milliseconds(256), 5)));
 
   std::string report_trace_id;
   std::string report_span_id;
@@ -192,7 +192,7 @@ TEST_F(OtlpHttpLogExporterTestPeer, ExportBinaryIntegrationTest)
 
   auto provider = nostd::shared_ptr<sdk::logs::LoggerProvider>(new sdk::logs::LoggerProvider());
   provider->AddProcessor(std::unique_ptr<sdk::logs::LogProcessor>(
-      new sdk::logs::BatchLogProcessor(std::move(exporter), 5, std::chrono::milliseconds(256), 1)));
+      new sdk::logs::BatchLogProcessor(std::move(exporter), 5, std::chrono::milliseconds(256), 5)));
 
   std::string report_trace_id;
   std::string report_span_id;
diff --git a/ext/test/http/curl_http_test.cc b/ext/test/http/curl_http_test.cc
@@ -291,7 +291,9 @@ TEST_F(BasicCurlHttpTests, SendGetRequestSyncTimeout)
   auto result             = http_client.Get("http://222.222.222.200:19000/get/", m1);
   EXPECT_EQ(result, false);
 
-  EXPECT_EQ(result.GetSessionState(), http_client::SessionState::ConnectFailed);
+  // When network is under proxy, it may connect success but closed by peer when send data
+  EXPECT_TRUE(result.GetSessionState() == http_client::SessionState::ConnectFailed ||
+              result.GetSessionState() == http_client::SessionState::SendFailed);
 }
 
 TEST_F(BasicCurlHttpTests, SendPostRequestSync)
diff --git a/sdk/include/opentelemetry/sdk/_metrics/controller.h b/sdk/include/opentelemetry/sdk/_metrics/controller.h
@@ -80,7 +80,10 @@ class PushController
   {
     if (active_.exchange(false))
     {
-      runner_.join();
+      if (runner_.joinable())
+      {
+        runner_.join();
+      }
       tick();  // flush metrics sitting in the processor
     }
   }
diff --git a/sdk/include/opentelemetry/sdk/logs/batch_log_processor.h b/sdk/include/opentelemetry/sdk/logs/batch_log_processor.h
@@ -108,7 +108,7 @@ class BatchLogProcessor : public LogProcessor
 
   /* Synchronization primitives */
   std::condition_variable cv_, force_flush_cv_;
-  std::mutex cv_m_, force_flush_cv_m_;
+  std::mutex cv_m_, force_flush_cv_m_, shutdown_m_;
 
   /* The buffer/queue to which the ended logs are added */
   common::CircularBuffer<Recordable> buffer_;
diff --git a/sdk/include/opentelemetry/sdk/logs/logger.h b/sdk/include/opentelemetry/sdk/logs/logger.h
@@ -67,9 +67,10 @@ class Logger final : public opentelemetry::logs::Logger
   // The name of this logger
   std::string logger_name_;
 
-  // The logger context of this Logger. Uses a weak_ptr to avoid cyclic dependency issues the with
-  std::weak_ptr<LoggerContext> context_;
+  // order of declaration is important here - instrumentation library should destroy after
+  // logger-context.
   std::unique_ptr<instrumentationlibrary::InstrumentationLibrary> instrumentation_library_;
+  std::shared_ptr<LoggerContext> context_;
 };
 
 }  // namespace logs
diff --git a/sdk/include/opentelemetry/sdk/logs/logger_provider.h b/sdk/include/opentelemetry/sdk/logs/logger_provider.h
@@ -61,6 +61,8 @@ class LoggerProvider final : public opentelemetry::logs::LoggerProvider
    */
   explicit LoggerProvider(std::shared_ptr<sdk::logs::LoggerContext> context) noexcept;
 
+  ~LoggerProvider();
+
   /**
    * Creates a logger with the given name, and returns a shared pointer to it.
    * If a logger with that name already exists, return a shared pointer to it
@@ -107,14 +109,20 @@ class LoggerProvider final : public opentelemetry::logs::LoggerProvider
    */
   const opentelemetry::sdk::resource::Resource &GetResource() const noexcept;
 
-private:
-  // A pointer to the processor stored by this logger provider
-  std::shared_ptr<sdk::logs::LoggerContext> context_;
+  /**
+   * Shutdown the log processor associated with this log provider.
+   */
+  bool Shutdown() noexcept;
 
-  // A vector of pointers to all the loggers that have been created
-  std::vector<std::shared_ptr<opentelemetry::sdk::logs::Logger>> loggers_;
+  /**
+   * Force flush the log processor associated with this log provider.
+   */
+  bool ForceFlush(std::chrono::microseconds timeout = (std::chrono::microseconds::max)()) noexcept;
 
-  // A mutex that ensures only one thread is using the map of loggers
+private:
+  // order of declaration is important here - loggers should destroy only after context.
+  std::vector<std::shared_ptr<opentelemetry::sdk::logs::Logger>> loggers_;
+  std::shared_ptr<sdk::logs::LoggerContext> context_;
   std::mutex lock_;
 };
 }  // namespace logs
diff --git a/sdk/include/opentelemetry/sdk/trace/batch_span_processor.h b/sdk/include/opentelemetry/sdk/trace/batch_span_processor.h
@@ -139,7 +139,7 @@ class BatchSpanProcessor : public SpanProcessor
 
   /* Synchronization primitives */
   std::condition_variable cv_, force_flush_cv_;
-  std::mutex cv_m_, force_flush_cv_m_;
+  std::mutex cv_m_, force_flush_cv_m_, shutdown_m_;
 
   /* The buffer/queue to which the ended spans are added */
   common::CircularBuffer<Recordable> buffer_;
diff --git a/sdk/include/opentelemetry/sdk/trace/tracer_provider.h b/sdk/include/opentelemetry/sdk/trace/tracer_provider.h
@@ -59,6 +59,8 @@ class TracerProvider final : public opentelemetry::trace::TracerProvider
    */
   explicit TracerProvider(std::shared_ptr<sdk::trace::TracerContext> context) noexcept;
 
+  ~TracerProvider();
+
   opentelemetry::nostd::shared_ptr<opentelemetry::trace::Tracer> GetTracer(
       nostd::string_view library_name,
       nostd::string_view library_version = "",
diff --git a/sdk/src/logs/batch_log_processor.cc b/sdk/src/logs/batch_log_processor.cc
@@ -176,11 +176,17 @@ void BatchLogProcessor::DrainQueue()
 
 bool BatchLogProcessor::Shutdown(std::chrono::microseconds timeout) noexcept
 {
-  is_shutdown_.store(true);
+  std::lock_guard<std::mutex> shutdown_guard{shutdown_m_};
+  bool already_shutdown = is_shutdown_.exchange(true);
 
-  cv_.notify_one();
-  worker_thread_.join();
-  if (exporter_ != nullptr)
+  if (worker_thread_.joinable())
+  {
+    cv_.notify_one();
+    worker_thread_.join();
+  }
+
+  // Should only shutdown exporter ONCE.
+  if (!already_shutdown && exporter_ != nullptr)
   {
     return exporter_->Shutdown();
   }
diff --git a/sdk/src/logs/logger.cc b/sdk/src/logs/logger.cc
@@ -21,8 +21,8 @@ Logger::Logger(nostd::string_view name,
                std::unique_ptr<instrumentationlibrary::InstrumentationLibrary>
                    instrumentation_library) noexcept
     : logger_name_(std::string(name)),
-      context_(context),
-      instrumentation_library_{std::move(instrumentation_library)}
+      instrumentation_library_(std::move(instrumentation_library)),
+      context_(context)
 {}
 
 const nostd::string_view Logger::GetName() noexcept
@@ -45,12 +45,11 @@ void Logger::Log(opentelemetry::logs::Severity severity,
                  common::SystemTimestamp timestamp) noexcept
 {
   // If this logger does not have a processor, no need to create a log record
-  auto context = context_.lock();
-  if (!context)
+  if (!context_)
   {
     return;
   }
-  auto &processor = context->GetProcessor();
+  auto &processor = context_->GetProcessor();
 
   // TODO: Sampler (should include check for minSeverity)
 
@@ -68,7 +67,7 @@ void Logger::Log(opentelemetry::logs::Severity severity,
   recordable->SetBody(body);
   recordable->SetInstrumentationLibrary(GetInstrumentationLibrary());
 
-  recordable->SetResource(context->GetResource());
+  recordable->SetResource(context_->GetResource());
 
   attributes.ForEachKeyValue([&](nostd::string_view key, common::AttributeValue value) noexcept {
     recordable->SetAttribute(key, value);
diff --git a/sdk/src/logs/logger_provider.cc b/sdk/src/logs/logger_provider.cc
@@ -43,6 +43,17 @@ LoggerProvider::LoggerProvider(std::shared_ptr<sdk::logs::LoggerContext> context
     : context_{context}
 {}
 
+LoggerProvider::~LoggerProvider()
+{
+  // Logger hold the shared pointer to the context. So we can not use destructor of LoggerContext to
+  // Shutdown and flush all pending recordables when we hasve more than one loggers.These
+  // recordables may use the raw pointer of instrumentation_library_ in Logger
+  if (context_)
+  {
+    context_->Shutdown();
+  }
+}
+
 nostd::shared_ptr<opentelemetry::logs::Logger> LoggerProvider::GetLogger(
     nostd::string_view logger_name,
     nostd::string_view options,
@@ -105,6 +116,16 @@ const opentelemetry::sdk::resource::Resource &LoggerProvider::GetResource() cons
   return context_->GetResource();
 }
 
+bool LoggerProvider::Shutdown() noexcept
+{
+  return context_->Shutdown();
+}
+
+bool LoggerProvider::ForceFlush(std::chrono::microseconds timeout) noexcept
+{
+  return context_->ForceFlush(timeout);
+}
+
 }  // namespace logs
 }  // namespace sdk
 OPENTELEMETRY_END_NAMESPACE
diff --git a/sdk/src/logs/multi_log_processor.cc b/sdk/src/logs/multi_log_processor.cc
@@ -129,10 +129,8 @@ bool MultiLogProcessor::Shutdown(std::chrono::microseconds timeout) noexcept
   }
   for (auto &processor : processors_)
   {
-    if (!processor->Shutdown(std::chrono::duration_cast<std::chrono::microseconds>(timeout_ns)))
-    {
-      result = false;
-    }
+    result |=
+        processor->Shutdown(std::chrono::duration_cast<std::chrono::microseconds>(timeout_ns));
     start_time = std::chrono::system_clock::now();
     if (expire_time > start_time)
     {
diff --git a/sdk/src/logs/simple_log_processor.cc b/sdk/src/logs/simple_log_processor.cc
@@ -51,12 +51,12 @@ bool SimpleLogProcessor::ForceFlush(std::chrono::microseconds timeout) noexcept
 bool SimpleLogProcessor::Shutdown(std::chrono::microseconds timeout) noexcept
 {
   // Should only shutdown exporter ONCE.
-  if (!shutdown_latch_.test_and_set(std::memory_order_acquire))
+  if (!shutdown_latch_.test_and_set(std::memory_order_acquire) && exporter_ != nullptr)
   {
     return exporter_->Shutdown(timeout);
   }
 
-  return false;
+  return true;
 }
 }  // namespace logs
 }  // namespace sdk
diff --git a/sdk/src/trace/batch_span_processor.cc b/sdk/src/trace/batch_span_processor.cc
@@ -180,11 +180,17 @@ void BatchSpanProcessor::DrainQueue()
 
 bool BatchSpanProcessor::Shutdown(std::chrono::microseconds timeout) noexcept
 {
-  is_shutdown_.store(true);
+  std::lock_guard<std::mutex> shutdown_guard{shutdown_m_};
+  bool already_shutdown = is_shutdown_.exchange(true);
 
-  cv_.notify_one();
-  worker_thread_.join();
-  if (exporter_ != nullptr)
+  if (worker_thread_.joinable())
+  {
+    cv_.notify_one();
+    worker_thread_.join();
+  }
+
+  // Should only shutdown exporter ONCE.
+  if (!already_shutdown && exporter_ != nullptr)
   {
     return exporter_->Shutdown();
   }
diff --git a/sdk/src/trace/tracer_provider.cc b/sdk/src/trace/tracer_provider.cc
@@ -36,6 +36,17 @@ TracerProvider::TracerProvider(std::vector<std::unique_ptr<SpanProcessor>> &&pro
                                              std::move(id_generator));
 }
 
+TracerProvider::~TracerProvider()
+{
+  // Tracer hold the shared pointer to the context. So we can not use destructor of TracerContext to
+  // Shutdown and flush all pending recordables when we have more than one tracers.These recordables
+  // may use the raw pointer of instrumentation_library_ in Tracer
+  if (context_)
+  {
+    context_->Shutdown();
+  }
+}
+
 nostd::shared_ptr<trace_api::Tracer> TracerProvider::GetTracer(
     nostd::string_view library_name,
     nostd::string_view library_version,
diff --git a/sdk/test/logs/batch_log_processor_test.cc b/sdk/test/logs/batch_log_processor_test.cc
@@ -118,6 +118,8 @@ TEST_F(BatchLogProcessorTest, TestShutdown)
   // current batch of logs to be sent to the log exporter
   // by checking the number of logs sent and the names of the logs sent
   EXPECT_EQ(true, batch_processor->Shutdown());
+  // It's safe to shutdown again
+  EXPECT_TRUE(batch_processor->Shutdown());
 
   EXPECT_EQ(num_logs, logs_received->size());
 
diff --git a/sdk/test/logs/logger_provider_sdk_test.cc b/sdk/test/logs/logger_provider_sdk_test.cc
@@ -10,6 +10,7 @@
 #  include "opentelemetry/sdk/logs/log_record.h"
 #  include "opentelemetry/sdk/logs/logger.h"
 #  include "opentelemetry/sdk/logs/logger_provider.h"
+#  include "opentelemetry/sdk/logs/simple_log_processor.h"
 
 #  include <gtest/gtest.h>
 
@@ -103,4 +104,30 @@ TEST(LoggerProviderSDK, GetResource)
   LoggerProvider lp{nullptr, resource};
   ASSERT_EQ(nostd::get<std::string>(lp.GetResource().GetAttributes().at("key")), "value");
 }
+
+TEST(LoggerProviderSDK, Shutdown)
+{
+  std::unique_ptr<SimpleLogProcessor> processor(new SimpleLogProcessor(nullptr));
+  std::vector<std::unique_ptr<LogProcessor>> processors;
+  processors.push_back(std::move(processor));
+
+  LoggerProvider lp(std::make_shared<LoggerContext>(std::move(processors)));
+
+  EXPECT_TRUE(lp.Shutdown());
+
+  // It's safe to shutdown again
+  EXPECT_TRUE(lp.Shutdown());
+}
+
+TEST(LoggerProviderSDK, ForceFlush)
+{
+  std::unique_ptr<SimpleLogProcessor> processor(new SimpleLogProcessor(nullptr));
+  std::vector<std::unique_ptr<LogProcessor>> processors;
+  processors.push_back(std::move(processor));
+
+  LoggerProvider lp(std::make_shared<LoggerContext>(std::move(processors)));
+
+  EXPECT_TRUE(lp.ForceFlush());
+}
+
 #endif
diff --git a/sdk/test/logs/simple_log_processor_test.cc b/sdk/test/logs/simple_log_processor_test.cc
diff --git a/sdk/test/trace/batch_span_processor_test.cc b/sdk/test/trace/batch_span_processor_test.cc
diff --git a/sdk/test/trace/tracer_provider_test.cc b/sdk/test/trace/tracer_provider_test.cc

Original file line number	Diff line number	Diff line change
`@@ -111,9 +111,8 @@ class ElasticSearchRecordable final : public sdk::logs::Recordable`
`111`	`111`	`void SetSeverity(opentelemetry::logs::Severity severity) noexcept override`
`112`	`112`	`{`
`113`	`113`	`// Convert the severity enum to a string`
`114`		`- int severity_index = static_cast<int>(severity);`
`115`		`- if (severity_index < 0 \|\|`
`116`		`- severity_index >= std::extent<decltype(opentelemetry::logs::SeverityNumToText)>::value)`
	`114`	`+ std::uint32_t severity_index = static_cast<std::uint32_t>(severity);`
	`115`	`+ if (severity_index >= std::extent<decltype(opentelemetry::logs::SeverityNumToText)>::value)`
`117`	`116`	`{`
`118`	`117`	`std::stringstream sout;`
`119`	`118`	`sout << "Invalid severity(" << severity_index << ")";`
Original file line number	Diff line number	Diff line change
`@@ -291,7 +291,9 @@ TEST_F(BasicCurlHttpTests, SendGetRequestSyncTimeout)`
`291`	`291`	`auto result = http_client.Get("http://222.222.222.200:19000/get/", m1);`
`292`	`292`	`EXPECT_EQ(result, false);`
`293`	`293`
`294`		`- EXPECT_EQ(result.GetSessionState(), http_client::SessionState::ConnectFailed);`
	`294`	`+ // When network is under proxy, it may connect success but closed by peer when send data`
	`295`	`+ EXPECT_TRUE(result.GetSessionState() == http_client::SessionState::ConnectFailed \|\|`
	`296`	`+ result.GetSessionState() == http_client::SessionState::SendFailed);`
`295`	`297`	`}`
`296`	`298`
`297`	`299`	`TEST_F(BasicCurlHttpTests, SendPostRequestSync)`
Original file line number	Diff line number	Diff line change
`@@ -80,7 +80,10 @@ class PushController`
`80`	`80`	`{`
`81`	`81`	`if (active_.exchange(false))`
`82`	`82`	`{`
`83`		`- runner_.join();`
	`83`	`+ if (runner_.joinable())`
	`84`	`+ {`
	`85`	`+ runner_.join();`
	`86`	`+ }`
`84`	`87`	`tick(); // flush metrics sitting in the processor`
`85`	`88`	`}`
`86`	`89`	`}`