You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@spark.apache.org by "Anh Nguyen (JIRA)" <ji...@apache.org> on 2016/07/29 11:19:20 UTC
[jira] [Closed] (SPARK-16762) spark hanging when action method
print
[ https://issues.apache.org/jira/browse/SPARK-16762?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Anh Nguyen closed SPARK-16762.
------------------------------
this issue relate resoure for master and slave
> 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-unsubscribe@spark.apache.org
For additional commands, e-mail: issues-help@spark.apache.org