Dispatcher: keeps a stack of tracked objects.

docs/root/version_history/current.rst

@@ -69,6 +69,7 @@ New Features
 * config: added ability to flush stats when the admin's :ref:`/stats endpoint <operations_admin_interface_stats>` is hit instead of on a timer via :ref:`stats_flush_on_admin <envoy_v3_api_field_config.bootstrap.v3.Bootstrap.stats_flush_on_admin>`.
 * config: added new runtime feature `envoy.features.enable_all_deprecated_features` that allows the use of all deprecated features.
 * crash support: added the ability to dump L4 connection data on crash.
+* dispatcher: supports a stack of `Envoy::ScopeTrackedObject` instead of a single tracked object. This will allow us to dump more debug information on crash.
 * formatter: added new :ref:`text_format_source <envoy_v3_api_field_config.core.v3.SubstitutionFormatString.text_format_source>` field to support format strings both inline and from a file.
 * formatter: added support for custom date formatting to :ref:`%DOWNSTREAM_PEER_CERT_V_START% <config_access_log_format_downstream_peer_cert_v_start>` and :ref:`%DOWNSTREAM_PEER_CERT_V_END% <config_access_log_format_downstream_peer_cert_v_end>`, similar to :ref:`%START_TIME% <config_access_log_format_start_time>`.
 * grpc: implemented header value syntax support when defining :ref:`initial metadata <envoy_v3_api_field_config.core.v3.GrpcService.initial_metadata>` for gRPC-based `ext_authz` :ref:`HTTP <envoy_v3_api_field_extensions.filters.http.ext_authz.v3.ExtAuthz.grpc_service>` and :ref:`network <envoy_v3_api_field_extensions.filters.network.ext_authz.v3.ExtAuthz.grpc_service>` filters, and :ref:`ratelimit <envoy_v3_api_field_config.ratelimit.v3.RateLimitServiceConfig.grpc_service>` filters.

include/envoy/event/dispatcher.h

