Warning - Scheduler for MirrorCheckpointTask took too long

[irmiller22]

I'm getting the following warning message in the MirrorMaker2 logs:

2023-08-01 01:00:13,911 WARN [prod-gcp-us-west1-kudu-confluent-sso->prod-gcp-us-west1-kudu-confluent.MirrorCheckpointConnector|task-0] Scheduler for MirrorCheckpointTask took too long (72050 ms) running task: refreshing idle consumers group offsets at target cluster (org.apache.kafka.connect.mirror.Scheduler) [Scheduler for MirrorCheckpointTask-refreshing idle consumers group offsets at target cluster]

I'm noticing that the consumer group offsets aren't getting fully synced over. Does this mean that refresh.groups.interval.seconds is potentially set too low? The checkpoint connector configs are below:

checkpointConnector:
      config:
        checkpoints.topic.replication.factor: 1
        replication.policy.class: "io.strimzi.kafka.connect.mirror.IdentityReplicationPolicy"        
        sync.group.offsets.enabled: true
        refresh.groups.interval.seconds: 60

Any help would be appreciated!

[scholzj]

60 seconds do not sound like a super slow number. So I think the more interesting thing is why does it take so long. Maybe you need to add more tasks, replicas and/or resources to the MM2 deployment?

[irmiller22]

@scholzj I think it's due to the large number of consumer groups that are being synced across. I belive you're right in that tasks / replicas / resources need to be added, as more offsets are being synced across successfully now.

After doing the above, I now see errors like this:

Caused by: org.apache.kafka.common.errors.TimeoutException: The AdminClient thread is not accepting new calls.
2023-08-01 14:37:49,188 ERROR [prod-gcp-us-west1-kudu-confluent-sso->prod-gcp-us-west1-kudu-confluent.MirrorCheckpointConnector|task-0] Error querying for consumer group jms-client-contentmanager-service-65d6dcf64d-zqc5b_0-DISC-Data-Migration-Step-1.0-gr10 on cluster prod-gcp-us-west1-kudu-confluent. (org.apache.kafka.connect.mirror.MirrorCheckpointTask) [Scheduler for MirrorCheckpointTask-refreshing idle consumers group offsets at target cluster]
java.util.concurrent.ExecutionException: org.apache.kafka.common.errors.TimeoutException: The AdminClient thread is not accepting new calls.
	at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:396)
	at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:2073)
	at org.apache.kafka.common.internals.KafkaFutureImpl.get(KafkaFutureImpl.java:165)
	at org.apache.kafka.connect.mirror.MirrorCheckpointTask.refreshIdleConsumerGroupOffset(MirrorCheckpointTask.java:247)
	at org.apache.kafka.connect.mirror.Scheduler.run(Scheduler.java:93)
	at org.apache.kafka.connect.mirror.Scheduler.executeThread(Scheduler.java:112)
	at org.apache.kafka.connect.mirror.Scheduler.lambda$scheduleRepeating$0(Scheduler.java:50)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539)
	at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305)
	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)

I added the following timeout configurations to the checkPointConnector config:

        default.api.timeout.ms: 100000
        request.timeout.ms: 100000

Now my checkPointConnector config looks like the below:

    checkpointConnector:
      config:
        # Internal topic '<source-cluster-alias>.checkpoints.internal' created at the target cluster
        checkpoints.topic.replication.factor: 1
        # Override automatic renaming (use this policy for ACTIVE / PASSIVE use cases)
        # Instead of prepending the name with the name of the source cluster, the topic retains its original name
        replication.policy.class: "io.strimzi.kafka.connect.mirror.IdentityReplicationPolicy"        
        # Offset synchronization periodically transfers the consumer offsets for the consumer groups
        # of a source cluster into the consumer offsets topic of a target cluster.
        sync.group.offsets.enabled: true
        # Interval period to refresh consumer groups statuses (Default: 600)
        refresh.groups.interval.seconds: 60
        # timeouts for syncing CGs
        default.api.timeout.ms: 100000
        request.timeout.ms: 100000

It doesn't look like the timeout settings are helping, however. Is the AdminClient timeout setting managed by another config?

[scholzj]

TBH, I do not know, the configuration is a bit chaotic. Maybe you can try to prefix it with admin.. But to be honest, I do not even know if these two options would help with the error you are getting.

[scholzj]

@mimaison Any idea for this?

[mimaison]

I'm not entirely sure how Strimzi maps these configs to the connector configs, but for the Admin client to pick it up it has to start with the cluster prefix (source.cluster. or target.cluster.), the admin prefix (admin.) or both combined (source.cluster.admin.).

The The AdminClient thread is not accepting new calls message indicates the Admin client is currently shutting down. This usually happens when the connector itself is shutting down so I don't think it's the root cause. It would be useful to have the rest of the connector logs. Listing consumer groups can timeout if there are too many groups on the cluster but usually it takes thousands or hundreds of thousands of groups at least to trigger this behavior). Broker also expose request duration via metrics, so it may be worth checking these too (for example kafka.network:type=RequestMetrics,name=TotalTimeMs,request=ListGroups)

[irmiller22]

@mimaison there's definitely > 1000 consumer groups on this cluster I'm migrating (due to incorrectly implemented consumer group configs by downstream services). However, after scaling up replicas even further, I'm no longer seeing the AdminClient errors. I think the consumer group syncs have been assigned across workers / tasks to an extent that the API calls are no longer timing out.

I'll check those metrics as well. Thank you both for your help and guidance!

As a side note, this open-source discussion forum has been one of the best open-source experiences I've had. @scholzj you've been especially helpful with any issues I've had. Thank you.