[KUDU-1548] Looping raft_consensus-itest hitting some failures - ASF JIRA

XML

Word

Printable

JSON

Details

Type: Bug
Status: Open
Priority: Major
Resolution: Unresolved
Affects Version/s: 0.10.0
Fix Version/s: None
Component/s: consensus
Labels:
None

Description

Find the detailed test results/logs under the attached tarfile dist-test-results-1548.tar.gz

mpercy aready is addressing one test flakiness here: https://gerrit.cloudera.org/#/c/3819

The test log looked something like this:

I0729 18:59:47.834403 11544 raft_consensus.cc:370] T e3503c47a21649ca931234999cd0bb45 P d4f64819170a4cf78fe4c9e9a72ec4b9 [term 1 FOLLOWER]: No leader contacted us within the election timeout. Triggering leader election
I0729 18:59:47.834686 11544 raft_consensus.cc:2019] T e3503c47a21649ca931234999cd0bb45 P d4f64819170a4cf78fe4c9e9a72ec4b9 [term 1 FOLLOWER]: Advancing to term 2
I0729 18:59:47.840427 11544 leader_election.cc:223] T e3503c47a21649ca931234999cd0bb45 P d4f64819170a4cf78fe4c9e9a72ec4b9 [CANDIDATE]: Term 2 election: Requesting vote from peer 54197053abab4b6cb1b1632c9d1062dc
I0729 18:59:47.840860 11544 leader_election.cc:223] T e3503c47a21649ca931234999cd0bb45 P d4f64819170a4cf78fe4c9e9a72ec4b9 [CANDIDATE]: Term 2 election: Requesting vote from peer 3522a8de8170476dba0beb58cb2150d4
I0729 18:59:47.872720 11669 raft_consensus.cc:869] T e3503c47a21649ca931234999cd0bb45 P 3522a8de8170476dba0beb58cb2150d4 [term 1 FOLLOWER]: Refusing update from remote peer 54197053abab4b6cb1b1632c9d1062dc: Log matching property violated. Preceding OpId in replica: term: 1 index: 1. Preceding OpId from leader: term: 1 index: 2. (index mismatch)
I0729 18:59:47.874522 11454 consensus_queue.cc:578] T e3503c47a21649ca931234999cd0bb45 P 54197053abab4b6cb1b1632c9d1062dc [LEADER]: Connected to new peer: Peer: 3522a8de8170476dba0beb58cb2150d4, Is new: false, Last received: 1.1, Next index: 2, Last known committed idx: 1, Last exchange result: ERROR, Needs remote bootstrap: false
I0729 18:59:47.878105 11150 raft_consensus.cc:1324] T e3503c47a21649ca931234999cd0bb45 P 54197053abab4b6cb1b1632c9d1062dc [term 1 LEADER]: Handling vote request from an unknown peer d4f64819170a4cf78fe4c9e9a72ec4b9
I0729 18:59:47.878290 11150 raft_consensus.cc:2014] T e3503c47a21649ca931234999cd0bb45 P 54197053abab4b6cb1b1632c9d1062dc [term 1 LEADER]: Stepping down as leader of term 1
I0729 18:59:47.878451 11150 raft_consensus.cc:499] T e3503c47a21649ca931234999cd0bb45 P 54197053abab4b6cb1b1632c9d1062dc [term 1 LEADER]: Becoming Follower/Learner. State: Replica: 54197053abab4b6cb1b1632c9d1062dc, State: 1, Role: LEADER
Watermarks: {Received: term: 1 index: 2 Committed: term: 1 index: 1}
I0729 18:59:47.878968 11150 consensus_queue.cc:162] T e3503c47a21649ca931234999cd0bb45 P 54197053abab4b6cb1b1632c9d1062dc [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated op: 0.0, Majority replicated op: 1.1, Committed index: 1.1, Last appended: 1.2, Current term: 1, Majority size: -1, State: 1, Mode: NON_LEADER
I0729 18:59:47.879871 11150 consensus_peers.cc:358] T e3503c47a21649ca931234999cd0bb45 P 54197053abab4b6cb1b1632c9d1062dc -> Peer 3522a8de8170476dba0beb58cb2150d4 (127.37.56.2:53243): Closing peer: 3522a8de8170476dba0beb58cb2150d4
I0729 18:59:47.882057 11150 raft_consensus.cc:2019] T e3503c47a21649ca931234999cd0bb45 P 54197053abab4b6cb1b1632c9d1062dc [term 1 FOLLOWER]: Advancing to term 2
I0729 18:59:47.885711 11150 raft_consensus.cc:1626] T e3503c47a21649ca931234999cd0bb45 P 54197053abab4b6cb1b1632c9d1062dc [term 2 FOLLOWER]: Leader election vote request: Denying vote to candidate d4f64819170a4cf78fe4c9e9a72ec4b9 for term 2 because replica has last-logged OpId of term: 1 index: 2, which is greater than that of the candidate, which has last-logged OpId of term: 1 index: 1.
I0729 18:59:47.892060 11477 leader_election.cc:361] T e3503c47a21649ca931234999cd0bb45 P d4f64819170a4cf78fe4c9e9a72ec4b9 [CANDIDATE]: Term 2 election: Vote denied by peer 54197053abab4b6cb1b1632c9d1062dc. Message: Invalid argument: T e3503c47a21649ca931234999cd0bb45 P 54197053abab4b6cb1b1632c9d1062dc [term 2 FOLLOWER]: Leader election vote request: Denying vote to candidate d4f64819170a4cf78fe4c9e9a72ec4b9 for term 2 because replica has last-logged OpId of term: 1 index: 2, which is greater than that of the candidate, which has last-logged OpId of term: 1 index: 1.
I0729 18:59:47.894548 11669 raft_consensus.cc:1324] T e3503c47a21649ca931234999cd0bb45 P 3522a8de8170476dba0beb58cb2150d4 [term 1 FOLLOWER]: Handling vote request from an unknown peer d4f64819170a4cf78fe4c9e9a72ec4b9
I0729 18:59:47.894688 11669 raft_consensus.cc:2019] T e3503c47a21649ca931234999cd0bb45 P 3522a8de8170476dba0beb58cb2150d4 [term 1 FOLLOWER]: Advancing to term 2
I0729 18:59:47.896904 11669 raft_consensus.cc:1626] T e3503c47a21649ca931234999cd0bb45 P 3522a8de8170476dba0beb58cb2150d4 [term 2 FOLLOWER]: Leader election vote request: Denying vote to candidate d4f64819170a4cf78fe4c9e9a72ec4b9 for term 2 because replica has last-logged OpId of term: 1 index: 2, which is greater than that of the candidate, which has last-logged OpId of term: 1 index: 1.
I0729 18:59:47.898056 11477 leader_election.cc:361] T e3503c47a21649ca931234999cd0bb45 P d4f64819170a4cf78fe4c9e9a72ec4b9 [CANDIDATE]: Term 2 election: Vote denied by peer 3522a8de8170476dba0beb58cb2150d4. Message: Invalid argument: T e3503c47a21649ca931234999cd0bb45 P 3522a8de8170476dba0beb58cb2150d4 [term 2 FOLLOWER]: Leader election vote request: Denying vote to candidate d4f64819170a4cf78fe4c9e9a72ec4b9 for term 2 because replica has last-logged OpId of term: 1 index: 2, which is greater than that of the candidate, which has last-logged OpId of term: 1 index: 1.
I0729 18:59:47.898530 11477 leader_election.cc:248] T e3503c47a21649ca931234999cd0bb45 P d4f64819170a4cf78fe4c9e9a72ec4b9 [CANDIDATE]: Term 2 election: Election decided. Result: candidate lost.
I0729 18:59:47.899269 11598 raft_consensus.cc:1821] T e3503c47a21649ca931234999cd0bb45 P d4f64819170a4cf78fe4c9e9a72ec4b9 [term 2 FOLLOWER]: Leader election lost for term 2. Reason: None given
W0729 19:00:48.184541 11433 batcher.cc:315] Timed out: Failed to write batch of 10 ops to tablet e3503c47a21649ca931234999cd0bb45 after 340 attempt(s): Failed to write to server: (no server available): Write(tablet: e3503c47a21649ca931234999cd0bb45, num_ops: 10, num_attempts: 340) passed its deadline: Illegal state: Replica 54197053abab4b6cb1b1632c9d1062dc is not leader of this config. Role: FOLLOWER. Consensus state: current_term: 2 leader_uuid: "" config { peers { permanent_uuid: "54197053abab4b6cb1b1632c9d1062dc" member_type: VOTER last_known_addr { host: "127.37.56.0" port: 33531 } } peers { permanent_uuid: "3522a8de8170476dba0beb58cb2150d4" member_type: VOTER last_known_addr { host: "127.37.56.2" port: 53243 } } }
E0729 19:00:48.185212  9528 raft_consensus-itest.cc:246] Unexpected error: Timed out: Failed to write batch of 10 ops to tablet e3503c47a21649ca931234999cd0bb45 after 340 attempt(s): Failed to write to server: (no server available): Write(tablet: e3503c47a21649ca931234999cd0bb45, num_ops: 10, num_attempts: 340) passed its deadline: Illegal state: Replica 54197053abab4b6cb1b1632c9d1062dc is not leader of this config. Role: FOLLOWER. Consensus state: current_term: 2 leader_uuid: "" config { peers { permanent_uuid: "54197053abab4b6cb1b1632c9d1062dc" member_type: VOTER last_known_addr { host: "127.37.56.0" port: 33531 } } peers { permanent_uuid: "3522a8de8170476dba0beb58cb2150d4" member_type: VOTER last_known_addr { host: "127.37.56.2" port: 53243 } } }

