Details
-
Bug
-
Status: Resolved
-
Major
-
Resolution: Cannot Reproduce
-
Impala 2.10.0
-
ghx-label-9
Description
TestRuntimeRowFilters::test_row_filters failed on an exhaustive integration jenkins run.
I'm not sure if the test is flaky (is it safe to check row_regex: .Rows rejected: 2.43K . - will that be deterministic?) or if there was some other problem, e.g. missing stats and the plan had the wrong join order.
15:56:01 FAIL query_test/test_runtime_filters.py::TestRuntimeRowFilters::()::test_row_filters[exec_option: {'batch_size': 0, 'num_nodes': 0, 'disable_codegen_rows_threshold': 0, 'disable_codegen': False, 'abort_on_error': 1, 'exec_single_node_rows_threshold': 0} | table_format: parquet/none]
15:56:01 =================================== FAILURES ===================================
15:56:01 TestRuntimeRowFilters.test_row_filters[exec_option: {'batch_size': 0, 'num_nodes': 0, 'disable_codegen_rows_threshold': 0, 'disable_codegen': False, 'abort_on_error': 1, 'exec_single_node_rows_threshold': 0} | table_format: parquet/none]
15:56:01 [gw1] linux2 -- Python 2.6.6 /data/jenkins/workspace/impala-asf-master-exhaustive-integration/repos/Impala/bin/../infra/python/env/bin/python
15:56:01 query_test/test_runtime_filters.py:64: in test_row_filters
15:56:01 self.run_test_case('QueryTest/runtime_row_filters', vector)
15:56:01 common/impala_test_suite.py:430: in run_test_case
15:56:01 verify_runtime_profile(test_section['RUNTIME_PROFILE'], result.runtime_profile)
15:56:01 common/test_result_verifier.py:560: in verify_runtime_profile
15:56:01 actual))
15:56:01 E AssertionError: Did not find matches for lines in runtime profile:
15:56:01 E EXPECTED LINES:
15:56:01 E row_regex: .*Rows rejected: 2.43K .*
15:56:01 E
15:56:01 E ACTUAL PROFILE:
15:56:01 E Query (id=364e2b65ff166530:f9d9801200000000):
15:56:01 E DEBUG MODE WARNING: Query profile created while running a DEBUG build of Impala. Use RELEASE builds to measure query performance.
15:56:01 E Summary:
15:56:01 E Session ID: 9647fdab4ef2c145:5dcf33aad4d16d9a
15:56:01 E Session Type: BEESWAX
15:56:01 E Start Time: 2017-07-26 13:17:25.663511000
15:56:01 E End Time:
15:56:01 E Query Type: QUERY
15:56:01 E Query State: FINISHED
15:56:01 E Query Status: OK
15:56:01 E Impala Version: impalad version 2.10.0-SNAPSHOT DEBUG (build 7ccbfe47fe1a0b693f6d94ae4b1062a0e3b66e88)
15:56:01 E User: jenkins
15:56:01 E Connected User: jenkins
15:56:01 E Delegated User:
15:56:01 E Network Address: 127.0.0.1:36306
15:56:01 E Default Db: functional_parquet
15:56:01 E Sql Statement: select STRAIGHT_JOIN count(*) from alltypes p join [SHUFFLE] alltypestiny b
15:56:01 E on p.id = b.int_col and b.month = 1 and b.string_col = "1"
15:56:01 E Coordinator: impala-boost-static-burst-slave-0e4c.vpc.cloudera.com:22000
15:56:01 E Query Options (non default): ABORT_ON_ERROR=1,EXEC_SINGLE_NODE_ROWS_THRESHOLD=0,RUNTIME_FILTER_WAIT_TIME_MS=30000,MT_DOP=0,DISABLE_CODEGEN_ROWS_THRESHOLD=0
15:56:01 E Plan:
15:56:01 E ----------------
15:56:01 E Per-Host Resource Reservation: Memory=136.00MB
15:56:01 E Per-Host Resource Estimates: Memory=2.07GB
15:56:01 E WARNING: The following tables are missing relevant table and/or column statistics.
15:56:01 E functional_parquet.alltypes, functional_parquet.alltypestiny
15:56:01 E
15:56:01 E F03:PLAN FRAGMENT [UNPARTITIONED] hosts=1 instances=1
15:56:01 E | Per-Host Resources: mem-estimate=10.00MB mem-reservation=0B
15:56:01 E PLAN-ROOT SINK
15:56:01 E | mem-estimate=0B mem-reservation=0B
15:56:01 E |
15:56:01 E 07:AGGREGATE [FINALIZE]
15:56:01 E | output: count:merge(*)
15:56:01 E | mem-estimate=10.00MB mem-reservation=0B
15:56:01 E | tuple-ids=2 row-size=8B cardinality=1
15:56:01 E |
15:56:01 E 06:EXCHANGE [UNPARTITIONED]
15:56:01 E | mem-estimate=0B mem-reservation=0B
15:56:01 E | tuple-ids=2 row-size=8B cardinality=1
15:56:01 E |
15:56:01 E F02:PLAN FRAGMENT [HASH(p.id)] hosts=3 instances=3
15:56:01 E Per-Host Resources: mem-estimate=2.01GB mem-reservation=136.00MB
15:56:01 E 03:AGGREGATE
15:56:01 E | output: count(*)
15:56:01 E | mem-estimate=10.00MB mem-reservation=0B
15:56:01 E | tuple-ids=2 row-size=8B cardinality=1
15:56:01 E |
15:56:01 E 02:HASH JOIN [INNER JOIN, PARTITIONED]
15:56:01 E | hash predicates: p.id = b.int_col
15:56:01 E | fk/pk conjuncts: assumed fk/pk
15:56:01 E | runtime filters: RF000 <- b.int_col
15:56:01 E | mem-estimate=2.00GB mem-reservation=136.00MB
15:56:01 E | tuple-ids=0,1 row-size=23B cardinality=unavailable
15:56:01 E |
15:56:01 E |--05:EXCHANGE [HASH(b.int_col)]
15:56:01 E | | mem-estimate=0B mem-reservation=0B
15:56:01 E | | tuple-ids=1 row-size=19B cardinality=unavailable
15:56:01 E | |
15:56:01 E | F01:PLAN FRAGMENT [RANDOM] hosts=1 instances=1
15:56:01 E | Per-Host Resources: mem-estimate=32.00MB mem-reservation=0B
15:56:01 E | 01:SCAN HDFS [functional_parquet.alltypestiny b, RANDOM]
15:56:01 E | partitions=1/4 files=1 size=2.69KB
15:56:01 E | predicates: b.string_col = '1'
15:56:01 E | stats-rows=unavailable extrapolated-rows=disabled
15:56:01 E | table stats: rows=unavailable size=unavailable
15:56:01 E | columns missing stats: int_col, string_col
15:56:01 E | parquet statistics predicates: b.string_col = '1'
15:56:01 E | parquet dictionary predicates: b.string_col = '1'
15:56:01 E | mem-estimate=32.00MB mem-reservation=0B
15:56:01 E | tuple-ids=1 row-size=19B cardinality=unavailable
15:56:01 E |
15:56:01 E 04:EXCHANGE [HASH(p.id)]
15:56:01 E | mem-estimate=0B mem-reservation=0B
15:56:01 E | tuple-ids=0 row-size=4B cardinality=unavailable
15:56:01 E |
15:56:01 E F00:PLAN FRAGMENT [RANDOM] hosts=3 instances=3
15:56:01 E Per-Host Resources: mem-estimate=16.00MB mem-reservation=0B
15:56:01 E 00:SCAN HDFS [functional_parquet.alltypes p, RANDOM]
15:56:01 E partitions=24/24 files=24 size=179.70KB
15:56:01 E runtime filters: RF000 -> p.id
15:56:01 E stats-rows=unavailable extrapolated-rows=disabled
15:56:01 E table stats: rows=unavailable size=unavailable
15:56:01 E column stats: unavailable
15:56:01 E mem-estimate=16.00MB mem-reservation=0B
15:56:01 E tuple-ids=0 row-size=4B cardinality=unavailable
15:56:01 E ----------------
15:56:01 E Estimated Per-Host Mem: 2218786816
15:56:01 E Per-Host Memory Reservation: 142606336
15:56:01 E Tables Missing Stats: functional_parquet.alltypes,functional_parquet.alltypestiny
15:56:01 E Request Pool: default-pool
15:56:01 E Admission result: Admitted immediately
15:56:01 E Planner Timeline: 4.309ms
15:56:01 E - Analysis finished: 967.002us (967.002us)
15:56:01 E - Equivalence classes computed: 1.041ms (74.288us)
15:56:01 E - Single node plan created: 3.279ms (2.238ms)
15:56:01 E - Runtime filters computed: 3.358ms (78.210us)
15:56:01 E - Distributed plan created: 3.455ms (96.947us)
15:56:01 E - Planning finished: 4.309ms (854.818us)
15:56:01 E Query Timeline: 632.010ms
15:56:01 E - Query submitted: 0.000ns (0.000ns)
15:56:01 E - Planning finished: 6.000ms (6.000ms)
15:56:01 E - Submit for admission: 11.000ms (5.000ms)
15:56:01 E - Completed admission: 11.000ms (0.000ns)
15:56:01 E - Ready to start on 3 backends: 14.000ms (3.000ms)
15:56:01 E - All 3 execution backends (8 fragment instances) started: 19.000ms (5.000ms)
15:56:01 E - First dynamic filter received: 508.008ms (489.008ms)
15:56:01 E - Rows available: 614.010ms (106.001ms)
15:56:01 E - First row fetched: 624.010ms (10.000ms)
15:56:01 E - ComputeScanRangeAssignmentTimer: 3.000ms
15:56:01 E ImpalaServer:
15:56:01 E - ClientFetchWaitTimer: 11.000ms
15:56:01 E - RowMaterializationTimer: 5.000ms
15:56:01 E Execution Profile 364e2b65ff166530:f9d9801200000000:(Total: 600.010ms, non-child: 0.000ns, % non-child: 0.00%)
15:56:01 E Number of filters: 1
15:56:01 E Filter routing table:
15:56:01 E ID Src. Node Tgt. Node(s) Target type Partition filter Pending (Expected) First arrived Completed Enabled
15:56:01 E -------------------------------------------------------------------------------------------------------------------
15:56:01 E 0 2 0 REMOTE false 3 (3) N/A N/A true
15:56:01 E Backend startup latencies: Count: 3, min / max: 2ms / 4ms, 25th %-ile: 2ms, 50th %-ile: 3ms, 75th %-ile: 3ms, 90th %-ile: 4ms, 95th %-ile: 4ms, 99.9th %-ile: 4ms
15:56:01 E Final filter table:
15:56:01 E ID Src. Node Tgt. Node(s) Target type Partition filter Pending (Expected) First arrived Completed Enabled
15:56:01 E -------------------------------------------------------------------------------------------------------------------
15:56:01 E 0 2 0 REMOTE false 0 (3) 508.008ms 578.009ms false
15:56:01 E Per Node Peak Memory Usage: impala-boost-static-burst-slave-0e4c.vpc.cloudera.com:22000(3.18 MB) impala-boost-static-burst-slave-0e4c.vpc.cloudera.com:22001(2.36 MB) impala-boost-static-burst-slave-0e4c.vpc.cloudera.com:22002(2.40 MB)
15:56:01 E - FiltersReceived: 3 (3)
15:56:01 E - FinalizationTimer: 0.000ns
15:56:01 E Averaged Fragment F03:(Total: 605.010ms, non-child: 23.000ms, % non-child: 3.80%)
15:56:01 E split sizes: min: 0, max: 0, avg: 0, stddev: 0
15:56:01 E completion times: min:606.010ms max:606.010ms mean: 606.010ms stddev:0.000ns
15:56:01 E execution rates: min:0.00 /sec max:0.00 /sec mean:0.00 /sec stddev:0.00 /sec
15:56:01 E num instances: 1
15:56:01 E - AverageThreadTokens: 0.00
15:56:01 E - BloomFilterBytes: 0
15:56:01 E - PeakMemoryUsage: 36.02 KB (36880)
15:56:01 E - PerHostPeakMemUsage: 3.18 MB (3330710)
15:56:01 E - RowsProduced: 1 (1)
15:56:01 E - TotalNetworkReceiveTime: 530.009ms
15:56:01 E - TotalNetworkSendTime: 0.000ns
15:56:01 E - TotalStorageWaitTime: 0.000ns
15:56:01 E - TotalThreadsInvoluntaryContextSwitches: 0 (0)
15:56:01 E - TotalThreadsTotalWallClockTime: 541.009ms
15:56:01 E - TotalThreadsSysTime: 0.000ns
15:56:01 E - TotalThreadsUserTime: 0.000ns
15:56:01 E - TotalThreadsVoluntaryContextSwitches: 5 (5)
15:56:01 E Fragment Instance Lifecycle Timings:
15:56:01 E - ExecTime: 11.000ms
15:56:01 E - ExecTreeExecTime: 0.000ns
15:56:01 E - OpenTime: 530.009ms
15:56:01 E - ExecTreeOpenTime: 530.009ms
15:56:01 E - PrepareTime: 64.001ms
15:56:01 E - ExecTreePrepareTime: 0.000ns
15:56:01 E BlockMgr:
15:56:01 E - BlockWritesOutstanding: 0 (0)
15:56:01 E - BlocksCreated: 16 (16)
15:56:01 E - BlocksRecycled: 0 (0)
15:56:01 E - BufferedPins: 0 (0)
15:56:01 E - MaxBlockSize: 8.00 MB (8388608)
15:56:01 E - MemoryLimit: 14.31 GB (15365329920)
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - ScratchBytesRead: 0
15:56:01 E - ScratchBytesWritten: 0
15:56:01 E - ScratchFileUsedBytes: 0
15:56:01 E - ScratchReads: 0 (0)
15:56:01 E - ScratchWrites: 0 (0)
15:56:01 E - TotalBufferWaitTime: 0.000ns
15:56:01 E - TotalEncryptionTime: 0.000ns
15:56:01 E - TotalReadBlockTime: 0.000ns
15:56:01 E PLAN_ROOT_SINK:
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E CodeGen:(Total: 52.000ms, non-child: 52.000ms, % non-child: 100.00%)
15:56:01 E - CodegenTime: 0.000ns
15:56:01 E - CompileTime: 0.000ns
15:56:01 E - LoadTime: 0.000ns
15:56:01 E - ModuleBitcodeSize: 1.97 MB (2062036)
15:56:01 E - NumFunctions: 0 (0)
15:56:01 E - NumInstructions: 0 (0)
15:56:01 E - OptimizationTime: 0.000ns
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - PrepareTime: 51.000ms
15:56:01 E AGGREGATION_NODE (id=7):(Total: 530.009ms, non-child: 0.000ns, % non-child: 0.00%)
15:56:01 E - BuildTime: 0.000ns
15:56:01 E - GetResultsTime: 0.000ns
15:56:01 E - HTResizeTime: 0.000ns
15:56:01 E - HashBuckets: 0 (0)
15:56:01 E - LargestPartitionPercent: 0 (0)
15:56:01 E - MaxPartitionLevel: 0 (0)
15:56:01 E - NumRepartitions: 0 (0)
15:56:01 E - PartitionsCreated: 0 (0)
15:56:01 E - PeakMemoryUsage: 28.00 KB (28672)
15:56:01 E - RowsRepartitioned: 0 (0)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - RowsReturnedRate: 1.00 /sec
15:56:01 E - SpilledPartitions: 0 (0)
15:56:01 E EXCHANGE_NODE (id=6):(Total: 530.009ms, non-child: 530.009ms, % non-child: 100.00%)
15:56:01 E - BytesReceived: 48.00 B (48)
15:56:01 E - ConvertRowBatchTime: 0.000ns
15:56:01 E - DeserializeRowBatchTimer: 1.000ms
15:56:01 E - FirstBatchArrivalWaitTime: 528.009ms
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - RowsReturned: 3 (3)
15:56:01 E - RowsReturnedRate: 5.00 /sec
15:56:01 E - SendersBlockedTimer: 0.000ns
15:56:01 E - SendersBlockedTotalTimer(*): 0.000ns
15:56:01 E Coordinator Fragment F03:
15:56:01 E Instance 364e2b65ff166530:f9d9801200000000 (host=impala-boost-static-burst-slave-0e4c.vpc.cloudera.com:22000):(Total: 605.010ms, non-child: 23.000ms, % non-child: 3.80%)
15:56:01 E MemoryUsage(500.000ms): 12.00 KB
15:56:01 E - AverageThreadTokens: 0.00
15:56:01 E - BloomFilterBytes: 0
15:56:01 E - PeakMemoryUsage: 36.02 KB (36880)
15:56:01 E - PerHostPeakMemUsage: 3.18 MB (3330710)
15:56:01 E - RowsProduced: 1 (1)
15:56:01 E - TotalNetworkReceiveTime: 530.009ms
15:56:01 E - TotalNetworkSendTime: 0.000ns
15:56:01 E - TotalStorageWaitTime: 0.000ns
15:56:01 E - TotalThreadsInvoluntaryContextSwitches: 0 (0)
15:56:01 E - TotalThreadsTotalWallClockTime: 541.009ms
15:56:01 E - TotalThreadsSysTime: 0.000ns
15:56:01 E - TotalThreadsUserTime: 0.000ns
15:56:01 E - TotalThreadsVoluntaryContextSwitches: 5 (5)
15:56:01 E Fragment Instance Lifecycle Timings:
15:56:01 E - ExecTime: 11.000ms
15:56:01 E - ExecTreeExecTime: 0.000ns
15:56:01 E - OpenTime: 530.009ms
15:56:01 E - ExecTreeOpenTime: 530.009ms
15:56:01 E - PrepareTime: 64.001ms
15:56:01 E - ExecTreePrepareTime: 0.000ns
15:56:01 E BlockMgr:
15:56:01 E - BlockWritesOutstanding: 0 (0)
15:56:01 E - BlocksCreated: 16 (16)
15:56:01 E - BlocksRecycled: 0 (0)
15:56:01 E - BufferedPins: 0 (0)
15:56:01 E - MaxBlockSize: 8.00 MB (8388608)
15:56:01 E - MemoryLimit: 14.31 GB (15365329920)
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - ScratchBytesRead: 0
15:56:01 E - ScratchBytesWritten: 0
15:56:01 E - ScratchFileUsedBytes: 0
15:56:01 E - ScratchReads: 0 (0)
15:56:01 E - ScratchWrites: 0 (0)
15:56:01 E - TotalBufferWaitTime: 0.000ns
15:56:01 E - TotalEncryptionTime: 0.000ns
15:56:01 E - TotalReadBlockTime: 0.000ns
15:56:01 E PLAN_ROOT_SINK:
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E CodeGen:(Total: 52.000ms, non-child: 52.000ms, % non-child: 100.00%)
15:56:01 E - CodegenTime: 0.000ns
15:56:01 E - CompileTime: 0.000ns
15:56:01 E - LoadTime: 0.000ns
15:56:01 E - ModuleBitcodeSize: 1.97 MB (2062036)
15:56:01 E - NumFunctions: 0 (0)
15:56:01 E - NumInstructions: 0 (0)
15:56:01 E - OptimizationTime: 0.000ns
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - PrepareTime: 51.000ms
15:56:01 E AGGREGATION_NODE (id=7):(Total: 530.009ms, non-child: 0.000ns, % non-child: 0.00%)
15:56:01 E - BuildTime: 0.000ns
15:56:01 E - GetResultsTime: 0.000ns
15:56:01 E - HTResizeTime: 0.000ns
15:56:01 E - HashBuckets: 0 (0)
15:56:01 E - LargestPartitionPercent: 0 (0)
15:56:01 E - MaxPartitionLevel: 0 (0)
15:56:01 E - NumRepartitions: 0 (0)
15:56:01 E - PartitionsCreated: 0 (0)
15:56:01 E - PeakMemoryUsage: 28.00 KB (28672)
15:56:01 E - RowsRepartitioned: 0 (0)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - RowsReturnedRate: 1.00 /sec
15:56:01 E - SpilledPartitions: 0 (0)
15:56:01 E EXCHANGE_NODE (id=6):(Total: 530.009ms, non-child: 0.000ns, % non-child: 0.00%)
15:56:01 E BytesReceived(500.000ms): 0
15:56:01 E - BytesReceived: 48.00 B (48)
15:56:01 E - ConvertRowBatchTime: 0.000ns
15:56:01 E - DeserializeRowBatchTimer: 1.000ms
15:56:01 E - FirstBatchArrivalWaitTime: 528.009ms
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - RowsReturned: 3 (3)
15:56:01 E - RowsReturnedRate: 5.00 /sec
15:56:01 E - SendersBlockedTimer: 0.000ns
15:56:01 E - SendersBlockedTotalTimer(*): 0.000ns
15:56:01 E Averaged Fragment F02:(Total: 594.010ms, non-child: 36.000ms, % non-child: 6.06%)
15:56:01 E split sizes: min: 0, max: 0, avg: 0, stddev: 0
15:56:01 E completion times: min:595.010ms max:598.010ms mean: 596.010ms stddev:1.414ms
15:56:01 E execution rates: min:0.00 /sec max:0.00 /sec mean:0.00 /sec stddev:0.00 /sec
15:56:01 E num instances: 3
15:56:01 E - AverageThreadTokens: 1.00
15:56:01 E - BloomFilterBytes: 1.00 MB (1048576)
15:56:01 E - PeakMemoryUsage: 2.08 MB (2183144)
15:56:01 E - PerHostPeakMemUsage: 2.65 MB (2775372)
15:56:01 E - RowsProduced: 1 (1)
15:56:01 E - TotalNetworkReceiveTime: 66.667ms
15:56:01 E - TotalNetworkSendTime: 1.333ms
15:56:01 E - TotalStorageWaitTime: 0.000ns
15:56:01 E - TotalThreadsInvoluntaryContextSwitches: 212 (212)
15:56:01 E - TotalThreadsTotalWallClockTime: 496.008ms
15:56:01 E - TotalThreadsSysTime: 4.999ms
15:56:01 E - TotalThreadsUserTime: 314.951ms
15:56:01 E - TotalThreadsVoluntaryContextSwitches: 9 (9)
15:56:01 E Fragment Instance Lifecycle Timings:
15:56:01 E - ExecTime: 2.000ms
15:56:01 E - ExecTreeExecTime: 0.000ns
15:56:01 E - OpenTime: 487.675ms
15:56:01 E - ExecTreeOpenTime: 67.667ms
15:56:01 E - PrepareTime: 103.668ms
15:56:01 E - ExecTreePrepareTime: 333.339us
15:56:01 E DataStreamSender (dst_id=6):
15:56:01 E - BytesSent: 16.00 B (16)
15:56:01 E - NetworkThroughput(*): 0.00 /sec
15:56:01 E - OverallThroughput: 0.00 /sec
15:56:01 E - PeakMemoryUsage: 16.00 KB (16384)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - SerializeBatchTime: 0.000ns
15:56:01 E - TransmitDataRPCTime: 0.000ns
15:56:01 E - UncompressedRowBatchSize: 16.00 B (16)
15:56:01 E CodeGen:(Total: 490.008ms, non-child: 490.008ms, % non-child: 100.00%)
15:56:01 E - CodegenTime: 1.000ms
15:56:01 E - CompileTime: 31.333ms
15:56:01 E - LoadTime: 0.000ns
15:56:01 E - ModuleBitcodeSize: 1.97 MB (2062036)
15:56:01 E - NumFunctions: 56 (56)
15:56:01 E - NumInstructions: 2.44K (2443)
15:56:01 E - OptimizationTime: 386.673ms
15:56:01 E - PeakMemoryUsage: 1.19 MB (1250816)
15:56:01 E - PrepareTime: 67.334ms
15:56:01 E AGGREGATION_NODE (id=3):(Total: 68.001ms, non-child: 666.678us, % non-child: 0.98%)
15:56:01 E - BuildTime: 0.000ns
15:56:01 E - GetResultsTime: 0.000ns
15:56:01 E - HTResizeTime: 0.000ns
15:56:01 E - HashBuckets: 0 (0)
15:56:01 E - LargestPartitionPercent: 0 (0)
15:56:01 E - MaxPartitionLevel: 0 (0)
15:56:01 E - NumRepartitions: 0 (0)
15:56:01 E - PartitionsCreated: 0 (0)
15:56:01 E - PeakMemoryUsage: 25.33 KB (25941)
15:56:01 E - RowsRepartitioned: 0 (0)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - RowsReturnedRate: 16.00 /sec
15:56:01 E - SpilledPartitions: 0 (0)
15:56:01 E HASH_JOIN_NODE (id=2):(Total: 67.334ms, non-child: 666.678us, % non-child: 0.99%)
15:56:01 E - BuildRows: 0 (0)
15:56:01 E - BuildTime: 6.000ms
15:56:01 E - NumHashTableBuildsSkipped: 0 (0)
15:56:01 E - PeakMemoryUsage: 1.03 MB (1085013)
15:56:01 E - ProbeRows: 0 (0)
15:56:01 E - ProbeRowsPartitioned: 0 (0)
15:56:01 E - ProbeTime: 0.000ns
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - RowsReturnedRate: 3.00 /sec
15:56:01 E Hash Join Builder (join_node_id=2):
15:56:01 E - BuildRowsPartitionTime: 0.000ns
15:56:01 E - BuildRowsPartitioned: 0 (0)
15:56:01 E - GetNewBlockTime: 666.678us
15:56:01 E - HashBuckets: 0 (0)
15:56:01 E - HashCollisions: 0 (0)
15:56:01 E - HashTablesBuildTime: 0.000ns
15:56:01 E - LargestPartitionPercent: 33 (33)
15:56:01 E - MaxPartitionLevel: 0 (0)
15:56:01 E - NumRepartitions: 0 (0)
15:56:01 E - PartitionsCreated: 16 (16)
15:56:01 E - PeakMemoryUsage: 1.01 MB (1057920)
15:56:01 E - PinTime: 0.000ns
15:56:01 E - RepartitionTime: 0.000ns
15:56:01 E - SpilledPartitions: 0 (0)
15:56:01 E - UnpinTime: 0.000ns
15:56:01 E EXCHANGE_NODE (id=5):
15:56:01 E - BytesReceived: 8.00 B (8)
15:56:01 E - ConvertRowBatchTime: 0.000ns
15:56:01 E - DeserializeRowBatchTimer: 0.000ns
15:56:01 E - FirstBatchArrivalWaitTime: 0.000ns
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - RowsReturnedRate: 0
15:56:01 E - SendersBlockedTimer: 0.000ns
15:56:01 E - SendersBlockedTotalTimer(*): 0.000ns
15:56:01 E EXCHANGE_NODE (id=4):(Total: 66.667ms, non-child: 66.667ms, % non-child: 100.00%)
15:56:01 E - BytesReceived: 4.00 B (4)
15:56:01 E - ConvertRowBatchTime: 0.000ns
15:56:01 E - DeserializeRowBatchTimer: 0.000ns
15:56:01 E - FirstBatchArrivalWaitTime: 66.667ms
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - RowsReturnedRate: 3.00 /sec
15:56:01 E - SendersBlockedTimer: 0.000ns
15:56:01 E - SendersBlockedTotalTimer(*): 0.000ns
15:56:01 E BlockMgr:
15:56:01 E - BlockWritesOutstanding: 0 (0)
15:56:01 E - BlocksCreated: 16 (16)
15:56:01 E - BlocksRecycled: 0 (0)
15:56:01 E - BufferedPins: 0 (0)
15:56:01 E - MaxBlockSize: 8.00 MB (8388608)
15:56:01 E - MemoryLimit: 14.31 GB (15365329920)
15:56:01 E - PeakMemoryUsage: 8.00 B (8)
15:56:01 E - ScratchBytesRead: 0
15:56:01 E - ScratchBytesWritten: 0
15:56:01 E - ScratchFileUsedBytes: 0
15:56:01 E - ScratchReads: 0 (0)
15:56:01 E - ScratchWrites: 0 (0)
15:56:01 E - TotalBufferWaitTime: 0.000ns
15:56:01 E - TotalEncryptionTime: 0.000ns
15:56:01 E - TotalReadBlockTime: 0.000ns
15:56:01 E Fragment F02:
15:56:01 E Instance 364e2b65ff166530:f9d9801200000005 (host=impala-boost-static-burst-slave-0e4c.vpc.cloudera.com:22002):(Total: 596.010ms, non-child: 64.001ms, % non-child: 10.74%)
15:56:01 E MemoryUsage(500.000ms): 54.25 KB
15:56:01 E ThreadUsage(500.000ms): 1
15:56:01 E - AverageThreadTokens: 1.00
15:56:01 E - BloomFilterBytes: 1.00 MB (1048576)
15:56:01 E - PeakMemoryUsage: 2.08 MB (2181776)
15:56:01 E - PerHostPeakMemUsage: 2.40 MB (2520736)
15:56:01 E - RowsProduced: 1 (1)
15:56:01 E - TotalNetworkReceiveTime: 49.000ms
15:56:01 E - TotalNetworkSendTime: 3.000ms
15:56:01 E - TotalStorageWaitTime: 0.000ns
15:56:01 E - TotalThreadsInvoluntaryContextSwitches: 157 (157)
15:56:01 E - TotalThreadsTotalWallClockTime: 474.008ms
15:56:01 E - TotalThreadsSysTime: 2.999ms
15:56:01 E - TotalThreadsUserTime: 313.952ms
15:56:01 E - TotalThreadsVoluntaryContextSwitches: 6 (6)
15:56:01 E Fragment Instance Lifecycle Timings:
15:56:01 E - ExecTime: 5.000ms
15:56:01 E - ExecTreeExecTime: 0.000ns
15:56:01 E - OpenTime: 463.007ms
15:56:01 E - ExecTreeOpenTime: 49.000ms
15:56:01 E - PrepareTime: 128.002ms
15:56:01 E - ExecTreePrepareTime: 1.000ms
15:56:01 E BlockMgr:
15:56:01 E - BlockWritesOutstanding: 0 (0)
15:56:01 E - BlocksCreated: 16 (16)
15:56:01 E - BlocksRecycled: 0 (0)
15:56:01 E - BufferedPins: 0 (0)
15:56:01 E - MaxBlockSize: 8.00 MB (8388608)
15:56:01 E - MemoryLimit: 14.31 GB (15365329920)
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - ScratchBytesRead: 0
15:56:01 E - ScratchBytesWritten: 0
15:56:01 E - ScratchFileUsedBytes: 0
15:56:01 E - ScratchReads: 0 (0)
15:56:01 E - ScratchWrites: 0 (0)
15:56:01 E - TotalBufferWaitTime: 0.000ns
15:56:01 E - TotalEncryptionTime: 0.000ns
15:56:01 E - TotalReadBlockTime: 0.000ns
15:56:01 E DataStreamSender (dst_id=6):
15:56:01 E - BytesSent: 16.00 B (16)
15:56:01 E - NetworkThroughput(*): 0.00 /sec
15:56:01 E - OverallThroughput: 0.00 /sec
15:56:01 E - PeakMemoryUsage: 16.00 KB (16384)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - SerializeBatchTime: 0.000ns
15:56:01 E - TransmitDataRPCTime: 0.000ns
15:56:01 E - UncompressedRowBatchSize: 16.00 B (16)
15:56:01 E CodeGen:(Total: 482.008ms, non-child: 482.008ms, % non-child: 100.00%)
15:56:01 E - CodegenTime: 1.000ms
15:56:01 E - CompileTime: 31.000ms
15:56:01 E - LoadTime: 0.000ns
15:56:01 E - ModuleBitcodeSize: 1.97 MB (2062036)
15:56:01 E - NumFunctions: 56 (56)
15:56:01 E - NumInstructions: 2.44K (2443)
15:56:01 E - OptimizationTime: 381.006ms
15:56:01 E - PeakMemoryUsage: 1.19 MB (1250816)
15:56:01 E - PrepareTime: 58.000ms
15:56:01 E AGGREGATION_NODE (id=3):(Total: 50.000ms, non-child: 0.000ns, % non-child: 0.00%)
15:56:01 E ExecOption: Codegen Enabled
15:56:01 E - BuildTime: 0.000ns
15:56:01 E - GetResultsTime: 0.000ns
15:56:01 E - HTResizeTime: 0.000ns
15:56:01 E - HashBuckets: 0 (0)
15:56:01 E - LargestPartitionPercent: 0 (0)
15:56:01 E - MaxPartitionLevel: 0 (0)
15:56:01 E - NumRepartitions: 0 (0)
15:56:01 E - PartitionsCreated: 0 (0)
15:56:01 E - PeakMemoryUsage: 24.00 KB (24576)
15:56:01 E - RowsRepartitioned: 0 (0)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - RowsReturnedRate: 19.00 /sec
15:56:01 E - SpilledPartitions: 0 (0)
15:56:01 E HASH_JOIN_NODE (id=2):(Total: 50.000ms, non-child: 1.000ms, % non-child: 2.00%)
15:56:01 E ExecOption: Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously
15:56:01 E - BuildRows: 0 (0)
15:56:01 E - BuildTime: 5.000ms
15:56:01 E - NumHashTableBuildsSkipped: 0 (0)
15:56:01 E - PeakMemoryUsage: 1.03 MB (1083648)
15:56:01 E - ProbeRows: 0 (0)
15:56:01 E - ProbeRowsPartitioned: 0 (0)
15:56:01 E - ProbeTime: 0.000ns
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - RowsReturnedRate: 0
15:56:01 E Hash Join Builder (join_node_id=2):
15:56:01 E ExecOption: Build Side Codegen Enabled, Hash Table Construction Codegen Enabled
15:56:01 E Runtime filters: 1 of 1 Runtime Filter Published
15:56:01 E - BuildRowsPartitionTime: 0.000ns
15:56:01 E - BuildRowsPartitioned: 0 (0)
15:56:01 E - GetNewBlockTime: 1.000ms
15:56:01 E - HashBuckets: 0 (0)
15:56:01 E - HashCollisions: 0 (0)
15:56:01 E - HashTablesBuildTime: 0.000ns
15:56:01 E - LargestPartitionPercent: 0 (0)
15:56:01 E - MaxPartitionLevel: 0 (0)
15:56:01 E - NumRepartitions: 0 (0)
15:56:01 E - PartitionsCreated: 16 (16)
15:56:01 E - PeakMemoryUsage: 1.01 MB (1057920)
15:56:01 E - PinTime: 0.000ns
15:56:01 E - RepartitionTime: 0.000ns
15:56:01 E - SpilledPartitions: 0 (0)
15:56:01 E - UnpinTime: 0.000ns
15:56:01 E EXCHANGE_NODE (id=5):
15:56:01 E BytesReceived(500.000ms): 0
15:56:01 E - BytesReceived: 0
15:56:01 E - ConvertRowBatchTime: 0.000ns
15:56:01 E - DeserializeRowBatchTimer: 0.000ns
15:56:01 E - FirstBatchArrivalWaitTime: 0.000ns
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - RowsReturnedRate: 0
15:56:01 E - SendersBlockedTimer: 0.000ns
15:56:01 E - SendersBlockedTotalTimer(*): 0.000ns
15:56:01 E EXCHANGE_NODE (id=4):(Total: 49.000ms, non-child: 0.000ns, % non-child: 0.00%)
15:56:01 E BytesReceived(500.000ms): 0
15:56:01 E - BytesReceived: 0
15:56:01 E - ConvertRowBatchTime: 0.000ns
15:56:01 E - DeserializeRowBatchTimer: 0.000ns
15:56:01 E - FirstBatchArrivalWaitTime: 49.000ms
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - RowsReturnedRate: 0
15:56:01 E - SendersBlockedTimer: 0.000ns
15:56:01 E - SendersBlockedTotalTimer(*): 0.000ns
15:56:01 E Instance 364e2b65ff166530:f9d9801200000007 (host=impala-boost-static-burst-slave-0e4c.vpc.cloudera.com:22000):(Total: 593.010ms, non-child: 24.000ms, % non-child: 4.05%)
15:56:01 E MemoryUsage(500.000ms): 1.25 MB
15:56:01 E ThreadUsage(500.000ms): 1
15:56:01 E - AverageThreadTokens: 1.00
15:56:01 E - BloomFilterBytes: 1.00 MB (1048576)
15:56:01 E - PeakMemoryUsage: 2.08 MB (2181776)
15:56:01 E - PerHostPeakMemUsage: 3.18 MB (3330710)
15:56:01 E - RowsProduced: 1 (1)
15:56:01 E - TotalNetworkReceiveTime: 43.000ms
15:56:01 E - TotalNetworkSendTime: 1.000ms
15:56:01 E - TotalStorageWaitTime: 0.000ns
15:56:01 E - TotalThreadsInvoluntaryContextSwitches: 380 (380)
15:56:01 E - TotalThreadsTotalWallClockTime: 532.009ms
15:56:01 E - TotalThreadsSysTime: 6.999ms
15:56:01 E - TotalThreadsUserTime: 314.952ms
15:56:01 E - TotalThreadsVoluntaryContextSwitches: 14 (14)
15:56:01 E Fragment Instance Lifecycle Timings:
15:56:01 E - ExecTime: 1.000ms
15:56:01 E - ExecTreeExecTime: 0.000ns
15:56:01 E - OpenTime: 523.008ms
15:56:01 E - ExecTreeOpenTime: 44.000ms
15:56:01 E - PrepareTime: 68.001ms
15:56:01 E - ExecTreePrepareTime: 0.000ns
15:56:01 E DataStreamSender (dst_id=6):
15:56:01 E - BytesSent: 16.00 B (16)
15:56:01 E - NetworkThroughput(*): 0.00 /sec
15:56:01 E - OverallThroughput: 0.00 /sec
15:56:01 E - PeakMemoryUsage: 16.00 KB (16384)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - SerializeBatchTime: 0.000ns
15:56:01 E - TransmitDataRPCTime: 0.000ns
15:56:01 E - UncompressedRowBatchSize: 16.00 B (16)
15:56:01 E CodeGen:(Total: 525.009ms, non-child: 525.009ms, % non-child: 100.00%)
15:56:01 E - CodegenTime: 1.000ms
15:56:01 E - CompileTime: 35.000ms
15:56:01 E - LoadTime: 0.000ns
15:56:01 E - ModuleBitcodeSize: 1.97 MB (2062036)
15:56:01 E - NumFunctions: 56 (56)
15:56:01 E - NumInstructions: 2.44K (2443)
15:56:01 E - OptimizationTime: 442.007ms
15:56:01 E - PeakMemoryUsage: 1.19 MB (1250816)
15:56:01 E - PrepareTime: 47.000ms
15:56:01 E AGGREGATION_NODE (id=3):(Total: 44.000ms, non-child: 0.000ns, % non-child: 0.00%)
15:56:01 E ExecOption: Codegen Enabled
15:56:01 E - BuildTime: 0.000ns
15:56:01 E - GetResultsTime: 0.000ns
15:56:01 E - HTResizeTime: 0.000ns
15:56:01 E - HashBuckets: 0 (0)
15:56:01 E - LargestPartitionPercent: 0 (0)
15:56:01 E - MaxPartitionLevel: 0 (0)
15:56:01 E - NumRepartitions: 0 (0)
15:56:01 E - PartitionsCreated: 0 (0)
15:56:01 E - PeakMemoryUsage: 24.00 KB (24576)
15:56:01 E - RowsRepartitioned: 0 (0)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - RowsReturnedRate: 22.00 /sec
15:56:01 E - SpilledPartitions: 0 (0)
15:56:01 E HASH_JOIN_NODE (id=2):(Total: 44.000ms, non-child: 1.000ms, % non-child: 2.27%)
15:56:01 E ExecOption: Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously
15:56:01 E - BuildRows: 0 (0)
15:56:01 E - BuildTime: 8.000ms
15:56:01 E - NumHashTableBuildsSkipped: 0 (0)
15:56:01 E - PeakMemoryUsage: 1.03 MB (1083648)
15:56:01 E - ProbeRows: 0 (0)
15:56:01 E - ProbeRowsPartitioned: 0 (0)
15:56:01 E - ProbeTime: 0.000ns
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - RowsReturnedRate: 0
15:56:01 E Hash Join Builder (join_node_id=2):
15:56:01 E ExecOption: Build Side Codegen Enabled, Hash Table Construction Codegen Enabled
15:56:01 E Runtime filters: 1 of 1 Runtime Filter Published
15:56:01 E - BuildRowsPartitionTime: 0.000ns
15:56:01 E - BuildRowsPartitioned: 0 (0)
15:56:01 E - GetNewBlockTime: 0.000ns
15:56:01 E - HashBuckets: 0 (0)
15:56:01 E - HashCollisions: 0 (0)
15:56:01 E - HashTablesBuildTime: 0.000ns
15:56:01 E - LargestPartitionPercent: 0 (0)
15:56:01 E - MaxPartitionLevel: 0 (0)
15:56:01 E - NumRepartitions: 0 (0)
15:56:01 E - PartitionsCreated: 16 (16)
15:56:01 E - PeakMemoryUsage: 1.01 MB (1057920)
15:56:01 E - PinTime: 0.000ns
15:56:01 E - RepartitionTime: 0.000ns
15:56:01 E - SpilledPartitions: 0 (0)
15:56:01 E - UnpinTime: 0.000ns
15:56:01 E EXCHANGE_NODE (id=5):
15:56:01 E BytesReceived(500.000ms): 0
15:56:01 E - BytesReceived: 0
15:56:01 E - ConvertRowBatchTime: 0.000ns
15:56:01 E - DeserializeRowBatchTimer: 0.000ns
15:56:01 E - FirstBatchArrivalWaitTime: 0.000ns
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - RowsReturnedRate: 0
15:56:01 E - SendersBlockedTimer: 0.000ns
15:56:01 E - SendersBlockedTotalTimer(*): 0.000ns
15:56:01 E EXCHANGE_NODE (id=4):(Total: 43.000ms, non-child: 0.000ns, % non-child: 0.00%)
15:56:01 E BytesReceived(500.000ms): 0
15:56:01 E - BytesReceived: 0
15:56:01 E - ConvertRowBatchTime: 0.000ns
15:56:01 E - DeserializeRowBatchTimer: 0.000ns
15:56:01 E - FirstBatchArrivalWaitTime: 43.000ms
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - RowsReturnedRate: 0
15:56:01 E - SendersBlockedTimer: 0.000ns
15:56:01 E - SendersBlockedTotalTimer(*): 0.000ns
15:56:01 E Instance 364e2b65ff166530:f9d9801200000006 (host=impala-boost-static-burst-slave-0e4c.vpc.cloudera.com:22001):(Total: 593.010ms, non-child: 20.000ms, % non-child: 3.37%)
15:56:01 E MemoryUsage(500.000ms): 1.26 MB
15:56:01 E ThreadUsage(500.000ms): 1
15:56:01 E - AverageThreadTokens: 1.00
15:56:01 E - BloomFilterBytes: 1.00 MB (1048576)
15:56:01 E - PeakMemoryUsage: 2.08 MB (2185880)
15:56:01 E - PerHostPeakMemUsage: 2.36 MB (2474672)
15:56:01 E - RowsProduced: 1 (1)
15:56:01 E - TotalNetworkReceiveTime: 108.001ms
15:56:01 E - TotalNetworkSendTime: 0.000ns
15:56:01 E - TotalStorageWaitTime: 0.000ns
15:56:01 E - TotalThreadsInvoluntaryContextSwitches: 101 (101)
15:56:01 E - TotalThreadsTotalWallClockTime: 482.008ms
15:56:01 E - TotalThreadsSysTime: 4.999ms
15:56:01 E - TotalThreadsUserTime: 315.951ms
15:56:01 E - TotalThreadsVoluntaryContextSwitches: 7 (7)
15:56:01 E Fragment Instance Lifecycle Timings:
15:56:01 E - ExecTime: 0.000ns
15:56:01 E - ExecTreeExecTime: 0.000ns
15:56:01 E - OpenTime: 477.008ms
15:56:01 E - ExecTreeOpenTime: 110.001ms
15:56:01 E - PrepareTime: 115.001ms
15:56:01 E - ExecTreePrepareTime: 0.000ns
15:56:01 E BlockMgr:
15:56:01 E - BlockWritesOutstanding: 0 (0)
15:56:01 E - BlocksCreated: 16 (16)
15:56:01 E - BlocksRecycled: 0 (0)
15:56:01 E - BufferedPins: 0 (0)
15:56:01 E - MaxBlockSize: 8.00 MB (8388608)
15:56:01 E - MemoryLimit: 14.31 GB (15365329920)
15:56:01 E - PeakMemoryUsage: 16.00 B (16)
15:56:01 E - ScratchBytesRead: 0
15:56:01 E - ScratchBytesWritten: 0
15:56:01 E - ScratchFileUsedBytes: 0
15:56:01 E - ScratchReads: 0 (0)
15:56:01 E - ScratchWrites: 0 (0)
15:56:01 E - TotalBufferWaitTime: 0.000ns
15:56:01 E - TotalEncryptionTime: 0.000ns
15:56:01 E - TotalReadBlockTime: 0.000ns
15:56:01 E DataStreamSender (dst_id=6):
15:56:01 E - BytesSent: 16.00 B (16)
15:56:01 E - NetworkThroughput(*): 0.00 /sec
15:56:01 E - OverallThroughput: 0.00 /sec
15:56:01 E - PeakMemoryUsage: 16.00 KB (16384)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - SerializeBatchTime: 0.000ns
15:56:01 E - TransmitDataRPCTime: 0.000ns
15:56:01 E - UncompressedRowBatchSize: 16.00 B (16)
15:56:01 E CodeGen:(Total: 463.007ms, non-child: 463.007ms, % non-child: 100.00%)
15:56:01 E - CodegenTime: 1.000ms
15:56:01 E - CompileTime: 28.000ms
15:56:01 E - LoadTime: 0.000ns
15:56:01 E - ModuleBitcodeSize: 1.97 MB (2062036)
15:56:01 E - NumFunctions: 56 (56)
15:56:01 E - NumInstructions: 2.44K (2443)
15:56:01 E - OptimizationTime: 337.005ms
15:56:01 E - PeakMemoryUsage: 1.19 MB (1250816)
15:56:01 E - PrepareTime: 97.001ms
15:56:01 E AGGREGATION_NODE (id=3):(Total: 110.001ms, non-child: 2.000ms, % non-child: 1.82%)
15:56:01 E ExecOption: Codegen Enabled
15:56:01 E - BuildTime: 0.000ns
15:56:01 E - GetResultsTime: 0.000ns
15:56:01 E - HTResizeTime: 0.000ns
15:56:01 E - HashBuckets: 0 (0)
15:56:01 E - LargestPartitionPercent: 0 (0)
15:56:01 E - MaxPartitionLevel: 0 (0)
15:56:01 E - NumRepartitions: 0 (0)
15:56:01 E - PartitionsCreated: 0 (0)
15:56:01 E - PeakMemoryUsage: 28.00 KB (28672)
15:56:01 E - RowsRepartitioned: 0 (0)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - RowsReturnedRate: 9.00 /sec
15:56:01 E - SpilledPartitions: 0 (0)
15:56:01 E HASH_JOIN_NODE (id=2):(Total: 108.001ms, non-child: 0.000ns, % non-child: 0.00%)
15:56:01 E ExecOption: Probe Side Codegen Enabled, Join Build-Side Prepared Asynchronously
15:56:01 E - BuildRows: 1 (1)
15:56:01 E - BuildTime: 5.000ms
15:56:01 E - NumHashTableBuildsSkipped: 0 (0)
15:56:01 E - PeakMemoryUsage: 1.04 MB (1087744)
15:56:01 E - ProbeRows: 1 (1)
15:56:01 E - ProbeRowsPartitioned: 0 (0)
15:56:01 E - ProbeTime: 0.000ns
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - RowsReturnedRate: 9.00 /sec
15:56:01 E Hash Join Builder (join_node_id=2):
15:56:01 E ExecOption: Build Side Codegen Enabled, Hash Table Construction Codegen Enabled
15:56:01 E Runtime filters: 1 of 1 Runtime Filter Published
15:56:01 E - BuildRowsPartitionTime: 0.000ns
15:56:01 E - BuildRowsPartitioned: 1 (1)
15:56:01 E - GetNewBlockTime: 1.000ms
15:56:01 E - HashBuckets: 1 (1)
15:56:01 E - HashCollisions: 0 (0)
15:56:01 E - HashTablesBuildTime: 0.000ns
15:56:01 E - LargestPartitionPercent: 100 (100)
15:56:01 E - MaxPartitionLevel: 0 (0)
15:56:01 E - NumRepartitions: 0 (0)
15:56:01 E - PartitionsCreated: 16 (16)
15:56:01 E - PeakMemoryUsage: 1.01 MB (1057920)
15:56:01 E - PinTime: 0.000ns
15:56:01 E - RepartitionTime: 0.000ns
15:56:01 E - SpilledPartitions: 0 (0)
15:56:01 E - UnpinTime: 0.000ns
15:56:01 E EXCHANGE_NODE (id=5):
15:56:01 E BytesReceived(500.000ms): 25.00 B
15:56:01 E - BytesReceived: 25.00 B (25)
15:56:01 E - ConvertRowBatchTime: 0.000ns
15:56:01 E - DeserializeRowBatchTimer: 0.000ns
15:56:01 E - FirstBatchArrivalWaitTime: 0.000ns
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - RowsReturnedRate: 0
15:56:01 E - SendersBlockedTimer: 0.000ns
15:56:01 E - SendersBlockedTotalTimer(*): 0.000ns
15:56:01 E EXCHANGE_NODE (id=4):(Total: 108.001ms, non-child: 0.000ns, % non-child: 0.00%)
15:56:01 E BytesReceived(500.000ms): 0
15:56:01 E - BytesReceived: 13.00 B (13)
15:56:01 E - ConvertRowBatchTime: 0.000ns
15:56:01 E - DeserializeRowBatchTimer: 0.000ns
15:56:01 E - FirstBatchArrivalWaitTime: 108.001ms
15:56:01 E - PeakMemoryUsage: 0
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - RowsReturnedRate: 9.00 /sec
15:56:01 E - SendersBlockedTimer: 0.000ns
15:56:01 E - SendersBlockedTotalTimer(*): 0.000ns
15:56:01 E Averaged Fragment F00:(Total: 584.676ms, non-child: 29.667ms, % non-child: 5.07%)
15:56:01 E split sizes: min: 59.70 KB, max: 60.18 KB, avg: 59.90 KB, stddev: 206.98 B
15:56:01 E completion times: min:583.009ms max:596.010ms mean: 590.343ms stddev:5.436ms
15:56:01 E execution rates: min:100.16 KB/sec max:102.63 KB/sec mean:101.48 KB/sec stddev:1.01 KB/sec
15:56:01 E num instances: 3
15:56:01 E - AverageThreadTokens: 1.67
15:56:01 E - BloomFilterBytes: 1.00 MB (1048576)
15:56:01 E - PeakMemoryUsage: 1.23 MB (1290597)
15:56:01 E - PerHostPeakMemUsage: 2.65 MB (2775372)
15:56:01 E - RowsProduced: 0 (0)
15:56:01 E - TotalNetworkReceiveTime: 0.000ns
15:56:01 E - TotalNetworkSendTime: 333.339us
15:56:01 E - TotalStorageWaitTime: 5.666ms
15:56:01 E - TotalThreadsInvoluntaryContextSwitches: 51 (51)
15:56:01 E - TotalThreadsTotalWallClockTime: 662.344ms
15:56:01 E - TotalThreadsSysTime: 2.666ms
15:56:01 E - TotalThreadsUserTime: 46.325ms
15:56:01 E - TotalThreadsVoluntaryContextSwitches: 62 (62)
15:56:01 E Fragment Instance Lifecycle Timings:
15:56:01 E - ExecTime: 427.673ms
15:56:01 E - ExecTreeExecTime: 426.673ms
15:56:01 E - OpenTime: 77.001ms
15:56:01 E - ExecTreeOpenTime: 333.339us
15:56:01 E - PrepareTime: 80.001ms
15:56:01 E - ExecTreePrepareTime: 333.339us
15:56:01 E DataStreamSender (dst_id=4):
15:56:01 E - BytesSent: 4.00 B (4)
15:56:01 E - NetworkThroughput(*): 0.00 /sec
15:56:01 E - OverallThroughput: 0.00 /sec
15:56:01 E - PeakMemoryUsage: 78.11 KB (79989)
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - SerializeBatchTime: 0.000ns
15:56:01 E - TransmitDataRPCTime: 0.000ns
15:56:01 E - UncompressedRowBatchSize: 4.00 B (4)
15:56:01 E CodeGen:(Total: 127.335ms, non-child: 127.335ms, % non-child: 100.00%)
15:56:01 E - CodegenTime: 2.666ms
15:56:01 E - CompileTime: 4.666ms
15:56:01 E - LoadTime: 0.000ns
15:56:01 E - ModuleBitcodeSize: 1.97 MB (2062036)
15:56:01 E - NumFunctions: 27 (27)
15:56:01 E - NumInstructions: 437 (437)
15:56:01 E - OptimizationTime: 70.334ms
15:56:01 E - PeakMemoryUsage: 218.50 KB (223744)
15:56:01 E - PrepareTime: 51.000ms
15:56:01 E HDFS_SCAN_NODE (id=0):(Total: 427.673ms, non-child: 427.673ms, % non-child: 100.00%)
15:56:01 E - AverageHdfsReadThreadConcurrency: 0.00
15:56:01 E - AverageScannerThreadConcurrency: 0.67
15:56:01 E - BytesRead: 72.66 KB (74400)
15:56:01 E - BytesReadDataNodeCache: 0
15:56:01 E - BytesReadLocal: 72.66 KB (74400)
15:56:01 E - BytesReadRemoteUnexpected: 0
15:56:01 E - BytesReadShortCircuit: 72.66 KB (74400)
15:56:01 E - CachedFileHandlesHitCount: 16 (16)
15:56:01 E - CachedFileHandlesMissCount: 0 (0)
15:56:01 E - DecompressionTime: 0.000ns
15:56:01 E - MaxCompressedTextFileLength: 0
15:56:01 E - NumColumns: 1 (1)
15:56:01 E - NumDictFilteredRowGroups: 0 (0)
15:56:01 E - NumDisksAccessed: 3 (3)
15:56:01 E - NumRowGroups: 8 (8)
15:56:01 E - NumScannerThreadsStarted: 3 (3)
15:56:01 E - NumScannersWithNoReads: 0 (0)
15:56:01 E - NumStatsFilteredRowGroups: 0 (0)
15:56:01 E - PeakMemoryUsage: 150.34 KB (153951)
15:56:01 E - PerReadThreadRawHdfsThroughput: 37.53 MB/sec
15:56:01 E - RemoteScanRanges: 0 (0)
15:56:01 E - RowBatchQueueGetWaitTime: 5.000ms
15:56:01 E - RowBatchQueuePutWaitTime: 0.000ns
15:56:01 E - RowsRead: 2.43K (2433)
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - RowsReturnedRate: 0
15:56:01 E - ScanRangesComplete: 8 (8)
15:56:01 E - ScannerThreadsInvoluntaryContextSwitches: 10 (10)
15:56:01 E - ScannerThreadsTotalWallClockTime: 157.669ms
15:56:01 E - MaterializeTupleTime(*): 333.339us
15:56:01 E - ScannerThreadsSysTime: 333.000us
15:56:01 E - ScannerThreadsUserTime: 3.664ms
15:56:01 E - ScannerThreadsVoluntaryContextSwitches: 30 (30)
15:56:01 E - TotalRawHdfsReadTime(*): 2.666ms
15:56:01 E - TotalReadThroughput: 0.00 /sec
15:56:01 E Filter 0 (1.00 MB):
15:56:01 E - Rows processed: 2.33K (2330)
15:56:01 E - Rows rejected: 2.33K (2329)
15:56:01 E - Rows total: 2.33K (2330)
15:56:01 E Fragment F00:
15:56:01 E Instance 364e2b65ff166530:f9d9801200000002 (host=impala-boost-static-burst-slave-0e4c.vpc.cloudera.com:22001):(Total: 592.010ms, non-child: 12.000ms, % non-child: 2.03%)
15:56:01 E Hdfs split stats (<volume id>:<# splits>/<split lengths>): 1:1/7.44 KB 2:3/22.57 KB 0:4/29.69 KB
15:56:01 E Filter 0 arrival: 566ms
15:56:01 E MemoryUsage(500.000ms): 84.78 KB
15:56:01 E ThreadUsage(500.000ms): 1
15:56:01 E - AverageThreadTokens: 1.00
15:56:01 E - BloomFilterBytes: 1.00 MB (1048576)
15:56:01 E - PeakMemoryUsage: 1.22 MB (1275920)
15:56:01 E - PerHostPeakMemUsage: 2.36 MB (2474672)
15:56:01 E - RowsProduced: 0 (0)
15:56:01 E - TotalNetworkReceiveTime: 0.000ns
15:56:01 E - TotalNetworkSendTime: 0.000ns
15:56:01 E - TotalStorageWaitTime: 8.000ms
15:56:01 E - TotalThreadsInvoluntaryContextSwitches: 30 (30)
15:56:01 E - TotalThreadsTotalWallClockTime: 640.010ms
15:56:01 E - TotalThreadsSysTime: 1.998ms
15:56:01 E - TotalThreadsUserTime: 45.991ms
15:56:01 E - TotalThreadsVoluntaryContextSwitches: 64 (64)
15:56:01 E Fragment Instance Lifecycle Timings:
15:56:01 E - ExecTime: 448.007ms
15:56:01 E - ExecTreeExecTime: 446.007ms
15:56:01 E - OpenTime: 68.001ms
15:56:01 E - ExecTreeOpenTime: 0.000ns
15:56:01 E - PrepareTime: 76.001ms
15:56:01 E - ExecTreePrepareTime: 1.000ms
15:56:01 E DataStreamSender (dst_id=4):
15:56:01 E - BytesSent: 0
15:56:01 E - NetworkThroughput(*): 0.00 /sec
15:56:01 E - OverallThroughput: 0.00 /sec
15:56:01 E - PeakMemoryUsage: 76.78 KB (78624)
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - SerializeBatchTime: 0.000ns
15:56:01 E - TransmitDataRPCTime: 0.000ns
15:56:01 E - UncompressedRowBatchSize: 0
15:56:01 E CodeGen:(Total: 132.002ms, non-child: 132.002ms, % non-child: 100.00%)
15:56:01 E - CodegenTime: 2.000ms
15:56:01 E - CompileTime: 5.000ms
15:56:01 E - LoadTime: 0.000ns
15:56:01 E - ModuleBitcodeSize: 1.97 MB (2062036)
15:56:01 E - NumFunctions: 27 (27)
15:56:01 E - NumInstructions: 437 (437)
15:56:01 E - OptimizationTime: 62.001ms
15:56:01 E - PeakMemoryUsage: 218.50 KB (223744)
15:56:01 E - PrepareTime: 64.001ms
15:56:01 E HDFS_SCAN_NODE (id=0):(Total: 448.007ms, non-child: 448.007ms, % non-child: 100.00%)
15:56:01 E Hdfs split stats (<volume id>:<# splits>/<split lengths>): 1:1/7.44 KB 2:3/22.57 KB 0:4/29.69 KB
15:56:01 E ExecOption: PARQUET Codegen Enabled, Codegen enabled: 8 out of 8
15:56:01 E Runtime filters: All filters arrived. Waited 442ms
15:56:01 E Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0%
15:56:01 E File Formats: PARQUET/SNAPPY:8
15:56:01 E BytesRead(500.000ms): 0
15:56:01 E - FooterProcessingTime: (Avg: 375.006us ; Min: 0.000ns ; Max: 1.000ms ; Number of samples: 8)
15:56:01 E - AverageHdfsReadThreadConcurrency: 0.00
15:56:01 E - AverageScannerThreadConcurrency: 0.00
15:56:01 E - BytesRead: 72.38 KB (74121)
15:56:01 E - BytesReadDataNodeCache: 0
15:56:01 E - BytesReadLocal: 72.38 KB (74121)
15:56:01 E - BytesReadRemoteUnexpected: 0
15:56:01 E - BytesReadShortCircuit: 72.38 KB (74121)
15:56:01 E - CachedFileHandlesHitCount: 16 (16)
15:56:01 E - CachedFileHandlesMissCount: 0 (0)
15:56:01 E - DecompressionTime: 0.000ns
15:56:01 E - MaxCompressedTextFileLength: 0
15:56:01 E - NumColumns: 1 (1)
15:56:01 E - NumDictFilteredRowGroups: 0 (0)
15:56:01 E - NumDisksAccessed: 3 (3)
15:56:01 E - NumRowGroups: 8 (8)
15:56:01 E - NumScannerThreadsStarted: 4 (4)
15:56:01 E - NumScannersWithNoReads: 0 (0)
15:56:01 E - NumStatsFilteredRowGroups: 0 (0)
15:56:01 E - PeakMemoryUsage: 136.01 KB (139274)
15:56:01 E - PerReadThreadRawHdfsThroughput: 17.67 MB/sec
15:56:01 E - RemoteScanRanges: 0 (0)
15:56:01 E - RowBatchQueueGetWaitTime: 3.000ms
15:56:01 E - RowBatchQueuePutWaitTime: 0.000ns
15:56:01 E - RowsRead: 2.42K (2420)
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - RowsReturnedRate: 0
15:56:01 E - ScanRangesComplete: 8 (8)
15:56:01 E - ScannerThreadsInvoluntaryContextSwitches: 1 (1)
15:56:01 E - ScannerThreadsTotalWallClockTime: 124.002ms
15:56:01 E - MaterializeTupleTime(*): 1.000ms
15:56:01 E - ScannerThreadsSysTime: 999.000us
15:56:01 E - ScannerThreadsUserTime: 2.997ms
15:56:01 E - ScannerThreadsVoluntaryContextSwitches: 35 (35)
15:56:01 E - TotalRawHdfsReadTime(*): 4.000ms
15:56:01 E - TotalReadThroughput: 0.00 /sec
15:56:01 E Filter 0 (1.00 MB):
15:56:01 E - Rows processed: 2.42K (2420)
15:56:01 E - Rows rejected: 2.42K (2420)
15:56:01 E - Rows total: 2.42K (2420)
15:56:01 E Instance 364e2b65ff166530:f9d9801200000001 (host=impala-boost-static-burst-slave-0e4c.vpc.cloudera.com:22002):(Total: 583.009ms, non-child: 38.000ms, % non-child: 6.52%)
15:56:01 E Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/7.57 KB 2:3/22.58 KB 1:4/30.03 KB
15:56:01 E Filter 0 arrival: 563ms
15:56:01 E MemoryUsage(500.000ms): 303.28 KB
15:56:01 E ThreadUsage(500.000ms): 1
15:56:01 E - AverageThreadTokens: 1.00
15:56:01 E - BloomFilterBytes: 1.00 MB (1048576)
15:56:01 E - PeakMemoryUsage: 1.32 MB (1387536)
15:56:01 E - PerHostPeakMemUsage: 2.40 MB (2520736)
15:56:01 E - RowsProduced: 1 (1)
15:56:01 E - TotalNetworkReceiveTime: 0.000ns
15:56:01 E - TotalNetworkSendTime: 1.000ms
15:56:01 E - TotalStorageWaitTime: 3.000ms
15:56:01 E - TotalThreadsInvoluntaryContextSwitches: 32 (32)
15:56:01 E - TotalThreadsTotalWallClockTime: 520.008ms
15:56:01 E - TotalThreadsSysTime: 2.000ms
15:56:01 E - TotalThreadsUserTime: 45.991ms
15:56:01 E - TotalThreadsVoluntaryContextSwitches: 56 (56)
15:56:01 E Fragment Instance Lifecycle Timings:
15:56:01 E - ExecTime: 419.007ms
15:56:01 E - ExecTreeExecTime: 418.007ms
15:56:01 E - OpenTime: 88.001ms
15:56:01 E - ExecTreeOpenTime: 0.000ns
15:56:01 E - PrepareTime: 76.001ms
15:56:01 E - ExecTreePrepareTime: 0.000ns
15:56:01 E DataStreamSender (dst_id=4):
15:56:01 E - BytesSent: 13.00 B (13)
15:56:01 E - NetworkThroughput(*): 0.00 /sec
15:56:01 E - OverallThroughput: 0.00 /sec
15:56:01 E - PeakMemoryUsage: 80.78 KB (82720)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - SerializeBatchTime: 0.000ns
15:56:01 E - TransmitDataRPCTime: 0.000ns
15:56:01 E - UncompressedRowBatchSize: 13.00 B (13)
15:56:01 E CodeGen:(Total: 127.002ms, non-child: 127.002ms, % non-child: 100.00%)
15:56:01 E - CodegenTime: 2.000ms
15:56:01 E - CompileTime: 5.000ms
15:56:01 E - LoadTime: 0.000ns
15:56:01 E - ModuleBitcodeSize: 1.97 MB (2062036)
15:56:01 E - NumFunctions: 27 (27)
15:56:01 E - NumInstructions: 437 (437)
15:56:01 E - OptimizationTime: 81.001ms
15:56:01 E - PeakMemoryUsage: 218.50 KB (223744)
15:56:01 E - PrepareTime: 41.000ms
15:56:01 E HDFS_SCAN_NODE (id=0):(Total: 418.007ms, non-child: 418.007ms, % non-child: 100.00%)
15:56:01 E Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/7.57 KB 2:3/22.58 KB 1:4/30.03 KB
15:56:01 E ExecOption: PARQUET Codegen Enabled, Codegen enabled: 8 out of 8
15:56:01 E Runtime filters: All filters arrived. Waited 403ms
15:56:01 E Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0%
15:56:01 E File Formats: PARQUET/SNAPPY:8
15:56:01 E BytesRead(500.000ms): 0
15:56:01 E - FooterProcessingTime: (Avg: 750.013us ; Min: 0.000ns ; Max: 1.000ms ; Number of samples: 8)
15:56:01 E - AverageHdfsReadThreadConcurrency: 0.00
15:56:01 E - AverageScannerThreadConcurrency: 0.00
15:56:01 E - BytesRead: 73.02 KB (74769)
15:56:01 E - BytesReadDataNodeCache: 0
15:56:01 E - BytesReadLocal: 73.02 KB (74769)
15:56:01 E - BytesReadRemoteUnexpected: 0
15:56:01 E - BytesReadShortCircuit: 73.02 KB (74769)
15:56:01 E - CachedFileHandlesHitCount: 16 (16)
15:56:01 E - CachedFileHandlesMissCount: 0 (0)
15:56:01 E - DecompressionTime: 0.000ns
15:56:01 E - MaxCompressedTextFileLength: 0
15:56:01 E - NumColumns: 1 (1)
15:56:01 E - NumDictFilteredRowGroups: 0 (0)
15:56:01 E - NumDisksAccessed: 3 (3)
15:56:01 E - NumRowGroups: 8 (8)
15:56:01 E - NumScannerThreadsStarted: 3 (3)
15:56:01 E - NumScannersWithNoReads: 0 (0)
15:56:01 E - NumStatsFilteredRowGroups: 0 (0)
15:56:01 E - PeakMemoryUsage: 245.01 KB (250890)
15:56:01 E - PerReadThreadRawHdfsThroughput: 71.30 MB/sec
15:56:01 E - RemoteScanRanges: 0 (0)
15:56:01 E - RowBatchQueueGetWaitTime: 4.000ms
15:56:01 E - RowBatchQueuePutWaitTime: 0.000ns
15:56:01 E - RowsRead: 2.45K (2450)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - RowsReturnedRate: 2.00 /sec
15:56:01 E - ScanRangesComplete: 8 (8)
15:56:01 E - ScannerThreadsInvoluntaryContextSwitches: 22 (22)
15:56:01 E - ScannerThreadsTotalWallClockTime: 13.000ms
15:56:01 E - MaterializeTupleTime(*): 0.000ns
15:56:01 E - ScannerThreadsSysTime: 0.000ns
15:56:01 E - ScannerThreadsUserTime: 2.998ms
15:56:01 E - ScannerThreadsVoluntaryContextSwitches: 23 (23)
15:56:01 E - TotalRawHdfsReadTime(*): 1.000ms
15:56:01 E - TotalReadThroughput: 0.00 /sec
15:56:01 E Filter 0 (1.00 MB):
15:56:01 E - Rows processed: 2.45K (2450)
15:56:01 E - Rows rejected: 2.45K (2449)
15:56:01 E - Rows total: 2.45K (2450)
15:56:01 E Instance 364e2b65ff166530:f9d9801200000003 (host=impala-boost-static-burst-slave-0e4c.vpc.cloudera.com:22000):(Total: 579.009ms, non-child: 39.000ms, % non-child: 6.74%)
15:56:01 E Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/7.57 KB 1:3/22.12 KB 2:4/30.15 KB
15:56:01 E Filter 0 arrival: 560ms
15:56:01 E MemoryUsage(500.000ms): 86.01 KB
15:56:01 E ThreadUsage(500.000ms): 3
15:56:01 E - AverageThreadTokens: 3.00
15:56:01 E - BloomFilterBytes: 1.00 MB (1048576)
15:56:01 E - PeakMemoryUsage: 1.15 MB (1208336)
15:56:01 E - PerHostPeakMemUsage: 3.18 MB (3330710)
15:56:01 E - RowsProduced: 0 (0)
15:56:01 E - TotalNetworkReceiveTime: 0.000ns
15:56:01 E - TotalNetworkSendTime: 0.000ns
15:56:01 E - TotalStorageWaitTime: 6.000ms
15:56:01 E - TotalThreadsInvoluntaryContextSwitches: 93 (93)
15:56:01 E - TotalThreadsTotalWallClockTime: 827.014ms
15:56:01 E - TotalThreadsSysTime: 4.000ms
15:56:01 E - TotalThreadsUserTime: 46.993ms
15:56:01 E - TotalThreadsVoluntaryContextSwitches: 68 (68)
15:56:01 E Fragment Instance Lifecycle Timings:
15:56:01 E - ExecTime: 416.007ms
15:56:01 E - ExecTreeExecTime: 416.007ms
15:56:01 E - OpenTime: 75.001ms
15:56:01 E - ExecTreeOpenTime: 1.000ms
15:56:01 E - PrepareTime: 88.001ms
15:56:01 E - ExecTreePrepareTime: 0.000ns
15:56:01 E DataStreamSender (dst_id=4):
15:56:01 E - BytesSent: 0
15:56:01 E - NetworkThroughput(*): 0.00 /sec
15:56:01 E - OverallThroughput: 0.00 /sec
15:56:01 E - PeakMemoryUsage: 76.78 KB (78624)
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - SerializeBatchTime: 0.000ns
15:56:01 E - TransmitDataRPCTime: 0.000ns
15:56:01 E - UncompressedRowBatchSize: 0
15:56:01 E CodeGen:(Total: 123.002ms, non-child: 123.002ms, % non-child: 100.00%)
15:56:01 E - CodegenTime: 4.000ms
15:56:01 E - CompileTime: 4.000ms
15:56:01 E - LoadTime: 0.000ns
15:56:01 E - ModuleBitcodeSize: 1.97 MB (2062036)
15:56:01 E - NumFunctions: 27 (27)
15:56:01 E - NumInstructions: 437 (437)
15:56:01 E - OptimizationTime: 68.001ms
15:56:01 E - PeakMemoryUsage: 218.50 KB (223744)
15:56:01 E - PrepareTime: 48.000ms
15:56:01 E HDFS_SCAN_NODE (id=0):(Total: 417.007ms, non-child: 417.007ms, % non-child: 100.00%)
15:56:01 E Hdfs split stats (<volume id>:<# splits>/<split lengths>): 0:1/7.57 KB 1:3/22.12 KB 2:4/30.15 KB
15:56:01 E ExecOption: PARQUET Codegen Enabled, Codegen enabled: 8 out of 8
15:56:01 E Runtime filters: All filters arrived. Waited 407ms
15:56:01 E Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0%
15:56:01 E File Formats: PARQUET/SNAPPY:8
15:56:01 E BytesRead(500.000ms): 0
15:56:01 E - FooterProcessingTime: (Avg: 250.004us ; Min: 0.000ns ; Max: 1.000ms ; Number of samples: 8)
15:56:01 E - AverageHdfsReadThreadConcurrency: 0.00
15:56:01 E - AverageScannerThreadConcurrency: 2.00
15:56:01 E - BytesRead: 72.57 KB (74310)
15:56:01 E - BytesReadDataNodeCache: 0
15:56:01 E - BytesReadLocal: 72.57 KB (74310)
15:56:01 E - BytesReadRemoteUnexpected: 0
15:56:01 E - BytesReadShortCircuit: 72.57 KB (74310)
15:56:01 E - CachedFileHandlesHitCount: 16 (16)
15:56:01 E - CachedFileHandlesMissCount: 0 (0)
15:56:01 E - DecompressionTime: 0.000ns
15:56:01 E - MaxCompressedTextFileLength: 0
15:56:01 E - NumColumns: 1 (1)
15:56:01 E - NumDictFilteredRowGroups: 0 (0)
15:56:01 E - NumDisksAccessed: 3 (3)
15:56:01 E - NumRowGroups: 8 (8)
15:56:01 E - NumScannerThreadsStarted: 3 (3)
15:56:01 E - NumScannersWithNoReads: 0 (0)
15:56:01 E - NumStatsFilteredRowGroups: 0 (0)
15:56:01 E - PeakMemoryUsage: 70.01 KB (71690)
15:56:01 E - PerReadThreadRawHdfsThroughput: 23.62 MB/sec
15:56:01 E - RemoteScanRanges: 0 (0)
15:56:01 E - RowBatchQueueGetWaitTime: 8.000ms
15:56:01 E - RowBatchQueuePutWaitTime: 0.000ns
15:56:01 E - RowsRead: 2.43K (2430)
15:56:01 E - RowsReturned: 0 (0)
15:56:01 E - RowsReturnedRate: 0
15:56:01 E - ScanRangesComplete: 8 (8)
15:56:01 E - ScannerThreadsInvoluntaryContextSwitches: 8 (8)
15:56:01 E - ScannerThreadsTotalWallClockTime: 336.005ms
15:56:01 E - MaterializeTupleTime(*): 0.000ns
15:56:01 E - ScannerThreadsSysTime: 0.000ns
15:56:01 E - ScannerThreadsUserTime: 4.999ms
15:56:01 E - ScannerThreadsVoluntaryContextSwitches: 34 (34)
15:56:01 E - TotalRawHdfsReadTime(*): 3.000ms
15:56:01 E - TotalReadThroughput: 0.00 /sec
15:56:01 E Filter 0 (1.00 MB):
15:56:01 E - Rows processed: 2.12K (2120)
15:56:01 E - Rows rejected: 2.12K (2120)
15:56:01 E - Rows total: 2.12K (2120)
15:56:01 E Averaged Fragment F01:(Total: 124.002ms, non-child: 19.000ms, % non-child: 15.32%)
15:56:01 E split sizes: min: 2.69 KB, max: 2.69 KB, avg: 2.69 KB, stddev: 0
15:56:01 E completion times: min:128.002ms max:128.002ms mean: 128.002ms stddev:0.000ns
15:56:01 E execution rates: min:20.98 KB/sec max:20.98 KB/sec mean:20.98 KB/sec stddev:0.00 /sec
15:56:01 E num instances: 1
15:56:01 E - AverageThreadTokens: 0.00
15:56:01 E - BloomFilterBytes: 0
15:56:01 E - PeakMemoryUsage: 264.28 KB (270624)
15:56:01 E - PerHostPeakMemUsage: 1.82 MB (1908032)
15:56:01 E - RowsProduced: 1 (1)
15:56:01 E - TotalNetworkReceiveTime: 0.000ns
15:56:01 E - TotalNetworkSendTime: 0.000ns
15:56:01 E - TotalStorageWaitTime: 0.000ns
15:56:01 E - TotalThreadsInvoluntaryContextSwitches: 71 (71)
15:56:01 E - TotalThreadsTotalWallClockTime: 68.001ms
15:56:01 E - TotalThreadsSysTime: 1.999ms
15:56:01 E - TotalThreadsUserTime: 57.992ms
15:56:01 E - TotalThreadsVoluntaryContextSwitches: 11 (11)
15:56:01 E Fragment Instance Lifecycle Timings:
15:56:01 E - ExecTime: 4.000ms
15:56:01 E - ExecTreeExecTime: 3.000ms
15:56:01 E - OpenTime: 61.001ms
15:56:01 E - ExecTreeOpenTime: 0.000ns
15:56:01 E - PrepareTime: 59.001ms
15:56:01 E - ExecTreePrepareTime: 0.000ns
15:56:01 E DataStreamSender (dst_id=5):
15:56:01 E - BytesSent: 25.00 B (25)
15:56:01 E - NetworkThroughput(*): 0.00 /sec
15:56:01 E - OverallThroughput: 0.00 /sec
15:56:01 E - PeakMemoryUsage: 22.28 KB (22816)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - SerializeBatchTime: 0.000ns
15:56:01 E - TransmitDataRPCTime: 0.000ns
15:56:01 E - UncompressedRowBatchSize: 30.00 B (30)
15:56:01 E CodeGen:(Total: 102.001ms, non-child: 102.001ms, % non-child: 100.00%)
15:56:01 E - CodegenTime: 2.000ms
15:56:01 E - CompileTime: 6.000ms
15:56:01 E - LoadTime: 0.000ns
15:56:01 E - ModuleBitcodeSize: 1.97 MB (2062036)
15:56:01 E - NumFunctions: 31 (31)
15:56:01 E - NumInstructions: 476 (476)
15:56:01 E - OptimizationTime: 53.000ms
15:56:01 E - PeakMemoryUsage: 238.00 KB (243712)
15:56:01 E - PrepareTime: 42.000ms
15:56:01 E HDFS_SCAN_NODE (id=1):(Total: 3.000ms, non-child: 3.000ms, % non-child: 100.00%)
15:56:01 E - AverageHdfsReadThreadConcurrency: 0.00
15:56:01 E - AverageScannerThreadConcurrency: 0.00
15:56:01 E - BytesRead: 2.81 KB (2880)
15:56:01 E - BytesReadDataNodeCache: 0
15:56:01 E - BytesReadLocal: 2.81 KB (2880)
15:56:01 E - BytesReadRemoteUnexpected: 0
15:56:01 E - BytesReadShortCircuit: 2.81 KB (2880)
15:56:01 E - CachedFileHandlesHitCount: 3 (3)
15:56:01 E - CachedFileHandlesMissCount: 0 (0)
15:56:01 E - DecompressionTime: 0.000ns
15:56:01 E - MaxCompressedTextFileLength: 0
15:56:01 E - NumColumns: 2 (2)
15:56:01 E - NumDictFilteredRowGroups: 0 (0)
15:56:01 E - NumDisksAccessed: 1 (1)
15:56:01 E - NumRowGroups: 1 (1)
15:56:01 E - NumScannerThreadsStarted: 1 (1)
15:56:01 E - NumScannersWithNoReads: 0 (0)
15:56:01 E - NumStatsFilteredRowGroups: 0 (0)
15:56:01 E - PeakMemoryUsage: 47.05 KB (48182)
15:56:01 E - PerReadThreadRawHdfsThroughput: 2.75 MB/sec
15:56:01 E - RemoteScanRanges: 0 (0)
15:56:01 E - RowBatchQueueGetWaitTime: 2.000ms
15:56:01 E - RowBatchQueuePutWaitTime: 0.000ns
15:56:01 E - RowsRead: 2 (2)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - RowsReturnedRate: 333.00 /sec
15:56:01 E - ScanRangesComplete: 1 (1)
15:56:01 E - ScannerThreadsInvoluntaryContextSwitches: 20 (20)
15:56:01 E - ScannerThreadsTotalWallClockTime: 3.000ms
15:56:01 E - MaterializeTupleTime(*): 0.000ns
15:56:01 E - ScannerThreadsSysTime: 999.000us
15:56:01 E - ScannerThreadsUserTime: 0.000ns
15:56:01 E - ScannerThreadsVoluntaryContextSwitches: 0 (0)
15:56:01 E - TotalRawHdfsReadTime(*): 1.000ms
15:56:01 E - TotalReadThroughput: 0.00 /sec
15:56:01 E Fragment F01:
15:56:01 E Instance 364e2b65ff166530:f9d9801200000004 (host=impala-boost-static-burst-slave-0e4c.vpc.cloudera.com:22000):(Total: 124.002ms, non-child: 19.000ms, % non-child: 15.32%)
15:56:01 E Hdfs split stats (<volume id>:<# splits>/<split lengths>): 2:1/2.69 KB
15:56:01 E - AverageThreadTokens: 0.00
15:56:01 E - BloomFilterBytes: 0
15:56:01 E - PeakMemoryUsage: 264.28 KB (270624)
15:56:01 E - PerHostPeakMemUsage: 1.82 MB (1908032)
15:56:01 E - RowsProduced: 1 (1)
15:56:01 E - TotalNetworkReceiveTime: 0.000ns
15:56:01 E - TotalNetworkSendTime: 0.000ns
15:56:01 E - TotalStorageWaitTime: 0.000ns
15:56:01 E - TotalThreadsInvoluntaryContextSwitches: 71 (71)
15:56:01 E - TotalThreadsTotalWallClockTime: 68.001ms
15:56:01 E - TotalThreadsSysTime: 1.999ms
15:56:01 E - TotalThreadsUserTime: 57.992ms
15:56:01 E - TotalThreadsVoluntaryContextSwitches: 11 (11)
15:56:01 E Fragment Instance Lifecycle Timings:
15:56:01 E - ExecTime: 4.000ms
15:56:01 E - ExecTreeExecTime: 3.000ms
15:56:01 E - OpenTime: 61.001ms
15:56:01 E - ExecTreeOpenTime: 0.000ns
15:56:01 E - PrepareTime: 59.001ms
15:56:01 E - ExecTreePrepareTime: 0.000ns
15:56:01 E DataStreamSender (dst_id=5):
15:56:01 E - BytesSent: 25.00 B (25)
15:56:01 E - NetworkThroughput(*): 0.00 /sec
15:56:01 E - OverallThroughput: 0.00 /sec
15:56:01 E - PeakMemoryUsage: 22.28 KB (22816)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - SerializeBatchTime: 0.000ns
15:56:01 E - TransmitDataRPCTime: 0.000ns
15:56:01 E - UncompressedRowBatchSize: 30.00 B (30)
15:56:01 E CodeGen:(Total: 102.001ms, non-child: 102.001ms, % non-child: 100.00%)
15:56:01 E - CodegenTime: 2.000ms
15:56:01 E - CompileTime: 6.000ms
15:56:01 E - LoadTime: 0.000ns
15:56:01 E - ModuleBitcodeSize: 1.97 MB (2062036)
15:56:01 E - NumFunctions: 31 (31)
15:56:01 E - NumInstructions: 476 (476)
15:56:01 E - OptimizationTime: 53.000ms
15:56:01 E - PeakMemoryUsage: 238.00 KB (243712)
15:56:01 E - PrepareTime: 42.000ms
15:56:01 E HDFS_SCAN_NODE (id=1):(Total: 3.000ms, non-child: 3.000ms, % non-child: 100.00%)
15:56:01 E Hdfs split stats (<volume id>:<# splits>/<split lengths>): 2:1/2.69 KB
15:56:01 E ExecOption: PARQUET Codegen Enabled, Codegen enabled: 1 out of 1
15:56:01 E Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0%
15:56:01 E File Formats: PARQUET/SNAPPY:2
15:56:01 E - FooterProcessingTime: (Avg: 0.000ns ; Min: 0.000ns ; Max: 0.000ns ; Number of samples: 1)
15:56:01 E - AverageHdfsReadThreadConcurrency: 0.00
15:56:01 E - AverageScannerThreadConcurrency: 0.00
15:56:01 E - BytesRead: 2.81 KB (2880)
15:56:01 E - BytesReadDataNodeCache: 0
15:56:01 E - BytesReadLocal: 2.81 KB (2880)
15:56:01 E - BytesReadRemoteUnexpected: 0
15:56:01 E - BytesReadShortCircuit: 2.81 KB (2880)
15:56:01 E - CachedFileHandlesHitCount: 3 (3)
15:56:01 E - CachedFileHandlesMissCount: 0 (0)
15:56:01 E - DecompressionTime: 0.000ns
15:56:01 E - MaxCompressedTextFileLength: 0
15:56:01 E - NumColumns: 2 (2)
15:56:01 E - NumDictFilteredRowGroups: 0 (0)
15:56:01 E - NumDisksAccessed: 1 (1)
15:56:01 E - NumRowGroups: 1 (1)
15:56:01 E - NumScannerThreadsStarted: 1 (1)
15:56:01 E - NumScannersWithNoReads: 0 (0)
15:56:01 E - NumStatsFilteredRowGroups: 0 (0)
15:56:01 E - PeakMemoryUsage: 47.05 KB (48182)
15:56:01 E - PerReadThreadRawHdfsThroughput: 2.75 MB/sec
15:56:01 E - RemoteScanRanges: 0 (0)
15:56:01 E - RowBatchQueueGetWaitTime: 2.000ms
15:56:01 E - RowBatchQueuePutWaitTime: 0.000ns
15:56:01 E - RowsRead: 2 (2)
15:56:01 E - RowsReturned: 1 (1)
15:56:01 E - RowsReturnedRate: 333.00 /sec
15:56:01 E - ScanRangesComplete: 1 (1)
15:56:01 E - ScannerThreadsInvoluntaryContextSwitches: 20 (20)
15:56:01 E - ScannerThreadsTotalWallClockTime: 3.000ms
15:56:01 E - MaterializeTupleTime(*): 0.000ns
15:56:01 E - ScannerThreadsSysTime: 999.000us
15:56:01 E - ScannerThreadsUserTime: 0.000ns
15:56:01 E - ScannerThreadsVoluntaryContextSwitches: 0 (0)
15:56:01 E - TotalRawHdfsReadTime(*): 1.000ms
15:56:01 E - TotalReadThroughput: 0.00 /sec
15:56:01 ----------------------------- Captured stderr call -----------------------------
15:56:01 -- executing against localhost:21000
15:56:01 use functional_parquet;
15:56:01
15:56:01 SET batch_size=0;
15:56:01 SET num_nodes=0;
15:56:01 SET disable_codegen_rows_threshold=0;
15:56:01 SET disable_codegen=False;
15:56:01 SET abort_on_error=1;
15:56:01 SET exec_single_node_rows_threshold=0;
15:56:01 -- executing against localhost:21000
15:56:01
15:56:01 SET RUNTIME_FILTER_WAIT_TIME_MS=30000;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01
15:56:01 SET RUNTIME_FILTER_MODE=OFF;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01
15:56:01 select STRAIGHT_JOIN count(*) from alltypes p join [BROADCAST] alltypestiny b
15:56:01 on p.id = b.id and b.month = 1 and b.string_col = "1";
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01 SET RUNTIME_FILTER_WAIT_TIME_MS=0;;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01 SET RUNTIME_FILTER_MODE=2;;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01 SET RUNTIME_FILTER_WAIT_TIME_MS=30000;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01
15:56:01 SET RUNTIME_FILTER_MODE=LOCAL;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01
15:56:01 select STRAIGHT_JOIN count(*) from alltypes p join [BROADCAST] alltypestiny b
15:56:01 on p.id = b.id and b.month = 1 and b.string_col = "1";
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01 SET RUNTIME_FILTER_WAIT_TIME_MS=0;;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01 SET RUNTIME_FILTER_MODE=2;;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01
15:56:01 SET RUNTIME_FILTER_WAIT_TIME_MS=30000;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01
15:56:01 SET RUNTIME_FILTER_MODE=LOCAL;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01
15:56:01 select STRAIGHT_JOIN count(*) from alltypes p join [SHUFFLE] alltypestiny b
15:56:01 on p.id = b.int_col and b.month = 1 and b.string_col = "1";
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01 SET RUNTIME_FILTER_WAIT_TIME_MS=0;;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01 SET RUNTIME_FILTER_MODE=2;;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01 SET RUNTIME_FILTER_WAIT_TIME_MS=30000;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01
15:56:01 SET RUNTIME_FILTER_MODE=GLOBAL;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01
15:56:01 select STRAIGHT_JOIN count(*) from alltypes p join [SHUFFLE] alltypestiny b
15:56:01 on p.id = b.int_col and b.month = 1 and b.string_col = "1";
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01 SET RUNTIME_FILTER_WAIT_TIME_MS=0;;
15:56:01
15:56:01 -- executing against localhost:21000
15:56:01 SET RUNTIME_FILTER_MODE=2;;
15:56:01
15:56:01 ===== 1 failed, 11027 passed, 187 skipped, 304 xfailed in 29479.09 seconds =====