为什么 Impala 扫描节点很慢 (RowBatchQueueGetWaitTime)？

Question

此查询 returns 大多数情况下需要 10 秒，但偶尔需要 40 秒或更长时间。

swarm中有两个executor节点，两个节点的profile没有明显区别，以下是其中一个：

      HDFS_SCAN_NODE (id=0):(Total: 39s818ms, non-child: 39s818ms, % non-child: 100.00%)
     - AverageHdfsReadThreadConcurrency: 0.07 
     - AverageScannerThreadConcurrency: 1.47 
     - BytesRead: 563.73 MB (591111366)
     - BytesReadDataNodeCache: 0
     - BytesReadLocal: 0
     - BytesReadRemoteUnexpected: 0
     - BytesReadShortCircuit: 0
     - CachedFileHandlesHitCount: 0 (0)
     - CachedFileHandlesMissCount: 560 (560)
     - CollectionItemsRead: 0 (0)
     - DecompressionTime: 1s501ms
     - MaterializeTupleTime(*): 11s685ms
     - MaxCompressedTextFileLength: 0
     - NumColumns: 9 (9)
     - NumDictFilteredRowGroups: 0 (0)
     - NumDisksAccessed: 1 (1)
     - NumRowGroups: 56 (56)
     - NumScannerThreadMemUnavailable: 0 (0)
     - NumScannerThreadReservationsDenied: 0 (0)
     - NumScannerThreadsStarted: 4 (4)
     - NumScannersWithNoReads: 0 (0)
     - NumStatsFilteredRowGroups: 0 (0)
     - PeakMemoryUsage: 142.10 MB (149004861)
     - PeakScannerThreadConcurrency: 2 (2)
     - PerReadThreadRawHdfsThroughput: 151.39 MB/sec
     - RemoteScanRanges: 1.68K (1680)
     - RowBatchBytesEnqueued: 2.32 GB (2491334455)
     - RowBatchQueueGetWaitTime: 39s786ms
     - RowBatchQueuePeakMemoryUsage: 1.87 MB (1959936)
     - RowBatchQueuePutWaitTime: 0.000ns
     - RowBatchesEnqueued: 6.38K (6377)
     - RowsRead: 73.99M (73994828)
     - RowsReturned: 6.40M (6401849)
     - RowsReturnedRate: 161.27 K/sec
     - ScanRangesComplete: 56 (56)
     - ScannerThreadsInvoluntaryContextSwitches: 99 (99)
     - ScannerThreadsTotalWallClockTime: 1m10s
       - ScannerThreadsSysTime: 630.808ms
       - ScannerThreadsUserTime: 12s824ms
     - ScannerThreadsVoluntaryContextSwitches: 1.25K (1248)
     - TotalRawHdfsOpenFileTime(*): 9s396ms
     - TotalRawHdfsReadTime(*): 3s789ms
     - TotalReadThroughput: 11.70 MB/sec
    Buffer pool:
       - AllocTime: 1.240ms
       - CumulativeAllocationBytes: 706.32 MB (740630528)
       - CumulativeAllocations: 578 (578)
       - PeakReservation: 140.00 MB (146800640)
       - PeakUnpinnedBytes: 0
       - PeakUsedReservation: 33.83 MB (35471360)
       - ReadIoBytes: 0
       - ReadIoOps: 0 (0)
       - ReadIoWaitTime: 0.000ns
       - WriteIoBytes: 0
       - WriteIoOps: 0 (0)
       - WriteIoWaitTime: 0.000ns

我们可以注意到 RowBatchQueueGetWaitTime 非常高，将近 40 秒，但我无法弄清楚为什么，承认 TotalRawHdfsOpenFileTime 需要 9 秒而 TotalRawHdfsReadTime 需要将近 4 秒，我仍然无法解释其他 27 秒花在了哪里。

你能提出可能的问题吗？我该如何解决？

Answer 1

ScannerThreadsVoluntaryContextSwitches: 1.25K (1248) 表示有 1248 种情况是扫描线程“卡住”等待某些外部资源，随后进入睡眠状态（）。该资源很可能是磁盘 IO。这可以解释相当低的平均阅读速度（TotalReadThroughput: *11.70 MB*/sec）而具有“正常”per-read吞吐量（PerReadThreadRawHdfsThroughput: 151.39 MB/sec）。

编辑

要提高性能，您可能想尝试：

启用 short circuit reads (dfs.client.read.shortcircuit=true)
配置 HDFS 缓存和 alter Impala table to use cache

（请注意，如果您运行 Impala 针对 HDFS 而不是某种对象存储，则两者都适用。）

Answer 2

扫描节点中的线程模型非常复杂，因为有两层工作线程用于扫描和 I/O - 我将它们称为扫描器和 I/O 线程。我将自上而下指出一些潜在的瓶颈以及如何识别它们。

高 RowBatchQueueGetWaitTime 表示消耗扫描的主线程花费大量时间等待扫描器线程生成行。差异的一个主要来源可能是扫描器线程的数量——如果系统处于资源压力之下，则每个查询可以获得更少的线程。因此，请密切关注 AverageScannerThreadConcurrency 以了解它是否有所不同。

扫描器线程会花时间做各种各样的事情。大部分时间一般是

不是运行因为操作系统安排了不同的线程。
正在等待 I/O 个线程从存储系统读取数据
解码数据，评估谓词，其他工作

对于 #1，您会看到 ScannerThreadsInvoluntaryContextSwitches 的值更高，并且 ScannerThreadsUserTime/ScannerThreadsSysTime 比 ScannerThreadsTotalWallClockTime 低得多。如果 ScannerThreadsUserTime 远低于 MaterializeTupleTime，那将是另一个症状。

对于 #2，您会看到较高的 ScannerThreadsUserTime 和 MaterializeTupleTime。看起来这里有大量 CPU 时间用于此，但不是大部分时间。

为了确定#3，我建议查看片段配置文件中的 TotalStorageWaitTime，以了解线程实际花费了多少时间等待 I/O。我还在最近的 Impala 版本中添加了 ScannerIoWaitTime，这更方便，因为它在扫描仪配置文件中。

如果存储等待时间很慢，有几点需要考虑

如果 TotalRawHdfsOpenFileTime 很高，则打开文件可能是一个瓶颈。这可能发生在任何存储系统上，包括 HDFS。参见
如果 TotalRawHdfsReadTime 很高，从存储系统读取可能会很慢（例如，如果数据不在 OS 缓冲区缓存中或者它是像 S3 这样的远程文件系统）
其他查询可能正在争用 I/O 资源 and/or I/O 线程

我怀疑在您的情况下，根本原因既是为此查询打开文件缓慢，又是为其他查询打开文件缓慢导致扫描程序线程被占用。启用文件句柄缓存可能会解决这个问题 - 我们已经看到通过这样做显着提高了生产部署的性能。

另一个值得一提的可能性是 built-in JVM 正在执行一些垃圾收集 - 这可能会阻止某些 HDFS 操作。我们有一些暂停检测，可以在 JVM 暂停时记录消息。您还可以查看 /memz 调试页面，我认为它有一些 GC 统计信息。或者连接其他 Java 调试工具。

为什么 Impala 扫描节点很慢 (RowBatchQueueGetWaitTime)？

Why Impala Scan Node is very slow (RowBatchQueueGetWaitTime)?

olap

hadoop

hdfs

impala