Uploaded image for project: 'IMPALA'
  1. IMPALA
  2. IMPALA-5682

Freeing memory from other plan nodes in RowBatch::Reset() results in confusing execution time breakdown

    XMLWordPrintableJSON

    Details

    • Type: Improvement
    • Status: Open
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: Impala 2.9.0
    • Fix Version/s: None
    • Component/s: Perf Investigation
    • Labels:
      None

      Description

      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, non-child: 416.017ms, % non-child: 28.96%)
      ExecOption: Codegen Enabled

      • InMemorySortTime: 165.000ns
      • 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
      • RowsRead: 103.96M (103960000)
      • RowsReturned: 0 (0)
      • 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.

        Attachments

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              alan@cloudera.com Alan Choi
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated: