search

druid-io / docker-druid

Druid Docker
197 stars 159 forks source link

Expected Replicants[2] #10

Open nmarasoiu opened 9 years ago

nmarasoiu commented 9 years ago

Hi, docker-druid says Expected Replicants[2] when trying to execute index task from the wiki example. where can this be changed? docker is a single node, cannot be replicated

nmarasoiu commented 9 years ago

I make: curl -X 'POST' -H 'Content-Type:application/json' -d @examples/indexing/wikipedia_index_task.json boot2docker ip:8090/druid/indexer/v1/task I get {"task":"index_wikipedia_2015-10-05T12:32:20.296Z"} In the logs I see the task being cancelled:

2015-10-05 12:31:36,697 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:31:36,696 INFO [Coordinator-Exec--0] io.druid.server.coordinator.helper.DruidCoordinatorSegmentInfoLoader - Found [1] available segments.

2015-10-05 12:31:36,697 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:31:36,697 INFO [Coordinator-Exec--0] io.druid.server.coordinator.ReplicationThrottler - [_default_tier]: Replicant create queue is empty. 2015-10-05T12:31:36,697 INFO [Coordinator-Exec--0] io.druid.server.coordinator.ReplicationThrottler - [_default_tier]: Replicant terminate queue is empty.

2015-10-05 12:31:36,711 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:31:36,710 WARN [Coordinator-Exec--0] io.druid.server.coordinator.rules.LoadRule - Not enough [_default_tier] servers or node capacity to assign segment[wikipedia_2013-08-01T00:00:00.000Z_2013-08-02T00:00:00.000Z_2013-08-08T21:22:48.989Z]! Expected Replicants[2]

2015-10-05 12:31:36,712 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:31:36,711 INFO [Coordinator-Exec--0] io.druid.server.coordinator.helper.DruidCoordinatorBalancer - [_default_tier]: One or fewer servers found. Cannot balance. 2015-10-05T12:31:36,712 INFO [Coordinator-Exec--0] io.druid.server.coordinator.helper.DruidCoordinatorLogger - [_default_tier] : Assigned 0 segments among 1 servers

2015-10-05 12:31:36,714 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:31:36,713 INFO [Coordinator-Exec--0] io.druid.server.coordinator.helper.DruidCoordinatorLogger - Load Queues: 2015-10-05T12:31:36,713 INFO [Coordinator-Exec--0] io.druid.server.coordinator.helper.DruidCoordinatorLogger - Server[172.17.0.22:8083, historical, _default_tier] has 0 left to load, 0 left to drop, 0 bytes queued, 24,664,730 bytes served.

2015-10-05 12:32:20,296 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:20,296 INFO [qtp1005331061-36] io.druid.indexing.overlord.MetadataTaskStorage - Inserting task index_wikipedia_2015-10-05T12:32:20.296Z with status: TaskStatus{id=index_wikipedia_2015-10-05T12:32:20.296Z, status=RUNNING, duration=-1}

2015-10-05 12:32:20,304 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:20,303 INFO [qtp1005331061-36] io.druid.indexing.overlord.TaskLockbox - Adding task[index_wikipedia_2015-10-05T12:32:20.296Z] to activeTasks

2015-10-05 12:32:20,306 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:20,305 INFO [TaskQueue-Manager] io.druid.indexing.common.actions.LocalTaskActionClient - Performing action for task[index_wikipedia_2015-10-05T12:32:20.296Z]: LockTryAcquireAction{interval=2013-08-31T00:00:00.000Z/2013-09-01T00:00:00.000Z} 2015-10-05T12:32:20,305 INFO [TaskQueue-Manager] io.druid.indexing.overlord.TaskLockbox - Created new TaskLockPosse: TaskLockPosse{taskLock=TaskLock{groupId=index_wikipedia_2015-10-05T12:32:20.296Z, dataSource=wikipedia, interval=2013-08-31T00:00:00.000Z/2013-09-01T00:00:00.000Z, version=2015-10-05T12:32:20.305Z}, taskIds=[]} 2015-10-05T12:32:20,305 INFO [TaskQueue-Manager] io.druid.indexing.overlord.TaskLockbox - Added task[index_wikipedia_2015-10-05T12:32:20.296Z] to TaskLock[index_wikipedia_2015-10-05T12:32:20.296Z] 2015-10-05T12:32:20,305 INFO [TaskQueue-Manager] io.druid.indexing.overlord.MetadataTaskStorage - Adding lock on interval[2013-08-31T00:00:00.000Z/2013-09-01T00:00:00.000Z] version[2015-10-05T12:32:20.305Z] for task: index_wikipedia_2015-10-05T12:32:20.296Z

