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

TotalStorageWaitTime counter not populated for fragments with Kudu scan node

    XMLWordPrintableJSON

Details

    Description

      Queries can easily become bottlenecked on Kudu scanners, TotalStorageWaitTime should be populated to indicate how much time was spent waiting on data from Kudu

          Instance d64eae570d8d0cc5:81a6c31b630ffdca (host=vd0234.halxg.cloudera.com:22000):(Total: 5m31s, non-child: 0.000ns, % non-child: 0.00%)
              Hdfs split stats (<volume id>:<# splits>/<split lengths>): 
              MemoryUsage(8s000ms): 13.01 MB, 17.04 MB, 16.48 MB, 17.87 MB, 17.59 MB, 17.87 MB, 17.65 MB, 15.97 MB, 18.25 MB, 18.13 MB, 15.71 MB, 16.25 MB, 16.61 MB, 16.10 MB, 16.55 MB, 16.83 MB, 17.89 MB, 17.49 MB, 16.04 MB, 17.30 MB, 16.73 MB, 17.08 MB, 16.74 MB, 16.70 MB, 16.51 MB, 16.37 MB, 17.36 MB, 17.39 MB, 16.85 MB, 16.93 MB, 17.50 MB, 15.98 MB, 16.97 MB, 16.40 MB, 16.84 MB, 17.28 MB, 17.35 MB, 17.75 MB, 17.50 MB, 17.16 MB, 17.15 MB
              ThreadUsage(8s000ms): 1, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2
               - AverageThreadTokens: 1.99 
               - BloomFilterBytes: 0
               - PeakMemoryUsage: 29.83 MB (31282640)
               - PerHostPeakMemUsage: 40.12 MB (42066848)
               - PrepareTime: 385.061ms
               - RowsProduced: 3.95K (3952)
               - TotalCpuTime: 11m2s
               - TotalNetworkReceiveTime: 538.425ms
               - TotalNetworkSendTime: 2.488ms
               - TotalStorageWaitTime: 0.000ns
              CodeGen:(Total: 1s313ms, non-child: 1s313ms, % non-child: 100.00%)
                 - CodegenTime: 1.875ms
                 - CompileTime: 296.852ms
                 - LoadTime: 0.000ns
                 - ModuleBitcodeSize: 2.11 MB (2217152)
                 - NumFunctions: 132 (132)
                 - NumInstructions: 7.82K (7824)
                 - OptimizationTime: 654.980ms
                 - PrepareTime: 361.100ms
              DataStreamSender (dst_id=15):(Total: 3.024ms, non-child: 3.024ms, % non-child: 100.00%)
                 - BytesSent: 70.71 KB (72411)
                 - NetworkThroughput(*): 229.80 MB/sec
                 - OverallThroughput: 22.83 MB/sec
                 - PeakMemoryUsage: 171.95 KB (176080)
                 - RowsReturned: 3.95K (3952)
                 - SerializeBatchTime: 2.666ms
                 - TransmitDataRPCTime: 300.512us
                 - UncompressedRowBatchSize: 108.10 KB (110692)
              AGGREGATION_NODE (id=7):(Total: 5m31s, non-child: 8s783ms, % non-child: 2.65%)
                ExecOption: Streaming Preaggregation, Codegen Enabled
                 - GetNewBlockTime: 142.544us
                 - GetResultsTime: 328.444us
                 - HTResizeTime: 179.596us
                 - HashBuckets: 32.77K (32768)
                 - LargestPartitionPercent: 0 (0)
                 - PartitionsCreated: 16 (16)
                 - PeakMemoryUsage: 17.45 MB (18299008)
                 - PinTime: 0.000ns
                 - ReductionFactorEstimate: 0.00 
                 - ReductionFactorThresholdToExpand: 0.00 
                 - RowsPassedThrough: 0 (0)
                 - RowsReturned: 3.95K (3952)
                 - RowsReturnedRate: 11.00 /sec
                 - StreamingTime: 8s332ms
                 - UnpinTime: 0.000ns
              HASH_JOIN_NODE (id=6):(Total: 5m22s, non-child: 555.712ms, % non-child: 0.17%)
                ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Hash Table Construction Codegen Enabled, Join Build-Side Prepared Asynchronously
                 - BuildPartitionTime: 54.692us
                 - BuildRows: 1.00K (1002)
                 - BuildRowsPartitioned: 1.00K (1002)
                 - BuildTime: 254.528us
                 - GetNewBlockTime: 2.454ms
                 - HashBuckets: 2.05K (2048)
                 - HashCollisions: 0 (0)
                 - LargestPartitionPercent: 6 (6)
                 - MaxPartitionLevel: 0 (0)
                 - NumRepartitions: 0 (0)
                 - PartitionsCreated: 16 (16)
                 - PeakMemoryUsage: 16.97 MB (17794176)
                 - PinTime: 0.000ns
                 - ProbeRows: 4.17M (4165447)
                 - ProbeRowsPartitioned: 0 (0)
                 - ProbeTime: 494.924ms
                 - RowsReturned: 4.07M (4067185)
                 - RowsReturnedRate: 12.60 K/sec
                 - SpilledPartitions: 0 (0)
                 - UnpinTime: 988.000ns
                EXCHANGE_NODE (id=14):(Total: 80.300us, non-child: 80.300us, % non-child: 100.00%)
                  BytesReceived(8s000ms): 7.42 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB, 7.86 KB
                   - BytesReceived: 7.86 KB (8052)
                   - ConvertRowBatchTime: 38.048us
                   - DeserializeRowBatchTimer: 49.260us
                   - FirstBatchArrivalWaitTime: 0.000ns
                   - PeakMemoryUsage: 0
                   - RowsReturned: 1.00K (1002)
                   - RowsReturnedRate: 12.48 M/sec
                   - SendersBlockedTimer: 0.000ns
                   - SendersBlockedTotalTimer(*): 0.000ns
              HASH_JOIN_NODE (id=5):(Total: 5m22s, non-child: 1s345ms, % non-child: 0.42%)
                ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Hash Table Construction Codegen Enabled
                 - BuildPartitionTime: 89.200us
                 - BuildRows: 365 (365)
                 - BuildRowsPartitioned: 365 (365)
                 - BuildTime: 15.500us
                 - GetNewBlockTime: 2.538ms
                 - HashBuckets: 1.02K (1024)
                 - HashCollisions: 0 (0)
                 - LargestPartitionPercent: 6 (6)
                 - MaxPartitionLevel: 0 (0)
                 - NumRepartitions: 0 (0)
                 - PartitionsCreated: 16 (16)
                 - PeakMemoryUsage: 9.04 MB (9479296)
                 - PinTime: 0.000ns
                 - ProbeRows: 12.72M (12724239)
                 - ProbeRowsPartitioned: 0 (0)
                 - ProbeTime: 1s226ms
                 - RowsReturned: 4.17M (4165447)
                 - RowsReturnedRate: 12.93 K/sec
                 - SpilledPartitions: 0 (0)
                 - UnpinTime: 852.000ns
                EXCHANGE_NODE (id=13):(Total: 448.481ms, non-child: 721.600us, % non-child: 0.16%)
                  BytesReceived(8s000ms): 5.71 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB, 6.38 KB
                   - BytesReceived: 6.38 KB (6533)
                   - ConvertRowBatchTime: 67.892us
                   - DeserializeRowBatchTimer: 770.700us
                   - FirstBatchArrivalWaitTime: 0.000ns
                   - PeakMemoryUsage: 0
                   - RowsReturned: 365 (365)
                   - RowsReturnedRate: 813.00 /sec
                   - SendersBlockedTimer: 0.000ns
                   - SendersBlockedTotalTimer(*): 0.000ns
              HASH_JOIN_NODE (id=4):(Total: 5m20s, non-child: 31s954ms, % non-child: 9.97%)
                ExecOption: Build Side Codegen Enabled, Probe Side Codegen Enabled, Hash Table Construction Codegen Enabled, Join Build-Side Prepared Asynchronously
                 - BuildPartitionTime: 8.349ms
                 - BuildRows: 15.41K (15406)
                 - BuildRowsPartitioned: 15.41K (15406)
                 - BuildTime: 419.980us
                 - GetNewBlockTime: 1.371ms
                 - HashBuckets: 32.77K (32768)
                 - HashCollisions: 0 (0)
                 - LargestPartitionPercent: 6 (6)
                 - MaxPartitionLevel: 0 (0)
                 - NumRepartitions: 0 (0)
                 - PartitionsCreated: 16 (16)
                 - PeakMemoryUsage: 10.54 MB (11048064)
                 - PinTime: 0.000ns
                 - ProbeRows: 305.61M (305609429)
                 - ProbeRowsPartitioned: 0 (0)
                 - ProbeTime: 30s767ms
                 - RowsReturned: 12.72M (12724239)
                 - RowsReturnedRate: 39.72 K/sec
                 - SpilledPartitions: 0 (0)
                 - UnpinTime: 1.652us
                EXCHANGE_NODE (id=12):(Total: 90.682ms, non-child: 980.172us, % non-child: 1.08%)
                  BytesReceived(8s000ms): 538.58 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB, 602.45 KB
                   - BytesReceived: 602.45 KB (616913)
                   - ConvertRowBatchTime: 493.532us
                   - DeserializeRowBatchTimer: 4.569ms
                   - FirstBatchArrivalWaitTime: 0.000ns
                   - PeakMemoryUsage: 0
                   - RowsReturned: 15.41K (15406)
                   - RowsReturnedRate: 169.89 K/sec
                   - SendersBlockedTimer: 0.000ns
                   - SendersBlockedTotalTimer(*): 0.000ns
              KUDU_SCAN_NODE (id=1):(Total: 4m48s, non-child: 4m48s, % non-child: 100.00%)
                BytesRead(8s000ms): 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0
                 - BytesRead: 0
                 - NumScannerThreadsStarted: 1 (1)
                 - PeakMemoryUsage: 2.62 MB (2744320)
                 - RowsRead: 305.61M (305609429)
                 - RowsReturned: 305.61M (305609429)
                 - RowsReturnedRate: 1.06 M/sec
                 - ScanRangesComplete: 10 (10)
                 - ScannerThreadsInvoluntaryContextSwitches: 101.31K (101311)
                 - ScannerThreadsTotalWallClockTime: 5m30s
                   - MaterializeTupleTime(*): 4m48s
                   - ScannerThreadsSysTime: 9s790ms
                   - ScannerThreadsUserTime: 1m6s
                   - TotalKuduReadTime: 4m
                 - ScannerThreadsVoluntaryContextSwitches: 75.47K (75465)
                 - TotalKuduScanRoundTrips: 7.28K (7280)
                 - TotalReadThroughput: 0.00 /sec
      

      Attachments

        Activity

          People

            anujphadke Anuj Phadke
            mmokhtar Mostafa Mokhtar
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: