Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ingestion task fails with InterruptedException when handling the segments #10866

Closed
tanisdlj opened this issue Feb 9, 2021 · 29 comments
Closed

Comments

@tanisdlj
Copy link

tanisdlj commented Feb 9, 2021

Affected Version

0.20.0

Description

We've seen tasks failing randomly. Didn't managed to get a pattern or cause, so I'm thinking might be some sort of bug.
The tasks ends up with the status:

  "statusCode": "FAILED",
  "status": "FAILED",
  "runnerStatusCode": "WAITING",

When happened, happened to three tasks that started around the same time (+-10 min)
Cluster size: 27 Dataservers (Middlemanager + Historical), 2 Brokers, 2 Routers, 2 Overlords, 2 Coordinator, 3 Zookeeper (in dedicated hosts).

Partial log:

2021-02-08T22:35:01,185 INFO [qtp1999784536-190] org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner - Stopping gracefully (status: [PUBLISHING])
2021-02-08T22:35:01,189 ERROR [task-runner-0-priority-0] org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner - Encountered exception in run() before persisting.
org.apache.kafka.common.errors.InterruptException: java.lang.InterruptedException
	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.maybeThrowInterruptException(ConsumerNetworkClient.java:520) ~[?:?]
	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:281) ~[?:?]
	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:236) ~[?:?]
	at org.apache.kafka.clients.consumer.KafkaConsumer.pollForFetches(KafkaConsumer.java:1301) ~[?:?]
	at org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1237) ~[?:?]
	at org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1210) ~[?:?]
	at org.apache.druid.indexing.kafka.KafkaRecordSupplier.poll(KafkaRecordSupplier.java:124) ~[?:?]
	at org.apache.druid.indexing.kafka.IncrementalPublishingKafkaIndexTaskRunner.getRecords(IncrementalPublishingKafkaIndexTaskRunner.java:98) ~[?:?]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.runInternal(SeekableStreamIndexTaskRunner.java:603) [druid-indexing-service-0.20.0.jar:0.20.0]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.run(SeekableStreamIndexTaskRunner.java:267) [druid-indexing-service-0.20.0.jar:0.20.0]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTask.run(SeekableStreamIndexTask.java:145) [druid-indexing-service-0.20.0.jar:0.20.0]
	at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:451) [druid-indexing-service-0.20.0.jar:0.20.0]
	at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:423) [druid-indexing-service-0.20.0.jar:0.20.0]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_275]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
Caused by: java.lang.InterruptedException
	... 17 more
2021-02-08T22:35:01,218 INFO [task-runner-0-priority-0] org.apache.druid.server.coordination.BatchDataSegmentAnnouncer - Unannouncing segment[ssp-events-hourly_2021-02-08T20:00:00.000Z_2021-02-08T21:00:00.000Z_2021-02-08T21:14:50.337Z_77] at path[/druid/segments/druid-dataserver-4:8103/druid-dataserver-4:8103_indexer-executor__default_tier_2021-02-08T18:29:28.553Z_8e48d33532c9490e9a7b6b372bf2cf0d0]
2021-02-08T22:35:01,221 INFO [task-runner-0-priority-0] org.apache.druid.server.coordination.BatchDataSegmentAnnouncer - Unannouncing segment[ssp-events-hourly_2021-02-08T19:00:00.000Z_2021-02-08T20:00:00.000Z_2021-02-08T19:58:53.766Z_427] at path[/druid/segments/druid-dataserver-4:8103/druid-dataserver-4:8103_indexer-executor__default_tier_2021-02-08T18:29:28.553Z_8e48d33532c9490e9a7b6b372bf2cf0d0]
2021-02-08T22:35:01,221 INFO [task-runner-0-priority-0] org.apache.druid.curator.announcement.Announcer - Unannouncing [/druid/segments/druid-dataserver-4:8103/druid-dataserver-4:8103_indexer-executor__default_tier_2021-02-08T18:29:28.553Z_8e48d33532c9490e9a7b6b372bf2cf0d0]
2021-02-08T22:35:01,621 ERROR [[index_kafka_ssp-events-hourly_5895d14b59e566a_fkffhhpn]-appenderator-persist] org.apache.druid.segment.realtime.appenderator.AppenderatorImpl - Incremental persist failed: {class=org.apache.druid.segment.realtime.appenderator.AppenderatorImpl, segment=ssp-events-hourly_2021-02-08T20:00:00.000Z_2021-02-08T21:00:00.000Z_2021-02-08T21:14:50.337Z_77, dataSource=ssp-events-hourly, count=10}
2021-02-08T22:35:01,623 INFO [task-runner-0-priority-0] org.apache.druid.curator.announcement.Announcer - Unannouncing [/druid/internal-discovery/PEON/druid-dataserver-4:8103]
2021-02-08T22:35:01,632 INFO [task-runner-0-priority-0] org.apache.druid.curator.discovery.CuratorDruidNodeAnnouncer - Unannounced self [{"druidNode":{"service":"druid/middleManager","host":"druid-dataserver-4","bindOnHost":false,"plaintextPort":8103,"port":-1,"tlsPort":-1,"enablePlaintextPort":true,"enableTlsPort":false},"nodeType":"peon","services":{"dataNodeService":{"type":"dataNodeService","tier":"_default_tier","maxSize":0,"type":"indexer-executor","priority":0},"lookupNodeService":{"type":"lookupNodeService","lookupTier":"__default"}}}].
2021-02-08T22:35:01,632 INFO [task-runner-0-priority-0] org.apache.druid.curator.announcement.Announcer - Unannouncing [/druid/announcements/druid-dataserver-4:8103]
2021-02-08T22:35:01,648 ERROR [task-runner-0-priority-0] org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner - Encountered exception while running task.
org.apache.kafka.common.errors.InterruptException: java.lang.InterruptedException
	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.maybeThrowInterruptException(ConsumerNetworkClient.java:520) ~[?:?]
	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:281) ~[?:?]
	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:236) ~[?:?]
	at org.apache.kafka.clients.consumer.KafkaConsumer.pollForFetches(KafkaConsumer.java:1301) ~[?:?]
	at org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1237) ~[?:?]
	at org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1210) ~[?:?]
	at org.apache.druid.indexing.kafka.KafkaRecordSupplier.poll(KafkaRecordSupplier.java:124) ~[?:?]
	at org.apache.druid.indexing.kafka.IncrementalPublishingKafkaIndexTaskRunner.getRecords(IncrementalPublishingKafkaIndexTaskRunner.java:98) ~[?:?]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.runInternal(SeekableStreamIndexTaskRunner.java:603) ~[druid-indexing-service-0.20.0.jar:0.20.0]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.run(SeekableStreamIndexTaskRunner.java:267) [druid-indexing-service-0.20.0.jar:0.20.0]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTask.run(SeekableStreamIndexTask.java:145) [druid-indexing-service-0.20.0.jar:0.20.0]
	at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:451) [druid-indexing-service-0.20.0.jar:0.20.0]
	at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:423) [druid-indexing-service-0.20.0.jar:0.20.0]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_275]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
	Suppressed: java.lang.InterruptedException
		at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:404) ~[?:1.8.0_275]
		at java.util.concurrent.FutureTask.get(FutureTask.java:191) ~[?:1.8.0_275]
		at org.apache.druid.segment.realtime.appenderator.StreamAppenderatorDriver.persist(StreamAppenderatorDriver.java:231) ~[druid-server-0.20.0.jar:0.20.0]
		at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.runInternal(SeekableStreamIndexTaskRunner.java:756) ~[druid-indexing-service-0.20.0.jar:0.20.0]
		at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.run(SeekableStreamIndexTaskRunner.java:267) [druid-indexing-service-0.20.0.jar:0.20.0]
		at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTask.run(SeekableStreamIndexTask.java:145) [druid-indexing-service-0.20.0.jar:0.20.0]
		at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:451) [druid-indexing-service-0.20.0.jar:0.20.0]
		at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:423) [druid-indexing-service-0.20.0.jar:0.20.0]
		at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_275]
		at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_275]
		at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_275]
		at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
Caused by: java.lang.InterruptedException
	... 17 more
2021-02-08T22:35:01,680 INFO [task-runner-0-priority-0] org.apache.druid.indexing.worker.executor.ExecutorLifecycle - Task completed with status: {
  "id" : "index_kafka_ssp-events-hourly_5895d14b59e566a_fkffhhpn",
  "status" : "FAILED",
  "duration" : 14743336,
  "errorMsg" : "org.apache.kafka.common.errors.InterruptException: java.lang.InterruptedException\n\tat org.apache.kaf...",
  "location" : {
    "host" : null,
    "port" : -1,
    "tlsPort" : -1
  }
}
2021-02-08T22:35:01,690 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle - Stopping lifecycle [module] stage [ANNOUNCEMENTS]
2021-02-08T22:35:01,691 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle - Stopping lifecycle [module] stage [SERVER]
@mkasprzyk
Copy link

Same problem in 0.20.1 / Similar cluster configuration

@tanisdlj
Copy link
Author

tanisdlj commented Feb 15, 2021 via email

@jai-jaiprakash
Copy link

I also see this issue Intermittently. I am using version 0.20.1.

@tanisdlj
Copy link
Author

No ack from druid so far :/

@adilsonbna
Copy link

