Created on 06-24-2016 11:06 AM - edited 09-16-2022 03:27 AM
I have a table with 15 million rows. I partitioned it differently to see the impact of running a big query.
Track A: Partitioned the table in 47 partitions and the query executed on partitions=13/47 files=13 size=97.34MB
Track B: Partitioned the table in 158 partitions (finer partitions) and the query executed on partitions = 13/158 files=13 size=51.44MB
However the response time on Track B is always poorer than Track A even though the size of files considered in Track B is smaller. I am pasting the profiles below for Track A and Track B, can someone point out the cause for slower response time in Track B?
Track A
Estimated Per-Host Requirements: Memory=3.09GB VCores=2 WRITE TO HDFS [table2, OVERWRITE=false] | partitions=1 | hosts=5 per-host-mem=1.00GB | 02:HASH JOIN [INNER JOIN, BROADCAST] | hash predicates: | other predicates: | hosts=5 per-host-mem=2.00GB | tuple-ids=0,1 row-size=304B cardinality=unavailable | |--03:EXCHANGE [BROADCAST] | | hosts=2 per-host-mem=0B | | tuple-ids=1 row-size=138B cardinality=unavailable | | | 01:SCAN HDFS | partitions=1/1 files=2 size=10.12KB | table stats: unavailable | column stats: unavailable | hosts=2 per-host-mem=96.00MB | tuple-ids=1 row-size=138B cardinality=unavailable | 00:SCAN HDFS [] partitions=13/47 files=13 size=97.34MB predicates: table stats: 15919755 rows total column stats: all hosts=5 per-host-mem=96.00MB tuple-ids=0 row-size=166B cardinality=546801 ---------------- Estimated Per-Host Mem: 3321888768 Estimated Per-Host VCores: 2 Tables Missing Stats: Request Pool: default-pool ExecSummary: Operator #Hosts Avg Time Max Time #Rows Est. #Rows Peak Mem Est. Peak Mem Detail --------------------------------------------------------------------------------------------------------------------------- 02:HASH JOIN 5 1m34s 1m54s 5.01M -1 2.68 MB 2.00 GB INNER JOIN, BROADCAST |--03:EXCHANGE 5 0.000ns 0.000ns 1.00K -1 0 0 BROADCAST | 01:SCAN HDFS 2 14.000ms 16.000ms 1.00K -1 245.00 KB 96.00 MB 00:SCAN HDFS 5 96.001ms 136.003ms 5.18M 546.80K 19.80 MB 96.00 MB Planner Timeline: 49.051ms - Analysis finished: 33.663ms (33.663ms) - Equivalence classes computed: 33.914ms (251.198us) - Single node plan created: 41.605ms (7.690ms) - Runtime filters computed: 41.754ms (149.537us) - Distributed plan created: 43.040ms (1.285ms) - Lineage info computed: 45.001ms (1.961ms) - Planning finished: 49.051ms (4.050ms) Query Timeline: 1m56s - Start execution: 0.000ns (0.000ns) - Planning finished: 56.000ms (56.000ms) - Ready to start 7 remote fragments: 84.000ms (28.000ms) - All 7 remote fragments started: 88.000ms (4.000ms) - DML data written: 1m55s (1m55s) - DML Metastore update finished: 1m56s (92.000ms) - Rows available: 1m56s (0.000ns) - First row fetched: 1m56s (204.001ms) - Unregister query: 1m56s (0.000ns) ImpalaServer: - CatalogOpExecTimer: 28.000ms - ClientFetchWaitTimer: 204.001ms - MetastoreUpdateTimer: 92.000ms - RowMaterializationTimer: 0.000ns Execution Profile b945a90530a80b3b:642f30da7608f785:(Total: 1m55s, non-child: 0.000ns, % non-child: 0.00%) Number of filters: 1 Filter routing table: ID Src. Node Tgt. Node Targets Type Partition filter ------------------------------------------------------------ 0 2 0 5 LOCAL false Fragment start latencies: Count: 7, 25th %-ile: 1ms, 50th %-ile: 3ms, 75th %-ile: 3ms, 90th %-ile: 3ms, 95th %-ile: 3ms, 99.9th %-ile: 3ms Insert Stats: Partition: Default BytesWritten: 635.54 KB Per Column Sizes: laneid: 615.84 KB posted_date: 13.62 KB total_paid_loads: 992.00 B total_paid_rate: 2.19 KB Per Node Peak Memory Usage: host1:22000(27.28 MB) host2:22000(28.16 MB) host3:22000(31.30 MB) host4:22000(30.96 MB) host5:22000(24.55 MB) Final filter table: ID Src. Node Tgt. Node Targets Type Partition filter ------------------------------------------------------------ 0 2 0 5 LOCAL false - FiltersReceived: 0 (0) - FinalizationTimer: 8.000ms - FileDeletionTimer: 4.000ms - FileMoveTimer: 0.000ns - Overwrite/PartitionCreationTimer: 4.000ms Averaged Fragment F00:(Total: 1m34s, non-child: 0.000ns, % non-child: 0.00%) split sizes: min: 16.80 MB, max: 22.28 MB, avg: 19.47 MB, stddev: 2.21 MB completion times: min:1m6s max:1m55s mean: 1m36s stddev:17s259ms execution rates: min:170.85 KB/sec max:299.26 KB/sec mean:214.14 KB/sec stddev:44.51 KB/sec num instances: 5 - AverageThreadTokens: 2.91 - BloomFilterBytes: 2.00 MB (2097152) - PeakMemoryUsage: 26.45 MB (27735086) - PerHostPeakMemUsage: 28.45 MB (29832238) - PrepareTime: 175.202ms - RowsProduced: 1.00M (1001200) - TotalCpuTime: 4m42s - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 0.000ns - TotalStorageWaitTime: 81.601ms BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 33 (33) - BlocksRecycled: 1 (1) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 32.00 KB (32768) - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns CodeGen:(Total: 1s188ms, non-child: 1s188ms, % non-child: 100.00%) - CodegenTime: 0.000ns - CompileTime: 346.405ms - LoadTime: 0.000ns - ModuleBitcodeSize: 1.85 MB (1940340) - OptimizationTime: 701.611ms - PrepareTime: 136.802ms HdfsTableSink:(Total: 424.007ms, non-child: 424.007ms, % non-child: 100.00%) - BytesWritten: 127.11 KB (130158) - CompressTimer: 800.006us - EncodeTimer: 400.806ms - FilesCreated: 1 (1) - FinalizePartitionFileTimer: 12.800ms - HdfsWriteTimer: 1.600ms - PartitionsCreated: 1 (1) - PeakMemoryUsage: 1.45 MB (1518120) - RowsInserted: 1.00M (1001200) - TmpFileCreateTimer: 10.400ms HASH_JOIN_NODE (id=2):(Total: 1m34s, non-child: 1m34s, % non-child: 99.90%) - BuildPartitionTime: 0.000ns - BuildRows: 1.00K (1000) - BuildRowsPartitioned: 1.00K (1000) - BuildTime: 800.005us - GetNewBlockTime: 0.000ns - HashBuckets: 2.05K (2048) - HashCollisions: 0 (0) - LargestPartitionPercent: 100 (100) - MaxPartitionLevel: 0 (0) - NumRepartitions: 0 (0) - PartitionsCreated: 16 (16) - PeakMemoryUsage: 2.68 MB (2809832) - PinTime: 0.000ns - ProbeRows: 1.04M (1036057) - ProbeRowsPartitioned: 0 (0) - ProbeTime: 1m34s - RowsReturned: 1.00M (1001200) - RowsReturnedRate: 10.74 K/sec - SpilledPartitions: 0 (0) - UnpinTime: 0.000ns EXCHANGE_NODE (id=3): - BytesReceived: 53.04 KB (54315) - ConvertRowBatchTime: 0.000ns - DeserializeRowBatchTimer: 0.000ns - FirstBatchArrivalWaitTime: 0.000ns - PeakMemoryUsage: 0 - RowsReturned: 1.00K (1000) - RowsReturnedRate: 0 - SendersBlockedTimer: 0.000ns - SendersBlockedTotalTimer(*): 0.000ns HDFS_SCAN_NODE (id=0):(Total: 96.001ms, non-child: 96.001ms, % non-child: 100.00%) - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 1.93 - BytesRead: 6.31 MB (6618566) - BytesReadDataNodeCache: 0 - BytesReadLocal: 6.31 MB (6618566) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 6.31 MB (6618566) - DecompressionTime: 12.800ms - MaxCompressedTextFileLength: 0 - NumColumns: 15 (15) - NumDisksAccessed: 1 (1) - NumRowGroups: 2 (2) - NumScannerThreadsStarted: 2 (2) - PeakMemoryUsage: 17.46 MB (18312745) - PerReadThreadRawHdfsThroughput: 527.02 MB/sec - RemoteScanRanges: 0 (0) - RowsRead: 1.09M (1093602) - RowsReturned: 1.04M (1036057) - RowsReturnedRate: 11.70 M/sec - ScanRangesComplete: 2 (2) - ScannerThreadsInvoluntaryContextSwitches: 1.36K (1363) - ScannerThreadsTotalWallClockTime: 3m6s - MaterializeTupleTime(*): 3m5s - ScannerThreadsSysTime: 20.299ms - ScannerThreadsUserTime: 2s434ms - ScannerThreadsVoluntaryContextSwitches: 1.03K (1031) - TotalRawHdfsReadTime(*): 18.400ms - TotalReadThroughput: 69.77 KB/sec Filter 0: - Rows processed: 42.59K (42595) - Rows rejected: 0 (0) - Rows total: 42.60K (42598) Averaged Fragment F01:(Total: 162.002ms, non-child: 148.002ms, % non-child: 91.36%) split sizes: min: 4.92 KB, max: 5.21 KB, avg: 5.06 KB, stddev: 148.00 B completion times: min:164.001ms max:164.001ms mean: 164.001ms stddev:0.000ns execution rates: min:29.97 KB/sec max:31.74 KB/sec mean:30.86 KB/sec stddev:901.58 B/sec num instances: 2 - AverageThreadTokens: 0.50 - BloomFilterBytes: 0 - PeakMemoryUsage: 257.18 KB (263352) - PerHostPeakMemUsage: 257.18 KB (263352) - PrepareTime: 0.000ns - RowsProduced: 500 (500) - TotalCpuTime: 20.000ms - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 144.002ms - TotalStorageWaitTime: 12.000ms DataStreamSender (dst_id=3): - BytesSent: 132.60 KB (135787) - NetworkThroughput(*): 191.67 KB/sec - OverallThroughput: 0.00 /sec - PeakMemoryUsage: 4.18 KB (4280) - SerializeBatchTime: 0.000ns - ThriftTransmitTime(*): 692.010ms - UncompressedRowBatchSize: 429.71 KB (440020) HDFS_SCAN_NODE (id=1):(Total: 14.000ms, non-child: 14.000ms, % non-child: 100.00%) - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 0.00 - BytesRead: 8.32 KB (8517) - BytesReadDataNodeCache: 0 - BytesReadLocal: 8.32 KB (8517) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 8.32 KB (8517) - DecompressionTime: 0.000ns - MaxCompressedTextFileLength: 0 - NumColumns: 14 (14) - NumDisksAccessed: 1 (1) - NumRowGroups: 1 (1) - NumScannerThreadsStarted: 1 (1) - PeakMemoryUsage: 245.00 KB (250880) - PerReadThreadRawHdfsThroughput: 0.00 /sec - RemoteScanRanges: 0 (0) - RowsRead: 500 (500) - RowsReturned: 500 (500) - RowsReturnedRate: 36.24 K/sec - ScanRangesComplete: 1 (1) - ScannerThreadsInvoluntaryContextSwitches: 4 (4) - ScannerThreadsTotalWallClockTime: 14.000ms - MaterializeTupleTime(*): 2.000ms - ScannerThreadsSysTime: 355.000us - ScannerThreadsUserTime: 408.500us - ScannerThreadsVoluntaryContextSwitches: 9 (9) - TotalRawHdfsReadTime(*): 0.000ns - TotalReadThroughput: 0.00 /sec Fragment F00: Instance b945a90530a80b3b:642f30da7608f787 (host=host4:22000):(Total: 1m54s, non-child: 0.000ns, % non-child: 0.00%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:3/21.58 MB Filter 0 arrival: 1s271ms MemoryUsage(2s000ms): ThreadUsage(2s000ms): - AverageThreadTokens: 3.47 - BloomFilterBytes: 2.00 MB (2097152) - PeakMemoryUsage: 28.96 MB (30364408) - PerHostPeakMemUsage: 30.96 MB (32461560) - PrepareTime: 180.004ms - RowsProduced: 983.00K (983000) - TotalCpuTime: 6m43s - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 0.000ns - TotalStorageWaitTime: 96.002ms BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 33 (33) - BlocksRecycled: 1 (1) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 32.00 KB (32768) - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns CodeGen:(Total: 1s236ms, non-child: 1s236ms, % non-child: 100.00%) - CodegenTime: 0.000ns - CompileTime: 412.010ms - LoadTime: 0.000ns - ModuleBitcodeSize: 1.85 MB (1940340) - OptimizationTime: 676.016ms - PrepareTime: 144.003ms HdfsTableSink:(Total: 364.009ms, non-child: 364.009ms, % non-child: 100.00%) - BytesWritten: 125.34 KB (128352) - CompressTimer: 0.000ns - EncodeTimer: 348.008ms - FilesCreated: 1 (1) - FinalizePartitionFileTimer: 12.000ms - HdfsWriteTimer: 4.000ms - PartitionsCreated: 1 (1) - PeakMemoryUsage: 1.45 MB (1518120) - RowsInserted: 983.00K (983000) - TmpFileCreateTimer: 4.000ms HASH_JOIN_NODE (id=2):(Total: 1m54s, non-child: 1m54s, % non-child: 99.93%) ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously, Build-Side Runtime-Filter Produced - BuildPartitionTime: 0.000ns - BuildRows: 1.00K (1000) - BuildRowsPartitioned: 1.00K (1000) - BuildTime: 0.000ns - GetNewBlockTime: 0.000ns - HashBuckets: 2.05K (2048) - HashCollisions: 0 (0) - LargestPartitionPercent: 100 (100) - MaxPartitionLevel: 0 (0) - NumRepartitions: 0 (0) - PartitionsCreated: 16 (16) - PeakMemoryUsage: 2.68 MB (2809832) - PinTime: 0.000ns - ProbeRows: 1.21M (1213458) - ProbeRowsPartitioned: 0 (0) - ProbeTime: 1m54s - RowsReturned: 983.00K (983000) - RowsReturnedRate: 8.59 K/sec - SpilledPartitions: 0 (0) - UnpinTime: 0.000ns EXCHANGE_NODE (id=3): BytesReceived(2s000ms): - BytesReceived: 53.04 KB (54315) - ConvertRowBatchTime: 0.000ns - DeserializeRowBatchTimer: 0.000ns - FirstBatchArrivalWaitTime: 0.000ns - PeakMemoryUsage: 0 - RowsReturned: 1.00K (1000) - RowsReturnedRate: 0 - SendersBlockedTimer: 0.000ns - SendersBlockedTotalTimer(*): 0.000ns HDFS_SCAN_NODE (id=0):(Total: 80.002ms, non-child: 80.002ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Enabled, Codegen enabled: 0 out of 3 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:3/21.58 MB Runtime filters: All filters arrived. Waited 0 Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:45 BytesRead(2s000ms): - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 2.51 - BytesRead: 6.93 MB (7262864) - BytesReadDataNodeCache: 0 - BytesReadLocal: 6.93 MB (7262864) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 6.93 MB (7262864) - DecompressionTime: 16.000ms - MaxCompressedTextFileLength: 0 - NumColumns: 15 (15) - NumDisksAccessed: 1 (1) - NumRowGroups: 3 (3) - NumScannerThreadsStarted: 3 (3) - PeakMemoryUsage: 19.19 MB (20118152) - PerReadThreadRawHdfsThroughput: 288.59 MB/sec - RemoteScanRanges: 0 (0) - RowsRead: 1.21M (1213458) - RowsReturned: 1.21M (1213458) - RowsReturnedRate: 15.17 M/sec - ScanRangesComplete: 3 (3) - ScannerThreadsInvoluntaryContextSwitches: 1.33K (1335) - ScannerThreadsTotalWallClockTime: 4m47s - MaterializeTupleTime(*): 4m46s - ScannerThreadsSysTime: 12.312ms - ScannerThreadsUserTime: 2s646ms - ScannerThreadsVoluntaryContextSwitches: 1.19K (1185) - TotalRawHdfsReadTime(*): 24.000ms - TotalReadThroughput: 61.41 KB/sec Filter 0: - Rows processed: 49.15K (49149) - Rows rejected: 0 (0) - Rows total: 49.15K (49152) Instance b945a90530a80b3b:642f30da7608f788 (host=host3:22000):(Total: 1m47s, non-child: 0.000ns, % non-child: 0.00%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:3/22.28 MB Filter 0 arrival: 1s182ms MemoryUsage(2s000ms): ThreadUsage(2s000ms): - AverageThreadTokens: 3.51 - BloomFilterBytes: 2.00 MB (2097152) - PeakMemoryUsage: 29.30 MB (30724816) - PerHostPeakMemUsage: 31.30 MB (32821968) - PrepareTime: 164.002ms - RowsProduced: 1.14M (1136000) - TotalCpuTime: 6m19s - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 0.000ns - TotalStorageWaitTime: 132.002ms BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 33 (33) - BlocksRecycled: 1 (1) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 32.00 KB (32768) - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns CodeGen:(Total: 1s144ms, non-child: 1s144ms, % non-child: 100.00%) - CodegenTime: 0.000ns - CompileTime: 328.005ms - LoadTime: 0.000ns - ModuleBitcodeSize: 1.85 MB (1940340) - OptimizationTime: 684.011ms - PrepareTime: 128.002ms HdfsTableSink:(Total: 496.008ms, non-child: 496.008ms, % non-child: 100.00%) - BytesWritten: 143.92 KB (147377) - CompressTimer: 0.000ns - EncodeTimer: 480.008ms - FilesCreated: 1 (1) - FinalizePartitionFileTimer: 12.000ms - HdfsWriteTimer: 0.000ns - PartitionsCreated: 1 (1) - PeakMemoryUsage: 1.45 MB (1518120) - RowsInserted: 1.14M (1136000) - TmpFileCreateTimer: 4.000ms HASH_JOIN_NODE (id=2):(Total: 1m46s, non-child: 1m46s, % non-child: 99.92%) ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously, Build-Side Runtime-Filter Produced - BuildPartitionTime: 0.000ns - BuildRows: 1.00K (1000) - BuildRowsPartitioned: 1.00K (1000) - BuildTime: 0.000ns - GetNewBlockTime: 0.000ns - HashBuckets: 2.05K (2048) - HashCollisions: 0 (0) - LargestPartitionPercent: 100 (100) - MaxPartitionLevel: 0 (0) - NumRepartitions: 0 (0) - PartitionsCreated: 16 (16) - PeakMemoryUsage: 2.68 MB (2809832) - PinTime: 0.000ns - ProbeRows: 1.24M (1239384) - ProbeRowsPartitioned: 0 (0) - ProbeTime: 1m46s - RowsReturned: 1.14M (1136000) - RowsReturnedRate: 10.65 K/sec - SpilledPartitions: 0 (0) - UnpinTime: 0.000ns EXCHANGE_NODE (id=3): BytesReceived(2s000ms): - BytesReceived: 53.04 KB (54315) - ConvertRowBatchTime: 0.000ns - DeserializeRowBatchTimer: 0.000ns - FirstBatchArrivalWaitTime: 0.000ns - PeakMemoryUsage: 0 - RowsReturned: 1.00K (1000) - RowsReturnedRate: 0 - SendersBlockedTimer: 0.000ns - SendersBlockedTotalTimer(*): 0.000ns HDFS_SCAN_NODE (id=0):(Total: 84.001ms, non-child: 84.001ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Enabled, Codegen enabled: 0 out of 3 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:3/22.28 MB Runtime filters: All filters arrived. Waited 0 Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:45 BytesRead(2s000ms): - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 2.53 - BytesRead: 7.30 MB (7655951) - BytesReadDataNodeCache: 0 - BytesReadLocal: 7.30 MB (7655951) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 7.30 MB (7655951) - DecompressionTime: 20.000ms - MaxCompressedTextFileLength: 0 - NumColumns: 15 (15) - NumDisksAccessed: 1 (1) - NumRowGroups: 3 (3) - NumScannerThreadsStarted: 3 (3) - PeakMemoryUsage: 19.80 MB (20762680) - PerReadThreadRawHdfsThroughput: 304.22 MB/sec - RemoteScanRanges: 0 (0) - RowsRead: 1.24M (1239384) - RowsReturned: 1.24M (1239384) - RowsReturnedRate: 14.75 M/sec - ScanRangesComplete: 3 (3) - ScannerThreadsInvoluntaryContextSwitches: 1.02K (1019) - ScannerThreadsTotalWallClockTime: 4m31s - MaterializeTupleTime(*): 4m30s - ScannerThreadsSysTime: 32.441ms - ScannerThreadsUserTime: 2s744ms - ScannerThreadsVoluntaryContextSwitches: 1.24K (1239) - TotalRawHdfsReadTime(*): 24.000ms - TotalReadThroughput: 69.22 KB/sec Filter 0: - Rows processed: 49.15K (49149) - Rows rejected: 0 (0) - Rows total: 49.15K (49152) Instance b945a90530a80b3b:642f30da7608f786 (host=host5:22000):(Total: 1m39s, non-child: 0.000ns, % non-child: 0.00%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:2/16.80 MB Filter 0 arrival: 1s236ms MemoryUsage(2s000ms): ThreadUsage(2s000ms): - AverageThreadTokens: 1.95 - BloomFilterBytes: 2.00 MB (2097152) - PeakMemoryUsage: 22.55 MB (23640456) - PerHostPeakMemUsage: 24.55 MB (25737608) - PrepareTime: 176.004ms - RowsProduced: 1.12M (1121000) - TotalCpuTime: 3m16s - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 0.000ns - TotalStorageWaitTime: 36.000ms BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 33 (33) - BlocksRecycled: 1 (1) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 32.00 KB (32768) - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns CodeGen:(Total: 1s200ms, non-child: 1s200ms, % non-child: 100.00%) - CodegenTime: 0.000ns - CompileTime: 336.007ms - LoadTime: 0.000ns - ModuleBitcodeSize: 1.85 MB (1940340) - OptimizationTime: 724.017ms - PrepareTime: 136.003ms HdfsTableSink:(Total: 536.012ms, non-child: 536.012ms, % non-child: 100.00%) - BytesWritten: 141.32 KB (144711) - CompressTimer: 0.000ns - EncodeTimer: 508.011ms - FilesCreated: 1 (1) - FinalizePartitionFileTimer: 16.000ms - HdfsWriteTimer: 4.000ms - PartitionsCreated: 1 (1) - PeakMemoryUsage: 1.45 MB (1518120) - RowsInserted: 1.12M (1121000) - TmpFileCreateTimer: 12.000ms HASH_JOIN_NODE (id=2):(Total: 1m39s, non-child: 1m38s, % non-child: 99.86%) ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously, Build-Side Runtime-Filter Produced - BuildPartitionTime: 0.000ns - BuildRows: 1.00K (1000) - BuildRowsPartitioned: 1.00K (1000) - BuildTime: 0.000ns - GetNewBlockTime: 0.000ns - HashBuckets: 2.05K (2048) - HashCollisions: 0 (0) - LargestPartitionPercent: 100 (100) - MaxPartitionLevel: 0 (0) - NumRepartitions: 0 (0) - PartitionsCreated: 16 (16) - PeakMemoryUsage: 2.68 MB (2809832) - PinTime: 0.000ns - ProbeRows: 951.43K (951428) - ProbeRowsPartitioned: 0 (0) - ProbeTime: 1m38s - RowsReturned: 1.12M (1121000) - RowsReturnedRate: 11.31 K/sec - SpilledPartitions: 0 (0) - UnpinTime: 0.000ns EXCHANGE_NODE (id=3): BytesReceived(2s000ms): - BytesReceived: 53.04 KB (54315) - ConvertRowBatchTime: 0.000ns - DeserializeRowBatchTimer: 0.000ns - FirstBatchArrivalWaitTime: 0.000ns - PeakMemoryUsage: 0 - RowsReturned: 1.00K (1000) - RowsReturnedRate: 0 - SendersBlockedTimer: 0.000ns - SendersBlockedTotalTimer(*): 0.000ns HDFS_SCAN_NODE (id=0):(Total: 136.003ms, non-child: 136.003ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Enabled, Codegen enabled: 0 out of 2 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:2/16.80 MB Runtime filters: All filters arrived. Waited 0 Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:30 BytesRead(2s000ms): - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 0.96 - BytesRead: 5.41 MB (5674529) - BytesReadDataNodeCache: 0 - BytesReadLocal: 5.41 MB (5674529) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 5.41 MB (5674529) - DecompressionTime: 4.000ms - MaxCompressedTextFileLength: 0 - NumColumns: 15 (15) - NumDisksAccessed: 1 (1) - NumRowGroups: 2 (2) - NumScannerThreadsStarted: 1 (1) - PeakMemoryUsage: 12.94 MB (13566272) - PerReadThreadRawHdfsThroughput: 1.32 GB/sec - RemoteScanRanges: 0 (0) - RowsRead: 951.43K (951428) - RowsReturned: 951.43K (951428) - RowsReturnedRate: 7.00 M/sec - ScanRangesComplete: 2 (2) - ScannerThreadsInvoluntaryContextSwitches: 1.47K (1466) - ScannerThreadsTotalWallClockTime: 1m35s - MaterializeTupleTime(*): 1m35s - ScannerThreadsSysTime: 32.869ms - ScannerThreadsUserTime: 2s074ms - ScannerThreadsVoluntaryContextSwitches: 956 (956) - TotalRawHdfsReadTime(*): 4.000ms - TotalReadThroughput: 55.14 KB/sec Filter 0: - Rows processed: 32.77K (32766) - Rows rejected: 0 (0) - Rows total: 32.77K (32768) Instance b945a90530a80b3b:642f30da7608f789 (host=host2:22000):(Total: 1m27s, non-child: 0.000ns, % non-child: 0.00%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:2/17.24 MB Filter 0 arrival: 1s217ms MemoryUsage(2s000ms): ThreadUsage(2s000ms): - AverageThreadTokens: 2.72 - BloomFilterBytes: 2.00 MB (2097152) - PeakMemoryUsage: 26.16 MB (27433976) - PerHostPeakMemUsage: 28.16 MB (29531128) - PrepareTime: 180.001ms - RowsProduced: 1.01M (1009000) - TotalCpuTime: 4m - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 0.000ns - TotalStorageWaitTime: 36.000ms BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 33 (33) - BlocksRecycled: 1 (1) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 32.00 KB (32768) - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns CodeGen:(Total: 1s176ms, non-child: 1s176ms, % non-child: 100.00%) - CodegenTime: 0.000ns - CompileTime: 328.002ms - LoadTime: 0.000ns - ModuleBitcodeSize: 1.85 MB (1940340) - OptimizationTime: 704.004ms - PrepareTime: 140.000ms HdfsTableSink:(Total: 404.002ms, non-child: 404.002ms, % non-child: 100.00%) - BytesWritten: 127.80 KB (130863) - CompressTimer: 0.000ns - EncodeTimer: 364.002ms - FilesCreated: 1 (1) - FinalizePartitionFileTimer: 12.000ms - HdfsWriteTimer: 0.000ns - PartitionsCreated: 1 (1) - PeakMemoryUsage: 1.45 MB (1518120) - RowsInserted: 1.01M (1009000) - TmpFileCreateTimer: 28.000ms HASH_JOIN_NODE (id=2):(Total: 1m27s, non-child: 1m27s, % non-child: 99.92%) ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously, Build-Side Runtime-Filter Produced - BuildPartitionTime: 0.000ns - BuildRows: 1.00K (1000) - BuildRowsPartitioned: 1.00K (1000) - BuildTime: 4.000ms - GetNewBlockTime: 0.000ns - HashBuckets: 2.05K (2048) - HashCollisions: 0 (0) - LargestPartitionPercent: 100 (100) - MaxPartitionLevel: 0 (0) - NumRepartitions: 0 (0) - PartitionsCreated: 16 (16) - PeakMemoryUsage: 2.68 MB (2809832) - PinTime: 0.000ns - ProbeRows: 988.06K (988056) - ProbeRowsPartitioned: 0 (0) - ProbeTime: 1m26s - RowsReturned: 1.01M (1009000) - RowsReturnedRate: 11.56 K/sec - SpilledPartitions: 0 (0) - UnpinTime: 0.000ns EXCHANGE_NODE (id=3): BytesReceived(2s000ms): - BytesReceived: 53.04 KB (54315) - ConvertRowBatchTime: 0.000ns - DeserializeRowBatchTimer: 0.000ns - FirstBatchArrivalWaitTime: 0.000ns - PeakMemoryUsage: 0 - RowsReturned: 1.00K (1000) - RowsReturnedRate: 0 - SendersBlockedTimer: 0.000ns - SendersBlockedTotalTimer(*): 0.000ns HDFS_SCAN_NODE (id=0):(Total: 68.000ms, non-child: 68.000ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Enabled, Codegen enabled: 0 out of 2 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:2/17.24 MB Runtime filters: All filters arrived. Waited 0 Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:30 BytesRead(2s000ms): - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 1.74 - BytesRead: 5.54 MB (5806016) - BytesReadDataNodeCache: 0 - BytesReadLocal: 5.54 MB (5806016) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 5.54 MB (5806016) - DecompressionTime: 8.000ms - MaxCompressedTextFileLength: 0 - NumColumns: 15 (15) - NumDisksAccessed: 1 (1) - NumRowGroups: 2 (2) - NumScannerThreadsStarted: 2 (2) - PeakMemoryUsage: 16.39 MB (17181552) - PerReadThreadRawHdfsThroughput: 461.42 MB/sec - RemoteScanRanges: 0 (0) - RowsRead: 988.06K (988056) - RowsReturned: 988.06K (988056) - RowsReturnedRate: 14.53 M/sec - ScanRangesComplete: 2 (2) - ScannerThreadsInvoluntaryContextSwitches: 1.38K (1383) - ScannerThreadsTotalWallClockTime: 2m32s - MaterializeTupleTime(*): 2m31s - ScannerThreadsSysTime: 7.985ms - ScannerThreadsUserTime: 2s169ms - ScannerThreadsVoluntaryContextSwitches: 958 (958) - TotalRawHdfsReadTime(*): 12.000ms - TotalReadThroughput: 64.07 KB/sec Filter 0: - Rows processed: 32.77K (32766) - Rows rejected: 0 (0) - Rows total: 32.77K (32768) Instance b945a90530a80b3b:642f30da7608f78a (host=host1:22000):(Total: 1m5s, non-child: 0.000ns, % non-child: 0.00%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:3/19.44 MB Filter 0 arrival: 1s228ms MemoryUsage(2s000ms): ThreadUsage(2s000ms): - AverageThreadTokens: 2.89 - BloomFilterBytes: 2.00 MB (2097152) - PeakMemoryUsage: 25.28 MB (26511776) - PerHostPeakMemUsage: 27.28 MB (28608928) - PrepareTime: 176.001ms - RowsProduced: 757.00K (757000) - TotalCpuTime: 3m11s - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 0.000ns - TotalStorageWaitTime: 108.000ms BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 33 (33) - BlocksRecycled: 1 (1) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 32.00 KB (32768) - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns CodeGen:(Total: 1s188ms, non-child: 1s188ms, % non-child: 100.00%) - CodegenTime: 0.000ns - CompileTime: 328.002ms - LoadTime: 0.000ns - ModuleBitcodeSize: 1.85 MB (1940340) - OptimizationTime: 720.005ms - PrepareTime: 136.001ms HdfsTableSink:(Total: 320.002ms, non-child: 320.002ms, % non-child: 100.00%) - BytesWritten: 97.16 KB (99490) - CompressTimer: 4.000ms - EncodeTimer: 304.002ms - FilesCreated: 1 (1) - FinalizePartitionFileTimer: 12.000ms - HdfsWriteTimer: 0.000ns - PartitionsCreated: 1 (1) - PeakMemoryUsage: 1.45 MB (1518120) - RowsInserted: 757.00K (757000) - TmpFileCreateTimer: 4.000ms HASH_JOIN_NODE (id=2):(Total: 1m5s, non-child: 1m5s, % non-child: 99.83%) ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously, Build-Side Runtime-Filter Produced - BuildPartitionTime: 0.000ns - BuildRows: 1.00K (1000) - BuildRowsPartitioned: 1.00K (1000) - BuildTime: 0.000ns - GetNewBlockTime: 0.000ns - HashBuckets: 2.05K (2048) - HashCollisions: 0 (0) - LargestPartitionPercent: 100 (100) - MaxPartitionLevel: 0 (0) - NumRepartitions: 0 (0) - PartitionsCreated: 16 (16) - PeakMemoryUsage: 2.68 MB (2809832) - PinTime: 0.000ns - ProbeRows: 787.96K (787961) - ProbeRowsPartitioned: 0 (0) - ProbeTime: 1m4s - RowsReturned: 757.00K (757000) - RowsReturnedRate: 11.62 K/sec - SpilledPartitions: 0 (0) - UnpinTime: 0.000ns EXCHANGE_NODE (id=3): BytesReceived(2s000ms): - BytesReceived: 53.04 KB (54315) - ConvertRowBatchTime: 0.000ns - DeserializeRowBatchTimer: 0.000ns - FirstBatchArrivalWaitTime: 0.000ns - PeakMemoryUsage: 0 - RowsReturned: 1.00K (1000) - RowsReturnedRate: 0 - SendersBlockedTimer: 0.000ns - SendersBlockedTotalTimer(*): 0.000ns HDFS_SCAN_NODE (id=0):(Total: 112.000ms, non-child: 112.000ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Enabled, Codegen enabled: 0 out of 3 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:3/19.44 MB Runtime filters: All filters arrived. Waited 0 Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:45 BytesRead(2s000ms): - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 1.93 - BytesRead: 6.38 MB (6693470) - BytesReadDataNodeCache: 0 - BytesReadLocal: 6.38 MB (6693470) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 6.38 MB (6693470) - DecompressionTime: 16.000ms - MaxCompressedTextFileLength: 0 - NumColumns: 15 (15) - NumDisksAccessed: 1 (1) - NumRowGroups: 3 (3) - NumScannerThreadsStarted: 3 (3) - PeakMemoryUsage: 19.01 MB (19935072) - PerReadThreadRawHdfsThroughput: 227.98 MB/sec - RemoteScanRanges: 0 (0) - RowsRead: 1.08M (1075686) - RowsReturned: 787.96K (787961) - RowsReturnedRate: 7.04 M/sec - ScanRangesComplete: 3 (3) - ScannerThreadsInvoluntaryContextSwitches: 1.61K (1612) - ScannerThreadsTotalWallClockTime: 2m5s - MaterializeTupleTime(*): 2m5s - ScannerThreadsSysTime: 15.891ms - ScannerThreadsUserTime: 2s539ms - ScannerThreadsVoluntaryContextSwitches: 817 (817) - TotalRawHdfsReadTime(*): 28.000ms - TotalReadThroughput: 99.04 KB/sec Filter 0: - Rows processed: 49.15K (49149) - Rows rejected: 0 (0) - Rows total: 49.15K (49152) Fragment F01: Instance b945a90530a80b3b:642f30da7608f78c (host=host2:22000):(Total: 164.001ms, non-child: 152.001ms, % non-child: 92.68%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/4.92 KB - AverageThreadTokens: 0.00 - BloomFilterBytes: 0 - PeakMemoryUsage: 257.18 KB (263352) - PerHostPeakMemUsage: 257.18 KB (263352) - PrepareTime: 0.000ns - RowsProduced: 479 (479) - TotalCpuTime: 24.000ms - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 144.000ms - TotalStorageWaitTime: 8.000ms DataStreamSender (dst_id=3): - BytesSent: 127.16 KB (130215) - NetworkThroughput(*): 182.70 KB/sec - OverallThroughput: 0.00 /sec - PeakMemoryUsage: 4.18 KB (4280) - SerializeBatchTime: 0.000ns - ThriftTransmitTime(*): 696.004ms - UncompressedRowBatchSize: 411.66 KB (421540) HDFS_SCAN_NODE (id=1):(Total: 12.000ms, non-child: 12.000ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Disabled, Codegen enabled: 0 out of 1 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/4.92 KB Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:14 - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 0.00 - BytesRead: 8.03 KB (8221) - BytesReadDataNodeCache: 0 - BytesReadLocal: 8.03 KB (8221) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 8.03 KB (8221) - DecompressionTime: 0.000ns - MaxCompressedTextFileLength: 0 - NumColumns: 14 (14) - NumDisksAccessed: 1 (1) - NumRowGroups: 1 (1) - NumScannerThreadsStarted: 1 (1) - PeakMemoryUsage: 245.00 KB (250880) - PerReadThreadRawHdfsThroughput: 0.00 /sec - RemoteScanRanges: 0 (0) - RowsRead: 479 (479) - RowsReturned: 479 (479) - RowsReturnedRate: 39.92 K/sec - ScanRangesComplete: 1 (1) - ScannerThreadsInvoluntaryContextSwitches: 4 (4) - ScannerThreadsTotalWallClockTime: 12.000ms - MaterializeTupleTime(*): 4.000ms - ScannerThreadsSysTime: 0.000ns - ScannerThreadsUserTime: 817.000us - ScannerThreadsVoluntaryContextSwitches: 12 (12) - TotalRawHdfsReadTime(*): 0.000ns - TotalReadThroughput: 0.00 /sec Instance b945a90530a80b3b:642f30da7608f78b (host=host4:22000):(Total: 160.004ms, non-child: 144.003ms, % non-child: 90.00%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/5.21 KB MemoryUsage(500.000ms): 12.18 KB ThreadUsage(500.000ms): 1 - AverageThreadTokens: 1.00 - BloomFilterBytes: 0 - PeakMemoryUsage: 257.18 KB (263352) - PerHostPeakMemUsage: 257.18 KB (263352) - PrepareTime: 0.000ns - RowsProduced: 521 (521) - TotalCpuTime: 16.000ms - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 144.003ms - TotalStorageWaitTime: 16.000ms DataStreamSender (dst_id=3): - BytesSent: 138.05 KB (141360) - NetworkThroughput(*): 200.64 KB/sec - OverallThroughput: 0.00 /sec - PeakMemoryUsage: 4.18 KB (4280) - SerializeBatchTime: 0.000ns - ThriftTransmitTime(*): 688.017ms - UncompressedRowBatchSize: 447.75 KB (458500) HDFS_SCAN_NODE (id=1):(Total: 16.000ms, non-child: 16.000ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Disabled, Codegen enabled: 0 out of 1 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/5.21 KB Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:14 - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 0.00 - BytesRead: 8.61 KB (8813) - BytesReadDataNodeCache: 0 - BytesReadLocal: 8.61 KB (8813) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 8.61 KB (8813) - DecompressionTime: 0.000ns - MaxCompressedTextFileLength: 0 - NumColumns: 14 (14) - NumDisksAccessed: 1 (1) - NumRowGroups: 1 (1) - NumScannerThreadsStarted: 1 (1) - PeakMemoryUsage: 245.00 KB (250880) - PerReadThreadRawHdfsThroughput: 0.00 /sec - RemoteScanRanges: 0 (0) - RowsRead: 521 (521) - RowsReturned: 521 (521) - RowsReturnedRate: 32.56 K/sec - ScanRangesComplete: 1 (1) - ScannerThreadsInvoluntaryContextSwitches: 4 (4) - ScannerThreadsTotalWallClockTime: 16.000ms - MaterializeTupleTime(*): 0.000ns - ScannerThreadsSysTime: 710.000us - ScannerThreadsUserTime: 0.000ns - ScannerThreadsVoluntaryContextSwitches: 6 (6) - TotalRawHdfsReadTime(*): 0.000ns - TotalReadThroughput: 0.00 /sec
Created 06-24-2016 11:50 AM
The main difference seems to be execution skew. In the second profile the max time for the join is over 3 minutes, compared to much lower in first profile. The average time isn't very different between the profiles. Probably the partitioning resulted in the data being distributed differently between the nodes, and for some reason that one node is slower. It doesn't look like it's necessarily processing more data, but maybe the node is more heavily loaded, or the data is somehow different.
Is the join condition something complicated? It's only processing a few thousand rows per second through the join, which is very low.
Created 06-24-2016 11:08 AM
Track B
Estimated Per-Host Requirements: Memory=3.09GB VCores=2 WRITE TO HDFS [] | partitions=1 | hosts=5 per-host-mem=1.00GB | 02:HASH JOIN [INNER JOIN, BROADCAST] | hash predicates: | other predicates: | hosts=5 per-host-mem=2.00GB | tuple-ids=0,1 row-size=292B cardinality=unavailable | |--03:EXCHANGE [BROADCAST] | | hosts=2 per-host-mem=0B | | tuple-ids=1 row-size=130B cardinality=unavailable | | | 01:SCAN HDFS [] | partitions=1/1 files=2 size=10.12KB | table stats: unavailable | column stats: unavailable | hosts=2 per-host-mem=96.00MB | tuple-ids=1 row-size=130B cardinality=unavailable | 00:SCAN HDFS [] partitions=13/158 files=13 size=51.44MB predicates: table stats: 15919755 rows total column stats: all hosts=5 per-host-mem=96.00MB tuple-ids=0 row-size=162B cardinality=281237 ---------------- Estimated Per-Host Mem: 3321888768 Estimated Per-Host VCores: 2 Request Pool: default-pool ExecSummary: Operator #Hosts Avg Time Max Time #Rows Est. #Rows Peak Mem Est. Peak Mem Detail ---------------------------------------------------------------------------------------------------------------------------- 02:HASH JOIN 5 1m49s 3m2s 5.01M -1 2.67 MB 2.00 GB INNER JOIN, BROADCAST |--03:EXCHANGE 5 0.000ns 0.000ns 1.00K -1 0 0 BROADCAST | 01:SCAN HDFS 2 14.000ms 16.000ms 1.00K -1 227.00 KB 96.00 MB 00:SCAN HDFS 5 267.202ms 912.007ms 2.68M 281.24K 14.35 MB 96.00 MB Planner Timeline: 91.010ms - Analysis finished: 33.809ms (33.809ms) - Equivalence classes computed: 34.045ms (236.269us) - Single node plan created: 83.341ms (49.295ms) - Runtime filters computed: 83.502ms (161.093us) - Distributed plan created: 84.886ms (1.384ms) - Lineage info computed: 86.836ms (1.949ms) - Planning finished: 91.010ms (4.174ms) Query Timeline: 3m9s - Start execution: 0.000ns (0.000ns) - Planning finished: 96.000ms (96.000ms) - Ready to start 7 remote fragments: 144.000ms (48.000ms) - All 7 remote fragments started: 152.001ms (8.000ms) - DML data written: 3m8s (3m8s) - DML Metastore update finished: 3m8s (136.000ms) - Rows available: 3m8s (0.000ns) - First row fetched: 3m9s (744.004ms) - Unregister query: 3m9s (0.000ns) ImpalaServer: - CatalogOpExecTimer: 48.000ms - ClientFetchWaitTimer: 744.004ms - MetastoreUpdateTimer: 136.000ms - RowMaterializationTimer: 0.000ns Execution Profile 9e4c857f471ba07e:1169bc0001433c91:(Total: 3m8s, non-child: 0.000ns, % non-child: 0.00%) Number of filters: 1 Filter routing table: ID Src. Node Tgt. Node Targets Type Partition filter ------------------------------------------------------------ 0 2 0 5 LOCAL false Fragment start latencies: Count: 7, 25th %-ile: 1ms, 50th %-ile: 2ms, 75th %-ile: 2ms, 90th %-ile: 3ms, 95th %-ile: 6ms, 99.9th %-ile: 6ms Insert Stats: Partition: Default BytesWritten: 634.10 KB Per Column Sizes: laneid: 614.60 KB posted_date: 13.39 KB total_paid_loads: 1014.00 B total_paid_rate: 2.20 KB Per Node Peak Memory Usage: host3:22000(22.66 MB) host1:22000(21.40 MB) host2:22000(25.78 MB) host5:22000(22.84 MB) host4:22000(23.82 MB) Final filter table: ID Src. Node Tgt. Node Targets Type Partition filter ------------------------------------------------------------ 0 2 0 5 LOCAL false - FiltersReceived: 0 (0) - FinalizationTimer: 8.000ms - FileDeletionTimer: 0.000ns - FileMoveTimer: 4.000ms - Overwrite/PartitionCreationTimer: 0.000ns Averaged Fragment F00:(Total: 1m49s, non-child: 0.000ns, % non-child: 0.00%) split sizes: min: 8.97 MB, max: 11.82 MB, avg: 10.29 MB, stddev: 1.08 MB completion times: min:1m25s max:3m8s mean: 1m51s stddev:38s847ms execution rates: min:48.75 KB/sec max:135.44 KB/sec mean:104.22 KB/sec stddev:29.36 KB/sec num instances: 5 - AverageThreadTokens: 2.62 - BloomFilterBytes: 2.00 MB (2097152) - PeakMemoryUsage: 21.30 MB (22335152) - PerHostPeakMemUsage: 23.30 MB (24432304) - PrepareTime: 212.803ms - RowsProduced: 1.00M (1001200) - TotalCpuTime: 4m39s - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 0.000ns - TotalStorageWaitTime: 73.601ms BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 33 (33) - BlocksRecycled: 1 (1) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 32.00 KB (32768) - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns CodeGen:(Total: 1s832ms, non-child: 1s832ms, % non-child: 100.00%) - CodegenTime: 0.000ns - CompileTime: 567.207ms - LoadTime: 0.000ns - ModuleBitcodeSize: 1.85 MB (1940340) - OptimizationTime: 1s088ms - PrepareTime: 176.002ms HdfsTableSink:(Total: 500.007ms, non-child: 500.007ms, % non-child: 100.00%) - BytesWritten: 126.82 KB (129863) - CompressTimer: 1.600ms - EncodeTimer: 477.606ms - FilesCreated: 1 (1) - FinalizePartitionFileTimer: 16.000ms - HdfsWriteTimer: 1.600ms - PartitionsCreated: 1 (1) - PeakMemoryUsage: 1.45 MB (1518120) - RowsInserted: 1.00M (1001200) - TmpFileCreateTimer: 6.400ms HASH_JOIN_NODE (id=2):(Total: 1m49s, non-child: 1m49s, % non-child: 99.76%) - BuildPartitionTime: 0.000ns - BuildRows: 1.00K (1000) - BuildRowsPartitioned: 1.00K (1000) - BuildTime: 0.000ns - GetNewBlockTime: 0.000ns - HashBuckets: 2.05K (2048) - HashCollisions: 0 (0) - LargestPartitionPercent: 100 (100) - MaxPartitionLevel: 0 (0) - NumRepartitions: 0 (0) - PartitionsCreated: 16 (16) - PeakMemoryUsage: 2.67 MB (2801832) - PinTime: 0.000ns - ProbeRows: 536.41K (536406) - ProbeRowsPartitioned: 0 (0) - ProbeTime: 1m48s - RowsReturned: 1.00M (1001200) - RowsReturnedRate: 10.08 K/sec - SpilledPartitions: 0 (0) - UnpinTime: 0.000ns EXCHANGE_NODE (id=3): - BytesReceived: 56.53 KB (57891) - ConvertRowBatchTime: 0.000ns - DeserializeRowBatchTimer: 0.000ns - FirstBatchArrivalWaitTime: 0.000ns - PeakMemoryUsage: 0 - RowsReturned: 1.00K (1000) - RowsReturnedRate: 0 - SendersBlockedTimer: 0.000ns - SendersBlockedTotalTimer(*): 0.000ns HDFS_SCAN_NODE (id=0):(Total: 267.202ms, non-child: 267.202ms, % non-child: 100.00%) - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 1.64 - BytesRead: 3.36 MB (3520547) - BytesReadDataNodeCache: 0 - BytesReadLocal: 3.36 MB (3520547) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 3.36 MB (3520547) - DecompressionTime: 9.600ms - MaxCompressedTextFileLength: 0 - NumColumns: 14 (14) - NumDisksAccessed: 1 (1) - NumRowGroups: 2 (2) - NumScannerThreadsStarted: 2 (2) - PeakMemoryUsage: 12.35 MB (12946390) - PerReadThreadRawHdfsThroughput: 337.55 MB/sec - RemoteScanRanges: 0 (0) - RowsRead: 562.47K (562473) - RowsReturned: 536.41K (536406) - RowsReturnedRate: 4.41 M/sec - ScanRangesComplete: 2 (2) - ScannerThreadsInvoluntaryContextSwitches: 535 (535) - ScannerThreadsTotalWallClockTime: 2m47s - MaterializeTupleTime(*): 2m47s - ScannerThreadsSysTime: 27.710ms - ScannerThreadsUserTime: 1s222ms - ScannerThreadsVoluntaryContextSwitches: 593 (593) - TotalRawHdfsReadTime(*): 16.800ms - TotalReadThroughput: 34.14 KB/sec Filter 0: - Rows processed: 42.59K (42595) - Rows rejected: 0 (0) - Rows total: 42.60K (42598) Averaged Fragment F01:(Total: 360.005ms, non-child: 346.005ms, % non-child: 96.11%) split sizes: min: 4.92 KB, max: 5.21 KB, avg: 5.06 KB, stddev: 148.00 B completion times: min:360.002ms max:360.002ms mean: 360.002ms stddev:0.000ns execution rates: min:13.66 KB/sec max:14.46 KB/sec mean:14.06 KB/sec stddev:410.76 B/sec num instances: 2 - AverageThreadTokens: 1.00 - BloomFilterBytes: 0 - PeakMemoryUsage: 239.41 KB (245160) - PerHostPeakMemUsage: 239.41 KB (245160) - PrepareTime: 0.000ns - RowsProduced: 500 (500) - TotalCpuTime: 18.000ms - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 346.005ms - TotalStorageWaitTime: 10.000ms DataStreamSender (dst_id=3): - BytesSent: 141.33 KB (144727) - NetworkThroughput(*): 159.37 KB/sec - OverallThroughput: 0.00 /sec - PeakMemoryUsage: 4.41 KB (4520) - SerializeBatchTime: 0.000ns - ThriftTransmitTime(*): 886.013ms - UncompressedRowBatchSize: 410.18 KB (420020) HDFS_SCAN_NODE (id=1):(Total: 14.000ms, non-child: 14.000ms, % non-child: 100.00%) - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 0.00 - BytesRead: 8.22 KB (8417) - BytesReadDataNodeCache: 0 - BytesReadLocal: 8.22 KB (8417) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 8.22 KB (8417) - DecompressionTime: 0.000ns - MaxCompressedTextFileLength: 0 - NumColumns: 12 (12) - NumDisksAccessed: 1 (1) - NumRowGroups: 1 (1) - NumScannerThreadsStarted: 1 (1) - PeakMemoryUsage: 227.00 KB (232448) - PerReadThreadRawHdfsThroughput: 0.00 /sec - RemoteScanRanges: 0 (0) - RowsRead: 500 (500) - RowsReturned: 500 (500) - RowsReturnedRate: 36.68 K/sec - ScanRangesComplete: 1 (1) - ScannerThreadsInvoluntaryContextSwitches: 8 (8) - ScannerThreadsTotalWallClockTime: 14.000ms - MaterializeTupleTime(*): 0.000ns - ScannerThreadsSysTime: 420.000us - ScannerThreadsUserTime: 0.000ns - ScannerThreadsVoluntaryContextSwitches: 3 (3) - TotalRawHdfsReadTime(*): 0.000ns - TotalReadThroughput: 0.00 /sec BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 0 (0) - BlocksRecycled: 0 (0) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 0 - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns Fragment F00: Instance 9e4c857f471ba07e:1169bc0001433c95 (host=host1:22000):(Total: 3m4s, non-child: 0.000ns, % non-child: 0.00%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:2/8.97 MB Filter 0 arrival: 4s640ms MemoryUsage(4s000ms): ThreadUsage(4s000ms): - AverageThreadTokens: 1.91 - BloomFilterBytes: 2.00 MB (2097152) - PeakMemoryUsage: 19.40 MB (20346824) - PerHostPeakMemUsage: 21.40 MB (22443976) - PrepareTime: 388.003ms - RowsProduced: 859.00K (859000) - TotalCpuTime: 6m - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 0.000ns - TotalStorageWaitTime: 40.000ms BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 33 (33) - BlocksRecycled: 1 (1) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 32.00 KB (32768) - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns CodeGen:(Total: 4s576ms, non-child: 4s576ms, % non-child: 100.00%) - CodegenTime: 0.000ns - CompileTime: 1s544ms - LoadTime: 0.000ns - ModuleBitcodeSize: 1.85 MB (1940340) - OptimizationTime: 2s700ms - PrepareTime: 332.002ms HdfsTableSink:(Total: 824.006ms, non-child: 824.006ms, % non-child: 100.00%) - BytesWritten: 109.41 KB (112037) - CompressTimer: 4.000ms - EncodeTimer: 800.006ms - FilesCreated: 1 (1) - FinalizePartitionFileTimer: 20.000ms - HdfsWriteTimer: 0.000ns - PartitionsCreated: 1 (1) - PeakMemoryUsage: 1.45 MB (1518120) - RowsInserted: 859.00K (859000) - TmpFileCreateTimer: 4.000ms HASH_JOIN_NODE (id=2):(Total: 3m3s, non-child: 3m2s, % non-child: 99.50%) ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Build-Side Runtime-Filter Produced - BuildPartitionTime: 0.000ns - BuildRows: 1.00K (1000) - BuildRowsPartitioned: 1.00K (1000) - BuildTime: 0.000ns - GetNewBlockTime: 0.000ns - HashBuckets: 2.05K (2048) - HashCollisions: 0 (0) - LargestPartitionPercent: 100 (100) - MaxPartitionLevel: 0 (0) - NumRepartitions: 0 (0) - PartitionsCreated: 16 (16) - PeakMemoryUsage: 2.67 MB (2801832) - PinTime: 0.000ns - ProbeRows: 503.95K (503955) - ProbeRowsPartitioned: 0 (0) - ProbeTime: 3m1s - RowsReturned: 859.00K (859000) - RowsReturnedRate: 4.68 K/sec - SpilledPartitions: 0 (0) - UnpinTime: 0.000ns EXCHANGE_NODE (id=3): BytesReceived(4s000ms): - BytesReceived: 56.53 KB (57891) - ConvertRowBatchTime: 0.000ns - DeserializeRowBatchTimer: 0.000ns - FirstBatchArrivalWaitTime: 0.000ns - PeakMemoryUsage: 0 - RowsReturned: 1.00K (1000) - RowsReturnedRate: 0 - SendersBlockedTimer: 0.000ns - SendersBlockedTotalTimer(*): 0.000ns HDFS_SCAN_NODE (id=0):(Total: 912.007ms, non-child: 912.007ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Enabled, Codegen enabled: 0 out of 2 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:2/8.97 MB Runtime filters: All filters arrived. Waited 0 Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:28 BytesRead(4s000ms): - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 0.94 - BytesRead: 2.90 MB (3036678) - BytesReadDataNodeCache: 0 - BytesReadLocal: 2.90 MB (3036678) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 2.90 MB (3036678) - DecompressionTime: 12.000ms - MaxCompressedTextFileLength: 0 - NumColumns: 14 (14) - NumDisksAccessed: 1 (1) - NumRowGroups: 2 (2) - NumScannerThreadsStarted: 1 (1) - PeakMemoryUsage: 9.67 MB (10142664) - PerReadThreadRawHdfsThroughput: 362.00 MB/sec - RemoteScanRanges: 0 (0) - RowsRead: 503.95K (503955) - RowsReturned: 503.95K (503955) - RowsReturnedRate: 552.58 K/sec - ScanRangesComplete: 2 (2) - ScannerThreadsInvoluntaryContextSwitches: 359 (359) - ScannerThreadsTotalWallClockTime: 2m52s - MaterializeTupleTime(*): 2m51s - ScannerThreadsSysTime: 12.462ms - ScannerThreadsUserTime: 1s178ms - ScannerThreadsVoluntaryContextSwitches: 719 (719) - TotalRawHdfsReadTime(*): 8.000ms - TotalReadThroughput: 15.81 KB/sec Filter 0: - Rows processed: 32.77K (32766) - Rows rejected: 0 (0) - Rows total: 32.77K (32768) Instance 9e4c857f471ba07e:1169bc0001433c94 (host=host2:22000):(Total: 1m41s, non-child: 0.000ns, % non-child: 0.00%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:3/11.82 MB Filter 0 arrival: 1s178ms MemoryUsage(2s000ms): ThreadUsage(2s000ms): - AverageThreadTokens: 3.36 - BloomFilterBytes: 2.00 MB (2097152) - PeakMemoryUsage: 23.78 MB (24932496) - PerHostPeakMemUsage: 25.78 MB (27029648) - PrepareTime: 172.001ms - RowsProduced: 1.15M (1148000) - TotalCpuTime: 5m42s - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 0.000ns - TotalStorageWaitTime: 116.000ms CodeGen:(Total: 1s148ms, non-child: 1s148ms, % non-child: 100.00%) - CodegenTime: 0.000ns - CompileTime: 320.002ms - LoadTime: 0.000ns - ModuleBitcodeSize: 1.85 MB (1940340) - OptimizationTime: 688.004ms - PrepareTime: 136.000ms HdfsTableSink:(Total: 432.002ms, non-child: 432.002ms, % non-child: 100.00%) - BytesWritten: 144.85 KB (148323) - CompressTimer: 0.000ns - EncodeTimer: 416.002ms - FilesCreated: 1 (1) - FinalizePartitionFileTimer: 12.000ms - HdfsWriteTimer: 4.000ms - PartitionsCreated: 1 (1) - PeakMemoryUsage: 1.45 MB (1518120) - RowsInserted: 1.15M (1148000) - TmpFileCreateTimer: 4.000ms HASH_JOIN_NODE (id=2):(Total: 1m40s, non-child: 1m40s, % non-child: 99.89%) ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously, Build-Side Runtime-Filter Produced - BuildPartitionTime: 0.000ns - BuildRows: 1.00K (1000) - BuildRowsPartitioned: 1.00K (1000) - BuildTime: 0.000ns - GetNewBlockTime: 0.000ns - HashBuckets: 2.05K (2048) - HashCollisions: 0 (0) - LargestPartitionPercent: 100 (100) - MaxPartitionLevel: 0 (0) - NumRepartitions: 0 (0) - PartitionsCreated: 16 (16) - PeakMemoryUsage: 2.67 MB (2801832) - PinTime: 0.000ns - ProbeRows: 645.49K (645487) - ProbeRowsPartitioned: 0 (0) - ProbeTime: 1m40s - RowsReturned: 1.15M (1148000) - RowsReturnedRate: 11.38 K/sec - SpilledPartitions: 0 (0) - UnpinTime: 0.000ns EXCHANGE_NODE (id=3): BytesReceived(2s000ms): - BytesReceived: 56.53 KB (57891) - ConvertRowBatchTime: 0.000ns - DeserializeRowBatchTimer: 0.000ns - FirstBatchArrivalWaitTime: 0.000ns - PeakMemoryUsage: 0 - RowsReturned: 1.00K (1000) - RowsReturnedRate: 0 - SendersBlockedTimer: 0.000ns - SendersBlockedTotalTimer(*): 0.000ns HDFS_SCAN_NODE (id=0):(Total: 108.000ms, non-child: 108.000ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Enabled, Codegen enabled: 0 out of 3 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:3/11.82 MB Runtime filters: All filters arrived. Waited 0 Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:42 BytesRead(2s000ms): - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 2.38 - BytesRead: 3.87 MB (4061514) - BytesReadDataNodeCache: 0 - BytesReadLocal: 3.87 MB (4061514) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 3.87 MB (4061514) - DecompressionTime: 0.000ns - MaxCompressedTextFileLength: 0 - NumColumns: 14 (14) - NumDisksAccessed: 1 (1) - NumRowGroups: 3 (3) - NumScannerThreadsStarted: 3 (3) - PeakMemoryUsage: 14.35 MB (15048648) - PerReadThreadRawHdfsThroughput: 322.78 MB/sec - RemoteScanRanges: 0 (0) - RowsRead: 645.49K (645487) - RowsReturned: 645.49K (645487) - RowsReturnedRate: 5.98 M/sec - ScanRangesComplete: 3 (3) - ScannerThreadsInvoluntaryContextSwitches: 607 (607) - ScannerThreadsTotalWallClockTime: 4m - MaterializeTupleTime(*): 3m59s - ScannerThreadsSysTime: 24.749ms - ScannerThreadsUserTime: 1s382ms - ScannerThreadsVoluntaryContextSwitches: 657 (657) - TotalRawHdfsReadTime(*): 12.000ms - TotalReadThroughput: 38.88 KB/sec Filter 0: - Rows processed: 49.15K (49149) - Rows rejected: 0 (0) - Rows total: 49.15K (49152) Instance 9e4c857f471ba07e:1169bc0001433c92 (host=host4:22000):(Total: 1m30s, non-child: 0.000ns, % non-child: 0.00%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:2/9.55 MB Filter 0 arrival: 1s146ms MemoryUsage(2s000ms): ThreadUsage(2s000ms): - AverageThreadTokens: 2.57 - BloomFilterBytes: 2.00 MB (2097152) - PeakMemoryUsage: 21.82 MB (22875336) - PerHostPeakMemUsage: 23.82 MB (24972488) - PrepareTime: 164.004ms - RowsProduced: 1.10M (1098000) - TotalCpuTime: 3m54s - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 0.000ns - TotalStorageWaitTime: 64.001ms BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 33 (33) - BlocksRecycled: 1 (1) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 32.00 KB (32768) - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns CodeGen:(Total: 1s116ms, non-child: 1s116ms, % non-child: 100.00%) - CodegenTime: 0.000ns - CompileTime: 316.007ms - LoadTime: 0.000ns - ModuleBitcodeSize: 1.85 MB (1940340) - OptimizationTime: 664.016ms - PrepareTime: 136.003ms HdfsTableSink:(Total: 396.009ms, non-child: 396.009ms, % non-child: 100.00%) - BytesWritten: 138.37 KB (141687) - CompressTimer: 0.000ns - EncodeTimer: 376.009ms - FilesCreated: 1 (1) - FinalizePartitionFileTimer: 16.000ms - HdfsWriteTimer: 0.000ns - PartitionsCreated: 1 (1) - PeakMemoryUsage: 1.45 MB (1518120) - RowsInserted: 1.10M (1098000) - TmpFileCreateTimer: 4.000ms HASH_JOIN_NODE (id=2):(Total: 1m29s, non-child: 1m29s, % non-child: 99.92%) ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously, Build-Side Runtime-Filter Produced - BuildPartitionTime: 0.000ns - BuildRows: 1.00K (1000) - BuildRowsPartitioned: 1.00K (1000) - BuildTime: 0.000ns - GetNewBlockTime: 0.000ns - HashBuckets: 2.05K (2048) - HashCollisions: 0 (0) - LargestPartitionPercent: 100 (100) - MaxPartitionLevel: 0 (0) - NumRepartitions: 0 (0) - PartitionsCreated: 16 (16) - PeakMemoryUsage: 2.67 MB (2801832) - PinTime: 0.000ns - ProbeRows: 529.59K (529594) - ProbeRowsPartitioned: 0 (0) - ProbeTime: 1m29s - RowsReturned: 1.10M (1098000) - RowsReturnedRate: 12.24 K/sec - SpilledPartitions: 0 (0) - UnpinTime: 0.000ns EXCHANGE_NODE (id=3): BytesReceived(2s000ms): - BytesReceived: 56.53 KB (57891) - ConvertRowBatchTime: 0.000ns - DeserializeRowBatchTimer: 0.000ns - FirstBatchArrivalWaitTime: 0.000ns - PeakMemoryUsage: 0 - RowsReturned: 1.00K (1000) - RowsReturnedRate: 0 - SendersBlockedTimer: 0.000ns - SendersBlockedTotalTimer(*): 0.000ns HDFS_SCAN_NODE (id=0):(Total: 76.001ms, non-child: 76.001ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Enabled, Codegen enabled: 0 out of 2 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:2/9.55 MB Runtime filters: All filters arrived. Waited 0 Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:28 BytesRead(2s000ms): - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 1.60 - BytesRead: 3.08 MB (3229092) - BytesReadDataNodeCache: 0 - BytesReadLocal: 3.08 MB (3229092) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 3.08 MB (3229092) - DecompressionTime: 8.000ms - MaxCompressedTextFileLength: 0 - NumColumns: 14 (14) - NumDisksAccessed: 1 (1) - NumRowGroups: 2 (2) - NumScannerThreadsStarted: 2 (2) - PeakMemoryUsage: 12.27 MB (12869128) - PerReadThreadRawHdfsThroughput: 769.86 MB/sec - RemoteScanRanges: 0 (0) - RowsRead: 529.59K (529594) - RowsReturned: 529.59K (529594) - RowsReturnedRate: 6.97 M/sec - ScanRangesComplete: 2 (2) - ScannerThreadsInvoluntaryContextSwitches: 597 (597) - ScannerThreadsTotalWallClockTime: 2m23s - MaterializeTupleTime(*): 2m23s - ScannerThreadsSysTime: 34.880ms - ScannerThreadsUserTime: 1s122ms - ScannerThreadsVoluntaryContextSwitches: 536 (536) - TotalRawHdfsReadTime(*): 4.000ms - TotalReadThroughput: 34.84 KB/sec Filter 0: - Rows processed: 32.77K (32766) - Rows rejected: 0 (0) - Rows total: 32.77K (32768) Instance 9e4c857f471ba07e:1169bc0001433c93 (host=host5:22000):(Total: 1m29s, non-child: 0.000ns, % non-child: 0.00%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:3/9.84 MB Filter 0 arrival: 1s238ms MemoryUsage(2s000ms): ThreadUsage(2s000ms): - AverageThreadTokens: 2.61 - BloomFilterBytes: 2.00 MB (2097152) - PeakMemoryUsage: 20.84 MB (21857128) - PerHostPeakMemUsage: 22.84 MB (23954280) - PrepareTime: 180.004ms - RowsProduced: 829.00K (829000) - TotalCpuTime: 3m56s - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 0.000ns - TotalStorageWaitTime: 76.001ms BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 33 (33) - BlocksRecycled: 1 (1) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 32.00 KB (32768) - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns CodeGen:(Total: 1s200ms, non-child: 1s200ms, % non-child: 100.00%) - CodegenTime: 0.000ns - CompileTime: 332.007ms - LoadTime: 0.000ns - ModuleBitcodeSize: 1.85 MB (1940340) - OptimizationTime: 724.017ms - PrepareTime: 144.003ms HdfsTableSink:(Total: 416.009ms, non-child: 416.009ms, % non-child: 100.00%) - BytesWritten: 106.23 KB (108784) - CompressTimer: 4.000ms - EncodeTimer: 388.009ms - FilesCreated: 1 (1) - FinalizePartitionFileTimer: 16.000ms - HdfsWriteTimer: 4.000ms - PartitionsCreated: 1 (1) - PeakMemoryUsage: 1.45 MB (1518120) - RowsInserted: 829.00K (829000) - TmpFileCreateTimer: 12.000ms HASH_JOIN_NODE (id=2):(Total: 1m29s, non-child: 1m28s, % non-child: 99.84%) ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously, Build-Side Runtime-Filter Produced - BuildPartitionTime: 0.000ns - BuildRows: 1.00K (1000) - BuildRowsPartitioned: 1.00K (1000) - BuildTime: 0.000ns - GetNewBlockTime: 0.000ns - HashBuckets: 2.05K (2048) - HashCollisions: 0 (0) - LargestPartitionPercent: 100 (100) - MaxPartitionLevel: 0 (0) - NumRepartitions: 0 (0) - PartitionsCreated: 16 (16) - PeakMemoryUsage: 2.67 MB (2801832) - PinTime: 0.000ns - ProbeRows: 521.32K (521320) - ProbeRowsPartitioned: 0 (0) - ProbeTime: 1m28s - RowsReturned: 829.00K (829000) - RowsReturnedRate: 9.31 K/sec - SpilledPartitions: 0 (0) - UnpinTime: 0.000ns EXCHANGE_NODE (id=3): BytesReceived(2s000ms): - BytesReceived: 56.53 KB (57891) - ConvertRowBatchTime: 0.000ns - DeserializeRowBatchTimer: 0.000ns - FirstBatchArrivalWaitTime: 0.000ns - PeakMemoryUsage: 0 - RowsReturned: 1.00K (1000) - RowsReturnedRate: 0 - SendersBlockedTimer: 0.000ns - SendersBlockedTotalTimer(*): 0.000ns HDFS_SCAN_NODE (id=0):(Total: 140.003ms, non-child: 140.003ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Enabled, Codegen enabled: 0 out of 3 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:3/9.84 MB Runtime filters: All filters arrived. Waited 0 Hdfs Read Thread Concurrency Bucket: 0:99.44% 1:0.5587% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:42 BytesRead(2s000ms): - AverageHdfsReadThreadConcurrency: 0.01 - AverageScannerThreadConcurrency: 1.63 - BytesRead: 3.28 MB (3443071) - BytesReadDataNodeCache: 0 - BytesReadLocal: 3.28 MB (3443071) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 3.28 MB (3443071) - DecompressionTime: 12.000ms - MaxCompressedTextFileLength: 0 - NumColumns: 14 (14) - NumDisksAccessed: 1 (1) - NumRowGroups: 3 (3) - NumScannerThreadsStarted: 2 (2) - PeakMemoryUsage: 11.43 MB (11983432) - PerReadThreadRawHdfsThroughput: 102.61 MB/sec - RemoteScanRanges: 0 (0) - RowsRead: 521.32K (521320) - RowsReturned: 521.32K (521320) - RowsReturnedRate: 3.72 M/sec - ScanRangesComplete: 3 (3) - ScannerThreadsInvoluntaryContextSwitches: 520 (520) - ScannerThreadsTotalWallClockTime: 2m25s - MaterializeTupleTime(*): 2m24s - ScannerThreadsSysTime: 28.031ms - ScannerThreadsUserTime: 1s113ms - ScannerThreadsVoluntaryContextSwitches: 539 (539) - TotalRawHdfsReadTime(*): 32.000ms - TotalReadThroughput: 37.15 KB/sec Filter 0: - Rows processed: 49.15K (49149) - Rows rejected: 0 (0) - Rows total: 49.15K (49152) Instance 9e4c857f471ba07e:1169bc0001433c96 (host=host3:22000):(Total: 1m24s, non-child: 0.000ns, % non-child: 0.00%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:3/11.26 MB Filter 0 arrival: 1s156ms MemoryUsage(2s000ms): ThreadUsage(2s000ms): - AverageThreadTokens: 2.63 - BloomFilterBytes: 2.00 MB (2097152) - PeakMemoryUsage: 20.66 MB (21663976) - PerHostPeakMemUsage: 22.66 MB (23761128) - PrepareTime: 160.002ms - RowsProduced: 1.07M (1072000) - TotalCpuTime: 3m42s - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 0.000ns - TotalStorageWaitTime: 72.001ms BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 33 (33) - BlocksRecycled: 1 (1) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 32.00 KB (32768) - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns CodeGen:(Total: 1s124ms, non-child: 1s124ms, % non-child: 100.00%) - CodegenTime: 0.000ns - CompileTime: 324.005ms - LoadTime: 0.000ns - ModuleBitcodeSize: 1.85 MB (1940340) - OptimizationTime: 668.011ms - PrepareTime: 132.002ms HdfsTableSink:(Total: 432.007ms, non-child: 432.007ms, % non-child: 100.00%) - BytesWritten: 135.24 KB (138488) - CompressTimer: 0.000ns - EncodeTimer: 408.006ms - FilesCreated: 1 (1) - FinalizePartitionFileTimer: 16.000ms - HdfsWriteTimer: 0.000ns - PartitionsCreated: 1 (1) - PeakMemoryUsage: 1.45 MB (1518120) - RowsInserted: 1.07M (1072000) - TmpFileCreateTimer: 8.000ms HASH_JOIN_NODE (id=2):(Total: 1m23s, non-child: 1m23s, % non-child: 99.88%) ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously, Build-Side Runtime-Filter Produced - BuildPartitionTime: 0.000ns - BuildRows: 1.00K (1000) - BuildRowsPartitioned: 1.00K (1000) - BuildTime: 0.000ns - GetNewBlockTime: 0.000ns - HashBuckets: 2.05K (2048) - HashCollisions: 0 (0) - LargestPartitionPercent: 100 (100) - MaxPartitionLevel: 0 (0) - NumRepartitions: 0 (0) - PartitionsCreated: 16 (16) - PeakMemoryUsage: 2.67 MB (2801832) - PinTime: 0.000ns - ProbeRows: 481.68K (481677) - ProbeRowsPartitioned: 0 (0) - ProbeTime: 1m23s - RowsReturned: 1.07M (1072000) - RowsReturnedRate: 12.80 K/sec - SpilledPartitions: 0 (0) - UnpinTime: 0.000ns EXCHANGE_NODE (id=3): BytesReceived(2s000ms): - BytesReceived: 56.53 KB (57891) - ConvertRowBatchTime: 0.000ns - DeserializeRowBatchTimer: 0.000ns - FirstBatchArrivalWaitTime: 0.000ns - PeakMemoryUsage: 0 - RowsReturned: 1.00K (1000) - RowsReturnedRate: 0 - SendersBlockedTimer: 0.000ns - SendersBlockedTotalTimer(*): 0.000ns HDFS_SCAN_NODE (id=0):(Total: 100.001ms, non-child: 100.001ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Enabled, Codegen enabled: 0 out of 3 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:3/11.26 MB Runtime filters: All filters arrived. Waited 0 Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:42 BytesRead(2s000ms): - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 1.65 - BytesRead: 3.65 MB (3832382) - BytesReadDataNodeCache: 0 - BytesReadLocal: 3.65 MB (3832382) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 3.65 MB (3832382) - DecompressionTime: 16.000ms - MaxCompressedTextFileLength: 0 - NumColumns: 14 (14) - NumDisksAccessed: 1 (1) - NumRowGroups: 3 (3) - NumScannerThreadsStarted: 3 (3) - PeakMemoryUsage: 14.01 MB (14688080) - PerReadThreadRawHdfsThroughput: 130.53 MB/sec - RemoteScanRanges: 0 (0) - RowsRead: 612.01K (612013) - RowsReturned: 481.68K (481677) - RowsReturnedRate: 4.82 M/sec - ScanRangesComplete: 3 (3) - ScannerThreadsInvoluntaryContextSwitches: 596 (596) - ScannerThreadsTotalWallClockTime: 2m17s - MaterializeTupleTime(*): 2m16s - ScannerThreadsSysTime: 38.430ms - ScannerThreadsUserTime: 1s314ms - ScannerThreadsVoluntaryContextSwitches: 515 (515) - TotalRawHdfsReadTime(*): 28.000ms - TotalReadThroughput: 44.03 KB/sec Filter 0: - Rows processed: 49.15K (49149) - Rows rejected: 0 (0) - Rows total: 49.15K (49152) Fragment F01: Instance 9e4c857f471ba07e:1169bc0001433c98 (host=host5:22000):(Total: 360.008ms, non-child: 344.008ms, % non-child: 95.56%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/4.92 KB MemoryUsage(500.000ms): 12.41 KB ThreadUsage(500.000ms): 1 - AverageThreadTokens: 1.00 - BloomFilterBytes: 0 - PeakMemoryUsage: 239.41 KB (245160) - PerHostPeakMemUsage: 239.41 KB (245160) - PrepareTime: 0.000ns - RowsProduced: 479 (479) - TotalCpuTime: 24.000ms - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 344.008ms - TotalStorageWaitTime: 8.000ms DataStreamSender (dst_id=3): - BytesSent: 128.40 KB (131485) - NetworkThroughput(*): 146.58 KB/sec - OverallThroughput: 0.00 /sec - PeakMemoryUsage: 4.41 KB (4520) - SerializeBatchTime: 0.000ns - ThriftTransmitTime(*): 876.020ms - UncompressedRowBatchSize: 392.95 KB (402380) HDFS_SCAN_NODE (id=1):(Total: 16.000ms, non-child: 16.000ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Disabled, Codegen enabled: 0 out of 1 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/4.92 KB Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:12 - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 0.00 - BytesRead: 7.93 KB (8121) - BytesReadDataNodeCache: 0 - BytesReadLocal: 7.93 KB (8121) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 7.93 KB (8121) - DecompressionTime: 0.000ns - MaxCompressedTextFileLength: 0 - NumColumns: 12 (12) - NumDisksAccessed: 1 (1) - NumRowGroups: 1 (1) - NumScannerThreadsStarted: 1 (1) - PeakMemoryUsage: 227.00 KB (232448) - PerReadThreadRawHdfsThroughput: 0.00 /sec - RemoteScanRanges: 0 (0) - RowsRead: 479 (479) - RowsReturned: 479 (479) - RowsReturnedRate: 29.94 K/sec - ScanRangesComplete: 1 (1) - ScannerThreadsInvoluntaryContextSwitches: 14 (14) - ScannerThreadsTotalWallClockTime: 16.000ms - MaterializeTupleTime(*): 0.000ns - ScannerThreadsSysTime: 562.000us - ScannerThreadsUserTime: 0.000ns - ScannerThreadsVoluntaryContextSwitches: 1 (1) - TotalRawHdfsReadTime(*): 0.000ns - TotalReadThroughput: 0.00 /sec Instance 9e4c857f471ba07e:1169bc0001433c97 (host=host2:22000):(Total: 360.002ms, non-child: 348.002ms, % non-child: 96.67%) Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/5.21 KB MemoryUsage(500.000ms): 12.41 KB ThreadUsage(500.000ms): 1 - AverageThreadTokens: 1.00 - BloomFilterBytes: 0 - PeakMemoryUsage: 239.41 KB (245160) - PerHostPeakMemUsage: 239.41 KB (245160) - PrepareTime: 0.000ns - RowsProduced: 521 (521) - TotalCpuTime: 12.000ms - TotalNetworkReceiveTime: 0.000ns - TotalNetworkSendTime: 348.002ms - TotalStorageWaitTime: 12.000ms BlockMgr: - BlockWritesOutstanding: 0 (0) - BlocksCreated: 0 (0) - BlocksRecycled: 0 (0) - BufferedPins: 0 (0) - BytesWritten: 0 - MaxBlockSize: 8.00 MB (8388608) - MemoryLimit: 6.85 GB (7360164864) - PeakMemoryUsage: 0 - TotalBufferWaitTime: 0.000ns - TotalEncryptionTime: 0.000ns - TotalIntegrityCheckTime: 0.000ns - TotalReadBlockTime: 0.000ns DataStreamSender (dst_id=3): - BytesSent: 154.27 KB (157970) - NetworkThroughput(*): 172.17 KB/sec - OverallThroughput: 0.00 /sec - PeakMemoryUsage: 4.41 KB (4520) - SerializeBatchTime: 0.000ns - ThriftTransmitTime(*): 896.006ms - UncompressedRowBatchSize: 427.40 KB (437660) HDFS_SCAN_NODE (id=1):(Total: 12.000ms, non-child: 12.000ms, % non-child: 100.00%) ExecOption: Expr Evaluation Codegen Disabled, Codegen enabled: 0 out of 1 Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/5.21 KB Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% File Formats: PARQUET/SNAPPY:12 - AverageHdfsReadThreadConcurrency: 0.00 - AverageScannerThreadConcurrency: 0.00 - BytesRead: 8.51 KB (8713) - BytesReadDataNodeCache: 0 - BytesReadLocal: 8.51 KB (8713) - BytesReadRemoteUnexpected: 0 - BytesReadShortCircuit: 8.51 KB (8713) - DecompressionTime: 0.000ns - MaxCompressedTextFileLength: 0 - NumColumns: 12 (12) - NumDisksAccessed: 1 (1) - NumRowGroups: 1 (1) - NumScannerThreadsStarted: 1 (1) - PeakMemoryUsage: 227.00 KB (232448) - PerReadThreadRawHdfsThroughput: 0.00 /sec - RemoteScanRanges: 0 (0) - RowsRead: 521 (521) - RowsReturned: 521 (521) - RowsReturnedRate: 43.42 K/sec - ScanRangesComplete: 1 (1) - ScannerThreadsInvoluntaryContextSwitches: 2 (2) - ScannerThreadsTotalWallClockTime: 12.000ms - MaterializeTupleTime(*): 0.000ns - ScannerThreadsSysTime: 278.000us - ScannerThreadsUserTime: 0.000ns - ScannerThreadsVoluntaryContextSwitches: 5 (5) - TotalRawHdfsReadTime(*): 0.000ns - TotalReadThroughput: 0.00 /sec
Created 06-24-2016 11:50 AM
The main difference seems to be execution skew. In the second profile the max time for the join is over 3 minutes, compared to much lower in first profile. The average time isn't very different between the profiles. Probably the partitioning resulted in the data being distributed differently between the nodes, and for some reason that one node is slower. It doesn't look like it's necessarily processing more data, but maybe the node is more heavily loaded, or the data is somehow different.
Is the join condition something complicated? It's only processing a few thousand rows per second through the join, which is very low.
Created 06-24-2016 12:07 PM
The join condition is simple, just equality on one column, however the where clause is very complicated..!!
You are right about that one server, there was a query that was running only on that one server. It was started about an hour ago. Probably aborted from the shell but this server was still running it (or hung?). I cancelled that query from the impala "Queries" tab in the UI and the my query performance improved. It is better only by 8% or 9% than Track A. I imagined it would be at least 30% better since the size of data being considered is almost half...
Thanks again...!
Created 06-24-2016 12:25 PM
That probably makes sense if the bottleneck is evaluating the where clause. If those extra rows are filtered out in the join, then the gain is limited, since you should filter out the extra rows during the scan or when evaluating the simple join condition.
Our scans are multithreaded too, so sometimes if the join is the bottleneck, making the scans do more work doesn't slow down the query overall.