Kafka Connect drop messages when Glue Exception is happening

[michalantkowicz]

Apache Iceberg version

1.9.2 (latest release)

Query engine

Trino

Please describe the bug 🐞

I have running instance in k8s that is putting Kafka's messages to my Iceberg tables. From time to time, after the restart I have the following, as I suppose Glue-related, issues in logs, preceded by some commit related warning:

2025-08-06T09:18:47.140Z INFO  [iceberg-coord                      ] [o.a.i.connect.channel.Coordinator   ] {}: Commit 7ad8812b-6591-4b4d-abcc-9d6b0f6067a6 initiated

...

2025-08-06T09:18:48.397Z WARN  [iceberg-coord                      ] [o.a.i.connect.channel.CommitState   ] {trace_id=08ba83bedcc8c610aee5a11fd0ee6474, trace_flags=01, span_id=bdf57fa8fd74331c}: Received commit response when no commit in progress, this can happen during recovery. Commit ID: 7ad8812b-6591-4b4d-abcc-9d6b0f6067a6

^^ the log above is repeating a few times

2025-08-06T09:19:17.565Z INFO  [iceberg-coord                      ] [o.a.i.connect.channel.CommitState   ] {}: Commit timeout reached. Commit ID: 7ad8812b-6591-4b4d-abcc-9d6b0f6067a6

...

2025-08-06T09:19:17.575Z WARN  [iceberg-coord                      ] [o.a.i.connect.channel.Coordinator   ] {}: Commit failed, will try again next cycle
java.lang.IllegalStateException: Connection pool shut down
	at org.apache.http.util.Asserts.check(Asserts.java:34)
	at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.requestConnection(PoolingHttpClientConnectionManager.java:269)
	at software.amazon.awssdk.http.apache.internal.conn.ClientConnectionManagerFactory$DelegatingHttpClientConnectionManager.requestConnection(ClientConnectionManagerFactory.java:75)
	at software.amazon.awssdk.http.apache.internal.conn.ClientConnectionManagerFactory$InstrumentedHttpClientConnectionManager.requestConnection(ClientConnectionManagerFactory.java:57)
	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:176)
	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
	at software.amazon.awssdk.http.apache.internal.impl.ApacheSdkHttpClient.execute(ApacheSdkHttpClient.java:72)
	at software.amazon.awssdk.http.apache.ApacheHttpClient.execute(ApacheHttpClient.java:259)
	at software.amazon.awssdk.http.apache.ApacheHttpClient.access$600(ApacheHttpClient.java:104)
	at software.amazon.awssdk.http.apache.ApacheHttpClient$1.call(ApacheHttpClient.java:236)
	at software.amazon.awssdk.http.apache.ApacheHttpClient$1.call(ApacheHttpClient.java:233)
	at software.amazon.awssdk.core.internal.util.MetricUtils.measureDurationUnsafe(MetricUtils.java:103)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeHttpRequestStage.executeHttpRequest(MakeHttpRequestStage.java:88)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeHttpRequestStage.execute(MakeHttpRequestStage.java:64)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.MakeHttpRequestStage.execute(MakeHttpRequestStage.java:46)
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.execute(ApiCallAttemptTimeoutTrackingStage.java:74)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptTimeoutTrackingStage.execute(ApiCallAttemptTimeoutTrackingStage.java:43)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.TimeoutExceptionHandlingStage.execute(TimeoutExceptionHandlingStage.java:79)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.TimeoutExceptionHandlingStage.execute(TimeoutExceptionHandlingStage.java:41)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptMetricCollectionStage.execute(ApiCallAttemptMetricCollectionStage.java:55)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallAttemptMetricCollectionStage.execute(ApiCallAttemptMetricCollectionStage.java:39)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.RetryableStage.executeRequest(RetryableStage.java:93)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.RetryableStage.execute(RetryableStage.java:56)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.RetryableStage.execute(RetryableStage.java:36)
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
	at software.amazon.awssdk.core.internal.http.StreamManagingStage.execute(StreamManagingStage.java:53)
	at software.amazon.awssdk.core.internal.http.StreamManagingStage.execute(StreamManagingStage.java:35)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.executeWithTimer(ApiCallTimeoutTrackingStage.java:82)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.execute(ApiCallTimeoutTrackingStage.java:62)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallTimeoutTrackingStage.execute(ApiCallTimeoutTrackingStage.java:43)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallMetricCollectionStage.execute(ApiCallMetricCollectionStage.java:50)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ApiCallMetricCollectionStage.execute(ApiCallMetricCollectionStage.java:32)
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
	at software.amazon.awssdk.core.internal.http.pipeline.RequestPipelineBuilder$ComposingRequestPipelineStage.execute(RequestPipelineBuilder.java:206)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ExecutionFailureExceptionReportingStage.execute(ExecutionFailureExceptionReportingStage.java:37)
	at software.amazon.awssdk.core.internal.http.pipeline.stages.ExecutionFailureExceptionReportingStage.execute(ExecutionFailureExceptionReportingStage.java:26)
	at software.amazon.awssdk.core.internal.http.AmazonSyncHttpClient$RequestExecutionBuilderImpl.execute(AmazonSyncHttpClient.java:210)
	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.invoke(BaseSyncClientHandler.java:103)
	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.doExecute(BaseSyncClientHandler.java:173)
	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.lambda$execute$1(BaseSyncClientHandler.java:80)
	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.measureApiCallSuccess(BaseSyncClientHandler.java:182)
	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.execute(BaseSyncClientHandler.java:74)
	at software.amazon.awssdk.core.client.handler.SdkSyncClientHandler.execute(SdkSyncClientHandler.java:45)
	at software.amazon.awssdk.awscore.client.handler.AwsSyncClientHandler.execute(AwsSyncClientHandler.java:53)
	at software.amazon.awssdk.services.sts.DefaultStsClient.assumeRoleWithWebIdentity(DefaultStsClient.java:757)
	at software.amazon.awssdk.services.sts.auth.StsAssumeRoleWithWebIdentityCredentialsProvider.getUpdatedCredentials(StsAssumeRoleWithWebIdentityCredentialsProvider.java:76)
	at software.amazon.awssdk.services.sts.auth.StsCredentialsProvider.updateSessionCredentials(StsCredentialsProvider.java:93)
	at software.amazon.awssdk.utils.cache.CachedSupplier.lambda$jitteredPrefetchValueSupplier$8(CachedSupplier.java:300)
	at software.amazon.awssdk.utils.cache.CachedSupplier$PrefetchStrategy.fetch(CachedSupplier.java:448)
	at software.amazon.awssdk.utils.cache.CachedSupplier.refreshCache(CachedSupplier.java:208)
	at software.amazon.awssdk.utils.cache.CachedSupplier.get(CachedSupplier.java:135)
	at software.amazon.awssdk.services.sts.auth.StsCredentialsProvider.resolveCredentials(StsCredentialsProvider.java:106)
	at software.amazon.awssdk.services.sts.internal.StsWebIdentityCredentialsProviderFactory$StsWebIdentityCredentialsProvider.resolveCredentials(StsWebIdentityCredentialsProviderFactory.java:109)
	at software.amazon.awssdk.auth.credentials.WebIdentityTokenFileCredentialsProvider.resolveCredentials(WebIdentityTokenFileCredentialsProvider.java:141)
	at software.amazon.awssdk.auth.credentials.AwsCredentialsProvider.resolveIdentity(AwsCredentialsProvider.java:54)
	at software.amazon.awssdk.identity.spi.IdentityProvider.resolveIdentity(IdentityProvider.java:60)
	at software.amazon.awssdk.auth.credentials.AwsCredentialsProviderChain.resolveCredentials(AwsCredentialsProviderChain.java:103)
	at software.amazon.awssdk.auth.credentials.internal.LazyAwsCredentialsProvider.resolveCredentials(LazyAwsCredentialsProvider.java:45)
	at software.amazon.awssdk.auth.credentials.DefaultCredentialsProvider.resolveCredentials(DefaultCredentialsProvider.java:134)
	at software.amazon.awssdk.auth.credentials.AwsCredentialsProvider.resolveIdentity(AwsCredentialsProvider.java:54)
	at software.amazon.awssdk.services.glue.auth.scheme.internal.GlueAuthSchemeInterceptor.lambda$trySelectAuthScheme$4(GlueAuthSchemeInterceptor.java:134)
	at software.amazon.awssdk.core.internal.util.MetricUtils.reportDuration(MetricUtils.java:81)
	at software.amazon.awssdk.services.glue.auth.scheme.internal.GlueAuthSchemeInterceptor.trySelectAuthScheme(GlueAuthSchemeInterceptor.java:134)
	at software.amazon.awssdk.services.glue.auth.scheme.internal.GlueAuthSchemeInterceptor.selectAuthScheme(GlueAuthSchemeInterceptor.java:81)
	at software.amazon.awssdk.services.glue.auth.scheme.internal.GlueAuthSchemeInterceptor.beforeExecution(GlueAuthSchemeInterceptor.java:61)
	at software.amazon.awssdk.core.interceptor.ExecutionInterceptorChain.lambda$beforeExecution$1(ExecutionInterceptorChain.java:59)
	at java.base/java.util.ArrayList.forEach(ArrayList.java:1596)
	at software.amazon.awssdk.core.interceptor.ExecutionInterceptorChain.beforeExecution(ExecutionInterceptorChain.java:59)
	at software.amazon.awssdk.awscore.internal.AwsExecutionContextBuilder.runInitialInterceptors(AwsExecutionContextBuilder.java:315)
	at software.amazon.awssdk.awscore.internal.AwsExecutionContextBuilder.invokeInterceptorsAndCreateExecutionContext(AwsExecutionContextBuilder.java:151)
	at software.amazon.awssdk.awscore.client.handler.AwsSyncClientHandler.invokeInterceptorsAndCreateExecutionContext(AwsSyncClientHandler.java:67)
	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.lambda$execute$1(BaseSyncClientHandler.java:76)
	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.measureApiCallSuccess(BaseSyncClientHandler.java:182)
	at software.amazon.awssdk.core.internal.handler.BaseSyncClientHandler.execute(BaseSyncClientHandler.java:74)
	at software.amazon.awssdk.core.client.handler.SdkSyncClientHandler.execute(SdkSyncClientHandler.java:45)
	at software.amazon.awssdk.awscore.client.handler.AwsSyncClientHandler.execute(AwsSyncClientHandler.java:53)
	at software.amazon.awssdk.services.glue.DefaultGlueClient.getTable(DefaultGlueClient.java:30890)
	at org.apache.iceberg.aws.glue.GlueTableOperations.getGlueTable(GlueTableOperations.java:279)
	at org.apache.iceberg.aws.glue.GlueTableOperations.doRefresh(GlueTableOperations.java:128)
	at org.apache.iceberg.BaseMetastoreTableOperations.refresh(BaseMetastoreTableOperations.java:88)
	at org.apache.iceberg.BaseMetastoreTableOperations.current(BaseMetastoreTableOperations.java:71)
	at org.apache.iceberg.BaseMetastoreCatalog.loadTable(BaseMetastoreCatalog.java:49)
	at org.apache.iceberg.connect.channel.Coordinator.commitToTable(Coordinator.java:188)
	at org.apache.iceberg.connect.channel.Coordinator.lambda$doCommit$1(Coordinator.java:152)
	at org.apache.iceberg.util.Tasks$Builder.runTaskWithRetry(Tasks.java:413)
	at org.apache.iceberg.util.Tasks$Builder$1.run(Tasks.java:315)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at java.base/java.lang.Thread.run(Thread.java:1583)

