Details
-
Bug
-
Status: Resolved
-
Blocker
-
Resolution: Fixed
-
Impala 1.3
-
None
-
None
Description
The average times look messed up. They are way higher than the actual individual fragment times and
it looks we are just summing the values instead of averaging them.
From the 10 node cluster:
Averaged Fragment 2:(Active: 20m52s, % non-child: 0.00%)
split sizes: min: 7.24 GB, max: 7.44 GB, avg: 7.36 GB, stddev: 50.58 MB
completion times: min:6s010ms max:11m7s mean: 5m21s stddev:3m2s
execution rates: min:11.20 MB/sec max:1.24 GB/sec mean:58.45 MB/sec stddev:123.35 MB/sec
num instances: 10
- AverageThreadTokens: 226.98
- PeakMemoryUsage: 10.65 GB
- PrepareTime: 6s189ms
- RowsProduced: 8
- TotalCpuTime: 39m52s
- TotalNetworkWaitTime: 3.736ms
- TotalStorageWaitTime: 41m49s
CodeGen:(Active: 1m22s, % non-child: 0.00%)
- CodegenTime: 5s887ms
- CompileTime: 1m20s
- LoadTime: 1s859ms
- ModuleFileSize: 12.00 MB
DataStreamSender (dst_id=2):(Active: 92.836ms, % non-child: 0.00%)
- BytesSent: 724.00 B
- NetworkThroughput(*): 569.90 KB/sec
- OverallThroughput: 5.58 MB/sec
- PeakMemoryUsage: 1.30 MB
- SerializeBatchTime: 131.735us
- ThriftTransmitTime(*): 3.255ms
- UncompressedRowBatchSize: 976.00 B
AGGREGATION_NODE (id=1):(Active: 20m55s, % non-child: 0.00%)
- BuildBuckets: 116.53K (116531)
- BuildTime: 16m45s
- GetResultsTime: 49.275us
- LoadFactor: 0.44
- PeakMemoryUsage: 945.14 MB
- RowsReturned: 8
- RowsReturnedRate: 0
HDFS_SCAN_NODE (id=0):(Active: 9h51m, % non-child: 0.00%) <-- This is way too high. This has always been wallclock time.
- AverageHdfsReadThreadConcurrency: 3.78
- AverageScannerThreadConcurrency: 113.80
- BytesRead: 427.60 GB
- BytesReadLocal: 14.71 GB
- BytesReadShortCircuit: 14.71 GB
- NumDisksAccessed: 22
- NumScannerThreadsStarted: 113
- PeakMemoryUsage: 10.65 GB
- PerReadThreadRawHdfsThroughput: 43.58 GB/sec
- RowsRead: 3.46B (3455736751)
- RowsReturned: 3.41B (3407086725)
- RowsReturnedRate: 10.85 M/sec
- ScanRangesComplete: 3.34K (3340)
- ScannerThreadsInvoluntaryContextSwitches: 273.82K (273818)
- ScannerThreadsTotalWallClockTime: 20m52s
- DelimiterParseTime: 3h2m
- MaterializeTupleTime(*): 1h27m
- ScannerThreadsSysTime: 1s367ms
- ScannerThreadsUserTime: 5m43s
- ScannerThreadsVoluntaryContextSwitches: 632
- TotalRawHdfsReadTime(*): 19m8s
- TotalReadThroughput: 1.33 GB/sec
Fragment 2: <--- This is the slowest fragment 2 instance.
Instance a34348c0c6c35c5f:35890889650ed2a0 (host=c2308.halxg.cloudera.com:22000):(Active: 11m7s, % non-child: 0.00%)
Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:7/896.00 MB 1:3/384.00 MB 2:6/768.00 MB 3:4/512.00 MB 4:5/640.00 MB 5:10/1.25 GB 6:7/896.00 MB 7:7/896.00 MB 8:2/256.00 MB 9:3/304.72 MB 10:5/640.00 MB
MemoryUsage(16s000ms): 18.40 MB, 56.16 MB, 52.91 MB, 41.16 MB, 56.66 MB, 45.66 MB, 47.66 MB, 42.41 MB, 34.66 MB, 55.16 MB, 46.91 MB, 56.91 MB, 50.16 MB, 52.41 MB, 50.41 MB, 43.85 MB, 39.44 MB, 49.16 MB, 52.41 MB, 51.41 MB, 50.16 MB, 57.41 MB, 43.91 MB, 44.92 MB, 54.16 MB, 41.41 MB, 54.16 MB, 30.41 MB, 28.16 MB, 36.91 MB, 47.91 MB, 48.66 MB, 21.91 MB, 30.91 MB, 11.66 MB, 37.91 MB, 27.41 MB, 49.91 MB, 43.16 MB, 8.16 MB, 18.91 MB
ThreadUsage(16s000ms): 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: 2.00
- PeakMemoryUsage: 120.25 MB
- PrepareTime: 133.545ms
- RowsProduced: 4
- TotalCpuTime: 21m3s
- TotalNetworkWaitTime: 1.860ms
- TotalStorageWaitTime: 1m12s
CodeGen:(Active: 1s306ms, % non-child: 0.20%)
- CodegenTime: 113.344ms
- CompileTime: 1s275ms
- LoadTime: 27.468ms
- ModuleFileSize: 107.95 KB
DataStreamSender (dst_id=2):(Active: 6.278ms, % non-child: 0.00%)
- BytesSent: 359.00 B
- NetworkThroughput(*): 215.54 KB/sec
- OverallThroughput: 55.84 KB/sec
- PeakMemoryUsage: 27.41 KB
- SerializeBatchTime: 69.127us
- ThriftTransmitTime(*): 1.626ms
- UncompressedRowBatchSize: 488.00 B
AGGREGATION_NODE (id=1):(Active: 11m7s, % non-child: 2.61%)
ExecOption: Codegen Enabled
- BuildBuckets: 1.02K (1024)
- BuildTime: 17s213ms
- GetResultsTime: 25.631us
- LoadFactor: 0.00
- PeakMemoryUsage: 8.31 MB
- RowsReturned: 4
- RowsReturnedRate: 0
HDFS_SCAN_NODE (id=0):(Active: 10m49s, % non-child: 97.39%) <--- This number looks closer to reasonable.
File Formats: TEXT/NONE:59
ExecOption: Codegen enabled: 59 out of 59
- AverageHdfsReadThreadConcurrency: 0.03
- AverageScannerThreadConcurrency: 1.00
- BytesRead: 7.30 GB
- BytesReadLocal: 7.30 GB
- BytesReadShortCircuit: 7.30 GB
- NumDisksAccessed: 11
- NumScannerThreadsStarted: 1
- PeakMemoryUsage: 120.19 MB
- PerReadThreadRawHdfsThroughput: 350.58 MB/sec
- RowsRead: 59.52M (59522180)
- RowsReturned: 58.69M (58685909)
- RowsReturnedRate: 90.31 K/sec
- ScanRangesComplete: 59
- ScannerThreadsInvoluntaryContextSwitches: 159.04K (159044)
- ScannerThreadsTotalWallClockTime: 11m7s
- DelimiterParseTime: 3m39s
- MaterializeTupleTime(*): 1m47s
- ScannerThreadsSysTime: 883.865ms
- ScannerThreadsUserTime: 2m50s
- ScannerThreadsVoluntaryContextSwitches: 353
- TotalRawHdfsReadTime(*): 21s315ms
- TotalReadThroughput: 11.19 MB/sec