Druid: "taskLockHelper is not initialized yet"

[sixtus]

I am running index_parallel tasks on the experimental druid indexer.

They fail immediately with the error message above.

Affected Version

Druid 0.18 (0.17 was fine)

Description

This seems to be independent of cluster size.

Based on the stack trace I tried this patch: https://github.com/liquidm/druid/commit/a815e3571f17ce31f62f47529e4258bfe8c52f8a

But it didn't help. So I tried this one:
https://github.com/liquidm/druid/commit/ef1cfc696105c813fba900ef137ba9a3194d4466

which likely is not in the spirit of the assertion, but it all started working again.

[dene14]

Facing the same issue even with a native index (non-parallel) task.

[sixtus]

Facing the same issue even with a native index (non-parallel) task.

on expérimental indexer or middle manager?

[vikramsinghchandel]

Same issue here. index_parallel with dynamic partitioning, seeing this issue. With hashed partitioning strategy works fine.

@sixtus were you able to find any solution/workaround. With hashed partitioner & forcedGranularityRollUp the performance of indexing is very bad almost twice as bad compared to EMR based indexing

[jihoonson]

Hi @vikramsinghchandel, I bet you can workaround this bug by setting intervals in the granularitySpec. Can you try with explicit intervals?

@sixtus were you able to find any solution/workaround. With hashed partitioner & forcedGranularityRollUp the performance of indexing is very bad almost twice as bad compared to EMR based indexing

BTW, this is interesting. Was the setup exactly same for both ingestion methods? Could you share how they are different in what setup if possible?

[vikramsinghchandel]

Hi @vikramsinghchandel, I bet you can workaround this bug by setting intervals in the granularitySpec. Can you try with explicit intervals?

@sixtus were you able to find any solution/workaround. With hashed partitioner & forcedGranularityRollUp the performance of indexing is very bad almost twice as bad compared to EMR based indexing

BTW, this is interesting. Was the setup exactly same for both ingestion methods? Could you share how they are different in what setup if possible?

@jihoonson

I already have set intervals in granularitySpec

this is how it looks

"granularitySpec": { "type": "uniform", "segmentGranularity": "HOUR", "queryGranularity": "HOUR", "rollup": true, "intervals": [ "2020-07-16/2020-07-18" ] }

Sure Following is the setup

EMR:: 22 * m5.2xl nodes == 176 vCPU
Native (K8S indexer nodes) = 50 nodes each with 4 CPU and 26G memory (200 vCPU)
Each node has 3 worker so a total of 150 workers are spawned for native ingestion.

Let me know if you need detailed numbers for infra and ingestion, can create a separate ticket with the details.

[jihoonson]

I already have set intervals in granularitySpec

@vikramsinghchandel Hmm, OK. Let me dig into this more.

Let me know if you need detailed numbers for infra and ingestion, can create a separate ticket with the details.

That would be great! Could you open a new issue about performance? And could you share the tuningConfigs of hadoop and native tasks as well as the cluster setup above if possible?

[vikramsinghchandel]

@jihoonson creted a ticket with all the details.
https://github.com/apache/druid/issues/10210

[cloventt]

We see this same issue using index tasks that are appending to an existing interval, on indexers with Druid 0.18.1.

2020-09-07 01:16:43,897 ERROR [[index_ssp-hour_jjejaoee_2020-09-07T01:16:43.738Z]-threading-task-runner-executor-4] logger.Logger (Logger.java:226) - Encountered exception in BUILD_SEGMENTS.
java.lang.NullPointerException: taskLockHelper is not initialized yet
    at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:229) ~[guava-16.0.1.jar:?]
    at org.apache.druid.indexing.common.task.AbstractBatchIndexTask.getTaskLockHelper(AbstractBatchIndexTask.java:184) ~[druid-indexing-service-0.18.1.jar:0.18.1]
    at org.apache.druid.indexing.common.task.IndexTask.generateAndPublishSegments(IndexTask.java:905) ~[druid-indexing-service-0.18.1.jar:0.18.1]
    at org.apache.druid.indexing.common.task.IndexTask.runTask(IndexTask.java:526) [druid-indexing-service-0.18.1.jar:0.18.1]
    at org.apache.druid.indexing.common.task.AbstractBatchIndexTask.run(AbstractBatchIndexTask.java:123) [druid-indexing-service-0.18.1.jar:0.18.1]
    at org.apache.druid.indexing.overlord.ThreadingTaskRunner$1.call(ThreadingTaskRunner.java:209) [druid-indexing-service-0.18.1.jar:0.18.1]
    at org.apache.druid.indexing.overlord.ThreadingTaskRunner$1.call(ThreadingTaskRunner.java:149) [druid-indexing-service-0.18.1.jar:0.18.1]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_265]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_265]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_265]
    at java.lang.Thread.run(Thread.java:748) [?:1.8.0_265]

