Created 08-18-2020 07:43 AM
Hi,
I used Impala 2.11 before (CDH 5.14) and I noticed that query runtime used to be roughly the same when we query a table or when we query a view of that table (the view statement is a select of all columns in the table). My tables (and the respective views) have around 400 columns.
However, since I moved to Impala 3.2.0 (CDH 6.3.1), I noticed a degradation while querying views of up to 6 times increase in runtime. When I created a test view that contained only the columns used in my query, I noticed that runtime becomes closer from selecting the actual table.
This seems to be a regressed issue, because this was not present on previous Impala versions, as far as I know. Could you please explain what changed on Impala's behavior on 3.2.0, which started to cause this discrepancy?
Since Impala 3.2.0 is the last version released in CDH, I would like to know if this problem was already tracked and handle in some Impala version after that.
Thanks!
Created 08-18-2020 09:40 AM
Additional info: pretty much all the difference in runtime is due to query compilation and planning. The actual execution time is the same for tables and views.
I also don't have any joins, just selection of a column and a simple aggregation. For example:
Created on 08-19-2020 10:22 AM - edited 08-19-2020 10:25 AM
I'm not aware of any significant regressions in planning time between those versions. There were actually some major improvements for some common types of complex queries with many columns - https://issues.apache.org/jira/browse/IMPALA-4242
So there's no known issue that this obviously maps to (the problem described is quite abstract so take that with a grain of salt). There were a couple of issues related to authorization and Sentry that I initially thought about but I believe had been addressed by 6.3.1 (keep in mind that there are quite a lot of improvements in CDH6.3.1 relative to Impala 3.2.0). Anyway I don't want to speculate too much without even knowing which part of planning may be slow.
Can you provide query profiles for those queries? Or if that isn't possible, at least the "Query Timeline" and "Planner Timeline" for the fast and slow queries.
Edit: just to be clear, the info you provided about the views was useful, but this seems like it's probably something pretty specific to your queries so it's likely any investigation is going to be most fruitful starting from data about the specific queries in your environment.
Created 08-19-2020 02:49 PM
Hi Tim,
Thanks for your reply.
Please find below the profile for the 3 scenarios:
1) querying the table directly
Query Runtime Profile:
Query (id=ac4f8093207cddaf:b37ffcb700000000):
Summary:
Session ID: de4fee1bba7b5c62:7e6351f590447c9f
Session Type: BEESWAX
Start Time: 2020-08-18 12:12:01.344591000
End Time: 2020-08-18 12:12:01.671599000
Query Type: QUERY
Query State: FINISHED
Query Status: OK
Impala Version: impalad version 3.2.0-cdh6.3.1 RELEASE (build 3d5de689e9b9cfde0c01e1c64f4b4e830cee69c3)
Default Db: default
Sql Statement: SELECT sum(column1) from db.table_test where partition_col = 1597431600
Coordinator: impalad-0:22000
Query Options (set by configuration): NUM_SCANNER_THREADS=8,QUERY_TIMEOUT_S=600,SCRATCH_LIMIT=137438953472,CLIENT_IDENTIFIER=Impala Shell v3.2.0-cdh6.3.1 (3d5de68) built on Thu Sep 26 03:03:52 PDT 2019
Query Options (set by configuration and planner): NUM_SCANNER_THREADS=8,QUERY_TIMEOUT_S=600,MT_DOP=0,SCRATCH_LIMIT=137438953472,CLIENT_IDENTIFIER=Impala Shell v3.2.0-cdh6.3.1 (3d5de68) built on Thu Sep 26 03:03:52 PDT 2019
Plan:
----------------
Max Per-Host Resource Reservation: Memory=4.00MB Threads=3
Per-Host Resource Estimates: Memory=100MB
WARNING: The following tables are missing relevant table and/or column statistics.
db.table_test
Analyzed query: SELECT sum(CAST(column1 AS BIGINT)) FROM
db.table_test WHERE partition_col =
CAST(1597431600 AS BIGINT)
F01:PLAN FRAGMENT [UNPARTITIONED] hosts=1 instances=1
| Per-Host Resources: mem-estimate=10.02MB mem-reservation=0B thread-reservation=1
PLAN-ROOT SINK
| mem-estimate=0B mem-reservation=0B thread-reservation=0
|
03:AGGREGATE [FINALIZE]
| output: sum:merge(column1)
| mem-estimate=10.00MB mem-reservation=0B spill-buffer=2.00MB thread-reservation=0
| tuple-ids=1 row-size=8B cardinality=1
| in pipelines: 03(GETNEXT), 01(OPEN)
|
02:EXCHANGE [UNPARTITIONED]
| mem-estimate=16.00KB mem-reservation=0B thread-reservation=0
| tuple-ids=1 row-size=8B cardinality=1
| in pipelines: 01(GETNEXT)
|
F00:PLAN FRAGMENT [RANDOM] hosts=1 instances=1
Per-Host Resources: mem-estimate=90.00MB mem-reservation=4.00MB thread-reservation=2
01:AGGREGATE
| output: sum(CAST(column1 AS BIGINT))
| mem-estimate=10.00MB mem-reservation=0B spill-buffer=2.00MB thread-reservation=0
| tuple-ids=1 row-size=8B cardinality=1
| in pipelines: 01(GETNEXT), 00(OPEN)
|
00:SCAN HDFS [db.table_test, RANDOM]
partition predicates: partition_col = CAST(1597431600 AS BIGINT)
partitions=1/7 files=1 size=67.53MB
stored statistics:
table: rows=unavailable size=unavailable
partitions: 0/1 rows=unavailable
columns missing stats: column1
extrapolated-rows=disabled max-scan-range-rows=unavailable
mem-estimate=80.00MB mem-reservation=4.00MB thread-reservation=1
tuple-ids=0 row-size=4B cardinality=unavailable
in pipelines: 00(GETNEXT)
----------------
Estimated Per-Host Mem: 104873984
Tables Missing Stats: db.table_test
Per Host Min Memory Reservation: impalad-0:22000(4.00 MB)
Request Pool: root.default
Admission result: Admitted immediately
Cluster Memory Admitted: 100.02 MB
ExecSummary:
Operator #Hosts Avg Time Max Time #Rows Est. #Rows Peak Mem Est. Peak Mem Detail
---------------------------------------------------------------------------------------------------------------------------------------------
F01:ROOT 1 0.000ns 0.000ns 0 0
03:AGGREGATE 1 0.000ns 0.000ns 1 1 16.00 KB 10.00 MB FINALIZE
02:EXCHANGE 1 0.000ns 0.000ns 1 1 16.00 KB 16.00 KB UNPARTITIONED
F00:EXCHANGE SENDER 1 0.000ns 0.000ns 14.22 KB 0
01:AGGREGATE 1 63.998ms 63.998ms 1 1 21.00 KB 10.00 MB
00:SCAN HDFS 1 135.997ms 135.997ms 6.76M -1 4.54 MB 80.00 MB db.table_test
Errors:
Query Compilation: 4.934ms
- Metadata of all 1 tables cached: 599.546us (599.546us)
- Analysis finished: 1.364ms (764.845us)
- Value transfer graph computed: 1.396ms (31.936us)
- Single node plan created: 1.935ms (538.745us)
- Runtime filters computed: 2.080ms (145.119us)
- Distributed plan created: 2.113ms (33.569us)
- Planning finished: 4.934ms (2.820ms)
Query Timeline: 339.994ms
- Query submitted: 3.999ms (3.999ms)
- Planning finished: 11.999ms (7.999ms)
- Submit for admission: 11.999ms (0.000ns)
- Completed admission: 11.999ms (0.000ns)
- Ready to start on 1 backends: 11.999ms (0.000ns)
- All 1 execution backends (2 fragment instances) started: 23.999ms (11.999ms)
- Rows available: 323.994ms (299.995ms)
- First row fetched: 323.994ms (0.000ns)
- Last row fetched: 327.994ms (3.999ms)
- Released admission control resources: 327.994ms (0.000ns)
- Unregister query: 331.994ms (3.999ms)
- AdmissionControlTimeSinceLastUpdate: 101.000ms
- ComputeScanRangeAssignmentTimer: 0.000ns
Frontend:
ImpalaServer:
- ClientFetchWaitTimer: 3.999ms
- RowMaterializationTimer: 3.999ms
Execution Profile ac4f8093207cddaf:b37ffcb700000000:(Total: 315.995ms, 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: 1, min / max: 4ms / 4ms, 25th %-ile: 4ms, 50th %-ile: 4ms, 75th %-ile: 4ms, 90th %-ile: 4ms, 95th %-ile: 4ms, 99.9th %-ile: 4ms
Slowest backend to start up: impalad-0:22000
Per Node Peak Memory Usage: impalad-0:22000(4.59 MB)
Per Node Bytes Read: impalad-0:22000(100.48 KB)
Per Node User Time: impalad-0:22000(340.628ms)
Per Node System Time: impalad-0:22000(12.985ms)
- ExchangeScanRatio: 0.00
- FiltersReceived: 0 (0)
- FinalizationTimer: 0.000ns
- InnerNodeSelectivityRatio: 0.00
- NumBackends: 1 (1)
- NumFragmentInstances: 2 (2)
- NumFragments: 2 (2)
- TotalBytesRead: 100.48 KB (102895)
- TotalBytesSent: 13.00 B (13)
- TotalCpuTime: 353.613ms
- TotalInnerBytesSent: 0
- TotalScanBytesSent: 13.00 B (13)
Per Node Profiles:
impalad-0:22000:
- ScratchBytesRead: 0
- ScratchBytesWritten: 0
- ScratchFileUsedBytes: 0
- ScratchReads: 0 (0)
- ScratchWrites: 0 (0)
- TotalEncryptionTime: 0.000ns
- TotalReadBlockTime: 0.000ns
Averaged Fragment F01:(Total: 299.995ms, non-child: 0.000ns, % non-child: 0.00%)
split sizes: min: 0, max: 0, avg: 0, stddev: 0
completion times: min:303.995ms max:303.995ms mean: 303.995ms 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
- ExchangeScanRatio: 0.00
- PeakMemoryUsage: 40.00 KB (40960)
- PeakReservation: 0
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 4.59 MB (4813462)
- RowsProduced: 1 (1)
- TotalNetworkReceiveTime: 251.996ms
- TotalNetworkSendTime: 0.000ns
- TotalStorageWaitTime: 0.000ns
- TotalThreadsInvoluntaryContextSwitches: 5 (5)
- TotalThreadsTotalWallClockTime: 299.995ms
- TotalThreadsSysTime: 0.000ns
- TotalThreadsUserTime: 47.515ms
- TotalThreadsVoluntaryContextSwitches: 3 (3)
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 0
- CumulativeAllocations: 0 (0)
- PeakReservation: 0
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 0
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- ReservationLimit: 0
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Fragment Instance Lifecycle Timings:
- ExecTime: 0.000ns
- ExecTreeExecTime: 0.000ns
- OpenTime: 299.995ms
- ExecTreeOpenTime: 251.996ms
- PrepareTime: 0.000ns
- ExecTreePrepareTime: 0.000ns
PLAN_ROOT_SINK:
- PeakMemoryUsage: 0
AGGREGATION_NODE (id=3):(Total: 251.996ms, non-child: 0.000ns, % non-child: 0.00%)
- PeakMemoryUsage: 16.00 KB (16384)
- RowsReturned: 1 (1)
- RowsReturnedRate: 3.00 /sec
NonGroupingAggregator 0:
- BuildTime: 0.000ns
- PeakMemoryUsage: 8.00 KB (8192)
- RowsReturned: 1 (1)
EXCHANGE_NODE (id=2):(Total: 251.996ms, non-child: 251.996ms, % non-child: 100.00%)
- ConvertRowBatchTime: 0.000ns
- PeakMemoryUsage: 16.00 KB (16384)
- RowsReturned: 1 (1)
- RowsReturnedRate: 3.00 /sec
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 16.00 KB (16384)
- CumulativeAllocations: 2 (2)
- PeakReservation: 16.00 KB (16384)
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 16.00 KB (16384)
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Dequeue:
- FirstBatchWaitTime: 251.996ms
- TotalBytesDequeued: 17.00 B (17)
- TotalGetBatchTime: 251.996ms
- DataWaitTime: 251.996ms
Enqueue:
- DeserializeRowBatchTime: 0.000ns
- TotalBatchesEnqueued: 1 (1)
- TotalBatchesReceived: 1 (1)
- TotalBytesReceived: 13.00 B (13)
- TotalEarlySenders: 0 (0)
- TotalEosReceived: 1 (1)
- TotalHasDeferredRPCsTime: 0.000ns
- TotalRPCsDeferred: 0 (0)
CodeGen:(Total: 47.999ms, non-child: 47.999ms, % non-child: 100.00%)
- CodegenInvoluntaryContextSwitches: 5 (5)
- CodegenTotalWallClockTime: 47.999ms
- CodegenSysTime: 0.000ns
- CodegenUserTime: 46.197ms
- CodegenVoluntaryContextSwitches: 1 (1)
- CompileTime: 0.000ns
- IrGenerationTime: 0.000ns
- LoadTime: 0.000ns
- ModuleBitcodeSize: 2.28 MB (2393476)
- NumFunctions: 0 (0)
- NumInstructions: 0 (0)
- OptimizationTime: 0.000ns
- PeakMemoryUsage: 0
- PrepareTime: 47.999ms
Coordinator Fragment F01:
Instance ac4f8093207cddaf:b37ffcb700000000 (host=impalad-0:22000):(Total: 299.995ms, non-child: 0.000ns, % non-child: 0.00%)
Last report received time: 2020-08-18 12:12:01.671
Fragment Instance Lifecycle Event Timeline: 307.995ms
- Prepare Finished: 7.999ms (7.999ms)
- Open Finished: 307.995ms (299.995ms)
- First Batch Produced: 307.995ms (0.000ns)
- First Batch Sent: 307.995ms (0.000ns)
- ExecInternal Finished: 307.995ms (0.000ns)
- AverageThreadTokens: 0.00
- BloomFilterBytes: 0
- ExchangeScanRatio: 0.00
- PeakMemoryUsage: 40.00 KB (40960)
- PeakReservation: 0
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 4.59 MB (4813462)
- RowsProduced: 1 (1)
- TotalNetworkReceiveTime: 251.996ms
- TotalNetworkSendTime: 0.000ns
- TotalStorageWaitTime: 0.000ns
- TotalThreadsInvoluntaryContextSwitches: 5 (5)
- TotalThreadsTotalWallClockTime: 299.995ms
- TotalThreadsSysTime: 0.000ns
- TotalThreadsUserTime: 47.515ms
- TotalThreadsVoluntaryContextSwitches: 3 (3)
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 0
- CumulativeAllocations: 0 (0)
- PeakReservation: 0
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 0
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- ReservationLimit: 0
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Fragment Instance Lifecycle Timings:
- ExecTime: 0.000ns
- ExecTreeExecTime: 0.000ns
- OpenTime: 299.995ms
- ExecTreeOpenTime: 251.996ms
- PrepareTime: 0.000ns
- ExecTreePrepareTime: 0.000ns
PLAN_ROOT_SINK:
- PeakMemoryUsage: 0
AGGREGATION_NODE (id=3):(Total: 251.996ms, non-child: 0.000ns, % non-child: 0.00%)
Node Lifecycle Event Timeline: 307.995ms
- Open Started: 55.999ms (55.999ms)
- Open Finished: 307.995ms (251.996ms)
- First Batch Requested: 307.995ms (0.000ns)
- First Batch Returned: 307.995ms (0.000ns)
- Last Batch Returned: 307.995ms (0.000ns)
- Closed: 307.995ms (0.000ns)
- PeakMemoryUsage: 16.00 KB (16384)
- RowsReturned: 1 (1)
- RowsReturnedRate: 3.00 /sec
NonGroupingAggregator 0:
- BuildTime: 0.000ns
- PeakMemoryUsage: 8.00 KB (8192)
- RowsReturned: 1 (1)
EXCHANGE_NODE (id=2):(Total: 251.996ms, non-child: 0.000ns, % non-child: 0.00%)
Node Lifecycle Event Timeline: 307.995ms
- Open Started: 55.999ms (55.999ms)
- Open Finished: 307.995ms (251.996ms)
- First Batch Requested: 307.995ms (0.000ns)
- First Batch Returned: 307.995ms (0.000ns)
- Last Batch Returned: 307.995ms (0.000ns)
- Closed: 307.995ms (0.000ns)
- ConvertRowBatchTime: 0.000ns
- PeakMemoryUsage: 16.00 KB (16384)
- RowsReturned: 1 (1)
- RowsReturnedRate: 3.00 /sec
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 16.00 KB (16384)
- CumulativeAllocations: 2 (2)
- PeakReservation: 16.00 KB (16384)
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 16.00 KB (16384)
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Dequeue:
- FirstBatchWaitTime: 251.996ms
- TotalBytesDequeued: 17.00 B (17)
- TotalGetBatchTime: 251.996ms
- DataWaitTime: 251.996ms
Enqueue:
- DispatchTime: (Avg: 60.827us ; Min: 60.827us ; Max: 60.827us ; Number of samples: 1)
- DeserializeRowBatchTime: 0.000ns
- TotalBatchesEnqueued: 1 (1)
- TotalBatchesReceived: 1 (1)
- TotalBytesReceived: 13.00 B (13)
- TotalEarlySenders: 0 (0)
- TotalEosReceived: 1 (1)
- TotalHasDeferredRPCsTime: 0.000ns
- TotalRPCsDeferred: 0 (0)
CodeGen:(Total: 47.999ms, non-child: 47.999ms, % non-child: 100.00%)
- CodegenInvoluntaryContextSwitches: 5 (5)
- CodegenTotalWallClockTime: 47.999ms
- CodegenSysTime: 0.000ns
- CodegenUserTime: 46.197ms
- CodegenVoluntaryContextSwitches: 1 (1)
- CompileTime: 0.000ns
- IrGenerationTime: 0.000ns
- LoadTime: 0.000ns
- ModuleBitcodeSize: 2.28 MB (2393476)
- NumFunctions: 0 (0)
- NumInstructions: 0 (0)
- OptimizationTime: 0.000ns
- PeakMemoryUsage: 0
- PrepareTime: 47.999ms
Averaged Fragment F00:(Total: 295.995ms, non-child: 0.000ns, % non-child: 0.00%)
split sizes: min: 67.53 MB, max: 67.53 MB, avg: 67.53 MB, stddev: 0
completion times: min:303.995ms max:303.995ms mean: 303.995ms stddev:0.000ns
execution rates: min:222.14 MB/sec max:222.14 MB/sec mean:222.14 MB/sec stddev:0.00 /sec
num instances: 1
- AverageThreadTokens: 0.00
- BloomFilterBytes: 0
- ExchangeScanRatio: 0.00
- PeakMemoryUsage: 4.58 MB (4801174)
- PeakReservation: 4.00 MB (4194304)
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 4.59 MB (4813462)
- RowsProduced: 1 (1)
- TotalNetworkReceiveTime: 0.000ns
- TotalNetworkSendTime: 0.000ns
- TotalStorageWaitTime: 0.000ns
- TotalThreadsInvoluntaryContextSwitches: 172 (172)
- TotalThreadsTotalWallClockTime: 479.992ms
- TotalThreadsSysTime: 12.985ms
- TotalThreadsUserTime: 293.113ms
- TotalThreadsVoluntaryContextSwitches: 637 (637)
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 0
- CumulativeAllocations: 0 (0)
- PeakReservation: 0
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 0
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- ReservationLimit: 0
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Fragment Instance Lifecycle Timings:
- ExecTime: 0.000ns
- ExecTreeExecTime: 0.000ns
- OpenTime: 295.995ms
- ExecTreeOpenTime: 199.996ms
- PrepareTime: 0.000ns
- ExecTreePrepareTime: 0.000ns
KrpcDataStreamSender (dst_id=2):
- EosSent: 1 (1)
- PeakMemoryUsage: 14.22 KB (14560)
- RowsSent: 1 (1)
- RpcFailure: 0 (0)
- RpcRetry: 0 (0)
- SerializeBatchTime: 0.000ns
- TotalBytesSent: 13.00 B (13)
- UncompressedRowBatchSize: 17.00 B (17)
AGGREGATION_NODE (id=1):(Total: 199.996ms, non-child: 63.998ms, % non-child: 32.00%)
- PeakMemoryUsage: 21.00 KB (21504)
- RowsReturned: 1 (1)
- RowsReturnedRate: 5.00 /sec
NonGroupingAggregator 0:
- BuildTime: 51.999ms
- PeakMemoryUsage: 8.00 KB (8192)
- RowsReturned: 1 (1)
HDFS_SCAN_NODE (id=0):(Total: 135.997ms, non-child: 135.997ms, % non-child: 100.00%)
- AverageHdfsReadThreadConcurrency: 0.00
- AverageScannerThreadConcurrency: 0.00
- BytesRead: 100.48 KB (102895)
- BytesReadDataNodeCache: 0
- BytesReadLocal: 100.48 KB (102895)
- BytesReadRemoteUnexpected: 0
- BytesReadShortCircuit: 100.48 KB (102895)
- CachedFileHandle**bleep**Count: 2 (2)
- CachedFileHandlesMissCount: 0 (0)
- CollectionItemsRead: 0 (0)
- DataCacheHitBytes: 0
- DataCacheHitCount: 0 (0)
- DataCacheMissBytes: 0
- DataCacheMissCount: 0 (0)
- DataCachePartialHitCount: 0 (0)
- DecompressionTime: 0.000ns
- MaterializeTupleTime(*): 95.998ms
- MaxCompressedTextFileLength: 0
- NumColumns: 1 (1)
- NumDictFilteredRowGroups: 0 (0)
- NumDisksAccessed: 1 (1)
- NumRowGroups: 1 (1)
- NumScannerThreadMemUnavailable: 0 (0)
- NumScannerThreadReservationsDenied: 0 (0)
- NumScannerThreadsStarted: 1 (1)
- NumScannersWithNoReads: 0 (0)
- NumStatsFilteredRowGroups: 0 (0)
- PeakMemoryUsage: 4.54 MB (4761604)
- PeakScannerThreadConcurrency: 1 (1)
- PerReadThreadRawHdfsThroughput: 0.00 /sec
- RemoteScanRanges: 0 (0)
- RowBatchBytesEnqueued: 32.25 MB (33812480)
- RowBatchQueueGetWaitTime: 79.998ms
- RowBatchQueuePeakMemoryUsage: 546.00 KB (559104)
- RowBatchQueuePutWaitTime: 51.999ms
- RowBatchesEnqueued: 6.61K (6606)
- RowsRead: 6.76M (6761664)
- RowsReturned: 6.76M (6761664)
- RowsReturnedRate: 49.72 M/sec
- ScanRangesComplete: 1 (1)
- ScannerIoWaitTime: 0.000ns
- ScannerThreadWorklessLoops: 0 (0)
- ScannerThreadsInvoluntaryContextSwitches: 32 (32)
- ScannerThreadsTotalWallClockTime: 183.997ms
- ScannerThreadsSysTime: 4.326ms
- ScannerThreadsUserTime: 114.242ms
- ScannerThreadsVoluntaryContextSwitches: 44 (44)
- TotalRawHdfsOpenFileTime(*): 0.000ns
- TotalRawHdfsReadTime(*): 0.000ns
- TotalReadThroughput: 0.00 /sec
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 136.00 KB (139264)
- CumulativeAllocations: 2 (2)
- PeakReservation: 4.00 MB (4194304)
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 128.00 KB (131072)
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
CodeGen:(Total: 95.998ms, non-child: 95.998ms, % non-child: 100.00%)
- CodegenInvoluntaryContextSwitches: 70 (70)
- CodegenTotalWallClockTime: 95.998ms
- CodegenSysTime: 0.000ns
- CodegenUserTime: 90.735ms
- CodegenVoluntaryContextSwitches: 1 (1)
- CompileTime: 15.999ms
- IrGenerationTime: 0.000ns
- LoadTime: 0.000ns
- ModuleBitcodeSize: 2.28 MB (2393476)
- NumFunctions: 13 (13)
- NumInstructions: 254 (254)
- OptimizationTime: 31.999ms
- PeakMemoryUsage: 127.00 KB (130048)
- PrepareTime: 43.999ms
Fragment F00:
Instance ac4f8093207cddaf:b37ffcb700000001 (host=impalad-0:22000):(Total: 295.995ms, non-child: 0.000ns, % non-child: 0.00%)
Last report received time: 2020-08-18 12:12:01.670
Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/67.53 MB
Fragment Instance Lifecycle Event Timeline: 303.995ms
- Prepare Finished: 7.999ms (7.999ms)
- Open Finished: 303.995ms (295.995ms)
- First Batch Produced: 303.995ms (0.000ns)
- First Batch Sent: 303.995ms (0.000ns)
- ExecInternal Finished: 303.995ms (0.000ns)
- AverageThreadTokens: 0.00
- BloomFilterBytes: 0
- ExchangeScanRatio: 0.00
- PeakMemoryUsage: 4.58 MB (4801174)
- PeakReservation: 4.00 MB (4194304)
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 4.59 MB (4813462)
- RowsProduced: 1 (1)
- TotalNetworkReceiveTime: 0.000ns
- TotalNetworkSendTime: 0.000ns
- TotalStorageWaitTime: 0.000ns
- TotalThreadsInvoluntaryContextSwitches: 172 (172)
- TotalThreadsTotalWallClockTime: 479.992ms
- TotalThreadsSysTime: 12.985ms
- TotalThreadsUserTime: 293.113ms
- TotalThreadsVoluntaryContextSwitches: 637 (637)
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 0
- CumulativeAllocations: 0 (0)
- PeakReservation: 0
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 0
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- ReservationLimit: 0
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Fragment Instance Lifecycle Timings:
- ExecTime: 0.000ns
- ExecTreeExecTime: 0.000ns
- OpenTime: 295.995ms
- ExecTreeOpenTime: 199.996ms
- PrepareTime: 0.000ns
- ExecTreePrepareTime: 0.000ns
KrpcDataStreamSender (dst_id=2):
ExecOption: Unpartitioned Sender Codegen Disabled: not needed
- NetworkThroughput: (Avg: 42.76 KB/sec ; Min: 42.76 KB/sec ; Max: 42.76 KB/sec ; Number of samples: 1)
- EosSent: 1 (1)
- PeakMemoryUsage: 14.22 KB (14560)
- RowsSent: 1 (1)
- RpcFailure: 0 (0)
- RpcRetry: 0 (0)
- SerializeBatchTime: 0.000ns
- TotalBytesSent: 13.00 B (13)
- UncompressedRowBatchSize: 17.00 B (17)
AGGREGATION_NODE (id=1):(Total: 199.996ms, non-child: 63.998ms, % non-child: 32.00%)
Node Lifecycle Event Timeline: 303.995ms
- Open Started: 103.998ms (103.998ms)
- Open Finished: 303.995ms (199.996ms)
- First Batch Requested: 303.995ms (0.000ns)
- First Batch Returned: 303.995ms (0.000ns)
- Last Batch Returned: 303.995ms (0.000ns)
- Closed: 303.995ms (0.000ns)
- PeakMemoryUsage: 21.00 KB (21504)
- RowsReturned: 1 (1)
- RowsReturnedRate: 5.00 /sec
NonGroupingAggregator 0:
ExecOption: Codegen Enabled
- BuildTime: 51.999ms
- PeakMemoryUsage: 8.00 KB (8192)
- RowsReturned: 1 (1)
HDFS_SCAN_NODE (id=0):(Total: 135.997ms, non-child: 135.997ms, % non-child: 100.00%)
Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/67.53 MB
ExecOption: PARQUET Codegen Enabled, Codegen enabled: 1 out of 1
Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0% 7:0% 8:0% 9:0% 10:0% 11:0% 12:0% 13:0% 14:0%
File Formats: PARQUET/SNAPPY:1
Node Lifecycle Event Timeline: 303.995ms
- Open Started: 103.998ms (103.998ms)
- Open Finished: 103.998ms (0.000ns)
- First Batch Requested: 103.998ms (0.000ns)
- First Batch Returned: 119.998ms (15.999ms)
- Last Batch Returned: 303.995ms (183.997ms)
- Closed: 303.995ms (0.000ns)
- FooterProcessingTime: (Avg: 3.999ms ; Min: 3.999ms ; Max: 3.999ms ; Number of samples: 1)
- InitialRangeActualReservation: (Avg: 4.00 MB (4194304) ; Min: 4.00 MB (4194304) ; Max: 4.00 MB (4194304) ; Number of samples: 1)
- InitialRangeIdealReservation: (Avg: 128.00 KB (131072) ; Min: 128.00 KB (131072) ; Max: 128.00 KB (131072) ; Number of samples: 1)
- ParquetCompressedBytesReadPerColumn: (Avg: 210.00 B (210) ; Min: 210.00 B (210) ; Max: 210.00 B (210) ; Number of samples: 1)
- ParquetCompressedPageSize: (Avg: 15.00 B (15) ; Min: 15.00 B (15) ; Max: 15.00 B (15) ; Number of samples: 14)
- ParquetRowGroupActualReservation: (Avg: 4.00 MB (4194304) ; Min: 4.00 MB (4194304) ; Max: 4.00 MB (4194304) ; Number of samples: 1)
- ParquetRowGroupIdealReservation: (Avg: 8.00 KB (8192) ; Min: 8.00 KB (8192) ; Max: 8.00 KB (8192) ; Number of samples: 1)
- ParquetUncompressedBytesReadPerColumn: (Avg: 182.00 B (182) ; Min: 182.00 B (182) ; Max: 182.00 B (182) ; Number of samples: 1)
- ParquetUncompressedPageSize: (Avg: 13.00 B (13) ; Min: 13.00 B (13) ; Max: 13.00 B (13) ; Number of samples: 14)
- AverageHdfsReadThreadConcurrency: 0.00
- AverageScannerThreadConcurrency: 0.00
- BytesRead: 100.48 KB (102895)
- BytesReadDataNodeCache: 0
- BytesReadLocal: 100.48 KB (102895)
- BytesReadRemoteUnexpected: 0
- BytesReadShortCircuit: 100.48 KB (102895)
- CachedFileHandle**bleep**Count: 2 (2)
- CachedFileHandlesMissCount: 0 (0)
- CollectionItemsRead: 0 (0)
- DataCacheHitBytes: 0
- DataCacheHitCount: 0 (0)
- DataCacheMissBytes: 0
- DataCacheMissCount: 0 (0)
- DataCachePartialHitCount: 0 (0)
- DecompressionTime: 0.000ns
- MaterializeTupleTime(*): 95.998ms
- MaxCompressedTextFileLength: 0
- NumColumns: 1 (1)
- NumDictFilteredRowGroups: 0 (0)
- NumDisksAccessed: 1 (1)
- NumRowGroups: 1 (1)
- NumScannerThreadMemUnavailable: 0 (0)
- NumScannerThreadReservationsDenied: 0 (0)
- NumScannerThreadsStarted: 1 (1)
- NumScannersWithNoReads: 0 (0)
- NumStatsFilteredRowGroups: 0 (0)
- PeakMemoryUsage: 4.54 MB (4761604)
- PeakScannerThreadConcurrency: 1 (1)
- PerReadThreadRawHdfsThroughput: 0.00 /sec
- RemoteScanRanges: 0 (0)
- RowBatchBytesEnqueued: 32.25 MB (33812480)
- RowBatchQueueGetWaitTime: 79.998ms
- RowBatchQueuePeakMemoryUsage: 546.00 KB (559104)
- RowBatchQueuePutWaitTime: 51.999ms
- RowBatchesEnqueued: 6.61K (6606)
- RowsRead: 6.76M (6761664)
- RowsReturned: 6.76M (6761664)
- RowsReturnedRate: 49.72 M/sec
- ScanRangesComplete: 1 (1)
- ScannerIoWaitTime: 0.000ns
- ScannerThreadWorklessLoops: 0 (0)
- ScannerThreadsInvoluntaryContextSwitches: 32 (32)
- ScannerThreadsTotalWallClockTime: 183.997ms
- ScannerThreadsSysTime: 4.326ms
- ScannerThreadsUserTime: 114.242ms
- ScannerThreadsVoluntaryContextSwitches: 44 (44)
- TotalRawHdfsOpenFileTime(*): 0.000ns
- TotalRawHdfsReadTime(*): 0.000ns
- TotalReadThroughput: 0.00 /sec
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 136.00 KB (139264)
- CumulativeAllocations: 2 (2)
- PeakReservation: 4.00 MB (4194304)
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 128.00 KB (131072)
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
CodeGen:(Total: 95.998ms, non-child: 95.998ms, % non-child: 100.00%)
- CodegenInvoluntaryContextSwitches: 70 (70)
- CodegenTotalWallClockTime: 95.998ms
- CodegenSysTime: 0.000ns
- CodegenUserTime: 90.735ms
- CodegenVoluntaryContextSwitches: 1 (1)
- CompileTime: 15.999ms
- IrGenerationTime: 0.000ns
- LoadTime: 0.000ns
- ModuleBitcodeSize: 2.28 MB (2393476)
- NumFunctions: 13 (13)
- NumInstructions: 254 (254)
- OptimizationTime: 31.999ms
- PeakMemoryUsage: 127.00 KB (130048)
- PrepareTime: 43.999ms
2) querying the view, which is based on all columns of that table
Query Runtime Profile:
Query (id=b2457b3a74ffe669:077cac0100000000):
Summary:
Session ID: b34b7ed0cc2c3c3e:cf6cde62e6c74686
Session Type: BEESWAX
Start Time: 2020-08-18 12:13:24.865970000
End Time: 2020-08-18 12:13:27.712742000
Query Type: QUERY
Query State: FINISHED
Query Status: OK
Impala Version: impalad version 3.2.0-cdh6.3.1 RELEASE (build 3d5de689e9b9cfde0c01e1c64f4b4e830cee69c3)
Default Db: default
Sql Statement: SELECT sum(column1) from db.view_test where partition_col = 1597431600
Coordinator: impalad-0:22000
Query Options (set by configuration): NUM_SCANNER_THREADS=8,QUERY_TIMEOUT_S=600,SCRATCH_LIMIT=137438953472,CLIENT_IDENTIFIER=Impala Shell v3.2.0-cdh6.3.1 (3d5de68) built on Thu Sep 26 03:03:52 PDT 2019
Query Options (set by configuration and planner): NUM_SCANNER_THREADS=8,QUERY_TIMEOUT_S=600,MT_DOP=0,SCRATCH_LIMIT=137438953472,CLIENT_IDENTIFIER=Impala Shell v3.2.0-cdh6.3.1 (3d5de68) built on Thu Sep 26 03:03:52 PDT 2019
Plan:
----------------
Max Per-Host Resource Reservation: Memory=4.00MB Threads=3
Per-Host Resource Estimates: Memory=100MB
WARNING: The following tables are missing relevant table and/or column statistics.
db.table_test
Analyzed query: SELECT sum(CAST(column1 AS BIGINT)) FROM
db.view_test WHERE partition_col = CAST(1597431600 AS
BIGINT)
F01:PLAN FRAGMENT [UNPARTITIONED] hosts=1 instances=1
| Per-Host Resources: mem-estimate=10.02MB mem-reservation=0B thread-reservation=1
PLAN-ROOT SINK
| mem-estimate=0B mem-reservation=0B thread-reservation=0
|
03:AGGREGATE [FINALIZE]
| output: sum:merge(column1)
| mem-estimate=10.00MB mem-reservation=0B spill-buffer=2.00MB thread-reservation=0
| tuple-ids=2 row-size=8B cardinality=1
| in pipelines: 03(GETNEXT), 01(OPEN)
|
02:EXCHANGE [UNPARTITIONED]
| mem-estimate=16.00KB mem-reservation=0B thread-reservation=0
| tuple-ids=2 row-size=8B cardinality=1
| in pipelines: 01(GETNEXT)
|
F00:PLAN FRAGMENT [RANDOM] hosts=1 instances=1
Per-Host Resources: mem-estimate=90.00MB mem-reservation=4.00MB thread-reservation=2
01:AGGREGATE
| output: sum(CAST(column1 AS BIGINT))
| mem-estimate=10.00MB mem-reservation=0B spill-buffer=2.00MB thread-reservation=0
| tuple-ids=2 row-size=8B cardinality=1
| in pipelines: 01(GETNEXT), 00(OPEN)
|
00:SCAN HDFS [db.table_test, RANDOM]
partition predicates: db.table_test.partition_col = CAST(1597431600 AS BIGINT)
partitions=1/7 files=1 size=67.53MB
stored statistics:
table: rows=unavailable size=unavailable
partitions: 0/1 rows=unavailable
columns missing stats: column1,column2,column3,column4,column5,column6,column7,column8,column9,column10,column11,column12,column13,column14,column15,column16,column17,column18,column19,column20,column21,column22,column23,column24,column25,column26,column27,column28,column29,column30,column31,column32,column33,column34,column35,column36,column37,column38,column39,column40,column41,column42,column43,column44,column45,column46,column47,column48,column49,column50,column51,column52,column53,column54,column55,column56,column57,column58,column59,column60,column61,column62,column63,column64,column65,column66,column67,column68,column69,column70,column71,column72,column73,column74,column75,column76,column77,column78,column79,column80,column81,column82,column83,column84,column85,column86,column87,column88,column89,column90,column91,column92,column93,column94,column95,column96,column97,column98,column99,column100,column101,column102,column103,column104,column105,column106,column107,column108,column109,column110,column111,column112,column113,column114,column115,column116,column117,column118,column119,column120,column121,column122,column123,column124,column125,column126,column127,column128,column129,column130,column131,column132,column133,column134,column135,column136,column137,column138,column139,column140,column141,column142,column143,column144,column145,column146,column147,column148,column149,column150,column151,column152,column153,column154,column155,column156,column157,column158,column159,column160,column161,column162,column163,column164,column165,column166,column167,column168,column169,column170,column171,column172,column173,column174,column175,column176,column177,column178,column179,column180,column181,column182,column183,column184,column185,column186,column187,column188,column189,column190,column191,column192,column193,column194,column195,column196,column197,column198,column199,column200,column201,column202,column203,column204,column205,column206,column207,column208,column209,column210,column211,column212,column213,column214,column215,column216,column217,column218,column219,column220,column221,column222,column223,column224,column225,column226,column227,column228,column229,column230,column231,column232,column233,column234,column235,column236,column237,column238,column239,column240,column241,column242,column243,column244,column245,column246,column247,column248,column249,column250,column251,column252,column253,column254,column255,column256,column257,column258,column259,column260,column261,column262,column263,column264,column265,column266,column267,column268,column269,column270,column271,column272,column273,column274,column275,column276,column277,column278,column279,column280,column281,column282,column283,column284,column285,column286,column287,column288,column289,column290,column291,column292,column293,column294,column295,column296,column297,column298,column299,column300,column301,column302,column303,column304,column305,column306,column307,column308,column309,column310,column311,column312,column313,column314,column315,column316,column317,column318,column319,column320,column321,column322,column323,column324,column325,column326,column327,column328,column329,column330,column331,column332,column333,column334,column335,column336,column337,column338,column339,column340,column341,column342,column343,column344,column345,column346,column347,column348,column349,column350,column351,column352,column353,column354,column355,column356,column357,column358,column359,column360,column361,column362,column363,column364,column365,column366,column367,column368,column369,column370,column371,column372,column373,column374,column375,column376,column377,column378,column379,column380,column381,column382,column383,column384,column385,column386,column387,column388,column389,column390,column391,column392,column393,column394,column395,column396,column397,column398,column399,column400,column401,column402,column403,column404,column405,column406,column407,column408,column409,column410,column411,column412,column413,column414,column415,column416,column417,column418,column419,column420,column421,column422,column423,column424,column425,column426,column427,column428,column429,column430,column431,column432,column433,column434,column435,column436,column437,column438,column439,column440,column441,column442,column443,column444,column445,column446,column447,column448,column449,column450,column451,column452,column453,column454,column455,column456,column457,column458,column459,column460,column461,column462,column463,column464,column465,column466,column467,column468,column469,column470,column471,column472,column473,column474,column475,column476,column477,column478,column479,column480,column481,column482,column483,column484,column485,column486
extrapolated-rows=disabled max-scan-range-rows=unavailable
mem-estimate=80.00MB mem-reservation=4.00MB thread-reservation=1
tuple-ids=0 row-size=4B cardinality=unavailable
in pipelines: 00(GETNEXT)
----------------
Estimated Per-Host Mem: 104873984
Tables Missing Stats: db.table_test
Per Host Min Memory Reservation: impalad-0:22000(4.00 MB)
Request Pool: root.default
Admission result: Admitted immediately
Cluster Memory Admitted: 100.02 MB
ExecSummary:
Operator #Hosts Avg Time Max Time #Rows Est. #Rows Peak Mem Est. Peak Mem Detail
-------------------------------------------------------------------------------------------------------------------------------------------
F01:ROOT 1 0.000ns 0.000ns 0 0
03:AGGREGATE 1 0.000ns 0.000ns 1 1 16.00 KB 10.00 MB FINALIZE
02:EXCHANGE 1 0.000ns 0.000ns 1 1 16.00 KB 16.00 KB UNPARTITIONED
F00:EXCHANGE SENDER 1 0.000ns 0.000ns 14.22 KB 0
01:AGGREGATE 1 59.999ms 59.999ms 1 1 21.00 KB 10.00 MB
00:SCAN HDFS 1 67.998ms 67.998ms 6.76M -1 4.54 MB 80.00 MB db.table_test
Errors:
Query Compilation: 2s517ms
- Metadata of all 2 tables cached: 1.361ms (1.361ms)
- Analysis finished: 2s509ms (2s507ms)
- Value transfer graph computed: 2s513ms (4.034ms)
- Single node plan created: 2s515ms (2.614ms)
- Runtime filters computed: 2s516ms (257.341us)
- Distributed plan created: 2s516ms (56.362us)
- Planning finished: 2s517ms (1.724ms)
Query Timeline: 2s859ms
- Query submitted: 0.000ns (0.000ns)
- Planning finished: 2s523ms (2s523ms)
- Submit for admission: 2s523ms (0.000ns)
- Completed admission: 2s523ms (0.000ns)
- Ready to start on 1 backends: 2s523ms (0.000ns)
- All 1 execution backends (2 fragment instances) started: 2s527ms (3.999ms)
- Rows available: 2s759ms (231.996ms)
- First row fetched: 2s839ms (79.998ms)
- Last row fetched: 2s839ms (0.000ns)
- Released admission control resources: 2s843ms (3.999ms)
- Unregister query: 2s851ms (7.999ms)
- AdmissionControlTimeSinceLastUpdate: 45.000ms
- ComputeScanRangeAssignmentTimer: 0.000ns
Frontend:
ImpalaServer:
- ClientFetchWaitTimer: 83.998ms
- RowMaterializationTimer: 7.999ms
Execution Profile b2457b3a74ffe669:077cac0100000000:(Total: 243.996ms, 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: 1, min / max: 3ms / 3ms, 25th %-ile: 3ms, 50th %-ile: 3ms, 75th %-ile: 3ms, 90th %-ile: 3ms, 95th %-ile: 3ms, 99.9th %-ile: 3ms
Slowest backend to start up: impalad-0:22000
Per Node Peak Memory Usage: impalad-0:22000(4.59 MB)
Per Node Bytes Read: impalad-0:22000(100.48 KB)
Per Node User Time: impalad-0:22000(346.031ms)
Per Node System Time: impalad-0:22000(6.969ms)
- ExchangeScanRatio: 0.00
- FiltersReceived: 0 (0)
- FinalizationTimer: 0.000ns
- InnerNodeSelectivityRatio: 0.00
- NumBackends: 1 (1)
- NumFragmentInstances: 2 (2)
- NumFragments: 2 (2)
- TotalBytesRead: 100.48 KB (102895)
- TotalBytesSent: 13.00 B (13)
- TotalCpuTime: 353.000ms
- TotalInnerBytesSent: 0
- TotalScanBytesSent: 13.00 B (13)
Per Node Profiles:
impalad-0:22000:
- ScratchBytesRead: 0
- ScratchBytesWritten: 0
- ScratchFileUsedBytes: 0
- ScratchReads: 0 (0)
- ScratchWrites: 0 (0)
- TotalEncryptionTime: 0.000ns
- TotalReadBlockTime: 0.000ns
Averaged Fragment F01:(Total: 311.995ms, non-child: 3.999ms, % non-child: 1.28%)
split sizes: min: 0, max: 0, avg: 0, stddev: 0
completion times: min:315.995ms max:315.995ms mean: 315.995ms 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
- ExchangeScanRatio: 0.00
- PeakMemoryUsage: 40.00 KB (40960)
- PeakReservation: 0
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 4.59 MB (4813462)
- RowsProduced: 1 (1)
- TotalNetworkReceiveTime: 183.997ms
- TotalNetworkSendTime: 0.000ns
- TotalStorageWaitTime: 0.000ns
- TotalThreadsInvoluntaryContextSwitches: 4 (4)
- TotalThreadsTotalWallClockTime: 307.995ms
- TotalThreadsSysTime: 0.000ns
- TotalThreadsUserTime: 43.889ms
- TotalThreadsVoluntaryContextSwitches: 5 (5)
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 0
- CumulativeAllocations: 0 (0)
- PeakReservation: 0
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 0
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- ReservationLimit: 0
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Fragment Instance Lifecycle Timings:
- ExecTime: 79.998ms
- ExecTreeExecTime: 0.000ns
- OpenTime: 227.996ms
- ExecTreeOpenTime: 183.997ms
- PrepareTime: 3.999ms
- ExecTreePrepareTime: 0.000ns
PLAN_ROOT_SINK:(Total: 79.998ms, non-child: 79.998ms, % non-child: 100.00%)
- PeakMemoryUsage: 0
AGGREGATION_NODE (id=3):(Total: 183.997ms, non-child: 0.000ns, % non-child: 0.00%)
- PeakMemoryUsage: 16.00 KB (16384)
- RowsReturned: 1 (1)
- RowsReturnedRate: 5.00 /sec
NonGroupingAggregator 0:
- BuildTime: 0.000ns
- PeakMemoryUsage: 8.00 KB (8192)
- RowsReturned: 1 (1)
EXCHANGE_NODE (id=2):(Total: 183.997ms, non-child: 183.997ms, % non-child: 100.00%)
- ConvertRowBatchTime: 0.000ns
- PeakMemoryUsage: 16.00 KB (16384)
- RowsReturned: 1 (1)
- RowsReturnedRate: 5.00 /sec
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 16.00 KB (16384)
- CumulativeAllocations: 2 (2)
- PeakReservation: 16.00 KB (16384)
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 16.00 KB (16384)
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Dequeue:
- FirstBatchWaitTime: 183.997ms
- TotalBytesDequeued: 17.00 B (17)
- TotalGetBatchTime: 183.997ms
- DataWaitTime: 183.997ms
Enqueue:
- DeserializeRowBatchTime: 0.000ns
- TotalBatchesEnqueued: 1 (1)
- TotalBatchesReceived: 1 (1)
- TotalBytesReceived: 13.00 B (13)
- TotalEarlySenders: 0 (0)
- TotalEosReceived: 1 (1)
- TotalHasDeferredRPCsTime: 0.000ns
- TotalRPCsDeferred: 0 (0)
CodeGen:(Total: 43.999ms, non-child: 43.999ms, % non-child: 100.00%)
- CodegenInvoluntaryContextSwitches: 4 (4)
- CodegenTotalWallClockTime: 43.999ms
- CodegenSysTime: 0.000ns
- CodegenUserTime: 43.262ms
- CodegenVoluntaryContextSwitches: 2 (2)
- CompileTime: 0.000ns
- IrGenerationTime: 0.000ns
- LoadTime: 0.000ns
- ModuleBitcodeSize: 2.28 MB (2393476)
- NumFunctions: 0 (0)
- NumInstructions: 0 (0)
- OptimizationTime: 0.000ns
- PeakMemoryUsage: 0
- PrepareTime: 43.999ms
Coordinator Fragment F01:
Instance b2457b3a74ffe669:077cac0100000000 (host=impalad-0:22000):(Total: 311.995ms, non-child: 3.999ms, % non-child: 1.28%)
Last report received time: 2020-08-18 12:13:27.712
Fragment Instance Lifecycle Event Timeline: 311.995ms
- Prepare Finished: 3.999ms (3.999ms)
- Open Finished: 231.996ms (227.996ms)
- First Batch Produced: 231.996ms (0.000ns)
- First Batch Sent: 311.995ms (79.998ms)
- ExecInternal Finished: 311.995ms (0.000ns)
- MemoryUsage (500.000ms): 12.00 KB
- AverageThreadTokens: 0.00
- BloomFilterBytes: 0
- ExchangeScanRatio: 0.00
- PeakMemoryUsage: 40.00 KB (40960)
- PeakReservation: 0
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 4.59 MB (4813462)
- RowsProduced: 1 (1)
- TotalNetworkReceiveTime: 183.997ms
- TotalNetworkSendTime: 0.000ns
- TotalStorageWaitTime: 0.000ns
- TotalThreadsInvoluntaryContextSwitches: 4 (4)
- TotalThreadsTotalWallClockTime: 307.995ms
- TotalThreadsSysTime: 0.000ns
- TotalThreadsUserTime: 43.889ms
- TotalThreadsVoluntaryContextSwitches: 5 (5)
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 0
- CumulativeAllocations: 0 (0)
- PeakReservation: 0
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 0
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- ReservationLimit: 0
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Fragment Instance Lifecycle Timings:
- ExecTime: 79.998ms
- ExecTreeExecTime: 0.000ns
- OpenTime: 227.996ms
- ExecTreeOpenTime: 183.997ms
- PrepareTime: 3.999ms
- ExecTreePrepareTime: 0.000ns
PLAN_ROOT_SINK:(Total: 79.998ms, non-child: 0.000ns, % non-child: 0.00%)
- PeakMemoryUsage: 0
AGGREGATION_NODE (id=3):(Total: 183.997ms, non-child: 0.000ns, % non-child: 0.00%)
Node Lifecycle Event Timeline: 311.995ms
- Open Started: 47.999ms (47.999ms)
- Open Finished: 231.996ms (183.997ms)
- First Batch Requested: 231.996ms (0.000ns)
- First Batch Returned: 231.996ms (0.000ns)
- Last Batch Returned: 231.996ms (0.000ns)
- Closed: 311.995ms (79.998ms)
- PeakMemoryUsage: 16.00 KB (16384)
- RowsReturned: 1 (1)
- RowsReturnedRate: 5.00 /sec
NonGroupingAggregator 0:
- BuildTime: 0.000ns
- PeakMemoryUsage: 8.00 KB (8192)
- RowsReturned: 1 (1)
EXCHANGE_NODE (id=2):(Total: 183.997ms, non-child: 0.000ns, % non-child: 0.00%)
Node Lifecycle Event Timeline: 231.996ms
- Open Started: 47.999ms (47.999ms)
- Open Finished: 231.996ms (183.997ms)
- First Batch Requested: 231.996ms (0.000ns)
- First Batch Returned: 231.996ms (0.000ns)
- Last Batch Returned: 231.996ms (0.000ns)
- Closed: 231.996ms (0.000ns)
- ConvertRowBatchTime: 0.000ns
- PeakMemoryUsage: 16.00 KB (16384)
- RowsReturned: 1 (1)
- RowsReturnedRate: 5.00 /sec
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 16.00 KB (16384)
- CumulativeAllocations: 2 (2)
- PeakReservation: 16.00 KB (16384)
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 16.00 KB (16384)
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Dequeue:
- BytesDequeued (500.000ms): 0
- FirstBatchWaitTime: 183.997ms
- TotalBytesDequeued: 17.00 B (17)
- TotalGetBatchTime: 183.997ms
- DataWaitTime: 183.997ms
Enqueue:
- BytesReceived (500.000ms): 0
- DeferredQueueSize (500.000ms): 0
- DispatchTime: (Avg: 107.819us ; Min: 107.819us ; Max: 107.819us ; Number of samples: 1)
- DeserializeRowBatchTime: 0.000ns
- TotalBatchesEnqueued: 1 (1)
- TotalBatchesReceived: 1 (1)
- TotalBytesReceived: 13.00 B (13)
- TotalEarlySenders: 0 (0)
- TotalEosReceived: 1 (1)
- TotalHasDeferredRPCsTime: 0.000ns
- TotalRPCsDeferred: 0 (0)
CodeGen:(Total: 43.999ms, non-child: 43.999ms, % non-child: 100.00%)
- CodegenInvoluntaryContextSwitches: 4 (4)
- CodegenTotalWallClockTime: 43.999ms
- CodegenSysTime: 0.000ns
- CodegenUserTime: 43.262ms
- CodegenVoluntaryContextSwitches: 2 (2)
- CompileTime: 0.000ns
- IrGenerationTime: 0.000ns
- LoadTime: 0.000ns
- ModuleBitcodeSize: 2.28 MB (2393476)
- NumFunctions: 0 (0)
- NumInstructions: 0 (0)
- OptimizationTime: 0.000ns
- PeakMemoryUsage: 0
- PrepareTime: 43.999ms
Averaged Fragment F00:(Total: 231.996ms, non-child: 0.000ns, % non-child: 0.00%)
split sizes: min: 67.53 MB, max: 67.53 MB, avg: 67.53 MB, stddev: 0
completion times: min:315.995ms max:315.995ms mean: 315.995ms stddev:0.000ns
execution rates: min:213.71 MB/sec max:213.71 MB/sec mean:213.71 MB/sec stddev:0.00 /sec
num instances: 1
- AverageThreadTokens: 1.00
- BloomFilterBytes: 0
- ExchangeScanRatio: 0.00
- PeakMemoryUsage: 4.58 MB (4801174)
- PeakReservation: 4.00 MB (4194304)
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 4.59 MB (4813462)
- RowsProduced: 1 (1)
- TotalNetworkReceiveTime: 0.000ns
- TotalNetworkSendTime: 3.999ms
- TotalStorageWaitTime: 0.000ns
- TotalThreadsInvoluntaryContextSwitches: 25 (25)
- TotalThreadsTotalWallClockTime: 347.994ms
- TotalThreadsSysTime: 6.969ms
- TotalThreadsUserTime: 302.142ms
- TotalThreadsVoluntaryContextSwitches: 402 (402)
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 0
- CumulativeAllocations: 0 (0)
- PeakReservation: 0
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 0
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- ReservationLimit: 0
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Fragment Instance Lifecycle Timings:
- ExecTime: 3.999ms
- ExecTreeExecTime: 0.000ns
- OpenTime: 223.996ms
- ExecTreeOpenTime: 123.998ms
- PrepareTime: 3.999ms
- ExecTreePrepareTime: 3.999ms
KrpcDataStreamSender (dst_id=2):(Total: 3.999ms, non-child: 3.999ms, % non-child: 100.00%)
- EosSent: 1 (1)
- PeakMemoryUsage: 14.22 KB (14560)
- RowsSent: 1 (1)
- RpcFailure: 0 (0)
- RpcRetry: 0 (0)
- SerializeBatchTime: 0.000ns
- TotalBytesSent: 13.00 B (13)
- UncompressedRowBatchSize: 17.00 B (17)
AGGREGATION_NODE (id=1):(Total: 127.997ms, non-child: 59.999ms, % non-child: 46.88%)
- PeakMemoryUsage: 21.00 KB (21504)
- RowsReturned: 1 (1)
- RowsReturnedRate: 7.00 /sec
NonGroupingAggregator 0:
- BuildTime: 55.999ms
- PeakMemoryUsage: 8.00 KB (8192)
- RowsReturned: 1 (1)
HDFS_SCAN_NODE (id=0):(Total: 67.998ms, non-child: 67.998ms, % non-child: 100.00%)
- AverageHdfsReadThreadConcurrency: 0.00
- AverageScannerThreadConcurrency: 0.00
- BytesRead: 100.48 KB (102895)
- BytesReadDataNodeCache: 0
- BytesReadLocal: 100.48 KB (102895)
- BytesReadRemoteUnexpected: 0
- BytesReadShortCircuit: 100.48 KB (102895)
- CachedFileHandle**bleep**Count: 2 (2)
- CachedFileHandlesMissCount: 0 (0)
- CollectionItemsRead: 0 (0)
- DataCacheHitBytes: 0
- DataCacheHitCount: 0 (0)
- DataCacheMissBytes: 0
- DataCacheMissCount: 0 (0)
- DataCachePartialHitCount: 0 (0)
- DecompressionTime: 0.000ns
- MaterializeTupleTime(*): 83.998ms
- MaxCompressedTextFileLength: 0
- NumColumns: 1 (1)
- NumDictFilteredRowGroups: 0 (0)
- NumDisksAccessed: 1 (1)
- NumRowGroups: 1 (1)
- NumScannerThreadMemUnavailable: 0 (0)
- NumScannerThreadReservationsDenied: 0 (0)
- NumScannerThreadsStarted: 1 (1)
- NumScannersWithNoReads: 0 (0)
- NumStatsFilteredRowGroups: 0 (0)
- PeakMemoryUsage: 4.54 MB (4761604)
- PeakScannerThreadConcurrency: 1 (1)
- PerReadThreadRawHdfsThroughput: 0.00 /sec
- RemoteScanRanges: 0 (0)
- RowBatchBytesEnqueued: 32.25 MB (33812480)
- RowBatchQueueGetWaitTime: 27.999ms
- RowBatchQueuePeakMemoryUsage: 541.00 KB (553984)
- RowBatchQueuePutWaitTime: 11.999ms
- RowBatchesEnqueued: 6.61K (6606)
- RowsRead: 6.76M (6761664)
- RowsReturned: 6.76M (6761664)
- RowsReturnedRate: 99.44 M/sec
- ScanRangesComplete: 1 (1)
- ScannerIoWaitTime: 0.000ns
- ScannerThreadWorklessLoops: 0 (0)
- ScannerThreadsInvoluntaryContextSwitches: 9 (9)
- ScannerThreadsTotalWallClockTime: 119.998ms
- ScannerThreadsSysTime: 0.000ns
- ScannerThreadsUserTime: 107.215ms
- ScannerThreadsVoluntaryContextSwitches: 35 (35)
- TotalRawHdfsOpenFileTime(*): 0.000ns
- TotalRawHdfsReadTime(*): 0.000ns
- TotalReadThroughput: 0.00 /sec
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 136.00 KB (139264)
- CumulativeAllocations: 2 (2)
- PeakReservation: 4.00 MB (4194304)
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 128.00 KB (131072)
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
CodeGen:(Total: 99.998ms, non-child: 99.998ms, % non-child: 100.00%)
- CodegenInvoluntaryContextSwitches: 5 (5)
- CodegenTotalWallClockTime: 99.998ms
- CodegenSysTime: 6.533ms
- CodegenUserTime: 92.713ms
- CodegenVoluntaryContextSwitches: 1 (1)
- CompileTime: 15.999ms
- IrGenerationTime: 7.999ms
- LoadTime: 0.000ns
- ModuleBitcodeSize: 2.28 MB (2393476)
- NumFunctions: 13 (13)
- NumInstructions: 254 (254)
- OptimizationTime: 35.999ms
- PeakMemoryUsage: 127.00 KB (130048)
- PrepareTime: 39.999ms
Fragment F00:
Instance b2457b3a74ffe669:077cac0100000001 (host=impalad-0:22000):(Total: 231.996ms, non-child: 0.000ns, % non-child: 0.00%)
Last report received time: 2020-08-18 12:13:27.711
Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/67.53 MB
Fragment Instance Lifecycle Event Timeline: 231.996ms
- Prepare Finished: 3.999ms (3.999ms)
- Open Finished: 227.996ms (223.996ms)
- First Batch Produced: 227.996ms (0.000ns)
- First Batch Sent: 227.996ms (0.000ns)
- ExecInternal Finished: 231.996ms (3.999ms)
- MemoryUsage (500.000ms): 26.22 KB
- ThreadUsage (500.000ms): 1
- AverageThreadTokens: 1.00
- BloomFilterBytes: 0
- ExchangeScanRatio: 0.00
- PeakMemoryUsage: 4.58 MB (4801174)
- PeakReservation: 4.00 MB (4194304)
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 4.59 MB (4813462)
- RowsProduced: 1 (1)
- TotalNetworkReceiveTime: 0.000ns
- TotalNetworkSendTime: 3.999ms
- TotalStorageWaitTime: 0.000ns
- TotalThreadsInvoluntaryContextSwitches: 25 (25)
- TotalThreadsTotalWallClockTime: 347.994ms
- TotalThreadsSysTime: 6.969ms
- TotalThreadsUserTime: 302.142ms
- TotalThreadsVoluntaryContextSwitches: 402 (402)
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 0
- CumulativeAllocations: 0 (0)
- PeakReservation: 0
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 0
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- ReservationLimit: 0
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Fragment Instance Lifecycle Timings:
- ExecTime: 3.999ms
- ExecTreeExecTime: 0.000ns
- OpenTime: 223.996ms
- ExecTreeOpenTime: 123.998ms
- PrepareTime: 3.999ms
- ExecTreePrepareTime: 3.999ms
KrpcDataStreamSender (dst_id=2):(Total: 3.999ms, non-child: 0.000ns, % non-child: 0.00%)
ExecOption: Unpartitioned Sender Codegen Disabled: not needed
- BytesSent (500.000ms): 0
- NetworkThroughput: (Avg: 25.62 KB/sec ; Min: 25.62 KB/sec ; Max: 25.62 KB/sec ; Number of samples: 1)
- EosSent: 1 (1)
- PeakMemoryUsage: 14.22 KB (14560)
- RowsSent: 1 (1)
- RpcFailure: 0 (0)
- RpcRetry: 0 (0)
- SerializeBatchTime: 0.000ns
- TotalBytesSent: 13.00 B (13)
- UncompressedRowBatchSize: 17.00 B (17)
AGGREGATION_NODE (id=1):(Total: 127.997ms, non-child: 59.999ms, % non-child: 46.88%)
Node Lifecycle Event Timeline: 231.996ms
- Open Started: 103.998ms (103.998ms)
- Open Finished: 227.996ms (123.998ms)
- First Batch Requested: 227.996ms (0.000ns)
- First Batch Returned: 227.996ms (0.000ns)
- Last Batch Returned: 227.996ms (0.000ns)
- Closed: 231.996ms (3.999ms)
- PeakMemoryUsage: 21.00 KB (21504)
- RowsReturned: 1 (1)
- RowsReturnedRate: 7.00 /sec
NonGroupingAggregator 0:
ExecOption: Codegen Enabled
- BuildTime: 55.999ms
- PeakMemoryUsage: 8.00 KB (8192)
- RowsReturned: 1 (1)
HDFS_SCAN_NODE (id=0):(Total: 67.998ms, non-child: 67.998ms, % non-child: 100.00%)
Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/67.53 MB
ExecOption: PARQUET Codegen Enabled, Codegen enabled: 1 out of 1
Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0% 7:0% 8:0% 9:0% 10:0% 11:0% 12:0% 13:0% 14:0%
File Formats: PARQUET/SNAPPY:1
Node Lifecycle Event Timeline: 227.996ms
- Open Started: 103.998ms (103.998ms)
- Open Finished: 103.998ms (0.000ns)
- First Batch Requested: 107.998ms (3.999ms)
- First Batch Returned: 115.998ms (7.999ms)
- Last Batch Returned: 227.996ms (111.998ms)
- Closed: 227.996ms (0.000ns)
- BytesRead (500.000ms): 0
- FooterProcessingTime: (Avg: 7.999ms ; Min: 7.999ms ; Max: 7.999ms ; Number of samples: 1)
- InitialRangeActualReservation: (Avg: 4.00 MB (4194304) ; Min: 4.00 MB (4194304) ; Max: 4.00 MB (4194304) ; Number of samples: 1)
- InitialRangeIdealReservation: (Avg: 128.00 KB (131072) ; Min: 128.00 KB (131072) ; Max: 128.00 KB (131072) ; Number of samples: 1)
- ParquetCompressedBytesReadPerColumn: (Avg: 210.00 B (210) ; Min: 210.00 B (210) ; Max: 210.00 B (210) ; Number of samples: 1)
- ParquetCompressedPageSize: (Avg: 15.00 B (15) ; Min: 15.00 B (15) ; Max: 15.00 B (15) ; Number of samples: 14)
- ParquetRowGroupActualReservation: (Avg: 4.00 MB (4194304) ; Min: 4.00 MB (4194304) ; Max: 4.00 MB (4194304) ; Number of samples: 1)
- ParquetRowGroupIdealReservation: (Avg: 8.00 KB (8192) ; Min: 8.00 KB (8192) ; Max: 8.00 KB (8192) ; Number of samples: 1)
- ParquetUncompressedBytesReadPerColumn: (Avg: 182.00 B (182) ; Min: 182.00 B (182) ; Max: 182.00 B (182) ; Number of samples: 1)
- ParquetUncompressedPageSize: (Avg: 13.00 B (13) ; Min: 13.00 B (13) ; Max: 13.00 B (13) ; Number of samples: 14)
- AverageHdfsReadThreadConcurrency: 0.00
- AverageScannerThreadConcurrency: 0.00
- BytesRead: 100.48 KB (102895)
- BytesReadDataNodeCache: 0
- BytesReadLocal: 100.48 KB (102895)
- BytesReadRemoteUnexpected: 0
- BytesReadShortCircuit: 100.48 KB (102895)
- CachedFileHandle**bleep**Count: 2 (2)
- CachedFileHandlesMissCount: 0 (0)
- CollectionItemsRead: 0 (0)
- DataCacheHitBytes: 0
- DataCacheHitCount: 0 (0)
- DataCacheMissBytes: 0
- DataCacheMissCount: 0 (0)
- DataCachePartialHitCount: 0 (0)
- DecompressionTime: 0.000ns
- MaterializeTupleTime(*): 83.998ms
- MaxCompressedTextFileLength: 0
- NumColumns: 1 (1)
- NumDictFilteredRowGroups: 0 (0)
- NumDisksAccessed: 1 (1)
- NumRowGroups: 1 (1)
- NumScannerThreadMemUnavailable: 0 (0)
- NumScannerThreadReservationsDenied: 0 (0)
- NumScannerThreadsStarted: 1 (1)
- NumScannersWithNoReads: 0 (0)
- NumStatsFilteredRowGroups: 0 (0)
- PeakMemoryUsage: 4.54 MB (4761604)
- PeakScannerThreadConcurrency: 1 (1)
- PerReadThreadRawHdfsThroughput: 0.00 /sec
- RemoteScanRanges: 0 (0)
- RowBatchBytesEnqueued: 32.25 MB (33812480)
- RowBatchQueueGetWaitTime: 27.999ms
- RowBatchQueuePeakMemoryUsage: 541.00 KB (553984)
- RowBatchQueuePutWaitTime: 11.999ms
- RowBatchesEnqueued: 6.61K (6606)
- RowsRead: 6.76M (6761664)
- RowsReturned: 6.76M (6761664)
- RowsReturnedRate: 99.44 M/sec
- ScanRangesComplete: 1 (1)
- ScannerIoWaitTime: 0.000ns
- ScannerThreadWorklessLoops: 0 (0)
- ScannerThreadsInvoluntaryContextSwitches: 9 (9)
- ScannerThreadsTotalWallClockTime: 119.998ms
- ScannerThreadsSysTime: 0.000ns
- ScannerThreadsUserTime: 107.215ms
- ScannerThreadsVoluntaryContextSwitches: 35 (35)
- TotalRawHdfsOpenFileTime(*): 0.000ns
- TotalRawHdfsReadTime(*): 0.000ns
- TotalReadThroughput: 0.00 /sec
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 136.00 KB (139264)
- CumulativeAllocations: 2 (2)
- PeakReservation: 4.00 MB (4194304)
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 128.00 KB (131072)
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
CodeGen:(Total: 99.998ms, non-child: 99.998ms, % non-child: 100.00%)
- CodegenInvoluntaryContextSwitches: 5 (5)
- CodegenTotalWallClockTime: 99.998ms
- CodegenSysTime: 6.533ms
- CodegenUserTime: 92.713ms
- CodegenVoluntaryContextSwitches: 1 (1)
- CompileTime: 15.999ms
- IrGenerationTime: 7.999ms
- LoadTime: 0.000ns
- ModuleBitcodeSize: 2.28 MB (2393476)
- NumFunctions: 13 (13)
- NumInstructions: 254 (254)
- OptimizationTime: 35.999ms
- PeakMemoryUsage: 127.00 KB (130048)
- PrepareTime: 39.999ms
Created 08-19-2020 02:50 PM
3) querying a view, which has only the columns present in the select of the query, rather than all columns of the table.
Query Runtime Profile:
Query (id=2b4478280f2c43ac:621b87f300000000):
Summary:
Session ID: bb480b18a48ed00b:ef4322da7645b7a6
Session Type: BEESWAX
Start Time: 2020-08-18 12:14:03.290383000
End Time: 2020-08-18 12:14:03.616854000
Query Type: QUERY
Query State: FINISHED
Query Status: OK
Impala Version: impalad version 3.2.0-cdh6.3.1 RELEASE (build 3d5de689e9b9cfde0c01e1c64f4b4e830cee69c3)
Default Db: default
Sql Statement: SELECT sum(column1) from db.view_test where partition_col = 1597431600
Coordinator: impalad-0:22000
Query Options (set by configuration): NUM_SCANNER_THREADS=8,QUERY_TIMEOUT_S=600,SCRATCH_LIMIT=137438953472,CLIENT_IDENTIFIER=Impala Shell v3.2.0-cdh6.3.1 (3d5de68) built on Thu Sep 26 03:03:52 PDT 2019
Query Options (set by configuration and planner): NUM_SCANNER_THREADS=8,QUERY_TIMEOUT_S=600,MT_DOP=0,SCRATCH_LIMIT=137438953472,CLIENT_IDENTIFIER=Impala Shell v3.2.0-cdh6.3.1 (3d5de68) built on Thu Sep 26 03:03:52 PDT 2019
Plan:
----------------
Max Per-Host Resource Reservation: Memory=4.00MB Threads=3
Per-Host Resource Estimates: Memory=100MB
WARNING: The following tables are missing relevant table and/or column statistics.
db.table_test
Analyzed query: SELECT sum(CAST(column1 AS BIGINT)) FROM
db.view_test WHERE partition_col = CAST(1597431600 AS BIGINT)
F01:PLAN FRAGMENT [UNPARTITIONED] hosts=1 instances=1
| Per-Host Resources: mem-estimate=10.02MB mem-reservation=0B thread-reservation=1
PLAN-ROOT SINK
| mem-estimate=0B mem-reservation=0B thread-reservation=0
|
03:AGGREGATE [FINALIZE]
| output: sum:merge(column1)
| mem-estimate=10.00MB mem-reservation=0B spill-buffer=2.00MB thread-reservation=0
| tuple-ids=2 row-size=8B cardinality=1
| in pipelines: 03(GETNEXT), 01(OPEN)
|
02:EXCHANGE [UNPARTITIONED]
| mem-estimate=16.00KB mem-reservation=0B thread-reservation=0
| tuple-ids=2 row-size=8B cardinality=1
| in pipelines: 01(GETNEXT)
|
F00:PLAN FRAGMENT [RANDOM] hosts=1 instances=1
Per-Host Resources: mem-estimate=90.00MB mem-reservation=4.00MB thread-reservation=2
01:AGGREGATE
| output: sum(CAST(column1 AS BIGINT))
| mem-estimate=10.00MB mem-reservation=0B spill-buffer=2.00MB thread-reservation=0
| tuple-ids=2 row-size=8B cardinality=1
| in pipelines: 01(GETNEXT), 00(OPEN)
|
00:SCAN HDFS [db.table_test, RANDOM]
partition predicates: db.table_test.partition_col = CAST(1597431600 AS BIGINT)
partitions=1/7 files=1 size=67.53MB
stored statistics:
table: rows=unavailable size=unavailable
partitions: 0/1 rows=unavailable
columns missing stats: column1
extrapolated-rows=disabled max-scan-range-rows=unavailable
mem-estimate=80.00MB mem-reservation=4.00MB thread-reservation=1
tuple-ids=0 row-size=4B cardinality=unavailable
in pipelines: 00(GETNEXT)
----------------
Estimated Per-Host Mem: 104873984
Tables Missing Stats: db.table_test
Per Host Min Memory Reservation: impalad-0:22000(4.00 MB)
Request Pool: root.default
Admission result: Admitted immediately
Cluster Memory Admitted: 100.02 MB
ExecSummary:
Operator #Hosts Avg Time Max Time #Rows Est. #Rows Peak Mem Est. Peak Mem Detail
-------------------------------------------------------------------------------------------------------------------------------------------
F01:ROOT 1 0.000ns 0.000ns 0 0
03:AGGREGATE 1 0.000ns 0.000ns 1 1 16.00 KB 10.00 MB FINALIZE
02:EXCHANGE 1 0.000ns 0.000ns 1 1 16.00 KB 16.00 KB UNPARTITIONED
F00:EXCHANGE SENDER 1 0.000ns 0.000ns 14.22 KB 0
01:AGGREGATE 1 59.999ms 59.999ms 1 1 21.00 KB 10.00 MB
00:SCAN HDFS 1 47.999ms 47.999ms 6.76M -1 4.53 MB 80.00 MB db.table_test
Errors:
Query Compilation: 6.732ms
- Metadata of all 2 tables cached: 1.828ms (1.828ms)
- Analysis finished: 4.138ms (2.310ms)
- Value transfer graph computed: 4.180ms (41.991us)
- Single node plan created: 5.345ms (1.165ms)
- Runtime filters computed: 5.499ms (153.055us)
- Distributed plan created: 5.538ms (39.917us)
- Planning finished: 6.732ms (1.193ms)
Query Timeline: 335.994ms
- Query submitted: 0.000ns (0.000ns)
- Planning finished: 7.999ms (7.999ms)
- Submit for admission: 11.999ms (3.999ms)
- Completed admission: 11.999ms (0.000ns)
- Ready to start on 1 backends: 11.999ms (0.000ns)
- All 1 execution backends (2 fragment instances) started: 19.999ms (7.999ms)
- Rows available: 251.996ms (231.996ms)
- First row fetched: 319.994ms (67.998ms)
- Last row fetched: 323.994ms (3.999ms)
- Released admission control resources: 323.994ms (0.000ns)
- Unregister query: 327.994ms (3.999ms)
- AdmissionControlTimeSinceLastUpdate: 16.000ms
- ComputeScanRangeAssignmentTimer: 0.000ns
Frontend:
ImpalaServer:
- ClientFetchWaitTimer: 67.998ms
- RowMaterializationTimer: 7.999ms
Execution Profile 2b4478280f2c43ac:621b87f300000000:(Total: 247.996ms, 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: 1, min / max: 6ms / 6ms, 25th %-ile: 6ms, 50th %-ile: 6ms, 75th %-ile: 6ms, 90th %-ile: 6ms, 95th %-ile: 6ms, 99.9th %-ile: 6ms
Slowest backend to start up: impalad-0:22000
Per Node Peak Memory Usage: impalad-0:22000(4.58 MB)
Per Node Bytes Read: impalad-0:22000(100.48 KB)
Per Node User Time: impalad-0:22000(297.010ms)
Per Node System Time: impalad-0:22000(40.216ms)
- ExchangeScanRatio: 0.00
- FiltersReceived: 0 (0)
- FinalizationTimer: 0.000ns
- InnerNodeSelectivityRatio: 0.00
- NumBackends: 1 (1)
- NumFragmentInstances: 2 (2)
- NumFragments: 2 (2)
- TotalBytesRead: 100.48 KB (102895)
- TotalBytesSent: 13.00 B (13)
- TotalCpuTime: 337.226ms
- TotalInnerBytesSent: 0
- TotalScanBytesSent: 13.00 B (13)
Per Node Profiles:
impalad-0:22000:
- ScratchBytesRead: 0
- ScratchBytesWritten: 0
- ScratchFileUsedBytes: 0
- ScratchReads: 0 (0)
- ScratchWrites: 0 (0)
- TotalEncryptionTime: 0.000ns
- TotalReadBlockTime: 0.000ns
Averaged Fragment F01:(Total: 303.995ms, non-child: 0.000ns, % non-child: 0.00%)
split sizes: min: 0, max: 0, avg: 0, stddev: 0
completion times: min:303.995ms max:303.995ms mean: 303.995ms 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
- ExchangeScanRatio: 0.00
- PeakMemoryUsage: 40.00 KB (40960)
- PeakReservation: 0
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 4.58 MB (4805270)
- RowsProduced: 1 (1)
- TotalNetworkReceiveTime: 187.997ms
- TotalNetworkSendTime: 0.000ns
- TotalStorageWaitTime: 0.000ns
- TotalThreadsInvoluntaryContextSwitches: 79 (79)
- TotalThreadsTotalWallClockTime: 303.995ms
- TotalThreadsSysTime: 0.000ns
- TotalThreadsUserTime: 40.921ms
- TotalThreadsVoluntaryContextSwitches: 3 (3)
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 0
- CumulativeAllocations: 0 (0)
- PeakReservation: 0
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 0
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- ReservationLimit: 0
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Fragment Instance Lifecycle Timings:
- ExecTime: 71.998ms
- ExecTreeExecTime: 0.000ns
- OpenTime: 231.996ms
- ExecTreeOpenTime: 187.997ms
- PrepareTime: 0.000ns
- ExecTreePrepareTime: 0.000ns
PLAN_ROOT_SINK:(Total: 71.998ms, non-child: 71.998ms, % non-child: 100.00%)
- PeakMemoryUsage: 0
AGGREGATION_NODE (id=3):(Total: 187.997ms, non-child: 0.000ns, % non-child: 0.00%)
- PeakMemoryUsage: 16.00 KB (16384)
- RowsReturned: 1 (1)
- RowsReturnedRate: 5.00 /sec
NonGroupingAggregator 0:
- BuildTime: 0.000ns
- PeakMemoryUsage: 8.00 KB (8192)
- RowsReturned: 1 (1)
EXCHANGE_NODE (id=2):(Total: 187.997ms, non-child: 187.997ms, % non-child: 100.00%)
- ConvertRowBatchTime: 0.000ns
- PeakMemoryUsage: 16.00 KB (16384)
- RowsReturned: 1 (1)
- RowsReturnedRate: 5.00 /sec
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 16.00 KB (16384)
- CumulativeAllocations: 2 (2)
- PeakReservation: 16.00 KB (16384)
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 16.00 KB (16384)
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Dequeue:
- FirstBatchWaitTime: 187.997ms
- TotalBytesDequeued: 17.00 B (17)
- TotalGetBatchTime: 187.997ms
- DataWaitTime: 187.997ms
Enqueue:
- DeserializeRowBatchTime: 0.000ns
- TotalBatchesEnqueued: 1 (1)
- TotalBatchesReceived: 1 (1)
- TotalBytesReceived: 13.00 B (13)
- TotalEarlySenders: 0 (0)
- TotalEosReceived: 1 (1)
- TotalHasDeferredRPCsTime: 0.000ns
- TotalRPCsDeferred: 0 (0)
CodeGen:(Total: 43.999ms, non-child: 43.999ms, % non-child: 100.00%)
- CodegenInvoluntaryContextSwitches: 79 (79)
- CodegenTotalWallClockTime: 43.999ms
- CodegenSysTime: 0.000ns
- CodegenUserTime: 40.378ms
- CodegenVoluntaryContextSwitches: 0 (0)
- CompileTime: 0.000ns
- IrGenerationTime: 0.000ns
- LoadTime: 0.000ns
- ModuleBitcodeSize: 2.28 MB (2393476)
- NumFunctions: 0 (0)
- NumInstructions: 0 (0)
- OptimizationTime: 0.000ns
- PeakMemoryUsage: 0
- PrepareTime: 43.999ms
Coordinator Fragment F01:
Instance 2b4478280f2c43ac:621b87f300000000 (host=impalad-0:22000):(Total: 303.995ms, non-child: 0.000ns, % non-child: 0.00%)
Last report received time: 2020-08-18 12:14:03.616
Fragment Instance Lifecycle Event Timeline: 303.995ms
- Prepare Finished: 0.000ns (0.000ns)
- Open Finished: 231.996ms (231.996ms)
- First Batch Produced: 231.996ms (0.000ns)
- First Batch Sent: 303.995ms (71.998ms)
- ExecInternal Finished: 303.995ms (0.000ns)
- MemoryUsage (500.000ms): 12.00 KB
- AverageThreadTokens: 0.00
- BloomFilterBytes: 0
- ExchangeScanRatio: 0.00
- PeakMemoryUsage: 40.00 KB (40960)
- PeakReservation: 0
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 4.58 MB (4805270)
- RowsProduced: 1 (1)
- TotalNetworkReceiveTime: 187.997ms
- TotalNetworkSendTime: 0.000ns
- TotalStorageWaitTime: 0.000ns
- TotalThreadsInvoluntaryContextSwitches: 79 (79)
- TotalThreadsTotalWallClockTime: 303.995ms
- TotalThreadsSysTime: 0.000ns
- TotalThreadsUserTime: 40.921ms
- TotalThreadsVoluntaryContextSwitches: 3 (3)
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 0
- CumulativeAllocations: 0 (0)
- PeakReservation: 0
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 0
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- ReservationLimit: 0
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Fragment Instance Lifecycle Timings:
- ExecTime: 71.998ms
- ExecTreeExecTime: 0.000ns
- OpenTime: 231.996ms
- ExecTreeOpenTime: 187.997ms
- PrepareTime: 0.000ns
- ExecTreePrepareTime: 0.000ns
PLAN_ROOT_SINK:(Total: 71.998ms, non-child: 0.000ns, % non-child: 0.00%)
- PeakMemoryUsage: 0
AGGREGATION_NODE (id=3):(Total: 187.997ms, non-child: 0.000ns, % non-child: 0.00%)
Node Lifecycle Event Timeline: 303.995ms
- Open Started: 43.999ms (43.999ms)
- Open Finished: 231.996ms (187.997ms)
- First Batch Requested: 231.996ms (0.000ns)
- First Batch Returned: 231.996ms (0.000ns)
- Last Batch Returned: 231.996ms (0.000ns)
- Closed: 303.995ms (71.998ms)
- PeakMemoryUsage: 16.00 KB (16384)
- RowsReturned: 1 (1)
- RowsReturnedRate: 5.00 /sec
NonGroupingAggregator 0:
- BuildTime: 0.000ns
- PeakMemoryUsage: 8.00 KB (8192)
- RowsReturned: 1 (1)
EXCHANGE_NODE (id=2):(Total: 187.997ms, non-child: 0.000ns, % non-child: 0.00%)
Node Lifecycle Event Timeline: 231.996ms
- Open Started: 43.999ms (43.999ms)
- Open Finished: 231.996ms (187.997ms)
- First Batch Requested: 231.996ms (0.000ns)
- First Batch Returned: 231.996ms (0.000ns)
- Last Batch Returned: 231.996ms (0.000ns)
- Closed: 231.996ms (0.000ns)
- ConvertRowBatchTime: 0.000ns
- PeakMemoryUsage: 16.00 KB (16384)
- RowsReturned: 1 (1)
- RowsReturnedRate: 5.00 /sec
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 16.00 KB (16384)
- CumulativeAllocations: 2 (2)
- PeakReservation: 16.00 KB (16384)
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 16.00 KB (16384)
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Dequeue:
- BytesDequeued (500.000ms): 0
- FirstBatchWaitTime: 187.997ms
- TotalBytesDequeued: 17.00 B (17)
- TotalGetBatchTime: 187.997ms
- DataWaitTime: 187.997ms
Enqueue:
- BytesReceived (500.000ms): 0
- DeferredQueueSize (500.000ms): 0
- DispatchTime: (Avg: 80.415us ; Min: 80.415us ; Max: 80.415us ; Number of samples: 1)
- DeserializeRowBatchTime: 0.000ns
- TotalBatchesEnqueued: 1 (1)
- TotalBatchesReceived: 1 (1)
- TotalBytesReceived: 13.00 B (13)
- TotalEarlySenders: 0 (0)
- TotalEosReceived: 1 (1)
- TotalHasDeferredRPCsTime: 0.000ns
- TotalRPCsDeferred: 0 (0)
CodeGen:(Total: 43.999ms, non-child: 43.999ms, % non-child: 100.00%)
- CodegenInvoluntaryContextSwitches: 79 (79)
- CodegenTotalWallClockTime: 43.999ms
- CodegenSysTime: 0.000ns
- CodegenUserTime: 40.378ms
- CodegenVoluntaryContextSwitches: 0 (0)
- CompileTime: 0.000ns
- IrGenerationTime: 0.000ns
- LoadTime: 0.000ns
- ModuleBitcodeSize: 2.28 MB (2393476)
- NumFunctions: 0 (0)
- NumInstructions: 0 (0)
- OptimizationTime: 0.000ns
- PeakMemoryUsage: 0
- PrepareTime: 43.999ms
Averaged Fragment F00:(Total: 231.996ms, non-child: 0.000ns, % non-child: 0.00%)
split sizes: min: 67.53 MB, max: 67.53 MB, avg: 67.53 MB, stddev: 0
completion times: min:303.995ms max:303.995ms mean: 303.995ms stddev:0.000ns
execution rates: min:222.14 MB/sec max:222.14 MB/sec mean:222.14 MB/sec stddev:0.00 /sec
num instances: 1
- AverageThreadTokens: 1.00
- BloomFilterBytes: 0
- ExchangeScanRatio: 0.00
- PeakMemoryUsage: 4.57 MB (4792982)
- PeakReservation: 4.00 MB (4194304)
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 4.58 MB (4805270)
- RowsProduced: 1 (1)
- TotalNetworkReceiveTime: 0.000ns
- TotalNetworkSendTime: 0.000ns
- TotalStorageWaitTime: 3.999ms
- TotalThreadsInvoluntaryContextSwitches: 212 (212)
- TotalThreadsTotalWallClockTime: 339.994ms
- TotalThreadsSysTime: 40.216ms
- TotalThreadsUserTime: 256.089ms
- TotalThreadsVoluntaryContextSwitches: 822 (822)
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 0
- CumulativeAllocations: 0 (0)
- PeakReservation: 0
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 0
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- ReservationLimit: 0
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Fragment Instance Lifecycle Timings:
- ExecTime: 0.000ns
- ExecTreeExecTime: 0.000ns
- OpenTime: 231.996ms
- ExecTreeOpenTime: 107.998ms
- PrepareTime: 0.000ns
- ExecTreePrepareTime: 0.000ns
KrpcDataStreamSender (dst_id=2):
- EosSent: 1 (1)
- PeakMemoryUsage: 14.22 KB (14560)
- RowsSent: 1 (1)
- RpcFailure: 0 (0)
- RpcRetry: 0 (0)
- SerializeBatchTime: 0.000ns
- TotalBytesSent: 13.00 B (13)
- UncompressedRowBatchSize: 17.00 B (17)
AGGREGATION_NODE (id=1):(Total: 107.998ms, non-child: 59.999ms, % non-child: 55.56%)
- PeakMemoryUsage: 21.00 KB (21504)
- RowsReturned: 1 (1)
- RowsReturnedRate: 9.00 /sec
NonGroupingAggregator 0:
- BuildTime: 47.999ms
- PeakMemoryUsage: 8.00 KB (8192)
- RowsReturned: 1 (1)
HDFS_SCAN_NODE (id=0):(Total: 47.999ms, non-child: 47.999ms, % non-child: 100.00%)
- AverageHdfsReadThreadConcurrency: 0.00
- AverageScannerThreadConcurrency: 0.00
- BytesRead: 100.48 KB (102895)
- BytesReadDataNodeCache: 0
- BytesReadLocal: 100.48 KB (102895)
- BytesReadRemoteUnexpected: 0
- BytesReadShortCircuit: 100.48 KB (102895)
- CachedFileHandle**bleep**Count: 2 (2)
- CachedFileHandlesMissCount: 0 (0)
- CollectionItemsRead: 0 (0)
- DataCacheHitBytes: 0
- DataCacheHitCount: 0 (0)
- DataCacheMissBytes: 0
- DataCacheMissCount: 0 (0)
- DataCachePartialHitCount: 0 (0)
- DecompressionTime: 3.999ms
- MaterializeTupleTime(*): 79.998ms
- MaxCompressedTextFileLength: 0
- NumColumns: 1 (1)
- NumDictFilteredRowGroups: 0 (0)
- NumDisksAccessed: 1 (1)
- NumRowGroups: 1 (1)
- NumScannerThreadMemUnavailable: 0 (0)
- NumScannerThreadReservationsDenied: 0 (0)
- NumScannerThreadsStarted: 1 (1)
- NumScannersWithNoReads: 0 (0)
- NumStatsFilteredRowGroups: 0 (0)
- PeakMemoryUsage: 4.53 MB (4748292)
- PeakScannerThreadConcurrency: 1 (1)
- PerReadThreadRawHdfsThroughput: 24.53 MB/sec
- RemoteScanRanges: 0 (0)
- RowBatchBytesEnqueued: 32.25 MB (33812480)
- RowBatchQueueGetWaitTime: 31.999ms
- RowBatchQueuePeakMemoryUsage: 533.00 KB (545792)
- RowBatchQueuePutWaitTime: 0.000ns
- RowBatchesEnqueued: 6.61K (6606)
- RowsRead: 6.76M (6761664)
- RowsReturned: 6.76M (6761664)
- RowsReturnedRate: 140.87 M/sec
- ScanRangesComplete: 1 (1)
- ScannerIoWaitTime: 3.999ms
- ScannerThreadWorklessLoops: 0 (0)
- ScannerThreadsInvoluntaryContextSwitches: 171 (171)
- ScannerThreadsTotalWallClockTime: 107.998ms
- ScannerThreadsSysTime: 8.063ms
- ScannerThreadsUserTime: 83.824ms
- ScannerThreadsVoluntaryContextSwitches: 6 (6)
- TotalRawHdfsOpenFileTime(*): 0.000ns
- TotalRawHdfsReadTime(*): 3.999ms
- TotalReadThroughput: 0.00 /sec
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 136.00 KB (139264)
- CumulativeAllocations: 2 (2)
- PeakReservation: 4.00 MB (4194304)
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 128.00 KB (131072)
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
CodeGen:(Total: 123.998ms, non-child: 123.998ms, % non-child: 100.00%)
- CodegenInvoluntaryContextSwitches: 16 (16)
- CodegenTotalWallClockTime: 123.998ms
- CodegenSysTime: 4.091ms
- CodegenUserTime: 116.221ms
- CodegenVoluntaryContextSwitches: 2 (2)
- CompileTime: 23.999ms
- IrGenerationTime: 3.999ms
- LoadTime: 0.000ns
- ModuleBitcodeSize: 2.28 MB (2393476)
- NumFunctions: 13 (13)
- NumInstructions: 254 (254)
- OptimizationTime: 47.999ms
- PeakMemoryUsage: 127.00 KB (130048)
- PrepareTime: 43.999ms
Fragment F00:
Instance 2b4478280f2c43ac:621b87f300000001 (host=impalad-0:22000):(Total: 231.996ms, non-child: 0.000ns, % non-child: 0.00%)
Last report received time: 2020-08-18 12:14:03.615
Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/67.53 MB
Fragment Instance Lifecycle Event Timeline: 231.996ms
- Prepare Finished: 0.000ns (0.000ns)
- Open Finished: 231.996ms (231.996ms)
- First Batch Produced: 231.996ms (0.000ns)
- First Batch Sent: 231.996ms (0.000ns)
- ExecInternal Finished: 231.996ms (0.000ns)
- MemoryUsage (500.000ms): 30.64 KB
- ThreadUsage (500.000ms): 1
- AverageThreadTokens: 1.00
- BloomFilterBytes: 0
- ExchangeScanRatio: 0.00
- PeakMemoryUsage: 4.57 MB (4792982)
- PeakReservation: 4.00 MB (4194304)
- PeakUsedReservation: 0
- PerHostPeakMemUsage: 4.58 MB (4805270)
- RowsProduced: 1 (1)
- TotalNetworkReceiveTime: 0.000ns
- TotalNetworkSendTime: 0.000ns
- TotalStorageWaitTime: 3.999ms
- TotalThreadsInvoluntaryContextSwitches: 212 (212)
- TotalThreadsTotalWallClockTime: 339.994ms
- TotalThreadsSysTime: 40.216ms
- TotalThreadsUserTime: 256.089ms
- TotalThreadsVoluntaryContextSwitches: 822 (822)
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 0
- CumulativeAllocations: 0 (0)
- PeakReservation: 0
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 0
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- ReservationLimit: 0
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
Fragment Instance Lifecycle Timings:
- ExecTime: 0.000ns
- ExecTreeExecTime: 0.000ns
- OpenTime: 231.996ms
- ExecTreeOpenTime: 107.998ms
- PrepareTime: 0.000ns
- ExecTreePrepareTime: 0.000ns
KrpcDataStreamSender (dst_id=2):
ExecOption: Unpartitioned Sender Codegen Disabled: not needed
- BytesSent (500.000ms): 0
- NetworkThroughput: (Avg: 9.44 KB/sec ; Min: 9.44 KB/sec ; Max: 9.44 KB/sec ; Number of samples: 1)
- EosSent: 1 (1)
- PeakMemoryUsage: 14.22 KB (14560)
- RowsSent: 1 (1)
- RpcFailure: 0 (0)
- RpcRetry: 0 (0)
- SerializeBatchTime: 0.000ns
- TotalBytesSent: 13.00 B (13)
- UncompressedRowBatchSize: 17.00 B (17)
AGGREGATION_NODE (id=1):(Total: 107.998ms, non-child: 59.999ms, % non-child: 55.56%)
Node Lifecycle Event Timeline: 231.996ms
- Open Started: 123.998ms (123.998ms)
- Open Finished: 231.996ms (107.998ms)
- First Batch Requested: 231.996ms (0.000ns)
- First Batch Returned: 231.996ms (0.000ns)
- Last Batch Returned: 231.996ms (0.000ns)
- Closed: 231.996ms (0.000ns)
- PeakMemoryUsage: 21.00 KB (21504)
- RowsReturned: 1 (1)
- RowsReturnedRate: 9.00 /sec
NonGroupingAggregator 0:
ExecOption: Codegen Enabled
- BuildTime: 47.999ms
- PeakMemoryUsage: 8.00 KB (8192)
- RowsReturned: 1 (1)
HDFS_SCAN_NODE (id=0):(Total: 47.999ms, non-child: 47.999ms, % non-child: 100.00%)
Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/67.53 MB
ExecOption: PARQUET Codegen Enabled, Codegen enabled: 1 out of 1
Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0% 7:0% 8:0% 9:0% 10:0% 11:0% 12:0% 13:0% 14:0%
File Formats: PARQUET/SNAPPY:1
Node Lifecycle Event Timeline: 231.996ms
- Open Started: 123.998ms (123.998ms)
- Open Finished: 123.998ms (0.000ns)
- First Batch Requested: 123.998ms (0.000ns)
- First Batch Returned: 131.997ms (7.999ms)
- Last Batch Returned: 231.996ms (99.998ms)
- Closed: 231.996ms (0.000ns)
- FooterProcessingTime: (Avg: 7.999ms ; Min: 7.999ms ; Max: 7.999ms ; Number of samples: 1)
- InitialRangeActualReservation: (Avg: 4.00 MB (4194304) ; Min: 4.00 MB (4194304) ; Max: 4.00 MB (4194304) ; Number of samples: 1)
- InitialRangeIdealReservation: (Avg: 128.00 KB (131072) ; Min: 128.00 KB (131072) ; Max: 128.00 KB (131072) ; Number of samples: 1)
- ParquetCompressedBytesReadPerColumn: (Avg: 210.00 B (210) ; Min: 210.00 B (210) ; Max: 210.00 B (210) ; Number of samples: 1)
- ParquetCompressedPageSize: (Avg: 15.00 B (15) ; Min: 15.00 B (15) ; Max: 15.00 B (15) ; Number of samples: 14)
- ParquetRowGroupActualReservation: (Avg: 4.00 MB (4194304) ; Min: 4.00 MB (4194304) ; Max: 4.00 MB (4194304) ; Number of samples: 1)
- ParquetRowGroupIdealReservation: (Avg: 8.00 KB (8192) ; Min: 8.00 KB (8192) ; Max: 8.00 KB (8192) ; Number of samples: 1)
- ParquetUncompressedBytesReadPerColumn: (Avg: 182.00 B (182) ; Min: 182.00 B (182) ; Max: 182.00 B (182) ; Number of samples: 1)
- ParquetUncompressedPageSize: (Avg: 13.00 B (13) ; Min: 13.00 B (13) ; Max: 13.00 B (13) ; Number of samples: 14)
- AverageHdfsReadThreadConcurrency: 0.00
- AverageScannerThreadConcurrency: 0.00
- BytesRead: 100.48 KB (102895)
- BytesReadDataNodeCache: 0
- BytesReadLocal: 100.48 KB (102895)
- BytesReadRemoteUnexpected: 0
- BytesReadShortCircuit: 100.48 KB (102895)
- CachedFileHandle**bleep**Count: 2 (2)
- CachedFileHandlesMissCount: 0 (0)
- CollectionItemsRead: 0 (0)
- DataCacheHitBytes: 0
- DataCacheHitCount: 0 (0)
- DataCacheMissBytes: 0
- DataCacheMissCount: 0 (0)
- DataCachePartialHitCount: 0 (0)
- DecompressionTime: 3.999ms
- MaterializeTupleTime(*): 79.998ms
- MaxCompressedTextFileLength: 0
- NumColumns: 1 (1)
- NumDictFilteredRowGroups: 0 (0)
- NumDisksAccessed: 1 (1)
- NumRowGroups: 1 (1)
- NumScannerThreadMemUnavailable: 0 (0)
- NumScannerThreadReservationsDenied: 0 (0)
- NumScannerThreadsStarted: 1 (1)
- NumScannersWithNoReads: 0 (0)
- NumStatsFilteredRowGroups: 0 (0)
- PeakMemoryUsage: 4.53 MB (4748292)
- PeakScannerThreadConcurrency: 1 (1)
- PerReadThreadRawHdfsThroughput: 24.53 MB/sec
- RemoteScanRanges: 0 (0)
- RowBatchBytesEnqueued: 32.25 MB (33812480)
- RowBatchQueueGetWaitTime: 31.999ms
- RowBatchQueuePeakMemoryUsage: 533.00 KB (545792)
- RowBatchQueuePutWaitTime: 0.000ns
- RowBatchesEnqueued: 6.61K (6606)
- RowsRead: 6.76M (6761664)
- RowsReturned: 6.76M (6761664)
- RowsReturnedRate: 140.87 M/sec
- ScanRangesComplete: 1 (1)
- ScannerIoWaitTime: 3.999ms
- ScannerThreadWorklessLoops: 0 (0)
- ScannerThreadsInvoluntaryContextSwitches: 171 (171)
- ScannerThreadsTotalWallClockTime: 107.998ms
- ScannerThreadsSysTime: 8.063ms
- ScannerThreadsUserTime: 83.824ms
- ScannerThreadsVoluntaryContextSwitches: 6 (6)
- TotalRawHdfsOpenFileTime(*): 0.000ns
- TotalRawHdfsReadTime(*): 3.999ms
- TotalReadThroughput: 0.00 /sec
Buffer pool:
- AllocTime: 0.000ns
- CumulativeAllocationBytes: 136.00 KB (139264)
- CumulativeAllocations: 2 (2)
- PeakReservation: 4.00 MB (4194304)
- PeakUnpinnedBytes: 0
- PeakUsedReservation: 128.00 KB (131072)
- ReadIoBytes: 0
- ReadIoOps: 0 (0)
- ReadIoWaitTime: 0.000ns
- SystemAllocTime: 0.000ns
- WriteIoBytes: 0
- WriteIoOps: 0 (0)
- WriteIoWaitTime: 0.000ns
CodeGen:(Total: 123.998ms, non-child: 123.998ms, % non-child: 100.00%)
- CodegenInvoluntaryContextSwitches: 16 (16)
- CodegenTotalWallClockTime: 123.998ms
- CodegenSysTime: 4.091ms
- CodegenUserTime: 116.221ms
- CodegenVoluntaryContextSwitches: 2 (2)
- CompileTime: 23.999ms
- IrGenerationTime: 3.999ms
- LoadTime: 0.000ns
- ModuleBitcodeSize: 2.28 MB (2393476)
- NumFunctions: 13 (13)
- NumInstructions: 254 (254)
- OptimizationTime: 47.999ms
- PeakMemoryUsage: 127.00 KB (130048)
- PrepareTime: 43.999ms
Query runtime of 1 and 3 are similar, but it is much higher for 2. In all cases, it was used the same Impala partition (i.e., exactly the same data) and the same query.
There are actually 486 columns in the table. I noticed that all columns appear under "columns missing stats" for case 2, but for cases 1 and 3 only the "column1" that is in my query appears there.
I was wondering if this issue might be related to https://issues.apache.org/jira/browse/IMPALA-9358, although in my case I'm not using inline views.
From my experiments, looks like the query performance penalty is depending only on the number of columns in the view and it does not depend much on data size or complexity of the query itself. The idea is that we have some time that would normally be spent on HDFS scan and aggregations (query execution) for all cases, plus this penalty to compile the query, which happens only for case 2.
Thanks!
Created 09-28-2020 07:58 AM
Hi @PauloRC @Tim Armstrong ,
This might be a performance regression, but also in general a performance inefficiency with a specific planner data structure.
A correctness fix for IMPALA-8386 may have introduced this perf regression in 3.2.1, IMPALA-9358 may resolve this issue, but I don't think it's available in any CDH 6.3 release yet.
@PauloRC one thing to try which might mitigate the issue is to run your view query with SET ENABLE_EXPR_REWRITES=false to see if that helps.