[wrr] Add metrics to help debug high WRR cost (#34095)

WRR is showing a very high CPU cost relative to previous solutions, and
it's unclear why this is.
Add two metrics that should help us see the shape of the subchannel sets
that are being passed to high cost systems in order to confirm/deny
theories.

---------

Co-authored-by: ctiller <ctiller@users.noreply.github.com>
pull/34100/head
Craig Tiller 2 years ago committed by GitHub
parent 5fbc1a841b
commit b85b57fdc7
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
  1. 2
      src/core/BUILD
  2. 6
      src/core/ext/filters/client_channel/lb_policy/weighted_round_robin/weighted_round_robin.cc
  3. 114
      src/core/lib/debug/stats_data.cc
  4. 41
      src/core/lib/debug/stats_data.h
  5. 11
      src/core/lib/debug/stats_data.yaml
  6. 2
      test/core/client_channel/lb_policy/lb_policy_test_lib.h
  7. 2
      tools/codegen/core/gen_stats_data.py

@ -4876,6 +4876,7 @@ grpc_cc_library(
"ref_counted",
"resolved_address",
"static_stride_scheduler",
"stats_data",
"subchannel_interface",
"time",
"validation_errors",
@ -4890,6 +4891,7 @@ grpc_cc_library(
"//:ref_counted_ptr",
"//:server_address",
"//:sockaddr_utils",
"//:stats",
"//:work_serializer",
],
)

@ -51,6 +51,8 @@
#include "src/core/lib/address_utils/sockaddr_utils.h"
#include "src/core/lib/channel/channel_args.h"
#include "src/core/lib/config/core_configuration.h"
#include "src/core/lib/debug/stats.h"
#include "src/core/lib/debug/stats_data.h"
#include "src/core/lib/debug/trace.h"
#include "src/core/lib/gprpp/debug_location.h"
#include "src/core/lib/gprpp/orphanable.h"
@ -511,6 +513,9 @@ WeightedRoundRobin::Picker::Picker(
subchannels_.emplace_back(sd->subchannel()->Ref(), sd->weight());
}
}
global_stats().IncrementWrrSubchannelListSize(
subchannel_list->num_subchannels());
global_stats().IncrementWrrSubchannelReadySize(subchannels_.size());
if (GRPC_TRACE_FLAG_ENABLED(grpc_lb_wrr_trace)) {
gpr_log(GPR_INFO,
"[WRR %p picker %p] created picker from subchannel_list=%p "
@ -657,6 +662,7 @@ void WeightedRoundRobin::ResetBackoffLocked() {
}
absl::Status WeightedRoundRobin::UpdateLocked(UpdateArgs args) {
global_stats().IncrementWrrUpdates();
config_ = std::move(args.config);
ServerAddressList addresses;
if (args.addresses.ok()) {

@ -54,6 +54,19 @@ Histogram_16777216_20 operator-(const Histogram_16777216_20& left,
}
return result;
}
void HistogramCollector_10000_20::Collect(Histogram_10000_20* result) const {
for (int i = 0; i < 20; i++) {
result->buckets_[i] += buckets_[i].load(std::memory_order_relaxed);
}
}
Histogram_10000_20 operator-(const Histogram_10000_20& left,
const Histogram_10000_20& right) {
Histogram_10000_20 result;
for (int i = 0; i < 20; i++) {
result.buckets_[i] = left.buckets_[i] - right.buckets_[i];
}
return result;
}
void HistogramCollector_80_10::Collect(Histogram_80_10* result) const {
for (int i = 0; i < 10; i++) {
result->buckets_[i] += buckets_[i].load(std::memory_order_relaxed);
@ -69,15 +82,25 @@ Histogram_80_10 operator-(const Histogram_80_10& left,
}
const absl::string_view
GlobalStats::counter_name[static_cast<int>(Counter::COUNT)] = {
"client_calls_created", "server_calls_created",
"client_channels_created", "client_subchannels_created",
"server_channels_created", "insecure_connections_created",
"syscall_write", "syscall_read",
"tcp_read_alloc_8k", "tcp_read_alloc_64k",
"http2_settings_writes", "http2_pings_sent",
"http2_writes_begun", "http2_transport_stalls",
"http2_stream_stalls", "cq_pluck_creates",
"cq_next_creates", "cq_callback_creates",
"client_calls_created",
"server_calls_created",
"client_channels_created",
"client_subchannels_created",
"server_channels_created",
"insecure_connections_created",
"syscall_write",
"syscall_read",
"tcp_read_alloc_8k",
"tcp_read_alloc_64k",
"http2_settings_writes",
"http2_pings_sent",
"http2_writes_begun",
"http2_transport_stalls",
"http2_stream_stalls",
"cq_pluck_creates",
"cq_next_creates",
"cq_callback_creates",
"wrr_updates",
};
const absl::string_view GlobalStats::counter_doc[static_cast<int>(
Counter::COUNT)] = {
@ -105,12 +128,15 @@ const absl::string_view GlobalStats::counter_doc[static_cast<int>(
"usage)",
"Number of completion queues created for cq_callback (indicates callback "
"api usage)",
"Number of wrr updates that have been received",
};
const absl::string_view GlobalStats::histogram_name[static_cast<int>(
Histogram::COUNT)] = {
"call_initial_size", "tcp_write_size", "tcp_write_iov_size",
"tcp_read_size", "tcp_read_offer", "tcp_read_offer_iov_size",
"http2_send_message_size", "http2_metadata_size",
const absl::string_view
GlobalStats::histogram_name[static_cast<int>(Histogram::COUNT)] = {
"call_initial_size", "tcp_write_size",
"tcp_write_iov_size", "tcp_read_size",
"tcp_read_offer", "tcp_read_offer_iov_size",
"http2_send_message_size", "http2_metadata_size",
"wrr_subchannel_list_size", "wrr_subchannel_ready_size",
};
const absl::string_view GlobalStats::histogram_doc[static_cast<int>(
Histogram::COUNT)] = {
@ -122,6 +148,8 @@ const absl::string_view GlobalStats::histogram_doc[static_cast<int>(
"Number of byte segments offered to each syscall_read",
"Size of messages received by HTTP2 transport",
"Number of bytes consumed by metadata, according to HPACK accounting rules",
"Number of subchannels in a subchannel list at picker creation time",
"Number of READY subchannels in a subchannel list at picker creation time",
};
namespace {
const int kStatsTable0[27] = {0, 1, 2, 4, 7, 11, 17,
@ -138,8 +166,14 @@ const int kStatsTable2[21] = {
const uint8_t kStatsTable3[23] = {2, 3, 3, 4, 5, 6, 7, 8,
8, 9, 10, 11, 12, 12, 13, 14,
15, 16, 16, 17, 18, 19, 20};
const int kStatsTable4[11] = {0, 1, 2, 4, 7, 11, 17, 26, 38, 56, 80};
const uint8_t kStatsTable5[9] = {3, 3, 4, 5, 6, 6, 7, 8, 9};
const int kStatsTable4[21] = {0, 1, 2, 4, 7, 12, 19,
30, 47, 74, 116, 182, 285, 445,
695, 1084, 1691, 2637, 4113, 6414, 10000};
const uint8_t kStatsTable5[23] = {3, 3, 4, 5, 5, 6, 7, 8,
9, 9, 10, 11, 12, 12, 13, 14,
15, 15, 16, 17, 18, 18, 19};
const int kStatsTable6[11] = {0, 1, 2, 4, 7, 11, 17, 26, 38, 56, 80};
const uint8_t kStatsTable7[9] = {3, 3, 4, 5, 6, 6, 7, 8, 9};
} // namespace
int Histogram_65536_26::BucketFor(int value) {
if (value < 3) {
@ -179,7 +213,7 @@ int Histogram_16777216_20::BucketFor(int value) {
}
}
}
int Histogram_80_10::BucketFor(int value) {
int Histogram_10000_20::BucketFor(int value) {
if (value < 3) {
if (value < 0) {
return 0;
@ -187,12 +221,35 @@ int Histogram_80_10::BucketFor(int value) {
return value;
}
} else {
if (value < 49) {
if (value < 6145) {
DblUint val;
val.dbl = value;
const int bucket =
kStatsTable5[((val.uint - 4613937818241073152ull) >> 51)];
return bucket - (value < kStatsTable4[bucket]);
} else {
if (value < 6414) {
return 18;
} else {
return 19;
}
}
}
}
int Histogram_80_10::BucketFor(int value) {
if (value < 3) {
if (value < 0) {
return 0;
} else {
return value;
}
} else {
if (value < 49) {
DblUint val;
val.dbl = value;
const int bucket =
kStatsTable7[((val.uint - 4613937818241073152ull) >> 51)];
return bucket - (value < kStatsTable6[bucket]);
} else {
if (value < 56) {
return 8;
@ -220,7 +277,8 @@ GlobalStats::GlobalStats()
http2_stream_stalls{0},
cq_pluck_creates{0},
cq_next_creates{0},
cq_callback_creates{0} {}
cq_callback_creates{0},
wrr_updates{0} {}
HistogramView GlobalStats::histogram(Histogram which) const {
switch (which) {
default:
@ -232,7 +290,7 @@ HistogramView GlobalStats::histogram(Histogram which) const {
return HistogramView{&Histogram_16777216_20::BucketFor, kStatsTable2, 20,
tcp_write_size.buckets()};
case Histogram::kTcpWriteIovSize:
return HistogramView{&Histogram_80_10::BucketFor, kStatsTable4, 10,
return HistogramView{&Histogram_80_10::BucketFor, kStatsTable6, 10,
tcp_write_iov_size.buckets()};
case Histogram::kTcpReadSize:
return HistogramView{&Histogram_16777216_20::BucketFor, kStatsTable2, 20,
@ -241,7 +299,7 @@ HistogramView GlobalStats::histogram(Histogram which) const {
return HistogramView{&Histogram_16777216_20::BucketFor, kStatsTable2, 20,
tcp_read_offer.buckets()};
case Histogram::kTcpReadOfferIovSize:
return HistogramView{&Histogram_80_10::BucketFor, kStatsTable4, 10,
return HistogramView{&Histogram_80_10::BucketFor, kStatsTable6, 10,
tcp_read_offer_iov_size.buckets()};
case Histogram::kHttp2SendMessageSize:
return HistogramView{&Histogram_16777216_20::BucketFor, kStatsTable2, 20,
@ -249,6 +307,12 @@ HistogramView GlobalStats::histogram(Histogram which) const {
case Histogram::kHttp2MetadataSize:
return HistogramView{&Histogram_65536_26::BucketFor, kStatsTable0, 26,
http2_metadata_size.buckets()};
case Histogram::kWrrSubchannelListSize:
return HistogramView{&Histogram_10000_20::BucketFor, kStatsTable4, 20,
wrr_subchannel_list_size.buckets()};
case Histogram::kWrrSubchannelReadySize:
return HistogramView{&Histogram_10000_20::BucketFor, kStatsTable4, 20,
wrr_subchannel_ready_size.buckets()};
}
}
std::unique_ptr<GlobalStats> GlobalStatsCollector::Collect() const {
@ -288,6 +352,7 @@ std::unique_ptr<GlobalStats> GlobalStatsCollector::Collect() const {
data.cq_next_creates.load(std::memory_order_relaxed);
result->cq_callback_creates +=
data.cq_callback_creates.load(std::memory_order_relaxed);
result->wrr_updates += data.wrr_updates.load(std::memory_order_relaxed);
data.call_initial_size.Collect(&result->call_initial_size);
data.tcp_write_size.Collect(&result->tcp_write_size);
data.tcp_write_iov_size.Collect(&result->tcp_write_iov_size);
@ -296,6 +361,8 @@ std::unique_ptr<GlobalStats> GlobalStatsCollector::Collect() const {
data.tcp_read_offer_iov_size.Collect(&result->tcp_read_offer_iov_size);
data.http2_send_message_size.Collect(&result->http2_send_message_size);
data.http2_metadata_size.Collect(&result->http2_metadata_size);
data.wrr_subchannel_list_size.Collect(&result->wrr_subchannel_list_size);
data.wrr_subchannel_ready_size.Collect(&result->wrr_subchannel_ready_size);
}
return result;
}
@ -327,6 +394,7 @@ std::unique_ptr<GlobalStats> GlobalStats::Diff(const GlobalStats& other) const {
result->cq_pluck_creates = cq_pluck_creates - other.cq_pluck_creates;
result->cq_next_creates = cq_next_creates - other.cq_next_creates;
result->cq_callback_creates = cq_callback_creates - other.cq_callback_creates;
result->wrr_updates = wrr_updates - other.wrr_updates;
result->call_initial_size = call_initial_size - other.call_initial_size;
result->tcp_write_size = tcp_write_size - other.tcp_write_size;
result->tcp_write_iov_size = tcp_write_iov_size - other.tcp_write_iov_size;
@ -337,6 +405,10 @@ std::unique_ptr<GlobalStats> GlobalStats::Diff(const GlobalStats& other) const {
result->http2_send_message_size =
http2_send_message_size - other.http2_send_message_size;
result->http2_metadata_size = http2_metadata_size - other.http2_metadata_size;
result->wrr_subchannel_list_size =
wrr_subchannel_list_size - other.wrr_subchannel_list_size;
result->wrr_subchannel_ready_size =
wrr_subchannel_ready_size - other.wrr_subchannel_ready_size;
return result;
}
} // namespace grpc_core

@ -76,6 +76,29 @@ class HistogramCollector_16777216_20 {
private:
std::atomic<uint64_t> buckets_[20]{};
};
class HistogramCollector_10000_20;
class Histogram_10000_20 {
public:
static int BucketFor(int value);
const uint64_t* buckets() const { return buckets_; }
friend Histogram_10000_20 operator-(const Histogram_10000_20& left,
const Histogram_10000_20& right);
private:
friend class HistogramCollector_10000_20;
uint64_t buckets_[20]{};
};
class HistogramCollector_10000_20 {
public:
void Increment(int value) {
buckets_[Histogram_10000_20::BucketFor(value)].fetch_add(
1, std::memory_order_relaxed);
}
void Collect(Histogram_10000_20* result) const;
private:
std::atomic<uint64_t> buckets_[20]{};
};
class HistogramCollector_80_10;
class Histogram_80_10 {
public:
@ -119,6 +142,7 @@ struct GlobalStats {
kCqPluckCreates,
kCqNextCreates,
kCqCallbackCreates,
kWrrUpdates,
COUNT
};
enum class Histogram {
@ -130,6 +154,8 @@ struct GlobalStats {
kTcpReadOfferIovSize,
kHttp2SendMessageSize,
kHttp2MetadataSize,
kWrrSubchannelListSize,
kWrrSubchannelReadySize,
COUNT
};
GlobalStats();
@ -159,6 +185,7 @@ struct GlobalStats {
uint64_t cq_pluck_creates;
uint64_t cq_next_creates;
uint64_t cq_callback_creates;
uint64_t wrr_updates;
};
uint64_t counters[static_cast<int>(Counter::COUNT)];
};
@ -170,6 +197,8 @@ struct GlobalStats {
Histogram_80_10 tcp_read_offer_iov_size;
Histogram_16777216_20 http2_send_message_size;
Histogram_65536_26 http2_metadata_size;
Histogram_10000_20 wrr_subchannel_list_size;
Histogram_10000_20 wrr_subchannel_ready_size;
HistogramView histogram(Histogram which) const;
std::unique_ptr<GlobalStats> Diff(const GlobalStats& other) const;
};
@ -240,6 +269,9 @@ class GlobalStatsCollector {
data_.this_cpu().cq_callback_creates.fetch_add(1,
std::memory_order_relaxed);
}
void IncrementWrrUpdates() {
data_.this_cpu().wrr_updates.fetch_add(1, std::memory_order_relaxed);
}
void IncrementCallInitialSize(int value) {
data_.this_cpu().call_initial_size.Increment(value);
}
@ -264,6 +296,12 @@ class GlobalStatsCollector {
void IncrementHttp2MetadataSize(int value) {
data_.this_cpu().http2_metadata_size.Increment(value);
}
void IncrementWrrSubchannelListSize(int value) {
data_.this_cpu().wrr_subchannel_list_size.Increment(value);
}
void IncrementWrrSubchannelReadySize(int value) {
data_.this_cpu().wrr_subchannel_ready_size.Increment(value);
}
private:
struct Data {
@ -285,6 +323,7 @@ class GlobalStatsCollector {
std::atomic<uint64_t> cq_pluck_creates{0};
std::atomic<uint64_t> cq_next_creates{0};
std::atomic<uint64_t> cq_callback_creates{0};
std::atomic<uint64_t> wrr_updates{0};
HistogramCollector_65536_26 call_initial_size;
HistogramCollector_16777216_20 tcp_write_size;
HistogramCollector_80_10 tcp_write_iov_size;
@ -293,6 +332,8 @@ class GlobalStatsCollector {
HistogramCollector_80_10 tcp_read_offer_iov_size;
HistogramCollector_16777216_20 http2_send_message_size;
HistogramCollector_65536_26 http2_metadata_size;
HistogramCollector_10000_20 wrr_subchannel_list_size;
HistogramCollector_10000_20 wrr_subchannel_ready_size;
};
PerCpu<Data> data_{PerCpuOptions().SetCpusPerShard(4).SetMaxShards(32)};
};

@ -87,3 +87,14 @@
doc: Number of completion queues created for cq_next (indicates cq async api usage)
- counter: cq_callback_creates
doc: Number of completion queues created for cq_callback (indicates callback api usage)
# wrr
- histogram: wrr_subchannel_list_size
doc: Number of subchannels in a subchannel list at picker creation time
max: 10000
buckets: 20
- histogram: wrr_subchannel_ready_size
doc: Number of READY subchannels in a subchannel list at picker creation time
max: 10000
buckets: 20
- counter: wrr_updates
doc: Number of wrr updates that have been received

@ -243,6 +243,7 @@ class LoadBalancingPolicyTest : public ::testing::Test {
const absl::Status& status = absl::OkStatus(),
bool validate_state_transition = true,
SourceLocation location = SourceLocation()) {
ExecCtx exec_ctx;
if (state == GRPC_CHANNEL_TRANSIENT_FAILURE) {
EXPECT_FALSE(status.ok())
<< "bug in test: TRANSIENT_FAILURE must have non-OK status";
@ -614,6 +615,7 @@ class LoadBalancingPolicyTest : public ::testing::Test {
// Applies the update on the LB policy.
absl::Status ApplyUpdate(LoadBalancingPolicy::UpdateArgs update_args,
LoadBalancingPolicy* lb_policy) {
ExecCtx exec_ctx;
absl::Status status;
absl::Notification notification;
work_serializer_->Run(

@ -25,7 +25,7 @@ import sys
import yaml
with open("src/core/lib/debug/stats_data.yaml") as f:
attrs = yaml.safe_load(f.read(), Loader=yaml.Loader)
attrs = yaml.safe_load(f.read())
REQUIRED_FIELDS = ["name", "doc"]

Loading…
Cancel
Save