2015-10-05 12:32:20,312 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:20,311 INFO [TaskQueue-Manager] io.druid.indexing.overlord.TaskQueue - Asking taskRunner to run: index_wikipedia_2015-10-05T12:32:20.296Z

2015-10-05 12:32:20,315 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:20,315 INFO [pool-7-thread-6] io.druid.indexing.overlord.ForkingTaskRunner - Running command: java -cp /usr/local/druid/lib/druid-services-master-selfcontained.jar -server -Xmx1g -Dfile.encoding.pkg=sun.io -Djava.io.tmpdir=/tmp -Ddruid.peon.mode=local -Ddruid.metadata.storage.type=mysql -Ddruid.extensions.localRepository=/usr/local/druid/repository -Duser.timezone=UTC -Dfile.encoding=UTF-8 -Ddruid.metadata.storage.connector.user=druid -Ddruid.indexer.queue.startDelay=PT0M -Ddruid.metadata.storage.connector.connectURI=jdbc:mysql://localhost:3306/druid -Ddruid.extensions.coordinates=["io.druid.extensions:mysql-metadata-storage"] -Ddruid.host=172.17.0.22 -Ddruid.indexer.storage.type=metadata -Ddruid.indexer.runner.javaOpts=-server -Xmx1g -Ddruid.metadata.storage.connector.password=diurd -Ddruid.host=172.17.0.22 -Ddruid.port=8100 io.druid.cli.Main internal peon /tmp/persistent/task/index_wikipedia_2015-10-05T12:32:20.296Z/1244a766-70cb-4fa9-a7c4-80b19e448d0d/task.json /tmp/persistent/task/index_wikipedia_2015-10-05T12:32:20.296Z/1244a766-70cb-4fa9-a7c4-80b19e448d0d/status.json

2015-10-05 12:32:20,318 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:20,317 INFO [pool-7-thread-6] io.druid.indexing.overlord.ForkingTaskRunner - Logging task index_wikipedia_2015-10-05T12:32:20.296Z output to: /tmp/persistent/task/index_wikipedia_2015-10-05T12:32:20.296Z/1244a766-70cb-4fa9-a7c4-80b19e448d0d/log

2015-10-05 12:32:24,645 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:24,644 INFO [pool-7-thread-6] io.druid.indexing.overlord.ForkingTaskRunner - Process exited with status[1] for task: index_wikipedia_2015-10-05T12:32:20.296Z

2015-10-05 12:32:24,647 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:24,646 INFO [pool-7-thread-6] io.druid.indexing.common.tasklogs.FileTaskLogs - Wrote task log to: log/index_wikipedia_2015-10-05T12:32:20.296Z.log

2015-10-05 12:32:24,647 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:24,647 INFO [pool-7-thread-6] io.druid.indexing.overlord.ForkingTaskRunner - Removing temporary directory: /tmp/persistent/task/index_wikipedia_2015-10-05T12:32:20.296Z/1244a766-70cb-4fa9-a7c4-80b19e448d0d

2015-10-05 12:32:24,651 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:24,650 INFO [pool-7-thread-6] io.druid.indexing.overlord.TaskQueue - Received FAILED status for task: index_wikipedia_2015-10-05T12:32:20.296Z 2015-10-05T12:32:24,651 INFO [pool-7-thread-6] io.druid.indexing.overlord.ForkingTaskRunner - Ignoring request to cancel unknown task: index_wikipedia_2015-10-05T12:32:20.296Z 2015-10-05T12:32:24,651 INFO [pool-7-thread-6] io.druid.indexing.overlord.TaskLockbox - Removing task[index_wikipedia_2015-10-05T12:32:20.296Z] from activeTasks

2015-10-05 12:32:24,652 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:24,651 INFO [pool-7-thread-6] io.druid.indexing.overlord.TaskLockbox - Removing task[index_wikipedia_2015-10-05T12:32:20.296Z] from TaskLock[index_wikipedia_2015-10-05T12:32:20.296Z] 2015-10-05T12:32:24,651 INFO [pool-7-thread-6] io.druid.indexing.overlord.TaskLockbox - TaskLock is now empty: TaskLock{groupId=index_wikipedia_2015-10-05T12:32:20.296Z, dataSource=wikipedia, interval=2013-08-31T00:00:00.000Z/2013-09-01T00:00:00.000Z, version=2015-10-05T12:32:20.305Z}

