[ 
https://issues.apache.org/jira/browse/SPARK-16762?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Sean Owen resolved SPARK-16762.
-------------------------------
    Resolution: Invalid

Yeah, too many possible things wrong; it should be narrowed down separately 
first, possibly discussed on user@. If there's a fairly isolateable issue here, 
we can reopen.

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



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscr...@spark.apache.org
For additional commands, e-mail: issues-h...@spark.apache.org

Reply via email to