apache / apache/druid

Compaction task failed, how can I troubleshoot?

Open
#13,385 3 comments 0 reactions 0 assignees View on GitHub
Area - Compaction Bug
Dominant language
Java
Stars
14.1k
Forks
3.8k
Avg merge
2d 58m
Merged PRs (30d)
233

Description

Hi experts,

I am using druid 0.22.1, and I want to compact some small segments, so I submit a compaction task:
```
{
"type": "compact",
"dataSource": "autotest",
"ioConfig": {
"type": "compact",
"inputSpec": {
"type": "interval",
"interval": "1970-01-01T00:00:00Z/2023-11-18T07:14:34.000Z"
},
"dropExisting": true
},
"granularitySpec": {
"segmentGranularity": "MINUTE",
"queryGranularity": "MINUTE"
}
}
```
But the compaction task failed with the following status information
```
{
"id": "compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z",
"groupId": "compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z",
"type": "compact",
"createdTime": "2022-11-18T08:41:49.908Z",
"queueInsertionTime": "1970-01-01T00:00:00.000Z",
"statusCode": "FAILED",
"status": "FAILED",
"runnerStatusCode": "WAITING",
"duration": 27628,
"location": {
"host": "172.24.131.32",
"port": -1,
"tlsPort": 8100
},
"dataSource": "autotest",
"errorMsg": "Ran [1] specs, [0] succeeded, [1] failed"
}
```
And the logs:
```
{"instant":{"epochSecond":1668760935,"nanoOfSecond":19000000},"thread":"task-runner-0-priority-0","level":"INFO","loggerName":"org.apache.druid.storage.s3.S3DataSegmentPuller","message":"Pulling index at path[CloudObjectLocation{bucket='cerberus-zontal-ingest', path='druid/segments/autotest/2022-11-18T07:12:33.000Z_2022-11-18T07:12:34.000Z/2022-11-18T07:12:34.855Z/0/index.zip'}] to outDir[var/druid/task/compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z/work/autotest/2022-11-18T07:12:33.000Z_2022-11-18T07:12:34.000Z/2022-11-18T07:12:34.855Z/0]","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":106,"threadPriority":5}
{"instant":{"epochSecond":1668760935,"nanoOfSecond":217000000},"thread":"task-runner-0-priority-0","level":"INFO","loggerName":"org.apache.druid.storage.s3.S3DataSegmentPuller","message":"Loaded 370186 bytes from [CloudObjectLocation{bucket='cerberus-zontal-ingest', path='druid/segments/autotest/2022-11-18T07:12:33.000Z_2022-11-18T07:12:34.000Z/2022-11-18T07:12:34.855Z/0/index.zip'}] to [/opt/druid/var/druid/task/compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z/work/autotest/2022-11-18T07:12:33.000Z_2022-11-18T07:12:34.000Z/2022-11-18T07:12:34.855Z/0]","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":106,"threadPriority":5}
{"instant":{"epochSecond":1668760935,"nanoOfSecond":218000000},"thread":"task-runner-0-priority-0","level":"INFO","loggerName":"org.apache.druid.storage.s3.S3DataSegmentPuller","message":"Pulling index at path[CloudObjectLocation{bucket='cerberus-zontal-ingest', path='druid/segments/autotest/2022-11-18T07:12:41.000Z_2022-11-18T07:12:42.000Z/2022-11-18T07:12:42.687Z/0/index.zip'}] to outDir[var/druid/task/compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z/work/autotest/2022-11-18T07:12:41.000Z_2022-11-18T07:12:42.000Z/2022-11-18T07:12:42.687Z/0]","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":106,"threadPriority":5}
{"instant":{"epochSecond":1668760935,"nanoOfSecond":318000000},"thread":"task-runner-0-priority-0","level":"INFO","loggerName":"org.apache.druid.storage.s3.S3DataSegmentPuller","message":"Loaded 370186 bytes from [CloudObjectLocation{bucket='cerberus-zontal-ingest', path='druid/segments/autotest/2022-11-18T07:12:41.000Z_2022-11-18T07:12:42.000Z/2022-11-18T07:12:42.687Z/0/index.zip'}] to [/opt/druid/var/druid/task/compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z/work/autotest/2022-11-18T07:12:41.000Z_2022-11-18T07:12:42.000Z/2022-11-18T07:12:42.687Z/0]","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":106,"threadPriority":5}
{"instant":{"epochSecond":1668760935,"nanoOfSecond":319000000},"thread":"task-runner-0-priority-0","level":"INFO","loggerName":"org.apache.druid.storage.s3.S3DataSegmentPuller","message":"Pulling index at path[CloudObjectLocation{bucket='cerberus-zontal-ingest', path='druid/segments/autotest/2022-11-18T07:13:34.000Z_2022-11-18T07:13:35.000Z/2022-11-18T07:13:36.349Z/0/index.zip'}] to outDir[var/druid/task/compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z/work/autotest/2022-11-18T07:13:34.000Z_2022-11-18T07:13:35.000Z/2022-11-18T07:13:36.349Z/0]","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":106,"threadPriority":5}
{"instant":{"epochSecond":1668760935,"nanoOfSecond":414000000},"thread":"task-runner-0-priority-0","level":"INFO","loggerName":"org.apache.druid.storage.s3.S3DataSegmentPuller","message":"Loaded 370186 bytes from [CloudObjectLocation{bucket='cerberus-zontal-ingest', path='druid/segments/autotest/2022-11-18T07:13:34.000Z_2022-11-18T07:13:35.000Z/2022-11-18T07:13:36.349Z/0/index.zip'}] to [/opt/druid/var/druid/task/compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z/work/autotest/2022-11-18T07:13:34.000Z_2022-11-18T07:13:35.000Z/2022-11-18T07:13:36.349Z/0]","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":106,"threadPriority":5}
{"instant":{"epochSecond":1668760935,"nanoOfSecond":816000000},"thread":"task-runner-0-priority-0","level":"INFO","loggerName":"org.apache.druid.indexing.common.task.CompactionTask","message":"Generate compaction task spec with new query granularity overrided from input [{type=period, period=PT1M, timeZone=UTC, origin=null}]","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":106,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":502000000},"thread":"task-runner-0-priority-0","level":"INFO","loggerName":"org.apache.druid.indexing.common.task.CompactionTask","message":"Generated [1] compaction task specs","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":106,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":617000000},"thread":"task-runner-0-priority-0","level":"INFO","loggerName":"org.apache.druid.indexing.common.task.AbstractBatchIndexTask","message":"[forceTimeChunkLock] is set to true in task context. Use timeChunk lock","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":106,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":703000000},"thread":"task-runner-0-priority-0","level":"WARN","loggerName":"org.apache.druid.indexing.common.task.CompactionTask","message":"indexSpec is not ready: [{\n \"type\" : \"index_parallel\",\n \"id\" : \"compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z\",\n \"groupId\" : \"compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z\",\n \"resource\" : {\n \"availabilityGroup\" : \"compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z\",\n \"requiredCapacity\" : 1\n },\n \"spec\" : {\n \"dataSchema\" : {\n \"dataSource\" : \"autotest\",\n \"timestampSpec\" : {\n \"column\" : \"__time\",\n \"format\" : \"millis\",\n \"missingValue\" : null\n },\n \"dimensionsSpec\" : {\n \"dimensions\" : [ {\n \"type\" : \"string\",\n \"name\" : \"content_identifier\",\n \"multiValueHandling\" : \"SORTED_ARRAY\",\n \"createBitmapIndex\" : true\n }, {\n \"type\" : \"string\",\n \"name\" : \"information_package_iri\",\n \"multiValueHandling\" : \"SORTED_ARRAY\",\n \"createBitmapIndex\" : true\n }, {\n \"type\" : \"string\",\n \"name\" : \"iri\",\n \"multiValueHandling\" : \"SORTED_ARRAY\",\n \"createBitmapIndex\" : true\n }, {\n \"type\" : \"long\",\n \"name\" : \"x1_value_int\",\n \"multiValueHandling\" : \"SORTED_ARRAY\",\n \"createBitmapIndex\" : false\n }, {\n \"type\" : \"long\",\n \"name\" : \"y1_value_int\",\n \"multiValueHandling\" : \"SORTED_ARRAY\",\n \"createBitmapIndex\" : false\n } ],\n \"dimensionExclusions\" : [ \"__time\" ]\n },\n \"metricsSpec\" : [ ],\n \"granularitySpec\" : {\n \"type\" : \"uniform\",\n \"segmentGranularity\" : \"MINUTE\",\n \"queryGranularity\" : \"MINUTE\",\n \"rollup\" : false,\n \"intervals\" : [ \"2022-11-17T07:51:00.000Z/2022-11-18T07:13:35.000Z\" ]\n },\n \"transformSpec\" : {\n \"filter\" : null,\n \"transforms\" : [ ]\n }\n },\n \"ioConfig\" : {\n \"type\" : \"index_parallel\",\n \"inputSource\" : {\n \"type\" : \"druid\",\n \"dataSource\" : \"autotest\",\n \"interval\" : \"1970-01-01T00:00:00.000Z/2022-11-18T07:14:34.000Z\"\n },\n \"inputFormat\" : null,\n \"appendToExisting\" : false,\n \"dropExisting\" : true\n },\n \"tuningConfig\" : {\n \"type\" : \"compaction\",\n \"maxRowsPerSegment\" : 5000000,\n \"appendableIndexSpec\" : {\n \"type\" : \"onheap\"\n },\n \"maxRowsInMemory\" : 1000000,\n \"maxBytesInMemory\" : 0,\n \"skipBytesInMemoryOverheadCheck\" : false,\n \"maxTotalRows\" : 9223372036854775807,\n \"numShards\" : null,\n \"splitHintSpec\" : null,\n \"partitionsSpec\" : {\n \"type\" : \"dynamic\",\n \"maxRowsPerSegment\" : 5000000,\n \"maxTotalRows\" : 9223372036854775807\n },\n \"indexSpec\" : {\n \"bitmap\" : {\n \"type\" : \"roaring\",\n \"compressRunOnSerialization\" : true\n },\n \"dimensionCompression\" : \"lz4\",\n \"metricCompression\" : \"lz4\",\n \"longEncoding\" : \"longs\",\n \"segmentLoader\" : null\n },\n \"indexSpecForIntermediatePersists\" : {\n \"bitmap\" : {\n \"type\" : \"roaring\",\n \"compressRunOnSerialization\" : true\n },\n \"dimensionCompression\" : \"lz4\",\n \"metricCompression\" : \"lz4\",\n \"longEncoding\" : \"longs\",\n \"segmentLoader\" : null\n },\n \"maxPendingPersists\" : 0,\n \"forceGuaranteedRollup\" : false,\n \"reportParseExceptions\" : false,\n \"pushTimeout\" : 0,\n \"segmentWriteOutMediumFactory\" : null,\n \"maxNumConcurrentSubTasks\" : 1,\n \"maxRetry\" : 3,\n \"taskStatusCheckPeriodMs\" : 1000,\n \"chatHandlerTimeout\" : \"PT10S\",\n \"chatHandlerNumRetries\" : 5,\n \"maxNumSegmentsToMerge\" : 100,\n \"totalNumMergeTasks\" : 10,\n \"logParseExceptions\" : false,\n \"maxParseExceptions\" : 2147483647,\n \"maxSavedParseExceptions\" : 0,\n \"maxColumnsToMerge\" : -1,\n \"awaitSegmentAvailabilityTimeoutMillis\" : 0,\n \"partitionDimensions\" : [ ]\n }\n },\n \"context\" : {\n \"useLineageBasedSegmentAllocation\" : true,\n \"appenderatorTrackingTaskId\" : \"compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z\",\n \"storeCompactionState\" : true,\n \"forceTimeChunkLock\" : true,\n \"priority\" : 25\n },\n \"dataSource\" : \"autotest\"\n}].\nTrying the next indexSpec.","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":106,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":703000000},"thread":"task-runner-0-priority-0","level":"INFO","loggerName":"org.apache.druid.indexing.common.task.CompactionTask","message":"Ran [1] specs, [0] succeeded, [1] failed","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":106,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":705000000},"thread":"task-runner-0-priority-0","level":"INFO","loggerName":"org.apache.druid.indexing.worker.executor.ExecutorLifecycle","message":"Task completed with status: {\n \"id\" : \"compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z\",\n \"status\" : \"FAILED\",\n \"duration\" : 6798,\n \"errorMsg\" : \"Ran [1] specs, [0] succeeded, [1] failed\",\n \"location\" : {\n \"host\" : null,\n \"port\" : -1,\n \"tlsPort\" : -1\n }\n}","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":106,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":710000000},"thread":"main","level":"INFO","loggerName":"org.apache.druid.java.util.common.lifecycle.Lifecycle","message":"Stopping lifecycle [module] stage [ANNOUNCEMENTS]","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":1,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":711000000},"thread":"main","level":"INFO","loggerName":"org.apache.druid.java.util.common.lifecycle.Lifecycle","message":"Stopping lifecycle [module] stage [SERVER]","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":1,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":716000000},"thread":"main","level":"INFO","loggerName":"org.eclipse.jetty.server.AbstractConnector","message":"Stopped ServerConnector@58bad46f{SSL, (ssl, http/1.1)}{0.0.0.0:8100}","endOfBatch":false,"loggerFqcn":"org.eclipse.jetty.util.log.Slf4jLog","threadId":1,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":717000000},"thread":"main","level":"INFO","loggerName":"org.eclipse.jetty.server.session","message":"node0 Stopped scavenging","endOfBatch":false,"loggerFqcn":"org.eclipse.jetty.util.log.Slf4jLog","threadId":1,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":802000000},"thread":"main","level":"INFO","loggerName":"org.eclipse.jetty.server.handler.ContextHandler","message":"Stopped o.e.j.s.ServletContextHandler@7c4ca87c{/,null,STOPPED}","endOfBatch":false,"loggerFqcn":"org.eclipse.jetty.util.log.Slf4jLog","threadId":1,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":805000000},"thread":"main","level":"INFO","loggerName":"org.apache.druid.java.util.common.lifecycle.Lifecycle","message":"Stopping lifecycle [module] stage [NORMAL]","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":1,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":806000000},"thread":"main","level":"INFO","loggerName":"org.apache.druid.indexing.overlord.SingleTaskBackgroundRunner","message":"Starting graceful shutdown of task[compact_autotest_ddbohokd_2022-11-18T08:41:49.906Z].","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":1,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":816000000},"thread":"LookupExtractorFactoryContainerProvider-MainThread","level":"INFO","loggerName":"org.apache.druid.query.lookup.LookupReferencesManager","message":"Lookup Management loop exited. Lookup notices are not handled anymore.","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":103,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":816000000},"thread":"main","level":"INFO","loggerName":"org.apache.druid.query.lookup.LookupReferencesManager","message":"Closed lookup [deleted_information_packages].","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":1,"threadPriority":5}
{"instant":{"epochSecond":1668760936,"nanoOfSecond":821000000},"thread":"Curator-Framework-0","level":"INFO","loggerName":"org.apache.curator.framework.imps.CuratorFrameworkImpl","message":"backgroundOperationsLoop exiting","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":99,"threadPriority":5}
{"instant":{"epochSecond":1668760937,"nanoOfSecond":18000000},"thread":"main","level":"INFO","loggerName":"org.apache.zookeeper.ZooKeeper","message":"Session: 0x1001892b7e9010b closed","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":1,"threadPriority":5}
{"instant":{"epochSecond":1668760937,"nanoOfSecond":18000000},"thread":"main-EventThread","level":"INFO","loggerName":"org.apache.zookeeper.ClientCnxn","message":"EventThread shut down for session: 0x1001892b7e9010b","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":98,"threadPriority":5}
{"instant":{"epochSecond":1668760937,"nanoOfSecond":105000000},"thread":"main","level":"INFO","loggerName":"org.apache.druid.java.util.common.lifecycle.Lifecycle","message":"Stopping lifecycle [module] stage [INIT]","endOfBatch":false,"loggerFqcn":"org.apache.logging.slf4j.Log4jLogger","threadId":1,"threadPriority":5}
Finished peon task

```
I notice there is a "indexSpec is not ready:" warning in the log, but I don't know what does this mean.
FYI: The datasource is "Fully available"
Can anyone help me? Or how can I troubleshout issues like this? Thanks a lot in advance.

Contributor guide

Open the contributing guide

Research direction

Start with the submitted compaction-task JSON and the CompactionTask, S3DataSegmentPuller, and ExecutorLifecycle log entries. Trace why the single generated compaction spec fails beyond the reported summary. Done means the failure has an identified, reproducible cause and the issue contains actionable troubleshooting guidance or a confirmed fix.

Written by the indexing model from the issue text.

Assessment

Tech stack
java
Domain
databases
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.