-
Task
-
Resolution: Done
-
Major
-
None
-
None
-
False
-
None
-
False
The log snippet is
2022-04-07 09:58:18,121 INFO [io.deb.uti.Threads] (debezium-postgresconnector-testc-change-event-source-coordinator) Creating thread debezium-postgresconnector-testc-keep-alive 2022-04-07 09:58:18,146 INFO [io.deb.con.pos.PostgresSchema] (debezium-postgresconnector-testc-change-event-source-coordinator) REPLICA IDENTITY for 'inventory.customers' is 'FULL'; UPDATE AND DELETE events will contain the previous values of all the columns 2022-04-07 09:58:18,147 INFO [io.deb.con.pos.PostgresSchema] (debezium-postgresconnector-testc-change-event-source-coordinator) REPLICA IDENTITY for 'inventory.redis_test2' is 'DEFAULT'; UPDATE and DELETE events will contain previous values only for PK columns 2022-04-07 09:58:18,150 INFO [io.deb.con.pos.PostgresStreamingChangeEventSource] (debezium-postgresconnector-testc-change-event-source-coordinator) Searching for WAL resume position Entries in testc.inventory.redis_test2:22 2022-04-07 09:58:18,390 WARN [io.deb.ser.red.RedisStreamChangeConsumer] (pool-7-thread-1) Redis runs OOM, 28 command(s) failed 2022-04-07 09:58:18,992 WARN [io.deb.ser.red.RedisStreamChangeConsumer] (pool-7-thread-1) Redis runs OOM, 28 command(s) failed Pausing container Creating new redis_test table and inserting 5 records to it 2022-04-07 09:58:20,374 INFO [io.deb.jdb.JdbcConnection] (pool-3-thread-1) Connection gracefully closed Sleeping for 5 seconds to simulate no connection errors 2022-04-07 09:58:20,695 INFO [io.deb.con.pos.con.WalPositionLocator] (debezium-postgresconnector-testc-change-event-source-coordinator) First LSN 'LSN{0/2295E60}' received 2022-04-07 09:58:20,696 INFO [io.deb.con.pos.PostgresStreamingChangeEventSource] (debezium-postgresconnector-testc-change-event-source-coordinator) WAL resume position 'LSN{0/2295E60}' discovered 2022-04-07 09:58:20,699 INFO [io.deb.jdb.JdbcConnection] (pool-9-thread-1) Connection gracefully closed 2022-04-07 09:58:20,724 INFO [io.deb.uti.Threads] (debezium-postgresconnector-testc-change-event-source-coordinator) Requested thread factory for connector PostgresConnector, id = testc named = keep-alive 2022-04-07 09:58:20,725 INFO [io.deb.uti.Threads] (debezium-postgresconnector-testc-change-event-source-coordinator) Creating thread debezium-postgresconnector-testc-keep-alive 2022-04-07 09:58:20,735 INFO [io.deb.con.pos.PostgresStreamingChangeEventSource] (debezium-postgresconnector-testc-change-event-source-coordinator) Processing messages 2022-04-07 09:58:20,736 INFO [io.deb.con.pos.con.WalPositionLocator] (debezium-postgresconnector-testc-change-event-source-coordinator) Message with LSN 'LSN{0/2295E60}' arrived, switching off the filtering 2022-04-07 09:58:23,209 ERROR [io.deb.ser.red.RedisStreamChangeConsumer] (pool-7-thread-1) Connection error: redis.clients.jedis.exceptions.JedisConnectionException: java.net.SocketTimeoutException: Read timed out at redis.clients.jedis.util.RedisInputStream.ensureFill(RedisInputStream.java:204) at redis.clients.jedis.util.RedisInputStream.readByte(RedisInputStream.java:42) at redis.clients.jedis.Protocol.process(Protocol.java:126) at redis.clients.jedis.Protocol.read(Protocol.java:192) at redis.clients.jedis.Connection.readProtocolWithCheckingBroken(Connection.java:316) at redis.clients.jedis.Connection.getMany(Connection.java:328) at redis.clients.jedis.Pipeline.syncAndReturnAll(Pipeline.java:81) at io.debezium.server.redis.RedisStreamChangeConsumer.lambda$handleBatch$1(RedisStreamChangeConsumer.java:164) at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) at java.base/java.util.stream.IntPipeline$1$1.accept(IntPipeline.java:180) at java.base/java.util.stream.Streams$RangeIntSpliterator.forEachRemaining(Streams.java:104) at java.base/java.util.Spliterator$OfInt.forEachRemaining(Spliterator.java:711) at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) at io.debezium.server.redis.RedisStreamChangeConsumer.handleBatch(RedisStreamChangeConsumer.java:127) at io.debezium.embedded.ConvertingEngineBuilder.lambda$notifying$2(ConvertingEngineBuilder.java:83) at io.debezium.embedded.EmbeddedEngine.run(EmbeddedEngine.java:821) at io.debezium.embedded.ConvertingEngineBuilder$2.run(ConvertingEngineBuilder.java:192) at io.debezium.server.DebeziumServer.lambda$start$1(DebeziumServer.java:150) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) Caused by: java.net.SocketTimeoutException: Read timed out at java.base/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:283) at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:309) at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350) at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803) at java.base/java.net.Socket$SocketInputStream.read(Socket.java:966) at java.base/java.io.InputStream.read(InputStream.java:218) at redis.clients.jedis.util.RedisInputStream.ensureFill(RedisInputStream.java:198) ... 25 more Unpausing container 2022-04-07 09:58:25,396 INFO [io.deb.ser.red.RedisConnection] (pool-7-thread-1) Using Jedis 'Jedis{Connection{DefaultJedisSocketFactory{localhost:49188}}}' Error: Tests run: 3, Failures: 0, Errors: 1, Skipped: 0, Time elapsed: 77.481 s <<< FAILURE! - in io.debezium.server.redis.RedisStreamIT Error: io.debezium.server.redis.RedisStreamIT.testRedisConnectionRetry Time elapsed: 65.15 s <<< ERROR! org.awaitility.core.ConditionTimeoutException: Condition with io.debezium.server.redis.RedisStreamIT was not fulfilled within 1 minutes. at io.debezium.server.redis.RedisStreamIT.getStreamLength(RedisStreamIT.java:51) at io.debezium.server.redis.RedisStreamIT.testRedisConnectionRetry(RedisStreamIT.java:104) [INFO] Running io.debezium.server.redis.RedisOffsetIT
The PR https://github.com/debezium/debezium/pull/3367 tried but failed to reproduce the issue.