akhq: Failed to get offsets by times in 60000ms

Hey There

Thanks again for a great app, it really is superb for what you’ve done so far.

We seem to be starting to get a number of 504 timeouts caused by the below error;

2019-06-20 01:08:18,495 ERROR pGroup-1-2 o.k.c.ErrorController      java.lang.RuntimeException: Error for Describe Topics Offsets {}
java.util.concurrent.ExecutionException: java.lang.RuntimeException: Error for Describe Topics Offsets {}
        at java.base/java.util.concurrent.CompletableFuture.reportGet(CompletableFuture.java:395)
        at java.base/java.util.concurrent.CompletableFuture.get(CompletableFuture.java:1999)
        at org.kafkahq.utils.CompletablePaged.complete(CompletablePaged.java:68)
        at org.kafkahq.controllers.TopicController.list(TopicController.java:96)
        at org.kafkahq.controllers.$TopicControllerDefinition$$exec1.invokeInternal(Unknown Source)
        at io.micronaut.context.AbstractExecutableMethod.invoke(AbstractExecutableMethod.java:144)
        at io.micronaut.context.DefaultBeanContext$BeanExecutionHandle.invoke(DefaultBeanContext.java:2711)
        at io.micronaut.web.router.AbstractRouteMatch.execute(AbstractRouteMatch.java:295)
        at io.micronaut.web.router.RouteMatch.execute(RouteMatch.java:122)
        at io.micronaut.http.server.netty.RoutingInBoundHandler.lambda$buildResultEmitter$17(RoutingInBoundHandler.java:1360)
        at io.reactivex.internal.operators.flowable.FlowableCreate.subscribeActual(FlowableCreate.java:71)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.internal.operators.flowable.FlowableMap.subscribeActual(FlowableMap.java:37)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.internal.operators.flowable.FlowableSwitchIfEmpty.subscribeActual(FlowableSwitchIfEmpty.java:32)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.internal.operators.flowable.FlowableSwitchMap.subscribeActual(FlowableSwitchMap.java:49)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.reactivex.internal.operators.flowable.FlowableDefer.subscribeActual(FlowableDefer.java:42)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.reactivex.internal.operators.flowable.FlowableSwitchIfEmpty$SwitchIfEmptySubscriber.onComplete(FlowableSwitchIfEmpty.java:71)
        at io.micronaut.http.context.ServerRequestContext.with(ServerRequestContext.java:52)
        at io.micronaut.http.context.ServerRequestContext.lambda$instrument$0(ServerRequestContext.java:68)
        at io.micronaut.reactive.rxjava2.InstrumentedSubscriber.onComplete(InstrumentedSubscriber.java:112)
        at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drainLoop(FlowableFlatMap.java:426)
        at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drain(FlowableFlatMap.java:366)
        at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.onComplete(FlowableFlatMap.java:338)
        at io.micronaut.http.context.ServerRequestContext.with(ServerRequestContext.java:52)
        at io.micronaut.http.context.ServerRequestContext.lambda$instrument$0(ServerRequestContext.java:68)
        at io.micronaut.reactive.rxjava2.InstrumentedSubscriber.onComplete(InstrumentedSubscriber.java:112)
        at io.reactivex.internal.operators.maybe.MaybeToFlowable$MaybeToFlowableSubscriber.onComplete(MaybeToFlowable.java:80)
        at io.micronaut.http.context.ServerRequestContext.with(ServerRequestContext.java:52)
        at io.micronaut.http.context.ServerRequestContext.lambda$instrument$0(ServerRequestContext.java:68)
        at io.micronaut.reactive.rxjava2.RxInstrumentedMaybeObserver.onComplete(RxInstrumentedMaybeObserver.java:92)
        at io.reactivex.internal.operators.maybe.MaybeDoOnEvent$DoOnEventMaybeObserver.onComplete(MaybeDoOnEvent.java:115)
        at io.micronaut.http.context.ServerRequestContext.with(ServerRequestContext.java:52)
        at io.micronaut.http.context.ServerRequestContext.lambda$instrument$0(ServerRequestContext.java:68)
        at io.micronaut.reactive.rxjava2.RxInstrumentedMaybeObserver.onComplete(RxInstrumentedMaybeObserver.java:92)
        at io.reactivex.internal.operators.flowable.FlowableElementAtMaybe$ElementAtSubscriber.onComplete(FlowableElementAtMaybe.java:102)
        at io.micronaut.http.context.ServerRequestContext.with(ServerRequestContext.java:52)
        at io.micronaut.http.context.ServerRequestContext.lambda$instrument$0(ServerRequestContext.java:68)
        at io.micronaut.reactive.rxjava2.InstrumentedSubscriber.onComplete(InstrumentedSubscriber.java:112)
        at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drainLoop(FlowableFlatMap.java:426)
        at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drain(FlowableFlatMap.java:366)
        at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.onComplete(FlowableFlatMap.java:338)
        at io.micronaut.http.context.ServerRequestContext.with(ServerRequestContext.java:52)
        at io.micronaut.http.context.ServerRequestContext.lambda$instrument$0(ServerRequestContext.java:68)
        at io.micronaut.reactive.rxjava2.InstrumentedSubscriber.onComplete(InstrumentedSubscriber.java:112)
        at io.reactivex.internal.operators.flowable.FlowableFromIterable$IteratorSubscription.slowPath(FlowableFromIterable.java:255)
        at io.reactivex.internal.operators.flowable.FlowableFromIterable$BaseRangeSubscription.request(FlowableFromIterable.java:124)
        at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.onSubscribe(FlowableFlatMap.java:117)
        at io.micronaut.reactive.rxjava2.InstrumentedSubscriber.onSubscribe(InstrumentedSubscriber.java:75)
        at io.reactivex.internal.operators.flowable.FlowableFromIterable.subscribe(FlowableFromIterable.java:69)
        at io.reactivex.internal.operators.flowable.FlowableFromIterable.subscribeActual(FlowableFromIterable.java:47)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.internal.operators.flowable.FlowableFlatMap.subscribeActual(FlowableFlatMap.java:53)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.internal.operators.flowable.FlowableElementAtMaybe.subscribeActual(FlowableElementAtMaybe.java:36)
        at io.reactivex.Maybe.subscribe(Maybe.java:4262)
        at io.micronaut.reactive.rxjava2.RxInstrumentedMaybe.subscribeActual(RxInstrumentedMaybe.java:64)
        at io.reactivex.Maybe.subscribe(Maybe.java:4262)
        at io.reactivex.internal.operators.maybe.MaybeDoOnEvent.subscribeActual(MaybeDoOnEvent.java:39)
        at io.reactivex.Maybe.subscribe(Maybe.java:4262)
        at io.micronaut.reactive.rxjava2.RxInstrumentedMaybe.subscribeActual(RxInstrumentedMaybe.java:64)
        at io.reactivex.Maybe.subscribe(Maybe.java:4262)
        at io.reactivex.internal.operators.maybe.MaybeToFlowable.subscribeActual(MaybeToFlowable.java:45)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.internal.operators.flowable.FlowableFlatMap.subscribeActual(FlowableFlatMap.java:53)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.internal.operators.flowable.FlowableSwitchIfEmpty.subscribeActual(FlowableSwitchIfEmpty.java:32)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14755)
        at io.micronaut.configuration.metrics.binder.web.WebMetricsPublisher.subscribe(WebMetricsPublisher.java:122)
        at io.reactivex.internal.operators.flowable.FlowableFromPublisher.subscribeActual(FlowableFromPublisher.java:29)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.internal.operators.flowable.FlowableSwitchMap.subscribeActual(FlowableSwitchMap.java:49)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.internal.operators.flowable.FlowableMap.subscribeActual(FlowableMap.java:37)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14755)
        at io.micronaut.http.context.ServerRequestTracingPublisher.lambda$subscribe$0(ServerRequestTracingPublisher.java:52)
        at io.micronaut.http.context.ServerRequestContext.with(ServerRequestContext.java:52)
        at io.micronaut.http.context.ServerRequestTracingPublisher.subscribe(ServerRequestTracingPublisher.java:52)
        at io.reactivex.internal.operators.flowable.FlowableFromPublisher.subscribeActual(FlowableFromPublisher.java:29)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.micronaut.reactive.rxjava2.RxInstrumentedFlowable.subscribeActual(RxInstrumentedFlowable.java:68)
        at io.reactivex.Flowable.subscribe(Flowable.java:14805)
        at io.reactivex.Flowable.subscribe(Flowable.java:14752)
        at io.reactivex.internal.operators.flowable.FlowableSubscribeOn$SubscribeOnSubscriber.run(FlowableSubscribeOn.java:82)
        at io.reactivex.internal.schedulers.ExecutorScheduler$ExecutorWorker$BooleanRunnable.run(ExecutorScheduler.java:288)
        at io.reactivex.internal.schedulers.ExecutorScheduler$ExecutorWorker.run(ExecutorScheduler.java:253)
        at io.micrometer.core.instrument.composite.CompositeTimer.record(CompositeTimer.java:79)
        at io.micrometer.core.instrument.Timer.lambda$wrap$0(Timer.java:143)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.lang.RuntimeException: Error for Describe Topics Offsets {}
        at org.kafkahq.modules.KafkaModule.debug(KafkaModule.java:55)
        at org.kafkahq.modules.KafkaWrapper.describeTopicsOffsets(KafkaWrapper.java:94)
        at org.kafkahq.repositories.ConsumerGroupRepository.findByName(ConsumerGroupRepository.java:56)
        at org.kafkahq.repositories.ConsumerGroupRepository.list(ConsumerGroupRepository.java:37)
        at org.kafkahq.repositories.ConsumerGroupRepository.findByTopic(ConsumerGroupRepository.java:74)
        at org.kafkahq.repositories.TopicRepository.findByName(TopicRepository.java:101)
        at org.kafkahq.repositories.TopicRepository.findByName(TopicRepository.java:86)
        at org.kafkahq.repositories.TopicRepository.lambda$list$1(TopicRepository.java:63)
        at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1700)
        ... 1 common frames omitted
Caused by: org.apache.kafka.common.errors.TimeoutException: Failed to get offsets by times in 60001ms

I’ve tried changing some of the consumer properties for clients-defaults.consumer.properties.session.timeout.ms|heartbeat.interval.ms which showed some benefits.

This is running against docker image confluentinc/cp-schema-registry:5.2.2, which I’ve just tried updating from 5.0.1 we were using previously. The Kafka Clusters (multiple) are 3 brokers in each, running AMQStreams by RedHat, kafka version 2.0.0.

openjdk:11 for the base image, and adding the other files (.jar, kafkahq script etc) in manually.

We have about a dozen microservices that send/receive messages to/from this kafka from on and externally to OpenShift without timeouts etc.

Upping debugging doesn’t seem to show anything really more in the logs, but I’m more than happy to provide info as needed.

I do note that it appears when more than one person is concurrently using it from different PC’s that it starts to falter.

Application.yml

kafkahq:
  server:
    base-path: ""

  # default kafka properties for each clients
  clients-defaults:
    consumer:
      properties:
        isolation.level: read_committed
        session.timeout.ms: 10000
        heartbeat.interval.ms: 1000

  # list of kafka cluster available for kafkahq
  connections:
    dispatch:
      properties:
        bootstrap.servers: "dispatch-kafka-bootstrap:9092"
      schema-registry:
        url: "http://dispatch-schema-registry:8081"

  # Topic display data options
  topic-data:
    sort: NEWEST
    size: 50
    poll-timeout: 1000

  # Schama list display options
  schema:
    page-size: 25

  # Auth & Roles
  security:
    default-roles:
      - topic/read
      - topic/insert
      - topic/delete
      - topic/config/update
      - node/read
      - node/config/update
      - topic/data/read
      - topic/data/insert
      - topic/data/delete
      - group/read
      - group/delete
      - group/offsets/update
      - registry/read
      - registry/insert
      - registry/update
      - registry/delete
      - registry/version/delete

Thanks