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

Per operator timing in profile summary is incorrect when mt_dop > 0

    Details

      Description

      From the summary

      Operator #Hosts Avg Time Max Time #Rows Est. #Rows Peak Mem Est. Peak Mem Detail
      03:AGGREGATE 1 8.668ms 8.668ms 1 1 7.79 MB -1.00 B FINALIZE
      02:EXCHANGE 1 4.914ms 4.914ms 480 1 0 -1.00 B UNPARTITIONED
      01:AGGREGATE 480 1s024ms 21s191ms 24 1 14.04 MB -1.00 B  
      00:SCAN HDFS 480 949.025ms 20s143ms 900.74M 18.00B 136.28 MB -1.00 B tpch_3000_parquet.lineitem

      The slowest fragment in the query

            Instance d1403bdbfb6c9d71:156 (host=d2403.halxg.cloudera.com:22000):(Total: 36s524ms, non-child: 15.297ms, % non-child: 0.04%)
              Hdfs split stats (<volume id>:<# splits>/<split lengths>): 17:1/128.00 MB 20:1/128.00 MB 21:1/128.00 MB 14:2/256.00 MB 10:1/128.00 MB 7:3/384.00 MB 22:1/128.00 MB 6:1/81.40 MB 23:1/128.00 MB 11:2/218.92 MB 8:2/256.00 MB 12:1/80.91 MB 19:1/128.00 MB 2:2/256.00 MB 18:2/256.00 MB 9:2/256.00 MB 
              MemoryUsage(1s000ms): 40.30 KB, 112.32 MB, 90.32 MB, 79.82 MB, 108.32 MB, 63.35 MB, 84.50 MB, 88.45 MB, 105.82 MB, 108.32 MB, 130.57 MB, 113.95 MB, 86.32 MB, 126.32 MB, 55.56 MB, 108.32 MB, 92.06 MB, 61.55 MB, 112.32 MB, 90.32 MB, 69.55 MB, 108.32 MB, 63.51 MB, 75.82 MB, 130.32 MB, 97.82 MB, 94.32 MB, 130.32 MB, 90.45 MB, 76.07 MB, 123.07 MB, 90.45 MB, 86.32 MB, 94.31 MB, 75.82 MB, 126.57 MB
              ThreadUsage(1s000ms): 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1
               - AverageThreadTokens: 1.00 
               - BloomFilterBytes: 0
               - PeakMemoryUsage: 144.07 MB (151072208)
               - PerHostPeakMemUsage: 2.54 GB (2729446952)
               - RowsProduced: 1 (1)
               - TotalCpuTime: 32s934ms
               - TotalNetworkReceiveTime: 0.000ns
               - TotalNetworkSendTime: 250.604us
               - TotalStorageWaitTime: 3s600ms
              Fragment Instance Lifecycle Timings:
                 - ExecTime: 563.108us
                   - ExecTreeExecTime: 61.100us
                 - OpenTime: 36s464ms
                   - ExecTreeOpenTime: 35s741ms
                 - PrepareTime: 59.505ms
                   - ExecTreePrepareTime: 43.876ms
              CodeGen:(Total: 759.417ms, non-child: 759.417ms, % non-child: 100.00%)
                 - CodegenTime: 13.868ms
                 - CompileTime: 104.865ms
                 - LoadTime: 0.000ns
                 - ModuleBitcodeSize: 1.90 MB (1994596)
                 - NumFunctions: 166 (166)
                 - NumInstructions: 3.25K (3253)
                 - OptimizationTime: 614.018ms
                 - PrepareTime: 39.635ms
              DataStreamSender (dst_id=2):(Total: 135.680us, non-child: 135.680us, % non-child: 100.00%)
                 - BytesSent: 6.21 KB (6360)
                 - NetworkThroughput(*): 190.50 MB/sec
                 - OverallThroughput: 44.70 MB/sec
                 - RowsReturned: 1 (1)
                 - SerializeBatchTime: 85.840us
                 - TransmitDataRPCTime: 31.840us
                 - UncompressedRowBatchSize: 16.54 KB (16938)
              AGGREGATION_NODE (id=1):(Total: 35s749ms, non-child: 19s337ms, % non-child: 54.09%)
                ExecOption: Codegen Enabled
                 - BuildTime: 19s016ms
                 - GetResultsTime: 0.000ns
                 - HTResizeTime: 0.000ns
                 - HashBuckets: 0 (0)
                 - LargestPartitionPercent: 0 (0)
                 - MaxPartitionLevel: 0 (0)
                 - NumRepartitions: 0 (0)
                 - PartitionsCreated: 0 (0)
                 - PeakMemoryUsage: 13.79 MB (14464088)
                 - RowsRepartitioned: 0 (0)
                 - RowsReturned: 1 (1)
                 - RowsReturnedRate: 0
                 - SpilledPartitions: 0 (0)
              HDFS_SCAN_NODE (id=0):(Total: 16s411ms, non-child: 16s411ms, % non-child: 100.00%)
                Hdfs split stats (<volume id>:<# splits>/<split lengths>): 17:1/128.00 MB 20:1/128.00 MB 21:1/128.00 MB 14:2/256.00 MB 10:1/128.00 MB 7:3/384.00 MB 22:1/128.00 MB 6:1/81.40 MB 23:1/128.00 MB 11:2/218.92 MB 8:2/256.00 MB 12:1/80.91 MB 19:1/128.00 MB 2:2/256.00 MB 18:2/256.00 MB 9:2/256.00 MB 
                ExecOption: PARQUET Codegen Enabled, Codegen enabled: 24 out of 24
                Hdfs Read Thread Concurrency Bucket: 0:94.37% 1:5.634% 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% 15:0% 16:0% 17:0% 18:0% 19:0% 20:0% 21:0% 22:0% 23:0% 24:0% 25:0% 26:0% 27:0% 
                File Formats: PARQUET/NONE:360 
                BytesRead(1s000ms): 0, 121.18 MB, 183.47 MB, 283.25 MB, 373.75 MB, 429.74 MB, 500.75 MB, 586.76 MB, 686.16 MB, 751.84 MB, 873.22 MB, 935.50 MB, 1001.19 MB, 1.10 GB, 1.13 GB, 1.22 GB, 1.31 GB, 1.35 GB, 1.46 GB, 1.52 GB, 1.61 GB, 1.71 GB, 1.77 GB, 1.83 GB, 1.95 GB, 2.01 GB, 2.07 GB, 2.19 GB, 2.25 GB, 2.32 GB, 2.43 GB, 2.50 GB, 2.56 GB, 2.65 GB, 2.68 GB, 2.80 GB
                 - FooterProcessingTime: (Avg: 16.417ms ; Min: 1.397ms ; Max: 107.045ms ; Number of samples: 24)
                 - AverageHdfsReadThreadConcurrency: 0.06 
                 - AverageScannerThreadConcurrency: 0.00 
                 - BytesRead: 2.80 GB (3009913373)
                 - BytesReadDataNodeCache: 0
                 - BytesReadLocal: 2.80 GB (3008684573)
                 - BytesReadRemoteUnexpected: 0
                 - BytesReadShortCircuit: 2.80 GB (3008684573)
                 - DecompressionTime: 0.000ns
                 - MaxCompressedTextFileLength: 0
                 - NumColumns: 15 (15)
                 - NumDisksAccessed: 17 (17)
                 - NumRowGroups: 24 (24)
                 - NumScannerThreadsStarted: 0 (0)
                 - PeakMemoryUsage: 136.03 MB (142634136)
                 - PerReadThreadRawHdfsThroughput: 1.38 GB/sec
                 - RemoteScanRanges: 12 (12)
                 - RowsRead: 37.05M (37052184)
                 - RowsReturned: 37.05M (37052184)
                 - RowsReturnedRate: 2.26 M/sec
                 - ScanRangesComplete: 24 (24)
                 - ScannerThreadsInvoluntaryContextSwitches: 0 (0)
                 - ScannerThreadsTotalWallClockTime: 0.000ns
                   - MaterializeTupleTime(*): 12s392ms
                   - ScannerThreadsSysTime: 0.000ns
                   - ScannerThreadsUserTime: 0.000ns
                 - ScannerThreadsVoluntaryContextSwitches: 0 (0)
                 - TotalRawHdfsReadTime(*): 2s026ms
                 - TotalReadThroughput: 78.64 MB/sec
      

        Activity

        Hide
        sailesh Sailesh Mukil added a comment -
        Show
        sailesh Sailesh Mukil added a comment - Review in: https://gerrit.cloudera.org/#/c/4913/
        Hide
        mmokhtar Mostafa Mokhtar added a comment -

        [~ sailesh]

        The # Rows column is also incorrect.

        Show
        mmokhtar Mostafa Mokhtar added a comment - [~ sailesh] The # Rows column is also incorrect.
        Hide
        sailesh Sailesh Mukil added a comment -

        Mostafa Mokhtar Yes, that will be fixed too.

        Show
        sailesh Sailesh Mukil added a comment - Mostafa Mokhtar Yes, that will be fixed too.
        Show
        sailesh Sailesh Mukil added a comment - Commit in: https://github.com/apache/incubator-impala/commit/1af0aa4ad16b90bbec7c59fc75abe95d83b99c8d

          People

          • Assignee:
            sailesh Sailesh Mukil
            Reporter:
            mmokhtar Mostafa Mokhtar
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development