Why a new task is pending when middle manager still left a worker?

817 views

Skip to first unread message

Chanh Le

unread,

Sep 27, 2016, 4:40:16 AM9/27/16

to Druid User

Hi everyone,

I have 2 middle managers middle1 has 5 workers and middle2 has 6 workers.

I am running an indexing task (Kafka-index-service) with configuration tasks:5 replicas: 2 which means it costs 10 workers to run and left 1 worker for another task.

But when I put a new task it's in Pending Tasks - Tasks waiting to be assigned to a worker

I just wanna know why it happens?

Thanks.

Gian Merlino

unread,

Sep 29, 2016, 2:53:14 PM9/29/16

to druid...@googlegroups.com

Hey Chanh,

Hmm, one possible reason is that this task is waiting on locks. Another possibility is some issue assigning the task to a worker – the overlord logs may have some additional info there.

Gian

--
You received this message because you are subscribed to the Google Groups "Druid User" group.
To unsubscribe from this group and stop receiving emails from it, send an email to druid-user+unsubscribe@googlegroups.com.
To post to this group, send email to druid...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/druid-user/9a618a90-999b-4b2a-a798-cdd03fbf0766%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Chanh Le

unread,

Sep 30, 2016, 6:27:01 AM9/30/16

to druid...@googlegroups.com

Hi Gian,

Scenario was I have 2 middle manager nodes and I restarted 1 node the task was pending and failed after that.

Overlord logs:

2016-09-30T10:24:23,598 INFO [Curator-PathChildrenCache-2] io.druid.indexing.overlord.RemoteTaskRunner - Kaboom! Worker[adx-pro-vdchcm-ants20-ip-10-199-0-20:8091] removed!

2016-09-30T10:24:23,599 INFO [Curator-PathChildrenCache-2] io.druid.indexing.overlord.RemoteTaskRunner - [adx-pro-vdchcm-ants20-ip-10-199-0-20:8091]: Found 0 tasks assigned

2016-09-30T10:24:31,824 INFO [Curator-PathChildrenCache-2] io.druid.indexing.overlord.RemoteTaskRunner - Worker[adx-pro-vdchcm-ants20-ip-10-199-0-20:8091] reportin' for duty!

2016-09-30T10:24:31,824 INFO [Curator-PathChildrenCache-2] io.druid.indexing.overlord.RemoteTaskRunner - Cancelling Worker[adx-pro-vdchcm-ants20-ip-10-199-0-20:8091] scheduled task cleanup

2016-09-30T10:24:48,050 INFO [TaskQueue-StorageSync] io.druid.indexing.overlord.TaskQueue - Synced 1 tasks from storage (0 tasks added, 0 tasks removed).

2016-09-30T10:24:50,258 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.258Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jetty/numOpenConnections","value":7}]

2016-09-30T10:24:50,334 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.334Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/mem/max","value":3087007744,"memKind":"heap"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/max","value":251658240,"poolKind":"nonheap","poolName":"Code Cache"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/committed","value":31916032,"poolKind":"nonheap","poolName":"Code Cache"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/used","value":31560896,"poolKind":"nonheap","poolName":"Code Cache"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/init","value":2555904,"poolKind":"nonheap","poolName":"Code Cache"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/committed","value":57106432,"poolKind":"nonheap","poolName":"Metaspace"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/used","value":56044656,"poolKind":"nonheap","poolName":"Metaspace"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/init","value":0,"poolKind":"nonheap","poolName":"Metaspace"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/max","value":1073741824,"poolKind":"nonheap","poolName":"Compressed Class Space"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/committed","value":7077888,"poolKind":"nonheap","poolName":"Compressed Class Space"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/used","value":6771592,"poolKind":"nonheap","poolName":"Compressed Class Space"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/init","value":0,"poolKind":"nonheap","poolName":"Compressed Class Space"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/max","value":805306368,"poolKind":"heap","poolName":"PS Eden Space"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/committed","value":805306368,"poolKind":"heap","poolName":"PS Eden Space"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/used","value":58705696,"poolKind":"heap","poolName":"PS Eden Space"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/init","value":805306368,"poolKind":"heap","poolName":"PS Eden Space"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/max","value":134217728,"poolKind":"heap","poolName":"PS Survivor Space"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/committed","value":134217728,"poolKind":"heap","poolName":"PS Survivor Space"}]

2016-09-30T10:24:50,335 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/used","value":16094504,"poolKind":"heap","poolName":"PS Survivor Space"}]

2016-09-30T10:24:50,336 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.335Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/init","value":134217728,"poolKind":"heap","poolName":"PS Survivor Space"}]

2016-09-30T10:24:50,336 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.336Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/max","value":2147483648,"poolKind":"heap","poolName":"PS Old Gen"}]

2016-09-30T10:24:50,336 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.336Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/committed","value":2147483648,"poolKind":"heap","poolName":"PS Old Gen"}]

2016-09-30T10:24:50,336 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.336Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/used","value":20845032,"poolKind":"heap","poolName":"PS Old Gen"}]

2016-09-30T10:24:50,336 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.336Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/pool/init","value":2147483648,"poolKind":"heap","poolName":"PS Old Gen"}]

2016-09-30T10:24:50,336 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.336Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/bufferpool/capacity","value":9303010,"bufferpoolName":"direct"}]

2016-09-30T10:24:50,336 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.336Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/bufferpool/used","value":9303010,"bufferpoolName":"direct"}]

2016-09-30T10:24:50,336 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.336Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/bufferpool/count","value":397,"bufferpoolName":"direct"}]

2016-09-30T10:24:50,336 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.336Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/bufferpool/capacity","value":0,"bufferpoolName":"mapped"}]

2016-09-30T10:24:50,336 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.336Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/bufferpool/used","value":0,"bufferpoolName":"mapped"}]

2016-09-30T10:24:50,336 INFO [MonitorScheduler-0] com.metamx.emitter.core.LoggingEmitter - Event [{"feed":"metrics","timestamp":"2016-09-30T10:24:50.336Z","service":"druid/overlord","host":"adx-pro-vdchcm-ants19-ip-10-199-0-19:8090","metric":"jvm/bufferpool/count","value":0,"bufferpoolName":"mapped"}]

2016-09-30T10:24:54,307 INFO [rtr-pending-tasks-runner-0] io.druid.indexing.overlord.RemoteTaskRunner - Worker[adx-pro-vdchcm-ants20-ip-10-199-0-20:8091] completed task[index_kafka_ad_statistics_hourly_realtime_c0cdbe4966f10f8_lbilodko] with status[FAILED]

2016-09-30T10:24:54,307 INFO [rtr-pending-tasks-runner-0] io.druid.indexing.overlord.TaskRunnerUtils - Task [index_kafka_ad_statistics_hourly_realtime_c0cdbe4966f10f8_lbilodko] status changed to [FAILED].

2016-09-30T10:24:54,307 WARN [rtr-pending-tasks-runner-0] io.druid.indexing.overlord.RemoteTaskRunner - No worker selections strategy set. Using default.

2016-09-30T10:24:54,307 INFO [rtr-pending-tasks-runner-0] io.druid.indexing.overlord.RemoteTaskRunner - Coordinator asking Worker[adx-pro-vdchcm-ants19-ip-10-199-0-19:8091] to add task[index_hadoop_statistic_hourly_24h_2016-09-30T10:20:02.491Z]

2016-09-30T10:24:54,314 INFO [rtr-pending-tasks-runner-0] io.druid.indexing.overlord.RemoteTaskRunner - Task index_hadoop_statistic_hourly_24h_2016-09-30T10:20:02.491Z switched from pending to running (on [adx-pro-vdchcm-ants19-ip-10-199-0-19:8091])

2016-09-30T10:24:54,314 INFO [rtr-pending-tasks-runner-0] io.druid.indexing.overlord.TaskRunnerUtils - Task [index_hadoop_statistic_hourly_24h_2016-09-30T10:20:02.491Z] status changed to [RUNNING].

2016-09-30T10:24:54,554 INFO [Curator-PathChildrenCache-2] io.druid.indexing.overlord.RemoteTaskRunner - Worker[adx-pro-vdchcm-ants19-ip-10-199-0-19:8091] wrote RUNNING status for task [index_hadoop_statistic_hourly_24h_2016-09-30T10:20:02.491Z] on [TaskLocation{host='null', port=-1}]

2016-09-30T10:24:54,631 INFO [Curator-PathChildrenCache-2] io.druid.indexing.overlord.RemoteTaskRunner - Worker[adx-pro-vdchcm-ants19-ip-10-199-0-19:8091] wrote RUNNING status for task [index_hadoop_statistic_hourly_24h_2016-09-30T10:20:02.491Z] on [TaskLocation{host='adx-pro-vdchcm-ants19-ip-10-199-0-19', port=8100}]

2016-09-30T10:24:54,631 INFO [Curator-PathChildrenCache-2] io.druid.indexing.overlord.TaskRunnerUtils - Task [index_hadoop_statistic_hourly_24h_2016-09-30T10:20:02.491Z] location changed to [TaskLocation{host='adx-pro-vdchcm-ants19-ip-10-199-0-19', port=8100}].

2016-09-30T10:25:00,018 INFO [Curator-PathChildrenCache-2] io.druid.indexing.overlord.RemoteTaskRunner - Worker[adx-pro-vdchcm-ants19-ip-10-199-0-19:8091] wrote FAILED status for task [index_hadoop_statistic_hourly_24h_2016-09-30T10:20:02.491Z] on [TaskLocation{host='adx-pro-vdchcm-ants19-ip-10-199-0-19', port=8100}]

2016-09-30T10:25:00,018 INFO [Curator-PathChildrenCache-2] io.druid.indexing.overlord.RemoteTaskRunner - Worker[adx-pro-vdchcm-ants19-ip-10-199-0-19:8091] completed task[index_hadoop_statistic_hourly_24h_2016-09-30T10:20:02.491Z] with status[FAILED]

2016-09-30T10:25:00,019 INFO [Curator-PathChildrenCache-2] io.druid.indexing.overlord.TaskQueue - Received FAILED status for task: index_hadoop_statistic_hourly_24h_2016-09-30T10:20:02.491Z

You received this message because you are subscribed to a topic in the Google Groups "Druid User" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/druid-user/45ApSPoJ-Ks/unsubscribe.
To unsubscribe from this group and all its topics, send an email to druid-user+...@googlegroups.com.

To post to this group, send email to druid...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/druid-user/CACZNdYAJ6dPQjavTT8Me2tRKHDg9ScuC%3D-i282kV-CJfFHePwg%40mail.gmail.com.

Skyler Tao

unread,

Aug 21, 2017, 11:15:15 PM8/21/17

to Druid User

I think you're using druid version below 0.10.0, and using equalDistributionWorkerSelectStrategy which is the default.

In this case, there is a bug on worker select strategy, which is fixed in 0.10.0.