2015-10-05 12:32:24,658 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:24,657 INFO [pool-7-thread-6] io.druid.indexing.overlord.MetadataTaskStorage - Deleting TaskLock with id[6]: TaskLock{groupId=index_wikipedia_2015-10-05T12:32:20.296Z, dataSource=wikipedia, interval=2013-08-31T00:00:00.000Z/2013-09-01T00:00:00.000Z, version=2015-10-05T12:32:20.305Z}

2015-10-05 12:32:24,664 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:24,663 INFO [pool-7-thread-6] io.druid.indexing.overlord.MetadataTaskStorage - Updating task index_wikipedia_2015-10-05T12:32:20.296Z to status: TaskStatus{id=index_wikipedia_2015-10-05T12:32:20.296Z, status=FAILED, duration=-1}

2015-10-05 12:32:24,669 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:24,669 INFO [pool-7-thread-6] io.druid.indexing.overlord.TaskQueue - Task done: IndexTask{id=index_wikipedia_2015-10-05T12:32:20.296Z, type=index, dataSource=wikipedia}

2015-10-05 12:32:24,669 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:24,669 INFO [pool-7-thread-6] io.druid.indexing.overlord.TaskQueue - Task FAILED: IndexTask{id=index_wikipedia_2015-10-05T12:32:20.296Z, type=index, dataSource=wikipedia} (-1 run duration)

2015-10-05 12:32:30,764 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:32:30,763 INFO [DatabaseSegmentManager-Exec--0] io.druid.metadata.SQLMetadataSegmentManager - Polled and found 1 segments in the database

2015-10-05 12:32:30,916 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:32:30,914 INFO [DatabaseRuleManager-Exec--0] io.druid.metadata.SQLMetadataRuleManager - Polled and found rules for 1 datasource(s)

2015-10-05 12:32:31,307 DEBG 'druid-indexing-service' stdout output: 2015-10-05T12:32:31,306 INFO [TaskQueue-StorageSync] io.druid.indexing.overlord.TaskQueue - Synced 0 tasks from storage (0 tasks added, 0 tasks removed).

2015-10-05 12:32:36,716 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:32:36,715 INFO [Coordinator-Exec--0] io.druid.server.coordinator.helper.DruidCoordinatorSegmentInfoLoader - Starting coordination. Getting available segments.

2015-10-05 12:32:36,716 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:32:36,715 INFO [Coordinator-Exec--0] io.druid.server.coordinator.helper.DruidCoordinatorSegmentInfoLoader - Found [1] available segments.

2015-10-05 12:32:36,717 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:32:36,716 INFO [Coordinator-Exec--0] io.druid.server.coordinator.ReplicationThrottler - [_default_tier]: Replicant create queue is empty. 2015-10-05T12:32:36,716 INFO [Coordinator-Exec--0] io.druid.server.coordinator.ReplicationThrottler - [_default_tier]: Replicant terminate queue is empty.

2015-10-05 12:32:36,726 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:32:36,726 WARN [Coordinator-Exec--0] io.druid.server.coordinator.rules.LoadRule - Not enough [_default_tier] servers or node capacity to assign segment[wikipedia_2013-08-01T00:00:00.000Z_2013-08-02T00:00:00.000Z_2013-08-08T21:22:48.989Z]! Expected Replicants[2]

2015-10-05 12:32:36,730 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:32:36,729 INFO [Coordinator-Exec--0] io.druid.server.coordinator.helper.DruidCoordinatorBalancer - [_default_tier]: One or fewer servers found. Cannot balance. 2015-10-05T12:32:36,730 INFO [Coordinator-Exec--0] io.druid.server.coordinator.helper.DruidCoordinatorLogger - [_default_tier] : Assigned 0 segments among 1 servers

2015-10-05 12:32:36,731 DEBG 'druid-coordinator' stdout output: 2015-10-05T12:32:36,730 INFO [Coordinator-Exec--0] io.druid.server.coordinator.helper.DruidCoordinatorLogger - Load Queues: 2015-10-05T12:32:36,730 INFO [Coordinator-Exec--0] io.druid.server.coordinator.helper.DruidCoordinatorLogger - Server[172.17.0.22:8083, historical, _default_tier] has 0 left to load, 0 left to drop, 0 bytes queued, 24,664,730 bytes served.

Fokko commented 7 years ago

This can be modified by altering the rules of the datasource. Although this Expected replicants is a warning, and will not influence the working of the Druid cluster.