Our ingestion spec:

{
  "type": "index",
  "spec": {
    "dataSchema": {
      "dataSource": "datasource",
      "parser": {
        "type": "string",
        "parseSpec": {
          "format": "json",
          "timestampSpec": {
            "column": "timestamp",
            "format": "iso"
          },
          "dimensionsSpec": {
            "dimensions": ["redacted" ]
          }
        }
      },
      "metricsSpec": ["redacted"],
      "granularitySpec": {
        "type": "uniform",
        "segmentGranularity": "hour",
        "queryGranularity": "hour",
        "rollup": true,
        "intervals": [
          "2020-09-07T00:00Z/2020-09-07T01:00Z"
        ]
      }
    },
    "tuningConfig": {
      "type": "index",
      "maxRowsPerSegment": 5000000,
      "maxRowsInMemory": 100000
    },
    "ioConfig": {
      "type": "index",
      "appendToExisting": true,
      "firehose": {
        "type": "static-s3",
        "fetchTimeout": 180000,
        "maxFetchRetry": 5,
        "prefixes": [
          "s3://path-to-files"
        ]
      }
    }
  },
  "context": {
    "forceTimeChunkLock": false
  }
}

[cloventt]

We discovered a workaround. Deleting intervals from our granularitySpec allowed the append task to complete as normal (note that we are using an index task rather than an index_parallel task).

[cloventt]

We've tested and also observed this issue on 0.19.0.

[gianm]

10631 should fix this.

[jihoonson]

Closing as #10631 is merged. Please feel free to reopen if you still see the same issue.

[guptha308]

Using .20.1. Facing issue while using index_parallel tasks.
Any workaround for this.

{ "type": "index_parallel", "spec": { "dataSchema": { "dataSource": "aws", "timestampSpec": { "column": "epoch_time", "format": "iso", "missingValue": null }, "dimensionsSpec": { "dimensions": [ "events" { "type": "string", "name": "event_name", "multiValueHandling": "SORTED_ARRAY", "createBitmapIndex": true }, { "type": "string", "name": "event_section", "multiValueHandling": "SORTED_ARRAY", "createBitmapIndex": true } ] }, "metricsSpec": [ { "type": "count", "name": "count" } ] } }, "ioConfig": { "type": "index_parallel", "inputSource": { "type": "s3", "prefixes" : [ "s3://andromeda" ] }, "inputFormat": { "type": "orc", "flattenSpec": { "useFieldDiscovery": true, "fields": [] } }, "appendToExisting": true }, "tuningConfig": { "type": "index_parallel", "maxRowsPerSegment": 5000000, "maxRowsInMemory": 1000000, "maxBytesInMemory": 0, "maxTotalRows": null, "numShards": null, "splitHintSpec": null, "partitionsSpec": { "type": "dynamic", "maxRowsPerSegment": 5000000, "maxTotalRows": null }, "indexSpec": { "bitmap": { "type": "roaring", "compressRunOnSerialization": true }, "dimensionCompression": "lz4", "metricCompression": "lz4", "longEncoding": "longs", "segmentLoader": null }, "indexSpecForIntermediatePersists": { "bitmap": { "type": "roaring", "compressRunOnSerialization": true }, "dimensionCompression": "lz4", "metricCompression": "lz4", "longEncoding": "longs", "segmentLoader": null }, "maxPendingPersists": 0, "forceGuaranteedRollup": false, "reportParseExceptions": false, "pushTimeout": 0, "segmentWriteOutMediumFactory": null, "maxNumConcurrentSubTasks": 5, "maxRetry": 3, "taskStatusCheckPeriodMs": 1000, "chatHandlerTimeout": "PT10S", "chatHandlerNumRetries": 5, "maxNumSegmentsToMerge": 100, "totalNumMergeTasks": 10, "logParseExceptions": false, "maxParseExceptions": 2147483647, "maxSavedParseExceptions": 0, "buildV9Directly": true, "partitionDimensions": [] } } }