Apart from above, I am also observing few other interesting issues from the logs from various tests. I was hoping to upload the tarfile of logs, but not able to find the upload button.
========================> this looks like a genuine catch by the test:

INFO: Connected to all 7 Tablet Servers
INFO: Table TestTable is HEALTHY
INFO: The metadata for 1 tables is HEALTHY
I0729 19:04:55.100972 30908 tablet.cc:1317] T b6a2f16af1054af5ac2135d875fd16b9 Flush: entering phase 2 (starting to duplicate updates in new rowsets)
I0729 19:04:55.102052 30908 tablet.cc:1372] T b6a2f16af1054af5ac2135d875fd16b9 Flush Phase 2: carrying over any updates which arrived during Phase 1
I0729 19:04:55.102242 30908 tablet.cc:1374] T b6a2f16af1054af5ac2135d875fd16b9 Phase 2 snapshot: MvccSnapshot[committed={T|T < 6020378860105490432 or (T in {6020378860105490432})}]
I0729 19:04:57.870882 30908 tablet.cc:1415] T b6a2f16af1054af5ac2135d875fd16b9 Flush successful on 18820 rows (457274 bytes)
I0729 19:04:57.906981 30908 maintenance_manager.cc:353] Time spent running FlushMRSOp(b6a2f16af1054af5ac2135d875fd16b9): real 9.390s    user 5.560s     sys 0.108s
I0729 19:04:58.039110 30908 tablet.cc:1449] T b6a2f16af1054af5ac2135d875fd16b9 Compaction: stage 1 complete, picked 2 rowsets to compact
I0729 19:04:58.039314 30908 compaction.cc:588] Selected 2 rowsets to compact:
I0729 19:04:58.039435 30908 compaction.cc:591] RowSet(0)(current size on disk: ~424615 bytes)
I0729 19:04:58.039618 30908 compaction.cc:591] RowSet(1)(current size on disk: ~408012 bytes)
I0729 19:04:58.039865 30908 tablet.cc:1237] T b6a2f16af1054af5ac2135d875fd16b9 Compaction: entering phase 1 (flushing snapshot). Phase 1 snapshot: MvccSnapshot[committed={T|T < 6020378860105490432 or (T in {6020378860105490432})}]
I0729 19:04:58.042769 30908 multi_column_writer.cc:85] Opened CFile writer for column key[int32 NOT NULL]
I0729 19:04:58.043309 30908 multi_column_writer.cc:85] Opened CFile writer for column int_val[int32 NOT NULL]
I0729 19:04:58.043864 30908 multi_column_writer.cc:85] Opened CFile writer for column string_val[string NULLABLE]
-----------------------
TestTable
-----------------------
T b6a2f16af1054af5ac2135d875fd16b9 P 7f1a9aa5093941a48014539dac242908 (127.107.54.1:50824): Checksum: 82472867647901
T b6a2f16af1054af5ac2135d875fd16b9 P cccf457b5acd470d8014c032439134e5 (127.107.54.6:59813): Checksum: 82472867647901
T b6a2f16af1054af5ac2135d875fd16b9 P f342febecdae405c835dd8942dc65b7c (127.107.54.2:49802): Checksum: 82472867647901
T b6a2f16af1054af5ac2135d875fd16b9 P 8021d519fa2b431f97965b4e2ebd417f (127.107.54.3:48160): Checksum: 82472867647901
T b6a2f16af1054af5ac2135d875fd16b9 P f5c4abc758674f03947c4dd3e85cc97a (127.107.54.4:53658): Checksum: 82472867647901
T b6a2f16af1054af5ac2135d875fd16b9 P 9cce3c528e7c4d539d2e553f31bf0496 (127.107.54.0:48194): Checksum: 82472867647901
T b6a2f16af1054af5ac2135d875fd16b9 P c54f418ad2d245488f429c826c8ab64f (127.107.54.5:50458): Checksum: 82472867647901

/data/10/dinesh/kudu/src/kudu/integration-tests/cluster_verifier.cc:103: Failure
Failed
Bad status: Corruption: row count 38470 is not exactly expected value 40000
/data/10/dinesh/kudu/src/kudu/integration-tests/ts_itest-base.h:473: Failure
Expected: v.CheckRowCount(kTableId, ClusterVerifier::EXACTLY, expected_result_count) doesn't generate new fatal failures in the current thread.
  Actual: it does.
/data/10/dinesh/kudu/src/kudu/integration-tests/raft_consensus-itest.cc:1000: Failure
Expected: AssertAllReplicasAgree(FLAGS_client_inserts_per_thread * FLAGS_num_client_threads) doesn't generate new fatal failures in the current thread.
  Actual: it does.
