I have an application that is using the lpush command to push some data to a queue, another application is constantly polling that queue to look for elements, if it finds one (using brpop), it will process it and return the data via publishing to a channel the first app is subscribed to.
This works fine 99% of the time, but I'm testing something where the second application will take a minute or two to process between brpopping and publishing the result to a channel the first application is subscribed to, and whenever the first app receives the message, instead of processing it normally, it looks to trigger a channelInactive() command, and it disconnects/reconnects instead
Here are the DEBUG logs of what I am describing:
2024-01-18T09:12:10.937+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] io.lettuce.core.AbstractRedisClient : Connecting to Redis at localhost/<unresolved>:6380: Success
2024-01-18T09:12:10.959+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] io.lettuce.core.RedisChannelHandler : dispatching command SubscriptionCommand [type=SUBSCRIBE, output=PubSubOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.961+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380, epid=0x3] write() writeAndFlush command SubscriptionCommand [type=SUBSCRIBE, output=PubSubOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.961+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.CommandHandler : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380, epid=0x3, chid=0x3] write(ctx, SubscriptionCommand [type=SUBSCRIBE, output=PubSubOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command], promise)
2024-01-18T09:12:10.961+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.CommandEncoder : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380] writing command SubscriptionCommand [type=SUBSCRIBE, output=PubSubOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.962+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380, epid=0x3] write() done
2024-01-18T09:12:10.962+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.CommandHandler : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380, epid=0x3, chid=0x3] Received: 88 bytes, 1 commands in the stack
2024-01-18T09:12:10.963+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.l.core.protocol.RedisStateMachine : Decode done, empty stack: true
2024-01-18T09:12:10.966+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] a.c.c.s.service.SignalCoverageService : Publishing 4 requests for signal coverage
2024-01-18T09:12:10.966+10:30 INFO 1445575 --- [ioEventLoop-4-2] a.c.c.s.redis.RedisTaskQueueClient : Enqueueing 4 jobs to signal-coverage-tasks
2024-01-18T09:12:10.970+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] io.lettuce.core.RedisChannelHandler : dispatching command SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.970+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2] write() writeAndFlush command SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.970+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2] write() done
2024-01-18T09:12:10.970+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] write(ctx, SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command], promise)
2024-01-18T09:12:10.971+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandEncoder : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380] writing command SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.971+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] Received: 4 bytes, 1 commands in the stack
2024-01-18T09:12:10.972+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] Stack contains: 1 commands
2024-01-18T09:12:10.972+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.l.core.protocol.RedisStateMachine : Decode done, empty stack: true
2024-01-18T09:12:10.972+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] Completing command LatencyMeteredCommand [type=LPUSH, output=IntegerOutput [output=1, error='null'], commandType=io.lettuce.core.RedisPublisher$SubscriptionCommand]
2024-01-18T09:12:10.972+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] io.lettuce.core.RedisChannelHandler : dispatching command SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.972+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2] write() writeAndFlush command SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.972+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2] write() done
2024-01-18T09:12:10.972+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] write(ctx, SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command], promise)
2024-01-18T09:12:10.973+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandEncoder : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380] writing command SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.973+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] Received: 4 bytes, 1 commands in the stack
2024-01-18T09:12:10.973+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] Stack contains: 1 commands
2024-01-18T09:12:10.973+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.l.core.protocol.RedisStateMachine : Decode done, empty stack: true
2024-01-18T09:12:10.973+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] Completing command LatencyMeteredCommand [type=LPUSH, output=IntegerOutput [output=1, error='null'], commandType=io.lettuce.core.RedisPublisher$SubscriptionCommand]
2024-01-18T09:12:10.974+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] io.lettuce.core.RedisChannelHandler : dispatching command SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.974+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2] write() writeAndFlush command SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.974+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2] write() done
2024-01-18T09:12:10.974+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] write(ctx, SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command], promise)
2024-01-18T09:12:10.975+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandEncoder : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380] writing command SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.976+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] Received: 4 bytes, 1 commands in the stack
2024-01-18T09:12:10.976+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] Stack contains: 1 commands
2024-01-18T09:12:10.976+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.l.core.protocol.RedisStateMachine : Decode done, empty stack: true
2024-01-18T09:12:10.976+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] Completing command LatencyMeteredCommand [type=LPUSH, output=IntegerOutput [output=2, error='null'], commandType=io.lettuce.core.RedisPublisher$SubscriptionCommand]
2024-01-18T09:12:10.977+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] io.lettuce.core.RedisChannelHandler : dispatching command SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.977+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2] write() writeAndFlush command SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.977+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2] write() done
2024-01-18T09:12:10.977+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] write(ctx, SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command], promise)
2024-01-18T09:12:10.978+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandEncoder : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380] writing command SubscriptionCommand [type=LPUSH, output=IntegerOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:12:10.979+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] Received: 4 bytes, 1 commands in the stack
2024-01-18T09:12:10.979+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] Stack contains: 1 commands
2024-01-18T09:12:10.979+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.l.core.protocol.RedisStateMachine : Decode done, empty stack: true
2024-01-18T09:12:10.979+10:30 DEBUG 1445575 --- [oEventLoop-11-1] i.lettuce.core.protocol.CommandHandler : [channel=0x514c0a26, /127.0.0.1:42738 -> localhost/127.0.0.1:6380, epid=0x2, chid=0x2] Completing command LatencyMeteredCommand [type=LPUSH, output=IntegerOutput [output=3, error='null'], commandType=io.lettuce.core.RedisPublisher$SubscriptionCommand]
2024-01-18T09:12:46.142+10:30 DEBUG 1445575 --- [alina-utility-1] o.apache.catalina.session.ManagerBase : Start expire sessions StandardManager at 1705531366139 sessioncount 0
2024-01-18T09:12:46.142+10:30 DEBUG 1445575 --- [alina-utility-1] o.apache.catalina.session.ManagerBase : End expire sessions StandardManager processingTime 3 expired sessions: 0
2024-01-18T09:13:46.143+10:30 DEBUG 1445575 --- [alina-utility-1] o.apache.catalina.session.ManagerBase : Start expire sessions StandardManager at 1705531426143 sessioncount 0
2024-01-18T09:13:46.144+10:30 DEBUG 1445575 --- [alina-utility-1] o.apache.catalina.session.ManagerBase : End expire sessions StandardManager processingTime 1 expired sessions: 0
2024-01-18T09:14:16.465+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.CommandHandler : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380, epid=0x3, chid=0x3] channelInactive()
2024-01-18T09:14:16.465+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380, epid=0x3] deactivating endpoint handler
2024-01-18T09:14:16.465+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380, epid=0x3] notifyQueuedCommands adding 0 command(s) to buffer
2024-01-18T09:14:16.465+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.CommandHandler : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380, epid=0x3, chid=0x3] channelInactive() done
2024-01-18T09:14:16.466+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.l.core.protocol.ConnectionWatchdog : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380, last known addr=localhost/127.0.0.1:6380] channelInactive()
2024-01-18T09:14:16.466+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.l.core.protocol.ConnectionWatchdog : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380, last known addr=localhost/127.0.0.1:6380] scheduleReconnect()
2024-01-18T09:14:16.466+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.l.core.protocol.ConnectionWatchdog : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380, last known addr=localhost/127.0.0.1:6380] Reconnect attempt 1, delay 1ms
2024-01-18T09:14:16.467+10:30 DEBUG 1445575 --- [ioEventLoop-4-2] i.lettuce.core.protocol.CommandHandler : [channel=0x7cbad421, /127.0.0.1:43666 -> localhost/127.0.0.1:6380, epid=0x3, chid=0x3] channelUnregistered()
2024-01-18T09:14:16.482+10:30 INFO 1445575 --- [xecutorLoop-1-3] i.l.core.protocol.ConnectionWatchdog : Reconnecting, last destination was localhost/127.0.0.1:6380
2024-01-18T09:14:16.483+10:30 DEBUG 1445575 --- [xecutorLoop-1-3] io.lettuce.core.RedisClient : Resolved SocketAddress localhost/<unresolved>:6380 using redis://localhost:6380?timeout=20000s
2024-01-18T09:14:16.484+10:30 DEBUG 1445575 --- [xecutorLoop-1-3] i.l.core.protocol.ReconnectionHandler : Reconnecting to Redis at localhost/<unresolved>:6380
2024-01-18T09:14:16.485+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.CommandHandler : [channel=0x7107845d, [id: 0xa38b646c] (inactive), epid=0x3, chid=0x4] channelRegistered()
2024-01-18T09:14:16.488+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.CommandHandler : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3, chid=0x4] write(ctx, AsyncCommand [type=HELLO, output=GenericMapOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command], promise)
2024-01-18T09:14:16.488+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.CommandEncoder : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380] writing command AsyncCommand [type=HELLO, output=GenericMapOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:14:16.489+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.CommandHandler : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3, chid=0x4] Received: 146 bytes, 1 commands in the stack
2024-01-18T09:14:16.489+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.CommandHandler : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3, chid=0x4] Stack contains: 1 commands
2024-01-18T09:14:16.489+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.l.core.protocol.RedisStateMachine : Decode done, empty stack: true
2024-01-18T09:14:16.490+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.CommandHandler : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3, chid=0x4] Completing command LatencyMeteredCommand [type=HELLO, output=GenericMapOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.AsyncCommand]
2024-01-18T09:14:16.490+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.CommandHandler : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3, chid=0x4] channelActive()
2024-01-18T09:14:16.490+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3] activateEndpointAndExecuteBufferedCommands 0 command(s) buffered
2024-01-18T09:14:16.490+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3] activating endpoint
2024-01-18T09:14:16.490+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] io.lettuce.core.RedisChannelHandler : dispatching command AsyncCommand [type=SUBSCRIBE, output=PubSubOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.Command]
2024-01-18T09:14:16.491+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3] write() writeAndFlush command ActivationCommand [type=SUBSCRIBE, output=PubSubOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.AsyncCommand]
2024-01-18T09:14:16.491+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.CommandHandler : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3, chid=0x4] write(ctx, ActivationCommand [type=SUBSCRIBE, output=PubSubOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.AsyncCommand], promise)
2024-01-18T09:14:16.491+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.CommandEncoder : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380] writing command ActivationCommand [type=SUBSCRIBE, output=PubSubOutput [output=null, error='null'], commandType=io.lettuce.core.protocol.AsyncCommand]
2024-01-18T09:14:16.491+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3] write() done
2024-01-18T09:14:16.492+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3] flushCommands()
2024-01-18T09:14:16.492+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.DefaultEndpoint : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3] flushCommands() Flushing 0 commands
2024-01-18T09:14:16.492+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.l.core.protocol.ConnectionWatchdog : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, last known addr=localhost/127.0.0.1:6380] channelActive()
2024-01-18T09:14:16.492+10:30 DEBUG 1445575 --- [ioEventLoop-4-3] i.lettuce.core.protocol.CommandHandler : [channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380, epid=0x3, chid=0x4] channelActive() done
2024-01-18T09:14:16.492+10:30 INFO 1445575 --- [ioEventLoop-4-3] i.l.core.protocol.ReconnectionHandler : Reconnected to localhost/<unresolved>:6380, Channel channel=0x7107845d, /127.0.0.1:43376 -> localhost/127.0.0.1:6380
The application receives (or attempts to receive) the published message, judging by the logs, at 2024-01-18T09:16:12.558+10:30 DEBUG 1445575 , but instead of receiving the message is deems the channel is inactive and does the disconnect/reconnect behaviour I described
Is there a way to configure Redis to not do this? I've tried all the obvious things like setting timeout options, tcp keepalive, etc, e.g. here is my config where I'm trying to throw everything at the wall to see if something sticks and fixes my issue
public void connect() {
LOGGER.info("Attempting connection to Redis @ {}:{}", config.getHost(), config.getPort());
NettyCustomizer nettyCustomizer = new NettyCustomizer() {
@Override
public void afterBootstrapInitialized(Bootstrap bootstrap) {
LOGGER.info("Bootstrapped");
NettyCustomizer.super.afterBootstrapInitialized(bootstrap);
}
@Override
public void afterChannelInitialized(Channel channel) {
channel.config().setOption(ChannelOption.SO_KEEPALIVE, true);
channel.config().setOption(ChannelOption.SO_TIMEOUT, 100000000);
channel.config().setConnectTimeoutMillis(100000000);
SocketChannelConfig cfg = (SocketChannelConfig) channel.config();
cfg.setKeepAlive(true);
cfg.setAutoClose(false);
LOGGER.info("Channel initialized.");
}
};
ClientResources clientResources = ClientResources.builder()
.nettyCustomizer(nettyCustomizer)
.build();
RedisURI uri = RedisURI.create(config.getHost(), config.getPort());
uri.setTimeout(Duration.ofSeconds(100000));
client = RedisClient.create(clientResources, uri);
client.setOptions(ClientOptions.builder()
.timeoutOptions(TimeoutOptions.builder()
.fixedTimeout(Duration.ofSeconds(100000))
.timeoutCommands(false)
.build())
.socketOptions(SocketOptions.builder()
.keepAlive(true)
.connectTimeout(Duration.ofSeconds(100000))
.build())
.build());
connection = client.connect();
this.host = config.getHost();
this.port = config.getPort();
}