sometimes, before timeout, I see the following messages for the commit:

2025-08-06T09:19:08.091Z INFO  [iceberg-coord                      ] [o.a.i.connect.channel.CommitState   ] {trace_id=5c79db77f8193583564f9c0a6b71897a, trace_flags=01, span_id=e2c0fcfd749a670f}: Commit fb45dd59-3c9e-4cca-a075-37264d5b5a3a not ready, received responses for 1 of 3 partitions, waiting for more

This is definitely some issue I should take a look into, but what is worrying me most is the fact that Kafka Connect is loosing data - it's not in Iceberg anymore and never appear there. The problems I described above usually are being solved with the next restart of my instance but the data is never reprocessed

I've checked source topic offsets and they're just getting bigger, probably never reverts. I've checked my configuration and I see that errors.tolerance is not overwritten so I suppose it should be none but all workers are in RUNNING state

I've checked control topic connect-offsets but it is empty - I did read somewhere that it's expected because it's not being used for Sinks.

Did anyone had this issue?

Willingness to contribute

• I can contribute a fix for this bug independently
• I would be willing to contribute a fix for this bug with guidance from the Iceberg community
• I cannot contribute a fix for this bug at this time

[michalantkowicz]

btw it looks that I have this issue when more than one consumer is connected to control-iceberg topic - is it possible that there's some bug in rejoining groups? Or shouldn't I use more than one pod for the sink?

