I implement reading from AWS/Kinesis stream using KCL, but after read many messages from shards, suddenly i see this error in server logs:
ERROR 1 --- [oordinator-0000] c.a.s.kinesis.leases.impl.LeaseRenewer : Encountered an exception while renewing a lease.
java.lang.IllegalStateException: Connection pool shut down
at org.apache.http.util.Asserts.check(Asserts.java:34) ~[httpcore-4.4.14.jar:4.4.14]
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.requestConnection(PoolingHttpClientConnectionManager.java:269) ~[httpclient-4.5.13.jar:4.5.13]
at jdk.internal.reflect.GeneratedMethodAccessor61.invoke(Unknown Source) ~[na:na]
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na]
at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]
at com.amazonaws.http.conn.ClientConnectionManagerFactory$Handler.invoke(ClientConnectionManagerFactory.java:76) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.conn.$Proxy87.requestConnection(Unknown Source) ~[na:na]
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:176) ~[httpclient-4.5.13.jar:4.5.13]
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186) ~[httpclient-4.5.13.jar:4.5.13]
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) ~[httpclient-4.5.13.jar:4.5.13]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) ~[httpclient-4.5.13.jar:4.5.13]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) ~[httpclient-4.5.13.jar:4.5.13]
at com.amazonaws.http.apache.client.impl.SdkHttpClient.execute(SdkHttpClient.java:72) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeOneRequest(AmazonHttpClient.java:1346) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeHelper(AmazonHttpClient.java:1157) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.doExecute(AmazonHttpClient.java:814) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeWithTimer(AmazonHttpClient.java:781) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.execute(AmazonHttpClient.java:755) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.access$500(AmazonHttpClient.java:715) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutionBuilderImpl.execute(AmazonHttpClient.java:697) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:561) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:541) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.services.dynamodbv2.AmazonDynamoDBClient.doInvoke(AmazonDynamoDBClient.java:6409) ~[aws-java-sdk-dynamodb-1.12.300.jar:na]
at com.amazonaws.services.dynamodbv2.AmazonDynamoDBClient.invoke(AmazonDynamoDBClient.java:6376) ~[aws-java-sdk-dynamodb-1.12.300.jar:na]
at com.amazonaws.services.dynamodbv2.AmazonDynamoDBClient.executeUpdateItem(AmazonDynamoDBClient.java:5994) ~[aws-java-sdk-dynamodb-1.12.300.jar:na]
at com.amazonaws.services.dynamodbv2.AmazonDynamoDBClient.updateItem(AmazonDynamoDBClient.java:5958) ~[aws-java-sdk-dynamodb-1.12.300.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseManager.renewLease(LeaseManager.java:419) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseRenewer.renewLease(LeaseRenewer.java:176) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseRenewer.renewLease(LeaseRenewer.java:159) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseRenewer.access$000(LeaseRenewer.java:49) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseRenewer$RenewLeaseTask.call(LeaseRenewer.java:151) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseRenewer$RenewLeaseTask.call(LeaseRenewer.java:137) ~[amazon-kinesis-client-1.14.8.jar:na]
at java.base/java.util.concurrent.FutureTask.run(Unknown Source) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na]
at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
2022-11-14 01:31:52.777 ERROR 1 --- [oordinator-0000] c.a.s.kinesis.leases.impl.LeaseRenewer : Encountered an exception while renewing a lease.
java.lang.IllegalStateException: Connection pool shut down
at org.apache.http.util.Asserts.check(Asserts.java:34) ~[httpcore-4.4.14.jar:4.4.14]
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.requestConnection(PoolingHttpClientConnectionManager.java:269) ~[httpclient-4.5.13.jar:4.5.13]
at jdk.internal.reflect.GeneratedMethodAccessor61.invoke(Unknown Source) ~[na:na]
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[na:na]
at java.base/java.lang.reflect.Method.invoke(Unknown Source) ~[na:na]
at com.amazonaws.http.conn.ClientConnectionManagerFactory$Handler.invoke(ClientConnectionManagerFactory.java:76) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.conn.$Proxy87.requestConnection(Unknown Source) ~[na:na]
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:176) ~[httpclient-4.5.13.jar:4.5.13]
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186) ~[httpclient-4.5.13.jar:4.5.13]
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) ~[httpclient-4.5.13.jar:4.5.13]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) ~[httpclient-4.5.13.jar:4.5.13]
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) ~[httpclient-4.5.13.jar:4.5.13]
at com.amazonaws.http.apache.client.impl.SdkHttpClient.execute(SdkHttpClient.java:72) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeOneRequest(AmazonHttpClient.java:1346) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeHelper(AmazonHttpClient.java:1157) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.doExecute(AmazonHttpClient.java:814) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.executeWithTimer(AmazonHttpClient.java:781) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.execute(AmazonHttpClient.java:755) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutor.access$500(AmazonHttpClient.java:715) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient$RequestExecutionBuilderImpl.execute(AmazonHttpClient.java:697) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:561) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.http.AmazonHttpClient.execute(AmazonHttpClient.java:541) ~[aws-java-sdk-core-1.12.300.jar:na]
at com.amazonaws.services.dynamodbv2.AmazonDynamoDBClient.doInvoke(AmazonDynamoDBClient.java:6409) ~[aws-java-sdk-dynamodb-1.12.300.jar:na]
at com.amazonaws.services.dynamodbv2.AmazonDynamoDBClient.invoke(AmazonDynamoDBClient.java:6376) ~[aws-java-sdk-dynamodb-1.12.300.jar:na]
at com.amazonaws.services.dynamodbv2.AmazonDynamoDBClient.executeUpdateItem(AmazonDynamoDBClient.java:5994) ~[aws-java-sdk-dynamodb-1.12.300.jar:na]
at com.amazonaws.services.dynamodbv2.AmazonDynamoDBClient.updateItem(AmazonDynamoDBClient.java:5958) ~[aws-java-sdk-dynamodb-1.12.300.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseManager.renewLease(LeaseManager.java:419) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseRenewer.renewLease(LeaseRenewer.java:176) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseRenewer.renewLease(LeaseRenewer.java:159) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseRenewer.access$000(LeaseRenewer.java:49) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseRenewer$RenewLeaseTask.call(LeaseRenewer.java:151) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseRenewer$RenewLeaseTask.call(LeaseRenewer.java:137) ~[amazon-kinesis-client-1.14.8.jar:na]
at java.base/java.util.concurrent.FutureTask.run(Unknown Source) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na]
at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
then server back to read messages again, and after reading about 10 messages i see this log again:
ERROR 1 --- [oordinator-0000] c.a.s.k.leases.impl.LeaseCoordinator : LeasingException encountered in lease renewing thread
com.amazonaws.services.kinesis.leases.exceptions.DependencyException: Encountered an exception while renewing leases. The number of leases which might not have been renewed is 334
at com.amazonaws.services.kinesis.leases.impl.LeaseRenewer.renewLeases(LeaseRenewer.java:130) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseCoordinator.runRenewer(LeaseCoordinator.java:350) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseCoordinator$RenewerRunnable.run(LeaseCoordinator.java:274) ~[amazon-kinesis-client-1.14.8.jar:na]
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source) ~[na:na]
at java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source) ~[na:na]
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) ~[na:na]
at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
Caused by: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Connection pool shut down
at java.base/java.util.concurrent.FutureTask.report(Unknown Source) ~[na:na]
at java.base/java.util.concurrent.FutureTask.get(Unknown Source) ~[na:na]
at com.amazonaws.services.kinesis.leases.impl.LeaseRenewer.renewLeases(LeaseRenewer.java:111) ~[amazon-kinesis-client-1.14.8.jar:na]
... 8 common frames omitted
And the final log is next log before server run out of memory and shutdown directly after getting heap memory exception:
INFO 1 --- [skExecutor-9401] k.c.l.w.KinesisClientLibLeaseCoordinator : Worker 659d8b25-2067-4a40-b0df-1fdb0b2979bf could not update checkpoint for shard shardId-000000001060 because it does not hold the lease
2022-11-14 01:31:52.791 INFO 1 --- [skExecutor-9307] s.i.a.i.k.KclMessageDrivenChannelAdapter : Caught shutdown exception, skipping checkpoint.
com.amazonaws.services.kinesis.clientlibrary.exceptions.ShutdownException: Can't update checkpoint - instance doesn't hold the lease for this shard
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.KinesisClientLibLeaseCoordinator.setCheckpoint(KinesisClientLibLeaseCoordinator.java:198) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.RecordProcessorCheckpointer.advancePosition(RecordProcessorCheckpointer.java:307) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.RecordProcessorCheckpointer.checkpoint(RecordProcessorCheckpointer.java:85) ~[amazon-kinesis-client-1.14.8.jar:na]
at org.springframework.integration.aws.inbound.kinesis.KclMessageDrivenChannelAdapter$RecordProcessor.checkpoint(KclMessageDrivenChannelAdapter.java:551) ~[spring-integration-aws-2.4.0.jar:na]
at org.springframework.integration.aws.inbound.kinesis.KclMessageDrivenChannelAdapter$RecordProcessor.checkpointIfBatchMode(KclMessageDrivenChannelAdapter.java:573) ~[spring-integration-aws-2.4.0.jar:na]
at org.springframework.integration.aws.inbound.kinesis.KclMessageDrivenChannelAdapter$RecordProcessor.processRecords(KclMessageDrivenChannelAdapter.java:427) ~[spring-integration-aws-2.4.0.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.V1ToV2RecordProcessorAdapter.processRecords(V1ToV2RecordProcessorAdapter.java:42) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.ProcessTask.callProcessRecords(ProcessTask.java:221) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.ProcessTask.call(ProcessTask.java:176) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.MetricsCollectingTaskDecorator.call(MetricsCollectingTaskDecorator.java:49) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.MetricsCollectingTaskDecorator.call(MetricsCollectingTaskDecorator.java:24) ~[amazon-kinesis-client-1.14.8.jar:na]
at java.base/java.util.concurrent.FutureTask.run(Unknown Source) ~[na:na]
at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
2022-11-14 01:31:52.791 INFO 1 --- [skExecutor-9401] s.i.a.i.k.KclMessageDrivenChannelAdapter : Caught shutdown exception, skipping checkpoint.
com.amazonaws.services.kinesis.clientlibrary.exceptions.ShutdownException: Can't update checkpoint - instance doesn't hold the lease for this shard
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.KinesisClientLibLeaseCoordinator.setCheckpoint(KinesisClientLibLeaseCoordinator.java:198) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.RecordProcessorCheckpointer.advancePosition(RecordProcessorCheckpointer.java:307) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.RecordProcessorCheckpointer.checkpoint(RecordProcessorCheckpointer.java:85) ~[amazon-kinesis-client-1.14.8.jar:na]
at org.springframework.integration.aws.inbound.kinesis.KclMessageDrivenChannelAdapter$RecordProcessor.checkpoint(KclMessageDrivenChannelAdapter.java:551) ~[spring-integration-aws-2.4.0.jar:na]
at org.springframework.integration.aws.inbound.kinesis.KclMessageDrivenChannelAdapter$RecordProcessor.checkpointIfBatchMode(KclMessageDrivenChannelAdapter.java:573) ~[spring-integration-aws-2.4.0.jar:na]
at org.springframework.integration.aws.inbound.kinesis.KclMessageDrivenChannelAdapter$RecordProcessor.processRecords(KclMessageDrivenChannelAdapter.java:427) ~[spring-integration-aws-2.4.0.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.V1ToV2RecordProcessorAdapter.processRecords(V1ToV2RecordProcessorAdapter.java:42) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.ProcessTask.callProcessRecords(ProcessTask.java:221) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.ProcessTask.call(ProcessTask.java:176) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.MetricsCollectingTaskDecorator.call(MetricsCollectingTaskDecorator.java:49) ~[amazon-kinesis-client-1.14.8.jar:na]
at com.amazonaws.services.kinesis.clientlibrary.lib.worker.MetricsCollectingTaskDecorator.call(MetricsCollectingTaskDecorator.java:24) ~[amazon-kinesis-client-1.14.8.jar:na]
at java.base/java.util.concurrent.FutureTask.run(Unknown Source) ~[na:na]
at java.base/java.lang.Thread.run(Unknown Source) ~[na:na]
native Memory Tracking:
Total: reserved=5356493063, committed=4756977927
- Java Heap (reserved=4294967296, committed=4294967296)
(mmap: reserved=4294967296, committed=4294967296)
- Class (reserved=257082284, committed=68006828)
(classes #11596)
( instance classes #10884, array classes #712)
(malloc=1995692 #35200)
(mmap: reserved=255086592, committed=66011136)
( Metadata: )
( reserved=58720256, committed=57884672)
( used=56743912)
( free=1140760)
( waste=0 =0.00%)
( Class space:)
( reserved=196366336, committed=8126464)
( used=7488320)
( free=638144)
( waste=0 =0.00%)
- Thread (reserved=220970784, committed=20037408)
(thread #209)
(stack: reserved=219947008, committed=19013632)
(malloc=774944 #1256)
(arena=248832 #416)
- Code (reserved=257037944, committed=47531640)
(malloc=3405432 #12450)
(mmap: reserved=253632512, committed=44126208)
- GC (reserved=231540279, committed=231540279)
(malloc=37516855 #51275)
(mmap: reserved=194023424, committed=194023424)
- Compiler (reserved=1067450, committed=1067450)
(malloc=74786 #746)
(arena=992664 #11)
- Internal (reserved=2376498, committed=2376498)
(malloc=2343730 #9777)
(mmap: reserved=32768, committed=32768)
- Symbol (reserved=14679784, committed=14679784)
(malloc=12347464 #143005)
(arena=2332320 #1)
- Native Memory Tracking (reserved=4228952, committed=4228952)
(malloc=39032 #486)
(tracking overhead=4189920)
- Arena Chunk (reserved=72018832, committed=72018832)
(malloc=72018832)
- Tracing (reserved=97, committed=97)
(malloc=97 #5)
- Logging (reserved=4572, committed=4572)
(malloc=4572 #192)
- Arguments (reserved=19083, committed=19083)
(malloc=19083 #495)
- Module (reserved=231144, committed=231144)
(malloc=231144 #1923)
- Synchronizer (reserved=259872, committed=259872)
(malloc=259872 #2016)
- Safepoint (reserved=8192, committed=8192)
(mmap: reserved=8192, committed=8192)
Any idea why this happen?
