Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

http: dumping session state on the decode path #7390

Merged
merged 14 commits into from
Jul 3, 2019
1 change: 1 addition & 0 deletions docs/root/intro/version_history.rst
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,7 @@ Version history
* http: added support for :ref:`preserve_external_request_id<envoy_api_field_config.filter.network.http_connection_manager.v2.HttpConnectionManager.preserve_external_request_id>` that represents whether the x-request-id should not be reset on edge entry inside mesh
* http: changed `sendLocalReply` to send percent-encoded `GrpcMessage`.
* http: added :ref:`dynamic forward proxy <arch_overview_http_dynamic_forward_proxy>` support.
* http: tracking the active stream and dumping state in Envoy crash handlers. This can be disabled by building with -DENVOY_SKIP_OBJECT_TRACE_ON_DUMP
Copy link
Member

Choose a reason for hiding this comment

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

Can we add a bazel config setting similar to https://github.com/envoyproxy/envoy/blob/master/bazel/BUILD#L98? And then also document here: https://github.com/envoyproxy/envoy/tree/master/bazel#disabling-optional-features? And maybe also define this in the compile time options CI build? Also, does disabling signal traces implicitly disable this? I think so but maybe I'm not reading the code correctly? If that's the case can we document that?

* jwt_authn: make filter's parsing of JWT more flexible, allowing syntax like ``jwt=eyJhbGciOiJS...ZFnFIw,extra=7,realm=123``
* listener: added :ref:`source IP <envoy_api_field_listener.FilterChainMatch.source_prefix_ranges>`
and :ref:`source port <envoy_api_field_listener.FilterChainMatch.source_ports>` filter
Expand Down
5 changes: 5 additions & 0 deletions include/envoy/common/BUILD
Original file line number Diff line number Diff line change
Expand Up @@ -51,3 +51,8 @@ envoy_cc_library(
name = "backoff_strategy_interface",
hdrs = ["backoff_strategy.h"],
)

envoy_cc_library(
name = "scope_tracker_interface",
hdrs = ["scope_tracker.h"],
)
29 changes: 29 additions & 0 deletions include/envoy/common/scope_tracker.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,29 @@
#pragma once

#include <ostream>

#include "envoy/common/pure.h"

namespace Envoy {

/*
* A class for tracking the scope of work.
* Currently this is only used for best-effort tracking the L7 stream doing
* work if a fatal error occurs.
*/
class ScopeTrackedObject {
public:
virtual ~ScopeTrackedObject() = default;

/**
* Dump debug state of the object in question to the provided ostream
*
* This is called on Envoy fatal errors, so should do minimal memory allocation.
*
* @param os the ostream to output to.
* @param indent_level how far to indent, for pretty-printed classes and subclasses.
*/
virtual void dumpState(std::ostream& os, int indent_level = 0) const PURE;
};

} // namespace Envoy
1 change: 1 addition & 0 deletions include/envoy/event/BUILD
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,7 @@ envoy_cc_library(
":deferred_deletable",
":file_event_interface",
":signal_interface",
"//include/envoy/common:scope_tracker_interface",
"//include/envoy/common:time_interface",
"//include/envoy/event:timer_interface",
"//include/envoy/filesystem:watcher_interface",
Expand Down
12 changes: 12 additions & 0 deletions include/envoy/event/dispatcher.h
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@
#include <string>
#include <vector>

#include "envoy/common/scope_tracker.h"
#include "envoy/common/time.h"
#include "envoy/event/file_event.h"
#include "envoy/event/signal.h"
Expand Down Expand Up @@ -199,6 +200,17 @@ class Dispatcher {
* @return the watermark buffer factory for this dispatcher.
*/
virtual Buffer::WatermarkFactory& getWatermarkFactory() PURE;

/**
* Sets a tracked object, which is currently operating in this Dispatcher.
mattklein123 marked this conversation as resolved.
Show resolved Hide resolved
* 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.
*
* 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.
*/
virtual const ScopeTrackedObject* setTrackedObject(const ScopeTrackedObject* object) PURE;
};

using DispatcherPtr = std::unique_ptr<Dispatcher>;
Expand Down
18 changes: 11 additions & 7 deletions include/envoy/http/header_map.h
Original file line number Diff line number Diff line change
Expand Up @@ -527,19 +527,23 @@ class HeaderMap {
*/
virtual bool empty() const PURE;

/**
* Dump the header map to the ostream specified
*
* @param os the stream to dump state to
* @param indent_level the depth, for pretty-printing.
*
* This function is called on Envoy fatal errors so should avoid memory allocation where possible.
*/
virtual void dumpState(std::ostream& os, int indent_level = 0) const PURE;

/**
* Allow easy pretty-printing of the key/value pairs in HeaderMap
* @param os supplies the ostream to print to.
* @param headers the headers to print.
*/
friend std::ostream& operator<<(std::ostream& os, const HeaderMap& headers) {
headers.iterate(
[](const HeaderEntry& header, void* context) -> HeaderMap::Iterate {
*static_cast<std::ostream*>(context) << "'" << header.key().getStringView() << "', '"
<< header.value().getStringView() << "'\n";
return HeaderMap::Iterate::Continue;
},
&os);
headers.dumpState(os);
return os;
}
};
Expand Down
16 changes: 16 additions & 0 deletions source/common/common/BUILD
Original file line number Diff line number Diff line change
Expand Up @@ -109,6 +109,12 @@ envoy_cc_library(
deps = [":assert_lib"],
)

# Contains macros and helpers for dumpState utilities
envoy_cc_library(
name = "dump_state_utils",
hdrs = ["dump_state_utils.h"],
)

# Contains minimal code for logging to stderr.
envoy_cc_library(
name = "minimal_logger_lib",
Expand Down Expand Up @@ -140,6 +146,7 @@ envoy_cc_library(
srcs = ["logger_delegates.cc"],
hdrs = ["logger_delegates.h"],
deps = [
":dump_state_utils",
":macros",
":minimal_logger_lib",
"//include/envoy/access_log:access_log_interface",
Expand Down Expand Up @@ -177,6 +184,15 @@ envoy_cc_library(
hdrs = ["phantom.h"],
)

envoy_cc_library(
name = "scope_tracker",
hdrs = ["scope_tracker.h"],
deps = [
"//include/envoy/common:scope_tracker_interface",
"//include/envoy/event:dispatcher_interface",
],
)

envoy_cc_library(
name = "stl_helpers",
hdrs = ["stl_helpers.h"],
Expand Down
54 changes: 54 additions & 0 deletions source/common/common/dump_state_utils.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,54 @@
#pragma once

#include <sstream>

namespace Envoy {

// A collection of macros for pretty printing objects on fatal error.
// These are fairly ugly in an attempt to maximize the conditions where fatal error logging occurs,
// i.e. under the Envoy signal handler if encountering a SIGSEVG due to OOM, where allocating more
// memory would likely lead to the crash handler itself causing a subeqeuent OOM.

#define DUMP_MEMBER(member) ", " #member ": " << (member)

#define DUMP_OPTIONAL_MEMBER(member) \
", " #member ": " << ((member).has_value() ? absl::StrCat((member).value()) : "null")

// Macro assumes local member variables
// os (ostream)
// indent_level (int)
#define DUMP_DETAILS(member) \
do { \
os << spaces << #member ": "; \
if ((member) != nullptr) { \
os << "\n"; \
(member)->dumpState(os, indent_level + 1); \
} else { \
os << spaces << "null\n"; \
} \
} while (false)

// Return the const char* equivalent of string(level*2, ' '), without dealing
// with string creation overhead. Cap arbitrarily at 6 as we're (hopefully)
// not going to have nested objects deeper than that.
inline const char* spacesForLevel(int level) {
mattklein123 marked this conversation as resolved.
Show resolved Hide resolved
switch (level) {
case 0:
return "";
case 1:
return " ";
case 2:
return " ";
case 3:
return " ";
case 4:
return " ";
case 5:
return " ";
default:
return " ";
}
return "";
}

} // namespace Envoy
27 changes: 27 additions & 0 deletions source/common/common/scope_tracker.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
#pragma once

#include "envoy/common/scope_tracker.h"
#include "envoy/event/dispatcher.h"

namespace Envoy {

// A small class for tracking the scope of the 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.
class ScopeTrackerScopeState {
public:
ScopeTrackerScopeState(const ScopeTrackedObject* object, Event::Dispatcher& dispatcher)
: dispatcher_(dispatcher) {
latched_object_ = dispatcher_.setTrackedObject(object);
}

~ScopeTrackerScopeState() { dispatcher_.setTrackedObject(latched_object_); }

private:
const ScopeTrackedObject* latched_object_;
Event::Dispatcher& dispatcher_;
};

} // namespace Envoy
9 changes: 8 additions & 1 deletion source/common/event/BUILD
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ envoy_cc_library(
":dispatcher_includes",
":libevent_scheduler_lib",
":real_time_system_lib",
"//include/envoy/common:scope_tracker_interface",
"//include/envoy/common:time_interface",
"//include/envoy/event:signal_interface",
"//include/envoy/network:listen_socket_interface",
Expand Down Expand Up @@ -74,7 +75,13 @@ envoy_cc_library(
"//include/envoy/network:connection_handler_interface",
"//source/common/common:minimal_logger_lib",
"//source/common/common:thread_lib",
],
"//source/common/signal:fatal_error_handler_lib",
] + select({
"//bazel:disable_signal_trace": [],
"//conditions:default": [
"//source/common/signal:sigaction_lib",
],
}),
)

envoy_cc_library(
Expand Down
24 changes: 19 additions & 5 deletions source/common/event/dispatcher_impl.cc
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,10 @@

#include "event2/event.h"

#ifdef ENVOY_HANDLE_SIGNALS
#include "common/signal/signal_action.h"
#endif

namespace Envoy {
namespace Event {

Expand All @@ -35,11 +39,19 @@ DispatcherImpl::DispatcherImpl(Buffer::WatermarkFactoryPtr&& factory, Api::Api&
Event::TimeSystem& time_system)
: api_(api), buffer_factory_(std::move(factory)),
scheduler_(time_system.createScheduler(base_scheduler_)),
deferred_delete_timer_(createTimer([this]() -> void { clearDeferredDeleteList(); })),
post_timer_(createTimer([this]() -> void { runPostCallbacks(); })),
current_to_delete_(&to_delete_1_) {}
deferred_delete_timer_(createTimerInternal([this]() -> void { clearDeferredDeleteList(); })),
post_timer_(createTimerInternal([this]() -> void { runPostCallbacks(); })),
current_to_delete_(&to_delete_1_) {
#ifdef ENVOY_HANDLE_SIGNALS
SignalAction::registerFatalErrorHandler(*this);
#endif
}

DispatcherImpl::~DispatcherImpl() {}
DispatcherImpl::~DispatcherImpl() {
#ifdef ENVOY_HANDLE_SIGNALS
SignalAction::removeFatalErrorHandler(*this);
#endif
}

void DispatcherImpl::initializeStats(Stats::Scope& scope, const std::string& prefix) {
// This needs to be run in the dispatcher's thread, so that we have a thread id to log.
Expand Down Expand Up @@ -133,7 +145,9 @@ Network::ListenerPtr DispatcherImpl::createUdpListener(Network::Socket& socket,
return Network::ListenerPtr{new Network::UdpListenerImpl(*this, socket, cb, timeSource())};
}

TimerPtr DispatcherImpl::createTimer(TimerCb cb) {
TimerPtr DispatcherImpl::createTimer(TimerCb cb) { return createTimerInternal(cb); }

TimerPtr DispatcherImpl::createTimerInternal(TimerCb cb) {
ASSERT(isThreadSafe());
return scheduler_->createTimer(cb);
}
Expand Down
24 changes: 23 additions & 1 deletion source/common/event/dispatcher_impl.h
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@
#include <vector>

#include "envoy/api/api.h"
#include "envoy/common/scope_tracker.h"
#include "envoy/common/time.h"
#include "envoy/event/deferred_deletable.h"
#include "envoy/event/dispatcher.h"
Expand All @@ -17,14 +18,17 @@
#include "common/common/thread.h"
#include "common/event/libevent.h"
#include "common/event/libevent_scheduler.h"
#include "common/signal/fatal_error_handler.h"

namespace Envoy {
namespace Event {

/**
* libevent implementation of Event::Dispatcher.
*/
class DispatcherImpl : Logger::Loggable<Logger::Id::main>, public Dispatcher {
class DispatcherImpl : Logger::Loggable<Logger::Id::main>,
public Dispatcher,
public FatalErrorHandlerInterface {
public:
DispatcherImpl(Api::Api& api, Event::TimeSystem& time_system);
DispatcherImpl(Buffer::WatermarkFactoryPtr&& factory, Api::Api& api,
Expand Down Expand Up @@ -65,8 +69,25 @@ class DispatcherImpl : Logger::Loggable<Logger::Id::main>, public Dispatcher {
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;
}

// FatalErrorInterface
void onFatalError() const override {
// Dump the stae 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()) {
mattklein123 marked this conversation as resolved.
Show resolved Hide resolved
if (current_object_) {
current_object_->dumpState(std::cerr);
}
}
}

private:
TimerPtr createTimerInternal(TimerCb cb);
void runPostCallbacks();

// Validate that an operation is thread safe, i.e. it's invoked on the same thread that the
Expand All @@ -88,6 +109,7 @@ class DispatcherImpl : Logger::Loggable<Logger::Id::main>, public Dispatcher {
std::vector<DeferredDeletablePtr>* current_to_delete_;
Thread::MutexBasicLockable post_lock_;
std::list<std::function<void()>> post_callbacks_ GUARDED_BY(post_lock_);
const ScopeTrackedObject* current_object_{};
bool deferred_deleting_{};
};

Expand Down
4 changes: 4 additions & 0 deletions source/common/http/BUILD
Original file line number Diff line number Diff line change
Expand Up @@ -148,6 +148,7 @@ envoy_cc_library(
":utility_lib",
"//include/envoy/access_log:access_log_interface",
"//include/envoy/buffer:buffer_interface",
"//include/envoy/common:scope_tracker_interface",
"//include/envoy/common:time_interface",
"//include/envoy/event:deferred_deletable",
"//include/envoy/event:dispatcher_interface",
Expand All @@ -171,9 +172,11 @@ envoy_cc_library(
"//source/common/access_log:access_log_formatter_lib",
"//source/common/buffer:buffer_lib",
"//source/common/common:assert_lib",
"//source/common/common:dump_state_utils",
"//source/common/common:empty_string",
"//source/common/common:enum_to_int",
"//source/common/common:linked_object",
"//source/common/common:scope_tracker",
"//source/common/common:utility_lib",
"//source/common/http/http1:codec_lib",
"//source/common/http/http2:codec_lib",
Expand Down Expand Up @@ -214,6 +217,7 @@ envoy_cc_library(
":headers_lib",
"//include/envoy/http:header_map_interface",
"//source/common/common:assert_lib",
"//source/common/common:dump_state_utils",
"//source/common/common:empty_string",
"//source/common/common:non_copyable",
"//source/common/common:utility_lib",
Expand Down
Loading