alts: add debugging statements for ALTS
diff --git a/alts/src/main/java/io/grpc/alts/internal/AltsProtocolNegotiator.java b/alts/src/main/java/io/grpc/alts/internal/AltsProtocolNegotiator.java
index 300fd78..bebf968 100644
--- a/alts/src/main/java/io/grpc/alts/internal/AltsProtocolNegotiator.java
+++ b/alts/src/main/java/io/grpc/alts/internal/AltsProtocolNegotiator.java
@@ -34,6 +34,8 @@
import io.netty.channel.ChannelHandler;
import io.netty.channel.ChannelHandlerContext;
import io.netty.util.AsciiString;
+import java.util.logging.Level;
+import java.util.logging.Logger;
/**
* A GRPC {@link ProtocolNegotiator} for ALTS. This class creates a Netty handler that provides ALTS
@@ -41,6 +43,8 @@
*/
public abstract class AltsProtocolNegotiator implements ProtocolNegotiator {
+ private static final Logger logger = Logger.getLogger(AltsProtocolNegotiator.class.getName());
+
@Grpc.TransportAttr
public static final Attributes.Key<TsiPeer> TSI_PEER_KEY = Attributes.Key.create("TSI_PEER");
@Grpc.TransportAttr
@@ -51,46 +55,52 @@
/** Creates a negotiator used for ALTS client. */
public static AltsProtocolNegotiator createClientNegotiator(
final TsiHandshakerFactory handshakerFactory) {
- return new AltsProtocolNegotiator() {
+ final class ClientAltsProtocolNegotiator extends AltsProtocolNegotiator {
@Override
public Handler newHandler(GrpcHttp2ConnectionHandler grpcHandler) {
+ TsiHandshaker handshaker = handshakerFactory.newHandshaker(grpcHandler.getAuthority());
return new BufferUntilAltsNegotiatedHandler(
grpcHandler,
- new TsiHandshakeHandler(
- new NettyTsiHandshaker(
- handshakerFactory.newHandshaker(grpcHandler.getAuthority()))),
+ new TsiHandshakeHandler(new NettyTsiHandshaker(handshaker)),
new TsiFrameHandler());
}
@Override
public void close() {
+ logger.finest("ALTS Client ProtocolNegotiator Closed");
// TODO(jiangtaoli2016): release resources
}
- };
+ }
+
+ return new ClientAltsProtocolNegotiator();
}
/** Creates a negotiator used for ALTS server. */
public static AltsProtocolNegotiator createServerNegotiator(
final TsiHandshakerFactory handshakerFactory) {
- return new AltsProtocolNegotiator() {
+ final class ServerAltsProtocolNegotiator extends AltsProtocolNegotiator {
@Override
public Handler newHandler(GrpcHttp2ConnectionHandler grpcHandler) {
+ TsiHandshaker handshaker = handshakerFactory.newHandshaker(/*authority=*/ null);
return new BufferUntilAltsNegotiatedHandler(
grpcHandler,
- new TsiHandshakeHandler(new NettyTsiHandshaker(handshakerFactory.newHandshaker(null))),
+ new TsiHandshakeHandler(new NettyTsiHandshaker(handshaker)),
new TsiFrameHandler());
}
@Override
public void close() {
+ logger.finest("ALTS Server ProtocolNegotiator Closed");
// TODO(jiangtaoli2016): release resources
}
- };
+ }
+
+ return new ServerAltsProtocolNegotiator();
}
/** Buffers all writes until the ALTS handshake is complete. */
@VisibleForTesting
- static class BufferUntilAltsNegotiatedHandler extends AbstractBufferingHandler
+ static final class BufferUntilAltsNegotiatedHandler extends AbstractBufferingHandler
implements ProtocolNegotiator.Handler {
private final GrpcHttp2ConnectionHandler grpcHandler;
@@ -105,7 +115,8 @@
// TODO: Remove this once https://github.com/grpc/grpc-java/pull/3715 is in.
@Override
- public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) throws Exception {
+ public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) {
+ logger.log(Level.FINEST, "Exception while buffering for ALTS Negotiation", cause);
fail(ctx, cause);
ctx.fireExceptionCaught(cause);
}
@@ -117,6 +128,9 @@
@Override
public void userEventTriggered(ChannelHandlerContext ctx, Object evt) throws Exception {
+ if (logger.isLoggable(Level.FINEST)) {
+ logger.log(Level.FINEST, "User Event triggered while negotiating ALTS", new Object[]{evt});
+ }
if (evt instanceof TsiHandshakeCompletionEvent) {
TsiHandshakeCompletionEvent altsEvt = (TsiHandshakeCompletionEvent) evt;
if (altsEvt.isSuccess()) {
@@ -138,6 +152,7 @@
+ RpcProtocolVersionsUtil.getRpcProtocolVersions().toString()
+ "are not compatible with peer Rpc Protocol Versions "
+ altsContext.getPeerRpcVersions().toString();
+ logger.finest(errorMessage);
fail(ctx, Status.UNAVAILABLE.withDescription(errorMessage).asRuntimeException());
}
grpcHandler.handleProtocolNegotiationCompleted(
@@ -150,10 +165,11 @@
.build(),
new Security(new OtherSecurity("alts", Any.pack(altsContext.context))));
}
-
+ logger.finest("Flushing ALTS buffered data");
// Now write any buffered data and remove this handler.
writeBufferedAndRemove(ctx);
} else {
+ logger.log(Level.FINEST, "ALTS handshake failed", altsEvt.cause());
fail(ctx, unavailableException("ALTS handshake failed", altsEvt.cause()));
}
}
diff --git a/alts/src/main/java/io/grpc/alts/internal/TsiFrameHandler.java b/alts/src/main/java/io/grpc/alts/internal/TsiFrameHandler.java
index a7afca2..a2c1a1d 100644
--- a/alts/src/main/java/io/grpc/alts/internal/TsiFrameHandler.java
+++ b/alts/src/main/java/io/grpc/alts/internal/TsiFrameHandler.java
@@ -34,6 +34,8 @@
import java.util.ArrayList;
import java.util.List;
import java.util.concurrent.Future;
+import java.util.logging.Level;
+import java.util.logging.Logger;
/**
* Encrypts and decrypts TSI Frames. Writes are buffered here until {@link #flush} is called. Writes
@@ -41,6 +43,8 @@
*/
public final class TsiFrameHandler extends ByteToMessageDecoder implements ChannelOutboundHandler {
+ private static final Logger logger = Logger.getLogger(TsiFrameHandler.class.getName());
+
private TsiFrameProtector protector;
private PendingWriteQueue pendingUnprotectedWrites;
@@ -48,6 +52,7 @@
@Override
public void handlerAdded(ChannelHandlerContext ctx) throws Exception {
+ logger.finest("TsiFrameHandler added");
super.handlerAdded(ctx);
assert pendingUnprotectedWrites == null;
pendingUnprotectedWrites = new PendingWriteQueue(checkNotNull(ctx));
@@ -55,6 +60,9 @@
@Override
public void userEventTriggered(ChannelHandlerContext ctx, Object event) throws Exception {
+ if (logger.isLoggable(Level.FINEST)) {
+ logger.log(Level.FINEST, "TsiFrameHandler user event triggered", new Object[]{event});
+ }
if (event instanceof TsiHandshakeCompletionEvent) {
TsiHandshakeCompletionEvent tsiEvent = (TsiHandshakeCompletionEvent) event;
if (tsiEvent.isSuccess()) {
@@ -68,6 +76,7 @@
@VisibleForTesting
void setProtector(TsiFrameProtector protector) {
+ logger.finest("TsiFrameHandler protector set");
checkState(this.protector == null);
this.protector = checkNotNull(protector);
}
@@ -95,7 +104,8 @@
}
@Override
- public void handlerRemoved0(ChannelHandlerContext ctx) throws Exception {
+ public void handlerRemoved0(ChannelHandlerContext ctx) {
+ logger.finest("TsiFrameHandler removed");
if (!pendingUnprotectedWrites.isEmpty()) {
pendingUnprotectedWrites.removeAndFailAll(
new ChannelException("Pending write on removal of TSI handler"));
diff --git a/alts/src/main/java/io/grpc/alts/internal/TsiHandshakeHandler.java b/alts/src/main/java/io/grpc/alts/internal/TsiHandshakeHandler.java
index 98c9a7d..98dd1f9 100644
--- a/alts/src/main/java/io/grpc/alts/internal/TsiHandshakeHandler.java
+++ b/alts/src/main/java/io/grpc/alts/internal/TsiHandshakeHandler.java
@@ -19,6 +19,7 @@
import static com.google.common.base.Preconditions.checkNotNull;
import com.google.common.annotations.VisibleForTesting;
+import com.google.common.base.MoreObjects;
import io.netty.buffer.ByteBuf;
import io.netty.buffer.ByteBufAllocator;
import io.netty.channel.ChannelHandlerContext;
@@ -27,6 +28,8 @@
import java.security.GeneralSecurityException;
import java.util.List;
import java.util.concurrent.Future;
+import java.util.logging.Level;
+import java.util.logging.Logger;
import javax.annotation.Nullable;
/**
@@ -34,6 +37,9 @@
* TsiHandshakeCompletionEvent} indicating the result of the handshake.
*/
public final class TsiHandshakeHandler extends ByteToMessageDecoder {
+
+ private static final Logger logger = Logger.getLogger(TsiHandshakeHandler.class.getName());
+
private static final int HANDSHAKE_FRAME_SIZE = 1024;
private final NettyTsiHandshaker handshaker;
@@ -106,28 +112,42 @@
TsiFrameProtector protector() {
return protector;
}
+
+ @Override
+ public String toString() {
+ return MoreObjects.toStringHelper(this)
+ .add("peer", peer)
+ .add("protector", protector)
+ .add("context", context)
+ .add("cause", cause)
+ .toString();
+ }
}
@Override
public void handlerAdded(ChannelHandlerContext ctx) throws Exception {
+ logger.finest("TsiHandshakeHandler added");
maybeStart(ctx);
super.handlerAdded(ctx);
}
@Override
public void channelActive(ChannelHandlerContext ctx) throws Exception {
+ logger.finest("TsiHandshakeHandler channel active");
maybeStart(ctx);
super.channelActive(ctx);
}
@Override
public void handlerRemoved0(ChannelHandlerContext ctx) throws Exception {
+ logger.finest("TsiHandshakeHandler handler removed");
close();
super.handlerRemoved0(ctx);
}
@Override
public void exceptionCaught(ChannelHandlerContext ctx, Throwable cause) throws Exception {
+ logger.log(Level.FINEST, "Exception in TsiHandshakeHandler", cause);
ctx.fireUserEventTriggered(new TsiHandshakeCompletionEvent(cause));
super.exceptionCaught(ctx, cause);
}
