question Re: Impala 3.2.0 performance degradation while querying views in Support Questions

question Re: Impala 3.2.0 performance degradation while querying views in Support Questions https://community.cloudera.com/t5/Support-Questions/Impala-3-2-0-performance-degradation-while-querying-views/m-p/301666#M220794 3) querying a view, which has only the columns present in the select of the query, rather than all columns of the table. <LI-CODE lang="markup">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 </LI-CODE> 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 <A href="https://issues.apache.org/jira/browse/IMPALA-9358" target="_blank">https://issues.apache.org/jira/browse/IMPALA-9358</A>, 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! Wed, 19 Aug 2020 21:50:51 GMT PauloRC 2020-08-19T21:50:51Z