From 1ed538f253577273181986d29e1ac08e406aefcc Mon Sep 17 00:00:00 2001
From: ZHANG Dapeng <zdapeng@google.com>
Date: Tue, 28 Jan 2020 09:55:04 -0800
Subject: [PATCH] all: log picker when updating balancing state

Let `ManagedChannelImpl` log picker update when updating balancing state.
---
 .../AutoConfiguredLoadBalancerFactory.java    |  5 ++
 .../io/grpc/internal/ManagedChannelImpl.java  | 10 +++-
 .../java/io/grpc/internal/OobChannel.java     | 46 +++++++++++++------
 .../grpc/internal/PickFirstLoadBalancer.java  |  6 +++
 .../grpc/util/GracefulSwitchLoadBalancer.java | 20 +++++---
 .../io/grpc/util/RoundRobinLoadBalancer.java  | 11 +++++
 .../grpc/internal/ManagedChannelImplTest.java |  2 +-
 .../main/java/io/grpc/grpclb/GrpclbState.java |  8 ++++
 .../java/io/grpc/xds/ClientLoadCounter.java   | 14 ++++++
 9 files changed, 100 insertions(+), 22 deletions(-)

diff --git a/core/src/main/java/io/grpc/internal/AutoConfiguredLoadBalancerFactory.java b/core/src/main/java/io/grpc/internal/AutoConfiguredLoadBalancerFactory.java
index c775deca00..d0a71b3ded 100644
--- a/core/src/main/java/io/grpc/internal/AutoConfiguredLoadBalancerFactory.java
+++ b/core/src/main/java/io/grpc/internal/AutoConfiguredLoadBalancerFactory.java
@@ -432,6 +432,11 @@ public final class AutoConfiguredLoadBalancerFactory {
     public PickResult pickSubchannel(PickSubchannelArgs args) {
       return PickResult.withNoResult();
     }
+
+    @Override
+    public String toString() {
+      return MoreObjects.toStringHelper(EmptyPicker.class).toString();
+    }
   }
 
   private static final class FailingPicker extends SubchannelPicker {
diff --git a/core/src/main/java/io/grpc/internal/ManagedChannelImpl.java b/core/src/main/java/io/grpc/internal/ManagedChannelImpl.java
index 062acc3a59..040d964da5 100644
--- a/core/src/main/java/io/grpc/internal/ManagedChannelImpl.java
+++ b/core/src/main/java/io/grpc/internal/ManagedChannelImpl.java
@@ -812,6 +812,13 @@ final class ManagedChannelImpl extends ManagedChannel implements
       public PickResult pickSubchannel(PickSubchannelArgs args) {
         return panicPickResult;
       }
+
+      @Override
+      public String toString() {
+        return MoreObjects.toStringHelper(PanicSubchannelPicker.class)
+            .add("panicPickResult", panicPickResult)
+            .toString();
+      }
     }
 
     updateSubchannelPicker(new PanicSubchannelPicker());
@@ -1146,7 +1153,8 @@ final class ManagedChannelImpl extends ManagedChannel implements
           // It's not appropriate to report SHUTDOWN state from lb.
           // Ignore the case of newState == SHUTDOWN for now.
           if (newState != SHUTDOWN) {
-            channelLogger.log(ChannelLogLevel.INFO, "Entering {0} state", newState);
+            channelLogger.log(
+                ChannelLogLevel.INFO, "Entering {0} state with picker: {1}", newState, newPicker);
             channelStateManager.gotoState(newState);
           }
         }
diff --git a/core/src/main/java/io/grpc/internal/OobChannel.java b/core/src/main/java/io/grpc/internal/OobChannel.java
index 512abaeed1..aae3314f3f 100644
--- a/core/src/main/java/io/grpc/internal/OobChannel.java
+++ b/core/src/main/java/io/grpc/internal/OobChannel.java
@@ -173,14 +173,23 @@ final class OobChannel extends ManagedChannel implements InternalInstrumented<Ch
         }
     };
 
-    subchannelPicker = new SubchannelPicker() {
-        final PickResult result = PickResult.withSubchannel(subchannelImpl);
+    final class OobSubchannelPicker extends SubchannelPicker {
+      final PickResult result = PickResult.withSubchannel(subchannelImpl);
 
-        @Override
-        public PickResult pickSubchannel(PickSubchannelArgs args) {
-          return result;
-        }
-      };
+      @Override
+      public PickResult pickSubchannel(PickSubchannelArgs args) {
+        return result;
+      }
+
+      @Override
+      public String toString() {
+        return MoreObjects.toStringHelper(OobSubchannelPicker.class)
+            .add("result", result)
+            .toString();
+      }
+    }
+
+    subchannelPicker = new OobSubchannelPicker();
     delayedTransport.reprocess(subchannelPicker);
   }
 
@@ -253,14 +262,23 @@ final class OobChannel extends ManagedChannel implements InternalInstrumented<Ch
         delayedTransport.reprocess(subchannelPicker);
         break;
       case TRANSIENT_FAILURE:
-        delayedTransport.reprocess(new SubchannelPicker() {
-            final PickResult errorResult = PickResult.withError(newState.getStatus());
+        final class OobErrorPicker extends SubchannelPicker {
+          final PickResult errorResult = PickResult.withError(newState.getStatus());
 
-            @Override
-            public PickResult pickSubchannel(PickSubchannelArgs args) {
-              return errorResult;
-            }
-          });
+          @Override
+          public PickResult pickSubchannel(PickSubchannelArgs args) {
+            return errorResult;
+          }
+
+          @Override
+          public String toString() {
+            return MoreObjects.toStringHelper(OobErrorPicker.class)
+                .add("errorResult", errorResult)
+                .toString();
+          }
+        }
+
+        delayedTransport.reprocess(new OobErrorPicker());
         break;
       default:
         // Do nothing
diff --git a/core/src/main/java/io/grpc/internal/PickFirstLoadBalancer.java b/core/src/main/java/io/grpc/internal/PickFirstLoadBalancer.java
index d579e437b5..535b34b015 100644
--- a/core/src/main/java/io/grpc/internal/PickFirstLoadBalancer.java
+++ b/core/src/main/java/io/grpc/internal/PickFirstLoadBalancer.java
@@ -21,6 +21,7 @@ import static io.grpc.ConnectivityState.CONNECTING;
 import static io.grpc.ConnectivityState.SHUTDOWN;
 import static io.grpc.ConnectivityState.TRANSIENT_FAILURE;
 
+import com.google.common.base.MoreObjects;
 import io.grpc.ConnectivityState;
 import io.grpc.ConnectivityStateInfo;
 import io.grpc.EquivalentAddressGroup;
@@ -135,6 +136,11 @@ final class PickFirstLoadBalancer extends LoadBalancer {
     public PickResult pickSubchannel(PickSubchannelArgs args) {
       return result;
     }
+
+    @Override
+    public String toString() {
+      return MoreObjects.toStringHelper(Picker.class).add("result", result).toString();
+    }
   }
 
   /** Picker that requests connection during the first pick, and returns noResult. */
diff --git a/core/src/main/java/io/grpc/util/GracefulSwitchLoadBalancer.java b/core/src/main/java/io/grpc/util/GracefulSwitchLoadBalancer.java
index cdb68685ca..ecd1f77572 100644
--- a/core/src/main/java/io/grpc/util/GracefulSwitchLoadBalancer.java
+++ b/core/src/main/java/io/grpc/util/GracefulSwitchLoadBalancer.java
@@ -20,6 +20,7 @@ import static com.google.common.base.Preconditions.checkNotNull;
 import static com.google.common.base.Preconditions.checkState;
 
 import com.google.common.annotations.VisibleForTesting;
+import com.google.common.base.MoreObjects;
 import io.grpc.ConnectivityState;
 import io.grpc.ConnectivityStateInfo;
 import io.grpc.ExperimentalApi;
@@ -56,14 +57,21 @@ public final class GracefulSwitchLoadBalancer extends ForwardingLoadBalancer {
 
     @Override
     public void handleNameResolutionError(final Status error) {
+      class ErrorPicker extends SubchannelPicker {
+        @Override
+        public PickResult pickSubchannel(PickSubchannelArgs args) {
+          return PickResult.withError(error);
+        }
+
+        @Override
+        public String toString() {
+          return MoreObjects.toStringHelper(ErrorPicker.class).add("error", error).toString();
+        }
+      }
+
       helper.updateBalancingState(
           ConnectivityState.TRANSIENT_FAILURE,
-          new SubchannelPicker() {
-            @Override
-            public PickResult pickSubchannel(PickSubchannelArgs args) {
-              return PickResult.withError(error);
-            }
-          });
+          new ErrorPicker());
     }
 
     @Override
diff --git a/core/src/main/java/io/grpc/util/RoundRobinLoadBalancer.java b/core/src/main/java/io/grpc/util/RoundRobinLoadBalancer.java
index 7557aa86f7..82d803a829 100644
--- a/core/src/main/java/io/grpc/util/RoundRobinLoadBalancer.java
+++ b/core/src/main/java/io/grpc/util/RoundRobinLoadBalancer.java
@@ -24,6 +24,7 @@ import static io.grpc.ConnectivityState.SHUTDOWN;
 import static io.grpc.ConnectivityState.TRANSIENT_FAILURE;
 
 import com.google.common.annotations.VisibleForTesting;