I0729 19:04:58.774780 27446 external_mini_cluster.cc:658] Killing /tmp/run_tha_testfyBxna/build/tsan/bin/kudu-master with pid 27935
I0729 19:04:58.860906 27446 external_mini_cluster.cc:658] Killing /tmp/run_tha_testfyBxna/build/tsan/bin/kudu-tserver with pid 31766
W0729 19:04:58.924994 28455 heartbeater.cc:405] Failed to heartbeat to 127.0.0.1:38591: Network error: Failed to send heartbeat: Client connection negotiation failed: client connection to 127.0.0.1:38591: connect: Connection refused (error 111)
I0729 19:04:58.927733 27446 external_mini_cluster.cc:658] Killing /tmp/run_tha_testfyBxna/build/tsan/bin/kudu-tserver with pid 31960
W0729 19:04:58.956255 30910 consensus_peers.cc:333] T b6a2f16af1054af5ac2135d875fd16b9 P f342febecdae405c835dd8942dc65b7c -> Peer 9cce3c528e7c4d539d2e553f31bf0496 (127.107.54.0:48194): Couldn't send request to peer 9cce3c528e7c4d539d2e553f31bf0496 for tablet b6a2f16af1054af5ac2135d875fd16b9. Status: Network error: Client connection negotiation failed: client connection to 127.107.54.0:48194: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 1 times.
I0729 19:04:58.974784 27446 external_mini_cluster.cc:658] Killing /tmp/run_tha_testfyBxna/build/tsan/bin/kudu-tserver with pid 30905
W0729 19:04:59.052007 31340 heartbeater.cc:405] Failed to heartbeat to 127.0.0.1:38591: Network error: Failed to send heartbeat: Client connection negotiation failed: client connection to 127.0.0.1:38591: connect: Connection refused (error 111)
I0729 19:04:59.055640 27446 external_mini_cluster.cc:658] Killing /tmp/run_tha_testfyBxna/build/tsan/bin/kudu-tserver with pid 28341
W0729 19:04:59.083106 30664 heartbeater.cc:405] Failed to heartbeat to 127.0.0.1:38591: Network error: Failed to send heartbeat: Client connection negotiation failed: client connection to 127.0.0.1:38591: connect: Connection refused (error 111)
I0729 19:04:59.119417 27446 external_mini_cluster.cc:658] Killing /tmp/run_tha_testfyBxna/build/tsan/bin/kudu-tserver with pid 31174
W0729 19:04:59.153098 28806 heartbeater.cc:405] Failed to heartbeat to 127.0.0.1:38591: Network error: Failed to send heartbeat: Client connection negotiation failed: client connection to 127.0.0.1:38591: connect: Connection refused (error 111)
I0729 19:04:59.193274 27446 external_mini_cluster.cc:658] Killing /tmp/run_tha_testfyBxna/build/tsan/bin/kudu-tserver with pid 30504
I0729 19:04:59.258599 27446 external_mini_cluster.cc:658] Killing /tmp/run_tha_testfyBxna/build/tsan/bin/kudu-tserver with pid 28691
I0729 19:04:59.320971 27446 test_util.cc:70] -----------------------------------------------
I0729 19:04:59.321200 27446 test_util.cc:71] Had fatal failures, leaving test files at /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.MultiThreadedInsertWithFailovers.1469818744551962-27446
[  FAILED  ] RaftConsensusITest.MultiThreadedInsertWithFailovers (351497 ms)

================> watchdog kicking in, although this doesn't seem to be failing the test.

Related trace 'txn':
Metrics: {"raft.queue_time_us":307,"raft.run_cpu_time_us":185,"raft.run_wall_time_us":185,"child_traces":[["txn",{"num_ops":50,"prepare.queue_time_us":273,"prepare.run_cpu_time_us":7414,"prepare.run_wall_time_us":7442}],["txn",{"num_ops":50,"prepare.queue_time_us":1430,"prepare.run_cpu_time_us":7585,"prepare.run_wall_time_us":24823,"spinlock_wait_cycles":39318272}],["txn",{"prepare.queue_time_us":26022}]]}
I0729 18:58:06.279924 22734 raft_consensus.cc:815] T 50c839cb46394fdab0b77fca859f4060 P aeaeb005d6c143eba8fd2e76ae4194d0 [term 1 FOLLOWER]: Deduplicated request from leader. Original: 0.0->[1.1-1.5]   Dedup: 1.5->[]
W0729 18:58:06.340052 22430 kernel_stack_watchdog.cc:130] Thread 22810 stuck at /data/10/dinesh/kudu/src/kudu/util/thread.cc:508 for 306ms:
Kernel stack:
[<ffffffff810dcf96>] futex_wait_queue_me+0xd6/0x150
[<ffffffff81156f55>] __alloc_pages_nodemask+0x165/0xbb0
[<ffffffff810ddfc6>] futex_wait+0x186/0x280
[<ffffffff81094cba>] atomic_notifier_call_chain+0x1a/0x20
[<ffffffff8109d272>] set_task_cpu+0xa2/0x1c0
[<ffffffff810a645b>] update_curr+0x1ab/0x1b0
[<ffffffff810dfac8>] do_futex+0x368/0xb10
[<ffffffff810a68d3>] check_preempt_wakeup+0x103/0x1d0
[<ffffffff81056caf>] kvm_clock_read+0x1f/0x30
[<ffffffff8109cfb4>] check_preempt_curr+0x84/0xa0
[<ffffffff810a0274>] wake_up_new_task+0xf4/0x1b0
[<ffffffff8118525d>] mprotect_fixup+0x15d/0x250
[<ffffffff810e03c0>] SyS_futex+0x150/0x1c0
[<ffffffff8154c279>] stub_clone+0x69/0x90
[<ffffffff8154bf0d>] system_call_fast_compare_end+0x10/0x15
[<ffffffffffffffff>] 0xffffffffffffffff

User stack:
    @           0x425fc9  __tsan::ProcessPendingSignals() at ??:0
    @           0x44c54f  pthread_create at ??:0
    @     0x7fa2cee92301  kudu::Thread::StartThread() at ??:0
    @     0x7fa2ceea5ee9  kudu::Thread::Create<>() at ??:0
    @     0x7fa2ceea278c  kudu::ThreadPool::CreateThreadUnlocked() at ??:0
    @     0x7fa2ceea31bb  kudu::ThreadPool::Submit() at ??:0
    @     0x7fa2ceea2e13  kudu::ThreadPool::SubmitFunc() at ??:0
    @     0x7fa2ceea2cd8  kudu::ThreadPool::SubmitClosure() at ??:0
    @     0x7fa2d4b7ef6d  kudu::tablet::TransactionDriver::ApplyAsync() at ??:0
    @     0x7fa2d4b7a7db  kudu::tablet::TransactionDriver::ReplicationFinished() at ??:0
    @     0x7fa2d4b71dbc  kudu::internal::RunnableAdapter<>::Run() at ??:0
    @     0x7fa2d4b71bfc  kudu::internal::InvokeHelper<>::MakeItSo() at ??:0
    @     0x7fa2d4b71b16  kudu::internal::Invoker<>::Run() at ??:0
    @     0x7fa2d587b689  kudu::Callback<>::Run() at ??:0
    @     0x7fa2d45eec79  kudu::consensus::ConsensusRound::NotifyReplicationFinished() at ??:0
    @     0x7fa2d469942e  kudu::consensus::ReplicaState::AdvanceCommittedIndexUnlocked() at ??:0
