You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@impala.apache.org by meijie <me...@yandex.com> on 2018/08/02 07:31:37 UTC
Slow sql because NumScannerThreadsStarted is 1
Hi, Every One
I found the sql (select * from parquet_session_1 where browser =
'Firefox 20') was very slow at my impala cluster. which needed 15
seconds to executed and NumScannerThreadsStarted is 1 , it wasn't as
expected.
the part profile as blew：
- FooterProcessingTime: (Avg: 4.430ms ; Min: 2.924ms ; Max:
9.559ms ; Number of samples: 9)
- AverageHdfsReadThreadConcurrency: 0.00
- AverageScannerThreadConcurrency: 1.00
- BytesRead: 2.13 GB (2288275802)
- BytesReadDataNodeCache: 0
- BytesReadLocal: 2.13 GB (2288275802)
- BytesReadRemoteUnexpected: 0
- BytesReadShortCircuit: 2.13 GB (2288275802)
- CachedFileHandlesHitCount: 0 (0)
- CachedFileHandlesMissCount: 171 (171)
- CollectionItemsRead: 0 (0)
- DecompressionTime: 3s264ms
- MaxCompressedTextFileLength: 0
- NumColumns: 18 (18)
- NumDictFilteredRowGroups: 0 (0)
- NumDisksAccessed: 5 (5)
- NumRowGroups: 9 (9)
- NumScannerThreadsStarted: 1 (1)
- NumScannersWithNoReads: 0 (0)
- NumStatsFilteredRowGroups: 0 (0)
- PeakMemoryUsage: 143.25 MB (150207517)
- PerReadThreadRawHdfsThroughput: 1.30 GB/sec
- RemoteScanRanges: 0 (0)
- RowBatchQueueGetWaitTime: 14s216ms
- RowBatchQueuePutWaitTime: 0.000ns
- RowsRead: 51.90M (51903646)
- RowsReturned: 93 (93)
- RowsReturnedRate: 6.00 /sec
- ScanRangesComplete: 9 (9)
- ScannerThreadsInvoluntaryContextSwitches: 18 (18)
- ScannerThreadsTotalWallClockTime: 14s678ms
- MaterializeTupleTime(*): 10s639ms
- ScannerThreadsSysTime: 698.325ms
- ScannerThreadsUserTime: 13s452ms
- ScannerThreadsVoluntaryContextSwitches: 1.38K (1382)
- TotalRawHdfsReadTime(*): 1s637ms
- TotalReadThroughput: 148.73 MB/sec
But, if I only select one column(select uuid from parquet_session_1
where browser = 'Firefox 20'), It just needed 0.5 seconds and
NumScannerThreadsStarted is 4. I don't know what affects the number of
scan threads.
Impala Version: 2.11.0-cdh5.14.0 RELEASE, the sql submitted by impala-shell
Thanks
--
Best Regard
meijie
Re: Slow sql because NumScannerThreadsStarted is 1
Posted by Tim Armstrong <ta...@cloudera.com>.
Thanks, that helps!
There are a number of reasons why more scanner threads may not be started:
- Not enough parallelism possible (e.g. only scanning one Parquet file)
- Other concurrent queries using many threads (we have a soft limit of 3
* number of logical cores threads per impalad)
- Not enough memory to start a new thread (based on an estimate of
memory consumption
I think in your case it's probably memory - the estimate for Parquet is 3 *
8MB * <number of columns scanned>, so 432MB. Your query's memory limit is
400MB so it will think that it can't start a second thread without running
out of memory.
That's probably a bit too conservative for your use case. You could speed
it up by reducing the number of columns scanned (i.e. replace select * with
a shorter list) or by increasing the mem_limit for the query.
By coincidence I'm working on refining this heuristic for our next 3.1
release, since it's often too conservative.
On Thu, Aug 2, 2018 at 7:34 PM, meijie <me...@yandex.com> wrote:
> Thank you for your response. blew is complete profile
>
> Query Runtime Profile:
> Query (id=b4f4f6493e9fe5a:fc9961d600000000):
> Summary:
> Session ID: ef47d3119c267424:d9df967cefd5a883
> Session Type: BEESWAX
> Start Time: 2018-08-03 09:38:45.127171000
> End Time: 2018-08-03 09:39:02.285440000
> Query Type: QUERY
> Query State: FINISHED
> Query Status: OK
> Impala Version: impalad version 2.11.0-cdh5.14.0 RELEASE (build
> d68206561bce6b26762d62c01a78e6cd27aa7690)
> User: root
> Connected User: root
> Delegated User:
> Network Address: ::ffff:172.16.20.50:55138
> Default Db: bigdb_press_test
> Sql Statement: select * from parquet_session_1 where browser =
> 'Firefox 20'
> Coordinator: bigdb01:22000
> Query Options (set by configuration): MEM_LIMIT=419430400
> Query Options (set by configuration and planner):
> MEM_LIMIT=419430400,MT_DOP=0
> Plan:
> ----------------
> Max Per-Host Resource Reservation: Memory=0B
> Per-Host Resource Estimates: Memory=1.55GB
>
> F01:PLAN FRAGMENT [UNPARTITIONED] hosts=1 instances=1
> | Per-Host Resources: mem-estimate=0B mem-reservation=0B
> PLAN-ROOT SINK
> | mem-estimate=0B mem-reservation=0B
> |
> 01:EXCHANGE [UNPARTITIONED]
> | mem-estimate=0B mem-reservation=0B
> | tuple-ids=0 row-size=396B cardinality=1140504
> |
> F00:PLAN FRAGMENT [RANDOM] hosts=3 instances=3
> Per-Host Resources: mem-estimate=1.55GB mem-reservation=0B
> 00:SCAN HDFS [bigdb_press_test.parquet_session_1, RANDOM]
> partitions=1/1 files=27 size=6.37GB
> predicates: browser = 'Firefox 20'
> stats-rows=155108551 extrapolated-rows=disabled
> table stats: rows=155108551 size=6.37GB
> column stats: all
> parquet statistics predicates: browser = 'Firefox 20'
> parquet dictionary predicates: browser = 'Firefox 20'
> mem-estimate=1.55GB mem-reservation=0B
> tuple-ids=0 row-size=396B cardinality=1140504
> ----------------
> Estimated Per-Host Mem: 1660944384
> Per Host Min Reservation: bigdb01:22000(0) bigdb02:22000(0)
> bigdb03:22000(0)
> Request Pool: root.default
> Admission result: Admitted immediately
> ExecSummary:
> Operator #Hosts Avg Time Max Time #Rows Est. #Rows Peak Mem
> Est. Peak Mem Detail
> ------------------------------------------------------------
> ---------------------------------------------------------------
> 01:EXCHANGE 1 16s927ms 16s927ms 286 1.14M
> 0 0 UNPARTITIONED
> 00:SCAN HDFS 3 14s876ms 16s448ms 286 1.14M 143.25
> MB 1.55 GB bigdb_press_test.parquet_session_1
> Errors:
> Planner Timeline: 4.874ms
> - Analysis finished: 1.479ms (1.479ms)
> - Value transfer graph computed: 1.694ms (215.699us)
> - Single node plan created: 3.140ms (1.445ms)
> - Runtime filters computed: 3.256ms (116.502us)
> - Distributed plan created: 3.324ms (67.434us)
> - Lineage info computed: 3.467ms (143.587us)
> - Planning finished: 4.874ms (1.406ms)
> Query Timeline: 17s161ms
> - Query submitted: 75.337us (75.337us)
> - Planning finished: 6.136ms (6.061ms)
> - Submit for admission: 6.636ms (500.206us)
> - Completed admission: 6.716ms (79.190us)
> - Ready to start on 3 backends: 6.935ms (219.689us)
> - All 3 execution backends (4 fragment instances) started: 8.842ms
> (1.906ms)
> - Rows available: 351.212ms (342.370ms)
> - First row fetched: 441.198ms (89.985ms)
> - Unregister query: 17s158ms (16s717ms)
> - ComputeScanRangeAssignmentTimer: 109.935us
> ImpalaServer:
> - ClientFetchWaitTimer: 280.979ms
> - RowMaterializationTimer: 16s526ms
> Execution Profile b4f4f6493e9fe5a:fc9961d600000000:(Total: 16s870ms,
> non-child: 0.000ns, % non-child: 0.00%)
> Number of filters: 0
> Filter routing table:
> ID Src. Node Tgt. Node(s) Target type Partition filter Pending
> (Expected) First arrived Completed Enabled
> ------------------------------------------------------------
> -------------------------------------------------------
>
> Backend startup latencies: Count: 3, min / max: 1ms / 2ms, 25th %-ile:
> 1ms, 50th %-ile: 2ms, 75th %-ile: 2ms, 90th %-ile: 2ms, 95th %-ile: 2ms,
> 99.9th %-ile: 2ms
> Per Node Peak Memory Usage: bigdb01:22000(144.57 MB)
> bigdb02:22000(144.09 MB) bigdb03:22000(144.09 MB)
> - FiltersReceived: 0 (0)
> - FinalizationTimer: 0.000ns
> - NumBackends: 3 (3)
> - NumFragmentInstances: 4 (4)
> - NumFragments: 2 (2)
> Averaged Fragment F01:(Total: 16s955ms, non-child: 2.075ms, %
> non-child: 0.01%)
> split sizes: min: 0, max: 0, avg: 0, stddev: 0
> completion times: min:16s957ms max:16s957ms mean: 16s957ms
> stddev:0.000ns
> execution rates: min:0.00 /sec max:0.00 /sec mean:0.00 /sec
> stddev:0.00 /sec
> num instances: 1
> - AverageThreadTokens: 0.00
> - BloomFilterBytes: 0
> - PeakMemoryUsage: 580.02 KB (593936)
> - PeakReservation: 0
> - PeakUsedReservation: 0
> - PerHostPeakMemUsage: 144.57 MB (151595498)
> - RowsProduced: 286 (286)
> - TotalNetworkReceiveTime: 16s926ms
> - TotalNetworkSendTime: 0.000ns
> - TotalStorageWaitTime: 0.000ns
> - TotalThreadsInvoluntaryContextSwitches: 0 (0)
> - TotalThreadsTotalWallClockTime: 16s929ms
> - TotalThreadsSysTime: 849.000us
> - TotalThreadsUserTime: 3.925ms
> - TotalThreadsVoluntaryContextSwitches: 144 (144)
> Fragment Instance Lifecycle Timings:
> - ExecTime: 16s614ms
> - ExecTreeExecTime: 16s612ms
> - OpenTime: 314.632ms
> - ExecTreeOpenTime: 314.614ms
> - PrepareTime: 26.668ms
> - ExecTreePrepareTime: 43.413us
> PLAN_ROOT_SINK:
> - PeakMemoryUsage: 0
> CodeGen:(Total: 26.326ms, non-child: 26.326ms, % non-child: 100.00%)
> - CodegenTime: 0.000ns
> - CompileTime: 0.000ns
> - LoadTime: 0.000ns
> - ModuleBitcodeSize: 1.86 MB (1950884)
> - NumFunctions: 0 (0)
> - NumInstructions: 0 (0)
> - OptimizationTime: 0.000ns
> - PeakMemoryUsage: 0
> - PrepareTime: 25.464ms
> EXCHANGE_NODE (id=1):(Total: 16s927ms, non-child: 16s927ms, %
> non-child: 100.00%)
> - ConvertRowBatchTime: 290.044us
> - PeakMemoryUsage: 0
> - RowsReturned: 286 (286)
> - RowsReturnedRate: 16.00 /sec
> DataStreamReceiver:
> - BytesReceived: 54.30 KB (55602)
> - DeserializeRowBatchTimer: 2.272ms
> - FirstBatchArrivalWaitTime: 314.602ms
> - PeakMemoryUsage: 4.09 KB (4184)
> - SendersBlockedTimer: 0.000ns
> - SendersBlockedTotalTimer(*): 0.000ns
> Coordinator Fragment F01:
> Instance b4f4f6493e9fe5a:fc9961d600000000
> (host=bigdb01:22000):(Total: 16s955ms, non-child: 2.075ms, % non-child:
> 0.01%)
> MemoryUsage(500.000ms): 8.00 KB, 48.01 KB, 80.02 KB, 100.01 KB,
> 116.01 KB, 120.01 KB, 140.02 KB, 152.02 KB, 156.01 KB, 180.01 KB, 204.01
> KB, 232.05 KB, 252.01 KB, 268.02 KB, 284.01 KB, 296.01 KB, 316.01 KB,
> 332.01 KB, 344.01 KB, 364.01 KB, 368.01 KB, 404.01 KB, 436.01 KB, 440.01
> KB, 444.01 KB, 472.01 KB, 484.01 KB, 496.01 KB, 516.01 KB, 528.01 KB,
> 548.01 KB, 556.01 KB, 564.02 KB, 572.01 KB
> - AverageThreadTokens: 0.00
> - BloomFilterBytes: 0
> - PeakMemoryUsage: 580.02 KB (593936)
> - PeakReservation: 0
> - PeakUsedReservation: 0
> - PerHostPeakMemUsage: 144.57 MB (151595498)
> - RowsProduced: 286 (286)
> - TotalNetworkReceiveTime: 16s926ms
> - TotalNetworkSendTime: 0.000ns
> - TotalStorageWaitTime: 0.000ns
> - TotalThreadsInvoluntaryContextSwitches: 0 (0)
> - TotalThreadsTotalWallClockTime: 16s929ms
> - TotalThreadsSysTime: 849.000us
> - TotalThreadsUserTime: 3.925ms
> - TotalThreadsVoluntaryContextSwitches: 144 (144)
> Fragment Instance Lifecycle Timings:
> - ExecTime: 16s614ms
> - ExecTreeExecTime: 16s612ms
> - OpenTime: 314.632ms
> - ExecTreeOpenTime: 314.614ms
> - PrepareTime: 26.668ms
> - ExecTreePrepareTime: 43.413us
> PLAN_ROOT_SINK:
> - PeakMemoryUsage: 0
> CodeGen:(Total: 26.326ms, non-child: 26.326ms, % non-child:
> 100.00%)
> - CodegenTime: 0.000ns
> - CompileTime: 0.000ns
> - LoadTime: 0.000ns
> - ModuleBitcodeSize: 1.86 MB (1950884)
> - NumFunctions: 0 (0)
> - NumInstructions: 0 (0)
> - OptimizationTime: 0.000ns
> - PeakMemoryUsage: 0
> - PrepareTime: 25.464ms
> EXCHANGE_NODE (id=1):(Total: 16s927ms, non-child: 16s927ms, %
> non-child: 100.00%)
> - ConvertRowBatchTime: 290.044us
> - PeakMemoryUsage: 0
> - RowsReturned: 286 (286)
> - RowsReturnedRate: 16.00 /sec
> DataStreamReceiver:
> BytesReceived(500.000ms): 0, 3.67 KB, 7.30 KB, 9.67 KB, 10.76
> KB, 11.00 KB, 14.20 KB, 16.04 KB, 16.27 KB, 19.18 KB, 22.14 KB, 25.12 KB,
> 26.80 KB, 29.04 KB, 30.00 KB, 30.68 KB, 32.34 KB, 34.66 KB, 35.48 KB, 36.65
> KB, 36.91 KB, 39.72 KB, 42.90 KB, 43.14 KB, 43.39 KB, 45.58 KB, 46.29 KB,
> 47.24 KB, 48.57 KB, 50.38 KB, 51.53 KB, 52.24 KB, 52.95 KB, 53.84 KB
> - BytesReceived: 54.30 KB (55602)
> - DeserializeRowBatchTimer: 2.272ms
> - FirstBatchArrivalWaitTime: 314.602ms
> - PeakMemoryUsage: 4.09 KB (4184)
> - SendersBlockedTimer: 0.000ns
> - SendersBlockedTotalTimer(*): 0.000ns
> Averaged Fragment F00:(Total: 15s383ms, non-child: 436.851ms, %
> non-child: 2.84%)
> split sizes: min: 2.12 GB, max: 2.13 GB, avg: 2.12 GB, stddev: 5.95
> MB
> completion times: min:13s654ms max:16s956ms mean: 15s385ms
> stddev:1s352ms
> execution rates: min:128.65 MB/sec max:158.83 MB/sec mean:142.33
> MB/sec stddev:12.48 MB/sec
> num instances: 3
> - AverageThreadTokens: 1.99
> - BloomFilterBytes: 0
> - PeakMemoryUsage: 144.09 MB (151090554)
> - PeakReservation: 0
> - PeakUsedReservation: 0
> - PerHostPeakMemUsage: 144.25 MB (151259858)
> - RowsProduced: 95 (95)
> - TotalNetworkReceiveTime: 0.000ns
> - TotalNetworkSendTime: 21.262us
> - TotalStorageWaitTime: 456.615ms
> - TotalThreadsInvoluntaryContextSwitches: 50 (50)
> - TotalThreadsTotalWallClockTime: 30s671ms
> - TotalThreadsSysTime: 1s040ms
> - TotalThreadsUserTime: 14s297ms
> - TotalThreadsVoluntaryContextSwitches: 1.22K (1222)
> Fragment Instance Lifecycle Timings:
> - ExecTime: 15s314ms
> - ExecTreeExecTime: 14s876ms
> - OpenTime: 43.132ms
> - ExecTreeOpenTime: 44.527us
> - PrepareTime: 26.101ms
> - ExecTreePrepareTime: 214.813us
> DataStreamSender (dst_id=1):(Total: 3.177ms, non-child: 3.177ms, %
> non-child: 100.00%)
> - BytesSent: 18.10 KB (18534)
> - NetworkThroughput(*): 9.20 MB/sec
> - OverallThroughput: 5.57 MB/sec
> - PeakMemoryUsage: 456.00 B (456)
> - RowsReturned: 95 (95)
> - SerializeBatchTime: 1.049ms
> - TransmitDataRPCTime: 1.944ms
> - UncompressedRowBatchSize: 38.43 KB (39355)
> CodeGen:(Total: 67.190ms, non-child: 67.190ms, % non-child: 100.00%)
> - CodegenTime: 1.256ms
> - CompileTime: 10.469ms
> - LoadTime: 0.000ns
> - ModuleBitcodeSize: 1.86 MB (1950884)
> - NumFunctions: 32 (32)
> - NumInstructions: 483 (483)
> - OptimizationTime: 31.695ms
> - PeakMemoryUsage: 241.50 KB (247296)
> - PrepareTime: 24.214ms
> HDFS_SCAN_NODE (id=0):(Total: 14s876ms, non-child: 14s876ms, %
> non-child: 100.00%)
> - AverageHdfsReadThreadConcurrency: 0.13
> - AverageScannerThreadConcurrency: 1.00
> - BytesRead: 2.04 GB (2192368083)
> - BytesReadDataNodeCache: 0
> - BytesReadLocal: 2.04 GB (2192368083)
> - BytesReadRemoteUnexpected: 0
> - BytesReadShortCircuit: 2.04 GB (2192368083)
> - CachedFileHandlesHitCount: 0 (0)
> - CachedFileHandlesMissCount: 165 (165)
> - CollectionItemsRead: 0 (0)
> - DecompressionTime: 3s516ms
> - MaxCompressedTextFileLength: 0
> - NumColumns: 18 (18)
> - NumDictFilteredRowGroups: 0 (0)
> - NumDisksAccessed: 4 (4)
> - NumRowGroups: 9 (9)
> - NumScannerThreadsStarted: 1 (1)
> - NumScannersWithNoReads: 0 (0)
> - NumStatsFilteredRowGroups: 0 (0)
> - PeakMemoryUsage: 143.22 MB (150173543)
> - PerReadThreadRawHdfsThroughput: 1.58 GB/sec
> - RemoteScanRanges: 0 (0)
> - RowBatchQueueGetWaitTime: 14s871ms
> - RowBatchQueuePutWaitTime: 0.000ns
> - RowsRead: 49.70M (49702305)
> - RowsReturned: 95 (95)
> - RowsReturnedRate: 5.00 /sec
> - ScanRangesComplete: 9 (9)
> - ScannerThreadsInvoluntaryContextSwitches: 41 (41)
> - ScannerThreadsTotalWallClockTime: 15s313ms
> - MaterializeTupleTime(*): 11s093ms
> - ScannerThreadsSysTime: 645.800ms
> - ScannerThreadsUserTime: 14s202ms
> - ScannerThreadsVoluntaryContextSwitches: 904 (904)
> - TotalRawHdfsReadTime(*): 1s293ms
> - TotalReadThroughput: 136.47 MB/sec
> Fragment F00:
> Instance b4f4f6493e9fe5a:fc9961d600000002
> (host=bigdb02:22000):(Total: 16s955ms, non-child: 435.525ms, % non-child:
> 2.57%)
> Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> 1:1/162.67 MB 0:1/252.38 MB 2:2/504.68 MB 4:3/756.96 MB 3:2/504.74 MB
> MemoryUsage(500.000ms): 8.45 KB, 133.20 MB, 121.00 MB, 109.06 MB,
> 132.29 MB, 133.13 MB, 122.50 MB, 104.69 MB, 128.66 MB, 132.51 MB, 121.07
> MB, 110.50 MB, 86.04 MB, 97.95 MB, 82.56 MB, 121.29 MB, 133.22 MB, 126.65
> MB, 111.19 MB, 130.34 MB, 131.22 MB, 113.42 MB, 103.79 MB, 131.90 MB,
> 122.21 MB, 114.54 MB, 94.17 MB, 132.95 MB, 126.18 MB, 110.78 MB, 12.02 MB,
> 130.73 MB, 121.57 MB, 112.30 MB
> ThreadUsage(500.000ms): 1, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2,
> 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2
> - AverageThreadTokens: 1.97
> - BloomFilterBytes: 0
> - PeakMemoryUsage: 144.09 MB (151092462)
> - PeakReservation: 0
> - PeakUsedReservation: 0
> - PerHostPeakMemUsage: 144.09 MB (151092462)
> - RowsProduced: 93 (93)
> - TotalNetworkReceiveTime: 0.000ns
> - TotalNetworkSendTime: 24.406us
> - TotalStorageWaitTime: 489.566ms
> - TotalThreadsInvoluntaryContextSwitches: 37 (37)
> - TotalThreadsTotalWallClockTime: 33s813ms
> - TotalThreadsSysTime: 1s066ms
> - TotalThreadsUserTime: 15s812ms
> - TotalThreadsVoluntaryContextSwitches: 1.38K (1383)
> Fragment Instance Lifecycle Timings:
> - ExecTime: 16s884ms
> - ExecTreeExecTime: 16s448ms
> - OpenTime: 44.632ms
> - ExecTreeOpenTime: 47.029us
> - PrepareTime: 25.728ms
> - ExecTreePrepareTime: 176.442us
> DataStreamSender (dst_id=1):(Total: 3.196ms, non-child: 3.196ms, %
> non-child: 100.00%)
> - BytesSent: 18.56 KB (19004)
> - NetworkThroughput(*): 9.12 MB/sec
> - OverallThroughput: 5.67 MB/sec
> - PeakMemoryUsage: 456.00 B (456)
> - RowsReturned: 93 (93)
> - SerializeBatchTime: 1.026ms
> - TransmitDataRPCTime: 1.988ms
> - UncompressedRowBatchSize: 37.12 KB (38010)
> CodeGen:(Total: 68.333ms, non-child: 68.333ms, % non-child:
> 100.00%)
> - CodegenTime: 1.251ms
> - CompileTime: 10.833ms
> - LoadTime: 0.000ns
> - ModuleBitcodeSize: 1.86 MB (1950884)
> - NumFunctions: 32 (32)
> - NumInstructions: 483 (483)
> - OptimizationTime: 32.844ms
> - PeakMemoryUsage: 241.50 KB (247296)
> - PrepareTime: 23.839ms
> HDFS_SCAN_NODE (id=0):(Total: 16s448ms, non-child: 16s448ms, %
> non-child: 100.00%)
> Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> 1:1/162.67 MB 0:1/252.38 MB 2:2/504.68 MB 4:3/756.96 MB 3:2/504.74 MB
> ExecOption: PARQUET Codegen Enabled, Codegen enabled: 9 out of 9
> Hdfs Read Thread Concurrency Bucket: 0:81.82% 1:18.18% 2:0% 3:0%
> 4:0% 5:0% 6:0% 7:0% 8:0% 9:0% 10:0% 11:0%
> File Formats: PARQUET/SNAPPY:9
> BytesRead(500.000ms): 0, 134.13 MB, 186.80 MB, 234.80 MB, 354.64
> MB, 402.64 MB, 447.06 MB, 495.06 MB, 614.97 MB, 646.97 MB, 691.70 MB,
> 731.70 MB, 757.29 MB, 866.45 MB, 906.45 MB, 1007.14 MB, 1.05 GB, 1.09 GB,
> 1.14 GB, 1.25 GB, 1.30 GB, 1.34 GB, 1.39 GB, 1.51 GB, 1.56 GB, 1.60 GB,
> 1.64 GB, 1.76 GB, 1.81 GB, 1.86 GB, 1.89 GB, 2.02 GB, 2.07 GB, 2.11 GB
> - FooterProcessingTime: (Avg: 3.282ms ; Min: 1.994ms ; Max:
> 10.196ms ; Number of samples: 9)
> - AverageHdfsReadThreadConcurrency: 0.18
> - AverageScannerThreadConcurrency: 1.00
> - BytesRead: 2.13 GB (2288275802)
> - BytesReadDataNodeCache: 0
> - BytesReadLocal: 2.13 GB (2288275802)
> - BytesReadRemoteUnexpected: 0
> - BytesReadShortCircuit: 2.13 GB (2288275802)
> - CachedFileHandlesHitCount: 0 (0)
> - CachedFileHandlesMissCount: 171 (171)
> - CollectionItemsRead: 0 (0)
> - DecompressionTime: 3s738ms
> - MaxCompressedTextFileLength: 0
> - NumColumns: 18 (18)
> - NumDictFilteredRowGroups: 0 (0)
> - NumDisksAccessed: 5 (5)
> - NumRowGroups: 9 (9)
> - NumScannerThreadsStarted: 1 (1)
> - NumScannersWithNoReads: 0 (0)
> - NumStatsFilteredRowGroups: 0 (0)
> - PeakMemoryUsage: 143.25 MB (150207517)
> - PerReadThreadRawHdfsThroughput: 1.50 GB/sec
> - RemoteScanRanges: 0 (0)
> - RowBatchQueueGetWaitTime: 16s443ms
> - RowBatchQueuePutWaitTime: 0.000ns
> - RowsRead: 51.90M (51903646)
> - RowsReturned: 93 (93)
> - RowsReturnedRate: 5.00 /sec
> - ScanRangesComplete: 9 (9)
> - ScannerThreadsInvoluntaryContextSwitches: 26 (26)
> - ScannerThreadsTotalWallClockTime: 16s884ms
> - MaterializeTupleTime(*): 12s402ms
> - ScannerThreadsSysTime: 667.204ms
> - ScannerThreadsUserTime: 15s717ms
> - ScannerThreadsVoluntaryContextSwitches: 1.05K (1054)
> - TotalRawHdfsReadTime(*): 1s422ms
> - TotalReadThroughput: 127.33 MB/sec
> Instance b4f4f6493e9fe5a:fc9961d600000001
> (host=bigdb01:22000):(Total: 15s542ms, non-child: 413.267ms, % non-child:
> 2.66%)
> Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> 0:1/252.36 MB 3:1/149.88 MB 2:2/504.73 MB 4:1/252.35 MB 1:4/1009.49 MB
> MemoryUsage(500.000ms): 134.10 MB, 133.28 MB, 126.63 MB, 110.79
> MB, 88.39 MB, 134.59 MB, 126.31 MB, 114.98 MB, 91.04 MB, 131.00 MB, 127.24
> MB, 120.06 MB, 90.81 MB, 97.26 MB, 83.69 MB, 129.41 MB, 128.89 MB, 123.06
> MB, 111.92 MB, 89.77 MB, 130.64 MB, 122.12 MB, 106.75 MB, 130.91 MB, 128.53
> MB, 127.94 MB, 110.48 MB, 40.90 MB, 129.82 MB, 122.63 MB, 104.94 MB
> ThreadUsage(500.000ms): 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2,
> 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2
> - AverageThreadTokens: 2.00
> - BloomFilterBytes: 0
> - PeakMemoryUsage: 144.09 MB (151087586)
> - PeakReservation: 0
> - PeakUsedReservation: 0
> - PerHostPeakMemUsage: 144.57 MB (151595498)
> - RowsProduced: 89 (89)
> - TotalNetworkReceiveTime: 0.000ns
> - TotalNetworkSendTime: 17.632us
> - TotalStorageWaitTime: 434.756ms
> - TotalThreadsInvoluntaryContextSwitches: 95 (95)
> - TotalThreadsTotalWallClockTime: 30s991ms
> - TotalThreadsSysTime: 1s050ms
> - TotalThreadsUserTime: 14s447ms
> - TotalThreadsVoluntaryContextSwitches: 874 (874)
> Fragment Instance Lifecycle Timings:
> - ExecTime: 15s475ms
> - ExecTreeExecTime: 15s061ms
> - OpenTime: 40.572ms
> - ExecTreeOpenTime: 41.278us
> - PrepareTime: 26.145ms
> - ExecTreePrepareTime: 222.311us
> DataStreamSender (dst_id=1):(Total: 3.198ms, non-child: 3.198ms, %
> non-child: 100.00%)
> - BytesSent: 16.21 KB (16600)
> - NetworkThroughput(*): 7.50 MB/sec
> - OverallThroughput: 4.95 MB/sec
> - PeakMemoryUsage: 456.00 B (456)
> - RowsReturned: 89 (89)
> - SerializeBatchTime: 856.396us
> - TransmitDataRPCTime: 2.112ms
> - UncompressedRowBatchSize: 36.08 KB (36942)
> CodeGen:(Total: 64.650ms, non-child: 64.650ms, % non-child:
> 100.00%)
> - CodegenTime: 1.228ms
> - CompileTime: 9.773ms
> - LoadTime: 0.000ns
> - ModuleBitcodeSize: 1.86 MB (1950884)
> - NumFunctions: 32 (32)
> - NumInstructions: 483 (483)
> - OptimizationTime: 29.748ms
> - PeakMemoryUsage: 241.50 KB (247296)
> - PrepareTime: 24.331ms
> HDFS_SCAN_NODE (id=0):(Total: 15s061ms, non-child: 15s061ms, %
> non-child: 100.00%)
> Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> 0:1/252.36 MB 3:1/149.88 MB 2:2/504.73 MB 4:1/252.35 MB 1:4/1009.49 MB
> ExecOption: PARQUET Codegen Enabled, Codegen enabled: 9 out of 9
> Hdfs Read Thread Concurrency Bucket: 0:87.1% 1:12.9% 2:0% 3:0%
> 4:0% 5:0% 6:0% 7:0% 8:0% 9:0% 10:0% 11:0%
> File Formats: PARQUET/SNAPPY:8 PARQUET/(NONE,SNAPPY):1
> BytesRead(500.000ms): 102.00 MB, 150.00 MB, 194.70 MB, 226.70
> MB, 252.45 MB, 378.45 MB, 423.23 MB, 463.23 MB, 504.89 MB, 623.15 MB,
> 667.91 MB, 715.91 MB, 757.35 MB, 854.18 MB, 894.18 MB, 1009.41 MB, 1.02 GB,
> 1.07 GB, 1.11 GB, 1.13 GB, 1.26 GB, 1.32 GB, 1.36 GB, 1.48 GB, 1.52 GB,
> 1.56 GB, 1.60 GB, 1.65 GB, 1.77 GB, 1.82 GB, 1.87 GB
> - FooterProcessingTime: (Avg: 3.554ms ; Min: 1.844ms ; Max:
> 13.695ms ; Number of samples: 9)
> - AverageHdfsReadThreadConcurrency: 0.13
> - AverageScannerThreadConcurrency: 1.00
> - BytesRead: 1.88 GB (2013820022)
> - BytesReadDataNodeCache: 0
> - BytesReadLocal: 1.88 GB (2013820022)
> - BytesReadRemoteUnexpected: 0
> - BytesReadShortCircuit: 1.88 GB (2013820022)
> - CachedFileHandlesHitCount: 0 (0)
> - CachedFileHandlesMissCount: 154 (154)
> - CollectionItemsRead: 0 (0)
> - DecompressionTime: 3s506ms
> - MaxCompressedTextFileLength: 0
> - NumColumns: 18 (18)
> - NumDictFilteredRowGroups: 1 (1)
> - NumDisksAccessed: 5 (5)
> - NumRowGroups: 9 (9)
> - NumScannerThreadsStarted: 1 (1)
> - NumScannersWithNoReads: 0 (0)
> - NumStatsFilteredRowGroups: 0 (0)
> - PeakMemoryUsage: 143.15 MB (150100301)
> - PerReadThreadRawHdfsThroughput: 1.56 GB/sec
> - RemoteScanRanges: 0 (0)
> - RowBatchQueueGetWaitTime: 15s057ms
> - RowBatchQueuePutWaitTime: 0.000ns
> - RowsRead: 45.60M (45604014)
> - RowsReturned: 89 (89)
> - RowsReturnedRate: 5.00 /sec
> - ScanRangesComplete: 9 (9)
> - ScannerThreadsInvoluntaryContextSwitches: 82 (82)
> - ScannerThreadsTotalWallClockTime: 15s475ms
> - MaterializeTupleTime(*): 11s276ms
> - ScannerThreadsSysTime: 674.148ms
> - ScannerThreadsUserTime: 14s361ms
> - ScannerThreadsVoluntaryContextSwitches: 567 (567)
> - TotalRawHdfsReadTime(*): 1s202ms
> - TotalReadThroughput: 123.27 MB/sec
> Instance b4f4f6493e9fe5a:fc9961d600000003
> (host=bigdb03:22000):(Total: 13s653ms, non-child: 461.761ms, % non-child:
> 3.38%)
> Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> 2:2/504.66 MB 0:1/252.37 MB 3:3/654.56 MB 1:3/757.17 MB
> MemoryUsage(500.000ms): 132.79 MB, 123.57 MB, 108.74 MB, 97.90 MB,
> 79.75 MB, 129.78 MB, 125.51 MB, 110.49 MB, 69.49 MB, 141.21 MB, 114.37 MB,
> 89.40 MB, 130.39 MB, 121.69 MB, 92.30 MB, 135.26 MB, 127.93 MB, 104.04 MB,
> 130.38 MB, 120.88 MB, 104.35 MB, 132.65 MB, 123.71 MB, 106.08 MB, 130.69
> MB, 123.63 MB, 112.19 MB
> ThreadUsage(500.000ms): 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2,
> 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2
> - AverageThreadTokens: 2.00
> - BloomFilterBytes: 0
> - PeakMemoryUsage: 144.09 MB (151091614)
> - PeakReservation: 0
> - PeakUsedReservation: 0
> - PerHostPeakMemUsage: 144.09 MB (151091614)
> - RowsProduced: 104 (104)
> - TotalNetworkReceiveTime: 0.000ns
> - TotalNetworkSendTime: 21.748us
> - TotalStorageWaitTime: 445.522ms
> - TotalThreadsInvoluntaryContextSwitches: 20 (20)
> - TotalThreadsTotalWallClockTime: 27s208ms
> - TotalThreadsSysTime: 1s005ms
> - TotalThreadsUserTime: 12s631ms
> - TotalThreadsVoluntaryContextSwitches: 1.41K (1410)
> Fragment Instance Lifecycle Timings:
> - ExecTime: 13s582ms
> - ExecTreeExecTime: 13s119ms
> - OpenTime: 44.193ms
> - ExecTreeOpenTime: 45.276us
> - PrepareTime: 26.432ms
> - ExecTreePrepareTime: 245.688us
> DataStreamSender (dst_id=1):(Total: 3.138ms, non-child: 3.138ms, %
> non-child: 100.00%)
> - BytesSent: 19.53 KB (19998)
> - NetworkThroughput(*): 11.00 MB/sec
> - OverallThroughput: 6.08 MB/sec
> - PeakMemoryUsage: 456.00 B (456)
> - RowsReturned: 104 (104)
> - SerializeBatchTime: 1.264ms
> - TransmitDataRPCTime: 1.733ms
> - UncompressedRowBatchSize: 42.10 KB (43114)
> CodeGen:(Total: 68.585ms, non-child: 68.585ms, % non-child:
> 100.00%)
> - CodegenTime: 1.290ms
> - CompileTime: 10.802ms
> - LoadTime: 0.000ns
> - ModuleBitcodeSize: 1.86 MB (1950884)
> - NumFunctions: 32 (32)
> - NumInstructions: 483 (483)
> - OptimizationTime: 32.495ms
> - PeakMemoryUsage: 241.50 KB (247296)
> - PrepareTime: 24.471ms
> HDFS_SCAN_NODE (id=0):(Total: 13s119ms, non-child: 13s119ms, %
> non-child: 100.00%)
> Hdfs split stats (<volume id>:<# splits>/<split lengths>):
> 2:2/504.66 MB 0:1/252.37 MB 3:3/654.56 MB 1:3/757.17 MB
> ExecOption: PARQUET Codegen Enabled, Codegen enabled: 9 out of 9
> Hdfs Read Thread Concurrency Bucket: 0:92.59% 1:7.407% 2:0% 3:0%
> 4:0% 5:0% 6:0% 7:0% 8:0% 9:0% 10:0% 11:0%
> File Formats: PARQUET/SNAPPY:9
> BytesRead(500.000ms): 102.13 MB, 170.89 MB, 226.89 MB, 333.23
> MB, 389.23 MB, 512.37 MB, 565.15 MB, 621.15 MB, 696.90 MB, 804.95 MB,
> 865.63 MB, 907.22 MB, 1.02 GB, 1.08 GB, 1.13 GB, 1.26 GB, 1.32 GB, 1.38 GB,
> 1.50 GB, 1.56 GB, 1.62 GB, 1.74 GB, 1.80 GB, 1.85 GB, 1.99 GB, 2.04 GB,
> 2.09 GB
> - FooterProcessingTime: (Avg: 4.124ms ; Min: 1.805ms ; Max:
> 19.516ms ; Number of samples: 9)
> - AverageHdfsReadThreadConcurrency: 0.07
> - AverageScannerThreadConcurrency: 1.00
> - BytesRead: 2.12 GB (2275008425)
> - BytesReadDataNodeCache: 0
> - BytesReadLocal: 2.12 GB (2275008425)
> - BytesReadRemoteUnexpected: 0
> - BytesReadShortCircuit: 2.12 GB (2275008425)
> - CachedFileHandlesHitCount: 0 (0)
> - CachedFileHandlesMissCount: 171 (171)
> - CollectionItemsRead: 0 (0)
> - DecompressionTime: 3s303ms
> - MaxCompressedTextFileLength: 0
> - NumColumns: 18 (18)
> - NumDictFilteredRowGroups: 0 (0)
> - NumDisksAccessed: 4 (4)
> - NumRowGroups: 9 (9)
> - NumScannerThreadsStarted: 1 (1)
> - NumScannersWithNoReads: 0 (0)
> - NumStatsFilteredRowGroups: 0 (0)
> - PeakMemoryUsage: 143.25 MB (150212813)
> - PerReadThreadRawHdfsThroughput: 1.69 GB/sec
> - RemoteScanRanges: 0 (0)
> - RowBatchQueueGetWaitTime: 13s114ms
> - RowBatchQueuePutWaitTime: 0.000ns
> - RowsRead: 51.60M (51599256)
> - RowsReturned: 104 (104)
> - RowsReturnedRate: 7.00 /sec
> - ScanRangesComplete: 9 (9)
> - ScannerThreadsInvoluntaryContextSwitches: 17 (17)
> - ScannerThreadsTotalWallClockTime: 13s581ms
> - MaterializeTupleTime(*): 9s602ms
> - ScannerThreadsSysTime: 596.050ms
> - ScannerThreadsUserTime: 12s527ms
> - ScannerThreadsVoluntaryContextSwitches: 1.09K (1092)
> - TotalRawHdfsReadTime(*): 1s255ms
> - TotalReadThroughput: 158.81 MB/sec
>
> On 08/03/2018 02:22 AM, Tim Armstrong wrote:
>
> Can you include a complete profile?
>
> On Thu, Aug 2, 2018 at 12:31 AM, meijie <me...@yandex.com> wrote:
>
>> Hi, Every One
>>
>> I found the sql (select * from parquet_session_1 where browser = 'Firefox
>> 20') was very slow at my impala cluster. which needed 15 seconds to
>> executed and NumScannerThreadsStarted is 1 , it wasn't as expected.
>>
>> the part profile as blew：
>>
>> - FooterProcessingTime: (Avg: 4.430ms ; Min: 2.924ms ; Max:
>> 9.559ms ; Number of samples: 9)
>> - AverageHdfsReadThreadConcurrency: 0.00
>> - AverageScannerThreadConcurrency: 1.00
>> - BytesRead: 2.13 GB (2288275802)
>> - BytesReadDataNodeCache: 0
>> - BytesReadLocal: 2.13 GB (2288275802)
>> - BytesReadRemoteUnexpected: 0
>> - BytesReadShortCircuit: 2.13 GB (2288275802)
>> - CachedFileHandlesHitCount: 0 (0)
>> - CachedFileHandlesMissCount: 171 (171)
>> - CollectionItemsRead: 0 (0)
>> - DecompressionTime: 3s264ms
>> - MaxCompressedTextFileLength: 0
>> - NumColumns: 18 (18)
>> - NumDictFilteredRowGroups: 0 (0)
>> - NumDisksAccessed: 5 (5)
>> - NumRowGroups: 9 (9)
>> - NumScannerThreadsStarted: 1 (1)
>> - NumScannersWithNoReads: 0 (0)
>> - NumStatsFilteredRowGroups: 0 (0)
>> - PeakMemoryUsage: 143.25 MB (user150207517)
>> - PerReadThreadRawHdfsThroughput: 1.30 GB/sec
>> - RemoteScanRanges: 0 (0)
>> - RowBatchQueueGetWaitTime: 14s216ms
>> - RowBatchQueuePutWaitTime: 0.000ns
>> - RowsRead: 51.90M (51903646)
>> - RowsReturned: 93 (93)
>> - RowsReturnedRate: 6.00 /sec
>> - ScanRangesComplete: 9 (9)
>> - ScannerThreadsInvoluntaryContextSwitches: 18 (18)
>> - ScannerThreadsTotalWallClockTime: 14s678ms
>> - MaterializeTupleTime(*): 10s639ms
>> - ScannerThreadsSysTime: 698.325ms
>> - ScannerThreadsUserTime: 13s452ms
>> - ScannerThreadsVoluntaryContextSwitches: 1.38K (1382)
>> - TotalRawHdfsReadTime(*): 1s637ms
>> - TotalReadThroughput: 148.73 MB/sec
>>
>> But, if I only select one column(select uuid from parquet_session_1 where
>> browser = 'Firefox 20'), It just needed 0.5 seconds and
>> NumScannerThreadsStarted is 4. I don't know what affects the number of scan
>> threads.
>>
>> Impala Version: 2.11.0-cdh5.14.0 RELEASE, the sql submitted by
>> impala-shell
>>
>> Thanks
>>
>> --
>> Best Regard
>> meijie
>>
>>
>
> --
> Best Regard
> meijie
>
>
Re: Slow sql because NumScannerThreadsStarted is 1
Posted by meijie <me...@yandex.com>.
Thank you for your response. blew is complete profile
Query Runtime Profile:
Query (id=b4f4f6493e9fe5a:fc9961d600000000):
Summary:
Session ID: ef47d3119c267424:d9df967cefd5a883
Session Type: BEESWAX
Start Time: 2018-08-03 09:38:45.127171000
End Time: 2018-08-03 09:39:02.285440000
Query Type: QUERY
Query State: FINISHED
Query Status: OK
Impala Version: impalad version 2.11.0-cdh5.14.0 RELEASE (build
d68206561bce6b26762d62c01a78e6cd27aa7690)
User: root
Connected User: root
Delegated User:
Network Address: ::ffff:172.16.20.50:55138
Default Db: bigdb_press_test
Sql Statement: select * from parquet_session_1 where browser =
'Firefox 20'
Coordinator: bigdb01:22000
Query Options (set by configuration): MEM_LIMIT=419430400
Query Options (set by configuration and planner):
MEM_LIMIT=419430400,MT_DOP=0
Plan:
----------------
Max Per-Host Resource Reservation: Memory=0B
Per-Host Resource Estimates: Memory=1.55GB
F01:PLAN FRAGMENT [UNPARTITIONED] hosts=1 instances=1
| Per-Host Resources: mem-estimate=0B mem-reservation=0B
PLAN-ROOT SINK
| mem-estimate=0B mem-reservation=0B
|
01:EXCHANGE [UNPARTITIONED]
| mem-estimate=0B mem-reservation=0B
| tuple-ids=0 row-size=396B cardinality=1140504
|
F00:PLAN FRAGMENT [RANDOM] hosts=3 instances=3
Per-Host Resources: mem-estimate=1.55GB mem-reservation=0B
00:SCAN HDFS [bigdb_press_test.parquet_session_1, RANDOM]
partitions=1/1 files=27 size=6.37GB
predicates: browser = 'Firefox 20'
stats-rows=155108551 extrapolated-rows=disabled
table stats: rows=155108551 size=6.37GB
column stats: all
parquet statistics predicates: browser = 'Firefox 20'
parquet dictionary predicates: browser = 'Firefox 20'
mem-estimate=1.55GB mem-reservation=0B
tuple-ids=0 row-size=396B cardinality=1140504
----------------
Estimated Per-Host Mem: 1660944384
Per Host Min Reservation: bigdb01:22000(0) bigdb02:22000(0)
bigdb03:22000(0)
Request Pool: root.default
Admission result: Admitted immediately
ExecSummary:
Operator #Hosts Avg Time Max Time #Rows Est. #Rows Peak Mem
Est. Peak Mem Detail
---------------------------------------------------------------------------------------------------------------------------
01:EXCHANGE 1 16s927ms 16s927ms 286 1.14M
0 0 UNPARTITIONED
00:SCAN HDFS 3 14s876ms 16s448ms 286 1.14M 143.25
MB 1.55 GB bigdb_press_test.parquet_session_1
Errors:
Planner Timeline: 4.874ms
- Analysis finished: 1.479ms (1.479ms)
- Value transfer graph computed: 1.694ms (215.699us)
- Single node plan created: 3.140ms (1.445ms)
- Runtime filters computed: 3.256ms (116.502us)
- Distributed plan created: 3.324ms (67.434us)
- Lineage info computed: 3.467ms (143.587us)
- Planning finished: 4.874ms (1.406ms)
Query Timeline: 17s161ms
- Query submitted: 75.337us (75.337us)
- Planning finished: 6.136ms (6.061ms)
- Submit for admission: 6.636ms (500.206us)
- Completed admission: 6.716ms (79.190us)
- Ready to start on 3 backends: 6.935ms (219.689us)
- All 3 execution backends (4 fragment instances) started:
8.842ms (1.906ms)
- Rows available: 351.212ms (342.370ms)
- First row fetched: 441.198ms (89.985ms)
- Unregister query: 17s158ms (16s717ms)
- ComputeScanRangeAssignmentTimer: 109.935us
ImpalaServer:
- ClientFetchWaitTimer: 280.979ms
- RowMaterializationTimer: 16s526ms
Execution Profile b4f4f6493e9fe5a:fc9961d600000000:(Total: 16s870ms,
non-child: 0.000ns, % non-child: 0.00%)
Number of filters: 0
Filter routing table:
ID Src. Node Tgt. Node(s) Target type Partition filter Pending
(Expected) First arrived Completed Enabled
-------------------------------------------------------------------------------------------------------------------
Backend startup latencies: Count: 3, min / max: 1ms / 2ms, 25th
%-ile: 1ms, 50th %-ile: 2ms, 75th %-ile: 2ms, 90th %-ile: 2ms, 95th
%-ile: 2ms, 99.9th %-ile: 2ms
Per Node Peak Memory Usage: bigdb01:22000(144.57 MB)
bigdb02:22000(144.09 MB) bigdb03:22000(144.09 MB)
- FiltersReceived: 0 (0)
- FinalizationTimer: 0.000ns
- NumBackends: 3 (3)
- NumFragmentInstances: 4 (4)
- NumFragments: 2 (2)
Averaged Fragment F01:(Total: 16s955ms, non-child: 2.075ms, %
non-child: 0.01%)
split sizes: min: 0, max: 0, avg: 0, stddev: 0
completion times: min:16s957ms max:16s957ms mean: 16s957ms
stddev:0.000ns
execution rates: min:0.00 /sec max:0.00 /sec mean:0.00 /sec
stddev:0.00 /sec
num instances: 1
- AverageThreadTokens: 0.00
- BloomFilterBytes: 0
- PeakMemoryUsage: 580.02 KB (593936)
- PeakReservation: 0
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 144.57 MB (151595498)
- RowsProduced: 286 (286)
- TotalNetworkReceiveTime: 16s926ms
- TotalNetworkSendTime: 0.000ns
- TotalStorageWaitTime: 0.000ns
- TotalThreadsInvoluntaryContextSwitches: 0 (0)
- TotalThreadsTotalWallClockTime: 16s929ms
- TotalThreadsSysTime: 849.000us
- TotalThreadsUserTime: 3.925ms
- TotalThreadsVoluntaryContextSwitches: 144 (144)
Fragment Instance Lifecycle Timings:
- ExecTime: 16s614ms
- ExecTreeExecTime: 16s612ms
- OpenTime: 314.632ms
- ExecTreeOpenTime: 314.614ms
- PrepareTime: 26.668ms
- ExecTreePrepareTime: 43.413us
PLAN_ROOT_SINK:
- PeakMemoryUsage: 0
CodeGen:(Total: 26.326ms, non-child: 26.326ms, % non-child: 100.00%)
- CodegenTime: 0.000ns
- CompileTime: 0.000ns
- LoadTime: 0.000ns
- ModuleBitcodeSize: 1.86 MB (1950884)
- NumFunctions: 0 (0)
- NumInstructions: 0 (0)
- OptimizationTime: 0.000ns
- PeakMemoryUsage: 0
- PrepareTime: 25.464ms
EXCHANGE_NODE (id=1):(Total: 16s927ms, non-child: 16s927ms, %
non-child: 100.00%)
- ConvertRowBatchTime: 290.044us
- PeakMemoryUsage: 0
- RowsReturned: 286 (286)
- RowsReturnedRate: 16.00 /sec
DataStreamReceiver:
- BytesReceived: 54.30 KB (55602)
- DeserializeRowBatchTimer: 2.272ms
- FirstBatchArrivalWaitTime: 314.602ms
- PeakMemoryUsage: 4.09 KB (4184)
- SendersBlockedTimer: 0.000ns
- SendersBlockedTotalTimer(*): 0.000ns
Coordinator Fragment F01:
Instance b4f4f6493e9fe5a:fc9961d600000000
(host=bigdb01:22000):(Total: 16s955ms, non-child: 2.075ms, % non-child:
0.01%)
MemoryUsage(500.000ms): 8.00 KB, 48.01 KB, 80.02 KB, 100.01 KB,
116.01 KB, 120.01 KB, 140.02 KB, 152.02 KB, 156.01 KB, 180.01 KB, 204.01
KB, 232.05 KB, 252.01 KB, 268.02 KB, 284.01 KB, 296.01 KB, 316.01 KB,
332.01 KB, 344.01 KB, 364.01 KB, 368.01 KB, 404.01 KB, 436.01 KB, 440.01
KB, 444.01 KB, 472.01 KB, 484.01 KB, 496.01 KB, 516.01 KB, 528.01 KB,
548.01 KB, 556.01 KB, 564.02 KB, 572.01 KB
- AverageThreadTokens: 0.00
- BloomFilterBytes: 0
- PeakMemoryUsage: 580.02 KB (593936)
- PeakReservation: 0
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 144.57 MB (151595498)
- RowsProduced: 286 (286)
- TotalNetworkReceiveTime: 16s926ms
- TotalNetworkSendTime: 0.000ns
- TotalStorageWaitTime: 0.000ns
- TotalThreadsInvoluntaryContextSwitches: 0 (0)
- TotalThreadsTotalWallClockTime: 16s929ms
- TotalThreadsSysTime: 849.000us
- TotalThreadsUserTime: 3.925ms
- TotalThreadsVoluntaryContextSwitches: 144 (144)
Fragment Instance Lifecycle Timings:
- ExecTime: 16s614ms
- ExecTreeExecTime: 16s612ms
- OpenTime: 314.632ms
- ExecTreeOpenTime: 314.614ms
- PrepareTime: 26.668ms
- ExecTreePrepareTime: 43.413us
PLAN_ROOT_SINK:
- PeakMemoryUsage: 0
CodeGen:(Total: 26.326ms, non-child: 26.326ms, % non-child:
100.00%)
- CodegenTime: 0.000ns
- CompileTime: 0.000ns
- LoadTime: 0.000ns
- ModuleBitcodeSize: 1.86 MB (1950884)
- NumFunctions: 0 (0)
- NumInstructions: 0 (0)
- OptimizationTime: 0.000ns
- PeakMemoryUsage: 0
- PrepareTime: 25.464ms
EXCHANGE_NODE (id=1):(Total: 16s927ms, non-child: 16s927ms, %
non-child: 100.00%)
- ConvertRowBatchTime: 290.044us
- PeakMemoryUsage: 0
- RowsReturned: 286 (286)
- RowsReturnedRate: 16.00 /sec
DataStreamReceiver:
BytesReceived(500.000ms): 0, 3.67 KB, 7.30 KB, 9.67 KB,
10.76 KB, 11.00 KB, 14.20 KB, 16.04 KB, 16.27 KB, 19.18 KB, 22.14 KB,
25.12 KB, 26.80 KB, 29.04 KB, 30.00 KB, 30.68 KB, 32.34 KB, 34.66 KB,
35.48 KB, 36.65 KB, 36.91 KB, 39.72 KB, 42.90 KB, 43.14 KB, 43.39 KB,
45.58 KB, 46.29 KB, 47.24 KB, 48.57 KB, 50.38 KB, 51.53 KB, 52.24 KB,
52.95 KB, 53.84 KB
- BytesReceived: 54.30 KB (55602)
- DeserializeRowBatchTimer: 2.272ms
- FirstBatchArrivalWaitTime: 314.602ms
- PeakMemoryUsage: 4.09 KB (4184)
- SendersBlockedTimer: 0.000ns
- SendersBlockedTotalTimer(*): 0.000ns
Averaged Fragment F00:(Total: 15s383ms, non-child: 436.851ms, %
non-child: 2.84%)
split sizes: min: 2.12 GB, max: 2.13 GB, avg: 2.12 GB, stddev:
5.95 MB
completion times: min:13s654ms max:16s956ms mean: 15s385ms
stddev:1s352ms
execution rates: min:128.65 MB/sec max:158.83 MB/sec mean:142.33
MB/sec stddev:12.48 MB/sec
num instances: 3
- AverageThreadTokens: 1.99
- BloomFilterBytes: 0
- PeakMemoryUsage: 144.09 MB (151090554)
- PeakReservation: 0
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 144.25 MB (151259858)
- RowsProduced: 95 (95)
- TotalNetworkReceiveTime: 0.000ns
- TotalNetworkSendTime: 21.262us
- TotalStorageWaitTime: 456.615ms
- TotalThreadsInvoluntaryContextSwitches: 50 (50)
- TotalThreadsTotalWallClockTime: 30s671ms
- TotalThreadsSysTime: 1s040ms
- TotalThreadsUserTime: 14s297ms
- TotalThreadsVoluntaryContextSwitches: 1.22K (1222)
Fragment Instance Lifecycle Timings:
- ExecTime: 15s314ms
- ExecTreeExecTime: 14s876ms
- OpenTime: 43.132ms
- ExecTreeOpenTime: 44.527us
- PrepareTime: 26.101ms
- ExecTreePrepareTime: 214.813us
DataStreamSender (dst_id=1):(Total: 3.177ms, non-child: 3.177ms,
% non-child: 100.00%)
- BytesSent: 18.10 KB (18534)
- NetworkThroughput(*): 9.20 MB/sec
- OverallThroughput: 5.57 MB/sec
- PeakMemoryUsage: 456.00 B (456)
- RowsReturned: 95 (95)
- SerializeBatchTime: 1.049ms
- TransmitDataRPCTime: 1.944ms
- UncompressedRowBatchSize: 38.43 KB (39355)
CodeGen:(Total: 67.190ms, non-child: 67.190ms, % non-child: 100.00%)
- CodegenTime: 1.256ms
- CompileTime: 10.469ms
- LoadTime: 0.000ns
- ModuleBitcodeSize: 1.86 MB (1950884)
- NumFunctions: 32 (32)
- NumInstructions: 483 (483)
- OptimizationTime: 31.695ms
- PeakMemoryUsage: 241.50 KB (247296)
- PrepareTime: 24.214ms
HDFS_SCAN_NODE (id=0):(Total: 14s876ms, non-child: 14s876ms, %
non-child: 100.00%)
- AverageHdfsReadThreadConcurrency: 0.13
- AverageScannerThreadConcurrency: 1.00
- BytesRead: 2.04 GB (2192368083)
- BytesReadDataNodeCache: 0
- BytesReadLocal: 2.04 GB (2192368083)
- BytesReadRemoteUnexpected: 0
- BytesReadShortCircuit: 2.04 GB (2192368083)
- CachedFileHandlesHitCount: 0 (0)
- CachedFileHandlesMissCount: 165 (165)
- CollectionItemsRead: 0 (0)
- DecompressionTime: 3s516ms
- MaxCompressedTextFileLength: 0
- NumColumns: 18 (18)
- NumDictFilteredRowGroups: 0 (0)
- NumDisksAccessed: 4 (4)
- NumRowGroups: 9 (9)
- NumScannerThreadsStarted: 1 (1)
- NumScannersWithNoReads: 0 (0)
- NumStatsFilteredRowGroups: 0 (0)
- PeakMemoryUsage: 143.22 MB (150173543)
- PerReadThreadRawHdfsThroughput: 1.58 GB/sec
- RemoteScanRanges: 0 (0)
- RowBatchQueueGetWaitTime: 14s871ms
- RowBatchQueuePutWaitTime: 0.000ns
- RowsRead: 49.70M (49702305)
- RowsReturned: 95 (95)
- RowsReturnedRate: 5.00 /sec
- ScanRangesComplete: 9 (9)
- ScannerThreadsInvoluntaryContextSwitches: 41 (41)
- ScannerThreadsTotalWallClockTime: 15s313ms
- MaterializeTupleTime(*): 11s093ms
- ScannerThreadsSysTime: 645.800ms
- ScannerThreadsUserTime: 14s202ms
- ScannerThreadsVoluntaryContextSwitches: 904 (904)
- TotalRawHdfsReadTime(*): 1s293ms
- TotalReadThroughput: 136.47 MB/sec
Fragment F00:
Instance b4f4f6493e9fe5a:fc9961d600000002
(host=bigdb02:22000):(Total: 16s955ms, non-child: 435.525ms, %
non-child: 2.57%)
Hdfs split stats (<volume id>:<# splits>/<split lengths>):
1:1/162.67 MB 0:1/252.38 MB 2:2/504.68 MB 4:3/756.96 MB 3:2/504.74 MB
MemoryUsage(500.000ms): 8.45 KB, 133.20 MB, 121.00 MB, 109.06
MB, 132.29 MB, 133.13 MB, 122.50 MB, 104.69 MB, 128.66 MB, 132.51 MB,
121.07 MB, 110.50 MB, 86.04 MB, 97.95 MB, 82.56 MB, 121.29 MB, 133.22
MB, 126.65 MB, 111.19 MB, 130.34 MB, 131.22 MB, 113.42 MB, 103.79 MB,
131.90 MB, 122.21 MB, 114.54 MB, 94.17 MB, 132.95 MB, 126.18 MB, 110.78
MB, 12.02 MB, 130.73 MB, 121.57 MB, 112.30 MB
ThreadUsage(500.000ms): 1, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2,
2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2
- AverageThreadTokens: 1.97
- BloomFilterBytes: 0
- PeakMemoryUsage: 144.09 MB (151092462)
- PeakReservation: 0
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 144.09 MB (151092462)
- RowsProduced: 93 (93)
- TotalNetworkReceiveTime: 0.000ns
- TotalNetworkSendTime: 24.406us
- TotalStorageWaitTime: 489.566ms
- TotalThreadsInvoluntaryContextSwitches: 37 (37)
- TotalThreadsTotalWallClockTime: 33s813ms
- TotalThreadsSysTime: 1s066ms
- TotalThreadsUserTime: 15s812ms
- TotalThreadsVoluntaryContextSwitches: 1.38K (1383)
Fragment Instance Lifecycle Timings:
- ExecTime: 16s884ms
- ExecTreeExecTime: 16s448ms
- OpenTime: 44.632ms
- ExecTreeOpenTime: 47.029us
- PrepareTime: 25.728ms
- ExecTreePrepareTime: 176.442us
DataStreamSender (dst_id=1):(Total: 3.196ms, non-child:
3.196ms, % non-child: 100.00%)
- BytesSent: 18.56 KB (19004)
- NetworkThroughput(*): 9.12 MB/sec
- OverallThroughput: 5.67 MB/sec
- PeakMemoryUsage: 456.00 B (456)
- RowsReturned: 93 (93)
- SerializeBatchTime: 1.026ms
- TransmitDataRPCTime: 1.988ms
- UncompressedRowBatchSize: 37.12 KB (38010)
CodeGen:(Total: 68.333ms, non-child: 68.333ms, % non-child:
100.00%)
- CodegenTime: 1.251ms
- CompileTime: 10.833ms
- LoadTime: 0.000ns
- ModuleBitcodeSize: 1.86 MB (1950884)
- NumFunctions: 32 (32)
- NumInstructions: 483 (483)
- OptimizationTime: 32.844ms
- PeakMemoryUsage: 241.50 KB (247296)
- PrepareTime: 23.839ms
HDFS_SCAN_NODE (id=0):(Total: 16s448ms, non-child: 16s448ms, %
non-child: 100.00%)
Hdfs split stats (<volume id>:<# splits>/<split lengths>):
1:1/162.67 MB 0:1/252.38 MB 2:2/504.68 MB 4:3/756.96 MB 3:2/504.74 MB
ExecOption: PARQUET Codegen Enabled, Codegen enabled: 9 out of 9
Hdfs Read Thread Concurrency Bucket: 0:81.82% 1:18.18% 2:0%
3:0% 4:0% 5:0% 6:0% 7:0% 8:0% 9:0% 10:0% 11:0%
File Formats: PARQUET/SNAPPY:9
BytesRead(500.000ms): 0, 134.13 MB, 186.80 MB, 234.80 MB,
354.64 MB, 402.64 MB, 447.06 MB, 495.06 MB, 614.97 MB, 646.97 MB, 691.70
MB, 731.70 MB, 757.29 MB, 866.45 MB, 906.45 MB, 1007.14 MB, 1.05 GB,
1.09 GB, 1.14 GB, 1.25 GB, 1.30 GB, 1.34 GB, 1.39 GB, 1.51 GB, 1.56 GB,
1.60 GB, 1.64 GB, 1.76 GB, 1.81 GB, 1.86 GB, 1.89 GB, 2.02 GB, 2.07 GB,
2.11 GB
- FooterProcessingTime: (Avg: 3.282ms ; Min: 1.994ms ; Max:
10.196ms ; Number of samples: 9)
- AverageHdfsReadThreadConcurrency: 0.18
- AverageScannerThreadConcurrency: 1.00
- BytesRead: 2.13 GB (2288275802)
- BytesReadDataNodeCache: 0
- BytesReadLocal: 2.13 GB (2288275802)
- BytesReadRemoteUnexpected: 0
- BytesReadShortCircuit: 2.13 GB (2288275802)
- CachedFileHandlesHitCount: 0 (0)
- CachedFileHandlesMissCount: 171 (171)
- CollectionItemsRead: 0 (0)
- DecompressionTime: 3s738ms
- MaxCompressedTextFileLength: 0
- NumColumns: 18 (18)
- NumDictFilteredRowGroups: 0 (0)
- NumDisksAccessed: 5 (5)
- NumRowGroups: 9 (9)
- NumScannerThreadsStarted: 1 (1)
- NumScannersWithNoReads: 0 (0)
- NumStatsFilteredRowGroups: 0 (0)
- PeakMemoryUsage: 143.25 MB (150207517)
- PerReadThreadRawHdfsThroughput: 1.50 GB/sec
- RemoteScanRanges: 0 (0)
- RowBatchQueueGetWaitTime: 16s443ms
- RowBatchQueuePutWaitTime: 0.000ns
- RowsRead: 51.90M (51903646)
- RowsReturned: 93 (93)
- RowsReturnedRate: 5.00 /sec
- ScanRangesComplete: 9 (9)
- ScannerThreadsInvoluntaryContextSwitches: 26 (26)
- ScannerThreadsTotalWallClockTime: 16s884ms
- MaterializeTupleTime(*): 12s402ms
- ScannerThreadsSysTime: 667.204ms
- ScannerThreadsUserTime: 15s717ms
- ScannerThreadsVoluntaryContextSwitches: 1.05K (1054)
- TotalRawHdfsReadTime(*): 1s422ms
- TotalReadThroughput: 127.33 MB/sec
Instance b4f4f6493e9fe5a:fc9961d600000001
(host=bigdb01:22000):(Total: 15s542ms, non-child: 413.267ms, %
non-child: 2.66%)
Hdfs split stats (<volume id>:<# splits>/<split lengths>):
0:1/252.36 MB 3:1/149.88 MB 2:2/504.73 MB 4:1/252.35 MB 1:4/1009.49 MB
MemoryUsage(500.000ms): 134.10 MB, 133.28 MB, 126.63 MB, 110.79
MB, 88.39 MB, 134.59 MB, 126.31 MB, 114.98 MB, 91.04 MB, 131.00 MB,
127.24 MB, 120.06 MB, 90.81 MB, 97.26 MB, 83.69 MB, 129.41 MB, 128.89
MB, 123.06 MB, 111.92 MB, 89.77 MB, 130.64 MB, 122.12 MB, 106.75 MB,
130.91 MB, 128.53 MB, 127.94 MB, 110.48 MB, 40.90 MB, 129.82 MB, 122.63
MB, 104.94 MB
ThreadUsage(500.000ms): 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2,
2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2
- AverageThreadTokens: 2.00
- BloomFilterBytes: 0
- PeakMemoryUsage: 144.09 MB (151087586)
- PeakReservation: 0
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 144.57 MB (151595498)
- RowsProduced: 89 (89)
- TotalNetworkReceiveTime: 0.000ns
- TotalNetworkSendTime: 17.632us
- TotalStorageWaitTime: 434.756ms
- TotalThreadsInvoluntaryContextSwitches: 95 (95)
- TotalThreadsTotalWallClockTime: 30s991ms
- TotalThreadsSysTime: 1s050ms
- TotalThreadsUserTime: 14s447ms
- TotalThreadsVoluntaryContextSwitches: 874 (874)
Fragment Instance Lifecycle Timings:
- ExecTime: 15s475ms
- ExecTreeExecTime: 15s061ms
- OpenTime: 40.572ms
- ExecTreeOpenTime: 41.278us
- PrepareTime: 26.145ms
- ExecTreePrepareTime: 222.311us
DataStreamSender (dst_id=1):(Total: 3.198ms, non-child:
3.198ms, % non-child: 100.00%)
- BytesSent: 16.21 KB (16600)
- NetworkThroughput(*): 7.50 MB/sec
- OverallThroughput: 4.95 MB/sec
- PeakMemoryUsage: 456.00 B (456)
- RowsReturned: 89 (89)
- SerializeBatchTime: 856.396us
- TransmitDataRPCTime: 2.112ms
- UncompressedRowBatchSize: 36.08 KB (36942)
CodeGen:(Total: 64.650ms, non-child: 64.650ms, % non-child:
100.00%)
- CodegenTime: 1.228ms
- CompileTime: 9.773ms
- LoadTime: 0.000ns
- ModuleBitcodeSize: 1.86 MB (1950884)
- NumFunctions: 32 (32)
- NumInstructions: 483 (483)
- OptimizationTime: 29.748ms
- PeakMemoryUsage: 241.50 KB (247296)
- PrepareTime: 24.331ms
HDFS_SCAN_NODE (id=0):(Total: 15s061ms, non-child: 15s061ms, %
non-child: 100.00%)
Hdfs split stats (<volume id>:<# splits>/<split lengths>):
0:1/252.36 MB 3:1/149.88 MB 2:2/504.73 MB 4:1/252.35 MB 1:4/1009.49 MB
ExecOption: PARQUET Codegen Enabled, Codegen enabled: 9 out of 9
Hdfs Read Thread Concurrency Bucket: 0:87.1% 1:12.9% 2:0%
3:0% 4:0% 5:0% 6:0% 7:0% 8:0% 9:0% 10:0% 11:0%
File Formats: PARQUET/SNAPPY:8 PARQUET/(NONE,SNAPPY):1
BytesRead(500.000ms): 102.00 MB, 150.00 MB, 194.70 MB, 226.70
MB, 252.45 MB, 378.45 MB, 423.23 MB, 463.23 MB, 504.89 MB, 623.15 MB,
667.91 MB, 715.91 MB, 757.35 MB, 854.18 MB, 894.18 MB, 1009.41 MB, 1.02
GB, 1.07 GB, 1.11 GB, 1.13 GB, 1.26 GB, 1.32 GB, 1.36 GB, 1.48 GB, 1.52
GB, 1.56 GB, 1.60 GB, 1.65 GB, 1.77 GB, 1.82 GB, 1.87 GB
- FooterProcessingTime: (Avg: 3.554ms ; Min: 1.844ms ; Max:
13.695ms ; Number of samples: 9)
- AverageHdfsReadThreadConcurrency: 0.13
- AverageScannerThreadConcurrency: 1.00
- BytesRead: 1.88 GB (2013820022)
- BytesReadDataNodeCache: 0
- BytesReadLocal: 1.88 GB (2013820022)
- BytesReadRemoteUnexpected: 0
- BytesReadShortCircuit: 1.88 GB (2013820022)
- CachedFileHandlesHitCount: 0 (0)
- CachedFileHandlesMissCount: 154 (154)
- CollectionItemsRead: 0 (0)
- DecompressionTime: 3s506ms
- MaxCompressedTextFileLength: 0
- NumColumns: 18 (18)
- NumDictFilteredRowGroups: 1 (1)
- NumDisksAccessed: 5 (5)
- NumRowGroups: 9 (9)
- NumScannerThreadsStarted: 1 (1)
- NumScannersWithNoReads: 0 (0)
- NumStatsFilteredRowGroups: 0 (0)
- PeakMemoryUsage: 143.15 MB (150100301)
- PerReadThreadRawHdfsThroughput: 1.56 GB/sec
- RemoteScanRanges: 0 (0)
- RowBatchQueueGetWaitTime: 15s057ms
- RowBatchQueuePutWaitTime: 0.000ns
- RowsRead: 45.60M (45604014)
- RowsReturned: 89 (89)
- RowsReturnedRate: 5.00 /sec
- ScanRangesComplete: 9 (9)
- ScannerThreadsInvoluntaryContextSwitches: 82 (82)
- ScannerThreadsTotalWallClockTime: 15s475ms
- MaterializeTupleTime(*): 11s276ms
- ScannerThreadsSysTime: 674.148ms
- ScannerThreadsUserTime: 14s361ms
- ScannerThreadsVoluntaryContextSwitches: 567 (567)
- TotalRawHdfsReadTime(*): 1s202ms
- TotalReadThroughput: 123.27 MB/sec
Instance b4f4f6493e9fe5a:fc9961d600000003
(host=bigdb03:22000):(Total: 13s653ms, non-child: 461.761ms, %
non-child: 3.38%)
Hdfs split stats (<volume id>:<# splits>/<split lengths>):
2:2/504.66 MB 0:1/252.37 MB 3:3/654.56 MB 1:3/757.17 MB
MemoryUsage(500.000ms): 132.79 MB, 123.57 MB, 108.74 MB, 97.90
MB, 79.75 MB, 129.78 MB, 125.51 MB, 110.49 MB, 69.49 MB, 141.21 MB,
114.37 MB, 89.40 MB, 130.39 MB, 121.69 MB, 92.30 MB, 135.26 MB, 127.93
MB, 104.04 MB, 130.38 MB, 120.88 MB, 104.35 MB, 132.65 MB, 123.71 MB,
106.08 MB, 130.69 MB, 123.63 MB, 112.19 MB
ThreadUsage(500.000ms): 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2,
2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2
- AverageThreadTokens: 2.00
- BloomFilterBytes: 0
- PeakMemoryUsage: 144.09 MB (151091614)
- PeakReservation: 0
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 144.09 MB (151091614)
- RowsProduced: 104 (104)
- TotalNetworkReceiveTime: 0.000ns
- TotalNetworkSendTime: 21.748us
- TotalStorageWaitTime: 445.522ms
- TotalThreadsInvoluntaryContextSwitches: 20 (20)
- TotalThreadsTotalWallClockTime: 27s208ms
- TotalThreadsSysTime: 1s005ms
- TotalThreadsUserTime: 12s631ms
- TotalThreadsVoluntaryContextSwitches: 1.41K (1410)
Fragment Instance Lifecycle Timings:
- ExecTime: 13s582ms
- ExecTreeExecTime: 13s119ms
- OpenTime: 44.193ms
- ExecTreeOpenTime: 45.276us
- PrepareTime: 26.432ms
- ExecTreePrepareTime: 245.688us
DataStreamSender (dst_id=1):(Total: 3.138ms, non-child:
3.138ms, % non-child: 100.00%)
- BytesSent: 19.53 KB (19998)
- NetworkThroughput(*): 11.00 MB/sec
- OverallThroughput: 6.08 MB/sec
- PeakMemoryUsage: 456.00 B (456)
- RowsReturned: 104 (104)
- SerializeBatchTime: 1.264ms
- TransmitDataRPCTime: 1.733ms
- UncompressedRowBatchSize: 42.10 KB (43114)
CodeGen:(Total: 68.585ms, non-child: 68.585ms, % non-child:
100.00%)
- CodegenTime: 1.290ms
- CompileTime: 10.802ms
- LoadTime: 0.000ns
- ModuleBitcodeSize: 1.86 MB (1950884)
- NumFunctions: 32 (32)
- NumInstructions: 483 (483)
- OptimizationTime: 32.495ms
- PeakMemoryUsage: 241.50 KB (247296)
- PrepareTime: 24.471ms
HDFS_SCAN_NODE (id=0):(Total: 13s119ms, non-child: 13s119ms, %
non-child: 100.00%)
Hdfs split stats (<volume id>:<# splits>/<split lengths>):
2:2/504.66 MB 0:1/252.37 MB 3:3/654.56 MB 1:3/757.17 MB
ExecOption: PARQUET Codegen Enabled, Codegen enabled: 9 out of 9
Hdfs Read Thread Concurrency Bucket: 0:92.59% 1:7.407% 2:0%
3:0% 4:0% 5:0% 6:0% 7:0% 8:0% 9:0% 10:0% 11:0%
File Formats: PARQUET/SNAPPY:9
BytesRead(500.000ms): 102.13 MB, 170.89 MB, 226.89 MB, 333.23
MB, 389.23 MB, 512.37 MB, 565.15 MB, 621.15 MB, 696.90 MB, 804.95 MB,
865.63 MB, 907.22 MB, 1.02 GB, 1.08 GB, 1.13 GB, 1.26 GB, 1.32 GB, 1.38
GB, 1.50 GB, 1.56 GB, 1.62 GB, 1.74 GB, 1.80 GB, 1.85 GB, 1.99 GB, 2.04
GB, 2.09 GB
- FooterProcessingTime: (Avg: 4.124ms ; Min: 1.805ms ; Max:
19.516ms ; Number of samples: 9)
- AverageHdfsReadThreadConcurrency: 0.07
- AverageScannerThreadConcurrency: 1.00
- BytesRead: 2.12 GB (2275008425)
- BytesReadDataNodeCache: 0
- BytesReadLocal: 2.12 GB (2275008425)
- BytesReadRemoteUnexpected: 0
- BytesReadShortCircuit: 2.12 GB (2275008425)
- CachedFileHandlesHitCount: 0 (0)
- CachedFileHandlesMissCount: 171 (171)
- CollectionItemsRead: 0 (0)
- DecompressionTime: 3s303ms
- MaxCompressedTextFileLength: 0
- NumColumns: 18 (18)
- NumDictFilteredRowGroups: 0 (0)
- NumDisksAccessed: 4 (4)
- NumRowGroups: 9 (9)
- NumScannerThreadsStarted: 1 (1)
- NumScannersWithNoReads: 0 (0)
- NumStatsFilteredRowGroups: 0 (0)
- PeakMemoryUsage: 143.25 MB (150212813)
- PerReadThreadRawHdfsThroughput: 1.69 GB/sec
- RemoteScanRanges: 0 (0)
- RowBatchQueueGetWaitTime: 13s114ms
- RowBatchQueuePutWaitTime: 0.000ns
- RowsRead: 51.60M (51599256)
- RowsReturned: 104 (104)
- RowsReturnedRate: 7.00 /sec
- ScanRangesComplete: 9 (9)
- ScannerThreadsInvoluntaryContextSwitches: 17 (17)
- ScannerThreadsTotalWallClockTime: 13s581ms
- MaterializeTupleTime(*): 9s602ms
- ScannerThreadsSysTime: 596.050ms
- ScannerThreadsUserTime: 12s527ms
- ScannerThreadsVoluntaryContextSwitches: 1.09K (1092)
- TotalRawHdfsReadTime(*): 1s255ms
- TotalReadThroughput: 158.81 MB/sec
On 08/03/2018 02:22 AM, Tim Armstrong wrote:
> Can you include a complete profile?
>
> On Thu, Aug 2, 2018 at 12:31 AM, meijie <meijies@yandex.com
> <ma...@yandex.com>> wrote:
>
> Hi, Every One
>
> I found the sql (select * from parquet_session_1 where browser =
> 'Firefox 20') was very slow at my impala cluster. which needed 15
> seconds to executed and NumScannerThreadsStarted is 1 , it wasn't
> as expected.
>
> the part profile as blew：
>
> - FooterProcessingTime: (Avg: 4.430ms ; Min: 2.924ms ;
> Max: 9.559ms ; Number of samples: 9)
> - AverageHdfsReadThreadConcurrency: 0.00
> - AverageScannerThreadConcurrency: 1.00
> - BytesRead: 2.13 GB (2288275802)
> - BytesReadDataNodeCache: 0
> - BytesReadLocal: 2.13 GB (2288275802)
> - BytesReadRemoteUnexpected: 0
> - BytesReadShortCircuit: 2.13 GB (2288275802)
> - CachedFileHandlesHitCount: 0 (0)
> - CachedFileHandlesMissCount: 171 (171)
> - CollectionItemsRead: 0 (0)
> - DecompressionTime: 3s264ms
> - MaxCompressedTextFileLength: 0
> - NumColumns: 18 (18)
> - NumDictFilteredRowGroups: 0 (0)
> - NumDisksAccessed: 5 (5)
> - NumRowGroups: 9 (9)
> - NumScannerThreadsStarted: 1 (1)
> - NumScannersWithNoReads: 0 (0)
> - NumStatsFilteredRowGroups: 0 (0)
> - PeakMemoryUsage: 143.25 MB (user150207517)
> - PerReadThreadRawHdfsThroughput: 1.30 GB/sec
> - RemoteScanRanges: 0 (0)
> - RowBatchQueueGetWaitTime: 14s216ms
> - RowBatchQueuePutWaitTime: 0.000ns
> - RowsRead: 51.90M (51903646)
> - RowsReturned: 93 (93)
> - RowsReturnedRate: 6.00 /sec
> - ScanRangesComplete: 9 (9)
> - ScannerThreadsInvoluntaryContextSwitches: 18 (18)
> - ScannerThreadsTotalWallClockTime: 14s678ms
> - MaterializeTupleTime(*): 10s639ms
> - ScannerThreadsSysTime: 698.325ms
> - ScannerThreadsUserTime: 13s452ms
> - ScannerThreadsVoluntaryContextSwitches: 1.38K (1382)
> - TotalRawHdfsReadTime(*): 1s637ms
> - TotalReadThroughput: 148.73 MB/sec
>
> But, if I only select one column(select uuid from
> parquet_session_1 where browser = 'Firefox 20'), It just needed
> 0.5 seconds and NumScannerThreadsStarted is 4. I don't know what
> affects the number of scan threads.
>
> Impala Version: 2.11.0-cdh5.14.0 RELEASE, the sql submitted by
> impala-shell
>
> Thanks
>
> --
> Best Regard
> meijie
>
>
--
Best Regard
meijie
Re: Slow sql because NumScannerThreadsStarted is 1
Posted by Tim Armstrong <ta...@cloudera.com>.
Can you include a complete profile?
On Thu, Aug 2, 2018 at 12:31 AM, meijie <me...@yandex.com> wrote:
> Hi, Every One
>
> I found the sql (select * from parquet_session_1 where browser = 'Firefox
> 20') was very slow at my impala cluster. which needed 15 seconds to
> executed and NumScannerThreadsStarted is 1 , it wasn't as expected.
>
> the part profile as blew：
>
> - FooterProcessingTime: (Avg: 4.430ms ; Min: 2.924ms ; Max:
> 9.559ms ; Number of samples: 9)
> - AverageHdfsReadThreadConcurrency: 0.00
> - AverageScannerThreadConcurrency: 1.00
> - BytesRead: 2.13 GB (2288275802)
> - BytesReadDataNodeCache: 0
> - BytesReadLocal: 2.13 GB (2288275802)
> - BytesReadRemoteUnexpected: 0
> - BytesReadShortCircuit: 2.13 GB (2288275802)
> - CachedFileHandlesHitCount: 0 (0)
> - CachedFileHandlesMissCount: 171 (171)
> - CollectionItemsRead: 0 (0)
> - DecompressionTime: 3s264ms
> - MaxCompressedTextFileLength: 0
> - NumColumns: 18 (18)
> - NumDictFilteredRowGroups: 0 (0)
> - NumDisksAccessed: 5 (5)
> - NumRowGroups: 9 (9)
> - NumScannerThreadsStarted: 1 (1)
> - NumScannersWithNoReads: 0 (0)
> - NumStatsFilteredRowGroups: 0 (0)
> - PeakMemoryUsage: 143.25 MB (150207517)
> - PerReadThreadRawHdfsThroughput: 1.30 GB/sec
> - RemoteScanRanges: 0 (0)
> - RowBatchQueueGetWaitTime: 14s216ms
> - RowBatchQueuePutWaitTime: 0.000ns
> - RowsRead: 51.90M (51903646)
> - RowsReturned: 93 (93)
> - RowsReturnedRate: 6.00 /sec
> - ScanRangesComplete: 9 (9)
> - ScannerThreadsInvoluntaryContextSwitches: 18 (18)
> - ScannerThreadsTotalWallClockTime: 14s678ms
> - MaterializeTupleTime(*): 10s639ms
> - ScannerThreadsSysTime: 698.325ms
> - ScannerThreadsUserTime: 13s452ms
> - ScannerThreadsVoluntaryContextSwitches: 1.38K (1382)
> - TotalRawHdfsReadTime(*): 1s637ms
> - TotalReadThroughput: 148.73 MB/sec
>
> But, if I only select one column(select uuid from parquet_session_1 where
> browser = 'Firefox 20'), It just needed 0.5 seconds and
> NumScannerThreadsStarted is 4. I don't know what affects the number of scan
> threads.
>
> Impala Version: 2.11.0-cdh5.14.0 RELEASE, the sql submitted by impala-shell
>
> Thanks
>
> --
> Best Regard
> meijie
>
>