using kafka consumer, 2 mins batch, tasks process take 2 ~ 5 seconds in
general, but a part of tasks take more than 40 seconds. I guess
*CachedKafkaConsumer#poll* could be problem.

private def poll(timeout: Long): Unit = {
    val p = consumer.poll(timeout)
    val r = p.records(topicPartition)
    logDebug(s"Polled ${p.partitions()}  ${r.size}")
    buffer = r.iterator
}

make changes on that method. add time consuming log

private def poll(timeout: Long): Unit = {
    val start = System.currentTimeMillis()
    val p = consumer.poll(timeout)
    val end = System.currentTimeMillis()
    val r = p.records(topicPartition)
    logInfo(s"Polled ${p.partitions()}  ${r.size} cost ${end-start}" +
      s" ${System.currentTimeMillis() - end} timeout setting ${timeout}")
    buffer = r.iterator
}

task log below:
19/08/15 16:46:00 INFO executor.CoarseGrainedExecutorBackend: Got assigned
task 124
19/08/15 16:46:00 INFO executor.Executor: Running task 3.0 in stage 10.0
(TID 124)
19/08/15 16:46:00 INFO broadcast.TorrentBroadcast: Started reading broadcast
variable 10
19/08/15 16:46:00 INFO memory.MemoryStore: Block broadcast_10_piece0 stored
as bytes in memory (estimated size 2.1 KB, free 366.2 MB)
19/08/15 16:46:00 INFO broadcast.TorrentBroadcast: Reading broadcast
variable 10 took 10 ms
19/08/15 16:46:00 INFO memory.MemoryStore: Block broadcast_10 stored as
values in memory (estimated size 3.6 KB, free 366.2 MB)
19/08/15 16:46:00 INFO kafka010.KafkaRDD: Computing topic test_topic,
partition 9 offsets 4382382407 -> 4382457892
*19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
705 cost 40050 0 timeout setting 120000
*19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
691 cost 26 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
725 cost 16 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
714 cost 16 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
721 cost 17 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
709 cost 13 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
719 cost 16 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
734 cost 17 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
728 cost 17 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
724 cost 17 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
719 cost 17 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
738 cost 12 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
709 cost 16 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
701 cost 18 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
718 cost 16 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
734 cost 16 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
702 cost 17 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
717 cost 16 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
711 cost 17 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
715 cost 33 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
726 cost 11 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
713 cost 16 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
697 cost 16 0 timeout setting 120000
19/08/15 16:46:40 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
719 cost 22 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
750 cost 13 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
707 cost 11 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
743 cost 13 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
746 cost 12 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
737 cost 11 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
715 cost 17 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
725 cost 16 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
712 cost 17 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
703 cost 13 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
722 cost 12 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
709 cost 18 1 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
709 cost 19 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
702 cost 19 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
734 cost 15 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
716 cost 17 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
716 cost 18 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
716 cost 12 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
710 cost 17 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
737 cost 12 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
728 cost 13 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
710 cost 15 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
710 cost 15 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
713 cost 15 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
738 cost 16 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
722 cost 17 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
734 cost 16 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
729 cost 14 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
733 cost 15 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
727 cost 17 0 timeout setting 120000
19/08/15 16:46:41 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
734 cost 16 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
723 cost 17 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
735 cost 13 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
729 cost 23 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
718 cost 11 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
720 cost 13 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
729 cost 43 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
746 cost 13 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
742 cost 17 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
716 cost 16 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
730 cost 17 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
713 cost 16 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
724 cost 17 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
710 cost 17 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
706 cost 17 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
703 cost 16 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
734 cost 17 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
729 cost 41 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
711 cost 16 0 timeout setting 120000
19/08/15 16:46:42 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
720 cost 19 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
717 cost 366 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
722 cost 23 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
706 cost 16 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
717 cost 17 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
703 cost 22 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
708 cost 14 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
706 cost 20 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
715 cost 13 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
705 cost 11 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
719 cost 12 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
747 cost 12 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
742 cost 17 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
743 cost 35 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
717 cost 13 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
729 cost 22 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
724 cost 12 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
731 cost 17 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
736 cost 17 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
716 cost 20 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
698 cost 11 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
717 cost 12 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
751 cost 10 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
735 cost 12 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
690 cost 13 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
715 cost 12 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
723 cost 13 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
720 cost 11 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
713 cost 12 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
735 cost 11 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
727 cost 13 0 timeout setting 120000
19/08/15 16:46:43 INFO kafka010.CachedKafkaConsumer: Polled [test_topic-9] 
721 cost 12 0 timeout setting 120000
19/08/15 16:46:43 INFO executor.Executor: Finished task 3.0 in stage 10.0
(TID 124). 1813 bytes result sent to driver
19/08/15 16:46:46 INFO storage.BlockManager: Removing RDD 9

seems /consumer.poll(timeout)/ takes too long when first poll in task

Version information:
spark 2.11
kafka 0.10.0.1



--
Sent from: http://apache-spark-user-list.1001560.n3.nabble.com/

---------------------------------------------------------------------
To unsubscribe e-mail: user-unsubscr...@spark.apache.org

Reply via email to