From 0b27e2862da2da952d5073b333ba9a8b9c999c4a Mon Sep 17 00:00:00 2001 From: ZHANG Dapeng Date: Thu, 13 Jun 2019 15:43:53 -0700 Subject: [PATCH] xds: let ChannelLogger log more useful information --- .../java/io/grpc/xds/InterLocalityPicker.java | 17 +++++++++++++++++ .../main/java/io/grpc/xds/LocalityStore.java | 19 ++++++++++++++++--- xds/src/main/java/io/grpc/xds/XdsComms.java | 10 ++++++++-- xds/src/main/java/io/grpc/xds/XdsLbState.java | 1 + .../java/io/grpc/xds/XdsLoadBalancer.java | 9 ++++++++- .../test/java/io/grpc/xds/XdsCommsTest.java | 3 +++ 6 files changed, 53 insertions(+), 6 deletions(-) diff --git a/xds/src/main/java/io/grpc/xds/InterLocalityPicker.java b/xds/src/main/java/io/grpc/xds/InterLocalityPicker.java index 48523415fe..48f9bb19eb 100644 --- a/xds/src/main/java/io/grpc/xds/InterLocalityPicker.java +++ b/xds/src/main/java/io/grpc/xds/InterLocalityPicker.java @@ -20,6 +20,7 @@ import static com.google.common.base.Preconditions.checkArgument; import static com.google.common.base.Preconditions.checkNotNull; import com.google.common.annotations.VisibleForTesting; +import com.google.common.base.MoreObjects; import com.google.common.collect.ImmutableList; import io.grpc.LoadBalancer.PickResult; import io.grpc.LoadBalancer.PickSubchannelArgs; @@ -51,6 +52,14 @@ final class InterLocalityPicker extends SubchannelPicker { SubchannelPicker getPicker() { return childPicker; } + + @Override + public String toString() { + return MoreObjects.toStringHelper(this) + .add("weight", weight) + .add("childPicker", childPicker) + .toString(); + } } InterLocalityPicker(List weightedChildPickers) { @@ -99,4 +108,12 @@ final class InterLocalityPicker extends SubchannelPicker { return childPicker.pickSubchannel(args); } + + @Override + public String toString() { + return MoreObjects.toStringHelper(this) + .add("weightedChildPickers", weightedChildPickers) + .add("totalWeight", totalWeight) + .toString(); + } } diff --git a/xds/src/main/java/io/grpc/xds/LocalityStore.java b/xds/src/main/java/io/grpc/xds/LocalityStore.java index 745652859b..878fb78103 100644 --- a/xds/src/main/java/io/grpc/xds/LocalityStore.java +++ b/xds/src/main/java/io/grpc/xds/LocalityStore.java @@ -26,7 +26,6 @@ import static io.grpc.ConnectivityState.TRANSIENT_FAILURE; import com.google.common.annotations.VisibleForTesting; import com.google.common.base.MoreObjects; import com.google.common.collect.ImmutableList; -import io.grpc.ChannelLogger.ChannelLogLevel; import io.grpc.ConnectivityState; import io.grpc.ConnectivityStateInfo; import io.grpc.EquivalentAddressGroup; @@ -135,6 +134,14 @@ interface LocalityStore { } return delegate.pickSubchannel(args); } + + @Override + public String toString() { + return MoreObjects.toStringHelper(this) + .add("dropOverloads", dropOverloads) + .add("delegate", delegate) + .toString(); + } } private static final PickerFactory pickerFactoryImpl = @@ -324,8 +331,6 @@ interface LocalityStore { } if (state != null) { - helper.getChannelLogger().log( - ChannelLogLevel.INFO, "Picker updated - state: {0}, picker: {1}", state, picker); helper.updateBalancingState(state, picker); } } @@ -385,6 +390,14 @@ interface LocalityStore { public PickResult pickSubchannel(PickSubchannelArgs args) { return statsStore.interceptPickResult(delegate.pickSubchannel(args), locality); } + + @Override + public String toString() { + return MoreObjects.toStringHelper(this) + .add("delegate", delegate) + .add("locality", locality) + .toString(); + } } currentChildState = newState; diff --git a/xds/src/main/java/io/grpc/xds/XdsComms.java b/xds/src/main/java/io/grpc/xds/XdsComms.java index 37be630e9d..5a8db8efa6 100644 --- a/xds/src/main/java/io/grpc/xds/XdsComms.java +++ b/xds/src/main/java/io/grpc/xds/XdsComms.java @@ -36,6 +36,7 @@ import io.envoyproxy.envoy.api.v2.endpoint.LocalityLbEndpoints; import io.envoyproxy.envoy.service.discovery.v2.AggregatedDiscoveryServiceGrpc; import io.envoyproxy.envoy.type.FractionalPercent; import io.envoyproxy.envoy.type.FractionalPercent.DenominatorType; +import io.grpc.ChannelLogger.ChannelLogLevel; import io.grpc.EquivalentAddressGroup; import io.grpc.LoadBalancer.Helper; import io.grpc.ManagedChannel; @@ -195,6 +196,9 @@ final class XdsComms { return; } + helper.getChannelLogger().log( + ChannelLogLevel.DEBUG, + "Received an EDS response: {0}", clusterLoadAssignment); if (!firstEdsResponseReceived) { firstEdsResponseReceived = true; adsStreamCallback.onWorking(); @@ -277,7 +281,7 @@ final class XdsComms { this.localityStore = localityStore; // Assuming standard mode, and send EDS request only - xdsRequestWriter.onNext( + DiscoveryRequest edsRequest = DiscoveryRequest.newBuilder() .setNode(Node.newBuilder() .setMetadata(Struct.newBuilder() @@ -288,7 +292,9 @@ final class XdsComms { .putFields( "endpoints_required", Value.newBuilder().setBoolValue(true).build()))) - .setTypeUrl(EDS_TYPE_URL).build()); + .setTypeUrl(EDS_TYPE_URL).build(); + helper.getChannelLogger().log(ChannelLogLevel.DEBUG, "Sending EDS request {0}", edsRequest); + xdsRequestWriter.onNext(edsRequest); } AdsStream(AdsStream adsStream) { diff --git a/xds/src/main/java/io/grpc/xds/XdsLbState.java b/xds/src/main/java/io/grpc/xds/XdsLbState.java index 67c8df976f..7fe3739399 100644 --- a/xds/src/main/java/io/grpc/xds/XdsLbState.java +++ b/xds/src/main/java/io/grpc/xds/XdsLbState.java @@ -81,6 +81,7 @@ class XdsLbState { if (xdsComms != null) { xdsComms.refreshAdsStream(); } else { + // TODO(zdapeng): pass a helper that has the right ChannelLogger for the oobChannel xdsComms = new XdsComms(channel, helper, adsStreamCallback, localityStore); } diff --git a/xds/src/main/java/io/grpc/xds/XdsLoadBalancer.java b/xds/src/main/java/io/grpc/xds/XdsLoadBalancer.java index 8496c60c9b..5f55306429 100644 --- a/xds/src/main/java/io/grpc/xds/XdsLoadBalancer.java +++ b/xds/src/main/java/io/grpc/xds/XdsLoadBalancer.java @@ -158,6 +158,8 @@ final class XdsLoadBalancer extends LoadBalancer { } if (!fallbackManager.isInFallbackMode()) { + delegate.getChannelLogger().log( + ChannelLogLevel.INFO, "Picker updated - state: {0}, picker: {1}", newState, newPicker); delegate.updateBalancingState(newState, newPicker); } } @@ -349,6 +351,8 @@ final class XdsLoadBalancer extends LoadBalancer { void cancelFallback() { cancelFallbackTimer(); if (fallbackBalancer != null) { + helper.getChannelLogger().log( + ChannelLogLevel.INFO, "Shutting down XDS fallback balancer"); fallbackBalancer.shutdown(); fallbackBalancer = null; } @@ -362,7 +366,7 @@ final class XdsLoadBalancer extends LoadBalancer { cancelFallbackTimer(); helper.getChannelLogger().log( - ChannelLogLevel.INFO, "Using fallback policy"); + ChannelLogLevel.INFO, "Using XDS fallback policy"); final class FallbackBalancerHelper extends ForwardingLoadBalancerHelper { LoadBalancer balancer; @@ -374,6 +378,9 @@ final class XdsLoadBalancer extends LoadBalancer { // ignore updates from a misbehaving shutdown fallback balancer return; } + helper.getChannelLogger().log( + ChannelLogLevel.INFO, + "Picker updated - state: {0}, picker: {1}", newState, newPicker); super.updateBalancingState(newState, newPicker); } diff --git a/xds/src/test/java/io/grpc/xds/XdsCommsTest.java b/xds/src/test/java/io/grpc/xds/XdsCommsTest.java index c89d8abdc6..04a9accb8b 100644 --- a/xds/src/test/java/io/grpc/xds/XdsCommsTest.java +++ b/xds/src/test/java/io/grpc/xds/XdsCommsTest.java @@ -22,6 +22,7 @@ import static org.junit.Assert.assertFalse; import static org.junit.Assert.assertTrue; import static org.mockito.Mockito.doReturn; import static org.mockito.Mockito.inOrder; +import static org.mockito.Mockito.mock; import static org.mockito.Mockito.never; import static org.mockito.Mockito.times; import static org.mockito.Mockito.verify; @@ -43,6 +44,7 @@ import io.envoyproxy.envoy.api.v2.endpoint.LocalityLbEndpoints; import io.envoyproxy.envoy.service.discovery.v2.AggregatedDiscoveryServiceGrpc.AggregatedDiscoveryServiceImplBase; import io.envoyproxy.envoy.type.FractionalPercent; import io.envoyproxy.envoy.type.FractionalPercent.DenominatorType; +import io.grpc.ChannelLogger; import io.grpc.LoadBalancer; import io.grpc.LoadBalancer.Helper; import io.grpc.LoadBalancerProvider; @@ -146,6 +148,7 @@ public class XdsCommsTest { cleanupRule.register(InProcessChannelBuilder.forName(serverName).directExecutor().build()); doReturn("fake_authority").when(helper).getAuthority(); doReturn(syncContext).when(helper).getSynchronizationContext(); + doReturn(mock(ChannelLogger.class)).when(helper).getChannelLogger(); lbRegistry.register(new LoadBalancerProvider() { @Override public boolean isAvailable() {