alts: add debugging statements for ALTS

This commit is contained in:
Carl Mastrangelo 2018-12-11 16:44:51 -08:00 committed by GitHub
parent 94e7339748
commit 23dadaa85d
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
3 changed files with 58 additions and 12 deletions

View File

@ -34,6 +34,8 @@ import io.grpc.netty.ProtocolNegotiators.AbstractBufferingHandler;
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 @@ import io.netty.util.AsciiString;
*/
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 @@ public abstract class AltsProtocolNegotiator implements ProtocolNegotiator {
/** 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 @@ public abstract class AltsProtocolNegotiator implements ProtocolNegotiator {
// 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 @@ public abstract class AltsProtocolNegotiator implements ProtocolNegotiator {
@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 @@ public abstract class AltsProtocolNegotiator implements ProtocolNegotiator {
+ 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 @@ public abstract class AltsProtocolNegotiator implements ProtocolNegotiator {
.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()));
}
}

View File

@ -34,6 +34,8 @@ import java.security.GeneralSecurityException;
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 @@ import java.util.concurrent.Future;
*/
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 @@ public final class TsiFrameHandler extends ByteToMessageDecoder implements Chann
@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 @@ public final class TsiFrameHandler extends ByteToMessageDecoder implements Chann
@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 @@ public final class TsiFrameHandler extends ByteToMessageDecoder implements Chann
@VisibleForTesting
void setProtector(TsiFrameProtector protector) {
logger.finest("TsiFrameHandler protector set");
checkState(this.protector == null);
this.protector = checkNotNull(protector);
}
@ -95,7 +104,8 @@ public final class TsiFrameHandler extends ByteToMessageDecoder implements Chann
}
@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"));

View File

@ -19,6 +19,7 @@ package io.grpc.alts.internal;
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 io.netty.util.ReferenceCountUtil;
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 @@ import javax.annotation.Nullable;
* 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 @@ public final class TsiHandshakeHandler extends ByteToMessageDecoder {
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);
}