this is working fine:

GROUP                               TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID          HOST  CLIENT-ID
connect-mantkowicz-test-coord control-iceberg 0          457129          457130          1               e83b8e09-e577-... /10.4.82.138    e83b8e09-e577-...
connect-mantkowicz-test-coord control-iceberg 1          674804          674805          1               e83b8e09-e577-... /10.4.82.138    e83b8e09-e577-...
connect-mantkowicz-test-coord control-iceberg 2          602619          602624          5               e83b8e09-e577-... /10.4.82.138    e83b8e09-e577-...
mantkowicz@lab0-bastion-v1-ip-10-4-118-216:~$ 

this is not working and dropping messages:

GROUP                               TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID          HOST   CLIENT-ID
connect-metrics-usage-iceberg-coord control-iceberg 0          456985          456998          13              6818b728-ecce-... /10.4.84.89     6818b728-ecce-...
connect-metrics-usage-iceberg-coord control-iceberg 1          674770          674781          11              6818b728-ecce-... /10.4.84.89     6818b728-ecce-...
connect-metrics-usage-iceberg-coord control-iceberg 2          602596          602600          4               d4d1efcb-3a28-... /10.4.84.89     d4d1efcb-3a28-...

[michalantkowicz]

oh actually it seems that the same pod is rejoining to the control-iceberg twice

GROUP                                 TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID       HOST            CLIENT-ID
connect-mantkowicz-test-iceberg-coord control-iceberg 0          457321          457486          165             6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...
connect-mantkowicz-test-iceberg-coord control-iceberg 1          675247          675362          115             6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...
connect-mantkowicz-test-iceberg-coord control-iceberg 2          603218          603225          7               aa726279-97e7-... /10.4.79.156    aa726279-97e7-...


GROUP                                 TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID       HOST            CLIENT-ID
connect-mantkowicz-test-iceberg-coord control-iceberg 0          457321          457490          169             6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...
connect-mantkowicz-test-iceberg-coord control-iceberg 1          675247          675362          115             6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...
connect-mantkowicz-test-iceberg-coord control-iceberg 2          603224          603225          1               aa726279-97e7-... /10.4.79.156    aa726279-97e7-...


GROUP                                 TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID       HOST            CLIENT-ID
connect-mantkowicz-test-iceberg-coord control-iceberg 0          457321          457490          169             6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...
connect-mantkowicz-test-iceberg-coord control-iceberg 1          675247          675362          115             6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...
connect-mantkowicz-test-iceberg-coord control-iceberg 2          603224          603225          1               aa726279-97e7-... /10.4.79.156    aa726279-97e7-...


GROUP                                 TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID       HOST            CLIENT-ID
connect-mantkowicz-test-iceberg-coord control-iceberg 0          457321          457490          169             6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...
connect-mantkowicz-test-iceberg-coord control-iceberg 1          675247          675362          115             6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...
connect-mantkowicz-test-iceberg-coord control-iceberg 2          603224          603225          1               aa726279-97e7-... /10.4.79.156    aa726279-97e7-...


GROUP                                 TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID       HOST            CLIENT-ID
connect-mantkowicz-test-iceberg-coord control-iceberg 0          457321          457490          169             6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...
connect-mantkowicz-test-iceberg-coord control-iceberg 1          675247          675362          115             6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...
connect-mantkowicz-test-iceberg-coord control-iceberg 2          603224          603225          1               aa726279-97e7-... /10.4.79.156    aa726279-97e7-...



Warning: Consumer group 'connect-mantkowicz-test-iceberg-coord' is rebalancing.

GROUP                                 TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID     HOST            CLIENT-ID
connect-mantkowicz-test-iceberg-coord control-iceberg 0          457321          457490          169             -               -               -
connect-mantkowicz-test-iceberg-coord control-iceberg 1          675247          675362          115             -               -               -
connect-mantkowicz-test-iceberg-coord control-iceberg 2          603224          603225          1               -               -               -


GROUP                                 TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID       HOST            CLIENT-ID
connect-mantkowicz-test-iceberg-coord control-iceberg 0          457321          457490          169             6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...
connect-mantkowicz-test-iceberg-coord control-iceberg 1          675247          675362          115             6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...
connect-mantkowicz-test-iceberg-coord control-iceberg 2          603224          603225          1               6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...