@@ -86,15 +86,18 @@ class DispatcherBase {
   virtual Event::SchedulableCallbackPtr createSchedulableCallback(std::function<void()> cb) PURE;
 
   /**
-   * Sets a tracked object, which is currently operating in this Dispatcher.
-   * This should be cleared with another call to setTrackedObject() when the object is done doing
-   * work. Calling setTrackedObject(nullptr) results in no object being tracked.
+   * Appends a tracked object to the current stack of tracked objects operating
+   * in the dispatcher.
    *
-   * This is optimized for performance, to avoid allocation where we do scoped object tracking.
-   *
-   * @return The previously tracked object or nullptr if there was none.
+   * It's recommended to use ScopeTrackerScopeState to manage the object's tracking. If directly
+   * invoking, there needs to be a subsequent call to popTrackedObject().
+   */
+  virtual void pushTrackedObject(const ScopeTrackedObject* object) PURE;
+
+  /**
+   * Removes the top of the stack of tracked object and asserts that it was expected.
    */
-  virtual const ScopeTrackedObject* setTrackedObject(const ScopeTrackedObject* object) PURE;
+  virtual void popTrackedObject(const ScopeTrackedObject* expected_object) PURE;
 
   /**
    * Validates that an operation is thread-safe with respect to this dispatcher; i.e. that the

include/envoy/server/fatal_action_config.h

@@ -1,6 +1,7 @@
 #pragma once
 
 #include <memory>
+#include <vector>
 
 #include "envoy/common/pure.h"
 #include "envoy/config/bootstrap/v3/bootstrap.pb.h"
@@ -18,10 +19,9 @@ class FatalAction {
   virtual ~FatalAction() = default;
   /**
    * Callback function to run when we are crashing.
-   * @param current_object the object we were working on when we started
-   * crashing.
+   * @param objects a vector of objects we were working on when we started crashing.
    */
-  virtual void run(const ScopeTrackedObject* current_object) PURE;
+  virtual void run(absl::Span<const ScopeTrackedObject* const> tracked_objects) PURE;
 
   /**
    * @return whether the action is async-signal-safe.

source/common/common/scope_tracker.h

@@ -3,24 +3,35 @@
 #include "envoy/common/scope_tracker.h"
 #include "envoy/event/dispatcher.h"
 
+#include "common/common/assert.h"
+
 namespace Envoy {
 
-// A small class for tracking the scope of the object which is currently having
+// A small class for tracking the managing the scope of a tracked object which is currently having
 // work done in this thread.
 //
-// When created, it sets the tracked object in the dispatcher, and when destroyed it points the
-// dispatcher at the previously tracked object.
+// When created, it appends the tracked object to the dispatcher's stack of tracked objects, and
+// when destroyed it pops the dispatcher's stack of tracked object, which should be the object it
+// registered.
 class ScopeTrackerScopeState {
 public:
   ScopeTrackerScopeState(const ScopeTrackedObject* object, Event::Dispatcher& dispatcher)
-      : dispatcher_(dispatcher) {
-    latched_object_ = dispatcher_.setTrackedObject(object);
+      : registered_object_(object), dispatcher_(dispatcher) {
+    dispatcher_.pushTrackedObject(registered_object_);
+  }
+
+  ~ScopeTrackerScopeState() {
+    // If ScopeTrackerScopeState is always used for managing tracked objects,
+    // then the object popped off should be the object we registered.
+    dispatcher_.popTrackedObject(registered_object_);
   }
 
-  ~ScopeTrackerScopeState() { dispatcher_.setTrackedObject(latched_object_); }
+  // Make this object stack-only, it doesn't make sense for it
+  // to be on the heap since it's tracking a stack of active operations.
+  void* operator new(std::size_t) = delete;
 
 private:
-  const ScopeTrackedObject* latched_object_;
+  const ScopeTrackedObject* registered_object_;
   Event::Dispatcher& dispatcher_;
 };
 

source/common/event/dispatcher_impl.cc

@@ -7,10 +7,12 @@
 #include <vector>
 
 #include "envoy/api/api.h"
+#include "envoy/common/scope_tracker.h"
 #include "envoy/network/listen_socket.h"
 #include "envoy/network/listener.h"
 
 #include "common/buffer/buffer_impl.h"
+#include "common/common/assert.h"
 #include "common/common/lock_guard.h"
 #include "common/common/thread.h"
 #include "common/event/file_event_impl.h"
@@ -36,6 +38,12 @@
 
 namespace Envoy {
 namespace Event {
+namespace {
+// Our tracked object stack likely won't grow larger than this initial
+// reservation; this should make appends constant time since we shouldn't
+// have to grow the stack larger.
+constexpr size_t ExpectedMaxTrackedObjectStackDepth = 10;
+} // namespace
 
 DispatcherImpl::DispatcherImpl(const std::string& name, Api::Api& api,
                                Event::TimeSystem& time_system,
@@ -49,6 +57,7 @@ DispatcherImpl::DispatcherImpl(const std::string& name, Api::Api& api,
       post_cb_(base_scheduler_.createSchedulableCallback([this]() -> void { runPostCallbacks(); })),
       current_to_delete_(&to_delete_1_) {
   ASSERT(!name_.empty());
+  tracked_object_stack_.reserve(ExpectedMaxTrackedObjectStackDepth);
   FatalErrorHandler::registerFatalErrorHandler(*this);
   updateApproximateMonotonicTimeInternal();
   base_scheduler_.registerOnPrepareCallback(
@@ -287,6 +296,16 @@ void DispatcherImpl::runPostCallbacks() {
   }
 }
 
+void DispatcherImpl::onFatalError(std::ostream& os) const {
+  // Dump the state of the tracked objects in the dispatcher if thread safe. This generally
+  // results in dumping the active state only for the thread which caused the fatal error.
+  if (isThreadSafe()) {
+    for (auto iter = tracked_object_stack_.rbegin(); iter != tracked_object_stack_.rend(); ++iter) {
+      (*iter)->dumpState(os);
+    }
+  }
+}
+
 void DispatcherImpl::runFatalActionsOnTrackedObject(
     const FatalAction::FatalActionPtrList& actions) const {
   // Only run if this is the dispatcher of the current thread and
@@ -296,7 +315,7 @@ void DispatcherImpl::runFatalActionsOnTrackedObject(
   }
 
   for (const auto& action : actions) {
-    action->run(current_object_);
+    action->run(tracked_object_stack_);
   }
 }
 
@@ -306,5 +325,26 @@ void DispatcherImpl::touchWatchdog() {
   }
 }
 
+void DispatcherImpl::pushTrackedObject(const ScopeTrackedObject* object) {
+  ASSERT(isThreadSafe());
+  ASSERT(object != nullptr);
+  tracked_object_stack_.push_back(object);
+}
+
+void DispatcherImpl::popTrackedObject(const ScopeTrackedObject* expected_object) {
+  ASSERT(isThreadSafe());
+  ASSERT(expected_object != nullptr);
+  if (tracked_object_stack_.empty()) {
+    ASSERT(!expected_object,
+           "Tracked object stack is empty yet we expected a non-null tracked object on the top.");
+    return;
+  }
+
+  const ScopeTrackedObject* top = tracked_object_stack_.back();
+  tracked_object_stack_.pop_back();
+  ASSERT(top == expected_object,
+         "Popped the top of the tracked object stack, but it wasn't the expected object!");
+}
+
 } // namespace Event
 } // namespace Envoy

source/common/event/dispatcher_impl.h

@@ -74,25 +74,13 @@ class DispatcherImpl : Logger::Loggable<Logger::Id::main>,
   void post(std::function<void()> callback) override;
   void run(RunType type) override;
   Buffer::WatermarkFactory& getWatermarkFactory() override { return *buffer_factory_; }
-  const ScopeTrackedObject* setTrackedObject(const ScopeTrackedObject* object) override {
-    const ScopeTrackedObject* return_object = current_object_;
-    current_object_ = object;
-    return return_object;
-  }
+  void pushTrackedObject(const ScopeTrackedObject* object) override;
+  void popTrackedObject(const ScopeTrackedObject* expected_object) override;
   MonotonicTime approximateMonotonicTime() const override;
   void updateApproximateMonotonicTime() override;
 
   // FatalErrorInterface
-  void onFatalError(std::ostream& os) const override {
-    // Dump the state of the tracked object if it is in the current thread. This generally results
-    // in dumping the active state only for the thread which caused the fatal error.
-    if (isThreadSafe()) {
-      if (current_object_) {
-        current_object_->dumpState(os);
-      }
-    }
-  }
-
+  void onFatalError(std::ostream& os) const override;
   void
   runFatalActionsOnTrackedObject(const FatalAction::FatalActionPtrList& actions) const override;
 
@@ -150,7 +138,7 @@ class DispatcherImpl : Logger::Loggable<Logger::Id::main>,
   std::vector<DeferredDeletablePtr>* current_to_delete_;
   Thread::MutexBasicLockable post_lock_;
   std::list<std::function<void()>> post_callbacks_ ABSL_GUARDED_BY(post_lock_);
-  const ScopeTrackedObject* current_object_{};
+  std::vector<const ScopeTrackedObject*> tracked_object_stack_;
   bool deferred_deleting_{};
   MonotonicTime approximate_monotonic_time_;
   WatchdogRegistrationPtr watchdog_registration_;

test/common/common/BUILD

@@ -361,3 +361,15 @@ envoy_cc_test(
     srcs = ["interval_value_test.cc"],
     deps = ["//source/common/common:interval_value"],
 )
+
+envoy_cc_test(
+    name = "scope_tracker_test",
+    srcs = ["scope_tracker_test.cc"],
+    deps = [
+        "//source/common/api:api_lib",
+        "//source/common/common:scope_tracker",
+        "//source/common/event:dispatcher_lib",
+        "//test/mocks:common_lib",
+        "//test/test_common:utility_lib",
+    ],
+)

test/common/common/scope_tracker_test.cc

@@ -0,0 +1,37 @@
+#include <iostream>
+
+#include "common/api/api_impl.h"
+#include "common/common/scope_tracker.h"
+#include "common/event/dispatcher_impl.h"
+
+#include "test/mocks/common.h"
+#include "test/test_common/utility.h"
+
+#include "gmock/gmock.h"
+#include "gtest/gtest.h"
+
+namespace Envoy {
+namespace {
+
+using testing::_;
+
+TEST(ScopeTrackerScopeStateTest, ShouldManageTrackedObjectOnDispatcherStack) {
+  Api::ApiPtr api(Api::createApiForTest());
+  Event::DispatcherPtr dispatcher(api->allocateDispatcher("test_thread"));
+  MockScopedTrackedObject tracked_object;
+  {
+    ScopeTrackerScopeState scope(&tracked_object, *dispatcher);
+    // Check that the tracked_object is on the tracked object stack
+    dispatcher->popTrackedObject(&tracked_object);
+
+    // Restore it to the top, it should be removed in the dtor of scope.
+    dispatcher->pushTrackedObject(&tracked_object);
+  }
+
+  // Check nothing is tracked now.
+  EXPECT_CALL(tracked_object, dumpState(_, _)).Times(0);
+  static_cast<Event::DispatcherImpl*>(dispatcher.get())->onFatalError(std::cerr);
+}
+
+} // namespace
+} // namespace Envoy

test/common/event/dispatcher_impl_test.cc

@@ -1,10 +1,13 @@
 #include <functional>
 
+#include "envoy/common/scope_tracker.h"
 #include "envoy/thread/thread.h"
 
 #include "common/api/api_impl.h"
 #include "common/api/os_sys_calls_impl.h"
 #include "common/common/lock_guard.h"
+#include "common/common/scope_tracker.h"
+#include "common/common/utility.h"
 #include "common/event/deferred_task.h"
 #include "common/event/dispatcher_impl.h"
 #include "common/event/timer_impl.h"
@@ -533,9 +536,71 @@ TEST_F(DispatcherImplTest, IsThreadSafe) {
   EXPECT_FALSE(dispatcher_->isThreadSafe());
 }
 
+TEST_F(DispatcherImplTest, ShouldDumpNothingIfNoTrackedObjects) {
+  std::array<char, 1024> buffer;
+  OutputBufferStream ostream{buffer.data(), buffer.size()};
+
+  // Call on FatalError to trigger dumps of tracked objects.
+  dispatcher_->post([this, &ostream]() {
+    Thread::LockGuard lock(mu_);
+    static_cast<DispatcherImpl*>(dispatcher_.get())->onFatalError(ostream);
+    work_finished_ = true;
+    cv_.notifyOne();
+  });
+
+  Thread::LockGuard lock(mu_);
+  while (!work_finished_) {
+    cv_.wait(mu_);
+  }
+
+  // Check ostream still empty.
+  EXPECT_EQ(ostream.contents(), "");
+}
+
+class MessageTrackedObject : public ScopeTrackedObject {
+public:
+  MessageTrackedObject(absl::string_view sv) : sv_(sv) {}
+  void dumpState(std::ostream& os, int /*indent_level*/) const override { os << sv_; }
+
+private:
+  absl::string_view sv_;
+};
+
+TEST_F(DispatcherImplTest, ShouldDumpTrackedObjectsInFILO) {
+  std::array<char, 1024> buffer;
+  OutputBufferStream ostream{buffer.data(), buffer.size()};
+
+  // Call on FatalError to trigger dumps of tracked objects.
+  dispatcher_->post([this, &ostream]() {
+    Thread::LockGuard lock(mu_);
+
+    // Add several tracked objects to the dispatcher
+    MessageTrackedObject first{"first"};
+    ScopeTrackerScopeState first_state{&first, *dispatcher_};
+    MessageTrackedObject second{"second"};
+    ScopeTrackerScopeState second_state{&second, *dispatcher_};
+    MessageTrackedObject third{"third"};
+    ScopeTrackerScopeState third_state{&third, *dispatcher_};
+
+    static_cast<DispatcherImpl*>(dispatcher_.get())->onFatalError(ostream);
+    work_finished_ = true;
+    cv_.notifyOne();
+  });
+
+  Thread::LockGuard lock(mu_);
+  while (!work_finished_) {
+    cv_.wait(mu_);
+  }
+
+  // Check the dump includes and registered objects in a FILO order.
+  EXPECT_EQ(ostream.contents(), "thirdsecondfirst");
+}
+
 class TestFatalAction : public Server::Configuration::FatalAction {
 public:
-  void run(const ScopeTrackedObject* /*current_object*/) override { ++times_ran_; }
+  void run(absl::Span<const ScopeTrackedObject* const> /*tracked_objects*/) override {
+    ++times_ran_;
+  }
   bool isAsyncSignalSafe() const override { return true; }
   int getNumTimesRan() { return times_ran_; }
 

test/common/event/scaled_range_timer_manager_impl_test.cc

@@ -1,5 +1,6 @@
 #include <chrono>
 
+#include "envoy/common/scope_tracker.h"
 #include "envoy/event/timer.h"
 
 #include "common/event/dispatcher_impl.h"
@@ -24,9 +25,14 @@ class ScopeTrackingDispatcher : public WrappedDispatcher {
   ScopeTrackingDispatcher(DispatcherPtr dispatcher)
       : WrappedDispatcher(*dispatcher), dispatcher_(std::move(dispatcher)) {}
 
-  const ScopeTrackedObject* setTrackedObject(const ScopeTrackedObject* object) override {
+  void pushTrackedObject(const ScopeTrackedObject* object) override {
     scope_ = object;
-    return impl_.setTrackedObject(object);
+    return impl_.pushTrackedObject(object);
+  }
+
+  void popTrackedObject(const ScopeTrackedObject* expected_object) override {
+    scope_ = nullptr;
+    return impl_.popTrackedObject(expected_object);
   }
 
   const ScopeTrackedObject* scope_{nullptr};