Unable to reconnect Pub/Sub connection with authorization

[maestroua]

Bug Report

We have application with publish subscribe connection to Redis. We encounter a problem, when using password - once connection is lost to Redis it can not be reestablished. In logs we see:

2018-09-26 17:50:35.276  INFO 19192 --- [xecutorLoop-1-2] i.l.c.p.ConnectionWatchdog               : Reconnecting, last destination was localhost:6379
2018-09-26 17:50:36.277  WARN 19192 --- [ioEventLoop-4-3] i.l.c.p.ConnectionWatchdog               : Cannot reconnect: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: no further information: localhost/127.0.0.1:6379
2018-09-26 17:50:36.277  WARN 19192 --- [ioEventLoop-4-4] i.l.c.p.ConnectionWatchdog               : Cannot reconnect: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: no further information: localhost/127.0.0.1:6379
2018-09-26 17:50:36.281  WARN 19192 --- [ioEventLoop-4-1] i.l.c.p.ConnectionWatchdog               : Cannot reconnect: io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: no further information: localhost/127.0.0.1:6379
2018-09-26 17:50:37.376  INFO 19192 --- [ioEventLoop-4-3] i.l.c.p.ReconnectionHandler              : Reconnected to localhost:6379
2018-09-26 17:50:37.375  WARN 19192 --- [ioEventLoop-4-2] i.l.c.p.CommandHandler                   : null Unexpected exception during request: io.lettuce.core.RedisException: Command AUTH not allowed while subscribed. Allowed commands are: [PSUBSCRIBE, QUIT, PUNSUBSCRIBE, SUBSCRIBE, UNSUBSCRIBE]

io.lettuce.core.RedisException: Command AUTH not allowed while subscribed. Allowed commands are: [PSUBSCRIBE, QUIT, PUNSUBSCRIBE, SUBSCRIBE, UNSUBSCRIBE]
	at io.lettuce.core.pubsub.PubSubEndpoint.write(PubSubEndpoint.java:103) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.lettuce.core.RedisChannelHandler.dispatch(RedisChannelHandler.java:185) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.lettuce.core.StatefulRedisConnectionImpl.dispatch(StatefulRedisConnectionImpl.java:152) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.lettuce.core.AbstractRedisAsyncCommands.dispatch(AbstractRedisAsyncCommands.java:466) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.lettuce.core.AbstractRedisAsyncCommands.authAsync(AbstractRedisAsyncCommands.java:85) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.lettuce.core.StatefulRedisConnectionImpl.activated(StatefulRedisConnectionImpl.java:130) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.lettuce.core.pubsub.StatefulRedisPubSubConnectionImpl.activated(StatefulRedisPubSubConnectionImpl.java:143) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.lettuce.core.protocol.DefaultEndpoint.lambda$notifyChannelActive$0(DefaultEndpoint.java:379) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.lettuce.core.protocol.SharedLock.lambda$doExclusive$0(SharedLock.java:82) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.lettuce.core.protocol.SharedLock.doExclusive(SharedLock.java:103) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.lettuce.core.protocol.SharedLock.doExclusive(SharedLock.java:81) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.lettuce.core.protocol.DefaultEndpoint.notifyChannelActive(DefaultEndpoint.java:363) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.lettuce.core.protocol.CommandHandler.channelActive(CommandHandler.java:269) ~[lettuce-core-5.1.0.RELEASE.jar:?]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:213) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:199) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelActive(AbstractChannelHandlerContext.java:192) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.ChannelInboundHandlerAdapter.channelActive(ChannelInboundHandlerAdapter.java:64) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.lettuce.core.ChannelGroupListener.channelActive(ChannelGroupListener.java:40) [lettuce-core-5.1.0.RELEASE.jar:?]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:213) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:199) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelActive(AbstractChannelHandlerContext.java:192) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.ChannelInboundHandlerAdapter.channelActive(ChannelInboundHandlerAdapter.java:64) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.lettuce.core.PlainChannelInitializer$1.channelActive(PlainChannelInitializer.java:109) [lettuce-core-5.1.0.RELEASE.jar:?]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:213) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:199) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.AbstractChannelHandlerContext.fireChannelActive(AbstractChannelHandlerContext.java:192) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.DefaultChannelPipeline$HeadContext.channelActive(DefaultChannelPipeline.java:1322) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:213) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:199) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.DefaultChannelPipeline.fireChannelActive(DefaultChannelPipeline.java:902) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.fulfillConnectPromise(AbstractNioChannel.java:311) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:341) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:632) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:579) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:496) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:458) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858) [netty-all-4.1.13.Final.jar:4.1.13.Final]
	at io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138) [netty-all-4.1.13.Final.jar:4.1.13.Final]

And stack trace is repeating once a 1 minute.
Looks like statefull connection once entering "Subscribed" state no longer allow AUTH command, even if actual network connection was reestablished and it's required to authenticate again.

Current Behavior

1. Connect PubSub to Redis with password
2. Restart Redis Server
3. Pub sub no longer available

Expected behavior/code

Connections is restored with all previous subscriptions.

Environment

• Lettuce version(s): 5.1.0.RELEASE
• Redis version: any

Possible Solution

Allow "AUTH" and "SELECT" commands during reconnect.

[mp911de]

Lettuce itself prevents the execution of commands when it determines a subscribed state. We didn't consider in #579 that the connection is in a pristine state after reconnecting. We need to fix that in 5.1.1 and 4.5.1.

[mp911de]

That's fixed now.