https://linen.dev logo
Join Slack
Powered by
This message was deleted.
# troubleshooting
s
This message was deleted.
r
just upgraded here, like 24h ago, and no issue noticed
b
No issue
a
What problems are you encountering @Thomas? Any symptoms / messages you can share?
t
With the exact same specs, I’ve now got huge lag. Even if I scale up taskCount/workers to match kafka topic partition numbers, I’ve got lag.
I’ll dig and try to find interesting logs, i’ll keep you posted
And I can see a lot of failed tasks
The indexer log says the task completed with status SUCCESS, yet I see it in FAILED status on console
Copy code
2023-01-09T09:01:15,951 ERROR [[index_kafka_beam_advanced_9e22ee33bec07d0_alaobbia]-threading-task-runner-executor-6] org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner - Error while publishing segments for sequenceNumber[SequenceMetadata{sequenceId=2, sequenceName='index_kafka_beam_advanced_9e22ee33bec07d0_2', assignments=[], startOffsets={72=82799227089, 12=82796407538}, exclusiveStartPartitions=[], endOffsets={72=82800624620, 12=82800201794}, sentinel=false, checkpointed=true}]
java.util.concurrent.CancellationException: Task was cancelled.
        at com.google.common.util.concurrent.AbstractFuture.cancellationExceptionWithCause(AbstractFuture.java:392) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:306) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:286) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:116) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.Uninterruptibles.getUninterruptibly(Uninterruptibles.java:135) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.Futures$4.run(Futures.java:1170) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService.execute(MoreExecutors.java:297) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.ExecutionList.executeListener(ExecutionList.java:156) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.ExecutionList.execute(ExecutionList.java:145) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.AbstractFuture.cancel(AbstractFuture.java:134) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.Futures$ChainingListenableFuture.cancel(Futures.java:826) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.Futures$CombinedFuture$1.run(Futures.java:1505) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService.execute(MoreExecutors.java:297) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.ExecutionList.executeListener(ExecutionList.java:156) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.ExecutionList.execute(ExecutionList.java:145) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.AbstractFuture.cancel(AbstractFuture.java:134) ~[guava-16.0.1.jar:?]
        at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.runInternal(SeekableStreamIndexTaskRunner.java:863) ~[druid-indexing-service-25.0.0.jar:25.0.0]
        at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.run(SeekableStreamIndexTaskRunner.java:266) ~[druid-indexing-service-25.0.0.jar:25.0.0]
        at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTask.runTask(SeekableStreamIndexTask.java:151) ~[druid-indexing-service-25.0.0.jar:25.0.0]
        at org.apache.druid.indexing.common.task.AbstractTask.run(AbstractTask.java:169) ~[druid-indexing-service-25.0.0.jar:25.0.0]
        at org.apache.druid.indexing.overlord.ThreadingTaskRunner$1.call(ThreadingTaskRunner.java:210) ~[druid-indexing-service-25.0.0.jar:25.0.0]
        at org.apache.druid.indexing.overlord.ThreadingTaskRunner$1.call(ThreadingTaskRunner.java:152) ~[druid-indexing-service-25.0.0.jar:25.0.0]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_352]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_352]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_352]
        at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_352]
Caused by: java.util.concurrent.CancellationException: Future.cancel() was called.
        at com.google.common.util.concurrent.AbstractFuture$Sync.complete(AbstractFuture.java:378) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.AbstractFuture$Sync.cancel(AbstractFuture.java:355) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.AbstractFuture.cancel(AbstractFuture.java:131) ~[guava-16.0.1.jar:?]
        ... 16 more
Then segments got unannounced
Copy code
2023-01-09T09:01:15,954 WARN [[index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia]-appenderator-merge] org.apache.druid.segment.realtime.appenderator.StreamAppenderator - Failed to push merged index for segment[beam-advanced_2023-01-09T08:00:00.000Z_2023-01-09T09:00:00.000Z_2023-01-09T08:00:00.309Z_213].
java.lang.RuntimeException: java.lang.InterruptedException
        at org.apache.druid.segment.realtime.appenderator.UnifiedIndexerAppenderatorsManager$LimitedPoolIndexMerger.mergeQueryableIndex(UnifiedIndexerAppenderatorsManager.java:674) ~[druid-server-25.0.0.jar:25.0.0]
        at org.apache.druid.segment.realtime.appenderator.StreamAppenderator.mergeAndPush(StreamAppenderator.java:859) ~[druid-server-25.0.0.jar:25.0.0]
        at org.apache.druid.segment.realtime.appenderator.StreamAppenderator.lambda$push$1(StreamAppenderator.java:748) ~[druid-server-25.0.0.jar:25.0.0]
        at com.google.common.util.concurrent.Futures$1.apply(Futures.java:713) ~[guava-16.0.1.jar:?]
        at com.google.common.util.concurrent.Futures$ChainingListenableFuture.run(Futures.java:861) ~[guava-16.0.1.jar:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_352]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_352]
        at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_352]
Caused by: java.lang.InterruptedException
        at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:404) ~[?:1.8.0_352]
        at java.util.concurrent.FutureTask.get(FutureTask.java:191) ~[?:1.8.0_352]
        at org.apache.druid.segment.realtime.appenderator.UnifiedIndexerAppenderatorsManager$LimitedPoolIndexMerger.mergeQueryableIndex(UnifiedIndexerAppenderatorsManager.java:671) ~[druid-server-25.0.0.jar:25.0.0]
        ... 7 more
and finnaly :
Copy code
2023-01-09T09:01:16,564 INFO [WorkerTaskManager-NoticeHandler] org.apache.druid.indexing.worker.WorkerTaskManager - Task [index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia] completed with status [SUCCESS].
On Overlord side :
Copy code
2023-01-09T09:01:05,139 INFO [KafkaSupervisor-beam-advanced-Worker-8] org.apache.druid.indexing.overlord.MetadataTaskStorage - Updating task index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia to status: TaskStatus{id=index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia, status=FAILED, duration=-1, errorMsg=An exception occurred while waiting for task [index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia] to...}
2023-01-09T09:01:05,144 INFO [KafkaSupervisor-beam-advanced-Worker-8] org.apache.druid.indexing.overlord.RemoteTaskRunner - Shutdown [index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia] because: [An exception occurred while waiting for task [index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia] to pause: [org.apache.druid.java.util.common.ISE: Task [index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia] failed to change its status from [READING] to [PAUSED], aborting]]
2023-01-09T09:01:05,146 INFO [KafkaSupervisor-beam-advanced-Worker-8] org.apache.druid.indexing.overlord.RemoteTaskRunner - Sent shutdown message to worker: druid-indexer-v6fw:8091, status 200 OK, response: {"task":"index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia"}
Copy code
2023-01-09T09:01:05,495 INFO [TaskQueue-Manager] org.apache.druid.indexing.overlord.RemoteTaskRunner - Shutdown [index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia] because: [Task is not in knownTaskIds]
2023-01-09T09:01:05,496 INFO [TaskQueue-Manager] org.apache.druid.indexing.overlord.RemoteTaskRunner - Sent shutdown message to worker: druid-indexer-v6fw:8091, status 200 OK, response: {"task":"index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia"}
Copy code
2023-01-09T09:01:16,564 INFO [Curator-PathChildrenCache-1] org.apache.druid.indexing.overlord.RemoteTaskRunner - Worker[druid-indexer-v6fw:8091] completed task[index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia] with status[SUCCESS]
2023-01-09T09:01:16,564 INFO [Curator-PathChildrenCache-1] org.apache.druid.indexing.overlord.TaskQueue - Received SUCCESS status for task: index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia
2023-01-09T09:01:16,566 ERROR [Curator-PathChildrenCache-1] org.apache.druid.indexing.overlord.TaskQueue - Ignoring notification for already-complete task: {class=org.apache.druid.indexing.overlord.TaskQueue, task=index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia}
2023-01-09T09:01:16,566 INFO [Curator-PathChildrenCache-1] org.apache.druid.indexing.overlord.RemoteTaskRunner - Shutdown [index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia] because: [notified status change from task]
2023-01-09T09:01:16,566 INFO [Curator-PathChildrenCache-1] org.apache.druid.indexing.overlord.RemoteTaskRunner - Cleaning up task[index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia] on worker[druid-indexer-v6fw:8091]
2023-01-09T09:01:16,567 WARN [Curator-PathChildrenCache-1] org.apache.druid.indexing.overlord.TaskQueue - Unknown task completed: index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia
2023-01-09T09:01:16,567 INFO [Curator-PathChildrenCache-1] org.apache.druid.indexing.overlord.TaskQueue - Task SUCCESS: index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia (1878459 run duration)
2023-01-09T09:01:16,568 INFO [Curator-PathChildrenCache-1] org.apache.druid.indexing.overlord.RemoteTaskRunner - Task[index_kafka_beam-advanced_9e22ee33bec07d0_alaobbia] went bye bye.
I’m seeing a lot of this :
Copy code
2023-01-09T17:08:03,060 WARN [Curator-PathChildrenCache-1] org.apache.druid.indexing.overlord.TaskQueue - Unknown task completed: index_kafka_beam-advanced_86aa661daa6644e_cacdnbdo
I’m wondering if this is related to Kafka Task autoscaling
I’ll disable it for a while and check logs
3 Views
Open in Slack
PreviousNext
Powered by