Facing the same issue here :(

@abhishekagarwal87
Copy link
Contributor

can you share the full logs of the Kafka indexing task and supervisor?

@tanisdlj
Copy link
Author

Mhmhmh... how do I get that logs?
As far as I know the supervisor doesn't have specific logs. And no idea on how to get the Kafka Indexing Logs

@bengriffin1
Copy link

Facing a similar issue, @tanisdlj indexing logs are determined by druid.indexer.logs.type and druid.indexer.logs.directory in your runtime properties. Mine was in /opt/data/indexing-logs on the middle-manager

@tanisdlj
Copy link
Author

Thanks @bengriffin1 !!

Right now I don't have any task failing with this specific error, so I have no access to that log. If @bengriffin1 has some logs might use them instead. Otherwise next time I see it will post it here.

@tanisdlj
Copy link
Author

tanisdlj commented Apr 6, 2021

Ok, another crash. Supervisor task:

Indexer log:

{"ingestionStatsAndErrors":{"taskId":"index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc","payload":{"ingestionState":"BUILD_SEGMENTS","unparseableEvents":{},"rowStats":{"buildSegments":{"processed":184276930,"processedWithError":0,"thrownAway":78487,"unparseable":0}},"errorMsg":"org.apache.kafka.common.errors.InterruptException: java.lang.InterruptedException\n\tat org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.maybeThrowInterruptException(ConsumerNetworkClient.java:520)\n\tat org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:281)\n\tat org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:236)\n\tat org.apache.kafka.clients.consumer.KafkaConsumer.pollForFetches(KafkaConsumer.java:1301)\n\tat org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1237)\n\tat org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1210)\n\tat org.apache.druid.indexing.kafka.KafkaRecordSupplier.poll(KafkaRecordSupplier.java:124)\n\tat org.apache.druid.indexing.kafka.IncrementalPublishingKafkaIndexTaskRunner.getRecords(IncrementalPublishingKafkaIndexTaskRunner.java:98)\n\tat org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.runInternal(SeekableStreamIndexTaskRunner.java:603)\n\tat org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.run(SeekableStreamIndexTaskRunner.java:267)\n\tat org.apache.druid.indexing.seekablestream.SeekableStreamIndexTask.run(SeekableStreamIndexTask.java:145)\n\tat org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:451)\n\tat org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:423)\n\tat java.util.concurrent.FutureTask.run(FutureTask.java:266)\n\tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n\tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n\tat java.lang.Thread.run(Thread.java:748)\n\tSuppressed: java.lang.InterruptedException\n\t\tat java.util.concurrent.FutureTask.awaitDone(FutureTask.java:404)\n\t\tat java.util.concurrent.FutureTask.get(FutureTask.java:191)\n\t\tat org.apache.druid.segment.realtime.appenderator.StreamAppenderatorDriver.persist(StreamAppenderatorDriver.java:231)\n\t\tat org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.runInternal(SeekableStreamIndexTaskRunner.java:756)\n\t\t... 8 more\nCaused by: java.lang.InterruptedException\n\t... 17 more\n"},"type":"ingestionStatsAndErrors"}}
2021-04-06T13:36:36,486 INFO [qtp1718695429-151] org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner - Stopping gracefully (status: [PUBLISHING])
2021-04-06T13:36:36,490 ERROR [task-runner-0-priority-0] org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner - Encountered exception in run() before persisting.
org.apache.kafka.common.errors.InterruptException: java.lang.InterruptedException
	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.maybeThrowInterruptException(ConsumerNetworkClient.java:520) ~[?:?]
	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:281) ~[?:?]
	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:236) ~[?:?]
	at org.apache.kafka.clients.consumer.KafkaConsumer.pollForFetches(KafkaConsumer.java:1301) ~[?:?]
	at org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1237) ~[?:?]
	at org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1210) ~[?:?]
	at org.apache.druid.indexing.kafka.KafkaRecordSupplier.poll(KafkaRecordSupplier.java:124) ~[?:?]
	at org.apache.druid.indexing.kafka.IncrementalPublishingKafkaIndexTaskRunner.getRecords(IncrementalPublishingKafkaIndexTaskRunner.java:98) ~[?:?]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.runInternal(SeekableStreamIndexTaskRunner.java:603) [druid-indexing-service-0.20.1.jar:0.20.1]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.run(SeekableStreamIndexTaskRunner.java:267) [druid-indexing-service-0.20.1.jar:0.20.1]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTask.run(SeekableStreamIndexTask.java:145) [druid-indexing-service-0.20.1.jar:0.20.1]
	at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:451) [druid-indexing-service-0.20.1.jar:0.20.1]
	at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:423) [druid-indexing-service-0.20.1.jar:0.20.1]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_275]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
Caused by: java.lang.InterruptedException
	... 17 more
2021-04-06T13:36:36,527 ERROR [task-runner-0-priority-0] org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner - Error while publishing segments for sequenceNumber[SequenceMetadata{sequenceId=12, sequenceName='index_kafka_ssp-events-hourly_4e62ca9663a43dc_12', assignments=[], startOffsets={70=4049765636, 10=97308684185}, exclusiveStartPartitions=[], endOffsets={70=4051651832, 10=97310341952}, 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:867) [druid-indexing-service-0.20.1.jar:0.20.1]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.run(SeekableStreamIndexTaskRunner.java:267) [druid-indexing-service-0.20.1.jar:0.20.1]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTask.run(SeekableStreamIndexTask.java:145) [druid-indexing-service-0.20.1.jar:0.20.1]
	at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:451) [druid-indexing-service-0.20.1.jar:0.20.1]
	at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:423) [druid-indexing-service-0.20.1.jar:0.20.1]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_275]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
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:?]
	... 15 more
2021-04-06T13:36:36,545 INFO [task-runner-0-priority-0] org.apache.druid.server.coordination.BatchDataSegmentAnnouncer - Unannouncing segment[ssp-events-hourly_2021-04-06T13:00:00.000Z_2021-04-06T14:00:00.000Z_2021-04-06T13:00:01.025Z_103] at path[/druid/segments/druid-dataserver-11:8100/druid-dataserver-11:8100_indexer-executor__default_tier_2021-04-06T09:24:09.621Z_11bf1d0b81054d63a80702952d9e13700]
2021-04-06T13:36:36,546 INFO [task-runner-0-priority-0] org.apache.druid.server.coordination.BatchDataSegmentAnnouncer - Unannouncing segment[ssp-events-hourly_2021-04-06T12:00:00.000Z_2021-04-06T13:00:00.000Z_2021-04-06T12:00:00.048Z_283] at path[/druid/segments/druid-dataserver-11:8100/druid-dataserver-11:8100_indexer-executor__default_tier_2021-04-06T09:24:09.621Z_11bf1d0b81054d63a80702952d9e13700]
2021-04-06T13:36:36,546 INFO [task-runner-0-priority-0] org.apache.druid.server.coordination.BatchDataSegmentAnnouncer - Unannouncing segment[ssp-events-hourly_2021-04-06T13:00:00.000Z_2021-04-06T14:00:00.000Z_2021-04-06T13:00:01.025Z_30] at path[/druid/segments/druid-dataserver-11:8100/druid-dataserver-:8100_indexer-executor__default_tier_2021-04-06T09:24:09.621Z_11bf1d0b81054d63a80702952d9e13700]
2021-04-06T13:36:36,546 INFO [task-runner-0-priority-0] org.apache.druid.curator.announcement.Announcer - Unannouncing [/druid/segments/druid-dataserver-11:8100/druid-dataserver-11:8100_indexer-executor__default_tier_2021-04-06T09:24:09.621Z_11bf1d0b81054d63a80702952d9e13700]
2021-04-06T13:36:37,104 WARN [[index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc]-appenderator-merge] org.apache.druid.segment.realtime.appenderator.AppenderatorImpl - Failed to push merged index for segment[ssp-events-hourly_2021-04-06T12:00:00.000Z_2021-04-06T13:00:00.000Z_2021-04-06T12:00:00.048Z_283].
java.nio.channels.ClosedByInterruptException: null
	at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:202) ~[?:1.8.0_275]
	at sun.nio.ch.FileChannelImpl.write(FileChannelImpl.java:216) ~[?:1.8.0_275]
	at org.apache.druid.io.Channels.writeFully(Channels.java:32) ~[druid-core-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.writeout.FileWriteOutBytes.flush(FileWriteOutBytes.java:62) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.writeout.FileWriteOutBytes.flushIfNeeded(FileWriteOutBytes.java:54) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.writeout.FileWriteOutBytes.write(FileWriteOutBytes.java:86) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.data.GenericIndexedWriter$1.writeTo(GenericIndexedWriter.java:123) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.data.GenericIndexedWriter$1.writeTo(GenericIndexedWriter.java:96) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.data.GenericIndexedWriter.write(GenericIndexedWriter.java:237) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.data.BlockLayoutColumnarDoublesSerializer.add(BlockLayoutColumnarDoublesSerializer.java:95) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.DoubleColumnSerializer.serialize(DoubleColumnSerializer.java:83) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.IndexMergerV9.mergeIndexesAndWriteColumns(IndexMergerV9.java:573) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.IndexMergerV9.makeIndexFiles(IndexMergerV9.java:267) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.IndexMergerV9.merge(IndexMergerV9.java:999) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.IndexMergerV9.mergeQueryableIndex(IndexMergerV9.java:917) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.IndexMergerV9.mergeQueryableIndex(IndexMergerV9.java:895) ~[druid-processing-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.realtime.appenderator.AppenderatorImpl.mergeAndPush(AppenderatorImpl.java:769) ~[druid-server-0.20.1.jar:0.20.1]
	at org.apache.druid.segment.realtime.appenderator.AppenderatorImpl.lambda$push$1(AppenderatorImpl.java:660) ~[druid-server-0.20.1.jar:0.20.1]
	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_275]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_275]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