Warning: Consumer group 'connect-mantkowicz-test-iceberg-coord' is rebalancing.

GROUP                                 TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID     HOST            CLIENT-ID
connect-mantkowicz-test-iceberg-coord control-iceberg 0          457321          457490          169             -               -               -
connect-mantkowicz-test-iceberg-coord control-iceberg 1          675247          675362          115             -               -               -
connect-mantkowicz-test-iceberg-coord control-iceberg 2          603224          603225          1               -               -               -


GROUP                                 TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID       HOST            CLIENT-ID
connect-mantkowicz-test-iceberg-coord control-iceberg 0          457321          457490          169             1300dc38-a65e-... /10.4.79.156    1300dc38-a65e-...
connect-mantkowicz-test-iceberg-coord control-iceberg 1          675247          675364          117             1300dc38-a65e-... /10.4.79.156    1300dc38-a65e-...
connect-mantkowicz-test-iceberg-coord control-iceberg 2          603224          603225          1               6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...


GROUP                                 TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID       HOST            CLIENT-ID
connect-mantkowicz-test-iceberg-coord control-iceberg 0          457321          457490          169             1300dc38-a65e-... /10.4.79.156    1300dc38-a65e-...
connect-mantkowicz-test-iceberg-coord control-iceberg 1          675247          675364          117             1300dc38-a65e-... /10.4.79.156    1300dc38-a65e-...
connect-mantkowicz-test-iceberg-coord control-iceberg 2          603224          603225          1               6124a0d2-be09-... /10.4.79.156    6124a0d2-be09-...

logs from the pod:

2025-08-06T13:29:16.053Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerCoordinator     ] {}: [Consumer clientId=6124a0d2-be09-..., groupId=connect-mantkowicz-test-iceberg-coord] Request joining group due to: group is already rebalancing
2025-08-06T13:29:16.053Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerRebalanceListenerInvoker] {}: [Consumer clientId=6124a0d2-be09-..., groupId=connect-mantkowicz-test-iceberg-coord] Revoke previously assigned partitions control-iceberg-0, control-iceberg-1, control-iceberg-2
2025-08-06T13:29:16.053Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerCoordinator     ] {}: [Consumer clientId=6124a0d2-be09-..., groupId=connect-mantkowicz-test-iceberg-coord] (Re-)joining group
2025-08-06T13:29:16.055Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerCoordinator     ] {}: [Consumer clientId=1300dc38-a65e-..., groupId=connect-mantkowicz-test-iceberg-coord] Successfully joined group with generation Generation{generationId=1895, memberId='1300dc38-a65e-...', protocol='range'}
2025-08-06T13:29:16.055Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerCoordinator     ] {}: [Consumer clientId=6124a0d2-be09-..., groupId=connect-mantkowicz-test-iceberg-coord] Successfully joined group with generation Generation{generationId=1895, memberId='6124a0d2-be09-...', protocol='range'}
2025-08-06T13:29:16.055Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerCoordinator     ] {}: [Consumer clientId=6124a0d2-be09-..., groupId=connect-mantkowicz-test-iceberg-coord] Finished assignment for group at generation 1895: {1300dc38-a65e-...=Assignment(partitions=[control-iceberg-0, control-iceberg-1]), 6124a0d2-be09-...=Assignment(partitions=[control-iceberg-2])}
2025-08-06T13:29:16.072Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerCoordinator     ] {}: [Consumer clientId=1300dc38-a65e-..., groupId=connect-mantkowicz-test-iceberg-coord] Successfully synced group in generation Generation{generationId=1895, memberId='1300dc38-a65e-...', protocol='range'}
2025-08-06T13:29:16.072Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerCoordinator     ] {}: [Consumer clientId=6124a0d2-be09-..., groupId=connect-mantkowicz-test-iceberg-coord] Successfully synced group in generation Generation{generationId=1895, memberId='6124a0d2-be09-...', protocol='range'}
2025-08-06T13:29:16.072Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerCoordinator     ] {}: [Consumer clientId=6124a0d2-be09-..., groupId=connect-mantkowicz-test-iceberg-coord] Notifying assignor about the new Assignment(partitions=[control-iceberg-2])
2025-08-06T13:29:16.072Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerCoordinator     ] {}: [Consumer clientId=1300dc38-a65e-..., groupId=connect-mantkowicz-test-iceberg-coord] Notifying assignor about the new Assignment(partitions=[control-iceberg-0, control-iceberg-1])
2025-08-06T13:29:16.073Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerRebalanceListenerInvoker] {}: [Consumer clientId=6124a0d2-be09-..., groupId=connect-mantkowicz-test-iceberg-coord] Adding newly assigned partitions: control-iceberg-2
2025-08-06T13:29:16.073Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerRebalanceListenerInvoker] {}: [Consumer clientId=1300dc38-a65e-..., groupId=connect-mantkowicz-test-iceberg-coord] Adding newly assigned partitions: control-iceberg-0, control-iceberg-1