I0729 18:58:06.546285 22827 rpcz_store.cc:248] Call kudu.tserver.TabletServerService.Write from 127.0.0.1:35348

============================> Some random data race detection by raft_consensus-itest.RaftConsensusITest.TestAutomaticLeaderElection. Although this didn't seem like test specific.

W0729 18:57:58.055794 21432 kernel_stack_watchdog.cc:130] Thread 21503 stuck at /data/10/dinesh/kudu/src/kudu/util/thread.cc:508 for 321ms:
Kernel stack:
[<ffffffff8109f961>] sys_sched_yield+0x41/0x50
[<ffffffff8154bf0d>] system_call_fast_compare_end+0x10/0x15
[<ffffffffffffffff>] 0xffffffffffffffff

User stack:
    @           0x425fc9  __tsan::ProcessPendingSignals() at ??:0
    @           0x44c54f  pthread_create at ??:0
    @     0x7f1823011301  kudu::Thread::StartThread() at ??:0
    @     0x7f1823024ee9  kudu::Thread::Create<>() at ??:0
    @     0x7f182302178c  kudu::ThreadPool::CreateThreadUnlocked() at ??:0
    @     0x7f18230221bb  kudu::ThreadPool::Submit() at ??:0
    @     0x7f1823021e13  kudu::ThreadPool::SubmitFunc() at ??:0
    @     0x7f1823021cd8  kudu::ThreadPool::SubmitClosure() at ??:0
    @     0x7f18287e0a50  kudu::consensus::RaftConsensus::MarkDirty() at ??:0
    @     0x7f18287f4ef6  kudu::consensus::RaftConsensus::MarkDirtyOnSuccess() at ??:0
    @     0x7f182880b3ce  kudu::internal::RunnableAdapter<>::Run() at ??:0
    @     0x7f182880b289  kudu::internal::InvokeHelper<>::MakeItSo() at ??:0
    @     0x7f182880b1b2  kudu::internal::Invoker<>::Run() at ??:0
    @     0x7f18299fa689  kudu::Callback<>::Run() at ??:0
    @     0x7f18287fa9f0  kudu::consensus::RaftConsensus::NonTxRoundReplicationFinished() at ??:0
    @     0x7f18288093b7  kudu::internal::RunnableAdapter<>::Run() at ??:0