2021-04-06T13:36:37,133 ERROR [[index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc]-appenderator-persist] org.apache.druid.segment.realtime.appenderator.AppenderatorImpl - Incremental persist failed: {class=org.apache.druid.segment.realtime.appenderator.AppenderatorImpl, segment=ssp-events-hourly_2021-04-06T13:00:00.000Z_2021-04-06T14:00:00.000Z_2021-04-06T13:00:01.025Z_103, dataSource=ssp-events-hourly, count=9}
2021-04-06T13:36:37,157 INFO [task-runner-0-priority-0] org.apache.druid.curator.announcement.Announcer - Unannouncing [/druid/internal-discovery/PEON/druid-dataserver-11:8100]
2021-04-06T13:36:37,164 INFO [task-runner-0-priority-0] org.apache.druid.curator.discovery.CuratorDruidNodeAnnouncer - Unannounced self [{"druidNode":{"service":"druid/middleManager","host":"druid-dataserver-11","bindOnHost":false,"plaintextPort":8100,"port":-1,"tlsPort":-1,"enablePlaintextPort":true,"enableTlsPort":false},"nodeType":"peon","services":{"dataNodeService":{"type":"dataNodeService","tier":"_default_tier","maxSize":0,"type":"indexer-executor","priority":0},"lookupNodeService":{"type":"lookupNodeService","lookupTier":"__default"}}}].
2021-04-06T13:36:37,165 INFO [task-runner-0-priority-0] org.apache.druid.curator.announcement.Announcer - Unannouncing [/druid/announcements/druid-dataserver-11:8100]
2021-04-06T13:36:37,179 ERROR [task-runner-0-priority-0] org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner - Encountered exception while running task.
org.apache.kafka.common.errors.InterruptException: java.lang.InterruptedException
	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.maybeThrowInterruptException(ConsumerNetworkClient.java:520) ~[?:?]
	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:281) ~[?:?]
	at org.apache.kafka.clients.consumer.internals.ConsumerNetworkClient.poll(ConsumerNetworkClient.java:236) ~[?:?]
	at org.apache.kafka.clients.consumer.KafkaConsumer.pollForFetches(KafkaConsumer.java:1301) ~[?:?]
	at org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1237) ~[?:?]
	at org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:1210) ~[?:?]
	at org.apache.druid.indexing.kafka.KafkaRecordSupplier.poll(KafkaRecordSupplier.java:124) ~[?:?]
	at org.apache.druid.indexing.kafka.IncrementalPublishingKafkaIndexTaskRunner.getRecords(IncrementalPublishingKafkaIndexTaskRunner.java:98) ~[?:?]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.runInternal(SeekableStreamIndexTaskRunner.java:603) ~[druid-indexing-service-0.20.1.jar:0.20.1]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.run(SeekableStreamIndexTaskRunner.java:267) [druid-indexing-service-0.20.1.jar:0.20.1]
	at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTask.run(SeekableStreamIndexTask.java:145) [druid-indexing-service-0.20.1.jar:0.20.1]
	at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:451) [druid-indexing-service-0.20.1.jar:0.20.1]
	at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:423) [druid-indexing-service-0.20.1.jar:0.20.1]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_275]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_275]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
	Suppressed: java.lang.InterruptedException
		at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:404) ~[?:1.8.0_275]
		at java.util.concurrent.FutureTask.get(FutureTask.java:191) ~[?:1.8.0_275]
		at org.apache.druid.segment.realtime.appenderator.StreamAppenderatorDriver.persist(StreamAppenderatorDriver.java:231) ~[druid-server-0.20.1.jar:0.20.1]
		at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.runInternal(SeekableStreamIndexTaskRunner.java:756) ~[druid-indexing-service-0.20.1.jar:0.20.1]
		at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner.run(SeekableStreamIndexTaskRunner.java:267) [druid-indexing-service-0.20.1.jar:0.20.1]
		at org.apache.druid.indexing.seekablestream.SeekableStreamIndexTask.run(SeekableStreamIndexTask.java:145) [druid-indexing-service-0.20.1.jar:0.20.1]
		at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:451) [druid-indexing-service-0.20.1.jar:0.20.1]
		at org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner$SingleTaskBackgroundRunnerCallable.call(SingleTaskBackgroundRunner.java:423) [druid-indexing-service-0.20.1.jar:0.20.1]
		at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_275]
		at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_275]
		at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_275]
		at java.lang.Thread.run(Thread.java:748) [?:1.8.0_275]
Caused by: java.lang.InterruptedException
	... 17 more
