[ https://issues.apache.org/jira/browse/SPARK-16762?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Sean Owen resolved SPARK-16762. ------------------------------- Resolution: Invalid Yeah, too many possible things wrong; it should be narrowed down separately first, possibly discussed on user@. If there's a fairly isolateable issue here, we can reopen. > spark hanging when action method print > -------------------------------------- > > Key: SPARK-16762 > URL: https://issues.apache.org/jira/browse/SPARK-16762 > Project: Spark > Issue Type: Bug > Components: Deploy > Reporter: Anh Nguyen > Attachments: Screen Shot 2016-07-28 at 12.33.35 PM.png, Screen Shot > 2016-07-28 at 12.34.22 PM.png > > > I write code spark Streaming (consumer) intergate kafaka and deploy on mesos > FW: > import org.apache.spark.SparkConf > import org.apache.spark.streaming._ > import org.apache.spark.streaming.kafka._ > import org.apache.spark.streaming.kafka._ > object consumer { > def main(args: Array[String]) { > if (args.length < 4) { > System.err.println("Usage: KafkaWordCount <zkQuorum><group> <topics> > <numThreads>") > System.exit(1) > } > val Array(zkQuorum, group, topics, numThreads) = args > val sparkConf = new > SparkConf().setAppName("KafkaWordCount").set("spark.rpc.netty.dispatcher.numThreads","4") > val ssc = new StreamingContext(sparkConf, Seconds(2)) > ssc.checkpoint("checkpoint") > val topicMap = topics.split(",").map((_, numThreads.toInt)).toMap > val lines = KafkaUtils.createStream(ssc, zkQuorum, group, > topicMap).map(_._2) > lines.print() > val words = lines.flatMap(_.split(" ")) > val wordCounts = words.map(x => (x, 1L)).reduceByKeyAndWindow(_ + _, _ > - _, Minutes(10), Seconds(2), 2) > ssc.start() > ssc.awaitTermination() > } > } > This log: > I0728 04:28:05.439469 4295 exec.cpp:143] Version: 0.28.2 > I0728 04:28:05.443464 4296 exec.cpp:217] Executor registered on slave > 8e00b1ea-3f70-428a-8125-fb0eed88aede-S0 > Using Spark's default log4j profile: > org/apache/spark/log4j-defaults.properties > 16/07/28 04:28:07 INFO CoarseGrainedExecutorBackend: Registered signal > handlers for [TERM, HUP, INT] > 16/07/28 04:28:08 WARN NativeCodeLoader: Unable to load native-hadoop library > for your platform... using builtin-java classes where applicable > 16/07/28 04:28:09 INFO SecurityManager: Changing view acls to: vagrant > 16/07/28 04:28:09 INFO SecurityManager: Changing modify acls to: vagrant > 16/07/28 04:28:09 INFO SecurityManager: SecurityManager: authentication > disabled; ui acls disabled; users with view permissions: Set(vagrant); users > with modify permissions: Set(vagrant) > 16/07/28 04:28:11 INFO SecurityManager: Changing view acls to: vagrant > 16/07/28 04:28:11 INFO SecurityManager: Changing modify acls to: vagrant > 16/07/28 04:28:11 INFO SecurityManager: SecurityManager: authentication > disabled; ui acls disabled; users with view permissions: Set(vagrant); users > with modify permissions: Set(vagrant) > 16/07/28 04:28:12 INFO Slf4jLogger: Slf4jLogger started > 16/07/28 04:28:12 INFO Remoting: Starting remoting > 16/07/28 04:28:13 INFO Remoting: Remoting started; listening on addresses > :[akka.tcp://sparkExecutorActorSystem@slave1:57380] > 16/07/28 04:28:13 INFO Utils: Successfully started service > 'sparkExecutorActorSystem' on port 57380. > 16/07/28 04:28:13 INFO DiskBlockManager: Created local directory at > /home/vagrant/mesos/slave1/work/slaves/8e00b1ea-3f70-428a-8125-fb0eed88aede-S0/frameworks/3b189004-daea-47a3-9ba5-dfac5143f4ab-0000/executors/0/runs/0433234f-332d-4858-9527-64558fe7fb90/blockmgr-4e94f4ea-f074-4dbe-bfa1-34054e6e079c > 16/07/28 04:28:13 INFO MemoryStore: MemoryStore started with capacity 517.4 MB > 16/07/28 04:28:13 INFO CoarseGrainedExecutorBackend: Connecting to driver: > spark://CoarseGrainedScheduler@192.168.33.30:36179 > 16/07/28 04:28:13 INFO CoarseGrainedExecutorBackend: Successfully registered > with driver > 16/07/28 04:28:13 INFO Executor: Starting executor ID > 8e00b1ea-3f70-428a-8125-fb0eed88aede-S0 on host slave1 > 16/07/28 04:28:13 INFO Utils: Successfully started service > 'org.apache.spark.network.netty.NettyBlockTransferService' on port 48672. > 16/07/28 04:28:13 INFO NettyBlockTransferService: Server created on 48672 > 16/07/28 04:28:13 INFO BlockManagerMaster: Trying to register BlockManager > 16/07/28 04:28:13 INFO BlockManagerMaster: Registered BlockManager > 16/07/28 04:28:13 INFO CoarseGrainedExecutorBackend: Got assigned task 0 > 16/07/28 04:28:13 INFO Executor: Running task 0.0 in stage 0.0 (TID 0) > 16/07/28 04:28:13 INFO Executor: Fetching > http://192.168.33.30:52977/jars/spaka-1.0-SNAPSHOT-jar-with-dependencies.jar > with timestamp 1469680084686 > 16/07/28 04:28:14 INFO Utils: Fetching > http://192.168.33.30:52977/jars/spaka-1.0-SNAPSHOT-jar-with-dependencies.jar > to > /home/vagrant/mesos/slave1/work/slaves/8e00b1ea-3f70-428a-8125-fb0eed88aede-S0/frameworks/3b189004-daea-47a3-9ba5-dfac5143f4ab-0000/executors/0/runs/0433234f-332d-4858-9527-64558fe7fb90/spark-b833a8b6-b16c-46c6-92a7-89a8f0b3f713/fetchFileTemp4218016376984854956.tmp > 16/07/28 04:28:14 INFO Utils: Copying > /home/vagrant/mesos/slave1/work/slaves/8e00b1ea-3f70-428a-8125-fb0eed88aede-S0/frameworks/3b189004-daea-47a3-9ba5-dfac5143f4ab-0000/executors/0/runs/0433234f-332d-4858-9527-64558fe7fb90/spark-b833a8b6-b16c-46c6-92a7-89a8f0b3f713/-10744548291469680084686_cache > to > /home/vagrant/mesos/slave1/work/slaves/8e00b1ea-3f70-428a-8125-fb0eed88aede-S0/frameworks/3b189004-daea-47a3-9ba5-dfac5143f4ab-0000/executors/0/runs/0433234f-332d-4858-9527-64558fe7fb90/./spaka-1.0-SNAPSHOT-jar-with-dependencies.jar > 16/07/28 04:28:15 INFO Executor: Adding > file:/home/vagrant/mesos/slave1/work/slaves/8e00b1ea-3f70-428a-8125-fb0eed88aede-S0/frameworks/3b189004-daea-47a3-9ba5-dfac5143f4ab-0000/executors/0/runs/0433234f-332d-4858-9527-64558fe7fb90/./spaka-1.0-SNAPSHOT-jar-with-dependencies.jar > to class loader > 16/07/28 04:28:15 INFO TorrentBroadcast: Started reading broadcast variable 0 > 16/07/28 04:28:15 INFO MemoryStore: Block broadcast_0_piece0 stored as bytes > in memory (estimated size 1726.0 B, free 1726.0 B) > 16/07/28 04:28:15 INFO TorrentBroadcast: Reading broadcast variable 0 took > 258 ms > 16/07/28 04:28:15 INFO MemoryStore: Block broadcast_0 stored as values in > memory (estimated size 2.8 KB, free 4.4 KB) > 16/07/28 04:28:16 INFO Executor: Finished task 0.0 in stage 0.0 (TID 0). 1204 > bytes result sent to driver > 16/07/28 04:28:16 INFO CoarseGrainedExecutorBackend: Got assigned task 1 > 16/07/28 04:28:16 INFO Executor: Running task 1.0 in stage 0.0 (TID 1) > 16/07/28 04:28:16 INFO Executor: Finished task 1.0 in stage 0.0 (TID 1). 1204 > bytes result sent to driver > 16/07/28 04:28:16 INFO CoarseGrainedExecutorBackend: Got assigned task 2 > 16/07/28 04:28:16 INFO Executor: Running task 2.0 in stage 0.0 (TID 2) > 16/07/28 04:28:16 INFO Executor: Finished task 2.0 in stage 0.0 (TID 2). 1204 > bytes result sent to driver > 16/07/28 04:28:16 INFO CoarseGrainedExecutorBackend: Got assigned task 3 > 16/07/28 04:28:16 INFO Executor: Running task 3.0 in stage 0.0 (TID 3) > 16/07/28 04:28:16 INFO Executor: Finished task 3.0 in stage 0.0 (TID 3). 1204 > bytes result sent to driver > 16/07/28 04:28:16 INFO CoarseGrainedExecutorBackend: Got assigned task 4 > 16/07/28 04:28:16 INFO Executor: Running task 4.0 in stage 0.0 (TID 4) > 16/07/28 04:28:16 INFO Executor: Finished task 4.0 in stage 0.0 (TID 4). 1204 > bytes result sent to driver > 16/07/28 04:28:16 INFO CoarseGrainedExecutorBackend: Got assigned task 5 > 16/07/28 04:28:16 INFO Executor: Running task 5.0 in stage 0.0 (TID 5) > 16/07/28 04:28:16 INFO Executor: Finished task 5.0 in stage 0.0 (TID 5). 1204 > bytes result sent to driver > 16/07/28 04:28:16 INFO CoarseGrainedExecutorBackend: Got assigned task 6 > 16/07/28 04:28:16 INFO Executor: Running task 6.0 in stage 0.0 (TID 6) > 16/07/28 04:28:16 INFO Executor: Finished task 6.0 in stage 0.0 (TID 6). 1204 > bytes result sent to driver > 16/07/28 04:28:16 INFO CoarseGrainedExecutorBackend: Got assigned task 7 > 16/07/28 04:28:16 INFO Executor: Running task 7.0 in stage 0.0 (TID 7) > 16/07/28 04:28:16 INFO Executor: Finished task 7.0 in stage 0.0 (TID 7). 1204 > bytes result sent to driver > 16/07/28 04:28:16 INFO CoarseGrainedExecutorBackend: Got assigned task 8 > 16/07/28 04:28:16 INFO Executor: Running task 8.0 in stage 0.0 (TID 8) > 16/07/28 04:28:16 INFO Executor: Finished task 8.0 in stage 0.0 (TID 8). 1204 > bytes result sent to driver > 16/07/28 04:28:16 INFO CoarseGrainedExecutorBackend: Got assigned task 9 > 16/07/28 04:28:16 INFO Executor: Running task 9.0 in stage 0.0 (TID 9) > 16/07/28 04:28:16 INFO Executor: Finished task 9.0 in stage 0.0 (TID 9). 1204 > bytes result sent to driver > 16/07/28 04:28:16 INFO CoarseGrainedExecutorBackend: Got assigned task 10 > 16/07/28 04:28:16 INFO Executor: Running task 10.0 in stage 0.0 (TID 10) > 16/07/28 04:28:16 INFO Executor: Finished task 10.0 in stage 0.0 (TID 10). > 1204 bytes result sent to driver > 16/07/28 04:28:16 INFO CoarseGrainedExecutorBackend: Got assigned task 11 > 16/07/28 04:28:16 INFO Executor: Running task 11.0 in stage 0.0 (TID 11) > 16/07/28 04:28:17 INFO Executor: Finished task 11.0 in stage 0.0 (TID 11). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 12 > 16/07/28 04:28:17 INFO Executor: Running task 12.0 in stage 0.0 (TID 12) > 16/07/28 04:28:17 INFO Executor: Finished task 12.0 in stage 0.0 (TID 12). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 13 > 16/07/28 04:28:17 INFO Executor: Running task 13.0 in stage 0.0 (TID 13) > 16/07/28 04:28:17 INFO Executor: Finished task 13.0 in stage 0.0 (TID 13). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 14 > 16/07/28 04:28:17 INFO Executor: Running task 14.0 in stage 0.0 (TID 14) > 16/07/28 04:28:17 INFO Executor: Finished task 14.0 in stage 0.0 (TID 14). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 15 > 16/07/28 04:28:17 INFO Executor: Running task 15.0 in stage 0.0 (TID 15) > 16/07/28 04:28:17 INFO Executor: Finished task 15.0 in stage 0.0 (TID 15). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 16 > 16/07/28 04:28:17 INFO Executor: Running task 16.0 in stage 0.0 (TID 16) > 16/07/28 04:28:17 INFO Executor: Finished task 16.0 in stage 0.0 (TID 16). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 17 > 16/07/28 04:28:17 INFO Executor: Running task 17.0 in stage 0.0 (TID 17) > 16/07/28 04:28:17 INFO Executor: Finished task 17.0 in stage 0.0 (TID 17). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 18 > 16/07/28 04:28:17 INFO Executor: Running task 18.0 in stage 0.0 (TID 18) > 16/07/28 04:28:17 INFO Executor: Finished task 18.0 in stage 0.0 (TID 18). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 19 > 16/07/28 04:28:17 INFO Executor: Running task 19.0 in stage 0.0 (TID 19) > 16/07/28 04:28:17 INFO Executor: Finished task 19.0 in stage 0.0 (TID 19). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 20 > 16/07/28 04:28:17 INFO Executor: Running task 20.0 in stage 0.0 (TID 20) > 16/07/28 04:28:17 INFO Executor: Finished task 20.0 in stage 0.0 (TID 20). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 21 > 16/07/28 04:28:17 INFO Executor: Running task 21.0 in stage 0.0 (TID 21) > 16/07/28 04:28:17 INFO Executor: Finished task 21.0 in stage 0.0 (TID 21). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 22 > 16/07/28 04:28:17 INFO Executor: Running task 22.0 in stage 0.0 (TID 22) > 16/07/28 04:28:17 INFO Executor: Finished task 22.0 in stage 0.0 (TID 22). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 23 > 16/07/28 04:28:17 INFO Executor: Running task 23.0 in stage 0.0 (TID 23) > 16/07/28 04:28:17 INFO Executor: Finished task 23.0 in stage 0.0 (TID 23). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 24 > 16/07/28 04:28:17 INFO Executor: Running task 24.0 in stage 0.0 (TID 24) > 16/07/28 04:28:17 INFO Executor: Finished task 24.0 in stage 0.0 (TID 24). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 25 > 16/07/28 04:28:17 INFO Executor: Running task 25.0 in stage 0.0 (TID 25) > 16/07/28 04:28:17 INFO Executor: Finished task 25.0 in stage 0.0 (TID 25). > 1204 bytes result sent to driver > 16/07/28 04:28:17 INFO CoarseGrainedExecutorBackend: Got assigned task 26 > 16/07/28 04:28:17 INFO Executor: Running task 26.0 in stage 0.0 (TID 26) > 16/07/28 04:28:18 INFO Executor: Finished task 26.0 in stage 0.0 (TID 26). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 27 > 16/07/28 04:28:18 INFO Executor: Running task 27.0 in stage 0.0 (TID 27) > 16/07/28 04:28:18 INFO Executor: Finished task 27.0 in stage 0.0 (TID 27). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 28 > 16/07/28 04:28:18 INFO Executor: Running task 28.0 in stage 0.0 (TID 28) > 16/07/28 04:28:18 INFO Executor: Finished task 28.0 in stage 0.0 (TID 28). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 29 > 16/07/28 04:28:18 INFO Executor: Running task 29.0 in stage 0.0 (TID 29) > 16/07/28 04:28:18 INFO Executor: Finished task 29.0 in stage 0.0 (TID 29). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 30 > 16/07/28 04:28:18 INFO Executor: Running task 30.0 in stage 0.0 (TID 30) > 16/07/28 04:28:18 INFO Executor: Finished task 30.0 in stage 0.0 (TID 30). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 31 > 16/07/28 04:28:18 INFO Executor: Running task 31.0 in stage 0.0 (TID 31) > 16/07/28 04:28:18 INFO Executor: Finished task 31.0 in stage 0.0 (TID 31). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 32 > 16/07/28 04:28:18 INFO Executor: Running task 32.0 in stage 0.0 (TID 32) > 16/07/28 04:28:18 INFO Executor: Finished task 32.0 in stage 0.0 (TID 32). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 33 > 16/07/28 04:28:18 INFO Executor: Running task 33.0 in stage 0.0 (TID 33) > 16/07/28 04:28:18 INFO Executor: Finished task 33.0 in stage 0.0 (TID 33). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 34 > 16/07/28 04:28:18 INFO Executor: Running task 34.0 in stage 0.0 (TID 34) > 16/07/28 04:28:18 INFO Executor: Finished task 34.0 in stage 0.0 (TID 34). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 35 > 16/07/28 04:28:18 INFO Executor: Running task 35.0 in stage 0.0 (TID 35) > 16/07/28 04:28:18 INFO Executor: Finished task 35.0 in stage 0.0 (TID 35). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 36 > 16/07/28 04:28:18 INFO Executor: Running task 36.0 in stage 0.0 (TID 36) > 16/07/28 04:28:18 INFO Executor: Finished task 36.0 in stage 0.0 (TID 36). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 37 > 16/07/28 04:28:18 INFO Executor: Running task 37.0 in stage 0.0 (TID 37) > 16/07/28 04:28:18 INFO Executor: Finished task 37.0 in stage 0.0 (TID 37). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 38 > 16/07/28 04:28:18 INFO Executor: Running task 38.0 in stage 0.0 (TID 38) > 16/07/28 04:28:18 INFO Executor: Finished task 38.0 in stage 0.0 (TID 38). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 39 > 16/07/28 04:28:18 INFO Executor: Running task 39.0 in stage 0.0 (TID 39) > 16/07/28 04:28:18 INFO Executor: Finished task 39.0 in stage 0.0 (TID 39). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 40 > 16/07/28 04:28:18 INFO Executor: Running task 40.0 in stage 0.0 (TID 40) > 16/07/28 04:28:18 INFO Executor: Finished task 40.0 in stage 0.0 (TID 40). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 41 > 16/07/28 04:28:18 INFO Executor: Running task 41.0 in stage 0.0 (TID 41) > 16/07/28 04:28:18 INFO Executor: Finished task 41.0 in stage 0.0 (TID 41). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 42 > 16/07/28 04:28:18 INFO Executor: Running task 42.0 in stage 0.0 (TID 42) > 16/07/28 04:28:18 INFO Executor: Finished task 42.0 in stage 0.0 (TID 42). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 43 > 16/07/28 04:28:18 INFO Executor: Running task 43.0 in stage 0.0 (TID 43) > 16/07/28 04:28:18 INFO Executor: Finished task 43.0 in stage 0.0 (TID 43). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 44 > 16/07/28 04:28:18 INFO Executor: Running task 44.0 in stage 0.0 (TID 44) > 16/07/28 04:28:18 INFO Executor: Finished task 44.0 in stage 0.0 (TID 44). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 45 > 16/07/28 04:28:18 INFO Executor: Running task 45.0 in stage 0.0 (TID 45) > 16/07/28 04:28:18 INFO Executor: Finished task 45.0 in stage 0.0 (TID 45). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 46 > 16/07/28 04:28:18 INFO Executor: Running task 46.0 in stage 0.0 (TID 46) > 16/07/28 04:28:18 INFO Executor: Finished task 46.0 in stage 0.0 (TID 46). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 47 > 16/07/28 04:28:18 INFO Executor: Running task 47.0 in stage 0.0 (TID 47) > 16/07/28 04:28:18 INFO Executor: Finished task 47.0 in stage 0.0 (TID 47). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 48 > 16/07/28 04:28:18 INFO Executor: Running task 48.0 in stage 0.0 (TID 48) > 16/07/28 04:28:18 INFO Executor: Finished task 48.0 in stage 0.0 (TID 48). > 1204 bytes result sent to driver > 16/07/28 04:28:18 INFO CoarseGrainedExecutorBackend: Got assigned task 49 > 16/07/28 04:28:18 INFO Executor: Running task 49.0 in stage 0.0 (TID 49) > 16/07/28 04:28:19 INFO Executor: Finished task 49.0 in stage 0.0 (TID 49). > 1204 bytes result sent to driver > 16/07/28 04:28:19 INFO CoarseGrainedExecutorBackend: Got assigned task 50 > 16/07/28 04:28:19 INFO Executor: Running task 0.0 in stage 1.0 (TID 50) > 16/07/28 04:28:19 INFO MapOutputTrackerWorker: Updating epoch to 1 and > clearing cache > 16/07/28 04:28:19 INFO TorrentBroadcast: Started reading broadcast variable 1 > 16/07/28 04:28:19 INFO MemoryStore: Block broadcast_1_piece0 stored as bytes > in memory (estimated size 1588.0 B, free 6.0 KB) > 16/07/28 04:28:19 INFO TorrentBroadcast: Reading broadcast variable 1 took 73 > ms > 16/07/28 04:28:19 INFO MemoryStore: Block broadcast_1 stored as values in > memory (estimated size 2.6 KB, free 8.6 KB) > 16/07/28 04:28:19 INFO MapOutputTrackerWorker: Don't have map outputs for > shuffle 0, fetching them > 16/07/28 04:28:19 INFO MapOutputTrackerWorker: Doing the fetch; tracker > endpoint = NettyRpcEndpointRef(spark://MapOutputTracker@192.168.33.30:36179) > 16/07/28 04:28:19 INFO MapOutputTrackerWorker: Got the output locations > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Getting 2 non-empty > blocks out of 50 blocks > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 35 ms > 16/07/28 04:28:19 INFO Executor: Finished task 0.0 in stage 1.0 (TID 50). > 1336 bytes result sent to driver > 16/07/28 04:28:19 INFO CoarseGrainedExecutorBackend: Got assigned task 51 > 16/07/28 04:28:19 INFO Executor: Running task 1.0 in stage 1.0 (TID 51) > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Getting 3 non-empty > blocks out of 50 blocks > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 0 ms > 16/07/28 04:28:19 INFO Executor: Finished task 1.0 in stage 1.0 (TID 51). > 1357 bytes result sent to driver > 16/07/28 04:28:19 INFO CoarseGrainedExecutorBackend: Got assigned task 52 > 16/07/28 04:28:19 INFO Executor: Running task 2.0 in stage 1.0 (TID 52) > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Getting 3 non-empty > blocks out of 50 blocks > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 0 ms > 16/07/28 04:28:19 INFO Executor: Finished task 2.0 in stage 1.0 (TID 52). > 1365 bytes result sent to driver > 16/07/28 04:28:19 INFO CoarseGrainedExecutorBackend: Got assigned task 53 > 16/07/28 04:28:19 INFO Executor: Running task 3.0 in stage 1.0 (TID 53) > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Getting 3 non-empty > blocks out of 50 blocks > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 10 ms > 16/07/28 04:28:19 INFO Executor: Finished task 3.0 in stage 1.0 (TID 53). > 1365 bytes result sent to driver > 16/07/28 04:28:19 INFO CoarseGrainedExecutorBackend: Got assigned task 54 > 16/07/28 04:28:19 INFO Executor: Running task 4.0 in stage 1.0 (TID 54) > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Getting 3 non-empty > blocks out of 50 blocks > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 0 ms > 16/07/28 04:28:19 INFO Executor: Finished task 4.0 in stage 1.0 (TID 54). > 1365 bytes result sent to driver > 16/07/28 04:28:19 INFO CoarseGrainedExecutorBackend: Got assigned task 55 > 16/07/28 04:28:19 INFO Executor: Running task 5.0 in stage 1.0 (TID 55) > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Getting 3 non-empty > blocks out of 50 blocks > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 7 ms > 16/07/28 04:28:19 INFO Executor: Finished task 5.0 in stage 1.0 (TID 55). > 1365 bytes result sent to driver > 16/07/28 04:28:19 INFO CoarseGrainedExecutorBackend: Got assigned task 56 > 16/07/28 04:28:19 INFO Executor: Running task 6.0 in stage 1.0 (TID 56) > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Getting 3 non-empty > blocks out of 50 blocks > 16/07/28 04:28:19 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 1 ms > 16/07/28 04:28:20 INFO Executor: Finished task 6.0 in stage 1.0 (TID 56). > 1365 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 57 > 16/07/28 04:28:20 INFO Executor: Running task 7.0 in stage 1.0 (TID 57) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 3 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 7 ms > 16/07/28 04:28:20 INFO Executor: Finished task 7.0 in stage 1.0 (TID 57). > 1365 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 58 > 16/07/28 04:28:20 INFO Executor: Running task 8.0 in stage 1.0 (TID 58) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 3 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 1 ms > 16/07/28 04:28:20 INFO Executor: Finished task 8.0 in stage 1.0 (TID 58). > 1365 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 59 > 16/07/28 04:28:20 INFO Executor: Running task 9.0 in stage 1.0 (TID 59) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 3 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 0 ms > 16/07/28 04:28:20 INFO Executor: Finished task 9.0 in stage 1.0 (TID 59). > 1365 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 60 > 16/07/28 04:28:20 INFO Executor: Running task 10.0 in stage 1.0 (TID 60) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 3 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 1 ms > 16/07/28 04:28:20 INFO Executor: Finished task 10.0 in stage 1.0 (TID 60). > 1365 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 61 > 16/07/28 04:28:20 INFO Executor: Running task 11.0 in stage 1.0 (TID 61) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 2 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 7 ms > 16/07/28 04:28:20 INFO Executor: Finished task 11.0 in stage 1.0 (TID 61). > 1336 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 62 > 16/07/28 04:28:20 INFO Executor: Running task 12.0 in stage 1.0 (TID 62) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 2 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 3 ms > 16/07/28 04:28:20 INFO Executor: Finished task 12.0 in stage 1.0 (TID 62). > 1336 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 63 > 16/07/28 04:28:20 INFO Executor: Running task 13.0 in stage 1.0 (TID 63) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 2 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 0 ms > 16/07/28 04:28:20 INFO Executor: Finished task 13.0 in stage 1.0 (TID 63). > 1336 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 64 > 16/07/28 04:28:20 INFO Executor: Running task 14.0 in stage 1.0 (TID 64) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 2 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 11 ms > 16/07/28 04:28:20 INFO Executor: Finished task 14.0 in stage 1.0 (TID 64). > 1336 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 65 > 16/07/28 04:28:20 INFO Executor: Running task 15.0 in stage 1.0 (TID 65) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 2 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 0 ms > 16/07/28 04:28:20 INFO Executor: Finished task 15.0 in stage 1.0 (TID 65). > 1336 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 66 > 16/07/28 04:28:20 INFO Executor: Running task 16.0 in stage 1.0 (TID 66) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 2 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 1 ms > 16/07/28 04:28:20 INFO Executor: Finished task 16.0 in stage 1.0 (TID 66). > 1336 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 67 > 16/07/28 04:28:20 INFO Executor: Running task 17.0 in stage 1.0 (TID 67) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 2 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 0 ms > 16/07/28 04:28:20 INFO Executor: Finished task 17.0 in stage 1.0 (TID 67). > 1336 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 68 > 16/07/28 04:28:20 INFO Executor: Running task 18.0 in stage 1.0 (TID 68) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 2 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 1 ms > 16/07/28 04:28:20 INFO Executor: Finished task 18.0 in stage 1.0 (TID 68). > 1336 bytes result sent to driver > 16/07/28 04:28:20 INFO CoarseGrainedExecutorBackend: Got assigned task 69 > 16/07/28 04:28:20 INFO Executor: Running task 19.0 in stage 1.0 (TID 69) > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Getting 2 non-empty > blocks out of 50 blocks > 16/07/28 04:28:20 INFO ShuffleBlockFetcherIterator: Started 0 remote fetches > in 0 ms > 16/07/28 04:28:20 INFO Executor: Finished task 19.0 in stage 1.0 (TID 69). > 1336 bytes result sent to driver > 16/07/28 04:28:21 INFO CoarseGrainedExecutorBackend: Got assigned task 70 > 16/07/28 04:28:21 INFO Executor: Running task 0.0 in stage 2.0 (TID 70) > 16/07/28 04:28:21 INFO TorrentBroadcast: Started reading broadcast variable 2 > 16/07/28 04:28:21 INFO MemoryStore: Block broadcast_2_piece0 stored as bytes > in memory (estimated size 20.3 KB, free 28.8 KB) > 16/07/28 04:28:21 INFO TorrentBroadcast: Reading broadcast variable 2 took 52 > ms > 16/07/28 04:28:21 INFO MemoryStore: Block broadcast_2 stored as values in > memory (estimated size 60.9 KB, free 89.8 KB) > 16/07/28 04:28:21 INFO RecurringTimer: Started timer for BlockGenerator at > time 1469680101800 > 16/07/28 04:28:21 INFO BlockGenerator: Started BlockGenerator > 16/07/28 04:28:21 INFO BlockGenerator: Started block pushing thread > 16/07/28 04:28:21 INFO ReceiverSupervisorImpl: Starting receiver > 16/07/28 04:28:21 INFO KafkaReceiver: Starting Kafka Consumer Stream with > group: sparkkafka > 16/07/28 04:28:21 INFO KafkaReceiver: Connecting to Zookeeper: > 192.168.33.10:2181 > 16/07/28 04:28:21 INFO VerifiableProperties: Verifying properties > 16/07/28 04:28:21 INFO VerifiableProperties: Property group.id is overridden > to sparkkafka > 16/07/28 04:28:21 INFO VerifiableProperties: Property zookeeper.connect is > overridden to 192.168.33.10:2181 > 16/07/28 04:28:21 INFO VerifiableProperties: Property > zookeeper.connection.timeout.ms is overridden to 10000 > 16/07/28 04:28:21 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], Connecting to zookeeper instance > at 192.168.33.10:2181 > 16/07/28 04:28:21 INFO ZkEventThread: Starting ZkClient event thread. > 16/07/28 04:28:21 INFO ZooKeeper: Client > environment:zookeeper.version=3.4.6-1569965, built on 02/20/2014 09:09 GMT > 16/07/28 04:28:21 INFO ZooKeeper: Client environment:host.name=slave1 > 16/07/28 04:28:21 INFO ZooKeeper: Client environment:java.version=1.8.0_91 > 16/07/28 04:28:21 INFO ZooKeeper: Client environment:java.vendor=Oracle > Corporation > 16/07/28 04:28:21 INFO ZooKeeper: Client > environment:java.home=/usr/lib/jvm/java-8-oracle/jre > 16/07/28 04:28:21 INFO ZooKeeper: Client > environment:java.class.path=/home/vagrant/spark-1.6.2-bin-hadoop2.6/conf/:/home/vagrant/spark-1.6.2-bin-hadoop2.6/lib/spark-assembly-1.6.2-hadoop2.6.0.jar:/home/vagrant/spark-1.6.2-bin-hadoop2.6/lib/datanucleus-api-jdo-3.2.6.jar:/home/vagrant/spark-1.6.2-bin-hadoop2.6/lib/datanucleus-rdbms-3.2.9.jar:/home/vagrant/spark-1.6.2-bin-hadoop2.6/lib/datanucleus-core-3.2.10.jar > 16/07/28 04:28:21 INFO ZooKeeper: Client > environment:java.library.path=/usr/java/packages/lib/amd64:/usr/lib64:/lib64:/lib:/usr/lib > 16/07/28 04:28:21 INFO ZooKeeper: Client environment:java.io.tmpdir=/tmp > 16/07/28 04:28:21 INFO ZooKeeper: Client environment:java.compiler=<NA> > 16/07/28 04:28:21 INFO ZooKeeper: Client environment:os.name=Linux > 16/07/28 04:28:21 INFO ZooKeeper: Client environment:os.arch=amd64 > 16/07/28 04:28:21 INFO ZooKeeper: Client > environment:os.version=3.13.0-92-generic > 16/07/28 04:28:22 INFO ZooKeeper: Client environment:user.name=vagrant > 16/07/28 04:28:22 INFO ZooKeeper: Client environment:user.home=/home/vagrant > 16/07/28 04:28:22 INFO ZooKeeper: Client > environment:user.dir=/home/vagrant/mesos/slave1/work/slaves/8e00b1ea-3f70-428a-8125-fb0eed88aede-S0/frameworks/3b189004-daea-47a3-9ba5-dfac5143f4ab-0000/executors/0/runs/0433234f-332d-4858-9527-64558fe7fb90 > 16/07/28 04:28:22 INFO ZooKeeper: Initiating client connection, > connectString=192.168.33.10:2181 sessionTimeout=6000 > watcher=org.I0Itec.zkclient.ZkClient@23ab320 > 16/07/28 04:28:22 INFO ClientCnxn: Opening socket connection to server > 192.168.33.10/192.168.33.10:2181. Will not attempt to authenticate using SASL > (unknown error) > 16/07/28 04:28:22 INFO ClientCnxn: Socket connection established to > 192.168.33.10/192.168.33.10:2181, initiating session > 16/07/28 04:28:22 INFO ClientCnxn: Session establishment complete on server > 192.168.33.10/192.168.33.10:2181, sessionid = 0x1562fc100440006, negotiated > timeout = 6000 > 16/07/28 04:28:22 INFO ZkClient: zookeeper state changed (SyncConnected) > 16/07/28 04:28:22 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], starting auto committer every > 60000 ms > 16/07/28 04:28:22 WARN AppInfo$: Can't read Kafka version from MANIFEST.MF. > Possible cause: java.lang.NullPointerException > 16/07/28 04:28:22 INFO KafkaReceiver: Connected to 192.168.33.10:2181 > 16/07/28 04:28:22 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], begin registering consumer > sparkkafka_slave1-1469680101944-ce3f80ad in ZK > 16/07/28 04:28:22 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], end registering consumer > sparkkafka_slave1-1469680101944-ce3f80ad in ZK > 16/07/28 04:28:22 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], starting watcher executor thread > for consumer sparkkafka_slave1-1469680101944-ce3f80ad > 16/07/28 04:28:22 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], begin rebalancing consumer > sparkkafka_slave1-1469680101944-ce3f80ad try #0 > 16/07/28 04:28:22 WARN ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], no brokers found when trying to > rebalance. > 16/07/28 04:28:22 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], end rebalancing consumer > sparkkafka_slave1-1469680101944-ce3f80ad try #0 > 16/07/28 04:28:22 INFO ReceiverSupervisorImpl: Called receiver onStart > 16/07/28 04:28:22 INFO ReceiverSupervisorImpl: Waiting for receiver to be > stopped > 16/07/28 04:28:22 INFO KafkaReceiver: Starting MessageHandler. > 16/07/28 04:28:24 INFO BlockManager: Removing RDD 4 > 16/07/28 04:28:26 INFO BlockManager: Removing RDD 5 > 16/07/28 04:28:28 INFO BlockManager: Removing RDD 6 > 16/07/28 04:28:30 INFO BlockManager: Removing RDD 7 > 16/07/28 04:28:32 INFO BlockManager: Removing RDD 8 > 16/07/28 04:28:34 INFO BlockManager: Removing RDD 9 > 16/07/28 04:28:36 INFO BlockManager: Removing RDD 10 > 16/07/28 04:28:38 INFO BlockManager: Removing RDD 11 > 16/07/28 04:28:40 INFO BlockManager: Removing RDD 12 > 16/07/28 04:28:42 INFO BlockManager: Removing RDD 13 > 16/07/28 04:28:44 INFO BlockManager: Removing RDD 14 > 16/07/28 04:28:46 INFO BlockManager: Removing RDD 15 > 16/07/28 04:28:48 INFO BlockManager: Removing RDD 16 > 16/07/28 04:28:50 INFO BlockManager: Removing RDD 17 > 16/07/28 04:28:52 INFO BlockManager: Removing RDD 18 > 16/07/28 04:28:54 INFO BlockManager: Removing RDD 19 > 16/07/28 04:28:56 INFO BlockManager: Removing RDD 20 > 16/07/28 04:28:58 INFO BlockManager: Removing RDD 21 > 16/07/28 04:29:00 INFO BlockManager: Removing RDD 22 > 16/07/28 04:29:02 INFO BlockManager: Removing RDD 23 > 16/07/28 04:29:04 INFO BlockManager: Removing RDD 24 > 16/07/28 04:29:06 INFO BlockManager: Removing RDD 25 > 16/07/28 04:29:08 INFO BlockManager: Removing RDD 26 > 16/07/28 04:29:10 INFO BlockManager: Removing RDD 27 > 16/07/28 04:29:12 INFO BlockManager: Removing RDD 28 > 16/07/28 04:29:14 INFO BlockManager: Removing RDD 29 > 16/07/28 04:29:16 INFO BlockManager: Removing RDD 30 > 16/07/28 04:29:18 INFO BlockManager: Removing RDD 31 > 16/07/28 04:29:20 INFO BlockManager: Removing RDD 32 > 16/07/28 04:29:22 INFO BlockManager: Removing RDD 33 > 16/07/28 04:29:24 INFO BlockManager: Removing RDD 34 > 16/07/28 04:29:26 INFO BlockManager: Removing RDD 35 > 16/07/28 04:29:28 INFO BlockManager: Removing RDD 36 > 16/07/28 04:29:30 INFO BlockManager: Removing RDD 37 > 16/07/28 04:29:32 INFO BlockManager: Removing RDD 38 > 16/07/28 04:29:34 INFO BlockManager: Removing RDD 39 > 16/07/28 04:29:36 INFO BlockManager: Removing RDD 40 > 16/07/28 04:29:38 INFO BlockManager: Removing RDD 41 > 16/07/28 04:29:40 INFO BlockManager: Removing RDD 42 > 16/07/28 04:29:42 INFO BlockManager: Removing RDD 43 > 16/07/28 04:29:44 INFO BlockManager: Removing RDD 44 > 16/07/28 04:29:46 INFO BlockManager: Removing RDD 45 > 16/07/28 04:29:48 INFO BlockManager: Removing RDD 46 > 16/07/28 04:29:50 INFO BlockManager: Removing RDD 47 > 16/07/28 04:29:52 INFO BlockManager: Removing RDD 48 > 16/07/28 04:29:54 INFO BlockManager: Removing RDD 49 > 16/07/28 04:29:56 INFO BlockManager: Removing RDD 50 > 16/07/28 04:29:58 INFO BlockManager: Removing RDD 51 > 16/07/28 04:30:00 INFO BlockManager: Removing RDD 52 > 16/07/28 04:30:02 INFO BlockManager: Removing RDD 53 > 16/07/28 04:30:04 INFO BlockManager: Removing RDD 54 > 16/07/28 04:30:06 INFO BlockManager: Removing RDD 55 > 16/07/28 04:30:08 INFO BlockManager: Removing RDD 56 > 16/07/28 04:30:10 INFO BlockManager: Removing RDD 57 > 16/07/28 04:30:12 INFO BlockManager: Removing RDD 58 > 16/07/28 04:30:14 INFO BlockManager: Removing RDD 59 > 16/07/28 04:30:16 INFO BlockManager: Removing RDD 60 > 16/07/28 04:30:18 INFO BlockManager: Removing RDD 61 > 16/07/28 04:30:19 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], begin rebalancing consumer > sparkkafka_slave1-1469680101944-ce3f80ad try #0 > 16/07/28 04:30:19 INFO ConsumerFetcherManager: > [ConsumerFetcherManager-1469680102087] Stopping leader finder thread > 16/07/28 04:30:19 INFO ConsumerFetcherManager: > [ConsumerFetcherManager-1469680102087] Stopping all fetchers > 16/07/28 04:30:19 INFO ConsumerFetcherManager: > [ConsumerFetcherManager-1469680102087] All connections stopped > 16/07/28 04:30:19 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], Cleared all relevant queues for > this fetcher > 16/07/28 04:30:19 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], Cleared the data chunks in all > the consumer message iterators > 16/07/28 04:30:19 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], Committing all offsets after > clearing the fetcher queues > 16/07/28 04:30:19 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], Releasing partition ownership > 16/07/28 04:30:19 INFO RangeAssignor: Consumer > sparkkafka_slave1-1469680101944-ce3f80ad rebalancing the following > partitions: ArrayBuffer(0) for topic topic2 with consumers: > List(sparkkafka_slave1-1469680101944-ce3f80ad-0) > 16/07/28 04:30:19 INFO RangeAssignor: > sparkkafka_slave1-1469680101944-ce3f80ad-0 attempting to claim partition 0 > 16/07/28 04:30:19 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], > sparkkafka_slave1-1469680101944-ce3f80ad-0 successfully owned partition 0 for > topic topic2 > 16/07/28 04:30:19 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], Consumer > sparkkafka_slave1-1469680101944-ce3f80ad selected partitions : topic2:0: > fetched offset = 183: consumed offset = 183 > 16/07/28 04:30:19 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], end rebalancing consumer > sparkkafka_slave1-1469680101944-ce3f80ad try #0 > 16/07/28 04:30:19 INFO ConsumerFetcherManager$LeaderFinderThread: > [sparkkafka_slave1-1469680101944-ce3f80ad-leader-finder-thread], Starting > 16/07/28 04:30:19 INFO VerifiableProperties: Verifying properties > 16/07/28 04:30:19 INFO VerifiableProperties: Property client.id is overridden > to sparkkafka > 16/07/28 04:30:19 INFO VerifiableProperties: Property metadata.broker.list is > overridden to kafka:9092 > 16/07/28 04:30:19 INFO VerifiableProperties: Property request.timeout.ms is > overridden to 30000 > 16/07/28 04:30:19 INFO ClientUtils$: Fetching metadata from broker > id:0,host:kafka,port:9092 with correlation id 0 for 1 topic(s) Set(topic2) > 16/07/28 04:30:19 INFO SyncProducer: Connected to kafka:9092 for producing > 16/07/28 04:30:19 INFO SyncProducer: Disconnecting from kafka:9092 > 16/07/28 04:30:19 INFO ConsumerFetcherManager: > [ConsumerFetcherManager-1469680102087] Added fetcher for partitions > ArrayBuffer([[topic2,0], initOffset 183 to broker id:0,host:kafka,port:9092] ) > 16/07/28 04:30:19 INFO ConsumerFetcherThread: > [ConsumerFetcherThread-sparkkafka_slave1-1469680101944-ce3f80ad-0-0], > Starting > 16/07/28 04:30:20 ERROR ConsumerFetcherThread: > [ConsumerFetcherThread-sparkkafka_slave1-1469680101944-ce3f80ad-0-0], Error > for partition [topic2,0] to broker 0:class > kafka.common.UnknownTopicOrPartitionException > 16/07/28 04:30:20 INFO BlockManager: Removing RDD 62 > 16/07/28 04:30:20 INFO VerifiableProperties: Verifying properties > 16/07/28 04:30:20 INFO VerifiableProperties: Property client.id is overridden > to sparkkafka > 16/07/28 04:30:20 INFO VerifiableProperties: Property metadata.broker.list is > overridden to kafka:9092 > 16/07/28 04:30:20 INFO VerifiableProperties: Property request.timeout.ms is > overridden to 30000 > 16/07/28 04:30:20 INFO ClientUtils$: Fetching metadata from broker > id:0,host:kafka,port:9092 with correlation id 1 for 1 topic(s) Set(topic2) > 16/07/28 04:30:20 INFO SyncProducer: Connected to kafka:9092 for producing > 16/07/28 04:30:20 INFO SyncProducer: Disconnecting from kafka:9092 > 16/07/28 04:30:20 INFO ConsumerFetcherManager: > [ConsumerFetcherManager-1469680102087] Added fetcher for partitions > ArrayBuffer([[topic2,0], initOffset 183 to broker id:0,host:kafka,port:9092] ) > 16/07/28 04:30:20 INFO MemoryStore: Block input-0-1469680220200 stored as > bytes in memory (estimated size 164.0 B, free 81.4 KB) > 16/07/28 04:30:20 WARN BlockManager: Block input-0-1469680220200 replicated > to only 0 peer(s) instead of 1 peers > 16/07/28 04:30:20 INFO BlockGenerator: Pushed block input-0-1469680220200 > 16/07/28 04:31:51 INFO MemoryStore: Block input-0-1469680311200 stored as > bytes in memory (estimated size 79.0 B, free 81.4 KB) > 16/07/28 04:31:51 WARN BlockManager: Block input-0-1469680311200 replicated > to only 0 peer(s) instead of 1 peers > 16/07/28 04:31:51 INFO BlockGenerator: Pushed block input-0-1469680311200 > 16/07/28 04:31:54 INFO MemoryStore: Block input-0-1469680313800 stored as > bytes in memory (estimated size 116.0 B, free 81.5 KB) > 16/07/28 04:31:54 WARN BlockManager: Block input-0-1469680313800 replicated > to only 0 peer(s) instead of 1 peers > 16/07/28 04:31:54 INFO BlockGenerator: Pushed block input-0-1469680313800 > 16/07/28 04:40:39 INFO ReceiverSupervisorImpl: Received stop signal > 16/07/28 04:40:39 INFO ReceiverSupervisorImpl: Stopping receiver with > message: Stopped by driver: > 16/07/28 04:40:39 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], ZKConsumerConnector shutting down > 16/07/28 04:40:39 INFO ConsumerFetcherManager: > [ConsumerFetcherManager-1469680102087] Stopping leader finder thread > 16/07/28 04:40:39 INFO ConsumerFetcherManager$LeaderFinderThread: > [sparkkafka_slave1-1469680101944-ce3f80ad-leader-finder-thread], Shutting down > 16/07/28 04:40:39 INFO ConsumerFetcherManager$LeaderFinderThread: > [sparkkafka_slave1-1469680101944-ce3f80ad-leader-finder-thread], Stopped > 16/07/28 04:40:39 INFO ConsumerFetcherManager$LeaderFinderThread: > [sparkkafka_slave1-1469680101944-ce3f80ad-leader-finder-thread], Shutdown > completed > 16/07/28 04:40:39 INFO ConsumerFetcherManager: > [ConsumerFetcherManager-1469680102087] Stopping all fetchers > 16/07/28 04:40:39 INFO ConsumerFetcherThread: > [ConsumerFetcherThread-sparkkafka_slave1-1469680101944-ce3f80ad-0-0], > Shutting down > 16/07/28 04:40:39 INFO SimpleConsumer: Reconnect due to socket error: > java.nio.channels.ClosedByInterruptException > 16/07/28 04:40:39 INFO ConsumerFetcherThread: > [ConsumerFetcherThread-sparkkafka_slave1-1469680101944-ce3f80ad-0-0], Stopped > 16/07/28 04:40:39 INFO ConsumerFetcherThread: > [ConsumerFetcherThread-sparkkafka_slave1-1469680101944-ce3f80ad-0-0], > Shutdown completed > 16/07/28 04:40:39 INFO ConsumerFetcherManager: > [ConsumerFetcherManager-1469680102087] All connections stopped > 16/07/28 04:40:39 INFO ZkEventThread: Terminate ZkClient event thread. > 16/07/28 04:40:39 INFO ZooKeeper: Session: 0x1562fc100440006 closed > 16/07/28 04:40:39 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], ZKConsumerConnector shutdown > completed in 39 ms > 16/07/28 04:40:39 INFO ReceiverSupervisorImpl: Called receiver onStop > 16/07/28 04:40:39 INFO ReceiverSupervisorImpl: Deregistering receiver 0 > 16/07/28 04:40:39 INFO ClientCnxn: EventThread shut down > 16/07/28 04:40:39 INFO ReceiverSupervisorImpl: Stopped receiver 0 > 16/07/28 04:40:39 INFO BlockGenerator: Stopping BlockGenerator > 16/07/28 04:40:39 INFO RecurringTimer: Stopped timer for BlockGenerator after > time 1469680839800 > 16/07/28 04:40:39 INFO BlockGenerator: Waiting for block pushing thread to > terminate > 16/07/28 04:40:39 INFO BlockGenerator: Pushing out the last 0 blocks > 16/07/28 04:40:39 INFO BlockGenerator: Stopped block pushing thread > 16/07/28 04:40:39 INFO BlockGenerator: Stopped BlockGenerator > 16/07/28 04:40:39 INFO ReceiverSupervisorImpl: Stopped receiver without error > 16/07/28 04:40:39 INFO Executor: Finished task 0.0 in stage 2.0 (TID 70). 912 > bytes result sent to driver > 16/07/28 04:40:39 INFO CoarseGrainedExecutorBackend: Got assigned task 71 > 16/07/28 04:40:39 INFO Executor: Running task 0.0 in stage 3.0 (TID 71) > 16/07/28 04:40:39 INFO TorrentBroadcast: Started reading broadcast variable 3 > 16/07/28 04:40:39 INFO MemoryStore: Block broadcast_3_piece0 stored as bytes > in memory (estimated size 712.0 B, free 82.2 KB) > 16/07/28 04:40:39 INFO ZookeeperConsumerConnector: > [sparkkafka_slave1-1469680101944-ce3f80ad], stopping watcher executor thread > for consumer sparkkafka_slave1-1469680101944-ce3f80ad > 16/07/28 04:40:39 INFO TorrentBroadcast: Reading broadcast variable 3 took 77 > ms > 16/07/28 04:40:39 INFO MemoryStore: Block broadcast_3 stored as values in > memory (estimated size 1040.0 B, free 83.3 KB) > 16/07/28 04:40:39 INFO BlockManager: Found block input-0-1469680220200 locally > 16/07/28 04:40:39 INFO Executor: Finished task 0.0 in stage 3.0 (TID 71). > 1068 bytes result sent to driver > 16/07/28 04:40:40 INFO CoarseGrainedExecutorBackend: Got assigned task 72 > 16/07/28 04:40:40 INFO Executor: Running task 0.0 in stage 4.0 (TID 72) > 16/07/28 04:40:40 INFO TorrentBroadcast: Started reading broadcast variable 4 > 16/07/28 04:40:40 INFO MemoryStore: Block broadcast_4_piece0 stored as bytes > in memory (estimated size 712.0 B, free 84.0 KB) > 16/07/28 04:40:40 INFO TorrentBroadcast: Reading broadcast variable 4 took 26 > ms > 16/07/28 04:40:40 INFO MemoryStore: Block broadcast_4 stored as values in > memory (estimated size 1040.0 B, free 85.0 KB) > 16/07/28 04:40:40 INFO BlockManager: Found block input-0-1469680311200 locally > 16/07/28 04:40:40 INFO Executor: Finished task 0.0 in stage 4.0 (TID 72). 983 > bytes result sent to driver > 16/07/28 04:40:40 INFO CoarseGrainedExecutorBackend: Got assigned task 73 > 16/07/28 04:40:40 INFO Executor: Running task 0.0 in stage 5.0 (TID 73) > 16/07/28 04:40:40 INFO TorrentBroadcast: Started reading broadcast variable 5 > 16/07/28 04:40:40 INFO MemoryStore: Block broadcast_5_piece0 stored as bytes > in memory (estimated size 712.0 B, free 85.7 KB) > 16/07/28 04:40:40 INFO TorrentBroadcast: Reading broadcast variable 5 took 34 > ms > 16/07/28 04:40:40 INFO MemoryStore: Block broadcast_5 stored as values in > memory (estimated size 1040.0 B, free 86.7 KB) > 16/07/28 04:40:40 INFO BlockManager: Found block input-0-1469680313800 locally > 16/07/28 04:40:40 INFO Executor: Finished task 0.0 in stage 5.0 (TID 73). > 1020 bytes result sent to driver > 16/07/28 04:40:42 INFO CoarseGrainedExecutorBackend: Driver commanded a > shutdown > I0728 04:40:42.084553 4303 exec.cpp:390] Executor asked to shutdown > 16/07/28 04:40:42 INFO MemoryStore: MemoryStore cleared > 16/07/28 04:40:42 ERROR CoarseGrainedExecutorBackend: RECEIVED SIGNAL 15: > SIGTERM > 16/07/28 04:40:42 INFO ShutdownHookManager: Shutdown hook called > 16/07/28 04:40:42 INFO ShutdownHookManager: Deleting directory > /home/vagrant/mesos/slave1/work/slaves/8e00b1ea-3f70-428a-8125-fb0eed88aede-S0/frameworks/3b189004-daea-47a3-9ba5-dfac5143f4ab-0000/executors/0/runs/0433234f-332d-4858-9527-64558fe7fb90/spark-b833a8b6-b16c-46c6-92a7-89a8f0b3f713 > 16/07/28 04:40:42 INFO BlockManager: BlockManager stopped > 16/07/28 04:40:42 WARN CoarseGrainedExecutorBackend: An unknown > (slave1:36179) driver disconnected. > 16/07/28 04:40:42 ERROR CoarseGrainedExecutorBackend: Driver > 192.168.33.30:36179 disassociated! Shutting down. > 16/07/28 04:40:42 INFO RemoteActorRefProvider$RemotingTerminator: Shutting > down remote daemon. > 16/07/28 04:40:42 INFO RemoteActorRefProvider$RemotingTerminator: Remote > daemon shut down; proceeding with flushing remote transports. > when deploy, spark hanging at method action lines.print() > Please help me, explain this issue -- This message was sent by Atlassian JIRA (v6.3.4#6332) --------------------------------------------------------------------- To unsubscribe, e-mail: issues-unsubscr...@spark.apache.org For additional commands, e-mail: issues-h...@spark.apache.org