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

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

              Dates

              • Created:
                Updated:
                Resolved: