Skip to content

Commit

Permalink
CommandHandler notifications called out of order #315
Browse files Browse the repository at this point in the history 
Discard out-of-order events for disconnected/reconnected connections if inactive/unregister events arrive after register/active events of a reconnect. Allocate temporary buffer upon channel-handler initialization and do not remove the buffer until the channel is closed.
  • Loading branch information
@mp911de
mp911de committed Jul 24, 2016
1 parent d52e141 commit cc9a259
Show file tree
Hide file tree
Showing 2 changed files with 68 additions and 22 deletions.
6 changes: 5 additions & 1 deletion src/main/java/com/lambdaworks/redis/protocol/ChannelLogDescriptor.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -23,7 +23,11 @@ static String logDescriptor(Channel channel) {
}

if (!channel.isActive()) {
buffer.append(" (inactive)");
if(buffer.length() != 0){
buffer.append(' ');
}

buffer.append("(inactive)");
}

return buffer.toString();
Expand Down
84 changes: 63 additions & 21 deletions src/main/java/com/lambdaworks/redis/protocol/CommandHandler.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
import java.nio.channels.ClosedChannelException;
import java.nio.charset.Charset;
import java.util.*;
import java.util.concurrent.atomic.AtomicLong;
import java.util.concurrent.locks.ReentrantLock;

import com.google.common.collect.ImmutableList;
Expand All @@ -22,6 +23,7 @@
import com.lambdaworks.redis.resource.ClientResources;

import io.netty.buffer.ByteBuf;
import io.netty.buffer.ByteBufAllocator;
import io.netty.channel.Channel;
import io.netty.channel.ChannelDuplexHandler;
import io.netty.channel.ChannelFuture;
Expand All @@ -48,6 +50,7 @@ public class CommandHandler<K, V> extends ChannelDuplexHandler implements RedisC

private static final InternalLogger logger = InternalLoggerFactory.getInstance(CommandHandler.class);
private static final WriteLogListener WRITE_LOG_LISTENER = new WriteLogListener();
private static final AtomicLong CHANNEL_COUNTER = new AtomicLong();

/**
* When we encounter an unexpected IOException we look for these {@link Throwable#getMessage() messages} (because we have no
Expand All @@ -57,6 +60,7 @@ public class CommandHandler<K, V> extends ChannelDuplexHandler implements RedisC
private static final Set<String> SUPPRESS_IO_EXCEPTION_MESSAGES = ImmutableSet.of("Connection reset by peer", "Broken pipe",
"Connection timed out");

protected final long commandHandlerId = CHANNEL_COUNTER.incrementAndGet();
protected final ClientOptions clientOptions;
protected final ClientResources clientResources;
protected final Queue<RedisCommand<K, V, ?>> queue;
Expand All @@ -65,9 +69,9 @@ public class CommandHandler<K, V> extends ChannelDuplexHandler implements RedisC
// all access to the commandBuffer is synchronized
protected volatile Deque<RedisCommand<K, V, ?>> commandBuffer = newCommandBuffer();
protected final Deque<RedisCommand<K, V, ?>> transportBuffer = newCommandBuffer();
protected ByteBuf buffer;
protected RedisStateMachine<K, V> rsm;
protected Channel channel;
protected final ByteBuf buffer = ByteBufAllocator.DEFAULT.directBuffer(8192 * 8);
protected final RedisStateMachine<K, V> rsm = new RedisStateMachine<K, V>();
protected volatile Channel channel;
private volatile ConnectionWatchdog connectionWatchdog;

// If TRACE level logging has been enabled at startup.
Expand Down Expand Up @@ -111,24 +115,45 @@ public CommandHandler(ClientOptions clientOptions, ClientResources clientResourc
*/
@Override
public void channelRegistered(ChannelHandlerContext ctx) throws Exception {
setState(LifecycleState.REGISTERED);
buffer = ctx.alloc().directBuffer(8192 * 8);
rsm = new RedisStateMachine<K, V>();

synchronized (stateLock) {
channel = ctx.channel();
}

if (debugEnabled) {
logPrefix = null;
logger.debug("{} channelRegistered()", logPrefix());
}

setState(LifecycleState.REGISTERED);

if(buffer.refCnt() > 0) {
buffer.clear();
}
ctx.fireChannelRegistered();
}