I saw that in the 'healthy' situation one of the consumer should pro-actively leave the group like in this example:

2025-08-06T13:29:07.509Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerRebalanceListenerInvoker] {}: [Consumer clientId=aa726279-97e7-..., groupId=connect-mantkowicz-test-iceberg-coord] Revoke previously assigned partitions control-iceberg-2
2025-08-06T13:29:07.510Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerCoordinator     ] {}: [Consumer clientId=aa726279-97e7-..., groupId=connect-mantkowicz-test-iceberg-coord] Member aa726279-97e7-... sending LeaveGroup request to coordinator 10.129.161.68:9092 (id: 2147483636 rack: null isFenced: false) due to the consumer is being closed
2025-08-06T13:29:07.510Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerCoordinator     ] {}: [Consumer clientId=aa726279-97e7-..., groupId=connect-mantkowicz-test-iceberg-coord] Resetting generation and member id due to: consumer pro-actively leaving the group
2025-08-06T13:29:07.510Z INFO  [iceberg-coord                      ] [o.a.k.c.c.i.ConsumerCoordinator     ] {}: [Consumer clientId=aa726279-97e7-..., groupId=connect-mantkowicz-test-iceberg-coord] Request joining group due to: consumer pro-actively leaving the group

is it possible that there's a bug in rebalancing?

[nferrario]

Hi @michalantkowicz, yes, this is a duplicate of #13593.

The bugfix was just merged to main but it's not released yet: #13670

[michalantkowicz]

What a relief! 😌

Thank you very much for info @nferrario 🙌 I was looking into issues and indeed having similar logs - just wasn't aware it's connected

[michalantkowicz]

I'm sorry @nferrario just one more question - is the rebalancing issue I've described above connected to the issue or is it something else?

[nferrario]

@michalantkowicz as far as I know, it's the same underlying issue. I experienced it with AWS Glue and REST (self-hosted) catalogs. I haven't been able to test the fix yet

[michalantkowicz]

Thanks, I see now - the only thing I don't like is that actually I have data loss - metadata does not seem to be committed after the restart in my case

[nferrario]

Based on my experience, if you restart the connector before hitting the retention limits set on the control topic, the pending Iceberg snapshots should get committed. If nothing made it to the control topic (i.e. you got this exception in your first run), the connector will start reading the source data topic from beginning.

I had cases were I had to restart multiple times before it worked

[kumarpritam863]

@michalantkowicz @nferrario can you guys please try out the new changes. Also if possible can you describe the scenario in which you are getting this issue. Also are you guys running in RoundRobin or ICR mode?

[michalantkowicz]

@nferrario I've checked and it seems that my control topic has 7D retention (the default one) and the data was skipped anyway even after restarts - what's even more interesting not all of the data was lost - it usually was ~33% or 66% what makes sense while I have maxWorkers set to 3 - seems that some of them were corrupted

@kumarpritam863 - unfortunately in environment I have it set up I cannot test changes that are not released yet.. but I can describe the scenario:

1. I have two pods with docker image of iceberg-kafka-connect deployed in kubernetes cluster, let say they are working fine putting some messages from source topic to iceberg tables, one of them has coord process
2. There's restart (e.g. deployment of newer version)
3. After rolling restart sometimes the java.lang.IllegalStateException: Connection pool shut down logs start to appear on pod with coord process and it remains unhealthy until next restart (if the situation will not repeat after the restart)

I thought that it happens when I have more than one consumer-id connected to control-iceberg topic but now I see that I have this situation currently and there's no data loss

GROUP                               TOPIC           PARTITION  CURRENT-OFFSET  LOG-END-OFFSET  LAG             CONSUMER-ID                                                               HOST            CLIENT-ID
connect-mantkowicz-test-iceberg-coord control-iceberg 0          156894          156895          1               adbfe6cb-e30a-... /10.4.26.137    adbfe6cb-e30a-...
connect-mantkowicz-test-iceberg-coord control-iceberg 1          166922          166927          5               adbfe6cb-e30a-... /10.4.26.137    adbfe6cb-e30a-...
connect-mantkowicz-test-iceberg-coord control-iceberg 2          173379          173386          7               e803e448-6dad-... /10.4.26.137    e803e448-6dad-...

