Hive外表相同sql偶尔查询缓慢

【详述】
相同的sql查询hive外表,偶尔查询很慢需要几十秒,但是马上再查就又很快;
复现后发现是个别 Scan 慢(__MAX_OF_ScanTime大),看日志有个别文件读的慢,但是文件size不大几十kb且对应datanode看起来压力也不大;所以不确定是读 hdfs 慢还是解析慢(__MAX_OF_ReaderInitFooterRead这个时间比较长)。辛苦帮解答下是 hdfs 的问题还是解析 parquet 文件慢


【背景】做过哪些操作?
【业务影响】
【StarRocks版本】2.4.4
【集群规模】例如:3fe + 5be
【机器信息】CPU虚拟核/内存/网卡,例如:48C/64G/万兆
【联系方式】haibo-self@163.com
【附件】
附上1个sql的2个profile,第一个是跑的慢的,第二个是正常跑的;可以看到主要是 scanTime 的差异
slowB_1.txt (126.0 KB)
slowB_2.txt (132.8 KB)

观察到的现象是,某个表比如要读 20 个 hdfs 文件,看 be info日志:前 19 个都马上有 ‘open file success’ 的日志了,最后一个文件过了几十秒才有 ‘open file success’ 这个日志

求帮看 @jingdan

看起来最后一个文件拖慢了整个进度,和倒数第二个文件的差值 30s 也和 profile 中的 ScanTime 对的上。但是最后这个文件并不大,

应该是从 datanode 读数慢。

准备使用 HDFS Hedged Read 这个机制来解决

您好,请问每次慢的文件固定吗?您推断的从datanode读数慢是因为观察到对应的datanode压力比较大吗?其它读的很快的文件和慢的文件存储在同一个namenode上面吗?

每次慢的文件不固定;现象是:每天早上 7 - 10 这个时间范围内随机会出现某些hive外表 sql 查询缓慢,经过仔细排查后,发现这些 case 都是某个 hdfs 文件读取非常慢拖慢了整个查询进度,进一步定位后发现是因为该文件某个副本所在的 datanode 系统负载高、cpu压力大,所以合理猜测是因为 datanode 压力大导致的问题。

在同一个 namenode 上,看namenode日志,读的慢的那个文件的 open 请求 namenode 是很快收到的;所以推测是后续从datanode 读文件慢导致;根据猜测观察datanode负载,负载很高。所以得出这个结论

已使用 HDFS Hedged Read 机制解决。配置如下

    <property>
      <name>dfs.client.hedged.read.threadpool.size</name>
      <value>48</value>
    </property>

    <property>
      <name>dfs.client.hedged.read.threshold.millis</name>
      <value>2000</value>
    </property>
2赞

这种一般都是hdfs压力大导致读取元数据慢,延时高造成的

是的,仔细研究了下;就是因为 hdfs 读的那个副本所在的 datanode 压力比较大导致虽然数据文件不大但是scan很慢比如 5kb 用了 7s。而且看 hdfs scan parquet 的时候分 2 步:第一步会读 footer,第二步会读内容。因为2次读取都是同一个 hdfs client,导致2次都走到了datanode慢节点,结果就是如前所述慢了 7s *2 = 14s,导致更慢。看了下3个副本所在datanode 同时压力大的情况比较少,所以用 Hedged read 这个机制让 hdfs 读到 datanode 慢节点时取别的副本就比较好的解决这问题了。

1赞