Manuel Romero created KAFKA-4582:
------------------------------------
Summary: KStream job fails in multi-thread mode
Key: KAFKA-4582
URL: https://issues.apache.org/jira/browse/KAFKA-4582
Project: Kafka
Issue Type: Bug
Components: streams
Affects Versions: 0.10.0.1
Environment: t2.large EC2 AWS instance
Reporter: Manuel Romero
We are experimenting an issue with KStream when using more than one thread.
Currently, we are using 2 threads in a t2.large EC2 AWS instance. According to
the searches we made, this error should be solved in the version we are
currently using. It seems the job fails to rebalance due to an error on the
lock on the state directory. This is the full log.
16/12/19 16:36:36 INFO internals.AbstractCoordinator: (Re-)joining group
dougal_text_pipeline_id
16/12/19 16:36:36 INFO assignment.TaskAssignor: stream-thread [StreamThread-6]
Assigning tasks to clients: {a2a7324e-43da-4b17-878b-53f62a0fd870=[activeTasks:
([]) assignedTasks: ([]) prevActiveTasks: ([0_32, 0_2, 0_68, 0_38, 0_8, 0_74,
0_44, 0_14, 0_80, 0_50, 0_20, 0_86, 0_56, 0_26, 0_92, 0_62]) prevAssignedTasks:
([0_32, 0_2, 0_68, 0_38, 0_8, 0_74, 0_44, 0_14, 0_80, 0_50, 0_20, 0_86, 0_56,
0_26, 0_92, 0_62]) capacity: 1.0 cost: 0.0]}, prevAssignmentBalanced: false,
prevClientsUnchanged: false, tasks: [0_0, 0_1, 0_2, 0_3, 0_4, 0_5, 0_6, 0_7,
0_8, 0_9, 0_10, 0_11, 0_12, 0_13, 0_14, 0_15, 0_16, 0_17, 0_18, 0_19, 0_20,
0_21, 0_22, 0_23, 0_24, 0_25, 0_26, 0_27, 0_28, 0_29, 0_30, 0_31, 0_32, 0_33,
0_34, 0_35, 0_36, 0_37, 0_38, 0_39, 0_40, 0_41, 0_42, 0_43, 0_44, 0_45, 0_46,
0_47, 0_48, 0_49, 0_50, 0_51, 0_52, 0_53, 0_54, 0_55, 0_56, 0_57, 0_58, 0_59,
0_60, 0_61, 0_62, 0_63, 0_64, 0_65, 0_66, 0_67, 0_68, 0_69, 0_70, 0_71, 0_72,
0_73, 0_74, 0_75, 0_76, 0_77, 0_78, 0_79, 0_80, 0_81, 0_82, 0_83, 0_84, 0_85,
0_86, 0_87, 0_88, 0_89, 0_90, 0_91, 0_92, 0_93, 0_94, 0_95], replicas: 0
16/12/19 16:36:36 INFO assignment.TaskAssignor: stream-thread [StreamThread-6]
Assigned with: {a2a7324e-43da-4b17-878b-53f62a0fd870=[activeTasks: ([0_0, 0_1,
0_2, 0_3, 0_4, 0_5, 0_6, 0_7, 0_8, 0_9, 0_10, 0_11, 0_12, 0_13, 0_14, 0_15,
0_16, 0_17, 0_18, 0_19, 0_20, 0_21, 0_22, 0_23, 0_24, 0_25, 0_26, 0_27, 0_28,
0_29, 0_30, 0_31, 0_32, 0_33, 0_34, 0_35, 0_36, 0_37, 0_38, 0_39, 0_40, 0_41,
0_42, 0_43, 0_44, 0_45, 0_46, 0_47, 0_48, 0_49, 0_50, 0_51, 0_52, 0_53, 0_54,
0_55, 0_56, 0_57, 0_58, 0_59, 0_60, 0_61, 0_62, 0_63, 0_64, 0_65, 0_66, 0_67,
0_68, 0_69, 0_70, 0_71, 0_72, 0_73, 0_74, 0_75, 0_76, 0_77, 0_78, 0_79, 0_80,
0_81, 0_82, 0_83, 0_84, 0_85, 0_86, 0_87, 0_88, 0_89, 0_90, 0_91, 0_92, 0_93,
0_94, 0_95]) assignedTasks: ([0_0, 0_1, 0_2, 0_3, 0_4, 0_5, 0_6, 0_7, 0_8, 0_9,
0_10, 0_11, 0_12, 0_13, 0_14, 0_15, 0_16, 0_17, 0_18, 0_19, 0_20, 0_21, 0_22,
0_23, 0_24, 0_25, 0_26, 0_27, 0_28, 0_29, 0_30, 0_31, 0_32, 0_33, 0_34, 0_35,
0_36, 0_37, 0_38, 0_39, 0_40, 0_41, 0_42, 0_43, 0_44, 0_45, 0_46, 0_47, 0_48,
0_49, 0_50, 0_51, 0_52, 0_53, 0_54, 0_55, 0_56, 0_57, 0_58, 0_59, 0_60, 0_61,
0_62, 0_63, 0_64, 0_65, 0_66, 0_67, 0_68, 0_69, 0_70, 0_71, 0_72, 0_73, 0_74,
0_75, 0_76, 0_77, 0_78, 0_79, 0_80, 0_81, 0_82, 0_83, 0_84, 0_85, 0_86, 0_87,
0_88, 0_89, 0_90, 0_91, 0_92, 0_93, 0_94, 0_95]) prevActiveTasks: ([])
prevAssignedTasks: ([]) capacity: 1.0 cost: 41.600000000000016]}
16/12/19 16:36:36 INFO internals.AbstractCoordinator: Successfully joined group
dougal_text_pipeline_id with generation 21
16/12/19 16:36:36 INFO internals.ConsumerCoordinator: Setting newly assigned
partitions [crawler-fashion-content-83, crawler-fashion-content-17,
crawler-fashion-content-50, crawler-fashion-content-91,
crawler-fashion-content-25, crawler-fashion-content-58,
crawler-fashion-content-33, crawler-fashion-content-66,
crawler-fashion-content-0, crawler-fashion-content-41,
crawler-fashion-content-74, crawler-fashion-content-8,
crawler-fashion-content-49, crawler-fashion-content-82,
crawler-fashion-content-16, crawler-fashion-content-57,
crawler-fashion-content-90, crawler-fashion-content-24,
crawler-fashion-content-65, crawler-fashion-content-32,
crawler-fashion-content-73, crawler-fashion-content-7,
crawler-fashion-content-40, crawler-fashion-content-81,
crawler-fashion-content-15, crawler-fashion-content-48,
crawler-fashion-content-89, crawler-fashion-content-23,
crawler-fashion-content-56, crawler-fashion-content-31,
crawler-fashion-content-64, crawler-fashion-content-39,
crawler-fashion-content-72, crawler-fashion-content-6,
crawler-fashion-content-47, crawler-fashion-content-80,
crawler-fashion-content-14, crawler-fashion-content-55,
crawler-fashion-content-88, crawler-fashion-content-22,
crawler-fashion-content-63, crawler-fashion-content-30,
crawler-fashion-content-71, crawler-fashion-content-5,
crawler-fashion-content-38, crawler-fashion-content-79,
crawler-fashion-content-13, crawler-fashion-content-46,
crawler-fashion-content-87, crawler-fashion-content-21,
crawler-fashion-content-54, crawler-fashion-content-4,
crawler-fashion-content-95, crawler-fashion-content-29,
crawler-fashion-content-62, crawler-fashion-content-12,
crawler-fashion-content-37, crawler-fashion-content-70,
crawler-fashion-content-20, crawler-fashion-content-45,
crawler-fashion-content-78, crawler-fashion-content-28,
crawler-fashion-content-53, crawler-fashion-content-86,
crawler-fashion-content-3, crawler-fashion-content-36,
crawler-fashion-content-61, crawler-fashion-content-94,
crawler-fashion-content-11, crawler-fashion-content-44,
crawler-fashion-content-69, crawler-fashion-content-19,
crawler-fashion-content-52, crawler-fashion-content-77,
crawler-fashion-content-27, crawler-fashion-content-60,
crawler-fashion-content-85, crawler-fashion-content-35,
crawler-fashion-content-68, crawler-fashion-content-2,
crawler-fashion-content-93, crawler-fashion-content-43,
crawler-fashion-content-76, crawler-fashion-content-10,
crawler-fashion-content-51, crawler-fashion-content-84,
crawler-fashion-content-18, crawler-fashion-content-59,
crawler-fashion-content-92, crawler-fashion-content-26,
crawler-fashion-content-67, crawler-fashion-content-1,
crawler-fashion-content-34, crawler-fashion-content-75,
crawler-fashion-content-9, crawler-fashion-content-42] for group
dougal_text_pipeline_id
16/12/19 16:36:36 INFO internals.StreamThread: stream-thread [StreamThread-6]
New partitions [[crawler-fashion-content-83, crawler-fashion-content-17,
crawler-fashion-content-50, crawler-fashion-content-91,
crawler-fashion-content-25, crawler-fashion-content-58,
crawler-fashion-content-33, crawler-fashion-content-66,
crawler-fashion-content-0, crawler-fashion-content-41,
crawler-fashion-content-74, crawler-fashion-content-8,
crawler-fashion-content-49, crawler-fashion-content-82,
crawler-fashion-content-16, crawler-fashion-content-57,
crawler-fashion-content-90, crawler-fashion-content-24,
crawler-fashion-content-65, crawler-fashion-content-32,
crawler-fashion-content-73, crawler-fashion-content-7,
crawler-fashion-content-40, crawler-fashion-content-81,
crawler-fashion-content-15, crawler-fashion-content-48,
crawler-fashion-content-89, crawler-fashion-content-23,
crawler-fashion-content-56, crawler-fashion-content-31,
crawler-fashion-content-64, crawler-fashion-content-39,
crawler-fashion-content-72, crawler-fashion-content-6,
crawler-fashion-content-47, crawler-fashion-content-80,
crawler-fashion-content-14, crawler-fashion-content-55,
crawler-fashion-content-88, crawler-fashion-content-22,
crawler-fashion-content-63, crawler-fashion-content-30,
crawler-fashion-content-71, crawler-fashion-content-5,
crawler-fashion-content-38, crawler-fashion-content-79,
crawler-fashion-content-13, crawler-fashion-content-46,
crawler-fashion-content-87, crawler-fashion-content-21,
crawler-fashion-content-54, crawler-fashion-content-4,
crawler-fashion-content-95, crawler-fashion-content-29,
crawler-fashion-content-62, crawler-fashion-content-12,
crawler-fashion-content-37, crawler-fashion-content-70,
crawler-fashion-content-20, crawler-fashion-content-45,
crawler-fashion-content-78, crawler-fashion-content-28,
crawler-fashion-content-53, crawler-fashion-content-86,
crawler-fashion-content-3, crawler-fashion-content-36,
crawler-fashion-content-61, crawler-fashion-content-94,
crawler-fashion-content-11, crawler-fashion-content-44,
crawler-fashion-content-69, crawler-fashion-content-19,
crawler-fashion-content-52, crawler-fashion-content-77,
crawler-fashion-content-27, crawler-fashion-content-60,
crawler-fashion-content-85, crawler-fashion-content-35,
crawler-fashion-content-68, crawler-fashion-content-2,
crawler-fashion-content-93, crawler-fashion-content-43,
crawler-fashion-content-76, crawler-fashion-content-10,
crawler-fashion-content-51, crawler-fashion-content-84,
crawler-fashion-content-18, crawler-fashion-content-59,
crawler-fashion-content-92, crawler-fashion-content-26,
crawler-fashion-content-67, crawler-fashion-content-1,
crawler-fashion-content-34, crawler-fashion-content-75,
crawler-fashion-content-9, crawler-fashion-content-42]] assigned at the end of
consumer rebalance.
16/12/19 16:36:36 INFO internals.StreamThread: stream-thread [StreamThread-6]
Creating active task 0_0 with assigned partitions [[crawler-fashion-content-0]]
16/12/19 16:36:36 INFO kafka.KafkaStreamsBackboneCoordinator: get() called
16/12/19 16:36:36 INFO internals.StreamTask: task [0_0] Initializing state
stores
16/12/19 16:36:36 INFO internals.StreamTask: task [0_0] Initializing processor
nodes of the topology
16/12/19 16:36:36 INFO kafka.KafkaStreamsBackboneValueTransformer: Init called
with org.apache.kafka.streams.processor.internals.ProcessorContextImpl@43350b2e
0_0
16/12/19 16:36:36 INFO internals.StreamThread: stream-thread [StreamThread-6]
Creating active task 0_1 with assigned partitions [[crawler-fashion-content-1]]
16/12/19 16:36:36 INFO kafka.KafkaStreamsBackboneCoordinator: get() called
16/12/19 16:36:36 INFO internals.StreamTask: task [0_1] Initializing state
stores
16/12/19 16:36:36 INFO internals.StreamTask: task [0_1] Initializing processor
nodes of the topology
16/12/19 16:36:36 INFO kafka.KafkaStreamsBackboneValueTransformer: Init called
with org.apache.kafka.streams.processor.internals.ProcessorContextImpl@5d045471
0_1
16/12/19 16:36:36 INFO internals.StreamThread: stream-thread [StreamThread-6]
Creating active task 0_2 with assigned partitions [[crawler-fashion-content-2]]
16/12/19 16:36:36 INFO kafka.KafkaStreamsBackboneCoordinator: get() called
16/12/19 16:36:36 INFO internals.StreamTask: task [0_2] Initializing state
stores
16/12/19 16:36:36 INFO internals.StreamTask: task [0_2] Initializing processor
nodes of the topology
16/12/19 16:36:36 INFO kafka.KafkaStreamsBackboneValueTransformer: Init called
with org.apache.kafka.streams.processor.internals.ProcessorContextImpl@215e155a
0_2
16/12/19 16:36:36 INFO internals.StreamThread: stream-thread [StreamThread-6]
Creating active task 0_3 with assigned partitions [[crawler-fashion-content-3]]
16/12/19 16:36:36 INFO kafka.KafkaStreamsBackboneCoordinator: get() called
16/12/19 16:36:36 INFO internals.StreamTask: task [0_3] Initializing state
stores
16/12/19 16:36:36 INFO internals.StreamTask: task [0_3] Initializing processor
nodes of the topology
#011at
org.apache.kafka.streams.processor.internals.StreamTask.<init>(StreamTask.java:90)
#011at
org.apache.kafka.streams.processor.internals.StreamThread.createStreamTask(StreamThread.java:633)
#011at
org.apache.kafka.streams.processor.internals.StreamThread.addStreamTasks(StreamThread.java:660)
#011at
org.apache.kafka.streams.processor.internals.StreamThread.access$100(StreamThread.java:69)
#011at
org.apache.kafka.streams.processor.internals.StreamThread$1.onPartitionsAssigned(StreamThread.java:124)
#011at
org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.onJoinComplete(ConsumerCoordinator.java:228)
#011at
org.apache.kafka.clients.consumer.internals.AbstractCoordinator.joinGroupIfNeeded(AbstractCoordinator.java:313)
#011at
org.apache.kafka.clients.consumer.internals.AbstractCoordinator.ensureActiveGroup(AbstractCoordinator.java:277)
#011at
org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.poll(ConsumerCoordinator.java:259)
#011at
org.apache.kafka.clients.consumer.KafkaConsumer.pollOnce(KafkaConsumer.java:1013)
#011at
org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:979)
#011at
org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:407)
#011at
org.apache.kafka.streams.processor.internals.StreamThread.run(StreamThread.java:242)
Caused by: java.io.IOException: task [0_6] Failed to lock the state directory:
/tmp/kafka-streams/dougal_text_pipeline_id/0_6
#011at
org.apache.kafka.streams.processor.internals.ProcessorStateManager.<init>(ProcessorStateManager.java:101)
#011at
org.apache.kafka.streams.processor.internals.AbstractTask.<init>(AbstractTask.java:69)
#011... 13 more
16/12/19 16:36:37 ERROR internals.ConsumerCoordinator: User provided listener
org.apache.kafka.streams.processor.internals.StreamThread$1 for group
dougal_text_pipeline_id failed on partition assignment
org.apache.kafka.streams.errors.ProcessorStateException: task [0_6] Error while
creating the state manager
#011at
org.apache.kafka.streams.processor.internals.AbstractTask.<init>(AbstractTask.java:72)
#011at
org.apache.kafka.streams.processor.internals.StreamTask.<init>(StreamTask.java:90)
#011at
org.apache.kafka.streams.processor.internals.StreamThread.createStreamTask(StreamThread.java:633)
#011at
org.apache.kafka.streams.processor.internals.StreamThread.addStreamTasks(StreamThread.java:660)
#011at
org.apache.kafka.streams.processor.internals.StreamThread.access$100(StreamThread.java:69)
#011at
org.apache.kafka.streams.processor.internals.StreamThread$1.onPartitionsAssigned(StreamThread.java:124)
#011at
org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.onJoinComplete(ConsumerCoordinator.java:228)
#011at
org.apache.kafka.clients.consumer.internals.AbstractCoordinator.joinGroupIfNeeded(AbstractCoordinator.java:313)
#011at
org.apache.kafka.clients.consumer.internals.AbstractCoordinator.ensureActiveGroup(AbstractCoordinator.java:277)
#011at
org.apache.kafka.clients.consumer.internals.ConsumerCoordinator.poll(ConsumerCoordinator.java:259)
#011at
org.apache.kafka.clients.consumer.KafkaConsumer.pollOnce(KafkaConsumer.java:1013)
#011at
org.apache.kafka.clients.consumer.KafkaConsumer.poll(KafkaConsumer.java:979)
#011at
org.apache.kafka.streams.processor.internals.StreamThread.runLoop(StreamThread.java:407)
#011at
org.apache.kafka.streams.processor.internals.StreamThread.run(StreamThread.java:242)
Caused by: java.io.IOException: task [0_6] Failed to lock the state directory:
/tmp/kafka-streams/dougal_text_pipeline_id/0_6
#011at
org.apache.kafka.streams.processor.internals.ProcessorStateManager.<init>(ProcessorStateManager.java:101)
#011at
org.apache.kafka.streams.processor.internals.AbstractTask.<init>(AbstractTask.java:69)
#011... 13 more
16/12/19 16:36:37 INFO internals.StreamThread: stream-thread [StreamThread-6]
Shutting down
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
