You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@impala.apache.org by "Alan Choi (JIRA)" <ji...@apache.org> on 2017/07/19 16:54:00 UTC

[jira] [Created] (IMPALA-5682) Query execution time is unaccounted for in an extremely selective query

Alan Choi created IMPALA-5682:
---------------------------------

             Summary: Query execution time is unaccounted for in an extremely selective query
                 Key: IMPALA-5682
                 URL: https://issues.apache.org/jira/browse/IMPALA-5682
             Project: IMPALA
          Issue Type: Improvement
          Components: be, Perf Investigation
            Reporter: Alan Choi
            Assignee: Tim Armstrong


Even after IMPALA-4923 is fixed, query execution time is unaccounted for in an extremely selective query. See this query profile extract:

        SORT_NODE (id=1):(Total: 1s436ms, *{color:red}non-child: 416.017ms{color}*, % non-child: 28.96%)
          ExecOption: Codegen Enabled
           - {color:red}*InMemorySortTime: 165.000ns*{color}
           - InitialRunsCreated: 1 (1)
           - PeakMemoryUsage: 32.07 MB (33626999)
           - RowsReturned: 0 (0)
           - RowsReturnedRate: 0
           - SortDataSize: 0
           - SpilledRuns: 0 (0)
           - TotalMergesPerformed: 0 (0)
        HDFS_SCAN_NODE (id=0):(Total: 1s020ms, non-child: 1s020ms, % non-child: 100.00%)
          Hdfs split stats (<volume id>:<# splits>/<split lengths>): 2:9/2.25 GB 0:3/600.90 MB 1:4/685.12 MB 
          ExecOption: PARQUET Codegen Enabled, Codegen enabled: 16 out of 16
          Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0% 
          File Formats: PARQUET/SNAPPY:16 
          BytesRead(500.000ms): 0, 1.37 GB, 2.70 GB
           - FooterProcessingTime: (Avg: 3.065ms ; Min: 712.185us ; Max: 12.901ms ; Number of samples: 16)
           - AverageHdfsReadThreadConcurrency: 0.00 
           - AverageScannerThreadConcurrency: 7.50 
           - BytesRead: 3.51 GB (3763724319)
           - BytesReadDataNodeCache: 0
           - BytesReadLocal: 3.51 GB (3763724319)
           - BytesReadRemoteUnexpected: 0
           - BytesReadShortCircuit: 3.51 GB (3763724319)
           - DecompressionTime: 7s321ms
           - MaxCompressedTextFileLength: 0
           - NumColumns: 1 (1)
           - NumDictFilteredRowGroups: 0 (0)
           - NumDisksAccessed: 3 (3)
           - NumRowGroups: 16 (16)
           - NumScannerThreadsStarted: 8 (8)
           - NumScannersWithNoReads: 0 (0)
           - NumStatsFilteredRowGroups: 0 (0)
           - PeakMemoryUsage: 361.49 MB (379053770)
           - PerReadThreadRawHdfsThroughput: 2.25 GB/sec
           - RemoteScanRanges: 0 (0)
           - RowBatchQueueGetWaitTime: 1s016ms
           - RowBatchQueuePutWaitTime: 0.000ns
           - {color:red}*RowsRead: 103.96M*{color} (103960000)
           - {color:red}*RowsReturned: 0 (0)*{color}
           - RowsReturnedRate: 0
           - ScanRangesComplete: 16 (16)
           - ScannerThreadsInvoluntaryContextSwitches: 2.80K (2797)
           - ScannerThreadsTotalWallClockTime: 9s918ms
             - MaterializeTupleTime(*): 1s773ms
             - ScannerThreadsSysTime: 724.000ms
             - ScannerThreadsUserTime: 7s536ms
           - ScannerThreadsVoluntaryContextSwitches: 395 (395)
           - TotalRawHdfsReadTime(*): 1s555ms
           - TotalReadThroughput: 1.80 GB/sec

The sort node has processed zero rows but still spent ~500ms.



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)