[Gpr_To_Absl_Logging] Using GRPC_TRACE_LOG instead of GRPC_TRACE_FLAG_ENABLED (#37389)

[Gpr_To_Absl_Logging] Using GRPC_TRACE_LOG instead of GRPC_TRACE_FLAG_ENABLED

Closes #37389

COPYBARA_INTEGRATE_REVIEW=https://github.com/grpc/grpc/pull/37389 from tanvi-jagtap:GRPC_TRACE_FLAG_ENABLED_04 bcf1c6255f
PiperOrigin-RevId: 661111633
pull/37428/head
Tanvi Jagtap 6 months ago committed by Copybara-Service
parent 8271b14c41
commit 8fe72e49b2
  1. 69
      src/core/load_balancing/grpclb/grpclb.cc
  2. 48
      src/core/load_balancing/health_check_client.cc
  3. 63
      src/core/load_balancing/outlier_detection/outlier_detection.cc
  4. 151
      src/core/load_balancing/pick_first/pick_first.cc
  5. 72
      src/core/load_balancing/priority/priority.cc
  6. 26
      src/core/load_balancing/ring_hash/ring_hash.cc
  7. 105
      src/core/load_balancing/rls/rls.cc
  8. 34
      src/core/load_balancing/round_robin/round_robin.cc
  9. 49
      src/core/load_balancing/weighted_round_robin/weighted_round_robin.cc
  10. 57
      src/core/load_balancing/weighted_target/weighted_target.cc
  11. 47
      src/core/load_balancing/xds/cds.cc
  12. 19
      src/core/load_balancing/xds/xds_cluster_impl.cc
  13. 52
      src/core/load_balancing/xds/xds_cluster_manager.cc
  14. 56
      src/core/load_balancing/xds/xds_override_host.cc
  15. 23
      src/core/load_balancing/xds/xds_wrr_locality.cc

@ -1174,17 +1174,16 @@ void GrpcLb::BalancerCallState::OnBalancerMessageReceivedLocked() {
if (response.client_stats_report_interval != Duration::Zero()) {
client_stats_report_interval_ = std::max(
Duration::Seconds(1), response.client_stats_report_interval);
if (GRPC_TRACE_FLAG_ENABLED(glb)) {
LOG(INFO) << "[grpclb " << grpclb_policy() << "] lb_calld=" << this
<< ": Received initial LB response message; client load "
"reporting interval = "
<< client_stats_report_interval_.millis()
<< " milliseconds";
}
} else if (GRPC_TRACE_FLAG_ENABLED(glb)) {
LOG(INFO) << "[grpclb " << grpclb_policy() << "] lb_calld=" << this
<< ": Received initial LB response message; client load "
"reporting NOT enabled";
GRPC_TRACE_LOG(glb, INFO)
<< "[grpclb " << grpclb_policy() << "] lb_calld=" << this
<< ": Received initial LB response message; client load "
"reporting interval = "
<< client_stats_report_interval_.millis() << " milliseconds";
} else {
GRPC_TRACE_LOG(glb, INFO)
<< "[grpclb " << grpclb_policy() << "] lb_calld=" << this
<< ": Received initial LB response message; client load "
"reporting NOT enabled";
}
seen_initial_response_ = true;
break;
@ -1193,13 +1192,11 @@ void GrpcLb::BalancerCallState::OnBalancerMessageReceivedLocked() {
CHECK_NE(lb_call_, nullptr);
auto serverlist_wrapper =
MakeRefCounted<Serverlist>(std::move(response.serverlist));
if (GRPC_TRACE_FLAG_ENABLED(glb)) {
LOG(INFO) << "[grpclb " << grpclb_policy() << "] lb_calld=" << this
<< ": Serverlist with "
<< serverlist_wrapper->serverlist().size()
<< " servers received:\n"
<< serverlist_wrapper->AsText();
}
GRPC_TRACE_LOG(glb, INFO)
<< "[grpclb " << grpclb_policy() << "] lb_calld=" << this
<< ": Serverlist with " << serverlist_wrapper->serverlist().size()
<< " servers received:\n"
<< serverlist_wrapper->AsText();
seen_serverlist_ = true;
// Start sending client load report only after we start using the
// serverlist returned from the current LB call.
@ -1213,11 +1210,10 @@ void GrpcLb::BalancerCallState::OnBalancerMessageReceivedLocked() {
// Check if the serverlist differs from the previous one.
if (grpclb_policy()->serverlist_ != nullptr &&
*grpclb_policy()->serverlist_ == *serverlist_wrapper) {
if (GRPC_TRACE_FLAG_ENABLED(glb)) {
LOG(INFO) << "[grpclb " << grpclb_policy() << "] lb_calld=" << this
<< ": Incoming server list identical to current, "
"ignoring.";
}
GRPC_TRACE_LOG(glb, INFO)
<< "[grpclb " << grpclb_policy() << "] lb_calld=" << this
<< ": Incoming server list identical to current, "
"ignoring.";
} else { // New serverlist.
// Dispose of the fallback.
// TODO(roth): Ideally, we should stay in fallback mode until we
@ -1457,11 +1453,10 @@ GrpcLb::GrpcLb(Args args)
GRPC_ARG_GRPCLB_SUBCHANNEL_CACHE_INTERVAL_MS)
.value_or(Duration::Milliseconds(
GRPC_GRPCLB_DEFAULT_SUBCHANNEL_DELETION_DELAY_MS)))) {
if (GRPC_TRACE_FLAG_ENABLED(glb)) {
LOG(INFO) << "[grpclb " << this << "] Will use '"
<< std::string(channel_control_helper()->GetAuthority())
<< "' as the server name for LB request.";
}
GRPC_TRACE_LOG(glb, INFO)
<< "[grpclb " << this << "] Will use '"
<< std::string(channel_control_helper()->GetAuthority())
<< "' as the server name for LB request.";
}
void GrpcLb::ShutdownLocked() {
@ -1542,9 +1537,7 @@ class GrpcLb::NullLbTokenEndpointIterator final
};
absl::Status GrpcLb::UpdateLocked(UpdateArgs args) {
if (GRPC_TRACE_FLAG_ENABLED(glb)) {
LOG(INFO) << "[grpclb " << this << "] received update";
}
GRPC_TRACE_LOG(glb, INFO) << "[grpclb " << this << "] received update";
const bool is_initial_update = lb_channel_ == nullptr;
config_ = args.config.TakeAsSubclass<GrpcLbConfig>();
CHECK(config_ != nullptr);
@ -1656,11 +1649,10 @@ void GrpcLb::StartBalancerCallLocked() {
// Init the LB call data.
CHECK(lb_calld_ == nullptr);
lb_calld_ = MakeOrphanable<BalancerCallState>(Ref());
if (GRPC_TRACE_FLAG_ENABLED(glb)) {
LOG(INFO) << "[grpclb " << this
<< "] Query for backends (lb_channel: " << lb_channel_.get()
<< ", lb_calld: " << lb_calld_.get() << ")";
}
GRPC_TRACE_LOG(glb, INFO)
<< "[grpclb " << this
<< "] Query for backends (lb_channel: " << lb_channel_.get()
<< ", lb_calld: " << lb_calld_.get() << ")";
lb_calld_->StartQuery();
}
@ -1695,9 +1687,8 @@ void GrpcLb::StartBalancerCallRetryTimerLocked() {
void GrpcLb::OnBalancerCallRetryTimerLocked() {
lb_call_retry_timer_handle_.reset();
if (!shutting_down_ && lb_calld_ == nullptr) {
if (GRPC_TRACE_FLAG_ENABLED(glb)) {
LOG(INFO) << "[grpclb " << this << "] Restarting call to LB server";
}
GRPC_TRACE_LOG(glb, INFO)
<< "[grpclb " << this << "] Restarting call to LB server";
StartBalancerCallLocked();
}
}

@ -146,11 +146,9 @@ void HealthProducer::HealthChecker::OnConnectivityStateChangeLocked(
void HealthProducer::HealthChecker::NotifyWatchersLocked(
grpc_connectivity_state state, absl::Status status) {
if (GRPC_TRACE_FLAG_ENABLED(health_check_client)) {
LOG(INFO) << "HealthProducer " << producer_.get() << " HealthChecker "
<< this << ": reporting state " << ConnectivityStateName(state)
<< " to watchers";
}
GRPC_TRACE_LOG(health_check_client, INFO)
<< "HealthProducer " << producer_.get() << " HealthChecker " << this
<< ": reporting state " << ConnectivityStateName(state) << " to watchers";
work_serializer_->Schedule(
[self = Ref(), state, status = std::move(status)]() {
MutexLock lock(&self->producer_->mu_);
@ -285,11 +283,10 @@ class HealthProducer::HealthChecker::HealthStreamEventHandler final
void SetHealthStatusLocked(SubchannelStreamClient* client,
grpc_connectivity_state state,
const char* reason) {
if (GRPC_TRACE_FLAG_ENABLED(health_check_client)) {
LOG(INFO) << "HealthCheckClient " << client
<< ": setting state=" << ConnectivityStateName(state)
<< " reason=" << reason;
}
GRPC_TRACE_LOG(health_check_client, INFO)
<< "HealthCheckClient " << client
<< ": setting state=" << ConnectivityStateName(state)
<< " reason=" << reason;
health_checker_->OnHealthWatchStatusChange(
state, state == GRPC_CHANNEL_TRANSIENT_FAILURE
? absl::UnavailableError(reason)
@ -300,11 +297,9 @@ class HealthProducer::HealthChecker::HealthStreamEventHandler final
};
void HealthProducer::HealthChecker::StartHealthStreamLocked() {
if (GRPC_TRACE_FLAG_ENABLED(health_check_client)) {
LOG(INFO) << "HealthProducer " << producer_.get() << " HealthChecker "
<< this << ": creating HealthClient for \""
<< health_check_service_name_ << "\"";
}
GRPC_TRACE_LOG(health_check_client, INFO)
<< "HealthProducer " << producer_.get() << " HealthChecker " << this
<< ": creating HealthClient for \"" << health_check_service_name_ << "\"";
stream_client_ = MakeOrphanable<SubchannelStreamClient>(
producer_->connected_subchannel_, producer_->subchannel_->pollset_set(),
std::make_unique<HealthStreamEventHandler>(Ref()),
@ -356,9 +351,8 @@ void HealthProducer::Start(RefCountedPtr<Subchannel> subchannel) {
}
void HealthProducer::Orphaned() {
if (GRPC_TRACE_FLAG_ENABLED(health_check_client)) {
LOG(INFO) << "HealthProducer " << this << ": shutting down";
}
GRPC_TRACE_LOG(health_check_client, INFO)
<< "HealthProducer " << this << ": shutting down";
{
MutexLock lock(&mu_);
health_checkers_.clear();
@ -406,11 +400,10 @@ void HealthProducer::RemoveWatcher(
void HealthProducer::OnConnectivityStateChange(grpc_connectivity_state state,
const absl::Status& status) {
if (GRPC_TRACE_FLAG_ENABLED(health_check_client)) {
LOG(INFO) << "HealthProducer " << this
<< ": subchannel state update: state="
<< ConnectivityStateName(state) << " status=" << status;
}
GRPC_TRACE_LOG(health_check_client, INFO)
<< "HealthProducer " << this
<< ": subchannel state update: state=" << ConnectivityStateName(state)
<< " status=" << status;
MutexLock lock(&mu_);
state_ = state;
status_ = status;
@ -432,11 +425,10 @@ void HealthProducer::OnConnectivityStateChange(grpc_connectivity_state state,
//
HealthWatcher::~HealthWatcher() {
if (GRPC_TRACE_FLAG_ENABLED(health_check_client)) {
LOG(INFO) << "HealthWatcher " << this << ": unregistering from producer "
<< producer_.get() << " (health_check_service_name=\""
<< health_check_service_name_.value_or("N/A") << "\")";
}
GRPC_TRACE_LOG(health_check_client, INFO)
<< "HealthWatcher " << this << ": unregistering from producer "
<< producer_.get() << " (health_check_service_name=\""
<< health_check_service_name_.value_or("N/A") << "\")";
if (producer_ != nullptr) {
producer_->RemoveWatcher(this, health_check_service_name_);
}

@ -532,11 +532,10 @@ OutlierDetectionLb::Picker::Picker(OutlierDetectionLb* outlier_detection_lb,
RefCountedPtr<SubchannelPicker> picker,
bool counting_enabled)
: picker_(std::move(picker)), counting_enabled_(counting_enabled) {
if (GRPC_TRACE_FLAG_ENABLED(outlier_detection_lb)) {
LOG(INFO) << "[outlier_detection_lb " << outlier_detection_lb
<< "] constructed new picker " << this << " and counting "
<< "is " << (counting_enabled ? "enabled" : "disabled");
}
GRPC_TRACE_LOG(outlier_detection_lb, INFO)
<< "[outlier_detection_lb " << outlier_detection_lb
<< "] constructed new picker " << this << " and counting "
<< "is " << (counting_enabled ? "enabled" : "disabled");
}
LoadBalancingPolicy::PickResult OutlierDetectionLb::Picker::Pick(
@ -574,9 +573,8 @@ LoadBalancingPolicy::PickResult OutlierDetectionLb::Picker::Pick(
OutlierDetectionLb::OutlierDetectionLb(Args args)
: LoadBalancingPolicy(std::move(args)) {
if (GRPC_TRACE_FLAG_ENABLED(outlier_detection_lb)) {
LOG(INFO) << "[outlier_detection_lb " << this << "] created";
}
GRPC_TRACE_LOG(outlier_detection_lb, INFO)
<< "[outlier_detection_lb " << this << "] created";
}
OutlierDetectionLb::~OutlierDetectionLb() {
@ -586,9 +584,8 @@ OutlierDetectionLb::~OutlierDetectionLb() {
}
void OutlierDetectionLb::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(outlier_detection_lb)) {
LOG(INFO) << "[outlier_detection_lb " << this << "] shutting down";
}
GRPC_TRACE_LOG(outlier_detection_lb, INFO)
<< "[outlier_detection_lb " << this << "] shutting down";
ejection_timer_.reset();
shutting_down_ = true;
// Remove the child policy's interested_parties pollset_set from the
@ -612,9 +609,8 @@ void OutlierDetectionLb::ResetBackoffLocked() {
}
absl::Status OutlierDetectionLb::UpdateLocked(UpdateArgs args) {
if (GRPC_TRACE_FLAG_ENABLED(outlier_detection_lb)) {
LOG(INFO) << "[outlier_detection_lb " << this << "] Received update";
}
GRPC_TRACE_LOG(outlier_detection_lb, INFO)
<< "[outlier_detection_lb " << this << "] Received update";
auto old_config = std::move(config_);
// Update config.
config_ = args.config.TakeAsSubclass<OutlierDetectionLbConfig>();
@ -627,9 +623,8 @@ absl::Status OutlierDetectionLb::UpdateLocked(UpdateArgs args) {
ejection_timer_.reset();
} else if (ejection_timer_ == nullptr) {
// No timer running. Start it now.
if (GRPC_TRACE_FLAG_ENABLED(outlier_detection_lb)) {
LOG(INFO) << "[outlier_detection_lb " << this << "] starting timer";
}
GRPC_TRACE_LOG(outlier_detection_lb, INFO)
<< "[outlier_detection_lb " << this << "] starting timer";
ejection_timer_ = MakeOrphanable<EjectionTimer>(
RefAsSubclass<OutlierDetectionLb>(), Timestamp::Now());
for (const auto& p : endpoint_state_map_) {
@ -687,11 +682,9 @@ absl::Status OutlierDetectionLb::UpdateLocked(UpdateArgs args) {
key, MakeRefCounted<EndpointState>(std::move(subchannels)));
} else if (!config_->CountingEnabled()) {
// If counting is not enabled, reset state.
if (GRPC_TRACE_FLAG_ENABLED(outlier_detection_lb)) {
LOG(INFO) << "[outlier_detection_lb " << this
<< "] counting disabled; disabling ejection for "
<< key.ToString();
}
GRPC_TRACE_LOG(outlier_detection_lb, INFO)
<< "[outlier_detection_lb " << this
<< "] counting disabled; disabling ejection for " << key.ToString();
it->second->DisableEjection();
}
});
@ -931,17 +924,14 @@ void OutlierDetectionLb::EjectionTimer::OnTimerLocked() {
const double success_rate_stdev_factor =
static_cast<double>(config.success_rate_ejection->stdev_factor) / 1000;
double ejection_threshold = mean - stdev * success_rate_stdev_factor;
if (GRPC_TRACE_FLAG_ENABLED(outlier_detection_lb)) {
LOG(INFO) << "[outlier_detection_lb " << parent_.get()
<< "] stdev=" << stdev
<< ", ejection_threshold=" << ejection_threshold;
}
GRPC_TRACE_LOG(outlier_detection_lb, INFO)
<< "[outlier_detection_lb " << parent_.get() << "] stdev=" << stdev
<< ", ejection_threshold=" << ejection_threshold;
for (auto& candidate : success_rate_ejection_candidates) {
if (GRPC_TRACE_FLAG_ENABLED(outlier_detection_lb)) {
LOG(INFO) << "[outlier_detection_lb " << parent_.get()
<< "] checking candidate " << candidate.first
<< ": success_rate=" << candidate.second;
}
GRPC_TRACE_LOG(outlier_detection_lb, INFO)
<< "[outlier_detection_lb " << parent_.get()
<< "] checking candidate " << candidate.first
<< ": success_rate=" << candidate.second;
if (candidate.second < ejection_threshold) {
uint32_t random_key = absl::Uniform(bit_gen_, 1, 100);
double current_percent =
@ -979,11 +969,10 @@ void OutlierDetectionLb::EjectionTimer::OnTimerLocked() {
<< config.failure_percentage_ejection->enforcement_percentage;
}
for (auto& candidate : failure_percentage_ejection_candidates) {
if (GRPC_TRACE_FLAG_ENABLED(outlier_detection_lb)) {
LOG(INFO) << "[outlier_detection_lb " << parent_.get()
<< "] checking candidate " << candidate.first
<< ": success_rate=" << candidate.second;
}
GRPC_TRACE_LOG(outlier_detection_lb, INFO)
<< "[outlier_detection_lb " << parent_.get()
<< "] checking candidate " << candidate.first
<< ": success_rate=" << candidate.second;
// Extra check to make sure success rate algorithm didn't already
// eject this backend.
if (candidate.first->ejection_time().has_value()) continue;

@ -420,22 +420,16 @@ PickFirst::PickFirst(Args args)
.GetInt(GRPC_ARG_HAPPY_EYEBALLS_CONNECTION_ATTEMPT_DELAY_MS)
.value_or(250),
100, 2000))) {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "Pick First " << this << " created.";
}
GRPC_TRACE_LOG(pick_first, INFO) << "Pick First " << this << " created.";
}
PickFirst::~PickFirst() {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "Destroying Pick First " << this;
}
GRPC_TRACE_LOG(pick_first, INFO) << "Destroying Pick First " << this;
CHECK(subchannel_list_ == nullptr);
}
void PickFirst::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "Pick First " << this << " Shutting down";
}
GRPC_TRACE_LOG(pick_first, INFO) << "Pick First " << this << " Shutting down";
shutdown_ = true;
UnsetSelectedSubchannel();
subchannel_list_.reset();
@ -444,9 +438,8 @@ void PickFirst::ShutdownLocked() {
void PickFirst::ExitIdleLocked() {
if (shutdown_) return;
if (IsIdle()) {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "Pick First " << this << " exiting idle";
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "Pick First " << this << " exiting idle";
AttemptToConnectUsingLatestUpdateArgsLocked();
}
}
@ -681,11 +674,10 @@ PickFirst::SubchannelList::SubchannelData::SubchannelState::SubchannelState(
}
void PickFirst::SubchannelList::SubchannelData::SubchannelState::Orphan() {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "[PF " << pick_first_.get() << "] subchannel state " << this
<< " (subchannel " << subchannel_.get()
<< "): cancelling watch and unreffing subchannel";
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "[PF " << pick_first_.get() << "] subchannel state " << this
<< " (subchannel " << subchannel_.get()
<< "): cancelling watch and unreffing subchannel";
subchannel_data_ = nullptr;
subchannel_->CancelConnectivityStateWatch(watcher_);
watcher_ = nullptr;
@ -706,9 +698,8 @@ void PickFirst::SubchannelList::SubchannelData::SubchannelState::Select() {
// for the health status notification.
// If health checking is NOT enabled, report READY.
if (pick_first_->enable_health_watch_) {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "[PF " << pick_first_.get() << "] starting health watch";
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "[PF " << pick_first_.get() << "] starting health watch";
auto watcher = std::make_unique<HealthWatcher>(
pick_first_.Ref(DEBUG_LOCATION, "HealthWatcher"));
pick_first_->health_watcher_ = watcher.get();
@ -767,11 +758,10 @@ void PickFirst::SubchannelList::SubchannelData::SubchannelState::
}
// We aren't trying to connect, so we must be the selected subchannel.
CHECK(pick_first_->selected_.get() == this);
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "Pick First " << pick_first_.get()
<< " selected subchannel connectivity changed to "
<< ConnectivityStateName(new_state);
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "Pick First " << pick_first_.get()
<< " selected subchannel connectivity changed to "
<< ConnectivityStateName(new_state);
// Any state change is considered to be a failure of the existing
// connection. Report the failure.
auto& stats_plugins =
@ -791,11 +781,10 @@ PickFirst::SubchannelList::SubchannelData::SubchannelData(
SubchannelList* subchannel_list, size_t index,
RefCountedPtr<SubchannelInterface> subchannel)
: subchannel_list_(subchannel_list), index_(index) {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "[PF " << subchannel_list_->policy_.get()
<< "] subchannel list " << subchannel_list_ << " index " << index_
<< ": creating subchannel data";
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "[PF " << subchannel_list_->policy_.get() << "] subchannel list "
<< subchannel_list_ << " index " << index_
<< ": creating subchannel data";
subchannel_state_ =
MakeOrphanable<SubchannelState>(this, std::move(subchannel));
}
@ -856,11 +845,10 @@ void PickFirst::SubchannelList::SubchannelData::OnConnectivityStateChange(
// is not in the new list. In that case, we drop the current
// connection and report IDLE.
if (p->selected_ != nullptr) {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "[PF " << p << "] subchannel list " << subchannel_list_
<< ": new update has no subchannels in "
<< "state READY; dropping existing connection and going IDLE";
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "[PF " << p << "] subchannel list " << subchannel_list_
<< ": new update has no subchannels in state READY; dropping "
"existing connection and going IDLE";
p->GoIdle();
} else {
// Start trying to connect, starting with the first subchannel.
@ -1016,18 +1004,16 @@ PickFirst::SubchannelList::SubchannelList(RefCountedPtr<PickFirst> policy,
address.address(), address.args(), args_);
if (subchannel == nullptr) {
// Subchannel could not be created.
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "[PF " << policy_.get()
<< "] could not create subchannel for address "
<< address.ToString() << ", ignoring";
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "[PF " << policy_.get()
<< "] could not create subchannel for address " << address.ToString()
<< ", ignoring";
return;
}
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "[PF " << policy_.get() << "] subchannel list " << this
<< " index " << subchannels_.size() << ": Created subchannel "
<< subchannel.get() << " for address " << address.ToString();
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "[PF " << policy_.get() << "] subchannel list " << this << " index "
<< subchannels_.size() << ": Created subchannel " << subchannel.get()
<< " for address " << address.ToString();
subchannels_.emplace_back(std::make_unique<SubchannelData>(
this, subchannels_.size(), std::move(subchannel)));
});
@ -1374,23 +1360,17 @@ OldPickFirst::OldPickFirst(Args args)
.GetInt(GRPC_ARG_HAPPY_EYEBALLS_CONNECTION_ATTEMPT_DELAY_MS)
.value_or(250),
100, 2000))) {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "Pick First " << this << " created.";
}
GRPC_TRACE_LOG(pick_first, INFO) << "Pick First " << this << " created.";
}
OldPickFirst::~OldPickFirst() {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "Destroying Pick First " << this;
}
GRPC_TRACE_LOG(pick_first, INFO) << "Destroying Pick First " << this;
CHECK(subchannel_list_ == nullptr);
CHECK(latest_pending_subchannel_list_ == nullptr);
}
void OldPickFirst::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "Pick First " << this << " Shutting down";
}
GRPC_TRACE_LOG(pick_first, INFO) << "Pick First " << this << " Shutting down";
shutdown_ = true;
UnsetSelectedSubchannel();
subchannel_list_.reset();
@ -1400,9 +1380,8 @@ void OldPickFirst::ShutdownLocked() {
void OldPickFirst::ExitIdleLocked() {
if (shutdown_) return;
if (IsIdle()) {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "Pick First " << this << " exiting idle";
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "Pick First " << this << " exiting idle";
AttemptToConnectUsingLatestUpdateArgsLocked();
}
}
@ -1597,11 +1576,10 @@ OldPickFirst::SubchannelList::SubchannelData::SubchannelData(
: subchannel_list_(subchannel_list),
index_(index),
subchannel_(std::move(subchannel)) {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "[PF " << subchannel_list_->policy_.get()
<< "] subchannel list " << subchannel_list_ << " index " << index_
<< " (subchannel " << subchannel_.get() << "): starting watch";
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "[PF " << subchannel_list_->policy_.get() << "] subchannel list "
<< subchannel_list_ << " index " << index_ << " (subchannel "
<< subchannel_.get() << "): starting watch";
auto watcher = std::make_unique<Watcher>(
subchannel_list_->Ref(DEBUG_LOCATION, "Watcher"), index_);
pending_watcher_ = watcher.get();
@ -1658,11 +1636,9 @@ void OldPickFirst::SubchannelList::SubchannelData::OnConnectivityStateChange(
// Handle updates for the currently selected subchannel.
if (p->selected_ == this) {
CHECK(subchannel_list_ == p->subchannel_list_.get());
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "Pick First " << p
<< " selected subchannel connectivity changed to "
<< ConnectivityStateName(new_state);
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "Pick First " << p << " selected subchannel connectivity changed to "
<< ConnectivityStateName(new_state);
// Any state change is considered to be a failure of the existing
// connection.
stats_plugins.AddCounter(
@ -1677,11 +1653,10 @@ void OldPickFirst::SubchannelList::SubchannelData::OnConnectivityStateChange(
p->channel_control_helper()->RequestReresolution();
// If there is a pending update, switch to the pending update.
if (p->latest_pending_subchannel_list_ != nullptr) {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "Pick First " << p << " promoting pending subchannel "
<< "list " << p->latest_pending_subchannel_list_.get()
<< " to replace " << p->subchannel_list_.get();
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "Pick First " << p << " promoting pending subchannel "
<< "list " << p->latest_pending_subchannel_list_.get()
<< " to replace " << p->subchannel_list_.get();
p->UnsetSelectedSubchannel();
p->subchannel_list_ = std::move(p->latest_pending_subchannel_list_);
// Set our state to that of the pending subchannel list.
@ -1895,11 +1870,10 @@ void OldPickFirst::SubchannelList::SubchannelData::
subchannel_list_ == p->latest_pending_subchannel_list_.get());
// Case 2. Promote p->latest_pending_subchannel_list_ to p->subchannel_list_.
if (subchannel_list_ == p->latest_pending_subchannel_list_.get()) {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "Pick First " << p << " promoting pending subchannel list "
<< p->latest_pending_subchannel_list_.get() << " to replace "
<< p->subchannel_list_.get();
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "Pick First " << p << " promoting pending subchannel list "
<< p->latest_pending_subchannel_list_.get() << " to replace "
<< p->subchannel_list_.get();
p->UnsetSelectedSubchannel();
p->subchannel_list_ = std::move(p->latest_pending_subchannel_list_);
}
@ -1912,9 +1886,8 @@ void OldPickFirst::SubchannelList::SubchannelData::
// for the health status notification.
// If health checking is NOT enabled, report READY.
if (p->enable_health_watch_) {
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "[PF " << p << "] starting health watch";
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "[PF " << p << "] starting health watch";
auto watcher = std::make_unique<HealthWatcher>(
p->RefAsSubclass<OldPickFirst>(DEBUG_LOCATION, "HealthWatcher"));
p->health_watcher_ = watcher.get();
@ -1959,18 +1932,16 @@ OldPickFirst::SubchannelList::SubchannelList(
address.address(), address.args(), args_);
if (subchannel == nullptr) {
// Subchannel could not be created.
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "[PF " << policy_.get()
<< "] could not create subchannel for address "
<< address.ToString() << ", ignoring";
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "[PF " << policy_.get()
<< "] could not create subchannel for address " << address.ToString()
<< ", ignoring";
return;
}
if (GRPC_TRACE_FLAG_ENABLED(pick_first)) {
LOG(INFO) << "[PF " << policy_.get() << "] subchannel list " << this
<< " index " << subchannels_.size() << ": Created subchannel "
<< subchannel.get() << " for address " << address.ToString();
}
GRPC_TRACE_LOG(pick_first, INFO)
<< "[PF " << policy_.get() << "] subchannel list " << this << " index "
<< subchannels_.size() << ": Created subchannel " << subchannel.get()
<< " for address " << address.ToString();
subchannels_.emplace_back(this, subchannels_.size(), std::move(subchannel));
});
}

@ -294,21 +294,17 @@ PriorityLb::PriorityLb(Args args)
channel_args()
.GetDurationFromIntMillis(GRPC_ARG_PRIORITY_FAILOVER_TIMEOUT_MS)
.value_or(kDefaultChildFailoverTimeout))) {
if (GRPC_TRACE_FLAG_ENABLED(priority_lb)) {
LOG(INFO) << "[priority_lb " << this << "] created";
}
GRPC_TRACE_LOG(priority_lb, INFO) << "[priority_lb " << this << "] created";
}
PriorityLb::~PriorityLb() {
if (GRPC_TRACE_FLAG_ENABLED(priority_lb)) {
LOG(INFO) << "[priority_lb " << this << "] destroying priority LB policy";
}
GRPC_TRACE_LOG(priority_lb, INFO)
<< "[priority_lb " << this << "] destroying priority LB policy";
}
void PriorityLb::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(priority_lb)) {
LOG(INFO) << "[priority_lb " << this << "] shutting down";
}
GRPC_TRACE_LOG(priority_lb, INFO)
<< "[priority_lb " << this << "] shutting down";
shutting_down_ = true;
children_.clear();
}
@ -316,11 +312,9 @@ void PriorityLb::ShutdownLocked() {
void PriorityLb::ExitIdleLocked() {
if (current_priority_ != UINT32_MAX) {
const std::string& child_name = config_->priorities()[current_priority_];
if (GRPC_TRACE_FLAG_ENABLED(priority_lb)) {
LOG(INFO) << "[priority_lb " << this
<< "] exiting IDLE for current priority " << current_priority_
<< " child " << child_name;
}
GRPC_TRACE_LOG(priority_lb, INFO)
<< "[priority_lb " << this << "] exiting IDLE for current priority "
<< current_priority_ << " child " << child_name;
children_[child_name]->ExitIdleLocked();
}
}
@ -330,9 +324,8 @@ void PriorityLb::ResetBackoffLocked() {
}
absl::Status PriorityLb::UpdateLocked(UpdateArgs args) {
if (GRPC_TRACE_FLAG_ENABLED(priority_lb)) {
LOG(INFO) << "[priority_lb " << this << "] received update";
}
GRPC_TRACE_LOG(priority_lb, INFO)
<< "[priority_lb " << this << "] received update";
// Update config.
config_ = args.config.TakeAsSubclass<PriorityLbConfig>();
// Update args.
@ -451,11 +444,10 @@ void PriorityLb::ChoosePriorityLocked() {
}
// If we didn't find any priority to try, pick the first one in state
// CONNECTING.
if (GRPC_TRACE_FLAG_ENABLED(priority_lb)) {
LOG(INFO) << "[priority_lb " << this
<< "] no priority reachable, checking for CONNECTING priority to "
"delegate to";
}
GRPC_TRACE_LOG(priority_lb, INFO)
<< "[priority_lb " << this
<< "] no priority reachable, checking for CONNECTING priority to "
"delegate to";
for (uint32_t priority = 0; priority < config_->priorities().size();
++priority) {
// If the child for the priority does not exist yet, create it.
@ -530,11 +522,10 @@ PriorityLb::ChildPriority::DeactivationTimer::DeactivationTimer(
void PriorityLb::ChildPriority::DeactivationTimer::Orphan() {
if (timer_handle_.has_value()) {
if (GRPC_TRACE_FLAG_ENABLED(priority_lb)) {
LOG(INFO) << "[priority_lb " << child_priority_->priority_policy_.get()
<< "] child " << child_priority_->name_ << " ("
<< child_priority_.get() << "): reactivating";
}
GRPC_TRACE_LOG(priority_lb, INFO)
<< "[priority_lb " << child_priority_->priority_policy_.get()
<< "] child " << child_priority_->name_ << " (" << child_priority_.get()
<< "): reactivating";
child_priority_->priority_policy_->channel_control_helper()
->GetEventEngine()
->Cancel(*timer_handle_);
@ -588,11 +579,10 @@ PriorityLb::ChildPriority::FailoverTimer::FailoverTimer(
void PriorityLb::ChildPriority::FailoverTimer::Orphan() {
if (timer_handle_.has_value()) {
if (GRPC_TRACE_FLAG_ENABLED(priority_lb)) {
LOG(INFO) << "[priority_lb " << child_priority_->priority_policy_.get()
<< "] child " << child_priority_->name_ << " ("
<< child_priority_.get() << "): cancelling failover timer";
}
GRPC_TRACE_LOG(priority_lb, INFO)
<< "[priority_lb " << child_priority_->priority_policy_.get()
<< "] child " << child_priority_->name_ << " (" << child_priority_.get()
<< "): cancelling failover timer";
child_priority_->priority_policy_->channel_control_helper()
->GetEventEngine()
->Cancel(*timer_handle_);
@ -686,11 +676,10 @@ absl::Status PriorityLb::ChildPriority::UpdateLocked(
update_args.resolution_note = priority_policy_->resolution_note_;
update_args.args = priority_policy_->args_;
// Update the policy.
if (GRPC_TRACE_FLAG_ENABLED(priority_lb)) {
LOG(INFO) << "[priority_lb " << priority_policy_.get() << "] child "
<< name_ << " (" << this << "): updating child policy handler "
<< child_policy_.get();
}
GRPC_TRACE_LOG(priority_lb, INFO)
<< "[priority_lb " << priority_policy_.get() << "] child " << name_
<< " (" << this << "): updating child policy handler "
<< child_policy_.get();
return child_policy_->UpdateLocked(std::move(update_args));
}
@ -704,11 +693,10 @@ PriorityLb::ChildPriority::CreateChildPolicyLocked(const ChannelArgs& args) {
OrphanablePtr<LoadBalancingPolicy> lb_policy =
MakeOrphanable<ChildPolicyHandler>(std::move(lb_policy_args),
&priority_lb_trace);
if (GRPC_TRACE_FLAG_ENABLED(priority_lb)) {
LOG(INFO) << "[priority_lb " << priority_policy_.get() << "] child "
<< name_ << " (" << this << "): created new child policy handler "
<< lb_policy.get();
}
GRPC_TRACE_LOG(priority_lb, INFO)
<< "[priority_lb " << priority_policy_.get() << "] child " << name_
<< " (" << this << "): created new child policy handler "
<< lb_policy.get();
// Add the parent's interested_parties pollset_set to that of the newly
// created child policy. This will make the child policy progress upon
// activity on the parent LB, which in turn is tied to the application's call.

@ -597,21 +597,16 @@ void RingHash::RingHashEndpoint::OnStateUpdate(
//
RingHash::RingHash(Args args) : LoadBalancingPolicy(std::move(args)) {
if (GRPC_TRACE_FLAG_ENABLED(ring_hash_lb)) {
LOG(INFO) << "[RH " << this << "] Created";
}
GRPC_TRACE_LOG(ring_hash_lb, INFO) << "[RH " << this << "] Created";
}
RingHash::~RingHash() {
if (GRPC_TRACE_FLAG_ENABLED(ring_hash_lb)) {
LOG(INFO) << "[RH " << this << "] Destroying Ring Hash policy";
}
GRPC_TRACE_LOG(ring_hash_lb, INFO)
<< "[RH " << this << "] Destroying Ring Hash policy";
}
void RingHash::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(ring_hash_lb)) {
LOG(INFO) << "[RH " << this << "] Shutting down";
}
GRPC_TRACE_LOG(ring_hash_lb, INFO) << "[RH " << this << "] Shutting down";
shutdown_ = true;
endpoint_map_.clear();
}
@ -625,9 +620,7 @@ void RingHash::ResetBackoffLocked() {
absl::Status RingHash::UpdateLocked(UpdateArgs args) {
// Check address list.
if (args.addresses.ok()) {
if (GRPC_TRACE_FLAG_ENABLED(ring_hash_lb)) {
LOG(INFO) << "[RH " << this << "] received update";
}
GRPC_TRACE_LOG(ring_hash_lb, INFO) << "[RH " << this << "] received update";
// De-dup endpoints, taking weight into account.
endpoints_.clear();
std::map<EndpointAddressSet, size_t> endpoint_indices;
@ -641,11 +634,10 @@ absl::Status RingHash::UpdateLocked(UpdateArgs args) {
endpoint.args().GetInt(GRPC_ARG_ADDRESS_WEIGHT).value_or(1);
int prev_weight_arg =
prev_endpoint.args().GetInt(GRPC_ARG_ADDRESS_WEIGHT).value_or(1);
if (GRPC_TRACE_FLAG_ENABLED(ring_hash_lb)) {
LOG(INFO) << "[RH " << this << "] merging duplicate endpoint for "
<< key.ToString() << ", combined weight "
<< weight_arg + prev_weight_arg;
}
GRPC_TRACE_LOG(ring_hash_lb, INFO)
<< "[RH " << this << "] merging duplicate endpoint for "
<< key.ToString() << ", combined weight "
<< weight_arg + prev_weight_arg;
prev_endpoint = EndpointAddresses(
prev_endpoint.addresses(),
prev_endpoint.args().Set(GRPC_ARG_ADDRESS_WEIGHT,

@ -805,11 +805,9 @@ RlsLb::ChildPolicyWrapper::ChildPolicyWrapper(RefCountedPtr<RlsLb> lb_policy,
}
void RlsLb::ChildPolicyWrapper::Orphaned() {
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << lb_policy_.get()
<< "] ChildPolicyWrapper=" << this << " [" << target_
<< "]: shutdown";
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << lb_policy_.get() << "] ChildPolicyWrapper=" << this
<< " [" << target_ << "]: shutdown";
is_shutdown_ = true;
lb_policy_->child_policy_map_.erase(target_);
if (child_policy_ != nullptr) {
@ -876,11 +874,9 @@ void RlsLb::ChildPolicyWrapper::StartUpdate() {
*child_policy_config);
// Returned RLS target fails the validation.
if (!config.ok()) {
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << lb_policy_.get()
<< "] ChildPolicyWrapper=" << this << " [" << target_
<< "]: config failed to parse: " << config.status();
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << lb_policy_.get() << "] ChildPolicyWrapper=" << this
<< " [" << target_ << "]: config failed to parse: " << config.status();
pending_config_.reset();
picker_ = MakeRefCounted<TransientFailurePicker>(
absl::UnavailableError(config.status().message()));
@ -913,11 +909,10 @@ absl::Status RlsLb::ChildPolicyWrapper::MaybeFinishUpdate() {
lb_policy_->interested_parties());
}
// Send the child the updated config.
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << lb_policy_.get()
<< "] ChildPolicyWrapper=" << this << " [" << target_
<< "], updating child policy handler " << child_policy_.get();
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << lb_policy_.get() << "] ChildPolicyWrapper=" << this
<< " [" << target_ << "], updating child policy handler "
<< child_policy_.get();
UpdateArgs update_args;
update_args.config = std::move(pending_config_);
update_args.addresses = lb_policy_->addresses_;
@ -1430,9 +1425,8 @@ void RlsLb::Cache::Shutdown() {
if (cleanup_timer_handle_.has_value() &&
lb_policy_->channel_control_helper()->GetEventEngine()->Cancel(
*cleanup_timer_handle_)) {
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << lb_policy_ << "] cache cleanup timer canceled";
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << lb_policy_ << "] cache cleanup timer canceled";
}
cleanup_timer_handle_.reset();
}
@ -1468,9 +1462,8 @@ void RlsLb::Cache::StartCleanupTimer() {
}
void RlsLb::Cache::OnCleanupTimer() {
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << lb_policy_ << "] cache cleanup timer fired";
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << lb_policy_ << "] cache cleanup timer fired";
MutexLock lock(&lb_policy_->mu_);
if (!cleanup_timer_handle_.has_value()) return;
if (lb_policy_->is_shutdown_) return;
@ -1503,11 +1496,9 @@ void RlsLb::Cache::MaybeShrinkSize(size_t bytes) {
size_ -= map_it->second->Size();
map_.erase(map_it);
}
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << lb_policy_
<< "] LRU pass complete: desired size=" << bytes
<< " size=" << size_;
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << lb_policy_
<< "] LRU pass complete: desired size=" << bytes << " size=" << size_;
}
//
@ -1517,11 +1508,10 @@ void RlsLb::Cache::MaybeShrinkSize(size_t bytes) {
void RlsLb::RlsChannel::StateWatcher::OnConnectivityStateChange(
grpc_connectivity_state new_state, const absl::Status& status) {
auto* lb_policy = rls_channel_->lb_policy_.get();
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << lb_policy << "] RlsChannel=" << rls_channel_.get()
<< " StateWatcher=" << this << ": state changed to "
<< ConnectivityStateName(new_state) << " (" << status << ")";
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << lb_policy << "] RlsChannel=" << rls_channel_.get()
<< " StateWatcher=" << this << ": state changed to "
<< ConnectivityStateName(new_state) << " (" << status << ")";
if (rls_channel_->is_shutdown_) return;
MutexLock lock(&lb_policy->mu_);
if (new_state == GRPC_CHANNEL_READY && was_transient_failure_) {
@ -1614,11 +1604,10 @@ RlsLb::RlsChannel::RlsChannel(RefCountedPtr<RlsLb> lb_policy)
channel_.reset(Channel::FromC(
grpc_channel_create(lb_policy_->config_->lookup_service().c_str(),
creds.get(), args.ToC().get())));
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << lb_policy_.get() << "] RlsChannel=" << this
<< ": created channel " << channel_.get() << " for "
<< lb_policy_->config_->lookup_service();
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << lb_policy_.get() << "] RlsChannel=" << this
<< ": created channel " << channel_.get() << " for "
<< lb_policy_->config_->lookup_service();
if (channel_ != nullptr) {
// Set up channelz linkage.
channelz::ChannelNode* child_channelz_node = channel_->channelz_node();
@ -1821,11 +1810,9 @@ void RlsLb::RlsRequest::OnRlsCallCompleteLocked(grpc_error_handle error) {
grpc_call_unref(call_);
call_ = nullptr;
// Return result to cache.
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << lb_policy_.get() << "] rls_request=" << this
<< " " << key_.ToString()
<< ": response info: " << response.ToString();
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << lb_policy_.get() << "] rls_request=" << this << " "
<< key_.ToString() << ": response info: " << response.ToString();
std::vector<ChildPolicyWrapper*> child_policies_to_finish_update;
{
MutexLock lock(&lb_policy_->mu_);
@ -1940,9 +1927,7 @@ RlsLb::RlsLb(Args args)
cache_.ReportMetricsLocked(reporter);
},
Duration::Seconds(5), kMetricCacheSize, kMetricCacheEntries)) {
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << this << "] policy created";
}
GRPC_TRACE_LOG(rls_lb, INFO) << "[rlslb " << this << "] policy created";
}
bool EndpointsEqual(
@ -1967,9 +1952,7 @@ bool EndpointsEqual(
}
absl::Status RlsLb::UpdateLocked(UpdateArgs args) {
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << this << "] policy updated";
}
GRPC_TRACE_LOG(rls_lb, INFO) << "[rlslb " << this << "] policy updated";
update_in_progress_ = true;
// Swap out config.
RefCountedPtr<RlsLbConfig> old_config = std::move(config_);
@ -2002,16 +1985,14 @@ absl::Status RlsLb::UpdateLocked(UpdateArgs args) {
if (old_config == nullptr ||
config_->default_target() != old_config->default_target()) {
if (config_->default_target().empty()) {
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << this << "] unsetting default target";
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << this << "] unsetting default target";
default_child_policy_.reset();
} else {
auto it = child_policy_map_.find(config_->default_target());
if (it == child_policy_map_.end()) {
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << this << "] creating new default target";
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << this << "] creating new default target";
default_child_policy_ = MakeRefCounted<ChildPolicyWrapper>(
RefAsSubclass<RlsLb>(DEBUG_LOCATION, "ChildPolicyWrapper"),
config_->default_target());
@ -2040,9 +2021,8 @@ absl::Status RlsLb::UpdateLocked(UpdateArgs args) {
}
// Start update of child policies if needed.
if (update_child_policies) {
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << this << "] starting child policy updates";
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << this << "] starting child policy updates";
for (auto& p : child_policy_map_) {
p.second->StartUpdate();
}
@ -2055,9 +2035,8 @@ absl::Status RlsLb::UpdateLocked(UpdateArgs args) {
// Now that we've released the lock, finish update of child policies.
std::vector<std::string> errors;
if (update_child_policies) {
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << this << "] finishing child policy updates";
}
GRPC_TRACE_LOG(rls_lb, INFO)
<< "[rlslb " << this << "] finishing child policy updates";
for (auto& p : child_policy_map_) {
absl::Status status = p.second->MaybeFinishUpdate();
if (!status.ok()) {
@ -2109,9 +2088,7 @@ void RlsLb::ResetBackoffLocked() {
}
void RlsLb::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << this << "] policy shutdown";
}
GRPC_TRACE_LOG(rls_lb, INFO) << "[rlslb " << this << "] policy shutdown";
registered_metric_callback_.reset();
MutexLock lock(&mu_);
is_shutdown_ = true;
@ -2153,9 +2130,7 @@ void RlsLb::UpdatePickerLocked() {
// all children. This avoids unnecessary picker churn while an update
// is being propagated to our children.
if (update_in_progress_) return;
if (GRPC_TRACE_FLAG_ENABLED(rls_lb)) {
LOG(INFO) << "[rlslb " << this << "] updating picker";
}
GRPC_TRACE_LOG(rls_lb, INFO) << "[rlslb " << this << "] updating picker";
grpc_connectivity_state state = GRPC_CHANNEL_IDLE;
if (!child_policy_map_.empty()) {
state = GRPC_CHANNEL_TRANSIENT_FAILURE;

@ -196,11 +196,9 @@ RoundRobin::Picker::Picker(
RoundRobin::PickResult RoundRobin::Picker::Pick(PickArgs args) {
size_t index = last_picked_index_.fetch_add(1, std::memory_order_relaxed) %
pickers_.size();
if (GRPC_TRACE_FLAG_ENABLED(round_robin)) {
LOG(INFO) << "[RR " << parent_ << " picker " << this
<< "] using picker index " << index
<< ", picker=" << pickers_[index].get();
}
GRPC_TRACE_LOG(round_robin, INFO)
<< "[RR " << parent_ << " picker " << this << "] using picker index "
<< index << ", picker=" << pickers_[index].get();
return pickers_[index]->Pick(args);
}
@ -209,23 +207,18 @@ RoundRobin::PickResult RoundRobin::Picker::Pick(PickArgs args) {
//
RoundRobin::RoundRobin(Args args) : LoadBalancingPolicy(std::move(args)) {
if (GRPC_TRACE_FLAG_ENABLED(round_robin)) {
LOG(INFO) << "[RR " << this << "] Created";
}
GRPC_TRACE_LOG(round_robin, INFO) << "[RR " << this << "] Created";
}
RoundRobin::~RoundRobin() {
if (GRPC_TRACE_FLAG_ENABLED(round_robin)) {
LOG(INFO) << "[RR " << this << "] Destroying Round Robin policy";
}
GRPC_TRACE_LOG(round_robin, INFO)
<< "[RR " << this << "] Destroying Round Robin policy";
CHECK(endpoint_list_ == nullptr);
CHECK(latest_pending_endpoint_list_ == nullptr);
}
void RoundRobin::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(round_robin)) {
LOG(INFO) << "[RR " << this << "] Shutting down";
}
GRPC_TRACE_LOG(round_robin, INFO) << "[RR " << this << "] Shutting down";
shutdown_ = true;
endpoint_list_.reset();
latest_pending_endpoint_list_.reset();
@ -241,9 +234,7 @@ void RoundRobin::ResetBackoffLocked() {
absl::Status RoundRobin::UpdateLocked(UpdateArgs args) {
EndpointAddressesIterator* addresses = nullptr;
if (args.addresses.ok()) {
if (GRPC_TRACE_FLAG_ENABLED(round_robin)) {
LOG(INFO) << "[RR " << this << "] received update";
}
GRPC_TRACE_LOG(round_robin, INFO) << "[RR " << this << "] received update";
addresses = args.addresses->get();
} else {
GRPC_TRACE_LOG(round_robin, INFO)
@ -416,11 +407,10 @@ void RoundRobin::RoundRobinEndpointList::
GRPC_CHANNEL_CONNECTING, absl::Status(),
MakeRefCounted<QueuePicker>(nullptr));
} else if (num_transient_failure_ == size()) {
if (GRPC_TRACE_FLAG_ENABLED(round_robin)) {
LOG(INFO) << "[RR " << round_robin
<< "] reporting TRANSIENT_FAILURE with child list " << this
<< ": " << status_for_tf;
}
GRPC_TRACE_LOG(round_robin, INFO)
<< "[RR " << round_robin
<< "] reporting TRANSIENT_FAILURE with child list " << this << ": "
<< status_for_tf;
if (!status_for_tf.ok()) {
last_failure_ = absl::UnavailableError(
absl::StrCat("connections to all backends failing; last error: ",

@ -555,11 +555,10 @@ WeightedRoundRobin::Picker::Picker(RefCountedPtr<WeightedRoundRobin> wrr,
}
global_stats().IncrementWrrSubchannelListSize(endpoint_list->size());
global_stats().IncrementWrrSubchannelReadySize(endpoints_.size());
if (GRPC_TRACE_FLAG_ENABLED(weighted_round_robin_lb)) {
LOG(INFO) << "[WRR " << wrr_.get() << " picker " << this
<< "] created picker from endpoint_list=" << endpoint_list
<< " with " << endpoints_.size() << " subchannels";
}
GRPC_TRACE_LOG(weighted_round_robin_lb, INFO)
<< "[WRR " << wrr_.get() << " picker " << this
<< "] created picker from endpoint_list=" << endpoint_list << " with "
<< endpoints_.size() << " subchannels";
// Note: BuildSchedulerAndStartTimerLocked() passes out pointers to `this`,
// so we need to ensure that we really hold timer_mu_.
MutexLock lock(&timer_mu_);
@ -584,11 +583,9 @@ WeightedRoundRobin::PickResult WeightedRoundRobin::Picker::Pick(PickArgs args) {
size_t index = PickIndex();
CHECK(index < endpoints_.size());
auto& endpoint_info = endpoints_[index];
if (GRPC_TRACE_FLAG_ENABLED(weighted_round_robin_lb)) {
LOG(INFO) << "[WRR " << wrr_.get() << " picker " << this
<< "] returning index " << index
<< ", picker=" << endpoint_info.picker.get();
}
GRPC_TRACE_LOG(weighted_round_robin_lb, INFO)
<< "[WRR " << wrr_.get() << " picker " << this << "] returning index "
<< index << ", picker=" << endpoint_info.picker.get();
auto result = endpoint_info.picker->Pick(args);
// Collect per-call utilization data if needed.
if (!config_->enable_oob_load_report()) {
@ -665,11 +662,10 @@ void WeightedRoundRobin::Picker::BuildSchedulerAndStartTimerLocked() {
scheduler_ = std::move(scheduler);
}
// Start timer.
if (GRPC_TRACE_FLAG_ENABLED(weighted_round_robin_lb)) {
LOG(INFO) << "[WRR " << wrr_.get() << " picker " << this
<< "] scheduling timer for "
<< config_->weight_update_period().ToString();
}
GRPC_TRACE_LOG(weighted_round_robin_lb, INFO)
<< "[WRR " << wrr_.get() << " picker " << this
<< "] scheduling timer for "
<< config_->weight_update_period().ToString();
// It's insufficient to hold the implicit constructor lock here, a real lock
// over timer_mu_ is needed: we update timer_handle_ after the timer is
// scheduled, but it may run on another thread before that occurs, causing a
@ -713,17 +709,15 @@ WeightedRoundRobin::WeightedRoundRobin(Args args)
}
WeightedRoundRobin::~WeightedRoundRobin() {
if (GRPC_TRACE_FLAG_ENABLED(weighted_round_robin_lb)) {
LOG(INFO) << "[WRR " << this << "] Destroying Round Robin policy";
}
GRPC_TRACE_LOG(weighted_round_robin_lb, INFO)
<< "[WRR " << this << "] Destroying Round Robin policy";
CHECK(endpoint_list_ == nullptr);
CHECK(latest_pending_endpoint_list_ == nullptr);
}
void WeightedRoundRobin::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(weighted_round_robin_lb)) {
LOG(INFO) << "[WRR " << this << "] Shutting down";
}
GRPC_TRACE_LOG(weighted_round_robin_lb, INFO)
<< "[WRR " << this << "] Shutting down";
shutdown_ = true;
endpoint_list_.reset();
latest_pending_endpoint_list_.reset();
@ -741,9 +735,8 @@ absl::Status WeightedRoundRobin::UpdateLocked(UpdateArgs args) {
config_ = args.config.TakeAsSubclass<WeightedRoundRobinConfig>();
std::shared_ptr<EndpointAddressesIterator> addresses;
if (args.addresses.ok()) {
if (GRPC_TRACE_FLAG_ENABLED(weighted_round_robin_lb)) {
LOG(INFO) << "[WRR " << this << "] received update";
}
GRPC_TRACE_LOG(weighted_round_robin_lb, INFO)
<< "[WRR " << this << "] received update";
// Weed out duplicate endpoints. Also sort the endpoints so that if
// the set of endpoints doesn't change, their indexes in the endpoint
// list don't change, since this avoids unnecessary churn in the
@ -992,11 +985,9 @@ void WeightedRoundRobin::WrrEndpointList::
GRPC_CHANNEL_CONNECTING, absl::Status(),
MakeRefCounted<QueuePicker>(nullptr));
} else if (num_transient_failure_ == size()) {
if (GRPC_TRACE_FLAG_ENABLED(weighted_round_robin_lb)) {
LOG(INFO) << "[WRR " << wrr
<< "] reporting TRANSIENT_FAILURE with endpoint list " << this
<< ": " << status_for_tf;
}
GRPC_TRACE_LOG(weighted_round_robin_lb, INFO)
<< "[WRR " << wrr << "] reporting TRANSIENT_FAILURE with endpoint list "
<< this << ": " << status_for_tf;
if (!status_for_tf.ok()) {
last_failure_ = absl::UnavailableError(
absl::StrCat("connections to all backends failing; last error: ",

@ -284,9 +284,8 @@ WeightedTargetLb::PickResult WeightedTargetLb::WeightedPicker::Pick(
WeightedTargetLb::WeightedTargetLb(Args args)
: LoadBalancingPolicy(std::move(args)) {
if (GRPC_TRACE_FLAG_ENABLED(weighted_target_lb)) {
LOG(INFO) << "[weighted_target_lb " << this << "] created";
}
GRPC_TRACE_LOG(weighted_target_lb, INFO)
<< "[weighted_target_lb " << this << "] created";
}
WeightedTargetLb::~WeightedTargetLb() {
@ -296,9 +295,8 @@ WeightedTargetLb::~WeightedTargetLb() {
}
void WeightedTargetLb::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(weighted_target_lb)) {
LOG(INFO) << "[weighted_target_lb " << this << "] shutting down";
}
GRPC_TRACE_LOG(weighted_target_lb, INFO)
<< "[weighted_target_lb " << this << "] shutting down";
shutting_down_ = true;
targets_.clear();
}
@ -309,9 +307,8 @@ void WeightedTargetLb::ResetBackoffLocked() {
absl::Status WeightedTargetLb::UpdateLocked(UpdateArgs args) {
if (shutting_down_) return absl::OkStatus();
if (GRPC_TRACE_FLAG_ENABLED(weighted_target_lb)) {
LOG(INFO) << "[weighted_target_lb " << this << "] received update";
}
GRPC_TRACE_LOG(weighted_target_lb, INFO)
<< "[weighted_target_lb " << this << "] received update";
update_in_progress_ = true;
// Update config.
config_ = args.config.TakeAsSubclass<WeightedTargetLbConfig>();
@ -528,20 +525,16 @@ WeightedTargetLb::WeightedChild::WeightedChild(
}
WeightedTargetLb::WeightedChild::~WeightedChild() {
if (GRPC_TRACE_FLAG_ENABLED(weighted_target_lb)) {
LOG(INFO) << "[weighted_target_lb " << weighted_target_policy_.get()
<< "] WeightedChild " << this << " " << name_
<< ": destroying child";
}
GRPC_TRACE_LOG(weighted_target_lb, INFO)
<< "[weighted_target_lb " << weighted_target_policy_.get()
<< "] WeightedChild " << this << " " << name_ << ": destroying child";
weighted_target_policy_.reset(DEBUG_LOCATION, "WeightedChild");
}
void WeightedTargetLb::WeightedChild::Orphan() {
if (GRPC_TRACE_FLAG_ENABLED(weighted_target_lb)) {
LOG(INFO) << "[weighted_target_lb " << weighted_target_policy_.get()
<< "] WeightedChild " << this << " " << name_
<< ": shutting down child";
}
GRPC_TRACE_LOG(weighted_target_lb, INFO)
<< "[weighted_target_lb " << weighted_target_policy_.get()
<< "] WeightedChild " << this << " " << name_ << ": shutting down child";
// Remove the child policy's interested_parties pollset_set from the
// xDS policy.
grpc_pollset_set_del_pollset_set(
@ -566,11 +559,10 @@ WeightedTargetLb::WeightedChild::CreateChildPolicyLocked(
OrphanablePtr<LoadBalancingPolicy> lb_policy =
MakeOrphanable<ChildPolicyHandler>(std::move(lb_policy_args),
&weighted_target_lb_trace);
if (GRPC_TRACE_FLAG_ENABLED(weighted_target_lb)) {
LOG(INFO) << "[weighted_target_lb " << weighted_target_policy_.get()
<< "] WeightedChild " << this << " " << name_
<< ": created new child policy handler " << lb_policy.get();
}
GRPC_TRACE_LOG(weighted_target_lb, INFO)
<< "[weighted_target_lb " << weighted_target_policy_.get()
<< "] WeightedChild " << this << " " << name_
<< ": created new child policy handler " << lb_policy.get();
// Add the xDS's interested_parties pollset_set to that of the newly created
// child policy. This will make the child policy progress upon activity on
// xDS LB, which in turn is tied to the application's call.
@ -594,11 +586,9 @@ absl::Status WeightedTargetLb::WeightedChild::UpdateLocked(
weight_ = config.weight;
// Reactivate if needed.
if (delayed_removal_timer_ != nullptr) {
if (GRPC_TRACE_FLAG_ENABLED(weighted_target_lb)) {
LOG(INFO) << "[weighted_target_lb " << weighted_target_policy_.get()
<< "] WeightedChild " << this << " " << name_
<< ": reactivating";
}
GRPC_TRACE_LOG(weighted_target_lb, INFO)
<< "[weighted_target_lb " << weighted_target_policy_.get()
<< "] WeightedChild " << this << " " << name_ << ": reactivating";
delayed_removal_timer_.reset();
}
// Create child policy if needed.
@ -613,11 +603,10 @@ absl::Status WeightedTargetLb::WeightedChild::UpdateLocked(
update_args.resolution_note = resolution_note;
update_args.args = std::move(args);
// Update the policy.
if (GRPC_TRACE_FLAG_ENABLED(weighted_target_lb)) {
LOG(INFO) << "[weighted_target_lb " << weighted_target_policy_.get()
<< "] WeightedChild " << this << " " << name_
<< ": updating child policy handler " << child_policy_.get();
}
GRPC_TRACE_LOG(weighted_target_lb, INFO)
<< "[weighted_target_lb " << weighted_target_policy_.get()
<< "] WeightedChild " << this << " " << name_
<< ": updating child policy handler " << child_policy_.get();
return child_policy_->UpdateLocked(std::move(update_args));
}

@ -183,21 +183,16 @@ class CdsLb final : public LoadBalancingPolicy {
//
CdsLb::CdsLb(Args args) : LoadBalancingPolicy(std::move(args)) {
if (GRPC_TRACE_FLAG_ENABLED(cds_lb)) {
LOG(INFO) << "[cdslb " << this << "] created";
}
GRPC_TRACE_LOG(cds_lb, INFO) << "[cdslb " << this << "] created";
}
CdsLb::~CdsLb() {
if (GRPC_TRACE_FLAG_ENABLED(cds_lb)) {
LOG(INFO) << "[cdslb " << this << "] destroying cds LB policy";
}
GRPC_TRACE_LOG(cds_lb, INFO)
<< "[cdslb " << this << "] destroying cds LB policy";
}
void CdsLb::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(cds_lb)) {
LOG(INFO) << "[cdslb " << this << "] shutting down";
}
GRPC_TRACE_LOG(cds_lb, INFO) << "[cdslb " << this << "] shutting down";
shutting_down_ = true;
ResetState();
}
@ -280,11 +275,10 @@ class PriorityEndpointIterator final : public EndpointAddressesIterator {
absl::Status CdsLb::UpdateLocked(UpdateArgs args) {
// Get new config.
auto new_config = args.config.TakeAsSubclass<CdsLbConfig>();
if (GRPC_TRACE_FLAG_ENABLED(cds_lb)) {
LOG(INFO) << "[cdslb " << this
<< "] received update: cluster=" << new_config->cluster()
<< " is_dynamic=" << new_config->is_dynamic();
}
GRPC_TRACE_LOG(cds_lb, INFO)
<< "[cdslb " << this
<< "] received update: cluster=" << new_config->cluster()
<< " is_dynamic=" << new_config->is_dynamic();
CHECK(new_config != nullptr);
// Cluster name should never change, because we should use a different
// child name in xds_cluster_manager in that case.
@ -295,11 +289,9 @@ absl::Status CdsLb::UpdateLocked(UpdateArgs args) {
}
// Start dynamic subscription if needed.
if (new_config->is_dynamic() && subscription_ == nullptr) {
if (GRPC_TRACE_FLAG_ENABLED(cds_lb)) {
LOG(INFO) << "[cdslb " << this
<< "] obtaining dynamic subscription for cluster "
<< cluster_name_;
}
GRPC_TRACE_LOG(cds_lb, INFO)
<< "[cdslb " << this << "] obtaining dynamic subscription for cluster "
<< cluster_name_;
auto* dependency_mgr = args.args.GetObject<XdsDependencyManager>();
if (dependency_mgr == nullptr) {
// Should never happen.
@ -326,11 +318,10 @@ absl::Status CdsLb::UpdateLocked(UpdateArgs args) {
// If we are already subscribed, it's possible that we just
// recently subscribed but another update came through before we
// got the new cluster, in which case it will still be missing.
if (GRPC_TRACE_FLAG_ENABLED(cds_lb)) {
LOG(INFO) << "[cdslb " << this
<< "] xDS config has no entry for dynamic cluster "
<< cluster_name_ << ", waiting for subsequent update";
}
GRPC_TRACE_LOG(cds_lb, INFO)
<< "[cdslb " << this
<< "] xDS config has no entry for dynamic cluster " << cluster_name_
<< ", waiting for subsequent update";
// Stay in CONNECTING until we get an update that has the cluster.
return absl::OkStatus();
}
@ -452,11 +443,9 @@ absl::Status CdsLb::UpdateLocked(UpdateArgs args) {
}
grpc_pollset_set_add_pollset_set(child_policy_->interested_parties(),
interested_parties());
if (GRPC_TRACE_FLAG_ENABLED(cds_lb)) {
LOG(INFO) << "[cdslb " << this << "] created child policy "
<< (*child_config)->name() << " (" << child_policy_.get()
<< ")";
}
GRPC_TRACE_LOG(cds_lb, INFO)
<< "[cdslb " << this << "] created child policy "
<< (*child_config)->name() << " (" << child_policy_.get() << ")";
}
// Update child policy.
update_args.config = std::move(*child_config);

@ -511,9 +511,8 @@ XdsClusterImplLb::~XdsClusterImplLb() {
}
void XdsClusterImplLb::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(xds_cluster_impl_lb)) {
LOG(INFO) << "[xds_cluster_impl_lb " << this << "] shutting down";
}
GRPC_TRACE_LOG(xds_cluster_impl_lb, INFO)
<< "[xds_cluster_impl_lb " << this << "] shutting down";
shutting_down_ = true;
ResetState();
xds_client_.reset(DEBUG_LOCATION, "XdsClusterImpl");
@ -560,9 +559,8 @@ std::string GetEdsResourceName(const XdsClusterResource& cluster_resource) {
}
absl::Status XdsClusterImplLb::UpdateLocked(UpdateArgs args) {
if (GRPC_TRACE_FLAG_ENABLED(xds_cluster_impl_lb)) {
LOG(INFO) << "[xds_cluster_impl_lb " << this << "] Received update";
}
GRPC_TRACE_LOG(xds_cluster_impl_lb, INFO)
<< "[xds_cluster_impl_lb " << this << "] Received update";
// Grab new LB policy config.
auto new_config = args.config.TakeAsSubclass<XdsClusterImplLbConfig>();
// Cluster name should never change, because the cds policy will assign a
@ -732,11 +730,10 @@ void XdsClusterImplLb::MaybeUpdatePickerLocked() {
// whether) the child has reported.
if (drop_config_ != nullptr && drop_config_->drop_all()) {
auto drop_picker = MakeRefCounted<Picker>(this, picker_);
if (GRPC_TRACE_FLAG_ENABLED(xds_cluster_impl_lb)) {
LOG(INFO) << "[xds_cluster_impl_lb " << this
<< "] updating connectivity (drop all): state=READY picker="
<< drop_picker.get();
}
GRPC_TRACE_LOG(xds_cluster_impl_lb, INFO)
<< "[xds_cluster_impl_lb " << this
<< "] updating connectivity (drop all): state=READY picker="
<< drop_picker.get();
channel_control_helper()->UpdateState(GRPC_CHANNEL_READY, absl::Status(),
std::move(drop_picker));
return;

@ -255,9 +255,8 @@ XdsClusterManagerLb::~XdsClusterManagerLb() {
}
void XdsClusterManagerLb::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(xds_cluster_manager_lb)) {
LOG(INFO) << "[xds_cluster_manager_lb " << this << "] shutting down";
}
GRPC_TRACE_LOG(xds_cluster_manager_lb, INFO)
<< "[xds_cluster_manager_lb " << this << "] shutting down";
shutting_down_ = true;
children_.clear();
}
@ -272,9 +271,8 @@ void XdsClusterManagerLb::ResetBackoffLocked() {
absl::Status XdsClusterManagerLb::UpdateLocked(UpdateArgs args) {
if (shutting_down_) return absl::OkStatus();
if (GRPC_TRACE_FLAG_ENABLED(xds_cluster_manager_lb)) {
LOG(INFO) << "[xds_cluster_manager_lb " << this << "] Received update";
}
GRPC_TRACE_LOG(xds_cluster_manager_lb, INFO)
<< "[xds_cluster_manager_lb " << this << "] Received update";
update_in_progress_ = true;
// Update config.
config_ = args.config.TakeAsSubclass<XdsClusterManagerLbConfig>();
@ -365,22 +363,18 @@ void XdsClusterManagerLb::UpdateStateLocked() {
} else {
connectivity_state = GRPC_CHANNEL_TRANSIENT_FAILURE;
}
if (GRPC_TRACE_FLAG_ENABLED(xds_cluster_manager_lb)) {
LOG(INFO) << "[xds_cluster_manager_lb " << this
<< "] connectivity changed to "
<< ConnectivityStateName(connectivity_state);
}
GRPC_TRACE_LOG(xds_cluster_manager_lb, INFO)
<< "[xds_cluster_manager_lb " << this << "] connectivity changed to "
<< ConnectivityStateName(connectivity_state);
ClusterPicker::ClusterMap cluster_map;
for (const auto& p : config_->cluster_map()) {
const std::string& cluster_name = p.first;
RefCountedPtr<SubchannelPicker>& child_picker = cluster_map[cluster_name];
child_picker = children_[cluster_name]->picker();
if (child_picker == nullptr) {
if (GRPC_TRACE_FLAG_ENABLED(xds_cluster_manager_lb)) {
LOG(INFO) << "[xds_cluster_manager_lb " << this << "] child "
<< cluster_name
<< " has not yet returned a picker; creating a QueuePicker.";
}
GRPC_TRACE_LOG(xds_cluster_manager_lb, INFO)
<< "[xds_cluster_manager_lb " << this << "] child " << cluster_name
<< " has not yet returned a picker; creating a QueuePicker.";
child_picker =
MakeRefCounted<QueuePicker>(Ref(DEBUG_LOCATION, "QueuePicker"));
}
@ -418,11 +412,9 @@ XdsClusterManagerLb::ClusterChild::~ClusterChild() {
}
void XdsClusterManagerLb::ClusterChild::Orphan() {
if (GRPC_TRACE_FLAG_ENABLED(xds_cluster_manager_lb)) {
LOG(INFO) << "[xds_cluster_manager_lb " << xds_cluster_manager_policy_.get()
<< "] ClusterChild " << this << " " << name_
<< ": shutting down child";
}
GRPC_TRACE_LOG(xds_cluster_manager_lb, INFO)
<< "[xds_cluster_manager_lb " << xds_cluster_manager_policy_.get()
<< "] ClusterChild " << this << " " << name_ << ": shutting down child";
// Remove the child policy's interested_parties pollset_set from the
// xDS policy.
grpc_pollset_set_del_pollset_set(
@ -453,11 +445,10 @@ XdsClusterManagerLb::ClusterChild::CreateChildPolicyLocked(
OrphanablePtr<LoadBalancingPolicy> lb_policy =
MakeOrphanable<ChildPolicyHandler>(std::move(lb_policy_args),
&xds_cluster_manager_lb_trace);
if (GRPC_TRACE_FLAG_ENABLED(xds_cluster_manager_lb)) {
LOG(INFO) << "[xds_cluster_manager_lb " << xds_cluster_manager_policy_.get()
<< "] ClusterChild " << this << " " << name_
<< ": Created new child policy handler " << lb_policy.get();
}
GRPC_TRACE_LOG(xds_cluster_manager_lb, INFO)
<< "[xds_cluster_manager_lb " << xds_cluster_manager_policy_.get()
<< "] ClusterChild " << this << " " << name_
<< ": Created new child policy handler " << lb_policy.get();
// Add the xDS's interested_parties pollset_set to that of the newly created
// child policy. This will make the child policy progress upon activity on
// xDS LB, which in turn is tied to the application's call.
@ -490,11 +481,10 @@ absl::Status XdsClusterManagerLb::ClusterChild::UpdateLocked(
update_args.addresses = addresses;
update_args.args = args;
// Update the policy.
if (GRPC_TRACE_FLAG_ENABLED(xds_cluster_manager_lb)) {
LOG(INFO) << "[xds_cluster_manager_lb " << xds_cluster_manager_policy_.get()
<< "] ClusterChild " << this << " " << name_
<< ": Updating child policy handler " << child_policy_.get();
}
GRPC_TRACE_LOG(xds_cluster_manager_lb, INFO)
<< "[xds_cluster_manager_lb " << xds_cluster_manager_policy_.get()
<< "] ClusterChild " << this << " " << name_
<< ": Updating child policy handler " << child_policy_.get();
return child_policy_->UpdateLocked(std::move(update_args));
}

@ -486,18 +486,15 @@ XdsOverrideHostLb::Picker::PickOverridenHost(
if (it == policy_->subchannel_map_.end()) continue;
if (!override_host_health_status_set_.Contains(
it->second->eds_health_status())) {
if (GRPC_TRACE_FLAG_ENABLED(xds_override_host_lb)) {
LOG(INFO) << "Subchannel " << address
<< " health status is not overridden ("
<< it->second->eds_health_status().ToString() << ")";
}
GRPC_TRACE_LOG(xds_override_host_lb, INFO)
<< "Subchannel " << address << " health status is not overridden ("
<< it->second->eds_health_status().ToString() << ")";
continue;
}
auto subchannel = it->second->GetSubchannelRef();
if (subchannel == nullptr) {
if (GRPC_TRACE_FLAG_ENABLED(xds_override_host_lb)) {
LOG(INFO) << "No subchannel for " << address;
}
GRPC_TRACE_LOG(xds_override_host_lb, INFO)
<< "No subchannel for " << address;
if (address_with_no_subchannel.empty()) {
address_with_no_subchannel = it->first;
}
@ -507,9 +504,8 @@ XdsOverrideHostLb::Picker::PickOverridenHost(
if (connectivity_state == GRPC_CHANNEL_READY) {
// Found a READY subchannel. Pass back the actual address list
// and return the subchannel.
if (GRPC_TRACE_FLAG_ENABLED(xds_override_host_lb)) {
LOG(INFO) << "Picker override found READY subchannel " << address;
}
GRPC_TRACE_LOG(xds_override_host_lb, INFO)
<< "Picker override found READY subchannel " << address;
it->second->set_last_used_time();
override_host_attr->set_actual_address_list(it->second->address_list());
return PickResult::Complete(subchannel->wrapped_subchannel());
@ -523,9 +519,8 @@ XdsOverrideHostLb::Picker::PickOverridenHost(
// No READY subchannel found. If we found an IDLE subchannel, trigger
// a connection attempt and queue the pick until that attempt completes.
if (idle_subchannel != nullptr) {
if (GRPC_TRACE_FLAG_ENABLED(xds_override_host_lb)) {
LOG(INFO) << "Picker override found IDLE subchannel";
}
GRPC_TRACE_LOG(xds_override_host_lb, INFO)
<< "Picker override found IDLE subchannel";
// Deletes itself after the connection is requested.
new SubchannelConnectionRequester(std::move(idle_subchannel));
return PickResult::Queue();
@ -533,18 +528,16 @@ XdsOverrideHostLb::Picker::PickOverridenHost(
// No READY or IDLE subchannels. If we found a CONNECTING subchannel,
// queue the pick and wait for the connection attempt to complete.
if (found_connecting) {
if (GRPC_TRACE_FLAG_ENABLED(xds_override_host_lb)) {
LOG(INFO) << "Picker override found CONNECTING subchannel";
}
GRPC_TRACE_LOG(xds_override_host_lb, INFO)
<< "Picker override found CONNECTING subchannel";
return PickResult::Queue();
}
// No READY, IDLE, or CONNECTING subchannels found. If we found an
// entry that has no subchannel, then queue the pick and trigger
// creation of a subchannel for that entry.
if (!address_with_no_subchannel.empty()) {
if (GRPC_TRACE_FLAG_ENABLED(xds_override_host_lb)) {
LOG(INFO) << "Picker override found entry with no subchannel";
}
GRPC_TRACE_LOG(xds_override_host_lb, INFO)
<< "Picker override found entry with no subchannel";
if (!IsWorkSerializerDispatchEnabled()) {
new SubchannelCreationRequester(policy_, address_with_no_subchannel);
} else {
@ -645,9 +638,8 @@ void XdsOverrideHostLb::IdleTimer::OnTimerLocked() {
XdsOverrideHostLb::XdsOverrideHostLb(Args args)
: LoadBalancingPolicy(std::move(args)) {
if (GRPC_TRACE_FLAG_ENABLED(xds_override_host_lb)) {
LOG(INFO) << "[xds_override_host_lb " << this << "] created";
}
GRPC_TRACE_LOG(xds_override_host_lb, INFO)
<< "[xds_override_host_lb " << this << "] created";
}
XdsOverrideHostLb::~XdsOverrideHostLb() {
@ -657,9 +649,8 @@ XdsOverrideHostLb::~XdsOverrideHostLb() {
}
void XdsOverrideHostLb::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(xds_override_host_lb)) {
LOG(INFO) << "[xds_override_host_lb " << this << "] shutting down";
}
GRPC_TRACE_LOG(xds_override_host_lb, INFO)
<< "[xds_override_host_lb " << this << "] shutting down";
shutting_down_ = true;
ResetState();
}
@ -726,11 +717,9 @@ class ChildEndpointIterator final : public EndpointAddressesIterator {
parent_it_->ForEach([&](const EndpointAddresses& endpoint) {
XdsHealthStatus status = GetEndpointHealthStatus(endpoint);
if (status.status() != XdsHealthStatus::kDraining) {
if (GRPC_TRACE_FLAG_ENABLED(xds_override_host_lb)) {
LOG(INFO) << "[xds_override_host_lb " << this << "] endpoint "
<< endpoint.ToString()
<< ": not draining, passing to child";
}
GRPC_TRACE_LOG(xds_override_host_lb, INFO)
<< "[xds_override_host_lb " << this << "] endpoint "
<< endpoint.ToString() << ": not draining, passing to child";
callback(endpoint);
}
});
@ -741,9 +730,8 @@ class ChildEndpointIterator final : public EndpointAddressesIterator {
};
absl::Status XdsOverrideHostLb::UpdateLocked(UpdateArgs args) {
if (GRPC_TRACE_FLAG_ENABLED(xds_override_host_lb)) {
LOG(INFO) << "[xds_override_host_lb " << this << "] Received update";
}
GRPC_TRACE_LOG(xds_override_host_lb, INFO)
<< "[xds_override_host_lb " << this << "] Received update";
// Grab new LB policy config.
if (args.config == nullptr) {
return absl::InvalidArgumentError("Missing policy config");

@ -136,15 +136,13 @@ XdsWrrLocalityLb::XdsWrrLocalityLb(Args args)
: LoadBalancingPolicy(std::move(args)) {}
XdsWrrLocalityLb::~XdsWrrLocalityLb() {
if (GRPC_TRACE_FLAG_ENABLED(xds_wrr_locality_lb)) {
LOG(INFO) << "[xds_wrr_locality_lb " << this << "] destroying";
}
GRPC_TRACE_LOG(xds_wrr_locality_lb, INFO)
<< "[xds_wrr_locality_lb " << this << "] destroying";
}
void XdsWrrLocalityLb::ShutdownLocked() {
if (GRPC_TRACE_FLAG_ENABLED(xds_wrr_locality_lb)) {
LOG(INFO) << "[xds_wrr_locality_lb " << this << "] shutting down";
}
GRPC_TRACE_LOG(xds_wrr_locality_lb, INFO)
<< "[xds_wrr_locality_lb " << this << "] shutting down";
if (child_policy_ != nullptr) {
grpc_pollset_set_del_pollset_set(child_policy_->interested_parties(),
interested_parties());
@ -161,9 +159,8 @@ void XdsWrrLocalityLb::ResetBackoffLocked() {
}
absl::Status XdsWrrLocalityLb::UpdateLocked(UpdateArgs args) {
if (GRPC_TRACE_FLAG_ENABLED(xds_wrr_locality_lb)) {
LOG(INFO) << "[xds_wrr_locality_lb " << this << "] Received update";
}
GRPC_TRACE_LOG(xds_wrr_locality_lb, INFO)
<< "[xds_wrr_locality_lb " << this << "] Received update";
auto config = args.config.TakeAsSubclass<XdsWrrLocalityLbConfig>();
// Scan the addresses to find the weight for each locality.
std::map<RefCountedStringValue, uint32_t> locality_weights;
@ -203,11 +200,9 @@ absl::Status XdsWrrLocalityLb::UpdateLocked(UpdateArgs args) {
})},
}),
});
if (GRPC_TRACE_FLAG_ENABLED(xds_wrr_locality_lb)) {
LOG(INFO) << "[xds_wrr_locality_lb " << this
<< "] generated child policy config: "
<< JsonDump(child_config_json, /*indent=*/1);
}
GRPC_TRACE_LOG(xds_wrr_locality_lb, INFO)
<< "[xds_wrr_locality_lb " << this << "] generated child policy config: "
<< JsonDump(child_config_json, /*indent=*/1);
// Parse config.
auto child_config =
CoreConfiguration::Get().lb_policy_registry().ParseLoadBalancingConfig(

Loading…
Cancel
Save