HDFS read slow解决方法

通过spark的UI界面,我们可以看到多个metrics的分布情况,发现有个stage的75%的duration 20s,但有少量(4个左右)特别慢,达到8min。查看worker的errlog,发现如下日志:

 Python |  copy code |? 
1
15/05/21 17:48:33 INFO FSInputChecker: read block too slow, expect:512000 cost:513232
2
15/05/21 17:48:33 WARN FMSClient: DFS Read: org.apache.hadoop.hdfs.protocol.ReadSlowException: read block too slow, expect:512000 cost:513232

可见是由于读取block数据太慢导致的,我们的block大小是256MB,期望的读取时间是512000ms,即8.5min,而最终使用了513s,与慢task耗时一致。这个值是内部HDFS版本控制的,但开源届可能也有类似功能。通过修改spark/conf/hadoop-site.xml的dfs.client.slow.read.limit配置,调整为5242880,代表期望的下载速度是5MB,如果比这个速度慢就retry其他DataNode节点。调整后,max task duration变为1.3min。在max对应的worker上也看到了slow log,只不过超时时间变短了。

当然,也可能也意味着我们的HDFS集群中有部分慢节点,后续也得解决掉。

平均Duration过大的解决方法

Duration metric里,又发现有一个task,其75%的耗时9min+,GC时间最多2s,每个task处理2.2GB的数据。在不优化内部处理流程的情况下,能否通过增大并发度来提高task处理速度呢?

由于该task由join操作生成,修改其numPartition参数从1k变到2k。但由于driver运行在一个虚拟机上,期间多次发生worker node与其通信失败,导致task反而变慢,并引发retry重算!将该值该为1500,由于每个task处理数据变成1.5GB左右,故处理时间也下降了!

另,从pstats数据也可以看到,最耗时的操作还是shuffle的read过程。

 Python |  copy code |? 
01
   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
02
 62603140 388783.337    0.006 388783.337    0.006 {method 'read' of 'file' objects}
03
 31301070 21929.022    0.001 21929.022    0.001 {cPickle.loads}
04
 16958730 8177.087    0.000 8177.087    0.000 {_basic_image_lib.flash_decode}
05
 55610843 1719.077    0.000 1810.741    0.000 feature_murmur_sign.py:33(run)
06
 55610843 1088.828    0.000 10036.427    0.000 feature_flash_decoder.py:37(run)
07
     1000  664.456    0.664 17152.500   17.152 shuffle.py:245(mergeValues)
08
 55611841  482.160    0.000  482.160    0.000 encoder.py:206(iterencode)
09
 55610843  385.117    0.000 14211.060    0.000 callbacks.py:65(add_media_info)
10
     1000  361.858    0.362 411390.715  411.391 shuffle.py:282(mergeCombiners)
11
 55611841  246.357    0.000 1453.533    0.000 data.py:374(desc)
12
 55610843  234.460    0.000  520.973    0.000 policy_beidou_black_image.py:20(run)
13
 55610843  232.927    0.000 12084.700    0.000 review_policy.py:250(run)
14
 55610843  219.946    0.000 1593.674    0.000 review_policy.py:114(run)
15
 55610843  201.820    0.000  284.889    0.000 review_policy.py:168(_lack_image)
16
 49136554  189.099    0.000  222.585    0.000 join.py:56(dispatch)
17
 31300074  184.696    0.000 410952.765    0.013 serializers.py:127(load_stream)
18
 55431498  182.844    0.000  254.908    0.000 policy_reject_url_and_bin.py:20(run)
19
 55611841  180.865    0.000  778.554    0.000 encoder.py:180(encode)
20
   272005  157.849    0.001  157.860    0.001 {cPickle.dumps}
21
 16958894  145.608    0.000  351.860    0.000 basic_image_lib.py:183(__init__)
22
 55610843  139.166    0.000  590.473    0.000 review_policy.py:149(run)
23
221930724  138.625    0.000  210.047    0.000 {hasattr}
24
476047721  125.609    0.000  125.609    0.000 data.py:49(image)
25
287337626  124.806    0.000  223.212    0.000 {len}
26
 55610843  111.992    0.000  157.770    0.000 review_policy.py:185(_lack_flash)
27
 31300074  107.931    0.000 410768.069    0.013 serializers.py:144(_read_with_length)

Leave a Reply