+import com.google.common.base.MoreObjects;
 import com.google.common.base.Objects;
 import com.google.common.base.Preconditions;
 
@@ -428,6 +429,11 @@ final class RoundRobinLoadBalancer extends LoadBalancer {
       return PickResult.withSubchannel(subchannel != null ? subchannel : nextSubchannel());
     }
 
+    @Override
+    public String toString() {
+      return MoreObjects.toStringHelper(ReadyPicker.class).add("list", list).toString();
+    }
+
     private Subchannel nextSubchannel() {
       int size = list.size();
       int i = indexUpdater.incrementAndGet(this);
@@ -476,6 +482,11 @@ final class RoundRobinLoadBalancer extends LoadBalancer {
       return picker instanceof EmptyPicker && (Objects.equal(status, ((EmptyPicker) picker).status)
           || (status.isOk() && ((EmptyPicker) picker).status.isOk()));
     }
+
+    @Override
+    public String toString() {
+      return MoreObjects.toStringHelper(EmptyPicker.class).add("status", status).toString();
+    }
   }
 
   /**
diff --git a/core/src/test/java/io/grpc/internal/ManagedChannelImplTest.java b/core/src/test/java/io/grpc/internal/ManagedChannelImplTest.java
index f272316ded..9066f3e33a 100644
--- a/core/src/test/java/io/grpc/internal/ManagedChannelImplTest.java
+++ b/core/src/test/java/io/grpc/internal/ManagedChannelImplTest.java
@@ -2862,7 +2862,7 @@ public class ManagedChannelImplTest {
     timer.forwardNanos(1234);
     updateBalancingStateSafely(helper, CONNECTING, mockPicker);
     assertThat(getStats(channel).channelTrace.events).contains(new ChannelTrace.Event.Builder()
-        .setDescription("Entering CONNECTING state")
+        .setDescription("Entering CONNECTING state with picker: mockPicker")
         .setSeverity(ChannelTrace.Event.Severity.CT_INFO)
         .setTimestampNanos(timer.getTicker().read())
         .build());
diff --git a/grpclb/src/main/java/io/grpc/grpclb/GrpclbState.java b/grpclb/src/main/java/io/grpc/grpclb/GrpclbState.java
index 925eb2f04e..a2679472f6 100644
--- a/grpclb/src/main/java/io/grpc/grpclb/GrpclbState.java
+++ b/grpclb/src/main/java/io/grpc/grpclb/GrpclbState.java
@@ -26,6 +26,7 @@ import static io.grpc.ConnectivityState.SHUTDOWN;
 import static io.grpc.ConnectivityState.TRANSIENT_FAILURE;
 
 import com.google.common.annotations.VisibleForTesting;
+import com.google.common.base.MoreObjects;
 import com.google.common.base.Objects;
 import com.google.common.base.Stopwatch;
 import com.google.protobuf.util.Durations;
@@ -1051,5 +1052,12 @@ final class GrpclbState {
       }
     }
 
+    @Override
+    public String toString() {
+      return MoreObjects.toStringHelper(RoundRobinPicker.class)
+          .add("dropList", dropList)
+          .add("pickList", pickList)
+          .toString();
+    }
   }
 }
diff --git a/xds/src/main/java/io/grpc/xds/ClientLoadCounter.java b/xds/src/main/java/io/grpc/xds/ClientLoadCounter.java
index 2ad4fed502..8e8754d254 100644
--- a/xds/src/main/java/io/grpc/xds/ClientLoadCounter.java
+++ b/xds/src/main/java/io/grpc/xds/ClientLoadCounter.java
@@ -413,6 +413,13 @@ final class ClientLoadCounter {
         ClientStreamTracer.Factory originFactory) {
       return new LoadRecordingStreamTracerFactory(counter, originFactory);
     }
+
+    @Override
+    public String toString() {
+      return MoreObjects.toStringHelper(LoadRecordingSubchannelPicker.class)
+          .add("delegate", delegate)
+          .toString();
+    }
   }
 
   /**
@@ -445,5 +452,12 @@ final class ClientLoadCounter {
         ClientStreamTracer.Factory originFactory) {
       return orcaPerRequestUtil.newOrcaClientStreamTracerFactory(originFactory, listener);
     }
+
+    @Override
+    public String toString() {
+      return MoreObjects.toStringHelper(MetricsObservingSubchannelPicker.class)
+          .add("delegate", delegate)
+          .toString();
+    }
   }
 }