(I've compared counts by hour on kafka and in iceberg and they match)

I've observed that this situation is more likely to happen if the pod WITHOUT coord process will be restarted first

[michalantkowicz]

In general - for sure - offsets on control-iceberg topic are moving forward, no matter whether commits were done or not

[michalantkowicz]

Now it also seems that I'm able to reproduce this situation with only one pod - just a random restart makes this process unhealthy and loosing data..

@kumarpritam863 - as far as I see I didn't set any specific distribution-mode therefore seems that I'm using RoundRobin I guess?

[nferrario]

@michalantkowicz I don't think I'll be able to try the fix before some time next week. I'm using Kafka 3.9 (Confluent 7.9) and AFAIK the default mode is ICR.

I also didn't experience corruption, even after a full day of no commits, and I usually have 4-6 tasks for my connectors.

[michalantkowicz]

@nferrario I tested it carefeuly (hope it's last update 😓 ) and it looks that with 1 pod I don't observe data loss - while with two of them data gap remained after the restart now it's indeed reprocessed:

-- pod is unhealthy, "java.lang.IllegalStateException: Connection pool shut down" logs are appearing:

bucket_start           event_count_kafka     event_count_iceberg  diff    diff_percent
2025-08-07 10:50:00    21265                 21265                0       100.0
2025-08-07 10:52:00    18392                 18392                0       100.0
2025-08-07 10:54:00    21523                 21523                0       100.0
2025-08-07 10:56:00    19667                 19667                0       100.0
2025-08-07 10:58:00    18558                 18558                0       100.0
2025-08-07 11:00:00    23561                 23561                0       100.0
2025-08-07 11:02:00    19303                 19303                0       100.0
2025-08-07 11:04:00    20151                 20151                0       100.0
2025-08-07 11:06:00    19417                 18819                598     96
2025-08-07 11:08:00    18888                 9613                 9275    50
2025-08-07 11:10:00    20246                 13564                6682    66
2025-08-07 11:12:00    19219                 12904                6315    67
2025-08-07 11:14:00    29560                 19855                9705    67
2025-08-07 11:16:00    18490                 12406                6084    67
2025-08-07 11:18:00    18522                 12427                6095    67
2025-08-07 11:20:00    21311                 14295                7016    67
2025-08-07 11:22:00    18620                 12493                6127    67
2025-08-07 11:24:00    18740                 10300                8440    54 

then after restart:

-- pod is healthy, no error logs

bucket_start           event_count_kafka     event_count_iceberg  diff    diff_percent
2025-08-07 10:50:00    21265                 21265                0       100
2025-08-07 10:52:00    18392                 18392                0       100
2025-08-07 10:54:00    21523                 21523                0       100
2025-08-07 10:56:00    19667                 19667                0       100
2025-08-07 10:58:00    18558                 18558                0       100
2025-08-07 11:00:00    23561                 23561                0       100
2025-08-07 11:02:00    19303                 19303                0       100
2025-08-07 11:04:00    20151                 20151                0       100
2025-08-07 11:06:00    19417                 19417                0       100
2025-08-07 11:08:00    18888                 18888                0       100
2025-08-07 11:10:00    20246                 20246                0       100
2025-08-07 11:12:00    19219                 19219                0       100
2025-08-07 11:14:00    29560                 29560                0       100
2025-08-07 11:16:00    18490                 18490                0       100
2025-08-07 11:18:00    18522                 18522                0       100
2025-08-07 11:20:00    21311                 21311                0       100
2025-08-07 11:22:00    18620                 18620                0       100
2025-08-07 11:24:00    21105                 21105                0       100
2025-08-07 11:26:00    19228                 19228                0       100
2025-08-07 11:28:00    17477                 17477                0       100
2025-08-07 11:30:00    22943                 22943                0       100

so as for now this issue looks much much closer to the issue you've linked 🙌

interesting why I was losing data with two pods but I may investigate is later

do you know what is the release plan for Iceberg and when we can expect version 1.9.3? I saw that releases are usually happening ~once per month I wonder is there any other chance to have it in Aug...