@Override
public void channelUnregistered(ChannelHandlerContext ctx) throws Exception {
releaseBuffer();

if (debugEnabled) {
logger.debug("{} channelUnregistered()", logPrefix());
}

if (channel != null && ctx.channel() != channel) {
logger.debug("{} My channel and ctx.channel mismatch. Propagating event to other listeners", logPrefix());
ctx.fireChannelUnregistered();
return;
}

if (lifecycleState == LifecycleState.CLOSED) {
cancelCommands("Connection closed");
}
synchronized (stateLock) {
channel = null;
}

ctx.fireChannelUnregistered();
}

/**
Expand All @@ -139,15 +164,30 @@ public void channelUnregistered(ChannelHandlerContext ctx) throws Exception {
public void channelRead(ChannelHandlerContext ctx, Object msg) throws Exception {
ByteBuf input = (ByteBuf) msg;

if (!input.isReadable() || input.refCnt() == 0 || buffer == null) {
if (!input.isReadable() || input.refCnt() == 0) {
logger.warn("{} Input not readable {}, {}", logPrefix(), input.isReadable(), input.refCnt());
return;
}

if(debugEnabled) {
logger.debug("{} Received: {} bytes, {} queued commands", logPrefix(), input.readableBytes(), queue.size());
}

try {
if (buffer.refCnt() < 1) {
logger.warn("{} Ignoring received data for closed or abandoned connection", logPrefix());
return;
}

if (debugEnabled && ctx.channel() != channel) {
logger.debug("{} Ignoring data for a non-registered channel {}", logPrefix(), ctx.channel());
return;
}

buffer.writeBytes(input);

if (traceEnabled) {
logger.trace("{} Received: {}", logPrefix(), buffer.toString(Charset.defaultCharset()).trim());
logger.trace("{} Buffer: {}", logPrefix(), input.toString(Charset.defaultCharset()).trim());
}

decode(ctx, buffer);
Expand Down Expand Up @@ -181,7 +221,7 @@ protected void decode(ChannelHandlerContext ctx, ByteBuf buffer) throws Interrup

command.complete();

if (buffer != null && buffer.refCnt() != 0) {
if (buffer.refCnt() != 0) {
buffer.discardReadBytes();
}
}
Expand Down Expand Up @@ -564,6 +604,12 @@ public void channelInactive(ChannelHandlerContext ctx) throws Exception {
logger.debug("{} channelInactive()", logPrefix());
}

if (channel != null && ctx.channel() != channel) {
logger.debug("{} My channel and ctx.channel mismatch. Propagating event to other listeners.", logPrefix());
super.channelInactive(ctx);
return;
}

try {
writeLock.lock();
setStateIfNotClosed(LifecycleState.DISCONNECTED);
Expand All @@ -589,10 +635,7 @@ public void channelInactive(ChannelHandlerContext ctx) throws Exception {
writeLock.unlock();
}

if (buffer != null) {
rsm.reset();
buffer.clear();
}
rsm.reset();

if (debugEnabled) {
logger.debug("{} channelInactive() done", logPrefix());
Expand Down Expand Up @@ -708,12 +751,9 @@ public void close() {
} else if (connectionWatchdog != null) {
connectionWatchdog.prepareClose(new ConnectionEvents.PrepareClose());
}
}

private void releaseBuffer() {
if (buffer != null) {
if (buffer.refCnt() > 0) {
buffer.release();
buffer = null;
}
}

Expand All @@ -737,8 +777,9 @@ public void reset() {
writeLock.unlock();
}

if (buffer != null) {
rsm.reset();
rsm.reset();

if (buffer.refCnt() > 0) {
buffer.clear();
}
}
Expand Down Expand Up @@ -777,7 +818,8 @@ protected String logPrefix() {
return logPrefix;
}
StringBuffer buffer = new StringBuffer(64);
buffer.append('[').append(ChannelLogDescriptor.logDescriptor(channel)).append(']');
buffer.append('[').append("chid=0x").append(Long.toHexString(commandHandlerId)).append(", ")
.append(ChannelLogDescriptor.logDescriptor(channel)).append(']');
return logPrefix = buffer.toString();
}

Expand Down

0 comments on commit cc9a259

Please sign in to comment.