[
https://issues.apache.org/jira/browse/SPARK-16762?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15397516#comment-15397516
]
Cody Koeninger commented on SPARK-16762:
----------------------------------------
Couple things
- probably better to bring this kind of request for help up on mailing list
first
- make sure you have enough executors to run all receivers plus left over for
doing work
- there's an error about unknown topic, double check your topic
- use collect or foreachRDD(_.foreach(println)) instead of print
> 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://[email protected]: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://[email protected]: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: [email protected]
For additional commands, e-mail: [email protected]
