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

test_kudu_insert.py fails intermittenly

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Minor
    • Resolution: Cannot Reproduce
    • Impala 2.9.0
    • Not Applicable
    • Backend

    Description

      Ran into the following failure when testing a private build. Cannot reproduce it locally and didn't see this in other Jenkins job either.

      The interesting thing is that the merged DML stats in the coordinator shows NumErrorRows being 0 while one of the fragment instance actually shows NumErrorRows being 1. This appears to be some of race between the update of the merged DML stats and the output of the query summary. Looking at the code, there is nothing obvious so far.

      13:56:13 =================================== FAILURES ===================================
      13:56:13  TestKuduOperations.test_kudu_insert[exec_option: {'disable_codegen': False, 'abort_on_error': 1, 'exec_single_node_rows_threshold': 0, 'batch_size': 0, 'num_nodes': 0} | table_format: text/none] 
      13:56:13 [gw0] linux2 -- Python 2.6.6 /data/jenkins/workspace/impala-private-build-and-test/repos/Impala/bin/../infra/python/env/bin/python
      13:56:13 query_test/test_kudu.py:81: in test_kudu_insert
      13:56:13     self.run_test_case('QueryTest/kudu_insert', vector, use_db=unique_database)
      13:56:13 common/impala_test_suite.py:430: in run_test_case
      13:56:13     verify_runtime_profile(test_section['RUNTIME_PROFILE'], result.runtime_profile)
      13:56:13 common/test_result_verifier.py:560: in verify_runtime_profile
      13:56:13     actual))
      13:56:13 E   AssertionError: Did not find matches for lines in runtime profile:
      13:56:13 E   EXPECTED LINES:
      13:56:13 E   NumRowErrors: 1
      13:56:13 E   
      13:56:13 E   ACTUAL PROFILE:
      13:56:13 E   Query (id=8a420519db860e0f:1c20406c00000000):
      13:56:13 E     DEBUG MODE WARNING: Query profile created while running a DEBUG build of Impala. Use RELEASE builds to measure query performance.
      13:56:13 E     Summary:
      13:56:13 E       Session ID: a642205b6c4e3d69:96958bb7a8132f86
      13:56:13 E       Session Type: BEESWAX
      13:56:13 E       Start Time: 2017-06-08 13:16:56.112700000
      13:56:13 E       End Time: 
      13:56:13 E       Query Type: DML
      13:56:13 E       Query State: FINISHED
      13:56:13 E       Query Status: OK
      13:56:13 E       Impala Version: impalad version 2.9.0-cdh5.12.0 DEBUG (build db076960b39d9782aa22c5526c5e4d2973617791)
      13:56:13 E       User: jenkins
      13:56:13 E       Connected User: jenkins
      13:56:13 E       Delegated User: 
      13:56:13 E       Network Address: 127.0.0.1:54020
      13:56:13 E       Default Db: test_kudu_insert_932f6329
      13:56:13 E       Sql Statement: insert into multiple_partition_cols select bigint_col, null, string_col
      13:56:13 E     from functional.alltypes where id = 1
      13:56:13 E       Coordinator: impala-boost-static-burst-slave-0224.vpc.cloudera.com:22000
      13:56:13 E       Query Options (non default): ABORT_ON_ERROR=1,EXEC_SINGLE_NODE_ROWS_THRESHOLD=0
      13:56:13 E       Plan: 
      13:56:13 E   ----------------
      13:56:13 E   Per-Host Resource Reservation: Memory=48.00MB
      13:56:13 E   Per-Host Resource Estimates: Memory=144.00MB
      13:56:13 E   
      13:56:13 E   F01:PLAN FRAGMENT [KUDU(KuduPartition(bigint_col, NULL))] hosts=3 instances=3
      13:56:13 E   INSERT INTO KUDU [test_kudu_insert_932f6329.multiple_partition_cols]
      13:56:13 E   |  mem-estimate=0B mem-reservation=0B
      13:56:13 E   |
      13:56:13 E   02:SORT
      13:56:13 E   |  order by: KuduPartition(bigint_col, NULL) ASC NULLS LAST, bigint_col ASC NULLS LAST
      13:56:13 E   |  materialized: KuduPartition(bigint_col, NULL)
      13:56:13 E   |  mem-estimate=16.00MB mem-reservation=48.00MB
      13:56:13 E   |  tuple-ids=1 row-size=29B cardinality=1
      13:56:13 E   |
      13:56:13 E   01:EXCHANGE [KUDU(KuduPartition(bigint_col, NULL))]
      13:56:13 E   |  mem-estimate=0B mem-reservation=0B
      13:56:13 E   |  tuple-ids=0 row-size=29B cardinality=1
      13:56:13 E   |
      13:56:13 E   F00:PLAN FRAGMENT [RANDOM] hosts=3 instances=3
      13:56:13 E   00:SCAN HDFS [functional.alltypes, RANDOM]
      13:56:13 E      partitions=24/24 files=24 size=478.45KB
      13:56:13 E      predicates: id = 1
      13:56:13 E      table stats: 7300 rows total
      13:56:13 E      column stats: all
      13:56:13 E      parquet dictionary predicates: id = 1
      13:56:13 E      mem-estimate=128.00MB mem-reservation=0B
      13:56:13 E      tuple-ids=0 row-size=29B cardinality=1
      13:56:13 E   ----------------
      13:56:13 E       Estimated Per-Host Mem: 150994944
      13:56:13 E       Per-Host Memory Reservation: 50331648
      13:56:13 E       Request Pool: default-pool
      13:56:13 E       Admission result: Admitted immediately
      13:56:13 E       Planner Timeline: 7.053ms
      13:56:13 E          - Analysis finished: 1.614ms (1.614ms)
      13:56:13 E          - Equivalence classes computed: 1.719ms (105.247us)
      13:56:13 E          - Single node plan created: 5.177ms (3.458ms)
      13:56:13 E          - Runtime filters computed: 5.239ms (61.943us)
      13:56:13 E          - Distributed plan created: 5.645ms (405.986us)
      13:56:13 E          - Planning finished: 7.053ms (1.407ms)
      13:56:13 E       Query Timeline: 440.988ms
      13:56:13 E          - Query submitted: 0.000ns (0.000ns)
      13:56:13 E          - Planning finished: 10.999ms (10.999ms)
      13:56:13 E          - Submit for admission: 14.999ms (3.999ms)
      13:56:13 E          - Completed admission: 14.999ms (0.000ns)
      13:56:13 E          - Ready to start on 3 backends: 18.999ms (3.999ms)
      13:56:13 E          - All 3 execution backends (6 fragment instances) started: 28.999ms (9.999ms)
      13:56:13 E          - DML data written: 392.989ms (363.990ms)
      13:56:13 E          - DML Metastore update finished: 393.989ms (999.974us)
      13:56:13 E          - Request finished: 393.989ms (0.000ns)
      13:56:13 E        - ComputeScanRangeAssignmentTimer: 1.999ms
      13:56:13 E     ImpalaServer:
      13:56:13 E        - ClientFetchWaitTimer: 0.000ns
      13:56:13 E        - MetastoreUpdateTimer: 999.974us
      13:56:13 E        - RowMaterializationTimer: 0.000ns
      13:56:13 E     Execution Profile 8a420519db860e0f:1c20406c00000000:(Total: 371.990ms, non-child: 0.000ns, % non-child: 0.00%)
      13:56:13 E       Number of filters: 0
      13:56:13 E       Filter routing table: 
      13:56:13 E    ID  Src. Node  Tgt. Node(s)  Target type  Partition filter  Pending (Expected)  First arrived  Completed   Enabled
      13:56:13 E   -------------------------------------------------------------------------------------------------------------------
      13:56:13 E   
      13:56:13 E       Backend startup latencies: Count: 3, min / max: 4ms / 9ms, 25th %-ile: 4ms, 50th %-ile: 6ms, 75th %-ile: 6ms, 90th %-ile: 9ms, 95th %-ile: 9ms, 99.9th %-ile: 9ms
      13:56:13 E       DML Stats: 
      13:56:13 E   Partition: Default
      13:56:13 E   NumModifiedRows: 0
      13:56:13 E   NumRowErrors: 0
      13:56:13 E     BytesWritten: 0
      13:56:13 E       Per Node Peak Memory Usage: impala-boost-static-burst-slave-0224.vpc.cloudera.com:22000(44.02 MB) impala-boost-static-burst-slave-0224.vpc.cloudera.com:22001(44.02 MB) impala-boost-static-burst-slave-0224.vpc.cloudera.com:22002(44.05 MB) 
      13:56:13 E        - FiltersReceived: 0 (0)
      13:56:13 E        - FinalizationTimer: 0.000ns
      13:56:13 E       Averaged Fragment F01:(Total: 353.990ms, non-child: 9.999ms, % non-child: 2.82%)
      13:56:13 E         split sizes:  min: 0, max: 0, avg: 0, stddev: 0
      13:56:13 E         completion times: min:359.990ms  max:364.990ms  mean: 362.323ms  stddev:2.054ms
      13:56:13 E         execution rates: min:0.00 /sec  max:0.00 /sec  mean:0.00 /sec  stddev:0.00 /sec
      13:56:13 E         num instances: 3
      13:56:13 E          - AverageThreadTokens: 1.00 
      13:56:13 E          - BloomFilterBytes: 0
      13:56:13 E          - PeakMemoryUsage: 33.35 MB (34969471)
      13:56:13 E          - PerHostPeakMemUsage: 44.03 MB (46165053)
      13:56:13 E          - RowsProduced: 0 (0)
      13:56:13 E          - TotalNetworkReceiveTime: 164.995ms
      13:56:13 E          - TotalNetworkSendTime: 0.000ns
      13:56:13 E          - TotalStorageWaitTime: 0.000ns
      13:56:13 E          - TotalThreadsInvoluntaryContextSwitches: 95 (95)
      13:56:13 E          - TotalThreadsTotalWallClockTime: 278.992ms
      13:56:13 E            - TotalThreadsSysTime: 1.666ms
      13:56:13 E            - TotalThreadsUserTime: 84.320ms
      13:56:13 E          - TotalThreadsVoluntaryContextSwitches: 4 (4)
      13:56:13 E         Fragment Instance Lifecycle Timings:
      13:56:13 E            - ExecTime: 0.000ns
      13:56:13 E              - ExecTreeExecTime: 0.000ns
      13:56:13 E            - OpenTime: 278.992ms
      13:56:13 E              - ExecTreeOpenTime: 164.995ms
      13:56:13 E            - PrepareTime: 74.998ms
      13:56:13 E              - ExecTreePrepareTime: 1.666ms
      13:56:13 E         BlockMgr:
      13:56:13 E            - BlockWritesOutstanding: 0 (0)
      13:56:13 E            - BlocksCreated: 3 (3)
      13:56:13 E            - BlocksRecycled: 0 (0)
      13:56:13 E            - BufferedPins: 0 (0)
      13:56:13 E            - MaxBlockSize: 8.00 MB (8388608)
      13:56:13 E            - MemoryLimit: 14.31 GB (15365329920)
      13:56:13 E            - PeakMemoryUsage: 24.00 MB (25165824)
      13:56:13 E            - ScratchBytesRead: 0
      13:56:13 E            - ScratchBytesWritten: 0
      13:56:13 E            - ScratchFileUsedBytes: 0
      13:56:13 E            - ScratchReads: 0 (0)
      13:56:13 E            - ScratchWrites: 0 (0)
      13:56:13 E            - TotalBufferWaitTime: 0.000ns
      13:56:13 E            - TotalEncryptionTime: 0.000ns
      13:56:13 E            - TotalReadBlockTime: 0.000ns
      13:56:13 E         KuduTableSink:
      13:56:13 E            - KuduApplyTimer: 0.000ns
      13:56:13 E            - NumRowErrors: 0 (0)
      13:56:13 E            - PeakMemoryUsage: 20.00 MB (20971520)
      13:56:13 E            - RowsProcessedRate: 0
      13:56:13 E            - TotalNumRows: 0 (0)
      13:56:13 E         CodeGen:(Total: 177.328ms, non-child: 177.328ms, % non-child: 100.00%)
      13:56:13 E            - CodegenTime: 3.999ms
      13:56:13 E            - CompileTime: 3.333ms
      13:56:13 E            - LoadTime: 0.000ns
      13:56:13 E            - ModuleBitcodeSize: 1.98 MB (2077440)
      13:56:13 E            - NumFunctions: 28 (28)
      13:56:13 E            - NumInstructions: 541 (541)
      13:56:13 E            - OptimizationTime: 106.997ms
      13:56:13 E            - PeakMemoryUsage: 270.50 KB (276992)
      13:56:13 E            - PrepareTime: 66.331ms
      13:56:13 E         SORT_NODE (id=2):(Total: 166.662ms, non-child: 1.666ms, % non-child: 1.00%)
      13:56:13 E            - InMemorySortTime: 0.000ns
      13:56:13 E            - InitialRunsCreated: 1 (1)
      13:56:13 E            - PeakMemoryUsage: 24.01 MB (25178112)
      13:56:13 E            - RowsReturned: 0 (0)
      13:56:13 E            - RowsReturnedRate: 1.00 /sec
      13:56:13 E            - SortDataSize: 10.00 B (10)
      13:56:13 E            - SpilledRuns: 0 (0)
      13:56:13 E            - TotalMergesPerformed: 0 (0)
      13:56:13 E         EXCHANGE_NODE (id=1):(Total: 164.995ms, non-child: 164.995ms, % non-child: 100.00%)
      13:56:13 E            - BytesReceived: 9.00 B (9)
      13:56:13 E            - ConvertRowBatchTime: 0.000ns
      13:56:13 E            - DeserializeRowBatchTimer: 0.000ns
      13:56:13 E            - FirstBatchArrivalWaitTime: 142.662ms
      13:56:13 E            - PeakMemoryUsage: 0
      13:56:13 E            - RowsReturned: 0 (0)
      13:56:13 E            - RowsReturnedRate: 1.00 /sec
      13:56:13 E            - SendersBlockedTimer: 0.000ns
      13:56:13 E            - SendersBlockedTotalTimer(*): 0.000ns
      13:56:13 E       Fragment F01:
      13:56:13 E         Instance 8a420519db860e0f:1c20406c00000005 (host=impala-boost-static-burst-slave-0224.vpc.cloudera.com:22000):(Total: 363.990ms, non-child: 11.999ms, % non-child: 3.30%)
      13:56:13 E           MemoryUsage(500.000ms): 24.01 MB
      13:56:13 E           ThreadUsage(500.000ms): 1
      13:56:13 E            - AverageThreadTokens: 1.00 
      13:56:13 E            - BloomFilterBytes: 0
      13:56:13 E            - PeakMemoryUsage: 28.02 MB (29377066)
      13:56:13 E            - PerHostPeakMemUsage: 44.02 MB (46154282)
      13:56:13 E            - RowsProduced: 0 (0)
      13:56:13 E            - TotalNetworkReceiveTime: 134.996ms
      13:56:13 E            - TotalNetworkSendTime: 0.000ns
      13:56:13 E            - TotalStorageWaitTime: 0.000ns
      13:56:13 E            - TotalThreadsInvoluntaryContextSwitches: 103 (103)
      13:56:13 E            - TotalThreadsTotalWallClockTime: 268.992ms
      13:56:13 E              - TotalThreadsSysTime: 0.000ns
      13:56:13 E              - TotalThreadsUserTime: 113.983ms
      13:56:13 E            - TotalThreadsVoluntaryContextSwitches: 4 (4)
      13:56:13 E           Fragment Instance Lifecycle Timings:
      13:56:13 E              - ExecTime: 0.000ns
      13:56:13 E                - ExecTreeExecTime: 0.000ns
      13:56:13 E              - OpenTime: 268.992ms
      13:56:13 E                - ExecTreeOpenTime: 134.996ms
      13:56:13 E              - PrepareTime: 94.997ms
      13:56:13 E                - ExecTreePrepareTime: 1.999ms
      13:56:13 E           BlockMgr:
      13:56:13 E              - BlockWritesOutstanding: 0 (0)
      13:56:13 E              - BlocksCreated: 3 (3)
      13:56:13 E              - BlocksRecycled: 0 (0)
      13:56:13 E              - BufferedPins: 0 (0)
      13:56:13 E              - MaxBlockSize: 8.00 MB (8388608)
      13:56:13 E              - MemoryLimit: 14.31 GB (15365329920)
      13:56:13 E              - PeakMemoryUsage: 24.00 MB (25165824)
      13:56:13 E              - ScratchBytesRead: 0
      13:56:13 E              - ScratchBytesWritten: 0
      13:56:13 E              - ScratchFileUsedBytes: 0
      13:56:13 E              - ScratchReads: 0 (0)
      13:56:13 E              - ScratchWrites: 0 (0)
      13:56:13 E              - TotalBufferWaitTime: 0.000ns
      13:56:13 E              - TotalEncryptionTime: 0.000ns
      13:56:13 E              - TotalReadBlockTime: 0.000ns
      13:56:13 E           KuduTableSink:
      13:56:13 E              - KuduApplyTimer: 0.000ns
      13:56:13 E              - NumRowErrors: 0 (0)
      13:56:13 E              - PeakMemoryUsage: 20.00 MB (20971520)
      13:56:13 E              - RowsProcessedRate: 0
      13:56:13 E              - TotalNumRows: 0 (0)
      13:56:13 E           CodeGen:(Total: 214.994ms, non-child: 214.994ms, % non-child: 100.00%)
      13:56:13 E              - CodegenTime: 9.999ms
      13:56:13 E              - CompileTime: 3.999ms
      13:56:13 E              - LoadTime: 0.000ns
      13:56:13 E              - ModuleBitcodeSize: 1.98 MB (2077440)
      13:56:13 E              - NumFunctions: 28 (28)
      13:56:13 E              - NumInstructions: 541 (541)
      13:56:13 E              - OptimizationTime: 124.996ms
      13:56:13 E              - PeakMemoryUsage: 270.50 KB (276992)
      13:56:13 E              - PrepareTime: 84.997ms
      13:56:13 E           SORT_NODE (id=2):(Total: 136.996ms, non-child: 1.999ms, % non-child: 1.46%)
      13:56:13 E             ExecOption: Codegen Enabled
      13:56:13 E              - InMemorySortTime: 0.000ns
      13:56:13 E              - InitialRunsCreated: 1 (1)
      13:56:13 E              - PeakMemoryUsage: 24.01 MB (25174016)
      13:56:13 E              - RowsReturned: 0 (0)
      13:56:13 E              - RowsReturnedRate: 0
      13:56:13 E              - SortDataSize: 0
      13:56:13 E              - SpilledRuns: 0 (0)
      13:56:13 E              - TotalMergesPerformed: 0 (0)
      13:56:13 E           EXCHANGE_NODE (id=1):(Total: 134.996ms, non-child: 0.000ns, % non-child: 0.00%)
      13:56:13 E             BytesReceived(500.000ms): 0
      13:56:13 E              - BytesReceived: 0
      13:56:13 E              - ConvertRowBatchTime: 0.000ns
      13:56:13 E              - DeserializeRowBatchTimer: 0.000ns
      13:56:13 E              - FirstBatchArrivalWaitTime: 134.996ms
      13:56:13 E              - PeakMemoryUsage: 0
      13:56:13 E              - RowsReturned: 0 (0)
      13:56:13 E              - RowsReturnedRate: 0
      13:56:13 E              - SendersBlockedTimer: 0.000ns
      13:56:13 E              - SendersBlockedTotalTimer(*): 0.000ns
      13:56:13 E         Instance 8a420519db860e0f:1c20406c00000004 (host=impala-boost-static-burst-slave-0224.vpc.cloudera.com:22001):(Total: 349.990ms, non-child: 2.999ms, % non-child: 0.86%)
      13:56:13 E           MemoryUsage(500.000ms): 24.01 MB
      13:56:13 E           ThreadUsage(500.000ms): 1
      13:56:13 E            - AverageThreadTokens: 1.00 
      13:56:13 E            - BloomFilterBytes: 0
      13:56:13 E            - PeakMemoryUsage: 28.02 MB (29377066)
      13:56:13 E            - PerHostPeakMemUsage: 44.02 MB (46154282)
      13:56:13 E            - RowsProduced: 0 (0)
      13:56:13 E            - TotalNetworkReceiveTime: 169.995ms
      13:56:13 E            - TotalNetworkSendTime: 0.000ns
      13:56:13 E            - TotalStorageWaitTime: 0.000ns
      13:56:13 E            - TotalThreadsInvoluntaryContextSwitches: 79 (79)
      13:56:13 E            - TotalThreadsTotalWallClockTime: 286.992ms
      13:56:13 E              - TotalThreadsSysTime: 3.000ms
      13:56:13 E              - TotalThreadsUserTime: 70.990ms
      13:56:13 E            - TotalThreadsVoluntaryContextSwitches: 4 (4)
      13:56:13 E           Fragment Instance Lifecycle Timings:
      13:56:13 E              - ExecTime: 0.000ns
      13:56:13 E                - ExecTreeExecTime: 0.000ns
      13:56:13 E              - OpenTime: 286.992ms
      13:56:13 E                - ExecTreeOpenTime: 169.995ms
      13:56:13 E              - PrepareTime: 62.998ms
      13:56:13 E                - ExecTreePrepareTime: 1.999ms
      13:56:13 E           BlockMgr:
      13:56:13 E              - BlockWritesOutstanding: 0 (0)
      13:56:13 E              - BlocksCreated: 3 (3)
      13:56:13 E              - BlocksRecycled: 0 (0)
      13:56:13 E              - BufferedPins: 0 (0)
      13:56:13 E              - MaxBlockSize: 8.00 MB (8388608)
      13:56:13 E              - MemoryLimit: 14.31 GB (15365329920)
      13:56:13 E              - PeakMemoryUsage: 24.00 MB (25165824)
      13:56:13 E              - ScratchBytesRead: 0
      13:56:13 E              - ScratchBytesWritten: 0
      13:56:13 E              - ScratchFileUsedBytes: 0
      13:56:13 E              - ScratchReads: 0 (0)
      13:56:13 E              - ScratchWrites: 0 (0)
      13:56:13 E              - TotalBufferWaitTime: 0.000ns
      13:56:13 E              - TotalEncryptionTime: 0.000ns
      13:56:13 E              - TotalReadBlockTime: 0.000ns
      13:56:13 E           KuduTableSink:
      13:56:13 E              - KuduApplyTimer: 0.000ns
      13:56:13 E              - NumRowErrors: 0 (0)
      13:56:13 E              - PeakMemoryUsage: 20.00 MB (20971520)
      13:56:13 E              - RowsProcessedRate: 0
      13:56:13 E              - TotalNumRows: 0 (0)
      13:56:13 E           CodeGen:(Total: 174.995ms, non-child: 174.995ms, % non-child: 100.00%)
      13:56:13 E              - CodegenTime: 999.974us
      13:56:13 E              - CompileTime: 2.999ms
      13:56:13 E              - LoadTime: 0.000ns
      13:56:13 E              - ModuleBitcodeSize: 1.98 MB (2077440)
      13:56:13 E              - NumFunctions: 28 (28)
      13:56:13 E              - NumInstructions: 541 (541)
      13:56:13 E              - OptimizationTime: 110.997ms
      13:56:13 E              - PeakMemoryUsage: 270.50 KB (276992)
      13:56:13 E              - PrepareTime: 59.998ms
      13:56:13 E           SORT_NODE (id=2):(Total: 171.995ms, non-child: 1.999ms, % non-child: 1.16%)
      13:56:13 E             ExecOption: Codegen Enabled
      13:56:13 E              - InMemorySortTime: 0.000ns
      13:56:13 E              - InitialRunsCreated: 1 (1)
      13:56:13 E              - PeakMemoryUsage: 24.01 MB (25174016)
      13:56:13 E              - RowsReturned: 0 (0)
      13:56:13 E              - RowsReturnedRate: 0
      13:56:13 E              - SortDataSize: 0
      13:56:13 E              - SpilledRuns: 0 (0)
      13:56:13 E              - TotalMergesPerformed: 0 (0)
      13:56:13 E           EXCHANGE_NODE (id=1):(Total: 169.995ms, non-child: 0.000ns, % non-child: 0.00%)
      13:56:13 E             BytesReceived(500.000ms): 0
      13:56:13 E              - BytesReceived: 0
      13:56:13 E              - ConvertRowBatchTime: 0.000ns
      13:56:13 E              - DeserializeRowBatchTimer: 0.000ns
      13:56:13 E              - FirstBatchArrivalWaitTime: 169.995ms
      13:56:13 E              - PeakMemoryUsage: 0
      13:56:13 E              - RowsReturned: 0 (0)
      13:56:13 E              - RowsReturnedRate: 0
      13:56:13 E              - SendersBlockedTimer: 0.000ns
      13:56:13 E              - SendersBlockedTotalTimer(*): 0.000ns
      13:56:13 E         Instance 8a420519db860e0f:1c20406c00000003 (host=impala-boost-static-burst-slave-0224.vpc.cloudera.com:22002):(Total: 347.990ms, non-child: 14.999ms, % non-child: 4.31%)
      13:56:13 E           MemoryUsage(500.000ms): 24.02 MB
      13:56:13 E           ThreadUsage(500.000ms): 1
      13:56:13 E            - AverageThreadTokens: 1.00 
      13:56:13 E            - BloomFilterBytes: 0
      13:56:13 E            - PeakMemoryUsage: 44.02 MB (46154282)
      13:56:13 E            - PerHostPeakMemUsage: 44.05 MB (46186595)
      13:56:13 E            - RowsProduced: 1 (1)
      13:56:13 E            - TotalNetworkReceiveTime: 189.995ms
      13:56:13 E            - TotalNetworkSendTime: 0.000ns
      13:56:13 E            - TotalStorageWaitTime: 0.000ns
      13:56:13 E            - TotalThreadsInvoluntaryContextSwitches: 104 (104)
      13:56:13 E            - TotalThreadsTotalWallClockTime: 280.992ms
      13:56:13 E              - TotalThreadsSysTime: 2.000ms
      13:56:13 E              - TotalThreadsUserTime: 67.989ms
      13:56:13 E            - TotalThreadsVoluntaryContextSwitches: 4 (4)
      13:56:13 E           Fragment Instance Lifecycle Timings:
      13:56:13 E              - ExecTime: 0.000ns
      13:56:13 E                - ExecTreeExecTime: 0.000ns
      13:56:13 E              - OpenTime: 280.992ms
      13:56:13 E                - ExecTreeOpenTime: 189.995ms
      13:56:13 E              - PrepareTime: 66.998ms
      13:56:13 E                - ExecTreePrepareTime: 999.974us
      13:56:13 E           BlockMgr:
      13:56:13 E              - BlockWritesOutstanding: 0 (0)
      13:56:13 E              - BlocksCreated: 3 (3)
      13:56:13 E              - BlocksRecycled: 0 (0)
      13:56:13 E              - BufferedPins: 0 (0)
      13:56:13 E              - MaxBlockSize: 8.00 MB (8388608)
      13:56:13 E              - MemoryLimit: 14.31 GB (15365329920)
      13:56:13 E              - PeakMemoryUsage: 24.00 MB (25165824)
      13:56:13 E              - ScratchBytesRead: 0
      13:56:13 E              - ScratchBytesWritten: 0
      13:56:13 E              - ScratchFileUsedBytes: 0
      13:56:13 E              - ScratchReads: 0 (0)
      13:56:13 E              - ScratchWrites: 0 (0)
      13:56:13 E              - TotalBufferWaitTime: 0.000ns
      13:56:13 E              - TotalEncryptionTime: 0.000ns
      13:56:13 E              - TotalReadBlockTime: 0.000ns
      13:56:13 E           KuduTableSink:
      13:56:13 E              - KuduApplyTimer: 0.000ns
      13:56:13 E              - NumRowErrors: 1 (1)
      13:56:13 E              - PeakMemoryUsage: 20.00 MB (20971520)
      13:56:13 E              - RowsProcessedRate: 0
      13:56:13 E              - TotalNumRows: 1 (1)
      13:56:13 E           CodeGen:(Total: 141.996ms, non-child: 141.996ms, % non-child: 100.00%)
      13:56:13 E              - CodegenTime: 999.973us
      13:56:13 E              - CompileTime: 2.999ms
      13:56:13 E              - LoadTime: 0.000ns
      13:56:13 E              - ModuleBitcodeSize: 1.98 MB (2077440)
      13:56:13 E              - NumFunctions: 28 (28)
      13:56:13 E              - NumInstructions: 541 (541)
      13:56:13 E              - OptimizationTime: 84.997ms
      13:56:13 E              - PeakMemoryUsage: 270.50 KB (276992)
      13:56:13 E              - PrepareTime: 53.998ms
      13:56:13 E           SORT_NODE (id=2):(Total: 190.995ms, non-child: 999.974us, % non-child: 0.52%)
      13:56:13 E             ExecOption: Codegen Enabled
      13:56:13 E              - InMemorySortTime: 0.000ns
      13:56:13 E              - InitialRunsCreated: 1 (1)
      13:56:13 E              - PeakMemoryUsage: 24.02 MB (25186304)
      13:56:13 E              - RowsReturned: 1 (1)
      13:56:13 E              - RowsReturnedRate: 5.00 /sec
      13:56:13 E              - SortDataSize: 30.00 B (30)
      13:56:13 E              - SpilledRuns: 0 (0)
      13:56:13 E              - TotalMergesPerformed: 0 (0)
      13:56:13 E           EXCHANGE_NODE (id=1):(Total: 189.995ms, non-child: 0.000ns, % non-child: 0.00%)
      13:56:13 E             BytesReceived(500.000ms): 29.00 B
      13:56:13 E              - BytesReceived: 29.00 B (29)
      13:56:13 E              - ConvertRowBatchTime: 0.000ns
      13:56:13 E              - DeserializeRowBatchTimer: 0.000ns
      13:56:13 E              - FirstBatchArrivalWaitTime: 122.996ms
      13:56:13 E              - PeakMemoryUsage: 0
      13:56:13 E              - RowsReturned: 1 (1)
      13:56:13 E              - RowsReturnedRate: 5.00 /sec
      13:56:13 E              - SendersBlockedTimer: 0.000ns
      13:56:13 E              - SendersBlockedTotalTimer(*): 0.000ns
      13:56:13 E       Averaged Fragment F00:(Total: 297.992ms, non-child: 22.999ms, % non-child: 7.72%)
      13:56:13 E         split sizes:  min: 158.70 KB, max: 160.53 KB, avg: 159.48 KB, stddev: 788.98 B
      13:56:13 E         completion times: min:280.992ms  max:362.990ms  mean: 314.658ms  stddev:35.045ms
      13:56:13 E         execution rates: min:438.65 KB/sec  max:564.77 KB/sec  mean:512.84 KB/sec  stddev:53.84 KB/sec
      13:56:13 E         num instances: 3
      13:56:13 E          - AverageThreadTokens: 2.33 
      13:56:13 E          - BloomFilterBytes: 0
      13:56:13 E          - PeakMemoryUsage: 536.89 KB (549774)
      13:56:13 E          - PerHostPeakMemUsage: 31.08 MB (32591671)
      13:56:13 E          - RowsProduced: 0 (0)
      13:56:13 E          - TotalNetworkReceiveTime: 0.000ns
      13:56:13 E          - TotalNetworkSendTime: 0.000ns
      13:56:13 E          - TotalStorageWaitTime: 24.332ms
      13:56:13 E          - TotalThreadsInvoluntaryContextSwitches: 211 (211)
      13:56:13 E          - TotalThreadsTotalWallClockTime: 270.659ms
      13:56:13 E            - TotalThreadsSysTime: 2.000ms
      13:56:13 E            - TotalThreadsUserTime: 160.973ms
      13:56:13 E          - TotalThreadsVoluntaryContextSwitches: 47 (47)
      13:56:13 E         Fragment Instance Lifecycle Timings:
      13:56:13 E            - ExecTime: 21.332ms
      13:56:13 E              - ExecTreeExecTime: 19.666ms
      13:56:13 E            - OpenTime: 189.661ms
      13:56:13 E              - ExecTreeOpenTime: 0.000ns
      13:56:13 E            - PrepareTime: 86.997ms
      13:56:13 E              - ExecTreePrepareTime: 3.333ms
      13:56:13 E         DataStreamSender (dst_id=1):(Total: 999.974us, non-child: 999.974us, % non-child: 100.00%)
      13:56:13 E            - BytesSent: 9.00 B (9)
      13:56:13 E            - NetworkThroughput(*): 0.00 /sec
      13:56:13 E            - OverallThroughput: 9.44 KB/sec
      13:56:13 E            - PeakMemoryUsage: 14.55 KB (14901)
      13:56:13 E            - RowsReturned: 0 (0)
      13:56:13 E            - SerializeBatchTime: 0.000ns
      13:56:13 E            - TransmitDataRPCTime: 0.000ns
      13:56:13 E            - UncompressedRowBatchSize: 12.00 B (12)
      13:56:13 E         CodeGen:(Total: 244.660ms, non-child: 244.660ms, % non-child: 100.00%)
      13:56:13 E            - CodegenTime: 4.999ms
      13:56:13 E            - CompileTime: 15.666ms
      13:56:13 E            - LoadTime: 0.000ns
      13:56:13 E            - ModuleBitcodeSize: 1.98 MB (2077440)
      13:56:13 E            - NumFunctions: 27 (27)
      13:56:13 E            - NumInstructions: 591 (591)
      13:56:13 E            - OptimizationTime: 171.995ms
      13:56:13 E            - PeakMemoryUsage: 295.50 KB (302592)
      13:56:13 E            - PrepareTime: 56.665ms
      13:56:13 E         HDFS_SCAN_NODE (id=0):(Total: 29.332ms, non-child: 29.332ms, % non-child: 100.00%)
      13:56:13 E            - AverageHdfsReadThreadConcurrency: 0.00 
      13:56:13 E            - AverageScannerThreadConcurrency: 1.33 
      13:56:13 E            - BytesRead: 159.48 KB (163311)
      13:56:13 E            - BytesReadDataNodeCache: 0
      13:56:13 E            - BytesReadLocal: 159.48 KB (163311)
      13:56:13 E            - BytesReadRemoteUnexpected: 0
      13:56:13 E            - BytesReadShortCircuit: 159.48 KB (163311)
      13:56:13 E            - DecompressionTime: 0.000ns
      13:56:13 E            - MaxCompressedTextFileLength: 0
      13:56:13 E            - NumDisksAccessed: 2 (2)
      13:56:13 E            - NumScannerThreadsStarted: 6 (6)
      13:56:13 E            - PeakMemoryUsage: 509.33 KB (521557)
      13:56:13 E            - PerReadThreadRawHdfsThroughput: 0.00 /sec
      13:56:13 E            - RemoteScanRanges: 0 (0)
      13:56:13 E            - RowBatchQueueGetWaitTime: 6.999ms
      13:56:13 E            - RowBatchQueuePutWaitTime: 0.000ns
      13:56:13 E            - RowsRead: 2.43K (2433)
      13:56:13 E            - RowsReturned: 0 (0)
      13:56:13 E            - RowsReturnedRate: 19.00 /sec
      13:56:13 E            - ScanRangesComplete: 8 (8)
      13:56:13 E            - ScannerThreadsInvoluntaryContextSwitches: 6 (6)
      13:56:13 E            - ScannerThreadsTotalWallClockTime: 60.331ms
      13:56:13 E              - DelimiterParseTime: 3.333ms
      13:56:13 E              - MaterializeTupleTime(*): 1.333ms
      13:56:13 E              - ScannerThreadsSysTime: 0.000ns
      13:56:13 E              - ScannerThreadsUserTime: 2.664ms
      13:56:13 E            - ScannerThreadsVoluntaryContextSwitches: 27 (27)
      13:56:13 E            - TotalRawHdfsReadTime(*): 0.000ns
      13:56:13 E            - TotalReadThroughput: 92.22 KB/sec
      13:56:13 E       Fragment F00:
      13:56:13 E         Instance 8a420519db860e0f:1c20406c00000000 (host=impala-boost-static-burst-slave-0224.vpc.cloudera.com:22002):(Total: 338.991ms, non-child: 36.999ms, % non-child: 10.91%)
      13:56:13 E           Hdfs split stats (<volume id>:<# splits>/<split lengths>): 1:4/80.04 KB 2:4/79.18 KB 
      13:56:13 E           MemoryUsage(500.000ms): 21.22 KB
      13:56:13 E           ThreadUsage(500.000ms): 1
      13:56:13 E            - AverageThreadTokens: 1.00 
      13:56:13 E            - BloomFilterBytes: 0
      13:56:13 E            - PeakMemoryUsage: 404.56 KB (414265)
      13:56:13 E            - PerHostPeakMemUsage: 44.05 MB (46186595)
      13:56:13 E            - RowsProduced: 0 (0)
      13:56:13 E            - TotalNetworkReceiveTime: 0.000ns
      13:56:13 E            - TotalNetworkSendTime: 0.000ns
      13:56:13 E            - TotalStorageWaitTime: 13.999ms
      13:56:13 E            - TotalThreadsInvoluntaryContextSwitches: 254 (254)
      13:56:13 E            - TotalThreadsTotalWallClockTime: 304.992ms
      13:56:13 E              - TotalThreadsSysTime: 2.000ms
      13:56:13 E              - TotalThreadsUserTime: 166.972ms
      13:56:13 E            - TotalThreadsVoluntaryContextSwitches: 39 (39)
      13:56:13 E           Fragment Instance Lifecycle Timings:
      13:56:13 E              - ExecTime: 36.999ms
      13:56:13 E                - ExecTreeExecTime: 35.999ms
      13:56:13 E              - OpenTime: 199.994ms
      13:56:13 E                - ExecTreeOpenTime: 0.000ns
      13:56:13 E              - PrepareTime: 101.997ms
      13:56:13 E                - ExecTreePrepareTime: 999.974us
      13:56:13 E           DataStreamSender (dst_id=1):(Total: 999.974us, non-child: 999.974us, % non-child: 100.00%)
      13:56:13 E              - BytesSent: 0
      13:56:13 E              - NetworkThroughput(*): 0.00 /sec
      13:56:13 E              - OverallThroughput: 0.00 /sec
      13:56:13 E              - PeakMemoryUsage: 13.22 KB (13536)
      13:56:13 E              - RowsReturned: 0 (0)
      13:56:13 E              - SerializeBatchTime: 0.000ns
      13:56:13 E              - TransmitDataRPCTime: 0.000ns
      13:56:13 E              - UncompressedRowBatchSize: 0
      13:56:13 E           CodeGen:(Total: 262.993ms, non-child: 262.993ms, % non-child: 100.00%)
      13:56:13 E              - CodegenTime: 6.999ms
      13:56:13 E              - CompileTime: 18.999ms
      13:56:13 E              - LoadTime: 0.000ns
      13:56:13 E              - ModuleBitcodeSize: 1.98 MB (2077440)
      13:56:13 E              - NumFunctions: 27 (27)
      13:56:13 E              - NumInstructions: 591 (591)
      13:56:13 E              - OptimizationTime: 178.995ms
      13:56:13 E              - PeakMemoryUsage: 295.50 KB (302592)
      13:56:13 E              - PrepareTime: 64.998ms
      13:56:13 E           HDFS_SCAN_NODE (id=0):(Total: 37.999ms, non-child: 37.999ms, % non-child: 100.00%)
      13:56:13 E             Hdfs split stats (<volume id>:<# splits>/<split lengths>): 1:4/80.04 KB 2:4/79.18 KB 
      13:56:13 E             ExecOption: TEXT Codegen Enabled, Codegen enabled: 0 out of 8
      13:56:13 E             Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0% 
      13:56:13 E             File Formats: TEXT/NONE:8 
      13:56:13 E             BytesRead(500.000ms): 0
      13:56:13 E              - AverageHdfsReadThreadConcurrency: 0.00 
      13:56:13 E              - AverageScannerThreadConcurrency: 0.00 
      13:56:13 E              - BytesRead: 159.23 KB (163048)
      13:56:13 E              - BytesReadDataNodeCache: 0
      13:56:13 E              - BytesReadLocal: 159.23 KB (163048)
      13:56:13 E              - BytesReadRemoteUnexpected: 0
      13:56:13 E              - BytesReadShortCircuit: 159.23 KB (163048)
      13:56:13 E              - DecompressionTime: 0.000ns
      13:56:13 E              - MaxCompressedTextFileLength: 0
      13:56:13 E              - NumDisksAccessed: 2 (2)
      13:56:13 E              - NumScannerThreadsStarted: 4 (4)
      13:56:13 E              - PeakMemoryUsage: 377.00 KB (386048)
      13:56:13 E              - PerReadThreadRawHdfsThroughput: 0.00 /sec
      13:56:13 E              - RemoteScanRanges: 0 (0)
      13:56:13 E              - RowBatchQueueGetWaitTime: 4.999ms
      13:56:13 E              - RowBatchQueuePutWaitTime: 0.000ns
      13:56:13 E              - RowsRead: 2.43K (2430)
      13:56:13 E              - RowsReturned: 0 (0)
      13:56:13 E              - RowsReturnedRate: 0
      13:56:13 E              - ScanRangesComplete: 8 (8)
      13:56:13 E              - ScannerThreadsInvoluntaryContextSwitches: 8 (8)
      13:56:13 E              - ScannerThreadsTotalWallClockTime: 67.998ms
      13:56:13 E                - DelimiterParseTime: 999.974us
      13:56:13 E                - MaterializeTupleTime(*): 3.999ms
      13:56:13 E                - ScannerThreadsSysTime: 0.000ns
      13:56:13 E                - ScannerThreadsUserTime: 3.997ms
      13:56:13 E              - ScannerThreadsVoluntaryContextSwitches: 23 (23)
      13:56:13 E              - TotalRawHdfsReadTime(*): 0.000ns
      13:56:13 E              - TotalReadThroughput: 0.00 /sec
      13:56:13 E         Instance 8a420519db860e0f:1c20406c00000002 (host=impala-boost-static-burst-slave-0224.vpc.cloudera.com:22000):(Total: 278.992ms, non-child: 5.999ms, % non-child: 2.15%)
      13:56:13 E           Hdfs split stats (<volume id>:<# splits>/<split lengths>): 2:1/20.36 KB 0:3/59.78 KB 1:4/78.55 KB 
      13:56:13 E           MemoryUsage(500.000ms): 323.56 KB
      13:56:13 E           ThreadUsage(500.000ms): 5
      13:56:13 E            - AverageThreadTokens: 5.00 
      13:56:13 E            - BloomFilterBytes: 0
      13:56:13 E            - PeakMemoryUsage: 582.56 KB (596537)
      13:56:13 E            - PerHostPeakMemUsage: 24.58 MB (25775328)
      13:56:13 E            - RowsProduced: 0 (0)
      13:56:13 E            - TotalNetworkReceiveTime: 0.000ns
      13:56:13 E            - TotalNetworkSendTime: 0.000ns
      13:56:13 E            - TotalStorageWaitTime: 14.999ms
      13:56:13 E            - TotalThreadsInvoluntaryContextSwitches: 134 (134)
      13:56:13 E            - TotalThreadsTotalWallClockTime: 211.994ms
      13:56:13 E              - TotalThreadsSysTime: 0.000ns
      13:56:13 E              - TotalThreadsUserTime: 152.976ms
      13:56:13 E            - TotalThreadsVoluntaryContextSwitches: 52 (52)
      13:56:13 E           Fragment Instance Lifecycle Timings:
      13:56:13 E              - ExecTime: 7.999ms
      13:56:13 E                - ExecTreeExecTime: 5.999ms
      13:56:13 E              - OpenTime: 168.995ms
      13:56:13 E                - ExecTreeOpenTime: 0.000ns
      13:56:13 E              - PrepareTime: 101.997ms
      13:56:13 E                - ExecTreePrepareTime: 8.999ms
      13:56:13 E           DataStreamSender (dst_id=1):(Total: 999.974us, non-child: 999.974us, % non-child: 100.00%)
      13:56:13 E              - BytesSent: 0
      13:56:13 E              - NetworkThroughput(*): 0.00 /sec
      13:56:13 E              - OverallThroughput: 0.00 /sec
      13:56:13 E              - PeakMemoryUsage: 13.22 KB (13536)
      13:56:13 E              - RowsReturned: 0 (0)
      13:56:13 E              - SerializeBatchTime: 0.000ns
      13:56:13 E              - TransmitDataRPCTime: 0.000ns
      13:56:13 E              - UncompressedRowBatchSize: 0
      13:56:13 E           CodeGen:(Total: 238.993ms, non-child: 238.993ms, % non-child: 100.00%)
      13:56:13 E              - CodegenTime: 2.999ms
      13:56:13 E              - CompileTime: 12.999ms
      13:56:13 E              - LoadTime: 0.000ns
      13:56:13 E              - ModuleBitcodeSize: 1.98 MB (2077440)
      13:56:13 E              - NumFunctions: 27 (27)
      13:56:13 E              - NumInstructions: 591 (591)
      13:56:13 E              - OptimizationTime: 153.995ms
      13:56:13 E              - PeakMemoryUsage: 295.50 KB (302592)
      13:56:13 E              - PrepareTime: 70.998ms
      13:56:13 E           HDFS_SCAN_NODE (id=0):(Total: 32.999ms, non-child: 32.999ms, % non-child: 100.00%)
      13:56:13 E             Hdfs split stats (<volume id>:<# splits>/<split lengths>): 2:1/20.36 KB 0:3/59.78 KB 1:4/78.55 KB 
      13:56:13 E             ExecOption: TEXT Codegen Enabled, Codegen enabled: 0 out of 8
      13:56:13 E             Hdfs Read Thread Concurrency Bucket: 0:100% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0% 
      13:56:13 E             File Formats: TEXT/NONE:8 
      13:56:13 E             BytesRead(500.000ms): 138.33 KB
      13:56:13 E              - AverageHdfsReadThreadConcurrency: 0.00 
      13:56:13 E              - AverageScannerThreadConcurrency: 4.00 
      13:56:13 E              - BytesRead: 158.70 KB (162504)
      13:56:13 E              - BytesReadDataNodeCache: 0
      13:56:13 E              - BytesReadLocal: 158.70 KB (162504)
      13:56:13 E              - BytesReadRemoteUnexpected: 0
      13:56:13 E              - BytesReadShortCircuit: 158.70 KB (162504)
      13:56:13 E              - DecompressionTime: 0.000ns
      13:56:13 E              - MaxCompressedTextFileLength: 0
      13:56:13 E              - NumDisksAccessed: 3 (3)
      13:56:13 E              - NumScannerThreadsStarted: 8 (8)
      13:56:13 E              - PeakMemoryUsage: 555.00 KB (568320)
      13:56:13 E              - PerReadThreadRawHdfsThroughput: 0.00 /sec
      13:56:13 E              - RemoteScanRanges: 0 (0)
      13:56:13 E              - RowBatchQueueGetWaitTime: 3.999ms
      13:56:13 E              - RowBatchQueuePutWaitTime: 0.000ns
      13:56:13 E              - RowsRead: 2.42K (2420)
      13:56:13 E              - RowsReturned: 0 (0)
      13:56:13 E              - RowsReturnedRate: 0
      13:56:13 E              - ScanRangesComplete: 8 (8)
      13:56:13 E              - ScannerThreadsInvoluntaryContextSwitches: 5 (5)
      13:56:13 E              - ScannerThreadsTotalWallClockTime: 34.999ms
      13:56:13 E                - DelimiterParseTime: 5.999ms
      13:56:13 E                - MaterializeTupleTime(*): 0.000ns
      13:56:13 E                - ScannerThreadsSysTime: 0.000ns
      13:56:13 E                - ScannerThreadsUserTime: 999.000us
      13:56:13 E              - ScannerThreadsVoluntaryContextSwitches: 33 (33)
      13:56:13 E              - TotalRawHdfsReadTime(*): 0.000ns
      13:56:13 E              - TotalReadThroughput: 276.66 KB/sec
      13:56:13 E         Instance 8a420519db860e0f:1c20406c00000001 (host=impala-boost-static-burst-slave-0224.vpc.cloudera.com:22001):(Total: 275.992ms, non-child: 25.999ms, % non-child: 9.42%)
      13:56:13 E           Hdfs split stats (<volume id>:<# splits>/<split lengths>): 2:2/40.07 KB 1:4/79.73 KB 0:2/40.73 KB 
      13:56:13 E           MemoryUsage(500.000ms): 21.22 KB
      13:56:13 E           ThreadUsage(500.000ms): 1
      13:56:13 E            - AverageThreadTokens: 1.00 
      13:56:13 E            - BloomFilterBytes: 0
      13:56:13 E            - PeakMemoryUsage: 623.56 KB (638521)
      13:56:13 E            - PerHostPeakMemUsage: 24.62 MB (25813091)
      13:56:13 E            - RowsProduced: 1 (1)
      13:56:13 E            - TotalNetworkReceiveTime: 0.000ns
      13:56:13 E            - TotalNetworkSendTime: 0.000ns
      13:56:13 E            - TotalStorageWaitTime: 43.998ms
      13:56:13 E            - TotalThreadsInvoluntaryContextSwitches: 245 (245)
      13:56:13 E            - TotalThreadsTotalWallClockTime: 294.992ms
      13:56:13 E              - TotalThreadsSysTime: 4.000ms
      13:56:13 E              - TotalThreadsUserTime: 162.973ms
      13:56:13 E            - TotalThreadsVoluntaryContextSwitches: 51 (51)
      13:56:13 E           Fragment Instance Lifecycle Timings:
      13:56:13 E              - ExecTime: 18.999ms
      13:56:13 E                - ExecTreeExecTime: 16.999ms
      13:56:13 E              - OpenTime: 199.994ms
      13:56:13 E                - ExecTreeOpenTime: 0.000ns
      13:56:13 E              - PrepareTime: 56.998ms
      13:56:13 E                - ExecTreePrepareTime: 0.000ns
      13:56:13 E           DataStreamSender (dst_id=1):(Total: 999.974us, non-child: 999.974us, % non-child: 100.00%)
      13:56:13 E              - BytesSent: 29.00 B (29)
      13:56:13 E              - NetworkThroughput(*): 0.00 /sec
      13:56:13 E              - OverallThroughput: 28.32 KB/sec
      13:56:13 E              - PeakMemoryUsage: 17.22 KB (17632)
      13:56:13 E              - RowsReturned: 1 (1)
      13:56:13 E              - SerializeBatchTime: 0.000ns
      13:56:13 E              - TransmitDataRPCTime: 0.000ns
      13:56:13 E              - UncompressedRowBatchSize: 38.00 B (38)
      13:56:13 E           CodeGen:(Total: 231.993ms, non-child: 231.993ms, % non-child: 100.00%)
      13:56:13 E              - CodegenTime: 4.999ms
      13:56:13 E              - CompileTime: 14.999ms
      13:56:13 E              - LoadTime: 0.000ns
      13:56:13 E              - ModuleBitcodeSize: 1.98 MB (2077440)
      13:56:13 E              - NumFunctions: 27 (27)
      13:56:13 E              - NumInstructions: 591 (591)
      13:56:13 E              - OptimizationTime: 182.995ms
      13:56:13 E              - PeakMemoryUsage: 295.50 KB (302592)
      13:56:13 E              - PrepareTime: 33.999ms
      13:56:13 E           HDFS_SCAN_NODE (id=0):(Total: 16.999ms, non-child: 16.999ms, % non-child: 100.00%)
      13:56:13 E             Hdfs split stats (<volume id>:<# splits>/<split lengths>): 2:2/40.07 KB 1:4/79.73 KB 0:2/40.73 KB 
      13:56:13 E             ExecOption: TEXT Codegen Enabled, Codegen enabled: 0 out of 8
      13:56:13 E             Hdfs Read Thread Concurrency Bucket: 0:0% 1:0% 2:0% 3:0% 4:0% 5:0% 6:0% 
      13:56:13 E             File Formats: TEXT/NONE:8 
      13:56:13 E             BytesRead(500.000ms): 0
      13:56:13 E              - AverageHdfsReadThreadConcurrency: 0.00 
      13:56:13 E              - AverageScannerThreadConcurrency: 0.00 
      13:56:13 E              - BytesRead: 160.53 KB (164382)
      13:56:13 E              - BytesReadDataNodeCache: 0
      13:56:13 E              - BytesReadLocal: 160.53 KB (164382)
      13:56:13 E              - BytesReadRemoteUnexpected: 0
      13:56:13 E              - BytesReadShortCircuit: 160.53 KB (164382)
      13:56:13 E              - DecompressionTime: 0.000ns
      13:56:13 E              - MaxCompressedTextFileLength: 0
      13:56:13 E              - NumDisksAccessed: 3 (3)
      13:56:13 E              - NumScannerThreadsStarted: 8 (8)
      13:56:13 E              - PeakMemoryUsage: 596.00 KB (610304)
      13:56:13 E              - PerReadThreadRawHdfsThroughput: 0.00 /sec
      13:56:13 E              - RemoteScanRanges: 0 (0)
      13:56:13 E              - RowBatchQueueGetWaitTime: 11.999ms
      13:56:13 E              - RowBatchQueuePutWaitTime: 0.000ns
      13:56:13 E              - RowsRead: 2.45K (2450)
      13:56:13 E              - RowsReturned: 1 (1)
      13:56:13 E              - RowsReturnedRate: 58.00 /sec
      13:56:13 E              - ScanRangesComplete: 8 (8)
      13:56:13 E              - ScannerThreadsInvoluntaryContextSwitches: 5 (5)
      13:56:13 E              - ScannerThreadsTotalWallClockTime: 77.997ms
      13:56:13 E                - DelimiterParseTime: 2.999ms
      13:56:13 E                - MaterializeTupleTime(*): 0.000ns
      13:56:13 E                - ScannerThreadsSysTime: 0.000ns
      13:56:13 E                - ScannerThreadsUserTime: 2.997ms
      13:56:13 E              - ScannerThreadsVoluntaryContextSwitches: 26 (26)
      13:56:13 E              - TotalRawHdfsReadTime(*): 0.000ns
      13:56:13 E              - TotalReadThroughput: 0.00 /sec
      13:56:13 ---------------------------- Captured stderr setup -----------------------------
      13:56:13 SET sync_ddl=False;
      13:56:13 -- executing against localhost:21000
      13:56:13 DROP DATABASE IF EXISTS `test_kudu_insert_932f6329` CASCADE;
      13:56:13 
      13:56:13 SET sync_ddl=False;
      13:56:13 -- executing against localhost:21000
      13:56:13 CREATE DATABASE `test_kudu_insert_932f6329`;
      13:56:13 
      13:56:13 MainThread: Created database "test_kudu_insert_932f6329" for test ID "query_test/test_kudu.py::TestKuduOperations::()::test_kudu_insert[exec_option: {'disable_codegen': False, 'abort_on_error': 1, 'exec_single_node_rows_threshold': 0, 'batch_size': 0, 'num_nodes': 0} | table_format: text/none]"
      13:56:13 ----------------------------- Captured stderr call -----------------------------
      13:56:13 -- executing against localhost:21000
      13:56:13 use test_kudu_insert_932f6329;
      13:56:13 
      13:56:13 SET disable_codegen=False;
      13:56:13 SET abort_on_error=1;
      13:56:13 SET exec_single_node_rows_threshold=0;
      13:56:13 SET batch_size=0;
      13:56:13 SET num_nodes=0;
      13:56:13 -- executing against localhost:21000
      13:56:13 create table tdata
      13:56:13   (id int primary key, valf float null, vali bigint null, valv string null,
      13:56:13    valb boolean null, valt tinyint null, vals smallint null, vald double null,
      13:56:13    ts timestamp)
      13:56:13   PARTITION BY RANGE (PARTITION VALUES < 10, PARTITION 10 <= VALUES < 30,
      13:56:13   PARTITION 30 <= VALUES) STORED AS KUDU;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata values (1, 1, 1, 'one', true, 1, 1, 1,
      13:56:13   cast('1987-05-19 00:00:00' as timestamp));
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tdata limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata values (2, NULL, NULL, NULL, NULL, NULL, NULL, NULL, NULL);
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tdata limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata values
      13:56:13 (3, cast('nan' as float), max_bigint(), '', true, min_tinyint(), max_smallint(),
      13:56:13   cast('-inf' as double),
      13:56:13   nanoseconds_add(cast('9999-12-31 23:59:59' as timestamp), 999999999));
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tdata limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata (valb, vald, id) values (true, 0, 4);
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tdata limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata values
      13:56:13 (5, 5.0, 5, 'five', false, NULL, NULL, NULL, NULL),
      13:56:13 (6, 16, 60, '', true, 0, -1, -6, cast('2010-12-31 23:59:59' as timestamp)),
      13:56:13 (7, NULL, 10, NULL, false, max_tinyint(), -7, 2, cast('1400-01-01 00:00:00' as timestamp));
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tdata limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata (valv, valf, vali, id) values
      13:56:13 ('eight', 88, 888, 8),
      13:56:13 (NULL, -9, -99, 9);
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tdata limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata
      13:56:13 select id, float_col, bigint_col, string_col, bool_col, tinyint_col, smallint_col,
      13:56:13 double_col, timestamp_col
      13:56:13 from functional.alltypes where id = 10;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tdata limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata (id, vald, valb, vali, ts)
      13:56:13 select id, double_col, bool_col, bigint_col, timestamp_col
      13:56:13 from functional.alltypes where id = 11;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tdata limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 delete tdata;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tdata limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata
      13:56:13 select id, float_col, bigint_col, string_col, bool_col, tinyint_col, smallint_col,
      13:56:13 double_col, timestamp_col
      13:56:13 from functional.alltypes where id < 2;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tdata limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata (vals, id, valt, vald, ts)
      13:56:13 select smallint_col, id, tinyint_col, double_col, timestamp_col
      13:56:13 from functional.alltypes where id > 2 and id < 6;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tdata limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata values (320, 2.0, 932, cast('' as string), false, 0, 0, 0, NULL);
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select id, valv, valb from tdata where id = 320;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata values
      13:56:13 (666, cast(1.2 as float), 43, cast('z' as string), true, 0, 0, 0, NULL);
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tdata values
      13:56:13 (666, cast(1.2 as float), 43, cast('z' as VARCHAR(20)), true, 0, 0, 0, NULL);
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 create table kudu_test_tbl primary key(id)
      13:56:13 partition by range(id) (partition values < 100, partition 100 <= values <= 10000)
      13:56:13 stored as kudu as
      13:56:13 select * from functional_kudu.alltypes where id < 100;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into kudu_test_tbl
      13:56:13 select * from functional_kudu.alltypes where id < 100;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into kudu_test_tbl
      13:56:13 select * from functional_kudu.alltypes;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into kudu_test_tbl SELECT cast(id + 10000 as int), bool_col, tinyint_col,
      13:56:13   smallint_col, int_col, bigint_col, float_col, double_col, date_string_col, string_col,
      13:56:13   timestamp_col, year, month
      13:56:13 from functional_kudu.alltypes;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 create table allkeytypes (i1 tinyint, i2 smallint, i3 int, i4 bigint, name string,
      13:56:13   valf float, vald double, primary key (i1, i2, i3, i4, name)) partition by
      13:56:13   hash partitions 3, range (partition value = (1,1,1,1,'1'),
      13:56:13   partition value = (2,2,2,2,'2'), partition value = (3,3,3,3,'3')) stored as kudu;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into allkeytypes select cast(id as tinyint), smallint_col, int_col,
      13:56:13   cast (bigint_col/10 as bigint), string_col, float_col, double_col
      13:56:13   from functional.alltypes where id > 0 and id < 10;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 create table tbl_with_defaults (a int primary key, b int null default 10,
      13:56:13   c int not null default 100, d int default 1000, e int null, f int not null,
      13:56:13   g string default 'test', h boolean default true) partition by hash (a)
      13:56:13   partitions 3 stored as kudu;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tbl_with_defaults (a, f) values (1, 1), (2, 2), (3, 3), (4, 4);
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tbl_with_defaults limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tbl_with_defaults values (5, 5, 5, 5, 5, 5, 'row', false);
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tbl_with_defaults limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 alter table tbl_with_defaults add columns (i int null, j int not null default 10000);
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tbl_with_defaults;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tbl_with_defaults values (6,6,6,6,6,6,'another row',false,6,6);
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tbl_with_defaults limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tbl_with_defaults (a, c, f) values (0, null, 1);
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into tbl_with_defaults (a, b, d, f) values (0, 0, null, 0);
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from tbl_with_defaults limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 create table multiple_partition_cols (x bigint, y bigint, z string, primary key(x, y))
      13:56:13 partition by hash(x, y) partitions 8 stored as kudu;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into multiple_partition_cols select 0, bigint_col, string_col
      13:56:13   from functional.alltypes where id = 0;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 select * from multiple_partition_cols limit 1000;
      13:56:13 
      13:56:13 -- executing against localhost:21000
      13:56:13 insert into multiple_partition_cols select bigint_col, null, string_col
      13:56:13   from functional.alltypes where id = 1;
      

      cc'ing lv and mjacobs

      Attachments

        Issue Links

          Activity

            People

              Unassigned Unassigned
              kwho Michael Ho
              Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: