core: standardize logid format and add details for channelz

core/src/jmh/java/io/grpc/internal/ChannelzBenchmark.java

@@ -132,7 +132,7 @@ public class ChannelzBenchmark {
 
   private static <T> InternalInstrumented<T> create() {
     return new InternalInstrumented<T>() {
-      final InternalLogId id = InternalLogId.allocate("fake-tag");
+      final InternalLogId id = InternalLogId.allocate(getClass(), "fake-tag");
 
       @Override
       public ListenableFuture<T> getStats() {

core/src/main/java/io/grpc/InternalLogId.java

@@ -16,7 +16,11 @@
 
 package io.grpc;
 
+import static com.google.common.base.Preconditions.checkArgument;
+import static com.google.common.base.Preconditions.checkNotNull;
+
 import java.util.concurrent.atomic.AtomicLong;
+import javax.annotation.Nullable;
 
 /**
  * An internal class. Do not use.
@@ -25,38 +29,79 @@ import java.util.concurrent.atomic.AtomicLong;
  */
 @Internal
 public final class InternalLogId {
+
   private static final AtomicLong idAlloc = new AtomicLong();
 
   /**
-   * @param tag a loggable tag associated with this tag. The ID that is allocated is guaranteed
-   *            to be unique and increasing, irrespective of the tag.
+   * @param type the "Type" to be used when logging this id.   The short name of this class will be
+   *     used, or else a default if the class is anonymous.
+   * @param details a short, human readable string that describes the object the id is attached to.
+   *     Typically this will be an address or target.
    */
-  public static InternalLogId allocate(String tag) {
-    return new InternalLogId(tag, getNextId());
+  public static InternalLogId allocate(Class<?> type, @Nullable String details) {
+    return allocate(getClassName(type), details);
+  }
+
+  /**
+   * @param typeName the "Type" to be used when logging this id.
+   * @param details a short, human readable string that describes the object the id is attached to.
+   *     Typically this will be an address or target.
+   */
+  public static InternalLogId allocate(String typeName, @Nullable String details) {
+    return new InternalLogId(typeName, details, getNextId());
   }
 
   static long getNextId() {
     return idAlloc.incrementAndGet();
   }
 
-  private final String tag;
+  private final String typeName;
+  private final @Nullable String details;
   private final long id;
 
-  protected InternalLogId(String tag, long id) {
-    this.tag = tag;
+  InternalLogId(String typeName, String details, long id) {
+    checkNotNull(typeName, "typeName");
+    checkArgument(!typeName.isEmpty(), "empty type");
+    this.typeName = typeName;
+    this.details = details;
     this.id = id;
   }
 
+  public String getTypeName() {
+    return typeName;
+  }
+
+  @Nullable
+  public String getDetails() {
+    return details;
+  }
+
   public long getId() {
     return id;
   }
 
-  public String getTag() {
-    return tag;
-  }
-
   @Override
   public String toString() {
-    return tag + "-" + id;
+    StringBuilder sb = new StringBuilder();
+    sb.append(shortName());
+    if (details != null) {
+      sb.append(": (");
+      sb.append(details);
+      sb.append(')');
+    }
+    return sb.toString();
+  }
+
+  private static String getClassName(Class<?> type) {
+    String className = checkNotNull(type, "type").getSimpleName();
+    if (!className.isEmpty()) {
+      return className;
+    }
+    // + 1 removes the separating '.'
+    return type.getName().substring(type.getPackage().getName().length() + 1);
+  }
+
+  public String shortName() {
+    return typeName + "<" + id + ">";
   }
 }

core/src/main/java/io/grpc/inprocess/InProcessTransport.java

@@ -73,7 +73,7 @@ import javax.annotation.concurrent.ThreadSafe;
 final class InProcessTransport implements ServerTransport, ConnectionClientTransport {
   private static final Logger log = Logger.getLogger(InProcessTransport.class.getName());
 
-  private final InternalLogId logId = InternalLogId.allocate(getClass().getName());
+  private final InternalLogId logId;
   private final String name;
   private final int clientMaxInboundMetadataSize;
   private final String authority;
@@ -117,6 +117,7 @@ final class InProcessTransport implements ServerTransport, ConnectionClientTrans
     this.clientMaxInboundMetadataSize = maxInboundMetadataSize;
     this.authority = authority;
     this.userAgent = GrpcUtil.getGrpcUserAgent("inprocess", userAgent);
+    logId = InternalLogId.allocate(getClass(), name);
   }
 
   @CheckReturnValue

core/src/main/java/io/grpc/internal/DelayedClientTransport.java

@@ -49,7 +49,9 @@ import javax.annotation.concurrent.GuardedBy;
  * thus the delayed transport stops owning the stream.
  */
 final class DelayedClientTransport implements ManagedClientTransport {
-  private final InternalLogId lodId = InternalLogId.allocate(getClass().getName());
+  // lazily allocated, since it is infrequently used.
+  private final InternalLogId logId =
+      InternalLogId.allocate(DelayedClientTransport.class, /*details=*/ null);
 
   private final Object lock = new Object();
 
@@ -338,10 +340,9 @@ final class DelayedClientTransport implements ManagedClientTransport {
     syncContext.drain();
   }
 
-  // TODO(carl-mastrangelo): remove this once the Subchannel change is in.
   @Override
   public InternalLogId getLogId() {
-    return lodId;
+    return logId;
   }
 
   private class PendingStream extends DelayedStream {

core/src/main/java/io/grpc/internal/InternalSubchannel.java

@@ -183,7 +183,7 @@ final class InternalSubchannel implements InternalInstrumented<ChannelStats> {
     this.channelz = channelz;
     this.callsTracer = callsTracer;
     this.channelTracer = Preconditions.checkNotNull(channelTracer, "channelTracer");
-    this.logId = Preconditions.checkNotNull(logId, "logId");
+    this.logId = InternalLogId.allocate("Subchannel", authority);
     this.channelLogger = new ChannelLoggerImpl(channelTracer, timeProvider);
   }
 

core/src/main/java/io/grpc/internal/ManagedChannelImpl.java

@@ -122,7 +122,7 @@ final class ManagedChannelImpl extends ManagedChannel implements
   static final Status SUBCHANNEL_SHUTDOWN_STATUS =
       Status.UNAVAILABLE.withDescription("Subchannel shutdown invoked");
 
-  private final InternalLogId logId = InternalLogId.allocate(getClass().getName());
+  private final InternalLogId logId;
   private final String target;
   private final NameResolver.Factory nameResolverFactory;
   private final Attributes nameResolverParams;
@@ -532,6 +532,7 @@ final class ManagedChannelImpl extends ManagedChannel implements
       List<ClientInterceptor> interceptors,
       final TimeProvider timeProvider) {
     this.target = checkNotNull(builder.target, "target");
+    this.logId = InternalLogId.allocate("Channel", target);
     this.nameResolverFactory = builder.getNameResolverFactory();
     this.nameResolverParams = checkNotNull(builder.getNameResolverParams(), "nameResolverParams");
     this.nameResolver = getNameResolver(target, nameResolverFactory, nameResolverParams);
@@ -1010,7 +1011,7 @@ final class ManagedChannelImpl extends ManagedChannel implements
       checkState(!terminated, "Channel is terminated");
       final SubchannelImpl subchannel = new SubchannelImpl(attrs);
       long subchannelCreationTime = timeProvider.currentTimeNanos();
-      InternalLogId subchannelLogId = InternalLogId.allocate("Subchannel");
+      InternalLogId subchannelLogId = InternalLogId.allocate("Subchannel", /*details=*/ null);
       ChannelTracer subchannelTracer =
           new ChannelTracer(
               subchannelLogId, maxTraceEvents, subchannelCreationTime,
@@ -1141,8 +1142,8 @@ final class ManagedChannelImpl extends ManagedChannel implements
       // TODO(ejona): can we be even stricter? Like terminating?
       checkState(!terminated, "Channel is terminated");
       long oobChannelCreationTime = timeProvider.currentTimeNanos();
-      InternalLogId oobLogId = InternalLogId.allocate("OobChannel");
-      InternalLogId subchannelLogId = InternalLogId.allocate("Subchannel-OOB");
+      InternalLogId oobLogId = InternalLogId.allocate("OobChannel", /*details=*/ null);
+      InternalLogId subchannelLogId = InternalLogId.allocate("Subchannel-OOB", /*details=*/ null);
       ChannelTracer oobChannelTracer =
           new ChannelTracer(
               oobLogId, maxTraceEvents, oobChannelCreationTime,

core/src/main/java/io/grpc/internal/OobChannel.java

@@ -69,7 +69,7 @@ final class OobChannel extends ManagedChannel implements InternalInstrumented<Ch
   private AbstractSubchannel subchannelImpl;
   private SubchannelPicker subchannelPicker;
 
-  private final InternalLogId logId = InternalLogId.allocate(getClass().getName());
+  private final InternalLogId logId;
   private final String authority;
   private final DelayedClientTransport delayedTransport;
   private final InternalChannelz channelz;
@@ -104,6 +104,7 @@ final class OobChannel extends ManagedChannel implements InternalInstrumented<Ch
       CallTracer callsTracer, ChannelTracer channelTracer, InternalChannelz channelz,
       TimeProvider timeProvider) {
     this.authority = checkNotNull(authority, "authority");
+    this.logId = InternalLogId.allocate(getClass(), authority);
     this.executorPool = checkNotNull(executorPool, "executorPool");
     this.executor = checkNotNull(executorPool.getObject(), "executor");
     this.deadlineCancellationExecutor = checkNotNull(

core/src/main/java/io/grpc/internal/ServerImpl.java

@@ -82,7 +82,7 @@ public final class ServerImpl extends io.grpc.Server implements InternalInstrume
   private static final Logger log = Logger.getLogger(ServerImpl.class.getName());
   private static final ServerStreamListener NOOP_LISTENER = new NoopListener();
 
-  private final InternalLogId logId = InternalLogId.allocate(getClass().getName());
+  private final InternalLogId logId;
   private final ObjectPool<? extends Executor> executorPool;
   /** Executor for application processing. Safe to read after {@link #start()}. */
   private Executor executor;
@@ -133,6 +133,7 @@ public final class ServerImpl extends io.grpc.Server implements InternalInstrume
     this.fallbackRegistry =
         Preconditions.checkNotNull(builder.fallbackRegistry, "fallbackRegistry");
     this.transportServer = Preconditions.checkNotNull(transportServer, "transportServer");
+    this.logId = InternalLogId.allocate("Server", String.valueOf(transportServer.getPort()));
     // Fork from the passed in context so that it does not propagate cancellation, it only
     // inherits values.
     this.rootContext = Preconditions.checkNotNull(rootContext, "rootContext").fork();

core/src/test/java/io/grpc/InternalChannelzTest.java

@@ -303,7 +303,7 @@ public final class InternalChannelzTest {
 
   private static <T> InternalInstrumented<T> create() {
     return new InternalInstrumented<T>() {
-      final InternalLogId id = InternalLogId.allocate("fake-tag");
+      final InternalLogId id = InternalLogId.allocate("fake-type", /*details=*/ null);
       @Override
       public ListenableFuture<T> getStats() {
         throw new UnsupportedOperationException();

core/src/test/java/io/grpc/InternalLogIdTest.java

@@ -0,0 +1,53 @@
+/*
+ * Copyright 2018 The gRPC Authors
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package io.grpc;
+
+import com.google.common.truth.Truth;
+import java.io.Serializable;
+import org.junit.Test;
+import org.junit.runner.RunWith;
+import org.junit.runners.JUnit4;
+
+@RunWith(JUnit4.class)
+public class InternalLogIdTest {
+  
+  private static final String NO_DETAILS = null;
+
+  @Test
+  public void shortName() {
+    InternalLogId name = InternalLogId.allocate("foo", NO_DETAILS);
+    Truth.assertThat(name.shortName()).matches("foo<\\d+>");
+  }
+
+  @Test
+  public void toString_includesDetails() {
+    InternalLogId name = InternalLogId.allocate("foo", "deets");
+    Truth.assertThat(name.toString()).matches("foo<\\d+>: \\(deets\\)");
+  }
+
+  @Test
+  public void shortClassName() {
+    InternalLogId name = InternalLogId.allocate(getClass(), "deets");
+    Truth.assertThat(name.toString()).matches("InternalLogIdTest<\\d+>: \\(deets\\)");
+  }
+
+  @Test
+  public void shortAnonymousClassName() {
+    InternalLogId name = InternalLogId.allocate(new Serializable() {}.getClass(), "deets");
+    Truth.assertThat(name.toString()).matches("InternalLogIdTest\\$\\d+<\\d+>: \\(deets\\)");
+  }
+}

core/src/test/java/io/grpc/internal/ChannelLoggerImplTest.java

@@ -41,7 +41,7 @@ import org.junit.runners.JUnit4;
 public class ChannelLoggerImplTest {
   private static final Logger javaLogger = Logger.getLogger(ChannelLogger.class.getName());
   private final FakeClock clock = new FakeClock();
-  private final InternalLogId logId = InternalLogId.allocate("test");
+  private final InternalLogId logId = InternalLogId.allocate("test", /*details=*/ null);
   private final String logPrefix = "[" + logId + "] ";
   private final ArrayList<String> logs = new ArrayList<String>();
   private final Handler handler = new Handler() {

core/src/test/java/io/grpc/internal/ChannelTracerTest.java

@@ -56,7 +56,7 @@ public class ChannelTracerTest {
       }
     };
 
-  private final InternalLogId logId = InternalLogId.allocate("test");
+  private final InternalLogId logId = InternalLogId.allocate("test", /*details=*/ null);
   private final String logPrefix = "[" + logId + "] ";
 
   @Before

core/src/test/java/io/grpc/internal/InternalSubchannelTest.java

@@ -1117,7 +1117,7 @@ public class InternalSubchannelTest {
 
   private void createInternalSubchannel(EquivalentAddressGroup ... addrs) {
     List<EquivalentAddressGroup> addressGroups = Arrays.asList(addrs);
-    InternalLogId logId = InternalLogId.allocate("Subchannel");
+    InternalLogId logId = InternalLogId.allocate("Subchannel", /*details=*/ null);
     internalSubchannel = new InternalSubchannel(addressGroups, AUTHORITY, USER_AGENT,
         mockBackoffPolicyProvider, mockTransportFactory, fakeClock.getScheduledExecutorService(),
         fakeClock.getStopwatchSupplier(), syncContext, mockInternalSubchannelCallback,

core/src/test/java/io/grpc/internal/ServerImplTest.java

@@ -1380,7 +1380,7 @@ public class ServerImplTest {
 
   private class SimpleServerTransport implements ServerTransport {
     ServerTransportListener listener;
-    InternalLogId id = InternalLogId.allocate(getClass().getName());
+    InternalLogId id = InternalLogId.allocate(getClass(), /*details=*/ null);
 
     @Override
     public void shutdown() {

core/src/test/java/io/grpc/internal/TestUtils.java

@@ -75,7 +75,8 @@ final class TestUtils {
       @Override
       public ConnectionClientTransport answer(InvocationOnMock invocation) throws Throwable {
         final ConnectionClientTransport mockTransport = mock(ConnectionClientTransport.class);
-        when(mockTransport.getLogId()).thenReturn(InternalLogId.allocate("mocktransport"));
+        when(mockTransport.getLogId())
+            .thenReturn(InternalLogId.allocate("mocktransport", /*details=*/ null));
         when(mockTransport.newStream(
                 any(MethodDescriptor.class), any(Metadata.class), any(CallOptions.class)))
             .thenReturn(mock(ClientStream.class));

cronet/src/main/java/io/grpc/cronet/CronetClientTransport.java

@@ -46,7 +46,7 @@ import javax.annotation.concurrent.GuardedBy;
  * A cronet-based {@link ConnectionClientTransport} implementation.
  */
 class CronetClientTransport implements ConnectionClientTransport {
-  private final InternalLogId logId = InternalLogId.allocate(getClass().getName());
+  private final InternalLogId logId;
   private final InetSocketAddress address;
   private final String authority;
   private final String userAgent;
@@ -87,6 +87,7 @@ class CronetClientTransport implements ConnectionClientTransport {
       boolean alwaysUsePut,
       TransportTracer transportTracer) {
     this.address = Preconditions.checkNotNull(address, "address");
+    this.logId = InternalLogId.allocate(getClass(), address.toString());
     this.authority = authority;
     this.userAgent = GrpcUtil.getGrpcUserAgent("cronet", userAgent);
     this.maxMessageSize = maxMessageSize;

grpclb/src/main/java/io/grpc/grpclb/GrpclbLoadBalancer.java

@@ -39,6 +39,7 @@ import javax.annotation.Nullable;
  * or round-robin balancer.
  */
 class GrpclbLoadBalancer extends LoadBalancer {
+
   private final SubchannelPool subchannelPool;
 
   // All mutable states in this class are mutated ONLY from Channel Executor

netty/src/main/java/io/grpc/netty/NettyClientTransport.java

@@ -63,7 +63,7 @@ import javax.annotation.Nullable;
  * A Netty-based {@link ConnectionClientTransport} implementation.
  */
 class NettyClientTransport implements ConnectionClientTransport {
-  private final InternalLogId logId = InternalLogId.allocate(getClass().getName());
+  private final InternalLogId logId;
   private final Map<ChannelOption<?>, ?> channelOptions;
   private final SocketAddress remoteAddress;
   private final Class<? extends Channel> channelType;
@@ -121,6 +121,7 @@ class NettyClientTransport implements ConnectionClientTransport {
     this.transportTracer = Preconditions.checkNotNull(transportTracer, "transportTracer");
     this.eagAttributes = Preconditions.checkNotNull(eagAttributes, "eagAttributes");
     this.localSocketPicker = Preconditions.checkNotNull(localSocketPicker, "localSocketPicker");
+    this.logId = InternalLogId.allocate(getClass(), remoteAddress.toString());
   }
 
   @Override

netty/src/main/java/io/grpc/netty/NettyServer.java

@@ -67,7 +67,7 @@ import javax.annotation.Nullable;
 class NettyServer implements InternalServer, InternalWithLogId {
   private static final Logger log = Logger.getLogger(InternalServer.class.getName());
 
-  private final InternalLogId logId = InternalLogId.allocate(getClass().getName());
+  private final InternalLogId logId;
   private final SocketAddress address;
   private final Class<? extends ServerChannel> channelType;
   private final Map<ChannelOption<?>, ?> channelOptions;
@@ -133,6 +133,8 @@ class NettyServer implements InternalServer, InternalWithLogId {
     this.permitKeepAliveWithoutCalls = permitKeepAliveWithoutCalls;
     this.permitKeepAliveTimeInNanos = permitKeepAliveTimeInNanos;
     this.channelz = Preconditions.checkNotNull(channelz);
+    this.logId =
+        InternalLogId.allocate(getClass(), address != null ? address.toString() : "No address");
   }
 
   @Override
@@ -343,11 +345,12 @@ class NettyServer implements InternalServer, InternalWithLogId {
    * A class that can answer channelz queries about the server listen sockets.
    */
   private static final class ListenSocket implements InternalInstrumented<SocketStats> {
-    private final InternalLogId id = InternalLogId.allocate(getClass().getName());
+    private final InternalLogId id;
     private final Channel ch;
 
     ListenSocket(Channel ch) {
       this.ch = ch;
+      this.id = InternalLogId.allocate(getClass(), String.valueOf(ch.localAddress()));
     }
 
     @Override

netty/src/main/java/io/grpc/netty/NettyServerTransport.java

@@ -37,6 +37,7 @@ import io.netty.channel.ChannelPromise;
 import io.netty.util.concurrent.Future;
 import io.netty.util.concurrent.GenericFutureListener;
 import java.io.IOException;
+import java.net.SocketAddress;
 import java.util.List;
 import java.util.concurrent.ScheduledExecutorService;
 import java.util.logging.Level;
@@ -56,7 +57,7 @@ class NettyServerTransport implements ServerTransport {
       "An existing connection was forcibly closed by the remote host",
       "An established connection was aborted by the software in your host machine");
 
-  private final InternalLogId logId = InternalLogId.allocate(getClass().getName());
+  private final InternalLogId logId;
   private final Channel channel;
   private final ChannelPromise channelUnused;
   private final ProtocolNegotiator protocolNegotiator;
@@ -112,6 +113,8 @@ class NettyServerTransport implements ServerTransport {
     this.maxConnectionAgeGraceInNanos = maxConnectionAgeGraceInNanos;
     this.permitKeepAliveWithoutCalls = permitKeepAliveWithoutCalls;
     this.permitKeepAliveTimeInNanos = permitKeepAliveTimeInNanos;
+    SocketAddress remote = channel.remoteAddress();
+    this.logId = InternalLogId.allocate(getClass(), remote != null ? remote.toString() : null);
   }
 
   public void start(ServerTransportListener listener) {

okhttp/src/main/java/io/grpc/okhttp/OkHttpClientTransport.java

@@ -147,7 +147,7 @@ class OkHttpClientTransport implements ConnectionClientTransport, TransportExcep
   private AsyncFrameWriter frameWriter;
   private OutboundFlowController outboundFlow;
   private final Object lock = new Object();
-  private final InternalLogId logId = InternalLogId.allocate(getClass().getName());
+  private final InternalLogId logId;
   @GuardedBy("lock")
   private int nextStreamId;
   @GuardedBy("lock")
@@ -244,6 +244,7 @@ class OkHttpClientTransport implements ConnectionClientTransport, TransportExcep
         Preconditions.checkNotNull(tooManyPingsRunnable, "tooManyPingsRunnable");
     this.maxInboundMetadataSize = maxInboundMetadataSize;
     this.transportTracer = Preconditions.checkNotNull(transportTracer);
+    this.logId = InternalLogId.allocate(getClass(), address.toString());
     initTransportTracer();
   }
 
@@ -285,6 +286,7 @@ class OkHttpClientTransport implements ConnectionClientTransport, TransportExcep
         Preconditions.checkNotNull(tooManyPingsRunnable, "tooManyPingsRunnable");
     this.maxInboundMetadataSize = Integer.MAX_VALUE;
     this.transportTracer = Preconditions.checkNotNull(transportTracer, "transportTracer");
+    this.logId = InternalLogId.allocate(getClass(), String.valueOf(socket.getInetAddress()));
     initTransportTracer();
   }
 

services/src/test/java/io/grpc/services/ChannelzTestHelper.java

@@ -41,7 +41,7 @@ import java.util.Collections;
 final class ChannelzTestHelper {
 
   static final class TestSocket implements InternalInstrumented<SocketStats> {
-    private final InternalLogId id = InternalLogId.allocate("socket");
+    private final InternalLogId id = InternalLogId.allocate("socket", /*details=*/ null);
     TransportStats transportStats = new TransportStats(
         /*streamsStarted=*/ 1,
         /*lastLocalStreamCreatedTimeNanos=*/ 2,
@@ -88,7 +88,7 @@ final class ChannelzTestHelper {
   }
 
   static final class TestListenSocket implements InternalInstrumented<SocketStats> {
-    private final InternalLogId id = InternalLogId.allocate("listensocket");
+    private final InternalLogId id = InternalLogId.allocate("listensocket", /*details=*/ null);
     SocketAddress listenAddress = new InetSocketAddress("10.0.0.1", 1234);
 
     @Override
@@ -118,7 +118,7 @@ final class ChannelzTestHelper {
   }
 
   static final class TestServer implements InternalInstrumented<ServerStats> {
-    private final InternalLogId id = InternalLogId.allocate("server");
+    private final InternalLogId id = InternalLogId.allocate("server", /*details=*/ null);
     ServerStats serverStats = new ServerStats(
         /*callsStarted=*/ 1,
         /*callsSucceeded=*/ 2,
@@ -147,7 +147,8 @@ final class ChannelzTestHelper {
   }
 
   static final class TestChannel implements InternalInstrumented<ChannelStats> {
-    private final InternalLogId id = InternalLogId.allocate("channel-or-subchannel");
+    private final InternalLogId id =
+        InternalLogId.allocate("channel-or-subchannel", /*details=*/ null);
 
     ChannelStats stats = new ChannelStats.Builder()
         .setTarget("sometarget")