[
https://issues.apache.org/jira/browse/IMPALA-7028?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16474677#comment-16474677
]
Joe McDonnell commented on IMPALA-7028:
---------------------------------------
{noformat}
query_test/test_kudu.py:92: in test_kudu_update
self.run_test_case('QueryTest/kudu_update', vector, use_db=unique_database)
common/impala_test_suite.py:451: in run_test_case
verify_runtime_profile(test_section['RUNTIME_PROFILE'],
result.runtime_profile)
common/test_result_verifier.py:590: in verify_runtime_profile
actual))
E AssertionError: Did not find matches for lines in runtime profile:
E EXPECTED LINES:
E NumModifiedRows: 7300
E
E ACTUAL PROFILE:
E Query (id=de4b7a0e99753cd5:6ffa44fd00000000):
E DEBUG MODE WARNING: Query profile created while running a DEBUG build of
Impala. Use RELEASE builds to measure query performance.
E Summary:
E Session ID: 7f4a67a73c9ecf4e:5d51ba77392831b4
E Session Type: BEESWAX
E Start Time: 2018-05-12 15:08:10.372271000
E End Time:
E Query Type: DML
E Query State: FINISHED
E Query Status: OK
E Impala Version: impalad version 3.1.0-SNAPSHOT DEBUG (build
e12ee485cf4c77203b144c053ee167509cc39374)
E User: jenkins
E Connected User: jenkins
E Delegated User:
E Network Address: 127.0.0.1:55173
E Default Db: test_kudu_update_628738b5
E Sql Statement: update tdata set vali = -1
E Coordinator: ec2-m2-4xlarge-centos-6-4-092a.vpc.cloudera.com:22000
E Query Options (set by configuration):
ABORT_ON_ERROR=1,DISABLE_CODEGEN=1,EXEC_SINGLE_NODE_ROWS_THRESHOLD=0,DISABLE_CODEGEN_ROWS_THRESHOLD=0
E Query Options (set by configuration and planner):
ABORT_ON_ERROR=1,DISABLE_CODEGEN=1,EXEC_SINGLE_NODE_ROWS_THRESHOLD=0,MT_DOP=0,DISABLE_CODEGEN_ROWS_THRESHOLD=0
E Plan:
E ----------------
E Max Per-Host Resource Reservation: Memory=0B Threads=2
E Per-Host Resource Estimates: Memory=10.00MB
E WARNING: The following tables are missing relevant table and/or column
statistics.
E test_kudu_update_628738b5.tdata
E
E F00:PLAN FRAGMENT [RANDOM] hosts=3 instances=3
E | Per-Host Resources: mem-estimate=0B mem-reservation=0B
thread-reservation=2
E UPDATE KUDU [test_kudu_update_628738b5.tdata]
E | mem-estimate=0B mem-reservation=0B thread-reservation=0
E |
E 00:SCAN KUDU [test_kudu_update_628738b5.tdata]
E mem-estimate=0B mem-reservation=0B thread-reservation=1
E tuple-ids=0 row-size=4B cardinality=unavailable
E ----------------
E Estimated Per-Host Mem: 10485760
E Tables Missing Stats: test_kudu_update_628738b5.tdata
E Per Host Min Memory Reservation:
ec2-m2-4xlarge-centos-6-4-092a.vpc.cloudera.com:22000(0)
ec2-m2-4xlarge-centos-6-4-092a.vpc.cloudera.com:22001(0)
ec2-m2-4xlarge-centos-6-4-092a.vpc.cloudera.com:22002(0)
E Request Pool: default-pool
E Admission result: Admitted immediately
E Query Compilation: 6.606ms
E - Metadata of all 1 tables cached: 1.087ms (1.087ms)
E - Analysis finished: 1.457ms (369.234us)
E - Value transfer graph computed: 1.508ms (51.577us)
E - Single node plan created: 4.839ms (3.330ms)
E - Runtime filters computed: 4.876ms (37.680us)
E - Distributed plan created: 4.934ms (57.370us)
E - Planning finished: 6.606ms (1.672ms)
E Query Timeline: 84.999ms
E - Query submitted: 999.994us (999.994us)
E - Planning finished: 8.999ms (7.999ms)
E - Submit for admission: 11.999ms (2.999ms)
E - Completed admission: 11.999ms (0.000ns)
E - Ready to start on 3 backends: 12.999ms (999.994us)
E - All 3 execution backends (3 fragment instances) started: 24.999ms
(11.999ms)
E - Last row fetched: 39.999ms (14.999ms)
E - Released admission control resources: 39.999ms (0.000ns)
E - DML data written: 40.999ms (999.993us)
E - DML Metastore update finished: 40.999ms (0.000ns)
E - Request finished: 40.999ms (0.000ns)
E - First row fetched: 82.999ms (41.999ms)
E - ComputeScanRangeAssignmentTimer: 0.000ns
E ImpalaServer:
E - ClientFetchWaitTimer: 0.000ns
E - MetastoreUpdateTimer: 0.000ns
E - RowMaterializationTimer: 0.000ns
E Execution Profile de4b7a0e99753cd5:6ffa44fd00000000:(Total: 27.999ms,
non-child: 0.000ns, % non-child: 0.00%)
E Number of filters: 0
E Filter routing table:
E ID Src. Node Tgt. Node(s) Target type Partition filter Pending
(Expected) First arrived Completed Enabled
E
-------------------------------------------------------------------------------------------------------------------
E
E Backend startup latencies: Count: 3, min / max: 1ms / 11ms, 25th %-ile:
1ms, 50th %-ile: 2ms, 75th %-ile: 2ms, 90th %-ile: 11ms, 95th %-ile: 11ms,
99.9th %-ile: 11ms
E Per Node Peak Memory Usage:
ec2-m2-4xlarge-centos-6-4-092a.vpc.cloudera.com:22000(20.02 MB)
ec2-m2-4xlarge-centos-6-4-092a.vpc.cloudera.com:22001(20.02 MB)
ec2-m2-4xlarge-centos-6-4-092a.vpc.cloudera.com:22002(20.02 MB)
E DML Stats:
E Partition: Default
E NumModifiedRows: 32
E NumRowErrors: 0
E BytesWritten: 0
E - FiltersReceived: 0 (0)
E - FinalizationTimer: 0.000ns
E - NumBackends: 3 (3)
E - NumFragmentInstances: 3 (3)
E - NumFragments: 1 (1)
E Averaged Fragment F00:(Total: 9.666ms, non-child: 4.333ms, % non-child:
44.83%)
E split sizes: min: 0, max: 0, avg: 0, stddev: 0
E completion times: min:10.999ms max:14.999ms mean: 12.666ms
stddev:1.699ms
E execution rates: min:0.00 /sec max:0.00 /sec mean:0.00 /sec
stddev:0.00 /sec
E num instances: 3
E - AverageThreadTokens: 0.00
E - BloomFilterBytes: 0
E - PeakMemoryUsage: 20.02 MB (20992000)
E - PeakReservation: 0
E - PeakUsedReservation: 0
E - PerHostPeakMemUsage: 20.02 MB (20992000)
E - RowsProduced: 10 (10)
E - TotalNetworkReceiveTime: 0.000ns
E - TotalNetworkSendTime: 0.000ns
E - TotalStorageWaitTime: 1.666ms
E - TotalThreadsInvoluntaryContextSwitches: 3 (3)
E - TotalThreadsTotalWallClockTime: 12.666ms
E - TotalThreadsSysTime: 666.333us
E - TotalThreadsUserTime: 1.665ms
E - TotalThreadsVoluntaryContextSwitches: 9 (9)
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 0
E - CumulativeAllocations: 0 (0)
E - PeakReservation: 0
E - PeakUnpinnedBytes: 0
E - PeakUsedReservation: 0
E - ReadIoBytes: 0
E - ReadIoOps: 0 (0)
E - ReadIoWaitTime: 0.000ns
E - ReservationLimit: 0
E - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E Fragment Instance Lifecycle Timings:
E - ExecTime: 5.999ms
E - ExecTreeExecTime: 2.333ms
E - OpenTime: 2.999ms
E - ExecTreeOpenTime: 1.999ms
E - PrepareTime: 666.662us
E - ExecTreePrepareTime: 0.000ns
E KuduTableSink:
E - KuduApplyTimer: 0.000ns
E - NumRowErrors: 0 (0)
E - PeakMemoryUsage: 20.00 MB (20971520)
E - RowsProcessedRate: 0
E - TotalNumRows: 10 (10)
E KUDU_SCAN_NODE (id=0):(Total: 5.333ms, non-child: 5.333ms, %
non-child: 100.00%)
E - BytesRead: 0
E - CollectionItemsRead: 0 (0)
E - KuduRemoteScanTokens: 0 (0)
E - NumScannerThreadsStarted: 1 (1)
E - PeakMemoryUsage: 12.00 KB (12288)
E - RowsRead: 10 (10)
E - RowsReturned: 10 (10)
E - RowsReturnedRate: 2.11 K/sec
E - ScanRangesComplete: 1 (1)
E - ScannerThreadsInvoluntaryContextSwitches: 3 (3)
E - ScannerThreadsTotalWallClockTime: 3.666ms
E - MaterializeTupleTime(*): 2.333ms
E - ScannerThreadsSysTime: 0.000ns
E - ScannerThreadsUserTime: 333.000us
E - ScannerThreadsVoluntaryContextSwitches: 2 (2)
E - TotalKuduScanRoundTrips: 1 (1)
E - TotalReadThroughput: 0.00 /sec
E Fragment F00:
E Instance de4b7a0e99753cd5:6ffa44fd00000002
(host=ec2-m2-4xlarge-centos-6-4-092a.vpc.cloudera.com:22000):(Total: 9.999ms,
non-child: 4.999ms, % non-child: 50.00%)
E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
E Fragment Instance Lifecycle Event Timeline: 10.999ms
E - Prepare Finished: 999.993us (999.993us)
E - Open Finished: 4.999ms (3.999ms)
E - First Batch Produced: 6.999ms (1.999ms)
E - First Batch Sent: 6.999ms (0.000ns)
E - ExecInternal Finished: 10.999ms (3.999ms)
E - AverageThreadTokens: 0.00
E - BloomFilterBytes: 0
E - PeakMemoryUsage: 20.02 MB (20992000)
E - PeakReservation: 0
E - PeakUsedReservation: 0
E - PerHostPeakMemUsage: 20.02 MB (20992000)
E - RowsProduced: 10 (10)
E - TotalNetworkReceiveTime: 0.000ns
E - TotalNetworkSendTime: 0.000ns
E - TotalStorageWaitTime: 999.993us
E - TotalThreadsInvoluntaryContextSwitches: 4 (4)
E - TotalThreadsTotalWallClockTime: 13.999ms
E - TotalThreadsSysTime: 0.000ns
E - TotalThreadsUserTime: 2.998ms
E - TotalThreadsVoluntaryContextSwitches: 11 (11)
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 0
E - CumulativeAllocations: 0 (0)
E - PeakReservation: 0
E - PeakUnpinnedBytes: 0
E - PeakUsedReservation: 0
E - ReadIoBytes: 0
E - ReadIoOps: 0 (0)
E - ReadIoWaitTime: 0.000ns
E - ReservationLimit: 0
E - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E Fragment Instance Lifecycle Timings:
E - ExecTime: 5.999ms
E - ExecTreeExecTime: 1.999ms
E - OpenTime: 3.999ms
E - ExecTreeOpenTime: 2.999ms
E - PrepareTime: 0.000ns
E - ExecTreePrepareTime: 0.000ns
E KuduTableSink:
E - KuduApplyTimer: 0.000ns
E - NumRowErrors: 0 (0)
E - PeakMemoryUsage: 20.00 MB (20971520)
E - RowsProcessedRate: 0
E - TotalNumRows: 10 (10)
E KUDU_SCAN_NODE (id=0):(Total: 4.999ms, non-child: 4.999ms, %
non-child: 100.00%)
E - BytesRead: 0
E - CollectionItemsRead: 0 (0)
E - KuduRemoteScanTokens: 0 (0)
E - NumScannerThreadsStarted: 1 (1)
E - PeakMemoryUsage: 12.00 KB (12288)
E - RowsRead: 10 (10)
E - RowsReturned: 10 (10)
E - RowsReturnedRate: 2.00 K/sec
E - ScanRangesComplete: 1 (1)
E - ScannerThreadsInvoluntaryContextSwitches: 4 (4)
E - ScannerThreadsTotalWallClockTime: 3.999ms
E - MaterializeTupleTime(*): 1.999ms
E - ScannerThreadsSysTime: 0.000ns
E - ScannerThreadsUserTime: 999.000us
E - ScannerThreadsVoluntaryContextSwitches: 3 (3)
E - TotalKuduScanRoundTrips: 1 (1)
E - TotalReadThroughput: 0.00 /sec
E Instance de4b7a0e99753cd5:6ffa44fd00000001
(host=ec2-m2-4xlarge-centos-6-4-092a.vpc.cloudera.com:22001):(Total: 9.999ms,
non-child: 4.999ms, % non-child: 50.00%)
E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
E Fragment Instance Lifecycle Event Timeline: 10.999ms
E - Prepare Finished: 1.999ms (1.999ms)
E - Open Finished: 3.999ms (1.999ms)
E - First Batch Produced: 5.999ms (1.999ms)
E - First Batch Sent: 5.999ms (0.000ns)
E - ExecInternal Finished: 10.999ms (4.999ms)
E - AverageThreadTokens: 0.00
E - BloomFilterBytes: 0
E - PeakMemoryUsage: 20.02 MB (20992000)
E - PeakReservation: 0
E - PeakUsedReservation: 0
E - PerHostPeakMemUsage: 20.02 MB (20992000)
E - RowsProduced: 20 (20)
E - TotalNetworkReceiveTime: 0.000ns
E - TotalNetworkSendTime: 0.000ns
E - TotalStorageWaitTime: 1.999ms
E - TotalThreadsInvoluntaryContextSwitches: 4 (4)
E - TotalThreadsTotalWallClockTime: 12.999ms
E - TotalThreadsSysTime: 1.999ms
E - TotalThreadsUserTime: 0.000ns
E - TotalThreadsVoluntaryContextSwitches: 10 (10)
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 0
E - CumulativeAllocations: 0 (0)
E - PeakReservation: 0
E - PeakUnpinnedBytes: 0
E - PeakUsedReservation: 0
E - ReadIoBytes: 0
E - ReadIoOps: 0 (0)
E - ReadIoWaitTime: 0.000ns
E - ReservationLimit: 0
E - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E Fragment Instance Lifecycle Timings:
E - ExecTime: 6.999ms
E - ExecTreeExecTime: 2.999ms
E - OpenTime: 1.999ms
E - ExecTreeOpenTime: 999.994us
E - PrepareTime: 999.993us
E - ExecTreePrepareTime: 0.000ns
E KuduTableSink:
E - KuduApplyTimer: 0.000ns
E - NumRowErrors: 0 (0)
E - PeakMemoryUsage: 20.00 MB (20971520)
E - RowsProcessedRate: 0
E - TotalNumRows: 20 (20)
E KUDU_SCAN_NODE (id=0):(Total: 4.999ms, non-child: 4.999ms, %
non-child: 100.00%)
E - BytesRead: 0
E - CollectionItemsRead: 0 (0)
E - KuduRemoteScanTokens: 0 (0)
E - NumScannerThreadsStarted: 1 (1)
E - PeakMemoryUsage: 12.00 KB (12288)
E - RowsRead: 20 (20)
E - RowsReturned: 20 (20)
E - RowsReturnedRate: 4.00 K/sec
E - ScanRangesComplete: 1 (1)
E - ScannerThreadsInvoluntaryContextSwitches: 4 (4)
E - ScannerThreadsTotalWallClockTime: 3.999ms
E - MaterializeTupleTime(*): 2.999ms
E - ScannerThreadsSysTime: 0.000ns
E - ScannerThreadsUserTime: 0.000ns
E - ScannerThreadsVoluntaryContextSwitches: 2 (2)
E - TotalKuduScanRoundTrips: 1 (1)
E - TotalReadThroughput: 0.00 /sec
E Instance de4b7a0e99753cd5:6ffa44fd00000000
(host=ec2-m2-4xlarge-centos-6-4-092a.vpc.cloudera.com:22002):(Total: 8.999ms,
non-child: 2.999ms, % non-child: 33.33%)
E Hdfs split stats (<volume id>:<# splits>/<split lengths>):
E Fragment Instance Lifecycle Event Timeline: 13.999ms
E - Prepare Finished: 5.999ms (5.999ms)
E - Open Finished: 8.999ms (2.999ms)
E - First Batch Produced: 10.999ms (1.999ms)
E - First Batch Sent: 10.999ms (0.000ns)
E - ExecInternal Finished: 13.999ms (2.999ms)
E - AverageThreadTokens: 0.00
E - BloomFilterBytes: 0
E - PeakMemoryUsage: 20.02 MB (20992000)
E - PeakReservation: 0
E - PeakUsedReservation: 0
E - PerHostPeakMemUsage: 20.02 MB (20992000)
E - RowsProduced: 2 (2)
E - TotalNetworkReceiveTime: 0.000ns
E - TotalNetworkSendTime: 0.000ns
E - TotalStorageWaitTime: 1.999ms
E - TotalThreadsInvoluntaryContextSwitches: 2 (2)
E - TotalThreadsTotalWallClockTime: 10.999ms
E - TotalThreadsSysTime: 0.000ns
E - TotalThreadsUserTime: 1.999ms
E - TotalThreadsVoluntaryContextSwitches: 7 (7)
E Buffer pool:
E - AllocTime: 0.000ns
E - CumulativeAllocationBytes: 0
E - CumulativeAllocations: 0 (0)
E - PeakReservation: 0
E - PeakUnpinnedBytes: 0
E - PeakUsedReservation: 0
E - ReadIoBytes: 0
E - ReadIoOps: 0 (0)
E - ReadIoWaitTime: 0.000ns
E - ReservationLimit: 0
E - WriteIoBytes: 0
E - WriteIoOps: 0 (0)
E - WriteIoWaitTime: 0.000ns
E Fragment Instance Lifecycle Timings:
E - ExecTime: 4.999ms
E - ExecTreeExecTime: 1.999ms
E - OpenTime: 2.999ms
E - ExecTreeOpenTime: 1.999ms
E - PrepareTime: 999.994us
E - ExecTreePrepareTime: 0.000ns
E KuduTableSink:
E - KuduApplyTimer: 0.000ns
E - NumRowErrors: 0 (0)
E - PeakMemoryUsage: 20.00 MB (20971520)
E - RowsProcessedRate: 0
E - TotalNumRows: 2 (2)
E KUDU_SCAN_NODE (id=0):(Total: 5.999ms, non-child: 5.999ms, %
non-child: 100.00%)
E - BytesRead: 0
E - CollectionItemsRead: 0 (0)
E - KuduRemoteScanTokens: 0 (0)
E - NumScannerThreadsStarted: 1 (1)
E - PeakMemoryUsage: 12.00 KB (12288)
E - RowsRead: 2 (2)
E - RowsReturned: 2 (2)
E - RowsReturnedRate: 333.00 /sec
E - ScanRangesComplete: 1 (1)
E - ScannerThreadsInvoluntaryContextSwitches: 2 (2)
E - ScannerThreadsTotalWallClockTime: 2.999ms
E - MaterializeTupleTime(*): 1.999ms
E - ScannerThreadsSysTime: 0.000ns
E - ScannerThreadsUserTime: 0.000ns
E - ScannerThreadsVoluntaryContextSwitches: 2 (2)
E - TotalKuduScanRoundTrips: 1 (1)
E - TotalReadThroughput: 0.00 /sec{noformat}
> TestKuduOperations.test_kudu_update fails due to wrong NumModifiedRows
> ----------------------------------------------------------------------
>
> Key: IMPALA-7028
> URL: https://issues.apache.org/jira/browse/IMPALA-7028
> Project: IMPALA
> Issue Type: Bug
> Components: Backend
> Affects Versions: Impala 3.1.0
> Reporter: Joe McDonnell
> Priority: Critical
> Labels: broken-build, flaky
>
> Seen once on master exhaustive:
> {noformat}
> query_test/test_kudu.py:92: in test_kudu_update
> self.run_test_case('QueryTest/kudu_update', vector,
> use_db=unique_database)
> common/impala_test_suite.py:451: in run_test_case
> verify_runtime_profile(test_section['RUNTIME_PROFILE'],
> result.runtime_profile)
> common/test_result_verifier.py:590: in verify_runtime_profile
> actual))
> E AssertionError: Did not find matches for lines in runtime profile:
> E EXPECTED LINES:
> E NumModifiedRows: 7300
> ...
> # From the actual profile:
> E Partition: Default
> E NumModifiedRows: 32
> E NumRowErrors: 0{noformat}
> Will add a comment with the profile.
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