2021-04-06T13:36:37,217 INFO [task-runner-0-priority-0] org.apache.druid.indexing.worker.executor.ExecutorLifecycle - Task completed with status: {
  "id" : "index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc",
  "status" : "FAILED",
  "duration" : 15153268,
  "errorMsg" : "org.apache.kafka.common.errors.InterruptException: java.lang.InterruptedException\n\tat org.apache.kaf...",
  "location" : {
    "host" : null,
    "port" : -1,
    "tlsPort" : -1
  }
}
2021-04-06T13:36:37,229 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle - Stopping lifecycle [module] stage [ANNOUNCEMENTS]
2021-04-06T13:36:37,230 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle - Stopping lifecycle [module] stage [SERVER]
2021-04-06T13:37:07,254 INFO [main] org.eclipse.jetty.server.AbstractConnector - Stopped ServerConnector@73dbe25{HTTP/1.1, (http/1.1)}{0.0.0.0:8100}
2021-04-06T13:37:07,255 INFO [main] org.eclipse.jetty.server.session - node0 Stopped scavenging
2021-04-06T13:37:07,259 INFO [main] org.eclipse.jetty.server.handler.ContextHandler - Stopped o.e.j.s.ServletContextHandler@6d35ff7b{/,null,STOPPED}
2021-04-06T13:37:07,266 ERROR [main] org.apache.druid.server.initialization.jetty.JettyServerModule - Jetty lifecycle event failed [class org.eclipse.jetty.server.Server]
java.util.concurrent.TimeoutException: null
	at org.eclipse.jetty.util.FutureCallback.get(FutureCallback.java:130) ~[jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
	at org.eclipse.jetty.util.FutureCallback.get(FutureCallback.java:30) ~[jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
	at org.eclipse.jetty.server.handler.AbstractHandlerContainer.doShutdown(AbstractHandlerContainer.java:175) ~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
	at org.eclipse.jetty.server.Server.doStop(Server.java:447) ~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
	at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:94) [jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
	at org.apache.druid.server.initialization.jetty.JettyServerModule$2.stop(JettyServerModule.java:454) [druid-server-0.20.1.jar:0.20.1]
	at org.apache.druid.java.util.common.lifecycle.Lifecycle.stop(Lifecycle.java:368) [druid-core-0.20.1.jar:0.20.1]
	at org.apache.druid.cli.CliPeon.run(CliPeon.java:306) [druid-services-0.20.1.jar:0.20.1]
	at org.apache.druid.cli.Main.main(Main.java:113) [druid-services-0.20.1.jar:0.20.1]
2021-04-06T13:37:07,270 WARN [main] org.apache.druid.server.initialization.jetty.JettyServerModule - Unable to stop Jetty server.
java.util.concurrent.TimeoutException: null
	at org.eclipse.jetty.util.FutureCallback.get(FutureCallback.java:130) ~[jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
	at org.eclipse.jetty.util.FutureCallback.get(FutureCallback.java:30) ~[jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
	at org.eclipse.jetty.server.handler.AbstractHandlerContainer.doShutdown(AbstractHandlerContainer.java:175) ~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
	at org.eclipse.jetty.server.Server.doStop(Server.java:447) ~[jetty-server-9.4.34.v20201102.jar:9.4.34.v20201102]
	at org.eclipse.jetty.util.component.AbstractLifeCycle.stop(AbstractLifeCycle.java:94) ~[jetty-util-9.4.34.v20201102.jar:9.4.34.v20201102]
	at org.apache.druid.server.initialization.jetty.JettyServerModule$2.stop(JettyServerModule.java:454) [druid-server-0.20.1.jar:0.20.1]
	at org.apache.druid.java.util.common.lifecycle.Lifecycle.stop(Lifecycle.java:368) [druid-core-0.20.1.jar:0.20.1]
	at org.apache.druid.cli.CliPeon.run(CliPeon.java:306) [druid-services-0.20.1.jar:0.20.1]
	at org.apache.druid.cli.Main.main(Main.java:113) [druid-services-0.20.1.jar:0.20.1]
2021-04-06T13:37:07,271 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle - Stopping lifecycle [module] stage [NORMAL]
2021-04-06T13:37:07,272 INFO [main] org.apache.druid.server.coordination.ZkCoordinator - Stopping ZkCoordinator for [DruidServerMetadata{name='druid-dataserver-11:8100', hostAndPort='druid-dataserver-1:8100', hostAndTlsPort='null', maxSize=0, tier='_default_tier', type=indexer-executor, priority=0}]
2021-04-06T13:37:07,272 INFO [main] org.apache.druid.server.coordination.SegmentLoadDropHandler - Stopping...
2021-04-06T13:37:07,272 INFO [main] org.apache.druid.server.coordination.SegmentLoadDropHandler - Stopped.
2021-04-06T13:37:07,277 INFO [main] org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner - Starting graceful shutdown of task[index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc].
2021-04-06T13:37:07,277 INFO [main] org.apache.druid.indexing.seekablestream.SeekableStreamIndexTaskRunner - Stopping gracefully (status: [PUBLISHING])
2021-04-06T13:37:07,285 INFO [main] org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner - Graceful shutdown of task[index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc] finished in 0ms.
2021-04-06T13:37:07,353 INFO [LookupExtractorFactoryContainerProvider-MainThread] org.apache.druid.query.lookup.LookupReferencesManager - Lookup Management loop exited. Lookup notices are not handled anymore.
2021-04-06T13:37:07,354 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='IIN'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@59ffeff7
2021-04-06T13:37:07,356 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherProductIIN].
2021-04-06T13:37:07,356 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/adtagConfigs.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='id', valueFieldName='creativePublicationId'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@3cc22ab4
2021-04-06T13:37:07,356 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [adtagCreativePublicationId].
2021-04-06T13:37:07,356 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='tier'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@13bfbdc2
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherTier].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/adtagConfigs.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='id', valueFieldName='creativePublicationName'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@4d3fea62
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [adtagCreativePublicationName].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/adtagConfigs.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='id', valueFieldName='videoDuration'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@2860a0af
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [adtagVideoDuration].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/adtagConfigs.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='id', valueFieldName='adtagName'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@6a3ae078
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [adtagName].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/adtagConfigs.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='id', valueFieldName='creativeId'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@4ff4c694
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [adtagCreativeId].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='IID'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@32a8e87a
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherProductIID].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='FID'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@57380ab8
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherProductFID].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/deals.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='dealId', valueFieldName='name'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@31c4da0d
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [dealName].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='country'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@53078487
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherCountry].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='id'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@3c6f005f
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherId].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='editorialGroupName'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@64fd134f
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [editorialGroupName].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='PIV'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@16050083
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherProductPIV].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='categoryName'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@3850830a
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherCategory].
2021-04-06T13:37:07,357 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='name'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@60c28b08
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherName].
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/adtagConfigs.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='id', valueFieldName='productFamily'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@1107325c
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [adtagProductFamily].
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/adtagConfigs.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='id', valueFieldName='size'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@25c01974
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [adtagSize].
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/adtagConfigs.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='id', valueFieldName='extAdserver'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@43f81db5
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [adtagExtAdserver].
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='IVD'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@30a3d5e3
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherProductIVD].
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/adtagConfigs.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='id', valueFieldName='channel'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@79c0a348
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [adtagChannel].
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='IIV'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@6021c46e
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherProductIIV].
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='FIV'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@47c78112
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherProductFIV].
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.server.lookup.namespace.cache.CacheScheduler - Closing namespace [UriExtractionNamespace{uri=file:///usr/share/druid/lookups/publishers.json, uriPrefix=null, namespaceParseSpec=JSONFlatDataParser{keyFieldName='token', valueFieldName='IIT'}, fileRegex='null', pollPeriod=PT30M}] : org.apache.druid.server.lookup.namespace.cache.CacheScheduler$EntryImpl@7d520a64
2021-04-06T13:37:07,358 INFO [main] org.apache.druid.query.lookup.LookupReferencesManager - Closed lookup [publisherProductIIT].
2021-04-06T13:37:07,416 INFO [Curator-Framework-0] org.apache.curator.framework.imps.CuratorFrameworkImpl - backgroundOperationsLoop exiting
2021-04-06T13:37:07,422 INFO [main] org.apache.zookeeper.ZooKeeper - Session: 0x1034ca014c22804 closed
2021-04-06T13:37:07,422 INFO [main-EventThread] org.apache.zookeeper.ClientCnxn - EventThread shut down for session: 0x1034ca014c22804
2021-04-06T13:37:07,422 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle$CloseableHandler - Closing object[org.asynchttpclient.DefaultAsyncHttpClient@7be3abaa]
2021-04-06T13:37:07,434 INFO [main] org.apache.druid.java.util.common.lifecycle.Lifecycle - Stopping lifecycle [module] stage [INIT]
Finished peon task

index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc .txt

@tanisdlj
Copy link
Author

tanisdlj commented Apr 6, 2021

Middlemanager log:

Apr  6 09:00:01 druid-dataserver-11 java[6601]: 2021-04-06T09:00:01,455 INFO [NodeRoleWatcher[COORDINATOR]] org.apache.druid.curator.discovery.CuratorDruidNodeDiscoveryProvider$NodeRoleWatcher - Node[http://druid-master-1:8081] of role[coordinator] went offline.
Apr  6 09:04:17 druid-dataserver-11 java[6601]: 2021-04-06T09:04:17,958 INFO [NodeRoleWatcher[COORDINATOR]] org.apache.druid.curator.discovery.CuratorDruidNodeDiscoveryProvider$NodeRoleWatcher - Node[http://druid-master-1:8081] of role[coordinator] detected.
Apr  6 09:23:34 druid-dataserver-11 java[6601]: 2021-04-06T09:23:34,935 INFO [WorkerTaskManager-NoticeHandler] org.apache.druid.indexing.worker.WorkerTaskManager - Task[index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc] started.
Apr  6 09:23:34 druid-dataserver-11 java[6601]: 2021-04-06T09:23:34,951 INFO [forking-task-runner-0] org.apache.druid.indexing.overlord.ForkingTaskRunner - Running command: java -cp /etc/druid/_common:/etc/druid/middleManager:/opt/druid/lib/jackson-databind-2.10.5.1.jar:/opt/druid/lib/fastutil-8.2.3.jar:/opt/druid/lib/commons-logging-1.1.1.jar:/opt/druid/lib/commons-text-1.3.jar:/opt/druid/lib/curator-client-4.3.0.jar:/opt/druid/lib/netty-handler-4.1.48.Final.jar:/opt/druid/lib/javax.el-3.0.0.jar:/opt/druid/lib/maven-settings-builder-3.1.1.jar:/opt/druid/lib/joni-2.1.27.jar:/opt/druid/lib/joda-time-2.10.5.jar:/opt/druid/lib/classmate-1.1.0.jar:/opt/druid/lib/asm-commons-7.1.jar:/opt/druid/lib/javax.activation-api-1.2.0.jar:/opt/druid/lib/spymemcached-2.12.3.jar:/opt/druid/lib/jetty-http-9.4.34.v20201102.jar:/opt/druid/lib/commons-math3-3.6.1.jar:/opt/druid/lib/tesla-aether-0.0.5.jar:/opt/druid/lib/commons-io-2.6.jar:/opt/druid/lib/jackson-core-2.10.2.jar:/opt/druid/lib/audience-annotations-0.5.0.jar:/opt/druid/lib/guice-servlet-4.1.0.jar:/opt/druid/lib/commons-collections-3.2.2.jar:/opt/druid/lib/javax.el-api-3.0.0.jar:/opt/druid/lib/maven-artifact-3.6.0.jar:/opt/druid/lib/avatica-server-1.17.0.jar:/opt/druid/lib/httpcore-4.4.11.jar:/opt/druid/lib/aether-api-0.9.0.M2.jar:/opt/druid/lib/checker-qual-2.5.7.jar:/opt/druid/lib/protobuf-java-3.11.0.jar:/opt/druid/lib/RoaringBitmap-0.9.0.jar:/opt/druid/lib/maven-model-builder-3.1.1.jar:/opt/druid/lib/jetty-util-9.4.34.v20201102.jar:/opt/druid/lib/aether-spi-0.9.0.M2.jar:/opt/druid/lib/jaxb-runtime-2.3.1.jar:/opt/druid/lib/guice-multibindings-4.1.0.jar:/opt/druid/lib/asm-tree-7.1.jar:/opt/druid/lib/janino-3.0.11.jar:/opt/druid/lib/jmespath-java-1.11.199.jar:/opt/druid/lib/druid-console-0.20.1.jar:/opt/druid/lib/netty-handler-proxy-4.1.48.Final.jar:/opt/druid/lib/xz-1.8.jar:/opt/druid/lib/derbynet-10.14.2.0.jar:/opt/druid/lib/druid-core-0.20.1.jar:/opt/druid/lib/plexus-utils-3.0.24.jar:/opt/druid/lib/jackson-module-guice-2.10.2.jar:/opt/druid/lib/druid-indexing-service-0.20.1.jar:/opt/druid/lib/netty-transport-native-
Apr  6 09:23:34 druid-dataserver-11 java[6601]: epoll-4.1.48.Final-linux-x86_64.jar:/opt/druid/lib/istack-commons-runtime-3.0.7.jar:/opt/druid/lib/aws-java-sdk-ec2-1.11.199.jar:/opt/druid/lib/async-http-client-2.5.3.jar:/opt/druid/lib/esri-geometry-api-2.2.0.jar:/opt/druid/lib/log4j-1.2-api-2.8.2.jar:/opt/druid/lib/compress-lzf-1.0.4.jar:/opt/druid/lib/curator-framework-4.3.0.jar:/opt/druid/lib/google-http-client-1.26.0.jar:/opt/druid/lib/config-magic-0.9.jar:/opt/druid/lib/netty-transport-4.1.48.Final.jar:/opt/druid/lib/log4j-core-2.8.2.jar:/opt/druid/lib/disruptor-3.3.6.jar:/opt/druid/lib/jsr305-2.0.1.jar:/opt/druid/lib/jetty-servlet-9.4.34.v20201102.jar:/opt/druid/lib/aws-java-sdk-kms-1.11.199.jar:/opt/druid/lib/druid-aws-common-0.20.1.jar:/opt/druid/lib/avatica-metrics-1.17.0.jar:/opt/druid/lib/log4j-jul-2.8.2.jar:/opt/druid/lib/commons-compiler-3.0.11.jar:/opt/druid/lib/netty-common-4.1.48.Final.jar:/opt/druid/lib/aether-util-0.9.0.M2.jar:/opt/druid/lib/netty-resolver-dns-4.1.48.Final.jar:/opt/druid/lib/calcite-core-1.21.0.jar:/opt/druid/lib/netty-buffer-4.1.48.Final.jar:/opt/druid/lib/druid-processing-0.20.1.jar:/opt/druid/lib/aws-java-sdk-core-1.11.199.jar:/opt/druid/lib/druid-hll-0.20.1.jar:/opt/druid/lib/calcite-linq4j-1.21.0.jar:/opt/druid/lib/jdbi-2.63.1.jar:/opt/druid/lib/maven-model-3.1.1.jar:/opt/druid/lib/resilience4j-core-1.3.1.jar:/opt/druid/lib/async-http-client-netty-utils-2.5.3.jar:/opt/druid/lib/commons-lang3-3.8.1.jar:/opt/druid/lib/jsr311-api-1.1.1.jar:/opt/druid/lib/druid-sql-0.20.1.jar:/opt/druid/lib/avatica-core-1.17.0.jar:/opt/druid/lib/extendedset-0.20.1.jar:/opt/druid/lib/google-api-client-1.26.0.jar:/opt/druid/lib/jetty-io-9.4.34.v20201102.jar:/opt/druid/lib/log4j-api-2.8.2.jar:/opt/druid/lib/aopalliance-1.0.jar:/opt/druid/lib/jaxb-api-2.3.1.jar:/opt/druid/lib/icu4j-55.1.jar:/opt/druid/lib/validation-api-1.1.0.Final.jar:/opt/druid/lib/resilience4j-bulkhead-1.3.1.jar:/opt/druid/lib/caffeine-2.8.0.jar:/opt/druid/lib/datasketches-memory-1.2.0-incubating.jar:/opt/druid/lib/j2objc-annotations-1.1.jar:/opt/druid/lib/jetty-client-9.4.34.
Apr  6 09:23:34 druid-dataserver-11 java[6601]: v20201102.jar:/opt/druid/lib/jboss-logging-3.2.1.Final.jar:/opt/druid/lib/shims-0.9.0.jar:/opt/druid/lib/jetty-servlets-9.4.34.v20201102.jar:/opt/druid/lib/wagon-provider-api-2.4.jar:/opt/druid/lib/reactive-streams-1.0.2.jar:/opt/druid/lib/jetty-rewrite-9.4.34.v20201102.jar:/opt/druid/lib/json-smart-2.3.jar:/opt/druid/lib/aether-connector-okhttp-0.0.9.jar:/opt/druid/lib/aws-java-sdk-s3-1.11.199.jar:/opt/druid/lib/stax-ex-1.8.jar:/opt/druid/lib/derby-10.14.2.0.jar:/opt/druid/lib/guice-4.1.0.jar:/opt/druid/lib/sigar-1.6.5.132.jar:/opt/druid/lib/jetty-security-9.4.34.v20201102.jar:/opt/druid/lib/jvm-attach-api-1.5.jar:/opt/druid/lib/opencsv-4.6.jar:/opt/druid/lib/commons-compress-1.19.jar:/opt/druid/lib/datasketches-java-1.3.0-incubating.jar:/opt/druid/lib/jackson-jq-0.0.10.jar:/opt/druid/lib/jersey-servlet-1.19.3.jar:/opt/druid/lib/druid-gcp-common-0.20.1.jar:/opt/druid/lib/aether-connector-file-0.9.0.M2.jar:/opt/druid/lib/derbyclient-10.14.2.0.jar:/opt/druid/lib/jackson-module-jaxb-annotations-2.10.2.jar:/opt/druid/lib/maven-settings-3.1.1.jar:/opt/druid/lib/druid-indexing-hadoop-0.20.1.jar:/opt/druid/lib/airline-0.7.jar:/opt/druid/lib/jna-4.5.1.jar:/opt/druid/lib/javax.activation-1.2.0.jar:/opt/druid/lib/ion-java-1.0.2.jar:/opt/druid/lib/jackson-jaxrs-base-2.10.2.jar:/opt/druid/lib/slf4j-api-1.7.25.jar:/opt/druid/lib/jakarta.activation-api-1.2.1.jar:/opt/druid/lib/httpclient-4.5.10.jar:/opt/druid/lib/druid-server-0.20.1.jar:/opt/druid/lib/netty-3.10.6.Final.jar:/opt/druid/lib/jackson-datatype-joda-2.10.2.jar:/opt/druid/lib/asm-analysis-7.1.jar:/opt/druid/lib/maven-aether-provider-3.1.1.jar:/opt/druid/lib/log4j-slf4j-impl-2.8.2.jar:/opt/druid/lib/vavr-match-0.10.2.jar:/opt/druid/lib/metrics-core-4.0.0.jar:/opt/druid/lib/rhino-1.7.11.jar:/opt/druid/lib/aether-impl-0.9.0.M2.jar:/opt/druid/lib/netty-codec-http-4.1.48.Final.jar:/opt/druid/lib/netty-codec-4.1.48.Final.jar:/opt/druid/lib/jackson-annotations-2.10.2.jar:/opt/druid/lib/commons-net-3.6.jar:/opt/druid/lib/jackson-datatype-guava-2.10.2.jar:/opt/druid/lib/txw2
Apr  6 09:23:34 druid-dataserver-11 java[6601]: -2.3.1.jar:/opt/druid/lib/jackson-jaxrs-smile-provider-2.10.2.jar:/opt/druid/lib/google-oauth-client-1.26.0.jar:/opt/druid/lib/zstd-jni-1.3.3-1.jar:/opt/druid/lib/jersey-guice-1.19.3.jar:/opt/druid/lib/jcl-over-slf4j-1.7.12.jar:/opt/druid/lib/netty-codec-socks-4.1.48.Final.jar:/opt/druid/lib/lz4-java-1.7.1.jar:/opt/druid/lib/asm-7.1.jar:/opt/druid/lib/commons-lang-2.6.jar:/opt/druid/lib/jline-0.9.94.jar:/opt/druid/lib/commons-collections4-4.2.jar:/opt/druid/lib/javax.inject-1.jar:/opt/druid/lib/netty-resolver-4.1.48.Final.jar:/opt/druid/lib/curator-x-discovery-4.3.0.jar:/opt/druid/lib/jersey-core-1.19.3.jar:/opt/druid/lib/maven-repository-metadata-3.1.1.jar:/opt/druid/lib/json-path-2.3.0.jar:/opt/druid/lib/guava-16.0.1.jar:/opt/druid/lib/netty-codec-dns-4.1.48.Final.jar:/opt/druid/lib/commons-beanutils-1.9.4.jar:/opt/druid/lib/jackson-dataformat-cbor-2.10.2.jar:/opt/druid/lib/plexus-interpolation-1.19.jar:/opt/druid/lib/okhttp-1.0.2.jar:/opt/druid/lib/hibernate-validator-5.2.5.Final.jar:/opt/druid/lib/google-http-client-jackson2-1.26.0.jar:/opt/druid/lib/javax.servlet-api-3.1.0.jar:/opt/druid/lib/commons-dbcp2-2.0.1.jar:/opt/druid/lib/jakarta.xml.bind-api-2.3.2.jar:/opt/druid/lib/commons-pool2-2.2.jar:/opt/druid/lib/jetty-continuation-9.4.34.v20201102.jar:/opt/druid/lib/jcodings-1.0.43.jar:/opt/druid/lib/jetty-proxy-9.4.34.v20201102.jar:/opt/druid/lib/commons-codec-1.13.jar:/opt/druid/lib/jetty-server-9.4.34.v20201102.jar:/opt/druid/lib/error_prone_annotations-2.3.2.jar:/opt/druid/lib/aggdesigner-algorithm-6.0.jar:/opt/druid/lib/netty-reactive-streams-2.0.0.jar:/opt/druid/lib/jackson-jaxrs-json-provider-2.10.2.jar:/opt/druid/lib/FastInfoset-1.2.15.jar:/opt/druid/lib/jackson-dataformat-smile-2.10.2.jar:/opt/druid/lib/netty-transport-native-unix-common-4.1.48.Final.jar:/opt/druid/lib/curator-recipes-4.3.0.jar:/opt/druid/lib/vavr-0.10.2.jar:/opt/druid/lib/antlr4-runtime-4.5.1.jar:/opt/druid/lib/jersey-server-1.19.3.jar:/opt/druid/lib/guice-assistedinject-4.1.0.jar:/opt/druid/lib/accessors-smart-1.2.jar:/opt/druid/li
Apr  6 09:23:34 druid-dataserver-11 java[6601]: b/druid-services-0.20.1.jar:/opt/druid/lib/zookeeper-3.4.14.jar:/opt/jmx-exporter/jmx_prometheus_javaagent-0.14.0.jar -server -Xmx3g -Xms3g -XX:MaxDirectMemorySize=2g -Duser.timezone=UTC -Dfile.encoding=UTF-8 -Djava.util.logging.manager=org.apache.logging.log4j.jul.LogManager -Djava.io.tmpdir=/druid/tmp/peon -XX:+UseG1GC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCApplicationStoppedTime -XX:+PrintGCApplicationConcurrentTime -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=50 -XX:GCLogFileSize=10m -XX:+ExitOnOutOfMemoryError -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/var/log/druid/peon.hprof -Xloggc:/var/log/druid/peon.gc.log -Ddruid.announcer.skipLoadSpec=true -Ddruid.indexer.task.baseTaskDir=/druid/task -Ddruid.metadata.storage.connector.password=<masked> -Ddruid.indexer.fork.property.druid.processing.numThreads=2 -Ddruid.emitter.logging.logLevel=info -Ddruid.indexer.logs.prefix=indexing-logs -Ddruid.emitter=http -Ddruid.indexer.fork.property.druid.processing.buffer.sizeBytes=104857600 -Ddruid.google.bucket=seedtag_analytics_druid -Ddruid.indexer.task.restoreTasksOnRestart=true -Duser.timezone=UTC -Ddruid.cache.sizeInBytes=300MiB -Ddruid.announcer.skipDimensionsAndMetrics=true -Ddruid.emitter.http.recipientBaseUrl=http://druid-exporter-1:8080/druid -Dfile.encoding.pkg=sun.io -Ddruid.selectors.coordinator.serviceName=druid/coordinator -Ddruid.selectors.indexing.serviceName=druid/overlord -Ddruid.indexing.doubleStorage=double -Ddruid.query.vectorize=true -Ddruid.realtime.cache.useCache=true -Ddruid.server.http.numThreads=50 -Ddruid.worker.capacity=9 -Ddruid.cache.type=caffeine -Ddruid.google.prefix=storage -Ddruid.service=druid/middleManager -Ddruid.metadata.storage.connector.user=druid -Ddruid.metadata.storage.type=mysql -Ddruid.metadata.storage.connector.connectURI=jdbc:mysql://10.167.144.13:3306/druid -Ddruid.plaintextPort=8091 -Djava.io.tmpdir=/druid/tmp/middlemanager -Ddruid.extensions.loadList=["druid-datasketches", "druid-lookups-cached-global", "druid-google-extensi
Apr  6 09:23:34 druid-dataserver-11 java[6601]: ons", "mysql-metadata-storage", "druid-kafka-indexing-service", "ssp-events-extension"] -Ddruid.startup.logging.logProperties=true -Ddruid.indexer.fork.property.druid.lookup.enableLookupSyncOnStartup=true -Ddruid.global.http.readTimeout=PT30M -Ddruid.zk.service.host=druid-zookeeper-1:2181,druid-zookeeper-2:2181,druid-zookeeper-3:2181 -Ddruid.realtime.cache.populateCache=true -Ddruid.global.http.unusedConnectionTimeout=PT27M -Ddruid.indexer.logs.bucket=seedtag_analytics_druid_logs -Ddruid.zk.paths.base=/druid -Dfile.encoding=UTF-8 -Ddruid.storage.type=google -Ddruid.indexer.fork.property.druid.processing.numMergeBuffers=2 -Ddruid.indexer.logs.type=google -Ddruid.processing.numThreads=2 -Ddruid.processing.buffer.sizeBytes=104857600 -Ddruid.lookup.enableLookupSyncOnStartup=true -Ddruid.processing.numMergeBuffers=2 -Ddruid.metrics.emitter.dimension.dataSource=ssp-events-hourly -Ddruid.metrics.emitter.dimension.taskId=index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc -Ddruid.metrics.emitter.dimension.taskType=index_kafka -Ddruid.host=druid-dataserver-11 -Ddruid.plaintextPort=8100 -Ddruid.tlsPort=-1 -Ddruid.task.executor.service=druid/middleManager -Ddruid.task.executor.host=druid-dataserver-11 -Ddruid.task.executor.plaintextPort=8091 -Ddruid.task.executor.enablePlaintextPort=true -Ddruid.task.executor.tlsPort=-1 -Ddruid.task.executor.enableTlsPort=false org.apache.druid.cli.Main internal peon /druid/task/index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc/task.json /druid/task/index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc/7c3b599e-f705-4066-b0b6-672a30c8dc30/status.json /druid/task/index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc/7c3b599e-f705-4066-b0b6-672a30c8dc30/report.json --loadBroadcastSegments true
Apr  6 09:23:34 druid-dataserver-11 java[6601]: 2021-04-06T09:23:34,992 INFO [forking-task-runner-0] org.apache.druid.indexing.overlord.ForkingTaskRunner - Logging task index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc output to: /druid/task/index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc/log
Apr  6 09:24:14 druid-dataserver-11 java[6601]: 2021-04-06T09:24:14,274 INFO [WorkerTaskManager-NoticeHandler] org.apache.druid.indexing.worker.WorkerTaskManager - Task[index_kafka_ssp-events-hourly_210a1b80ffd27f0_ilblpfpb] started.
Apr  6 09:24:14 druid-dataserver-11 java[6601]: 2021-04-06T09:24:14,276 INFO [forking-task-runner-8] org.apache.druid.indexing.overlord.ForkingTaskRunner - Running command: java -cp /etc/druid/_common:/etc/druid/middleManager:/opt/druid/lib/jackson-databind-2.10.5.1.jar:/opt/druid/lib/fastutil-8.2.3.jar:/opt/druid/lib/commons-logging-1.1.1.jar:/opt/druid/lib/commons-text-1.3.jar:/opt/druid/lib/curator-client-4.3.0.jar:/opt/druid/lib/netty-handler-4.1.48.Final.jar:/opt/druid/lib/javax.el-3.0.0.jar:/opt/druid/lib/maven-settings-builder-3.1.1.jar:/opt/druid/lib/joni-2.1.27.jar:/opt/druid/lib/joda-time-2.10.5.jar:/opt/druid/lib/classmate-1.1.0.jar:/opt/druid/lib/asm-commons-7.1.jar:/opt/druid/lib/javax.activation-api-1.2.0.jar:/opt/druid/lib/spymemcached-2.12.3.jar:/opt/druid/lib/jetty-http-9.4.34.v20201102.jar:/opt/druid/lib/commons-math3-3.6.1.jar:/opt/druid/lib/tesla-aether-0.0.5.jar:/opt/druid/lib/commons-io-2.6.jar:/opt/druid/lib/jackson-core-2.10.2.jar:/opt/druid/lib/audience-annotations-0.5.0.jar:/opt/druid/lib/guice-servlet-4.1.0.jar:/opt/druid/lib/commons-collections-3.2.2.jar:/opt/druid/lib/javax.el-api-3.0.0.jar:/opt/druid/lib/maven-artifact-3.6.0.jar:/opt/druid/lib/avatica-server-1.17.0.jar:/opt/druid/lib/httpcore-4.4.11.jar:/opt/druid/lib/aether-api-0.9.0.M2.jar:/opt/druid/lib/checker-qual-2.5.7.jar:/opt/druid/lib/protobuf-java-3.11.0.jar:/opt/druid/lib/RoaringBitmap-0.9.0.jar:/opt/druid/lib/maven-model-builder-3.1.1.jar:/opt/druid/lib/jetty-util-9.4.34.v20201102.jar:/opt/druid/lib/aether-spi-0.9.0.M2.jar:/opt/druid/lib/jaxb-runtime-2.3.1.jar:/opt/druid/lib/guice-multibindings-4.1.0.jar:/opt/druid/lib/asm-tree-7.1.jar:/opt/druid/lib/janino-3.0.11.jar:/opt/druid/lib/jmespath-java-1.11.199.jar:/opt/druid/lib/druid-console-0.20.1.jar:/opt/druid/lib/netty-handler-proxy-4.1.48.Final.jar:/opt/druid/lib/xz-1.8.jar:/opt/druid/lib/derbynet-10.14.2.0.jar:/opt/druid/lib/druid-core-0.20.1.jar:/opt/druid/lib/plexus-utils-3.0.24.jar:/opt/druid/lib/jackson-module-guice-2.10.2.jar:/opt/druid/lib/druid-indexing-service-0.20.1.jar:/opt/druid/lib/netty-transport-native-
Apr  6 09:24:14 druid-dataserver-11 java[6601]: epoll-4.1.48.Final-linux-x86_64.jar:/opt/druid/lib/istack-commons-runtime-3.0.7.jar:/opt/druid/lib/aws-java-sdk-ec2-1.11.199.jar:/opt/druid/lib/async-http-client-2.5.3.jar:/opt/druid/lib/esri-geometry-api-2.2.0.jar:/opt/druid/lib/log4j-1.2-api-2.8.2.jar:/opt/druid/lib/compress-lzf-1.0.4.jar:/opt/druid/lib/curator-framework-4.3.0.jar:/opt/druid/lib/google-http-client-1.26.0.jar:/opt/druid/lib/config-magic-0.9.jar:/opt/druid/lib/netty-transport-4.1.48.Final.jar:/opt/druid/lib/log4j-core-2.8.2.jar:/opt/druid/lib/disruptor-3.3.6.jar:/opt/druid/lib/jsr305-2.0.1.jar:/opt/druid/lib/jetty-servlet-9.4.34.v20201102.jar:/opt/druid/lib/aws-java-sdk-kms-1.11.199.jar:/opt/druid/lib/druid-aws-common-0.20.1.jar:/opt/druid/lib/avatica-metrics-1.17.0.jar:/opt/druid/lib/log4j-jul-2.8.2.jar:/opt/druid/lib/commons-compiler-3.0.11.jar:/opt/druid/lib/netty-common-4.1.48.Final.jar:/opt/druid/lib/aether-util-0.9.0.M2.jar:/opt/druid/lib/netty-resolver-dns-4.1.48.Final.jar:/opt/druid/lib/calcite-core-1.21.0.jar:/opt/druid/lib/netty-buffer-4.1.48.Final.jar:/opt/druid/lib/druid-processing-0.20.1.jar:/opt/druid/lib/aws-java-sdk-core-1.11.199.jar:/opt/druid/lib/druid-hll-0.20.1.jar:/opt/druid/lib/calcite-linq4j-1.21.0.jar:/opt/druid/lib/jdbi-2.63.1.jar:/opt/druid/lib/maven-model-3.1.1.jar:/opt/druid/lib/resilience4j-core-1.3.1.jar:/opt/druid/lib/async-http-client-netty-utils-2.5.3.jar:/opt/druid/lib/commons-lang3-3.8.1.jar:/opt/druid/lib/jsr311-api-1.1.1.jar:/opt/druid/lib/druid-sql-0.20.1.jar:/opt/druid/lib/avatica-core-1.17.0.jar:/opt/druid/lib/extendedset-0.20.1.jar:/opt/druid/lib/google-api-client-1.26.0.jar:/opt/druid/lib/jetty-io-9.4.34.v20201102.jar:/opt/druid/lib/log4j-api-2.8.2.jar:/opt/druid/lib/aopalliance-1.0.jar:/opt/druid/lib/jaxb-api-2.3.1.jar:/opt/druid/lib/icu4j-55.1.jar:/opt/druid/lib/validation-api-1.1.0.Final.jar:/opt/druid/lib/resilience4j-bulkhead-1.3.1.jar:/opt/druid/lib/caffeine-2.8.0.jar:/opt/druid/lib/datasketches-memory-1.2.0-incubating.jar:/opt/druid/lib/j2objc-annotations-1.1.jar:/opt/druid/lib/jetty-client-9.4.34.
--
Apr  6 13:25:16 druid-dataserver-11 java[6601]: 2021-04-06T13:25:16,870 INFO [forking-task-runner-3] org.apache.druid.indexing.overlord.ForkingTaskRunner - Logging task index_kafka_ssp-events-hourly_94de22349e72f81_elfcdclf output to: /druid/task/index_kafka_ssp-events-hourly_94de22349e72f81_elfcdclf/log
Apr  6 13:30:01 druid-dataserver-11 java[6601]: 2021-04-06T13:30:01,087 INFO [NodeRoleWatcher[COORDINATOR]] org.apache.druid.curator.discovery.CuratorDruidNodeDiscoveryProvider$NodeRoleWatcher - Node[http://druid-master-2:8081] of role[coordinator] went offline.
Apr  6 13:33:45 druid-dataserver-11 java[6601]: 2021-04-06T13:33:45,452 INFO [NodeRoleWatcher[COORDINATOR]] org.apache.druid.curator.discovery.CuratorDruidNodeDiscoveryProvider$NodeRoleWatcher - Node[http://druid-master-2:8081] of role[coordinator] detected.
Apr  6 13:37:09 druid-dataserver-11 java[6601]: 2021-04-06T13:37:09,618 INFO [forking-task-runner-0-[index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc]] org.apache.druid.indexing.overlord.ForkingTaskRunner - Process exited with status[0] for task: index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc
Apr  6 13:37:09 druid-dataserver-11 java[6601]: 2021-04-06T13:37:09,618 INFO [forking-task-runner-0] org.apache.druid.storage.google.GoogleTaskLogs - Pushing task log /druid/task/index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc/log to: indexing-logs/index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc
Apr  6 13:37:09 druid-dataserver-11 java[6601]: 2021-04-06T13:37:09,920 INFO [forking-task-runner-0] org.apache.druid.storage.google.GoogleTaskLogs - Pushing task reports /druid/task/index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc/7c3b599e-f705-4066-b0b6-672a30c8dc30/report.json to: indexing-logs/index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc.report.json
Apr  6 13:37:10 druid-dataserver-11 java[6601]: 2021-04-06T13:37:10,069 INFO [forking-task-runner-0] org.apache.druid.indexing.overlord.ForkingTaskRunner - Removing task directory: /druid/task/index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc
Apr  6 13:37:10 druid-dataserver-11 java[6601]: 2021-04-06T13:37:10,128 INFO [WorkerTaskManager-NoticeHandler] org.apache.druid.indexing.worker.WorkerTaskManager - Task [index_kafka_ssp-events-hourly_4e62ca9663a43dc_cojlbdpc] completed with status [FAILED].
Apr  6 13:38:00 druid-dataserver-11 java[6601]: 2021-04-06T13:38:00,818 INFO [forking-task-runner-8-[index_kafka_ssp-events-hourly_210a1b80ffd27f0_ilblpfpb]] org.apache.druid.indexing.overlord.ForkingTaskRunner - Process exited with status[0] for task: index_kafka_ssp-events-hourly_210a1b80ffd27f0_ilblpfpb
Apr  6 13:38:00 druid-dataserver-11 java[6601]: 2021-04-06T13:38:00,819 INFO [forking-task-runner-8] org.apache.druid.storage.google.GoogleTaskLogs - Pushing task log /druid/task/index_kafka_ssp-events-hourly_210a1b80ffd27f0_ilblpfpb/log to: indexing-logs/index_kafka_ssp-events-hourly_210a1b80ffd27f0_ilblpfpb
Apr  6 13:38:01 druid-dataserver-11 java[6601]: 2021-04-06T13:38:01,086 INFO [forking-task-runner-8] org.apache.druid.storage.google.GoogleTaskLogs - Pushing task reports /druid/task/index_kafka_ssp-events-hourly_210a1b80ffd27f0_ilblpfpb/64b72335-39b4-40b6-b9b9-daf6ab7f7ed8/report.json to: indexing-logs/index_kafka_ssp-events-hourly_210a1b80ffd27f0_ilblpfpb.report.json

@tanisdlj
Copy link
Author

tanisdlj commented Apr 6, 2021

Overlord log
overlord-cojlbdpc-master-1.txt

@tanisdlj
Copy link
Author

tanisdlj commented Apr 6, 2021

can you share the full logs of the Kafka indexing task and supervisor?

☝️ There you go @abhishekagarwal87

@internaulte
Copy link

I have same issue intermittently in druid 0.21.0 (launch in docker containers), only when sending very few data in kafka (one line to insert in a new datasource). Does someone found any cause or workaround ?

@tanisdlj
Copy link
Author

No, still happening to me. No idea how to fix, waiting to see if we have any answer here :/

@a2l007
Copy link
Contributor

a2l007 commented May 11, 2021

Apr  6 13:35:56 druid-master-1 java[30627]: eec2d0f97d0493e_ppdbldcc', startTime=2021-04-06T09:24:58.038Z, remainingSeconds=1159}, {id='index_kafka_ssp-events-hourly_f8c76ca0ee1eb27_okikkdng', startTime=2021-04-06T09:24:57.074Z, remainingSeconds=1159}, {id='index_kafka_ssp-events-hourly_f8c76ca0ee1eb27_fnhihoaa', startTime=2021-04-06T09:25:02.131Z, remainingSeconds=1159}, {id='index_kafka_ssp-events-hourly_a424ab496d33a84_cecajcbn', startTime=2021-04-06T09:24:35.617Z, remainingSeconds=1123}, {id='index_kafka_ssp-events-hourly_a424ab496d33a84_iiicpdkd', startTime=2021-04-06T09:24:27.337Z, remainingSeconds=1123}, {id='index_kafka_ssp-events-hourly_e65adc6966fca7a_mgloohkf', startTime=2021-04-06T09:25:00.293Z, remainingSeconds=1159}, {id='index_kafka_ssp-events-hourly_e65adc6966fca7a_npellplj', startTime=2021-04-06T09:24:58.555Z, remainingSeconds=1159}, {id='index_kafka_ssp-events-hourly_cd9be6c86122678_mjlhhfdd', startTime=2021-04-06T09:24:59.640Z, remainingSeconds=1159}, {id='index_kafka_ssp-events-hourly_cd9be6c86122678_amdpcjbl', startTime=2021-04-06T09:25:01.798Z, remainingSeconds=1159}, {id='index_kafka_ssp-events-hourly_0e9e4a007183936_ofdnfgnb', startTime=2021-04-06T09:24:59.228Z, remainingSeconds=1159}, {id='index_kafka_ssp-events-hourly_0e9e4a007183936_dmecbihl', startTime=2021-04-06T09:24:56.665Z, remainingSeconds=1159}, {id='index_kafka_ssp-events-hourly_e98743e8e670c7f_fnpnaiec', startTime=2021-04-06T09:24:30.279Z, remainingSeconds=1123}, {id='index_kafka_ssp-events-hourly_e98743e8e670c7f_hefdbaid', startTime=2021-04-06T09:24:24.318Z, remainingSeconds=1123}, {id='index_kafka_ssp-events-hourly_328a9a55c69b61e_nbabbjpf', startTime=2021-04-06T09:24:59.698Z, remainingSeconds=1159}, {id='index_kafka_ssp-events-hourly_328a9a55c69b61e_lfdpdmip', startTime=2021-04-06T09:25:00.671Z, remainingSeconds=1159}, {id='index_kafka_ssp-events-hourly_3d2859b07ae02c9_dfanponf', startTime=2021-04-06T09:25:00.939Z, remainingSeconds=1159}, {id='index_kafka_ssp-events-hourly_3d2859b07ae02c9_galhbaca', startTime=2021-04-06T09:24:59.651Z, remainingSeconds=1159}, {id='inde
--
Apr  6 13:37:09 druid-master-1 java[30627]: 2021-04-06T13:37:09,940 INFO [KafkaSupervisor-events-hourly] org.apache.druid.indexing.seekablestream.supervisor.SeekableStreamSupervisor - [events-hourly] supervisor is running.

The log line above from the overlord log looks incomplete. Was this modified?
How does the memory utilization on the overlord and middlemanager hosts look like during the failure event?

@tanisdlj
Copy link
Author

@a2l007 no, it wasn't modified. No clue what happened there, sorry :/.

Middlemanager RAM:
image

Overlord RAM:
image

Heap of both (purple is overlord):
image

@a2l007
Copy link
Contributor

a2l007 commented May 13, 2021

I see the log messages getting clipped at multiple places. Not sure what's going on there.
Regarding the InterruptedException, could you try reducing the task count for the ssp-events-hourly supervisor and monitor if there is a decrease in the occurrences of this error? This would help identify if it is caused due to resource constraints.
Also it would be useful to turn on debug logging on the tasks so that we have a better idea of whats going on with the failed tasks.

@tanisdlj
Copy link
Author

Sorry, but no, we can't reduce the task count for ssp-events-hourly without losing data :(
If it were resource constraints, reducing the amount of tasks wouldn't increase the problem?

@internaulte
Copy link

Hello there !
Sorry for the time to respond, I had to work on other subjects.

So, as I said, we randomly have a similar error (logs are not exactly the same, but it seems to be quite similar to me) on indexing data in druid from kafka streaming. We are on druid 0.21.0 but we had the same problem in 0.20.1.

When creating data in druid, in fact we have 4 supervisors created. All of them on a similar scheme, pointing to slightly different datasources.

Example of supervisor spec :

[
	{
		"type": "kafka",
		"spec": {
			"dataSchema": {
				"dataSource": "testdatasource",
				"timestampSpec": {
					"column": "date",
					"format": "auto"
				},
				"dimensionsSpec": {
					"dimensions": [
						"number",
						{
							"type": "long",
							"name": "duration"
						},
						"string",
						"otherstring",
						"boolean"
					]
				},
				"metricsSpec": [],
				"granularitySpec": {
					"type": "uniform",
					"segmentGranularity": "YEAR",
					"queryGranularity": "NONE",
					"rollup": false
				}
			},
			"ioConfig": {
				"type": "kafka",
				"topic": "testdatasource",
				"consumerProperties": {
					"bootstrap.servers": "kafka-broker:00001"
				},
				"inputFormat": {
					"type": "json"
				},
				"useEarliestOffset": true
			},
			"tuningConfig": {
				"type": "kafka",
				"logParseExceptions": true,
				"intermediateHandoffPeriod": "PT30M"
			}
		}
	}
]

example of data in kafka topic :

{
   "date": "2010-10-10T08:05:00.000Z",
   "number": "8000",
   "duration": 300000,
   "string": "3",
   "otherstring": "b3701aefc6797a9c883067ef71341db1",
   "boolean": true
}

Usually, everything is fine, but randomly one of the 4 ingesting tasks fails (4 tasks as we created 4 supervisors). It seems to only happens when ingesting few lines (let's say less than 10).

Here is the stackTrace we obtain in druid 0.20.1 :
ingestion_fails-log-druid-0.20.1.txt

Here is the stackTrace we obtain in druid 0.21.0 :
ingestion_fails-log-druid-0.21.0.txt

@internaulte
Copy link

internaulte commented Jun 10, 2021

In the broker, we have those logs :
brokerLogs.txt

Hope it will help.

@internaulte
Copy link

Isn't stackTrace and description similar to #9207 ?

@sneerin
Copy link

sneerin commented Aug 4, 2021

the same issue for me, version is 0.21.1

@liubo-it
Copy link

liubo-it commented Nov 18, 2021

@tanisdlj Hi,I had the same problem with druid version 0.16。Is it solved now?

@tanisdlj
Copy link
Author

Not yet, no :(

@internaulte
Copy link

Seems to continue to randomly reproduce in druid 0.22.0.
Druid console return error "Task [taskId] failed to return start time, killing task".

complete log of the task:
druidTaskError.log

Many things are quite strange in the logs.

2022-01-07T08:56:42,389 WARN [IndexTaskClient-f701e547-b04b-4999-b5f0-843f75cbeebd-0] org.apache.druid.indexing.common.IndexTaskClient - Bad response HTTP [no response] from [http://50d8c771d9a9:8100/druid/worker/v1/chat/index_kafka_f701e547-b04b-4999-b5f0-843f75cbeebd_30620ba24ba5ec1_hhggdnjc/rowStats]; will try again in [PT2S] (body/exception: [Connection refused (Connection refused)])
2022-01-07T08:56:44,390 WARN [IndexTaskClient-f701e547-b04b-4999-b5f0-843f75cbeebd-0] org.apache.druid.indexing.common.IndexTaskClient - Bad response HTTP [no response] from [http://50d8c771d9a9:8100/druid/worker/v1/chat/index_kafka_f701e547-b04b-4999-b5f0-843f75cbeebd_30620ba24ba5ec1_hhggdnjc/rowStats]; will try again in [PT4S] (body/exception: [Connection refused (Connection refused)])
2022-01-07T08:56:48,391 WARN [IndexTaskClient-f701e547-b04b-4999-b5f0-843f75cbeebd-0] org.apache.druid.indexing.common.IndexTaskClient - Bad response HTTP [no response] from [http://50d8c771d9a9:8100/druid/worker/v1/chat/index_kafka_f701e547-b04b-4999-b5f0-843f75cbeebd_30620ba24ba5ec1_hhggdnjc/rowStats]; will try again in [PT8S] (body/exception: [Connection refused (Connection refused)])
2022-01-07T08:56:56,392 WARN [IndexTaskClient-f701e547-b04b-4999-b5f0-843f75cbeebd-0] org.apache.druid.indexing.common.IndexTaskClient - Bad response HTTP [no response] from [http://50d8c771d9a9:8100/druid/worker/v1/chat/index_kafka_f701e547-b04b-4999-b5f0-843f75cbeebd_30620ba24ba5ec1_hhggdnjc/rowStats]; will try again in [PT10S] (body/exception: [Connection refused (Connection refused)])

50d8c771d9a9:8100 => 50d8c771d9a9 is middle manager, but it is on port 8091, not 8100. Why is he looking at that port 8100 ? I'm missing something here.

Other thing is strange: Assigned a task[index_kafka_f701e547-b04b-4999-b5f0-843f75cbeebd_30620ba24ba5ec1_hhggdnjc] that is already pending!.

Any idea what's going on here ?

@internaulte
Copy link

Strangely, the problem disappeared in our last version of our code. Don't really see what have really changed. Just, one datasource disappeared, so we just kafka ingest in three datasources in parallel instead of 4. And datas send are a little different. And we now use druid 0.22.1, but really not sure it is linked, problem seems to have disappeared a little bit before that. Hard to be sure, as it happens randomly.

@github-actions
Copy link

github-actions bot commented Oct 7, 2023

This issue has been marked as stale due to 280 days of inactivity.
It will be closed in 4 weeks if no further activity occurs. If this issue is still
relevant, please simply write any comment. Even if closed, you can still revive the
issue at any time or discuss it on the dev@druid.apache.org list.
Thank you for your contributions.

@github-actions github-actions bot added the stale label Oct 7, 2023
Copy link

github-actions bot commented Nov 5, 2023

This issue has been closed due to lack of activity. If you think that
is incorrect, or the issue requires additional review, you can revive the issue at
any time.

@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Nov 5, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

10 participants