I0729 18:57:58.117558 19951 external_mini_cluster.cc:658] Killing /tmp/run_tha_testkyvCLE/build/tsan/bin/kudu-master with pid 20520
I0729 18:57:58.171807 19951 external_mini_cluster.cc:658] Killing /tmp/run_tha_testkyvCLE/build/tsan/bin/kudu-tserver with pid 21309
I0729 18:57:58.214403 19951 external_mini_cluster.cc:658] Killing /tmp/run_tha_testkyvCLE/build/tsan/bin/kudu-tserver with pid 20692
W0729 18:57:58.254817 20934 consensus_peers.cc:333] T 19cbc0882f244718af30f1c87c4fdc03 P 2f45c3dad4354e71ab1ed176fe1df1f8 -> Peer 131c71317237499fb49fa7d174861974 (127.77.239.0:33063): Couldn't send request to peer 131c71317237499fb49fa7d174861974 for tablet 19cbc0882f244718af30f1c87c4fdc03. Status: Network error: Client connection negotiation failed: client connection to 127.77.239.0:33063: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 1 times.
I0729 18:57:58.270571 19951 external_mini_cluster.cc:658] Killing /tmp/run_tha_testkyvCLE/build/tsan/bin/kudu-tserver with pid 21428
I0729 18:57:58.304476 19951 external_mini_cluster.cc:658] Killing /tmp/run_tha_testkyvCLE/build/tsan/bin/kudu-tserver with pid 20926
I0729 18:57:58.332816 19951 external_mini_cluster.cc:658] Killing /tmp/run_tha_testkyvCLE/build/tsan/bin/kudu-tserver with pid 21043
==================
WARNING: ThreadSanitizer: data race (pid=19951)
  Write of size 8 at 0x7d4c0000b1a0 by main thread:
    #0 pthread_cond_destroy /data/10/dinesh/kudu/thirdparty/llvm-3.8.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:1157 (raft_consensus-itest+0x0000004b8bdc)
    #1 kudu::ConditionVariable::~ConditionVariable() /data/10/dinesh/kudu/src/kudu/util/condition_variable.cc:57:12 (libkudu_util.so+0x00000018f2d8)
    #2 kudu::ThreadPool::~ThreadPool() /data/10/dinesh/kudu/src/kudu/util/threadpool.cc:132:1 (libkudu_util.so+0x0000002f031d)
    #3 kudu::DefaultDeleter<kudu::ThreadPool>::operator()(kudu::ThreadPool*) const /data/10/dinesh/kudu/src/kudu/gutil/gscoped_ptr.h:145:5 (libmaster.so+0x0000001141c6)
    #4 kudu::internal::gscoped_ptr_impl<kudu::ThreadPool, kudu::DefaultDeleter<kudu::ThreadPool> >::~gscoped_ptr_impl() /data/10/dinesh/kudu/src/kudu/gutil/gscoped_ptr.h:228:7 (libmaster.so+0x000000114155)
    #5 gscoped_ptr<kudu::ThreadPool, kudu::DefaultDeleter<kudu::ThreadPool> >::~gscoped_ptr() /data/10/dinesh/kudu/src/kudu/gutil/gscoped_ptr.h:318:7 (libmaster.so+0x0000000fbe58)
    #6 kudu::DnsResolver::~DnsResolver() /data/10/dinesh/kudu/src/kudu/util/net/dns_resolver.cc:45:1 (libkudu_util.so+0x00000028c5fc)
    #7 kudu::DefaultDeleter<kudu::DnsResolver>::operator()(kudu::DnsResolver*) const /data/10/dinesh/kudu/src/kudu/gutil/gscoped_ptr.h:145:5 (libkudu_client.so+0x0000001575a6)
    #8 kudu::internal::gscoped_ptr_impl<kudu::DnsResolver, kudu::DefaultDeleter<kudu::DnsResolver> >::reset(kudu::DnsResolver*) /data/10/dinesh/kudu/src/kudu/gutil/gscoped_ptr.h:254:7 (libkudu_client.so+0x00000015752d)
    #9 gscoped_ptr<kudu::DnsResolver, kudu::DefaultDeleter<kudu::DnsResolver> >::reset(kudu::DnsResolver*) /data/10/dinesh/kudu/src/kudu/gutil/gscoped_ptr.h:375:40 (libkudu_client.so+0x000000140228)
    #10 kudu::client::KuduClient::Data::~Data() /data/10/dinesh/kudu/src/kudu/client/client-internal.cc:270:3 (libkudu_client.so+0x000000165f05)
    #11 kudu::client::KuduClient::~KuduClient() /data/10/dinesh/kudu/src/kudu/client/client.cc:257:3 (libkudu_client.so+0x000000132b55)
    #12 std::tr1::_Sp_deleter<kudu::client::KuduClient>::operator()(kudu::client::KuduClient*) const /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/tr1/shared_ptr.h:285:41 (libkudu_client.so+0x000000155e56)
    #13 std::tr1::_Sp_counted_base_impl<kudu::client::KuduClient*, std::tr1::_Sp_deleter<kudu::client::KuduClient>, (__gnu_cxx::_Lock_policy)2>::_M_dispose() /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/tr1/shared_ptr.h:257:9 (libkudu_client.so+0x000000155c92)
    #14 std::tr1::_Sp_counted_base<(__gnu_cxx::_Lock_policy)2>::_M_release() /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/tr1/shared_ptr.h:141:6 (raft_consensus-itest+0x00000059f745)
    #15 std::tr1::__shared_count<(__gnu_cxx::_Lock_policy)2>::~__shared_count() /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/tr1/shared_ptr.h:341:4 (raft_consensus-itest+0x00000059f6b5)
    #16 std::tr1::__shared_ptr<kudu::client::KuduClient, (__gnu_cxx::_Lock_policy)2>::~__shared_ptr() /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/tr1/shared_ptr.h:541:11 (raft_consensus-itest+0x00000059f64c)
    #17 std::tr1::shared_ptr<kudu::client::KuduClient>::~shared_ptr() /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/tr1/shared_ptr.h:985:11 (raft_consensus-itest+0x00000058f028)
    #18 kudu::tserver::TabletServerIntegrationTestBase::~TabletServerIntegrationTestBase() /data/10/dinesh/kudu/src/kudu/integration-tests/ts_itest-base.h:67:7 (raft_consensus-itest+0x00000058f185)
    #19 kudu::tserver::RaftConsensusITest::~RaftConsensusITest() /data/10/dinesh/kudu/src/kudu/integration-tests/raft_consensus-itest.cc:97:7 (raft_consensus-itest+0x00000058e981)
    #20 kudu::tserver::RaftConsensusITest_TestAutomaticLeaderElection_Test::~RaftConsensusITest_TestAutomaticLeaderElection_Test() /data/10/dinesh/kudu/src/kudu/integration-tests/raft_consensus-itest.cc:1005:1 (raft_consensus-itest+0x00000058d598)
    #21 kudu::tserver::RaftConsensusITest_TestAutomaticLeaderElection_Test::~RaftConsensusITest_TestAutomaticLeaderElection_Test() /data/10/dinesh/kudu/src/kudu/integration-tests/raft_consensus-itest.cc:1005:1 (raft_consensus-itest+0x00000058d5dc)
    #22 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /data/10/dinesh/kudu/thirdparty/gmock-1.7.0/gtest/src/gtest.cc:2078:10 (libgmock.so+0x000000044939)
    #23 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /data/10/dinesh/kudu/thirdparty/gmock-1.7.0/gtest/src/gtest.cc:2114 (libgmock.so+0x000000044939)
    #24 main /data/10/dinesh/kudu/src/kudu/util/test_main.cc:48:13 (libkudu_test_main.so+0x000000001a34)

  Previous read of size 8 at 0x7d4c0000b1a0 by thread T30:
    #0 pthread_cond_signal /data/10/dinesh/kudu/thirdparty/llvm-3.8.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:1143 (raft_consensus-itest+0x0000004b8970)
    #1 kudu::ConditionVariable::Signal() /data/10/dinesh/kudu/src/kudu/util/condition_variable.cc:136:12 (libkudu_util.so+0x00000018f998)
    #2 kudu::ThreadPool::Submit(std::shared_ptr<kudu::Runnable> const&) /data/10/dinesh/kudu/src/kudu/util/threadpool.cc:239:3 (libkudu_util.so+0x0000002f1498)
    #3 kudu::ThreadPool::SubmitFunc(boost::function<void ()> const&) /data/10/dinesh/kudu/src/kudu/util/threadpool.cc:182:10 (libkudu_util.so+0x0000002f0e12)
    #4 kudu::DnsResolver::ResolveAddresses(kudu::HostPort const&, std::vector<kudu::Sockaddr, std::allocator<kudu::Sockaddr> >*, kudu::Callback<void (kudu::Status const&)> const&) /data/10/dinesh/kudu/src/kudu/util/net/dns_resolver.cc:57:14 (libkudu_util.so+0x00000028c720)
    #5 kudu::client::internal::RemoteTabletServer::InitProxy(kudu::client::KuduClient*, kudu::Callback<void (kudu::Status const&)> const&) /data/10/dinesh/kudu/src/kudu/client/meta_cache.cc:118:3 (libkudu_client.so+0x00000019b7d3)
    #6 kudu::client::internal::MetaCacheServerPicker::PickLeader(kudu::Callback<void (kudu::Status const&, kudu::client::internal::RemoteTabletServer*)> const&, kudu::MonoTime const&) /data/10/dinesh/kudu/src/kudu/client/meta_cache.cc:389:3 (libkudu_client.so+0x00000019e6d8)
    #7 kudu::rpc::RetriableRpc<kudu::client::internal::RemoteTabletServer, kudu::tserver::WriteRequestPB, kudu::tserver::WriteResponsePB>::SendRpc() /data/10/dinesh/kudu/src/kudu/rpc/retriable_rpc.h:129:3 (libkudu_client.so+0x00000011bc76)
    #8 kudu::rpc::RpcRetrier::DelayedRetryCb(kudu::rpc::Rpc*, kudu::Status const&) /data/10/dinesh/kudu/src/kudu/rpc/rpc.cc:88:5 (libkrpc.so+0x00000016290c)
    #9 boost::_mfi::mf2<void, kudu::rpc::RpcRetrier, kudu::rpc::Rpc*, kudu::Status const&>::operator()(kudu::rpc::RpcRetrier*, kudu::rpc::Rpc*, kudu::Status const&) const /data/10/dinesh/kudu/thirdparty/installed/include/boost/bind/mem_fn_template.hpp:280:29 (libkrpc.so+0x000000163ddb)
    #10 void boost::_bi::list3<boost::_bi::value<kudu::rpc::RpcRetrier*>, boost::_bi::value<kudu::rpc::Rpc*>, boost::arg<1> >::operator()<boost::_mfi::mf2<void, kudu::rpc::RpcRetrier, kudu::rpc::Rpc*, kudu::Status const&>, boost::_bi::rrlist1<kudu::Status const&> >(boost::_bi::type<void>, boost::_mfi::mf2<void, kudu::rpc::RpcRetrier, kudu::rpc::Rpc*, kudu::Status const&>&, boost::_bi::rrlist1<kudu::Status const&>&, int) /data/10/dinesh/kudu/thirdparty/installed/include/boost/bind/bind.hpp:398:9 (libkrpc.so+0x000000163c98)
    #11 void boost::_bi::bind_t<void, boost::_mfi::mf2<void, kudu::rpc::RpcRetrier, kudu::rpc::Rpc*, kudu::Status const&>, boost::_bi::list3<boost::_bi::value<kudu::rpc::RpcRetrier*>, boost::_bi::value<kudu::rpc::Rpc*>, boost::arg<1> > >::operator()<kudu::Status const&>(kudu::Status const&) /data/10/dinesh/kudu/thirdparty/installed/include/boost/bind/bind.hpp:1234:16 (libkrpc.so+0x000000163b4a)
    #12 boost::detail::function::void_function_obj_invoker1<boost::_bi::bind_t<void, boost::_mfi::mf2<void, kudu::rpc::RpcRetrier, kudu::rpc::Rpc*, kudu::Status const&>, boost::_bi::list3<boost::_bi::value<kudu::rpc::RpcRetrier*>, boost::_bi::value<kudu::rpc::Rpc*>, boost::arg<1> > >, void, kudu::Status const&>::invoke(boost::detail::function::function_buffer&, kudu::Status const&) /data/10/dinesh/kudu/thirdparty/installed/include/boost/function/function_template.hpp:159:11 (libkrpc.so+0x0000001636b9)
    #13 boost::function1<void, kudu::Status const&>::operator()(kudu::Status const&) const /data/10/dinesh/kudu/thirdparty/installed/include/boost/function/function_template.hpp:770:14 (libkrpc.so+0x00000013f08a)
    #14 kudu::rpc::DelayedTask::TimerHandler(ev::timer&, int) /data/10/dinesh/kudu/src/kudu/rpc/reactor.cc:473:5 (libkrpc.so+0x00000013b6fa)
    #15 void ev::base<ev_timer, ev::timer>::method_thunk<kudu::rpc::DelayedTask, &kudu::rpc::DelayedTask::TimerHandler>(ev_loop*, ev_timer*, int) /data/10/dinesh/kudu/thirdparty/installed/include/ev++.h:479:7 (libkrpc.so+0x0000001495bb)
    #16 ev_invoke_pending /data/10/dinesh/kudu/thirdparty/libev-4.20/ev.c:3155 (libev.so.4+0x0000000074fc)
    #17 kudu::rpc::ReactorThread::RunThread() /data/10/dinesh/kudu/src/kudu/rpc/reactor.cc:306:3 (libkrpc.so+0x0000001359dc)
    #18 boost::_mfi::mf0<void, kudu::rpc::ReactorThread>::operator()(kudu::rpc::ReactorThread*) const /data/10/dinesh/kudu/thirdparty/installed/include/boost/bind/mem_fn_template.hpp:49:29 (libkrpc.so+0x00000014513b)
    #19 void boost::_bi::list1<boost::_bi::value<kudu::rpc::ReactorThread*> >::operator()<boost::_mfi::mf0<void, kudu::rpc::ReactorThread>, boost::_bi::list0>(boost::_bi::type<void>, boost::_mfi::mf0<void, kudu::rpc::ReactorThread>&, boost::_bi::list0&, int) /data/10/dinesh/kudu/thirdparty/installed/include/boost/bind/bind.hpp:259:9 (libkrpc.so+0x000000145018)
    #20 boost::_bi::bind_t<void, boost::_mfi::mf0<void, kudu::rpc::ReactorThread>, boost::_bi::list1<boost::_bi::value<kudu::rpc::ReactorThread*> > >::operator()() /data/10/dinesh/kudu/thirdparty/installed/include/boost/bind/bind.hpp:1222:16 (libkrpc.so+0x000000144f7a)
    #21 boost::detail::function::void_function_obj_invoker0<boost::_bi::bind_t<void, boost::_mfi::mf0<void, kudu::rpc::ReactorThread>, boost::_bi::list1<boost::_bi::value<kudu::rpc::ReactorThread*> > >, void>::invoke(boost::detail::function::function_buffer&) /data/10/dinesh/kudu/thirdparty/installed/include/boost/function/function_template.hpp:159:11 (libkrpc.so+0x000000144c10)
    #22 boost::function0<void>::operator()() const /data/10/dinesh/kudu/thirdparty/installed/include/boost/function/function_template.hpp:770:14 (libkrpc.so+0x0000000ee8ea)
    #23 kudu::Thread::SuperviseThread(void*) /data/10/dinesh/kudu/src/kudu/util/thread.cc:586:3 (libkudu_util.so+0x0000002e0f99)

  As if synchronized via sleep:
    #0 nanosleep /data/10/dinesh/kudu/thirdparty/llvm-3.8.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:371 (raft_consensus-itest+0x0000004b3957)
    #1 boost::detail::yield(unsigned int) /data/10/dinesh/kudu/thirdparty/installed/include/boost/smart_ptr/detail/yield_k.hpp:151:9 (libmaster.so+0x000000139a76)
    #2 kudu::Thread::StartThread(std::string const&, std::string const&, boost::function<void ()> const&, unsigned long, scoped_refptr<kudu::Thread>*) /data/10/dinesh/kudu/src/kudu/util/thread.cc:540:7 (libkudu_util.so+0x0000002e06d5)
    #3 kudu::Status kudu::Thread::Create<void (kudu::ThreadPool::*)(bool), kudu::ThreadPool*, bool>(std::string const&, std::string const&, void (kudu::ThreadPool::* const&)(bool), kudu::ThreadPool* const&, bool const&, scoped_refptr<kudu::Thread>*) /data/10/dinesh/kudu/src/kudu/util/thread.h:162:12 (libkudu_util.so+0x0000002f3ee8)
    #4 kudu::ThreadPool::CreateThreadUnlocked() /data/10/dinesh/kudu/src/kudu/util/threadpool.cc:381:14 (libkudu_util.so+0x0000002f078b)
    #5 kudu::ThreadPool::Submit(std::shared_ptr<kudu::Runnable> const&) /data/10/dinesh/kudu/src/kudu/util/threadpool.cc:211:21 (libkudu_util.so+0x0000002f11ba)
    #6 kudu::ThreadPool::SubmitFunc(boost::function<void ()> const&) /data/10/dinesh/kudu/src/kudu/util/threadpool.cc:182:10 (libkudu_util.so+0x0000002f0e12)
    #7 kudu::DnsResolver::ResolveAddresses(kudu::HostPort const&, std::vector<kudu::Sockaddr, std::allocator<kudu::Sockaddr> >*, kudu::Callback<void (kudu::Status const&)> const&) /data/10/dinesh/kudu/src/kudu/util/net/dns_resolver.cc:57:14 (libkudu_util.so+0x00000028c720)
    #8 kudu::client::internal::RemoteTabletServer::InitProxy(kudu::client::KuduClient*, kudu::Callback<void (kudu::Status const&)> const&) /data/10/dinesh/kudu/src/kudu/client/meta_cache.cc:118:3 (libkudu_client.so+0x00000019b7d3)
    #9 kudu::client::KuduClient::Data::GetTabletServer(kudu::client::KuduClient*, scoped_refptr<kudu::client::internal::RemoteTablet> const&, kudu::client::KuduClient::ReplicaSelection, std::set<std::string, std::less<std::string>, std::allocator<std::string> > const&, std::vector<kudu::client::internal::RemoteTabletServer*, std::allocator<kudu::client::internal::RemoteTabletServer*> >*, kudu::client::internal::RemoteTabletServer**) /data/10/dinesh/kudu/src/kudu/client/client-internal.cc:351:3 (libkudu_client.so+0x000000166ed3)
    #10 kudu::client::KuduScanner::Data::OpenTablet(std::string const&, kudu::MonoTime const&, std::set<std::string, std::less<std::string>, std::allocator<std::string> >*) /data/10/dinesh/kudu/src/kudu/client/scanner-internal.cc:345:28 (libkudu_client.so+0x0000001dd81e)
    #11 kudu::client::KuduScanner::Data::OpenNextTablet(kudu::MonoTime const&, std::set<std::string, std::less<std::string>, std::allocator<std::string> >*) /data/10/dinesh/kudu/src/kudu/client/scanner-internal.cc:213:10 (libkudu_client.so+0x0000001dc761)
    #12 kudu::client::KuduScanner::Open() /data/10/dinesh/kudu/src/kudu/client/client.cc:1072:3 (libkudu_client.so+0x00000013ac98)
    #13 kudu::ClusterVerifier::DoCheckRowCount(std::string const&, kudu::ClusterVerifier::ComparisonMode, int) /data/10/dinesh/kudu/src/kudu/integration-tests/cluster_verifier.cc:119:3 (libintegration-tests.so+0x000000091a95)
    #14 kudu::ClusterVerifier::CheckRowCount(std::string const&, kudu::ClusterVerifier::ComparisonMode, int) /data/10/dinesh/kudu/src/kudu/integration-tests/cluster_verifier.cc:103:3 (libintegration-tests.so+0x000000091370)
    #15 kudu::tserver::TabletServerIntegrationTestBase::AssertAllReplicasAgree(int) /data/10/dinesh/kudu/src/kudu/integration-tests/ts_itest-base.h:473:5 (raft_consensus-itest+0x00000057a8b6)
    #16 kudu::tserver::RaftConsensusITest_TestAutomaticLeaderElection_Test::TestBody() /data/10/dinesh/kudu/src/kudu/integration-tests/raft_consensus-itest.cc:1046:3 (raft_consensus-itest+0x00000052c6f7)
    #17 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /data/10/dinesh/kudu/thirdparty/gmock-1.7.0/gtest/src/gtest.cc:2078:10 (libgmock.so+0x000000044939)
    #18 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /data/10/dinesh/kudu/thirdparty/gmock-1.7.0/gtest/src/gtest.cc:2114 (libgmock.so+0x000000044939)
    #19 main /data/10/dinesh/kudu/src/kudu/util/test_main.cc:48:13 (libkudu_test_main.so+0x000000001a34)

================== Mmmmm, may be not so interesting one:

W0729 19:05:02.906085  8280 consensus_peers.cc:333] T 711f402ed471458692610fdabce256a8 P a07659f1ae2444c5b7b6fbc9040f22ab -> Peer 08f3a26cd73e4546a012b26cbf494c7c (127.26.135.1:48804): Couldn't send request to peer 08f3a26cd73e4546a012b26cbf494c7c for tablet 711f402ed471458692610fdabce256a8. Error code: TABLET_NOT_RUNNING (12). Status: Illegal state: Tablet not RUNNING: FAILED: Corruption: Failed log replay. Reason: Debug Info: Error playing entry 2 of segment 6 of tablet 711f402ed471458692610fdabce256a8. Segment path: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.TestMasterReplacesEvictedFollowers.1469818927330810-6791/raft_consensus-itest-cluster/ts-1/wals/711f402ed471458692610fdabce256a8.recovery/wal-000000006. Entry: type: COMMIT commit { op_type: WRITE_OP commited_op_id { term: 2 index: 35 } result { ops { mutated_stores { mrs_id: 3 } } } }: CommitMsg was orphaned but it referred to stores which need replay. Commit: op_type: WRITE_OP commited_op_id { term: 2 index: 35 } result { ops { mutated_stores { mrs_id: 3 } } }. TabletMetadata: table_id: "3cc2bf30b612412f85f30331d371168d" tablet_id: "711f402ed471458692610fdabce256a8" last_durable_mrs_id: 2 rowsets { id: 3 last_durable_dms_id: -1 columns { block { id: 4023299910747499511 } column_id: 10 } columns { block { id: 1707928975668245347 } column_id: 11 } columns { block { id: 3632507944189818889 } column_id: 12 } undo_deltas { block { id: 341880068839001445 } } bloom_block { id: 4206696818985822323 } } table_name: "TestTable" schema { columns { id: 10 name: "key" type: INT32 is_key: true is_nullable: false encoding: AUTO_ENCODING compression: DEFAULT_COMPRESSION cfile_block_size: 0 } columns { id: 11 name: "int_val" type: INT32 is_key: false is_nullable: false encoding: AUTO_ENCODING compression: DEFAULT_COMPRESSION cfile_block_size: 0 } columns { id: 12 name: "string_val" type: STRING is_key: false is_nullable: true encoding: AUTO_ENCODING compression: DEFAULT_COMPRESSION cfile_block_size: 0 } } schema_version: 0 tablet_data_state: TABLET_DATA_READY partition { partition_key_start: "" partition_key_end: "" } partition_schema { range_schema { columns { id: 10 } } }. Retrying in the next heartbeat period. Already tried 60 times.
/data/10/dinesh/kudu/src/kudu/integration-tests/raft_consensus-itest.cc:2484: Failure
Failed
Bad status: Timed out: Index 2 not available on all replicas after 30.000s.
I0729 19:05:03.325995  6791 external_mini_cluster.cc:658] Killing /tmp/run_tha_test8pHEMJ/build/tsan/bin/kudu-master with pid 8218
I0729 19:05:03.351394  6791 external_mini_cluster.cc:658] Killing /tmp/run_tha_test8pHEMJ/build/tsan/bin/kudu-tserver with pid 8262
I0729 19:05:03.382586  6791 external_mini_cluster.cc:658] Killing /tmp/run_tha_test8pHEMJ/build/tsan/bin/kudu-tserver with pid 8390
I0729 19:05:03.413770  6791 external_mini_cluster.cc:658] Killing /tmp/run_tha_test8pHEMJ/build/tsan/bin/kudu-tserver with pid 8507
I0729 19:05:03.447187  6791 test_util.cc:70] -----------------------------------------------
I0729 19:05:03.447741  6791 test_util.cc:71] Had fatal failures, leaving test files at /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.TestMasterReplacesEvictedFollowers.1469818927330810-6791
[  FAILED  ] RaftConsensusITest.TestMasterReplacesEvictedFollowers (39224 ms)

============ Perhaps some more test flakiness:

==================
WARNING: ThreadSanitizer: signal-unsafe call inside of a signal (pid=21881)
    #0 operator new(unsigned long) /data/10/dinesh/kudu/thirdparty/llvm-3.8.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_new_delete.cc:45 (raft_consensus-itest+0x000000516803)
    #1 __gnu_cxx::new_allocator<char>::allocate(unsigned long, void const*) <null> (libstdc++.so.6+0x000000160f2a)
    #2 std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator<char> const&) <null> (libstdc++.so.6+0x000000160e0f)
    #3 char* std::string::_S_construct<char const*>(char const*, char const*, std::allocator<char> const&, std::forward_iterator_tag) /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/bits/basic_string.tcc:138:14 (libgutil.so+0x0000000c7b32)
    #4 char* std::string::_S_construct_aux<char const*>(char const*, char const*, std::allocator<char> const&, std::__false_type) /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/bits/basic_string.h:1772:18 (libgutil.so+0x0000000c79b8)
    #5 char* std::string::_S_construct<char const*>(char const*, char const*, std::allocator<char> const&) /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/bits/basic_string.h:1793:11 (libgutil.so+0x0000000c7958)
    #6 std::basic_string<char, std::char_traits<char>, std::allocator<char> >::basic_string(char const*, std::allocator<char> const&) <null> (libstdc++.so.6+0x000000162333)
    #7 kudu::PstackWatcher::HasProgram(char const*) /data/10/dinesh/kudu/src/kudu/util/pstack_watcher.cc:86:10 (libkudu_util.so+0x000000217603)
    #8 kudu::PstackWatcher::DumpPidStacks(int, int) /data/10/dinesh/kudu/src/kudu/util/pstack_watcher.cc:113:7 (libkudu_util.so+0x000000217c7d)
    #9 kudu::PstackWatcher::DumpStacks(int) /data/10/dinesh/kudu/src/kudu/util/pstack_watcher.cc:107:10 (libkudu_util.so+0x00000021758a)
    #10 KillTestOnTimeout(int) /data/10/dinesh/kudu/src/kudu/util/test_main.cc:72:3 (libkudu_test_main.so+0x000000001dd1)
    #11 __tsan::CallUserSignalHandler(__tsan::ThreadState*, bool, bool, bool, int, my_siginfo_t*, void*) /data/10/dinesh/kudu/thirdparty/llvm-3.8.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:1953 (raft_consensus-itest+0x00000048d1b0)
    #12 kudu::ConditionVariable::Wait() const /data/10/dinesh/kudu/src/kudu/util/condition_variable.cc:66:12 (libkudu_util.so+0x00000018f409)
    #13 kudu::CountDownLatch::Wait() const /data/10/dinesh/kudu/src/kudu/util/countdown_latch.h:74:7 (raft_consensus-itest+0x000000581388)
    #14 kudu::tserver::RaftConsensusITest_MultiThreadedInsertWithFailovers_Test::TestBody() /data/10/dinesh/kudu/src/kudu/integration-tests/raft_consensus-itest.cc:992:5 (raft_consensus-itest+0x00000052ac58)
    #15 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /data/10/dinesh/kudu/thirdparty/gmock-1.7.0/gtest/src/gtest.cc:2078:10 (libgmock.so+0x000000044939)
    #16 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /data/10/dinesh/kudu/thirdparty/gmock-1.7.0/gtest/src/gtest.cc:2114 (libgmock.so+0x000000044939)
    #17 main /data/10/dinesh/kudu/src/kudu/util/test_main.cc:48:13 (libkudu_test_main.so+0x000000001a34)

SUMMARY: ThreadSanitizer: signal-unsafe call inside of a signal /data/10/dinesh/kudu/thirdparty/llvm-3.8.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_new_delete.cc:45 in operator new(unsigned long)
==================
==================
WARNING: ThreadSanitizer: signal-unsafe call inside of a signal (pid=21881)
    #0 operator new(unsigned long) /data/10/dinesh/kudu/thirdparty/llvm-3.8.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_new_delete.cc:45 (raft_consensus-itest+0x000000516803)
    #1 __gnu_cxx::new_allocator<std::string>::allocate(unsigned long, void const*) /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/ext/new_allocator.h:104:27 (raft_consensus-itest+0x0000005af6ea)
    #2 std::allocator_traits<std::allocator<std::string> >::allocate(std::allocator<std::string>&, unsigned long) /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/bits/alloc_traits.h:357:16 (raft_consensus-itest+0x0000005af66c)
    #3 std::_Vector_base<std::string, std::allocator<std::string> >::_M_allocate(unsigned long) /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/bits/stl_vector.h:170:20 (raft_consensus-itest+0x0000005af54e)
    #4 void std::vector<std::string, std::allocator<std::string> >::_M_emplace_back_aux<std::string const&>(std::string const&) /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/bits/vector.tcc:412:22 (raft_consensus-itest+0x0000005c96a9)
    #5 std::vector<std::string, std::allocator<std::string> >::push_back(std::string const&) /data/10/dinesh/kudu/thirdparty/installed-deps-tsan/gcc/include/c++/4.9.3/bits/stl_vector.h:923:4 (raft_consensus-itest+0x000000587607)
    #6 kudu::PstackWatcher::HasProgram(char const*) /data/10/dinesh/kudu/src/kudu/util/pstack_watcher.cc:88:3 (libkudu_util.so+0x000000217631)
    #7 kudu::PstackWatcher::DumpPidStacks(int, int) /data/10/dinesh/kudu/src/kudu/util/pstack_watcher.cc:113:7 (libkudu_util.so+0x000000217c7d)
    #8 kudu::PstackWatcher::DumpStacks(int) /data/10/dinesh/kudu/src/kudu/util/pstack_watcher.cc:107:10 (libkudu_util.so+0x00000021758a)
    #9 KillTestOnTimeout(int) /data/10/dinesh/kudu/src/kudu/util/test_main.cc:72:3 (libkudu_test_main.so+0x000000001dd1)
    #10 __tsan::CallUserSignalHandler(__tsan::ThreadState*, bool, bool, bool, int, my_siginfo_t*, void*) /data/10/dinesh/kudu/thirdparty/llvm-3.8.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors.cc:1953 (raft_consensus-itest+0x00000048d1b0)
    #11 kudu::ConditionVariable::Wait() const /data/10/dinesh/kudu/src/kudu/util/condition_variable.cc:66:12 (libkudu_util.so+0x00000018f409)
    #12 kudu::CountDownLatch::Wait() const /data/10/dinesh/kudu/src/kudu/util/countdown_latch.h:74:7 (raft_consensus-itest+0x000000581388)
    #13 kudu::tserver::RaftConsensusITest_MultiThreadedInsertWithFailovers_Test::TestBody() /data/10/dinesh/kudu/src/kudu/integration-tests/raft_consensus-itest.cc:992:5 (raft_consensus-itest+0x00000052ac58)
    #14 void testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /data/10/dinesh/kudu/thirdparty/gmock-1.7.0/gtest/src/gtest.cc:2078:10 (libgmock.so+0x000000044939)
    #15 void testing::internal::HandleExceptionsInMethodIfSupported<testing::Test, void>(testing::Test*, void (testing::Test::*)(), char const*) /data/10/dinesh/kudu/thirdparty/gmock-1.7.0/gtest/src/gtest.cc:2114 (libgmock.so+0x000000044939)
    #16 main /data/10/dinesh/kudu/src/kudu/util/test_main.cc:48:13 (libkudu_test_main.so+0x000000001a34)

SUMMARY: ThreadSanitizer: signal-unsafe call inside of a signal /data/10/dinesh/kudu/thirdparty/llvm-3.8.0.src/projects/compiler-rt/lib/tsan/rtl/tsan_new_delete.cc:45 in operator new(unsigned long)

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending

dist-test-results-1548.tar.gz
05/Aug/16 18:04
9.43 MB
Dinesh Bhat

Issue Links

is related to

KUDU-2059 Data race in DnsResolver

Open

Activity

People

Assignee:: Unassigned

Reporter:: Dinesh Bhat

Votes:: 0 Vote for this issue

Watchers:: 4 Start watching this issue

Dates

Created:: 30/Jul/16 01:19

Updated:: 30/Jun/17 06:31