From a64cb54de152017d6c3c968ec9c22a98c405a8ba Mon Sep 17 00:00:00 2001 From: ncteisen Date: Tue, 2 Oct 2018 17:33:07 -0700 Subject: Channel trace is limited by memory --- include/grpc/impl/codegen/grpc_types.h | 8 +- src/core/ext/filters/client_channel/subchannel.cc | 8 +- src/core/lib/channel/channel_trace.cc | 40 +++-- src/core/lib/channel/channel_trace.h | 9 +- src/core/lib/slice/slice.cc | 8 + src/core/lib/slice/slice_internal.h | 5 + src/core/lib/surface/channel.cc | 10 +- src/core/lib/surface/server.cc | 8 +- test/core/channel/channel_trace_test.cc | 178 ++++++++++++++++------ test/core/channel/channelz_test.cc | 16 +- test/core/end2end/tests/channelz.cc | 5 +- test/cpp/end2end/channelz_service_test.cc | 6 +- 12 files changed, 207 insertions(+), 94 deletions(-) diff --git a/include/grpc/impl/codegen/grpc_types.h b/include/grpc/impl/codegen/grpc_types.h index 9ed5b3c1d4..672f130bab 100644 --- a/include/grpc/impl/codegen/grpc_types.h +++ b/include/grpc/impl/codegen/grpc_types.h @@ -285,9 +285,11 @@ typedef struct { #define GRPC_ARG_SOCKET_MUTATOR "grpc.socket_mutator" /** The grpc_socket_factory instance to create and bind sockets. A pointer. */ #define GRPC_ARG_SOCKET_FACTORY "grpc.socket_factory" -/** The maximum number of trace events to keep in the tracer for each channel or - * subchannel. The default is 10. If set to 0, channel tracing is disabled. */ -#define GRPC_ARG_MAX_CHANNEL_TRACE_EVENTS_PER_NODE \ +/** The maximum ammount of memory that the trace event can use per channel + * trace node. Once the maximum is reached, subsequent events will evict the + * oldest events from the buffer. The unit for this knob is bytes. Setting + * it to zero causes channel tracing to be disabled. */ +#define GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE \ "grpc.max_channel_trace_events_per_node" /** If non-zero, gRPC library will track stats and information at at per channel * level. Disabling channelz naturally disables channel tracing. The default diff --git a/src/core/ext/filters/client_channel/subchannel.cc b/src/core/ext/filters/client_channel/subchannel.cc index 2847f4bdc1..53954ea2d0 100644 --- a/src/core/ext/filters/client_channel/subchannel.cc +++ b/src/core/ext/filters/client_channel/subchannel.cc @@ -389,15 +389,15 @@ grpc_subchannel* grpc_subchannel_create(grpc_connector* connector, const grpc_arg* arg = grpc_channel_args_find(c->args, GRPC_ARG_ENABLE_CHANNELZ); bool channelz_enabled = grpc_channel_arg_get_bool(arg, false); - arg = grpc_channel_args_find(c->args, - GRPC_ARG_MAX_CHANNEL_TRACE_EVENTS_PER_NODE); + arg = grpc_channel_args_find( + c->args, GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE); const grpc_integer_options options = {0, 0, INT_MAX}; - size_t channel_tracer_max_nodes = + size_t channel_tracer_max_memory = (size_t)grpc_channel_arg_get_integer(arg, options); if (channelz_enabled) { c->channelz_subchannel = grpc_core::MakeRefCounted( - c, channel_tracer_max_nodes); + c, channel_tracer_max_memory); c->channelz_subchannel->AddTraceEvent( grpc_core::channelz::ChannelTrace::Severity::Info, grpc_slice_from_static_string("Subchannel created")); diff --git a/src/core/lib/channel/channel_trace.cc b/src/core/lib/channel/channel_trace.cc index cfb2faba51..3227fe53a1 100644 --- a/src/core/lib/channel/channel_trace.cc +++ b/src/core/lib/channel/channel_trace.cc @@ -48,31 +48,37 @@ ChannelTrace::TraceEvent::TraceEvent(Severity severity, grpc_slice data, timestamp_(grpc_millis_to_timespec(grpc_core::ExecCtx::Get()->Now(), GPR_CLOCK_REALTIME)), next_(nullptr), - referenced_entity_(std::move(referenced_entity)) {} + referenced_entity_(std::move(referenced_entity)) { + memory_usage_ = sizeof(TraceEvent) + grpc_slice_memory_usage(data); +} ChannelTrace::TraceEvent::TraceEvent(Severity severity, grpc_slice data) : severity_(severity), data_(data), timestamp_(grpc_millis_to_timespec(grpc_core::ExecCtx::Get()->Now(), GPR_CLOCK_REALTIME)), - next_(nullptr) {} + next_(nullptr) { + memory_usage_ = sizeof(TraceEvent) + grpc_slice_memory_usage(data); +} ChannelTrace::TraceEvent::~TraceEvent() { grpc_slice_unref_internal(data_); } -ChannelTrace::ChannelTrace(size_t max_events) +ChannelTrace::ChannelTrace(size_t max_event_memory) : num_events_logged_(0), - list_size_(0), - max_list_size_(max_events), + event_list_memory_usage_(0), + max_event_memory_(max_event_memory), head_trace_(nullptr), tail_trace_(nullptr) { - if (max_list_size_ == 0) return; // tracing is disabled if max_events == 0 + if (max_event_memory_ == 0) + return; // tracing is disabled if max_event_memory_ == 0 gpr_mu_init(&tracer_mu_); time_created_ = grpc_millis_to_timespec(grpc_core::ExecCtx::Get()->Now(), GPR_CLOCK_REALTIME); } ChannelTrace::~ChannelTrace() { - if (max_list_size_ == 0) return; // tracing is disabled if max_events == 0 + if (max_event_memory_ == 0) + return; // tracing is disabled if max_event_memory_ == 0 TraceEvent* it = head_trace_; while (it != nullptr) { TraceEvent* to_free = it; @@ -93,25 +99,27 @@ void ChannelTrace::AddTraceEventHelper(TraceEvent* new_trace_event) { tail_trace_->set_next(new_trace_event); tail_trace_ = tail_trace_->next(); } - ++list_size_; - // maybe garbage collect the end - if (list_size_ > max_list_size_) { + event_list_memory_usage_ += new_trace_event->memory_usage(); + // maybe garbage collect the tail until we are under the memory limit. + while (event_list_memory_usage_ > max_event_memory_) { TraceEvent* to_free = head_trace_; + event_list_memory_usage_ -= to_free->memory_usage(); head_trace_ = head_trace_->next(); Delete(to_free); - --list_size_; } } void ChannelTrace::AddTraceEvent(Severity severity, grpc_slice data) { - if (max_list_size_ == 0) return; // tracing is disabled if max_events == 0 + if (max_event_memory_ == 0) + return; // tracing is disabled if max_event_memory_ == 0 AddTraceEventHelper(New(severity, data)); } void ChannelTrace::AddTraceEventWithReference( Severity severity, grpc_slice data, RefCountedPtr referenced_entity) { - if (max_list_size_ == 0) return; // tracing is disabled if max_events == 0 + if (max_event_memory_ == 0) + return; // tracing is disabled if max_event_memory_ == 0 // create and fill up the new event AddTraceEventHelper( New(severity, data, std::move(referenced_entity))); @@ -162,8 +170,8 @@ void ChannelTrace::TraceEvent::RenderTraceEvent(grpc_json* json) const { } grpc_json* ChannelTrace::RenderJson() const { - if (!max_list_size_) - return nullptr; // tracing is disabled if max_events == 0 + if (max_event_memory_ == 0) + return nullptr; // tracing is disabled if max_event_memory_ == 0 grpc_json* json = grpc_json_create(GRPC_JSON_OBJECT); grpc_json* json_iterator = nullptr; if (num_events_logged_ > 0) { @@ -174,7 +182,7 @@ grpc_json* ChannelTrace::RenderJson() const { json_iterator, json, "creationTimestamp", gpr_format_timespec(time_created_), GRPC_JSON_STRING, true); // only add in the event list if it is non-empty. - if (num_events_logged_ > 0) { + if (head_trace_ != nullptr) { grpc_json* events = grpc_json_create_child(json_iterator, json, "events", nullptr, GRPC_JSON_ARRAY, false); json_iterator = nullptr; diff --git a/src/core/lib/channel/channel_trace.h b/src/core/lib/channel/channel_trace.h index 94fea20b45..0e9ce5f648 100644 --- a/src/core/lib/channel/channel_trace.h +++ b/src/core/lib/channel/channel_trace.h @@ -37,7 +37,7 @@ class BaseNode; // https://github.com/grpc/proposal/blob/master/A14-channelz.md class ChannelTrace { public: - ChannelTrace(size_t max_events); + ChannelTrace(size_t max_event_memory); ~ChannelTrace(); enum Severity { @@ -92,6 +92,8 @@ class ChannelTrace { TraceEvent* next() const { return next_; } void set_next(TraceEvent* next) { next_ = next; } + size_t memory_usage() { return memory_usage_; } + private: Severity severity_; grpc_slice data_; @@ -99,6 +101,7 @@ class ChannelTrace { TraceEvent* next_; // the tracer object for the (sub)channel that this trace event refers to. RefCountedPtr referenced_entity_; + size_t memory_usage_; }; // TraceEvent // Internal helper to add and link in a trace event @@ -106,8 +109,8 @@ class ChannelTrace { gpr_mu tracer_mu_; uint64_t num_events_logged_; - size_t list_size_; - size_t max_list_size_; + size_t event_list_memory_usage_; + size_t max_event_memory_; TraceEvent* head_trace_; TraceEvent* tail_trace_; gpr_timespec time_created_; diff --git a/src/core/lib/slice/slice.cc b/src/core/lib/slice/slice.cc index 419474129b..e842d84f11 100644 --- a/src/core/lib/slice/slice.cc +++ b/src/core/lib/slice/slice.cc @@ -88,6 +88,14 @@ static const grpc_slice_refcount_vtable noop_refcount_vtable = { static grpc_slice_refcount noop_refcount = {&noop_refcount_vtable, &noop_refcount}; +size_t grpc_slice_memory_usage(grpc_slice s) { + if (s.refcount == nullptr || s.refcount == &noop_refcount) { + return 0; + } else { + return s.data.refcounted.length; + } +} + grpc_slice grpc_slice_from_static_buffer(const void* s, size_t len) { grpc_slice slice; slice.refcount = &noop_refcount; diff --git a/src/core/lib/slice/slice_internal.h b/src/core/lib/slice/slice_internal.h index 5d3d26b67b..5b05951522 100644 --- a/src/core/lib/slice/slice_internal.h +++ b/src/core/lib/slice/slice_internal.h @@ -46,4 +46,9 @@ grpc_slice grpc_slice_maybe_static_intern(grpc_slice slice, uint32_t grpc_static_slice_hash(grpc_slice s); int grpc_static_slice_eq(grpc_slice a, grpc_slice b); +// Returns the memory used by this slice, not counting the slice structure +// itself. This means that inlined and slices from static strings will return +// 0. All other slices will return the size of the allocated chars. +size_t grpc_slice_memory_usage(grpc_slice s); + #endif /* GRPC_CORE_LIB_SLICE_SLICE_INTERNAL_H */ diff --git a/src/core/lib/surface/channel.cc b/src/core/lib/surface/channel.cc index 054fe105c3..6ca3af1aed 100644 --- a/src/core/lib/surface/channel.cc +++ b/src/core/lib/surface/channel.cc @@ -102,7 +102,7 @@ grpc_channel* grpc_channel_create_with_builder( channel->target = target; channel->is_client = grpc_channel_stack_type_is_client(channel_stack_type); - size_t channel_tracer_max_nodes = 0; // default to off + size_t channel_tracer_max_memory = 0; // default to off bool channelz_enabled = false; bool internal_channel = false; // this creates the default ChannelNode. Different types of channels may @@ -141,11 +141,11 @@ grpc_channel* grpc_channel_create_with_builder( static_cast(args->args[i].value.integer) | 0x1; /* always support no compression */ } else if (0 == strcmp(args->args[i].key, - GRPC_ARG_MAX_CHANNEL_TRACE_EVENTS_PER_NODE)) { - GPR_ASSERT(channel_tracer_max_nodes == 0); + GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE)) { + GPR_ASSERT(channel_tracer_max_memory == 0); // max_nodes defaults to 0 (which is off), clamped between 0 and INT_MAX const grpc_integer_options options = {0, 0, INT_MAX}; - channel_tracer_max_nodes = + channel_tracer_max_memory = (size_t)grpc_channel_arg_get_integer(&args->args[i], options); } else if (0 == strcmp(args->args[i].key, GRPC_ARG_ENABLE_CHANNELZ)) { // channelz will not be enabled by default until all concerns in @@ -169,7 +169,7 @@ grpc_channel* grpc_channel_create_with_builder( // bookkeeping for server channels occurs in src/core/lib/surface/server.cc if (channelz_enabled && channel->is_client) { channel->channelz_channel = channel_node_create_func( - channel, channel_tracer_max_nodes, !internal_channel); + channel, channel_tracer_max_memory, !internal_channel); channel->channelz_channel->AddTraceEvent( grpc_core::channelz::ChannelTrace::Severity::Info, grpc_slice_from_static_string("Channel created")); diff --git a/src/core/lib/surface/server.cc b/src/core/lib/surface/server.cc index 72ddc2648d..b9e86784f3 100644 --- a/src/core/lib/surface/server.cc +++ b/src/core/lib/surface/server.cc @@ -1009,13 +1009,13 @@ grpc_server* grpc_server_create(const grpc_channel_args* args, void* reserved) { const grpc_arg* arg = grpc_channel_args_find(args, GRPC_ARG_ENABLE_CHANNELZ); if (grpc_channel_arg_get_bool(arg, false)) { - arg = grpc_channel_args_find(args, - GRPC_ARG_MAX_CHANNEL_TRACE_EVENTS_PER_NODE); - size_t trace_events_per_node = + arg = grpc_channel_args_find( + args, GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE); + size_t channel_tracer_max_memory = grpc_channel_arg_get_integer(arg, {0, 0, INT_MAX}); server->channelz_server = grpc_core::MakeRefCounted( - trace_events_per_node); + channel_tracer_max_memory); server->channelz_server->AddTraceEvent( grpc_core::channelz::ChannelTrace::Severity::Info, grpc_slice_from_static_string("Server created")); diff --git a/test/core/channel/channel_trace_test.cc b/test/core/channel/channel_trace_test.cc index d594445bfb..8385475e7d 100644 --- a/test/core/channel/channel_trace_test.cc +++ b/test/core/channel/channel_trace_test.cc @@ -65,6 +65,11 @@ grpc_json* GetJsonChild(grpc_json* parent, const char* key) { void ValidateJsonArraySize(grpc_json* json, const char* key, size_t expected_size) { grpc_json* arr = GetJsonChild(json, key); + // the events array should not be present if there are no events. + if (expected_size == 0) { + EXPECT_EQ(arr, nullptr); + return; + } ASSERT_NE(arr, nullptr); ASSERT_EQ(arr->type, GRPC_JSON_ARRAY); size_t count = 0; @@ -94,29 +99,31 @@ void AddSimpleTrace(ChannelTrace* tracer) { } // checks for the existence of all the required members of the tracer. -void ValidateChannelTrace(ChannelTrace* tracer, - size_t expected_num_event_logged, size_t max_nodes) { - if (!max_nodes) return; +void ValidateChannelTraceCustom(ChannelTrace* tracer, size_t num_events_logged, + size_t num_events_expected) { grpc_json* json = tracer->RenderJson(); EXPECT_NE(json, nullptr); char* json_str = grpc_json_dump_to_string(json, 0); grpc_json_destroy(json); grpc::testing::ValidateChannelTraceProtoJsonTranslation(json_str); grpc_json* parsed_json = grpc_json_parse_string(json_str); - ValidateChannelTraceData(parsed_json, expected_num_event_logged, - GPR_MIN(expected_num_event_logged, max_nodes)); + ValidateChannelTraceData(parsed_json, num_events_logged, num_events_expected); grpc_json_destroy(parsed_json); gpr_free(json_str); } +void ValidateChannelTrace(ChannelTrace* tracer, size_t num_events_logged) { + ValidateChannelTraceCustom(tracer, num_events_logged, num_events_logged); +} + class ChannelFixture { public: - ChannelFixture(int max_trace_nodes) { + ChannelFixture(int max_tracer_event_memory) { grpc_arg client_a; client_a.type = GRPC_ARG_INTEGER; client_a.key = - const_cast(GRPC_ARG_MAX_CHANNEL_TRACE_EVENTS_PER_NODE); - client_a.value.integer = max_trace_nodes; + const_cast(GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE); + client_a.value.integer = max_tracer_event_memory; grpc_channel_args client_args = {1, &client_a}; channel_ = grpc_insecure_channel_create("fake_target", &client_args, nullptr); @@ -132,67 +139,67 @@ class ChannelFixture { } // anonymous namespace -class ChannelTracerTest : public ::testing::TestWithParam {}; +const int kEventListMemoryLimit = 1024 * 1024; // Tests basic ChannelTrace functionality like construction, adding trace, and // lookups by uuid. -TEST_P(ChannelTracerTest, BasicTest) { +TEST(ChannelTracerTest, BasicTest) { grpc_core::ExecCtx exec_ctx; - ChannelTrace tracer(GetParam()); + ChannelTrace tracer(kEventListMemoryLimit); AddSimpleTrace(&tracer); AddSimpleTrace(&tracer); tracer.AddTraceEvent(ChannelTrace::Severity::Info, grpc_slice_from_static_string("trace three")); tracer.AddTraceEvent(ChannelTrace::Severity::Error, grpc_slice_from_static_string("trace four error")); - ValidateChannelTrace(&tracer, 4, GetParam()); + ValidateChannelTrace(&tracer, 4); AddSimpleTrace(&tracer); AddSimpleTrace(&tracer); - ValidateChannelTrace(&tracer, 6, GetParam()); + ValidateChannelTrace(&tracer, 6); AddSimpleTrace(&tracer); AddSimpleTrace(&tracer); AddSimpleTrace(&tracer); AddSimpleTrace(&tracer); - ValidateChannelTrace(&tracer, 10, GetParam()); + ValidateChannelTrace(&tracer, 10); } // Tests more complex functionality, like a parent channel tracking // subchannles. This exercises the ref/unref patterns since the parent tracer // and this function will both hold refs to the subchannel. -TEST_P(ChannelTracerTest, ComplexTest) { +TEST(ChannelTracerTest, ComplexTest) { grpc_core::ExecCtx exec_ctx; - ChannelTrace tracer(GetParam()); + ChannelTrace tracer(kEventListMemoryLimit); AddSimpleTrace(&tracer); AddSimpleTrace(&tracer); - ChannelFixture channel1(GetParam()); - RefCountedPtr sc1 = - MakeRefCounted(channel1.channel(), GetParam(), true); + ChannelFixture channel1(kEventListMemoryLimit); + RefCountedPtr sc1 = MakeRefCounted( + channel1.channel(), kEventListMemoryLimit, true); ChannelNodePeer sc1_peer(sc1.get()); tracer.AddTraceEventWithReference( ChannelTrace::Severity::Info, grpc_slice_from_static_string("subchannel one created"), sc1); - ValidateChannelTrace(&tracer, 3, GetParam()); + ValidateChannelTrace(&tracer, 3); AddSimpleTrace(sc1_peer.trace()); AddSimpleTrace(sc1_peer.trace()); AddSimpleTrace(sc1_peer.trace()); - ValidateChannelTrace(sc1_peer.trace(), 3, GetParam()); + ValidateChannelTrace(sc1_peer.trace(), 3); AddSimpleTrace(sc1_peer.trace()); AddSimpleTrace(sc1_peer.trace()); AddSimpleTrace(sc1_peer.trace()); - ValidateChannelTrace(sc1_peer.trace(), 6, GetParam()); + ValidateChannelTrace(sc1_peer.trace(), 6); AddSimpleTrace(&tracer); AddSimpleTrace(&tracer); - ValidateChannelTrace(&tracer, 5, GetParam()); - ChannelFixture channel2(GetParam()); - RefCountedPtr sc2 = - MakeRefCounted(channel2.channel(), GetParam(), true); + ValidateChannelTrace(&tracer, 5); + ChannelFixture channel2(kEventListMemoryLimit); + RefCountedPtr sc2 = MakeRefCounted( + channel2.channel(), kEventListMemoryLimit, true); tracer.AddTraceEventWithReference( ChannelTrace::Severity::Info, grpc_slice_from_static_string("LB channel two created"), sc2); tracer.AddTraceEventWithReference( ChannelTrace::Severity::Warning, grpc_slice_from_static_string("subchannel one inactive"), sc1); - ValidateChannelTrace(&tracer, 7, GetParam()); + ValidateChannelTrace(&tracer, 7); AddSimpleTrace(&tracer); AddSimpleTrace(&tracer); AddSimpleTrace(&tracer); @@ -206,38 +213,38 @@ TEST_P(ChannelTracerTest, ComplexTest) { // Test a case in which the parent channel has subchannels and the subchannels // have connections. Ensures that everything lives as long as it should then // gets deleted. -TEST_P(ChannelTracerTest, TestNesting) { +TEST(ChannelTracerTest, TestNesting) { grpc_core::ExecCtx exec_ctx; - ChannelTrace tracer(GetParam()); + ChannelTrace tracer(kEventListMemoryLimit); AddSimpleTrace(&tracer); AddSimpleTrace(&tracer); - ValidateChannelTrace(&tracer, 2, GetParam()); - ChannelFixture channel1(GetParam()); - RefCountedPtr sc1 = - MakeRefCounted(channel1.channel(), GetParam(), true); + ValidateChannelTrace(&tracer, 2); + ChannelFixture channel1(kEventListMemoryLimit); + RefCountedPtr sc1 = MakeRefCounted( + channel1.channel(), kEventListMemoryLimit, true); ChannelNodePeer sc1_peer(sc1.get()); tracer.AddTraceEventWithReference( ChannelTrace::Severity::Info, grpc_slice_from_static_string("subchannel one created"), sc1); - ValidateChannelTrace(&tracer, 3, GetParam()); + ValidateChannelTrace(&tracer, 3); AddSimpleTrace(sc1_peer.trace()); - ChannelFixture channel2(GetParam()); - RefCountedPtr conn1 = - MakeRefCounted(channel2.channel(), GetParam(), true); + ChannelFixture channel2(kEventListMemoryLimit); + RefCountedPtr conn1 = MakeRefCounted( + channel2.channel(), kEventListMemoryLimit, true); ChannelNodePeer conn1_peer(conn1.get()); // nesting one level deeper. sc1_peer.trace()->AddTraceEventWithReference( ChannelTrace::Severity::Info, grpc_slice_from_static_string("connection one created"), conn1); - ValidateChannelTrace(&tracer, 3, GetParam()); + ValidateChannelTrace(&tracer, 3); AddSimpleTrace(conn1_peer.trace()); AddSimpleTrace(&tracer); AddSimpleTrace(&tracer); - ValidateChannelTrace(&tracer, 5, GetParam()); - ValidateChannelTrace(conn1_peer.trace(), 1, GetParam()); - ChannelFixture channel3(GetParam()); - RefCountedPtr sc2 = - MakeRefCounted(channel3.channel(), GetParam(), true); + ValidateChannelTrace(&tracer, 5); + ValidateChannelTrace(conn1_peer.trace(), 1); + ChannelFixture channel3(kEventListMemoryLimit); + RefCountedPtr sc2 = MakeRefCounted( + channel3.channel(), kEventListMemoryLimit, true); tracer.AddTraceEventWithReference( ChannelTrace::Severity::Info, grpc_slice_from_static_string("subchannel two created"), sc2); @@ -247,14 +254,93 @@ TEST_P(ChannelTracerTest, TestNesting) { ChannelTrace::Severity::Warning, grpc_slice_from_static_string("subchannel one inactive"), sc1); AddSimpleTrace(&tracer); - ValidateChannelTrace(&tracer, 8, GetParam()); + ValidateChannelTrace(&tracer, 8); sc1.reset(); sc2.reset(); conn1.reset(); } -INSTANTIATE_TEST_CASE_P(ChannelTracerTestSweep, ChannelTracerTest, - ::testing::Values(0, 1, 2, 6, 10, 15)); +TEST(ChannelTracerTest, TestSmallMemoryLimit) { + grpc_core::ExecCtx exec_ctx; + // doesn't make sense, but serves a testing purpose for the channel tracing + // bookkeeping. All tracing events added should will get immediately garbage + // collected. + const int kSmallMemoryLimit = 1; + ChannelTrace tracer(kSmallMemoryLimit); + AddSimpleTrace(&tracer); + AddSimpleTrace(&tracer); + tracer.AddTraceEvent(ChannelTrace::Severity::Info, + grpc_slice_from_static_string("trace three")); + tracer.AddTraceEvent(ChannelTrace::Severity::Error, + grpc_slice_from_static_string("trace four error")); + ValidateChannelTraceCustom(&tracer, 4, 0); + AddSimpleTrace(&tracer); + AddSimpleTrace(&tracer); + ValidateChannelTraceCustom(&tracer, 6, 0); + AddSimpleTrace(&tracer); + AddSimpleTrace(&tracer); + AddSimpleTrace(&tracer); + AddSimpleTrace(&tracer); + ValidateChannelTraceCustom(&tracer, 10, 0); +} + +TEST(ChannelTracerTest, TestEviction) { + grpc_core::ExecCtx exec_ctx; + // This depends on sizeof(ChannelTrace). If that struct has been updated, + // this will too. + const int kTraceEventSize = 80; + const int kNumEvents = 5; + ChannelTrace tracer(kTraceEventSize * kNumEvents); + for (int i = 1; i <= kNumEvents; ++i) { + AddSimpleTrace(&tracer); + ValidateChannelTrace(&tracer, i); + } + // at this point the list is full, and each subsequent enntry will cause an + // eviction. + for (int i = 1; i <= kNumEvents; ++i) { + AddSimpleTrace(&tracer); + ValidateChannelTraceCustom(&tracer, kNumEvents + i, kNumEvents); + } +} + +TEST(ChannelTracerTest, TestMultipleEviction) { + grpc_core::ExecCtx exec_ctx; + // This depends on sizeof(ChannelTrace). If that struct has been updated, + // this will too. + const int kTraceEventSize = 80; + const int kNumEvents = 5; + ChannelTrace tracer(kTraceEventSize * kNumEvents); + for (int i = 1; i <= kNumEvents; ++i) { + AddSimpleTrace(&tracer); + ValidateChannelTrace(&tracer, i); + } + // at this point the list is full, and each subsequent enntry will cause an + // eviction. We will now add in a trace event that has a copied string. This + // uses more memory, so it will cause a double eviciction + tracer.AddTraceEvent( + ChannelTrace::Severity::Info, + grpc_slice_from_copied_string( + "long enough string to trigger a multiple eviction")); + ValidateChannelTraceCustom(&tracer, kNumEvents + 1, kNumEvents - 1); +} + +TEST(ChannelTracerTest, TestTotalEviction) { + grpc_core::ExecCtx exec_ctx; + // This depends on sizeof(ChannelTrace). If that struct has been updated, + // this will too. + const int kTraceEventSize = 80; + const int kNumEvents = 5; + ChannelTrace tracer(kTraceEventSize * kNumEvents); + for (int i = 1; i <= kNumEvents; ++i) { + AddSimpleTrace(&tracer); + ValidateChannelTrace(&tracer, i); + } + // at this point the list is full. Now we add such a big slice that + // everything gets evicted. + grpc_slice huge_slice = grpc_slice_malloc(kTraceEventSize * (kNumEvents + 1)); + tracer.AddTraceEvent(ChannelTrace::Severity::Info, huge_slice); + ValidateChannelTraceCustom(&tracer, kNumEvents + 1, 0); +} } // namespace testing } // namespace channelz diff --git a/test/core/channel/channelz_test.cc b/test/core/channel/channelz_test.cc index bcda30d9f2..745a2bff09 100644 --- a/test/core/channel/channelz_test.cc +++ b/test/core/channel/channelz_test.cc @@ -124,11 +124,11 @@ void ValidateGetServers(size_t expected_servers) { class ChannelFixture { public: - ChannelFixture(int max_trace_nodes = 0) { + ChannelFixture(int max_tracer_event_memory = 0) { grpc_arg client_a[2]; client_a[0] = grpc_channel_arg_integer_create( - const_cast(GRPC_ARG_MAX_CHANNEL_TRACE_EVENTS_PER_NODE), - max_trace_nodes); + const_cast(GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE), + max_tracer_event_memory); client_a[1] = grpc_channel_arg_integer_create( const_cast(GRPC_ARG_ENABLE_CHANNELZ), true); grpc_channel_args client_args = {GPR_ARRAY_SIZE(client_a), client_a}; @@ -146,11 +146,11 @@ class ChannelFixture { class ServerFixture { public: - explicit ServerFixture(int max_trace_nodes = 0) { + explicit ServerFixture(int max_tracer_event_memory = 0) { grpc_arg server_a[] = { grpc_channel_arg_integer_create( - const_cast(GRPC_ARG_MAX_CHANNEL_TRACE_EVENTS_PER_NODE), - max_trace_nodes), + const_cast(GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE), + max_tracer_event_memory), grpc_channel_arg_integer_create( const_cast(GRPC_ARG_ENABLE_CHANNELZ), true), }; @@ -360,10 +360,10 @@ TEST(ChannelzGetServersTest, ManyServersTest) { } INSTANTIATE_TEST_CASE_P(ChannelzChannelTestSweep, ChannelzChannelTest, - ::testing::Values(0, 1, 2, 6, 10, 15)); + ::testing::Values(0, 8, 64, 1024, 1024 * 1024)); INSTANTIATE_TEST_CASE_P(ChannelzServerTestSweep, ChannelzServerTest, - ::testing::Values(0, 1, 2, 6, 10, 15)); + ::testing::Values(0, 8, 64, 1024, 1024 * 1024)); } // namespace testing } // namespace channelz diff --git a/test/core/end2end/tests/channelz.cc b/test/core/end2end/tests/channelz.cc index 40a0370f0e..58ffdc18da 100644 --- a/test/core/end2end/tests/channelz.cc +++ b/test/core/end2end/tests/channelz.cc @@ -267,8 +267,9 @@ static void test_channelz_with_channel_trace(grpc_end2end_test_config config) { grpc_arg arg[2]; arg[0].type = GRPC_ARG_INTEGER; - arg[0].key = const_cast(GRPC_ARG_MAX_CHANNEL_TRACE_EVENTS_PER_NODE); - arg[0].value.integer = 5; + arg[0].key = + const_cast(GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE); + arg[0].value.integer = 1024; arg[1].type = GRPC_ARG_INTEGER; arg[1].key = const_cast(GRPC_ARG_ENABLE_CHANNELZ); arg[1].value.integer = true; diff --git a/test/cpp/end2end/channelz_service_test.cc b/test/cpp/end2end/channelz_service_test.cc index a597fd9c4b..df9e23d50c 100644 --- a/test/cpp/end2end/channelz_service_test.cc +++ b/test/cpp/end2end/channelz_service_test.cc @@ -115,8 +115,8 @@ class ChannelzServerTest : public ::testing::Test { InsecureServerCredentials()); // forces channelz and channel tracing to be enabled. proxy_builder.AddChannelArgument(GRPC_ARG_ENABLE_CHANNELZ, 1); - proxy_builder.AddChannelArgument(GRPC_ARG_MAX_CHANNEL_TRACE_EVENTS_PER_NODE, - 10); + proxy_builder.AddChannelArgument( + GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE, 1024); proxy_builder.RegisterService(&proxy_service_); proxy_server_ = proxy_builder.BuildAndStart(); } @@ -142,7 +142,7 @@ class ChannelzServerTest : public ::testing::Test { // are the ones that our test will actually be validating. ChannelArguments args; args.SetInt(GRPC_ARG_ENABLE_CHANNELZ, 1); - args.SetInt(GRPC_ARG_MAX_CHANNEL_TRACE_EVENTS_PER_NODE, 10); + args.SetInt(GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE, 1024); std::shared_ptr channel_to_backend = CreateCustomChannel( backend_server_address, InsecureChannelCredentials(), args); proxy_service_.AddChannelToBackend(channel_to_backend); -- cgit v1.2.3 From 664178164a7ecd3b108b9dd61e7821b716848792 Mon Sep 17 00:00:00 2001 From: ncteisen Date: Thu, 4 Oct 2018 16:32:01 -0700 Subject: reviewer feedback --- include/grpc/impl/codegen/grpc_types.h | 8 ++++---- src/core/lib/channel/channel_trace.cc | 10 ++++------ src/core/lib/channel/channel_trace.h | 20 ++++++++++++++++---- src/core/lib/channel/channelz.h | 3 ++- test/core/channel/channel_trace_test.cc | 23 ++++++++++++----------- test/core/end2end/tests/channelz.cc | 18 +++++++----------- 6 files changed, 45 insertions(+), 37 deletions(-) diff --git a/include/grpc/impl/codegen/grpc_types.h b/include/grpc/impl/codegen/grpc_types.h index 42daf3bb6e..3ce88a8264 100644 --- a/include/grpc/impl/codegen/grpc_types.h +++ b/include/grpc/impl/codegen/grpc_types.h @@ -285,10 +285,10 @@ typedef struct { #define GRPC_ARG_SOCKET_MUTATOR "grpc.socket_mutator" /** The grpc_socket_factory instance to create and bind sockets. A pointer. */ #define GRPC_ARG_SOCKET_FACTORY "grpc.socket_factory" -/** The maximum ammount of memory that the trace event can use per channel - * trace node. Once the maximum is reached, subsequent events will evict the - * oldest events from the buffer. The unit for this knob is bytes. Setting - * it to zero causes channel tracing to be disabled. */ +/** The maximum amount of memory used by trace events per channel trace node. + * Once the maximum is reached, subsequent events will evict the oldest events + * from the buffer. The unit for this knob is bytes. Setting it to zero causes + * channel tracing to be disabled. */ #define GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE \ "grpc.max_channel_trace_event_memory_per_node" /** If non-zero, gRPC library will track stats and information at at per channel diff --git a/src/core/lib/channel/channel_trace.cc b/src/core/lib/channel/channel_trace.cc index 3227fe53a1..fe81acb617 100644 --- a/src/core/lib/channel/channel_trace.cc +++ b/src/core/lib/channel/channel_trace.cc @@ -48,18 +48,16 @@ ChannelTrace::TraceEvent::TraceEvent(Severity severity, grpc_slice data, timestamp_(grpc_millis_to_timespec(grpc_core::ExecCtx::Get()->Now(), GPR_CLOCK_REALTIME)), next_(nullptr), - referenced_entity_(std::move(referenced_entity)) { - memory_usage_ = sizeof(TraceEvent) + grpc_slice_memory_usage(data); -} + referenced_entity_(std::move(referenced_entity)), + memory_usage_(sizeof(TraceEvent) + grpc_slice_memory_usage(data)) {} ChannelTrace::TraceEvent::TraceEvent(Severity severity, grpc_slice data) : severity_(severity), data_(data), timestamp_(grpc_millis_to_timespec(grpc_core::ExecCtx::Get()->Now(), GPR_CLOCK_REALTIME)), - next_(nullptr) { - memory_usage_ = sizeof(TraceEvent) + grpc_slice_memory_usage(data); -} + next_(nullptr), + memory_usage_(sizeof(TraceEvent) + grpc_slice_memory_usage(data)) {} ChannelTrace::TraceEvent::~TraceEvent() { grpc_slice_unref_internal(data_); } diff --git a/src/core/lib/channel/channel_trace.h b/src/core/lib/channel/channel_trace.h index 0e9ce5f648..8ff91ee8c8 100644 --- a/src/core/lib/channel/channel_trace.h +++ b/src/core/lib/channel/channel_trace.h @@ -30,6 +30,10 @@ namespace grpc_core { namespace channelz { +namespace testing { +size_t GetSizeofTraceEvent(void); +} + class BaseNode; // Object used to hold live data for a channel. This data is exposed via the @@ -49,6 +53,12 @@ class ChannelTrace { // Adds a new trace event to the tracing object // + // NOTE: each ChannelTrace tracks the memory used by its list of trace + // events, so adding an event with a large amount of data could cause other + // trace event to be evicted. If a single trace is larger than the limit, it + // will cause all events to be evicted. The limit is set with the arg: + // GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE. + // // TODO(ncteisen): as this call is used more and more throughout the gRPC // stack, determine if it makes more sense to accept a char* instead of a // slice. @@ -59,9 +69,9 @@ class ChannelTrace { // channel has created a new subchannel, then it would record that with // a TraceEvent referencing the new subchannel. // - // TODO(ncteisen): as this call is used more and more throughout the gRPC - // stack, determine if it makes more sense to accept a char* instead of a - // slice. + // NOTE: see the note in the method above. + // + // TODO(ncteisen): see the todo in the method above. void AddTraceEventWithReference(Severity severity, grpc_slice data, RefCountedPtr referenced_entity); @@ -70,6 +80,8 @@ class ChannelTrace { grpc_json* RenderJson() const; private: + friend size_t testing::GetSizeofTraceEvent(void); + // Private class to encapsulate all the data and bookkeeping needed for a // a trace event. class TraceEvent { @@ -92,7 +104,7 @@ class ChannelTrace { TraceEvent* next() const { return next_; } void set_next(TraceEvent* next) { next_ = next; } - size_t memory_usage() { return memory_usage_; } + size_t memory_usage() const { return memory_usage_; } private: Severity severity_; diff --git a/src/core/lib/channel/channelz.h b/src/core/lib/channel/channelz.h index 97eef9868d..30ec66ced2 100644 --- a/src/core/lib/channel/channelz.h +++ b/src/core/lib/channel/channelz.h @@ -43,7 +43,8 @@ * GRPC_ARG_ENABLE_CHANNELZ is set, it will override this default value. */ #define GRPC_ENABLE_CHANNELZ_DEFAULT false -/** This is the default value for TODO. If +/** This is the default value for the maximum amount of memory used by trace + * events per channel trace node. If * GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE is set, it will override * this default value. */ #define GRPC_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE_DEFAULT 0 diff --git a/test/core/channel/channel_trace_test.cc b/test/core/channel/channel_trace_test.cc index 8385475e7d..a569444fed 100644 --- a/test/core/channel/channel_trace_test.cc +++ b/test/core/channel/channel_trace_test.cc @@ -30,6 +30,7 @@ #include "src/core/lib/gpr/useful.h" #include "src/core/lib/iomgr/exec_ctx.h" #include "src/core/lib/json/json.h" +#include "src/core/lib/surface/channel.h" #include "test/core/util/test_config.h" #include "test/cpp/util/channel_trace_proto_helper.h" @@ -51,6 +52,8 @@ class ChannelNodePeer { ChannelNode* node_; }; +size_t GetSizeofTraceEvent() { return sizeof(ChannelTrace::TraceEvent); } + namespace { grpc_json* GetJsonChild(grpc_json* parent, const char* key) { @@ -119,11 +122,9 @@ void ValidateChannelTrace(ChannelTrace* tracer, size_t num_events_logged) { class ChannelFixture { public: ChannelFixture(int max_tracer_event_memory) { - grpc_arg client_a; - client_a.type = GRPC_ARG_INTEGER; - client_a.key = - const_cast(GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE); - client_a.value.integer = max_tracer_event_memory; + grpc_arg client_a = grpc_channel_arg_integer_create( + const_cast(GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE), + max_tracer_event_memory); grpc_channel_args client_args = {1, &client_a}; channel_ = grpc_insecure_channel_create("fake_target", &client_args, nullptr); @@ -286,9 +287,9 @@ TEST(ChannelTracerTest, TestSmallMemoryLimit) { TEST(ChannelTracerTest, TestEviction) { grpc_core::ExecCtx exec_ctx; - // This depends on sizeof(ChannelTrace). If that struct has been updated, + // This depends on sizeof(ChannelEvent). If that struct has been updated, // this will too. - const int kTraceEventSize = 80; + const int kTraceEventSize = GetSizeofTraceEvent(); const int kNumEvents = 5; ChannelTrace tracer(kTraceEventSize * kNumEvents); for (int i = 1; i <= kNumEvents; ++i) { @@ -305,9 +306,9 @@ TEST(ChannelTracerTest, TestEviction) { TEST(ChannelTracerTest, TestMultipleEviction) { grpc_core::ExecCtx exec_ctx; - // This depends on sizeof(ChannelTrace). If that struct has been updated, + // This depends on sizeof(ChannelEvent). If that struct has been updated, // this will too. - const int kTraceEventSize = 80; + const int kTraceEventSize = GetSizeofTraceEvent(); const int kNumEvents = 5; ChannelTrace tracer(kTraceEventSize * kNumEvents); for (int i = 1; i <= kNumEvents; ++i) { @@ -326,9 +327,9 @@ TEST(ChannelTracerTest, TestMultipleEviction) { TEST(ChannelTracerTest, TestTotalEviction) { grpc_core::ExecCtx exec_ctx; - // This depends on sizeof(ChannelTrace). If that struct has been updated, + // This depends on sizeof(ChannelEvent). If that struct has been updated, // this will too. - const int kTraceEventSize = 80; + const int kTraceEventSize = GetSizeofTraceEvent(); const int kNumEvents = 5; ChannelTrace tracer(kTraceEventSize * kNumEvents); for (int i = 1; i <= kNumEvents; ++i) { diff --git a/test/core/end2end/tests/channelz.cc b/test/core/end2end/tests/channelz.cc index 58ffdc18da..0e3ad6a476 100644 --- a/test/core/end2end/tests/channelz.cc +++ b/test/core/end2end/tests/channelz.cc @@ -199,10 +199,8 @@ static void run_one_request(grpc_end2end_test_config config, static void test_channelz(grpc_end2end_test_config config) { grpc_end2end_test_fixture f; - grpc_arg arg; - arg.type = GRPC_ARG_INTEGER; - arg.key = const_cast(GRPC_ARG_ENABLE_CHANNELZ); - arg.value.integer = true; + grpc_arg arg = grpc_channel_arg_integer_create( + const_cast(GRPC_ARG_ENABLE_CHANNELZ), true); grpc_channel_args args = {1, &arg}; f = begin_test(config, "test_channelz", &args, &args); @@ -266,13 +264,11 @@ static void test_channelz_with_channel_trace(grpc_end2end_test_config config) { grpc_end2end_test_fixture f; grpc_arg arg[2]; - arg[0].type = GRPC_ARG_INTEGER; - arg[0].key = - const_cast(GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE); - arg[0].value.integer = 1024; - arg[1].type = GRPC_ARG_INTEGER; - arg[1].key = const_cast(GRPC_ARG_ENABLE_CHANNELZ); - arg[1].value.integer = true; + arg[0] = grpc_channel_arg_integer_create( + const_cast(GRPC_ARG_MAX_CHANNEL_TRACE_EVENT_MEMORY_PER_NODE), + 1024 * 1024); + arg[1] = grpc_channel_arg_integer_create( + const_cast(GRPC_ARG_ENABLE_CHANNELZ), true); grpc_channel_args args = {GPR_ARRAY_SIZE(arg), arg}; f = begin_test(config, "test_channelz_with_channel_trace", &args, &args); -- cgit v1.2.3 From 6f6033c91019709c601f90d84617f07f8374699e Mon Sep 17 00:00:00 2001 From: ncteisen Date: Fri, 5 Oct 2018 11:30:14 -0700 Subject: remove stale commentS --- test/core/channel/channel_trace_test.cc | 6 ------ 1 file changed, 6 deletions(-) diff --git a/test/core/channel/channel_trace_test.cc b/test/core/channel/channel_trace_test.cc index a569444fed..3d8de79e37 100644 --- a/test/core/channel/channel_trace_test.cc +++ b/test/core/channel/channel_trace_test.cc @@ -287,8 +287,6 @@ TEST(ChannelTracerTest, TestSmallMemoryLimit) { TEST(ChannelTracerTest, TestEviction) { grpc_core::ExecCtx exec_ctx; - // This depends on sizeof(ChannelEvent). If that struct has been updated, - // this will too. const int kTraceEventSize = GetSizeofTraceEvent(); const int kNumEvents = 5; ChannelTrace tracer(kTraceEventSize * kNumEvents); @@ -306,8 +304,6 @@ TEST(ChannelTracerTest, TestEviction) { TEST(ChannelTracerTest, TestMultipleEviction) { grpc_core::ExecCtx exec_ctx; - // This depends on sizeof(ChannelEvent). If that struct has been updated, - // this will too. const int kTraceEventSize = GetSizeofTraceEvent(); const int kNumEvents = 5; ChannelTrace tracer(kTraceEventSize * kNumEvents); @@ -327,8 +323,6 @@ TEST(ChannelTracerTest, TestMultipleEviction) { TEST(ChannelTracerTest, TestTotalEviction) { grpc_core::ExecCtx exec_ctx; - // This depends on sizeof(ChannelEvent). If that struct has been updated, - // this will too. const int kTraceEventSize = GetSizeofTraceEvent(); const int kNumEvents = 5; ChannelTrace tracer(kTraceEventSize * kNumEvents); -- cgit v1.2.3