05-22-2018 11:05 AM
Can anyone explain whatis RowBatchQueueGetWaitTime?
I'm looking into a slow-ish query that is taking 2 to 3 seconds to do hdfs scan on most nodes and I don't see why it should take that long: 3 or so files per node only a couple K each, cached (and confirmed all read from cache). The only thing that looks odd is this metric.
Here's a sample relevant profile fragment (about same for all executors):
>>> HDFS_SCAN_NODE (id=0) (1.96s) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 18:1/69.15 KB 20:2/142.83 KB ExecOption: PARQUET Codegen Enabled, Codegen enabled: 3 out of 3 Runtime filters: Not all filters arrived (arrived: , missing ), waited for 352ms Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0% 7:0% 8:0% 9:0% 10:0% 11:0% 12:0% 13:0% 14:0% 15:0% File Formats: PARQUET/SNAPPY:156 AverageHdfsReadThreadConcurrency: 0.00 AverageScannerThreadConcurrency: 1.00 BytesRead: 228.0 KiB BytesReadDataNodeCache: 228.0 KiB BytesReadLocal: 228.0 KiB BytesReadRemoteUnexpected: 0 B BytesReadShortCircuit: 228.0 KiB CachedFileHandle**bleep**Count: 0 CachedFileHandlesMissCount: 159 DecompressionTime: 188.47us InactiveTotalTime: 0ns MaxCompressedTextFileLength: 0 B NumColumns: 52 NumDictFilteredRowGroups: 0 NumDisksAccessed: 0 NumRowGroups: 3 NumScannerThreadsStarted: 1 NumScannersWithNoReads: 0 NumStatsFilteredRowGroups: 0 PeakMemoryUsage: 499.3 KiB PerReadThreadRawHdfsThroughput: 0 B/s RemoteScanRanges: 0 RowBatchQueueGetWaitTime: 1.60s RowBatchQueuePutWaitTime: 0ns RowsRead: 426 RowsReturned: 2 RowsReturnedRate: 1 per second ScanRangesComplete: 3 ScannerThreadsInvoluntaryContextSwitches: 8 ScannerThreadsTotalWallClockTime: 1.89s MaterializeTupleTime(*): 16ms ScannerThreadsSysTime: 10ms ScannerThreadsUserTime: 73ms ScannerThreadsVoluntaryContextSwitches: 393 TotalRawHdfsReadTime(*): 0ns TotalReadThroughput: 88.4 KiB/s TotalTime: 1.96s >>> Filter 0 (1.00 MB) (0ns) InactiveTotalTime: 0ns Rows processed: 0 Rows rejected: 0 Rows total: 426 TotalTime: 0ns >>> Filter 1 (1.00 MB) (0ns) InactiveTotalTime: 0ns Rows processed: 426 Rows rejected: 424 Rows total: 426 TotalTime: 0ns
Thanks in advance!
03-24-2019 09:57 AM
Impala scanners internally have a RowBatch queue that allows Impala to decouple I/O from CPU processing. The I/O threads read data into RowBatches and put them into a queue, CPU threads asynchronously fetch data from the queue and process them. RowBatchQueueGetWaitTime is the amount of time CPU threads wait on data to arrive into the queue. Essentially, it means the CPU threads were waiting a long time for the I/O threads to read the data.