You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@impala.apache.org by "HeLifu (JIRA)" <ji...@apache.org> on 2017/12/18 02:10:00 UTC
[jira] [Closed] (IMPALA-6328) why kudu HashJoin node takes much
more time than parquet on Q5 of TPC-H?
[ https://issues.apache.org/jira/browse/IMPALA-6328?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
HeLifu closed IMPALA-6328.
--------------------------
thanks Jim:P
> why kudu HashJoin node takes much more time than parquet on Q5 of TPC-H?
> ------------------------------------------------------------------------
>
> Key: IMPALA-6328
> URL: https://issues.apache.org/jira/browse/IMPALA-6328
> Project: IMPALA
> Issue Type: Improvement
> Components: Backend
> Affects Versions: Impala 2.9.0
> Reporter: HeLifu
> Attachments: TPCH-5-plan-kudu.jpg, TPCH-5-plan-parquet.jpg
>
>
> hi, i ran a tpc-h test under 1T scale and found that kudu HashJoin node took much more time(double!) than parquet on query 5 of TPC-H. could anybody help to explain why?
> Thanks in advance.
> *{color:red}Parquet:{color}*
> {code:java}
> HASH_JOIN_NODE (id=6):(Total: 3m34s, non-child: 3m18s, % non-child: 92.17%)
> ExecOption: Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously
> - BuildRows: 227.55M (227546432)
> - BuildTime: 1m8s
> - NumHashTableBuildsSkipped: 0 (0)
> - PeakMemoryUsage: 17.14 GB (18399317760)
> - ProbeRows: 2.00B (2001992073)
> - ProbeRowsPartitioned: 0 (0)
> - ProbeTime: 2m6s
> - RowsReturned: 303.68M (303678704)
> - RowsReturnedRate: 1.41 M/sec
> Hash Join Builder (join_node_id=6):
> ExecOption: Build Side Codegen Enabled, Hash Table Construction Codegen Enabled
> Runtime filters: 0 of 1 Runtime Filter Published, 1 Disabled
> - BuildRowsPartitionTime: 47s054ms
> - BuildRowsPartitioned: 227.55M (227546432)
> - GetNewBlockTime: 6.349ms
> - HashBuckets: 536.87M (536870912)
> - HashCollisions: 0 (0)
> - HashTablesBuildTime: 20s919ms
> - LargestPartitionPercent: 6 (6)
> - MaxPartitionLevel: 0 (0)
> - NumRepartitions: 0 (0)
> - PartitionsCreated: 16 (16)
> - PeakMemoryUsage: 17.13 GB (18397287552)
> - PinTime: 0.000ns
> - RepartitionTime: 0.000ns
> - SpilledPartitions: 0 (0)
> - UnpinTime: 0.000ns
> EXCHANGE_NODE (id=13):(Total: 9s442ms, non-child: 9s048ms, % non-child: 95.83%)
> BytesReceived(8s000ms): 224.35 MB, 907.67 MB, 1.53 GB, 2.16 GB, 2.79 GB, 3.43 GB, 4.11 GB, 4.63 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB, 4.66 GB
> - BytesReceived: 4.66 GB (5004716793)
> - ConvertRowBatchTime: 4s469ms
> - DeserializeRowBatchTimer: 19s513ms
> - FirstBatchArrivalWaitTime: 0.000ns
> - PeakMemoryUsage: 0
> - RowsReturned: 227.55M (227546432)
> - RowsReturnedRate: 24.10 M/sec
> - SendersBlockedTimer: 11s573ms
> - SendersBlockedTotalTimer(*): 26s223ms
> HDFS_SCAN_NODE (id=2):(Total: 7s389ms, non-child: 7s389ms, % non-child: 100.00%)
> Hdfs split stats (<volume id>:<# splits>/<split lengths>): 4:46/11.37 GB 2:52/12.85 GB 5:49/12.11 GB 1:48/11.86 GB 0:48/11.86 GB 3:51/12.60 GB
> ExecOption: PARQUET Codegen Enabled, Codegen enabled: 294 out of 294
> Runtime filters: All filters arrived. Waited 0
> Hdfs Read Thread Concurrency Bucket: 0:97.12% 1:1.37% 2:0.411% 3:0.274% 4:0.5479% 5:0.274% 6:0% 7:0% 8:0% 9:0% 10:0%
> File Formats: PARQUET/SNAPPY:1176
> BytesRead(8s000ms): 0, 0, 0, 0, 0, 0, 0, 0, 0, 80.38 MB, 3.32 GB, 3.33 GB, 3.33 GB, 3.33 GB, 3.33 GB, 6.13 GB, 6.65 GB, 6.65 GB, 6.65 GB, 6.65 GB, 8.79 GB, 9.98 GB, 9.98 GB, 9.98 GB, 9.98 GB, 11.38 GB, 13.31 GB, 13.31 GB, 13.31 GB, 13.31 GB, 15.24 GB, 16.64 GB, 16.64 GB, 16.64 GB, 16.73 GB, 19.83 GB, 19.96 GB, 19.96 GB, 19.96 GB, 21.27 GB, 23.29 GB, 23.29 GB, 23.29 GB, 23.32 GB, 24.34 GB
> - FooterProcessingTime: (Avg: 13.307ms ; Min: 1.982ms ; Max: 141.238ms ; Number of samples: 294)
> - AverageHdfsReadThreadConcurrency: 0.07
> - AverageScannerThreadConcurrency: 30.55
> - BytesRead: 24.45 GB (26257935312)
> - BytesReadDataNodeCache: 0
> - BytesReadLocal: 24.45 GB (26257935312)
> - BytesReadRemoteUnexpected: 0
> - BytesReadShortCircuit: 24.45 GB (26257935312)
> - DecompressionTime: 2m21s
> - MaxCompressedTextFileLength: 0
> - NumColumns: 4 (4)
> - NumDictFilteredRowGroups: 0 (0)
> - NumDisksAccessed: 6 (6)
> - NumRowGroups: 294 (294)
> - NumScannerThreadsStarted: 40 (40)
> - NumScannersWithNoReads: 0 (0)
> - NumStatsFilteredRowGroups: 0 (0)
> - PeakMemoryUsage: 3.61 GB (3872112566)
> - PerReadThreadRawHdfsThroughput: 825.37 MB/sec
> - RemoteScanRanges: 0 (0)
> - RowBatchQueueGetWaitTime: 56.799ms
> - RowBatchQueuePutWaitTime: 2h58m
> - RowsRead: 2.00B (2001992073)
> - RowsReturned: 2.00B (2001992073)
> - RowsReturnedRate: 270.93 M/sec
> - ScanRangesComplete: 294 (294)
> - ScannerThreadsInvoluntaryContextSwitches: 4.09K (4089)
> - ScannerThreadsTotalWallClockTime: 3h5m
> - MaterializeTupleTime(*): 3m33s
> - ScannerThreadsSysTime: 1m17s
> - ScannerThreadsUserTime: 5m45s
> - ScannerThreadsVoluntaryContextSwitches: 2.01M (2014822)
> - TotalRawHdfsReadTime(*): 30s339ms
> - TotalReadThroughput: 68.33 MB/sec
> Filter 4 (4.00 MB):
> - Rows processed: 4.82M (4816896)
> - Rows rejected: 0 (0)
> - Rows total: 2.00B (2001992073)
> Filter 5 (16.00 MB):
> - Rows processed: 4.82M (4816896)
> - Rows rejected: 0 (0)
> - Rows total: 2.00B (2001992073)
> {code}
> {color:red}*kudu:*{color}
> {code:java}
> HASH_JOIN_NODE (id=6):(Total: 6m12s, non-child: 5m50s, % non-child: 94.13%)
> ExecOption: Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously
> - BuildRows: 227.55M (227546432)
> - BuildTime: 29s641ms
> - NumHashTableBuildsSkipped: 0 (0)
> - PeakMemoryUsage: 11.63 GB (12491762944)
> - ProbeRows: 2.00B (2000027549)
> - ProbeRowsPartitioned: 0 (0)
> - ProbeTime: 5m16s
> - RowsReturned: 303.41M (303410631)
> - RowsReturnedRate: 815.04 K/sec
> Hash Join Builder (join_node_id=6):
> ExecOption: Build Side Codegen Enabled, Hash Table Construction Codegen Enabled
> - BuildRowsPartitionTime: 10s944ms
> - BuildRowsPartitioned: 227.55M (227546432)
> - GetNewBlockTime: 4.046ms
> - HashBuckets: 536.87M (536870912)
> - HashCollisions: 0 (0)
> - HashTablesBuildTime: 18s659ms
> - LargestPartitionPercent: 6 (6)
> - MaxPartitionLevel: 0 (0)
> - NumRepartitions: 0 (0)
> - PartitionsCreated: 16 (16)
> - PeakMemoryUsage: 11.63 GB (12491707520)
> - PinTime: 0.000ns
> - RepartitionTime: 0.000ns
> - SpilledPartitions: 0 (0)
> - UnpinTime: 0.000ns
> EXCHANGE_NODE (id=13):(Total: 13s166ms, non-child: 8s365ms, % non-child: 63.54%)
> BytesReceived(16s000ms): 934.36 MB, 2.80 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB, 3.15 GB
> - BytesReceived: 3.15 GB (3383413889)
> - ConvertRowBatchTime: 6s115ms
> - DeserializeRowBatchTimer: 7s268ms
> - FirstBatchArrivalWaitTime: 0.000ns
> - PeakMemoryUsage: 0
> - RowsReturned: 227.55M (227546432)
> - RowsReturnedRate: 17.28 M/sec
> - SendersBlockedTimer: 957.765ms
> - SendersBlockedTotalTimer(*): 1s915ms
> KUDU_SCAN_NODE (id=2):(Total: 8s687ms, non-child: 8s687ms, % non-child: 100.00%)
> BytesRead(16s000ms): 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
> - BytesRead: 0
> - KuduRemoteScanTokens: 0 (0)
> - NumScannerThreadsStarted: 40 (40)
> - PeakMemoryUsage: 5.65 MB (5919744)
> - RowsRead: 2.00B (2000027549)
> - RowsReturned: 2.00B (2000027549)
> - RowsReturnedRate: 230.22 M/sec
> - ScanRangesComplete: 40 (40)
> - ScannerThreadsInvoluntaryContextSwitches: 2.79K (2794)
> - ScannerThreadsTotalWallClockTime: 6h
> - MaterializeTupleTime(*): 8s466ms
> - ScannerThreadsSysTime: 55s996ms
> - ScannerThreadsUserTime: 2m7s
> - ScannerThreadsVoluntaryContextSwitches: 1.99M (1994345)
> - TotalKuduScanRoundTrips: 7.88K (7880)
> - TotalReadThroughput: 0.00 /sec
> {code}
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)