From 67d6600f71ff81ac8c2c87dd850460d5e783491a Mon Sep 17 00:00:00 2001 From: Sergey Matyukevich Date: Tue, 14 Feb 2023 14:27:21 -0700 Subject: [PATCH] core: add logger to OutlierDetectionLoadBalancer (#9880) --- .../util/OutlierDetectionLoadBalancer.java | 60 ++++++++++++++++--- ...lierDetectionLoadBalancerProviderTest.java | 4 ++ .../OutlierDetectionLoadBalancerTest.java | 5 ++ 3 files changed, 61 insertions(+), 8 deletions(-) diff --git a/core/src/main/java/io/grpc/util/OutlierDetectionLoadBalancer.java b/core/src/main/java/io/grpc/util/OutlierDetectionLoadBalancer.java index 4f74fbff44..a1a4b4be28 100644 --- a/core/src/main/java/io/grpc/util/OutlierDetectionLoadBalancer.java +++ b/core/src/main/java/io/grpc/util/OutlierDetectionLoadBalancer.java @@ -26,6 +26,8 @@ import com.google.common.collect.ForwardingMap; import com.google.common.collect.ImmutableList; import com.google.common.collect.ImmutableSet; import io.grpc.Attributes; +import io.grpc.ChannelLogger; +import io.grpc.ChannelLogger.ChannelLogLevel; import io.grpc.ClientStreamTracer; import io.grpc.ClientStreamTracer.StreamInfo; import io.grpc.ConnectivityState; @@ -73,6 +75,8 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { private ScheduledHandle detectionTimerHandle; private Long detectionTimerStartNanos; + private final ChannelLogger logger; + private static final Attributes.Key ADDRESS_TRACKER_ATTR_KEY = Attributes.Key.create("addressTrackerKey"); @@ -80,16 +84,19 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { * Creates a new instance of {@link OutlierDetectionLoadBalancer}. */ public OutlierDetectionLoadBalancer(Helper helper, TimeProvider timeProvider) { + logger = helper.getChannelLogger(); childHelper = new ChildHelper(checkNotNull(helper, "helper")); switchLb = new GracefulSwitchLoadBalancer(childHelper); trackerMap = new AddressTrackerMap(); this.syncContext = checkNotNull(helper.getSynchronizationContext(), "syncContext"); this.timeService = checkNotNull(helper.getScheduledExecutorService(), "timeService"); this.timeProvider = timeProvider; + logger.log(ChannelLogLevel.DEBUG, "OutlierDetection lb created."); } @Override public boolean acceptResolvedAddresses(ResolvedAddresses resolvedAddresses) { + logger.log(ChannelLogLevel.DEBUG, "Received resolution result: {0}", resolvedAddresses); OutlierDetectionLoadBalancerConfig config = (OutlierDetectionLoadBalancerConfig) resolvedAddresses.getLoadBalancingPolicyConfig(); @@ -129,7 +136,7 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { trackerMap.resetCallCounters(); } - detectionTimerHandle = syncContext.scheduleWithFixedDelay(new DetectionTimer(config), + detectionTimerHandle = syncContext.scheduleWithFixedDelay(new DetectionTimer(config, logger), initialDelayNanos, config.intervalNanos, NANOSECONDS, timeService); } else if (detectionTimerHandle != null) { // Outlier detection is not configured, but we have a lingering timer. Let's cancel it and @@ -162,9 +169,11 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { class DetectionTimer implements Runnable { OutlierDetectionLoadBalancerConfig config; + ChannelLogger logger; - DetectionTimer(OutlierDetectionLoadBalancerConfig config) { + DetectionTimer(OutlierDetectionLoadBalancerConfig config, ChannelLogger logger) { this.config = config; + this.logger = logger; } @Override @@ -173,7 +182,7 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { trackerMap.swapCounters(); - for (OutlierEjectionAlgorithm algo : OutlierEjectionAlgorithm.forConfig(config)) { + for (OutlierEjectionAlgorithm algo : OutlierEjectionAlgorithm.forConfig(config, logger)) { algo.ejectOutliers(trackerMap, detectionTimerStartNanos); } @@ -235,9 +244,11 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { private boolean ejected; private ConnectivityStateInfo lastSubchannelState; private SubchannelStateListener subchannelStateListener; + private final ChannelLogger logger; OutlierDetectionSubchannel(Subchannel delegate) { this.delegate = delegate; + this.logger = delegate.getChannelLogger(); } @Override @@ -316,12 +327,14 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { ejected = true; subchannelStateListener.onSubchannelState( ConnectivityStateInfo.forTransientFailure(Status.UNAVAILABLE)); + logger.log(ChannelLogLevel.INFO, "Subchannel ejected: {0}", this); } void uneject() { ejected = false; if (lastSubchannelState != null) { subchannelStateListener.onSubchannelState(lastSubchannelState); + logger.log(ChannelLogLevel.INFO, "Subchannel unejected: {0}", this); } } @@ -353,6 +366,13 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { } } } + + @Override + public String toString() { + return "OutlierDetectionSubchannel{" + + "addresses=" + delegate.getAllAddresses() + + '}'; + } } @@ -576,6 +596,13 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { failureCount.set(0); } } + + @Override + public String toString() { + return "AddressTracker{" + + "subchannels=" + subchannels + + '}'; + } } /** @@ -684,13 +711,14 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { /** Builds a list of algorithms that are enabled in the given config. */ @Nullable - static List forConfig(OutlierDetectionLoadBalancerConfig config) { + static List forConfig(OutlierDetectionLoadBalancerConfig config, + ChannelLogger logger) { ImmutableList.Builder algoListBuilder = ImmutableList.builder(); if (config.successRateEjection != null) { - algoListBuilder.add(new SuccessRateOutlierEjectionAlgorithm(config)); + algoListBuilder.add(new SuccessRateOutlierEjectionAlgorithm(config, logger)); } if (config.failurePercentageEjection != null) { - algoListBuilder.add(new FailurePercentageOutlierEjectionAlgorithm(config)); + algoListBuilder.add(new FailurePercentageOutlierEjectionAlgorithm(config, logger)); } return algoListBuilder.build(); } @@ -705,9 +733,13 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { private final OutlierDetectionLoadBalancerConfig config; - SuccessRateOutlierEjectionAlgorithm(OutlierDetectionLoadBalancerConfig config) { + private final ChannelLogger logger; + + SuccessRateOutlierEjectionAlgorithm(OutlierDetectionLoadBalancerConfig config, + ChannelLogger logger) { checkArgument(config.successRateEjection != null, "success rate ejection config is null"); this.config = config; + this.logger = logger; } @Override @@ -744,6 +776,11 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { // If success rate is below the threshold, eject the address. if (tracker.successRate() < requiredSuccessRate) { + logger.log(ChannelLogLevel.DEBUG, + "SuccessRate algorithm detected outlier: {0}. " + + "Parameters: successRate={1}, mean={2}, stdev={3}, " + + "requiredSuccessRate={4}", + tracker, tracker.successRate(), mean, stdev, requiredSuccessRate); // Only eject some addresses based on the enforcement percentage. if (new Random().nextInt(100) < config.successRateEjection.enforcementPercentage) { tracker.ejectSubchannels(ejectionTimeNanos); @@ -781,8 +818,12 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { private final OutlierDetectionLoadBalancerConfig config; - FailurePercentageOutlierEjectionAlgorithm(OutlierDetectionLoadBalancerConfig config) { + private final ChannelLogger logger; + + FailurePercentageOutlierEjectionAlgorithm(OutlierDetectionLoadBalancerConfig config, + ChannelLogger logger) { this.config = config; + this.logger = logger; } @Override @@ -814,6 +855,9 @@ public final class OutlierDetectionLoadBalancer extends LoadBalancer { // If the failure rate is above the threshold, we should eject... double maxFailureRate = ((double)config.failurePercentageEjection.threshold) / 100; if (tracker.failureRate() > maxFailureRate) { + logger.log(ChannelLogLevel.DEBUG, + "FailurePercentage algorithm detected outlier: {0}, failureRate={1}", + tracker, tracker.failureRate()); // ...but only enforce this based on the enforcement percentage. if (new Random().nextInt(100) < config.failurePercentageEjection.enforcementPercentage) { tracker.ejectSubchannels(ejectionTimeNanos); diff --git a/core/src/test/java/io/grpc/util/OutlierDetectionLoadBalancerProviderTest.java b/core/src/test/java/io/grpc/util/OutlierDetectionLoadBalancerProviderTest.java index 5a27e6f176..cf162ffaec 100644 --- a/core/src/test/java/io/grpc/util/OutlierDetectionLoadBalancerProviderTest.java +++ b/core/src/test/java/io/grpc/util/OutlierDetectionLoadBalancerProviderTest.java @@ -21,6 +21,7 @@ import static org.junit.Assert.fail; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.when; +import io.grpc.ChannelLogger; import io.grpc.InternalServiceProviders; import io.grpc.LoadBalancer.Helper; import io.grpc.LoadBalancerProvider; @@ -66,6 +67,9 @@ public class OutlierDetectionLoadBalancerProviderTest { @Test public void providesLoadBalancer() { Helper helper = mock(Helper.class); + ChannelLogger channelLogger = mock(ChannelLogger.class); + + when(helper.getChannelLogger()).thenReturn(channelLogger); when(helper.getSynchronizationContext()).thenReturn(syncContext); when(helper.getScheduledExecutorService()).thenReturn(mock(ScheduledExecutorService.class)); assertThat(provider.newLoadBalancer(helper)) diff --git a/core/src/test/java/io/grpc/util/OutlierDetectionLoadBalancerTest.java b/core/src/test/java/io/grpc/util/OutlierDetectionLoadBalancerTest.java index ccf3d40cdb..18f9bbf549 100644 --- a/core/src/test/java/io/grpc/util/OutlierDetectionLoadBalancerTest.java +++ b/core/src/test/java/io/grpc/util/OutlierDetectionLoadBalancerTest.java @@ -31,6 +31,7 @@ import com.google.common.collect.ImmutableMap; import com.google.common.collect.ImmutableSet; import com.google.common.collect.Lists; import com.google.common.collect.Maps; +import io.grpc.ChannelLogger; import io.grpc.ClientStreamTracer; import io.grpc.ConnectivityState; import io.grpc.ConnectivityStateInfo; @@ -165,6 +166,9 @@ public class OutlierDetectionLoadBalancerTest { subchannel4 = subchannelIterator.next(); subchannel5 = subchannelIterator.next(); + ChannelLogger channelLogger = mock(ChannelLogger.class); + + when(mockHelper.getChannelLogger()).thenReturn(channelLogger); when(mockHelper.getSynchronizationContext()).thenReturn(syncContext); when(mockHelper.getScheduledExecutorService()).thenReturn( fakeClock.getScheduledExecutorService()); @@ -174,6 +178,7 @@ public class OutlierDetectionLoadBalancerTest { public Subchannel answer(InvocationOnMock invocation) throws Throwable { CreateSubchannelArgs args = (CreateSubchannelArgs) invocation.getArguments()[0]; final Subchannel subchannel = subchannels.get(args.getAddresses()); + when(subchannel.getChannelLogger()).thenReturn(channelLogger); when(subchannel.getAllAddresses()).thenReturn(args.getAddresses()); when(subchannel.getAttributes()).thenReturn(args.getAttributes()); doAnswer(new Answer() {