[
https://issues.apache.org/jira/browse/KUDU-2361?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Todd Lipcon reassigned KUDU-2361:
---------------------------------
Assignee: Todd Lipcon
> MasterTest.TestDumpStacksOnRpcQueueOverflow fails in TSAN mode with stress
> --------------------------------------------------------------------------
>
> Key: KUDU-2361
> URL: https://issues.apache.org/jira/browse/KUDU-2361
> Project: Kudu
> Issue Type: Bug
> Components: test
> Affects Versions: 1.7.0
> Reporter: Adar Dembo
> Assignee: Todd Lipcon
> Priority: Major
>
> I noticed this in a full test run in TSAN mode on Ubuntu 16, and was able to
> repro by passing --stress_cpu_threads=8 (I have 8 cores on my machine)
> locally.
> Test output:
> {noformat}
> Note: Google Test filter = *TestDumpStacksOnRpcQueueOverflow*
> [==========] Running 1 test from 1 test case.
> [----------] Global test environment set-up.
> [----------] 1 test from MasterTest
> [ RUN ] MasterTest.TestDumpStacksOnRpcQueueOverflow
> I0320 12:28:58.121057 439 system_ntp.cc:143] NTP initialized. Skew: 500ppm
> Current error: 73757us
> I0320 12:28:58.121695 439 fs_manager.cc:260] Metadata directory not provided
> I0320 12:28:58.121868 439 fs_manager.cc:266] Using write-ahead log
> directory (fs_wal_dir) as metadata directory
> I0320 12:28:58.122126 439 server_base.cc:434] Could not load existing FS
> layout: Not found:
> /tmp/kudutest-1000/master-test.MasterTest.TestDumpStacksOnRpcQueueOverflow.1521574137899614-439/Master/instance:
> No such file or directory (error 2)
> I0320 12:28:58.122280 439 server_base.cc:435] Attempting to create new FS
> layout instead
> I0320 12:28:58.139992 439 fs_manager.cc:595] Generated new instance
> metadata in path
> /tmp/kudutest-1000/master-test.MasterTest.TestDumpStacksOnRpcQueueOverflow.1521574137899614-439/Master/instance:
> uuid: "55f12dd184874ef1906983634a1dda96"
> format_stamp: "Formatted at 2018-03-20 19:28:58 on adar-ThinkPad-T540p"
> I0320 12:28:58.167023 439 fs_manager.cc:495] Time spent creating directory
> manager: real 0.026s user 0.012s sys 0.012s
> I0320 12:28:58.168340 439 env_posix.cc:1624] Raising this process' open
> files per process limit from 1024 to 1048576
> I0320 12:28:58.168772 439 file_cache.cc:470] Constructed file cache lbm
> with capacity 419430
> I0320 12:28:58.204406 439 fs_manager.cc:417] Time spent opening block
> manager: real 0.019s user 0.000s sys 0.008s
> I0320 12:28:58.204677 439 fs_manager.cc:428] Opened local filesystem:
> /tmp/kudutest-1000/master-test.MasterTest.TestDumpStacksOnRpcQueueOverflow.1521574137899614-439/Master
> uuid: "55f12dd184874ef1906983634a1dda96"
> format_stamp: "Formatted at 2018-03-20 19:28:58 on adar-ThinkPad-T540p"
> I0320 12:28:58.205045 439 fs_report.cc:347] Block manager report
> --------------------
> 1 data directories:
> /tmp/kudutest-1000/master-test.MasterTest.TestDumpStacksOnRpcQueueOverflow.1521574137899614-439/Master/data
> Total live blocks: 0
> Total live bytes: 0
> Total live bytes (after alignment): 0
> Total number of LBM containers: 0 (0 full)
> Did not check for missing blocks
> Did not check for orphaned blocks
> Total full LBM containers with extra space: 0 (0 repaired)
> Total full LBM container extra space in bytes: 0 (0 repaired)
> Total incomplete LBM containers: 0 (0 repaired)
> Total LBM partial records: 0 (0 repaired)
> W0320 12:28:59.004899 439 thread.cc:559] rpc reactor (reactor) Time spent
> creating pthread: real 0.687s user 0.000s sys 0.008s
> W0320 12:28:59.005123 439 thread.cc:526] rpc reactor (reactor) Time spent
> starting thread: real 0.687s user 0.000s sys 0.008s
> I0320 12:28:59.151173 439 env_posix.cc:1629] Not raising this process'
> running threads per effective uid limit of 63233; it is already as high as it
> can go
> I0320 12:28:59.174991 467 process_memory.cc:182] Process hard memory limit
> is 12.441025 GB
> I0320 12:28:59.175251 467 process_memory.cc:184] Process soft memory limit
> is 9.952820 GB
> I0320 12:28:59.175415 467 process_memory.cc:187] Process memory pressure
> threshold is 7.464615 GB
> I0320 12:28:59.831009 439 rpc_server.cc:201] RPC server started. Bound to:
> 127.0.0.1:44269
> I0320 12:28:59.947118 439 webserver.cc:173] Starting webserver on
> 127.0.0.1:0
> I0320 12:28:59.947260 439 webserver.cc:184] Document root disabled
> I0320 12:28:59.970778 439 webserver.cc:311] Webserver started. Bound to:
> http://127.0.0.1:35093/
> I0320 12:28:59.984550 513 data_dirs.cc:931] Could only allocate 1 dirs of
> requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs
> full, 0 dirs failed
> I0320 12:29:00.052474 513 tablet_bootstrap.cc:436] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96:
> Bootstrap starting.
> I0320 12:29:00.055348 513 tablet_bootstrap.cc:581] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96: No
> blocks or log segments found. Creating new log.
> I0320 12:29:00.056701 513 log.cc:520] T 00000000000000000000000000000000 P
> 55f12dd184874ef1906983634a1dda96: Log is configured to *not* fsync() on all
> Append() calls
> I0320 12:29:00.074784 513 tablet_bootstrap.cc:436] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96: No
> bootstrap required, opened a new log
> I0320 12:29:00.111340 513 raft_consensus.cc:304] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 0
> FOLLOWER]: Replica starting. Triggering 0 pending transactions. Active
> config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid:
> "55f12dd184874ef1906983634a1dda96" member_type: VOTER }
> I0320 12:29:00.111927 513 raft_consensus.cc:330] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 0
> FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a
> prompt election more likely
> I0320 12:29:00.112182 513 raft_consensus.cc:605] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 0
> FOLLOWER]: Becoming Follower/Learner. State: Replica:
> 55f12dd184874ef1906983634a1dda96, State: Initialized, Role: FOLLOWER
> I0320 12:29:00.113060 513 consensus_queue.cc:226] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0,
> Majority replicated index: 0, Committed index: 0, Last appended: 0.0, Last
> appended by leader: 0, Current term: 0, Majority size: -1, State: 0, Mode:
> NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers {
> permanent_uuid: "55f12dd184874ef1906983634a1dda96" member_type: VOTER }
> I0320 12:29:00.113554 513 raft_consensus.cc:344] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 0
> FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
> I0320 12:29:00.113808 513 raft_consensus.cc:436] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 0
> FOLLOWER]: Starting leader election (initial election of a single-replica
> configuration)
> I0320 12:29:00.114053 513 raft_consensus.cc:2700] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96: Snoozing
> failure detection for 2.020s (starting election)
> I0320 12:29:00.114297 513 raft_consensus.cc:2752] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 0
> FOLLOWER]: Advancing to term 1
> I0320 12:29:00.118088 513 raft_consensus.cc:458] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 1
> FOLLOWER]: Starting leader election with config: opid_index: -1
> OBSOLETE_local: true peers { permanent_uuid:
> "55f12dd184874ef1906983634a1dda96" member_type: VOTER }
> I0320 12:29:00.118873 513 leader_election.cc:258] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [CANDIDATE]: Term 1 election: Election decided. Result: candidate won.
> I0320 12:29:00.143113 515 raft_consensus.cc:2700] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96: Snoozing
> failure detection for 1.623s (election complete)
> I0320 12:29:00.143416 515 raft_consensus.cc:2507] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 1
> FOLLOWER]: Leader election won for term 1
> I0320 12:29:00.174619 515 raft_consensus.cc:572] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 1
> LEADER]: Becoming Leader. State: Replica: 55f12dd184874ef1906983634a1dda96,
> State: Running, Role: LEADER
> I0320 12:29:00.175150 515 consensus_queue.cc:203] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [LEADER]:
> Queue going to LEADER mode. State: All replicated index: 0, Majority
> replicated index: 0, Committed index: 0, Last appended: 0.0, Last appended by
> leader: 0, Current term: 1, Majority size: 1, State: 0, Mode: LEADER, active
> raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid:
> "55f12dd184874ef1906983634a1dda96" member_type: VOTER }
> I0320 12:29:00.195482 517 sys_catalog.cc:335] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: SysCatalogTable state changed. Reason: New leader
> 55f12dd184874ef1906983634a1dda96. Latest consensus state: current_term: 1
> leader_uuid: "55f12dd184874ef1906983634a1dda96" committed_config {
> opid_index: -1 OBSOLETE_local: true peers { permanent_uuid:
> "55f12dd184874ef1906983634a1dda96" member_type: VOTER } }
> I0320 12:29:00.195924 517 sys_catalog.cc:338] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: This master's current role is: LEADER
> I0320 12:29:00.195751 513 sys_catalog.cc:335] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: SysCatalogTable state changed. Reason: Started TabletReplica.
> Latest consensus state: current_term: 1 leader_uuid:
> "55f12dd184874ef1906983634a1dda96" committed_config { opid_index: -1
> OBSOLETE_local: true peers { permanent_uuid:
> "55f12dd184874ef1906983634a1dda96" member_type: VOTER } }
> I0320 12:29:00.195516 516 sys_catalog.cc:335] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started.
> Latest consensus state: current_term: 1 leader_uuid:
> "55f12dd184874ef1906983634a1dda96" committed_config { opid_index: -1
> OBSOLETE_local: true peers { permanent_uuid:
> "55f12dd184874ef1906983634a1dda96" member_type: VOTER } }
> I0320 12:29:00.196521 516 sys_catalog.cc:338] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: This master's current role is: LEADER
> I0320 12:29:00.196115 513 sys_catalog.cc:338] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: This master's current role is: LEADER
> I0320 12:29:00.203620 513 sys_catalog.cc:422] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: configured and running, proceeding with master startup.
> W0320 12:29:00.267588 522 catalog_manager.cc:1018] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96:
> acquiring CA information for follower catalog manager: Not found: root CA
> entry not found
> W0320 12:29:00.267813 522 catalog_manager.cc:560] Not found: root CA entry
> not found: failed to prepare follower catalog manager, will retry
> I0320 12:29:00.268275 521 catalog_manager.cc:972] Loading table and tablet
> metadata into memory...
> I0320 12:29:00.270922 521 catalog_manager.cc:983] Initializing Kudu
> internal certificate authority...
> W0320 12:29:00.426303 467 tablet.cc:1679] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96: Can't
> schedule compaction. Clean time has not been advanced past its initial value.
> I0320 12:29:00.515857 521 catalog_manager.cc:870] Generated new certificate
> authority record
> I0320 12:29:00.518018 521 catalog_manager.cc:992] Loading token signing
> keys...
> I0320 12:29:00.546751 521 catalog_manager.cc:3871] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96:
> Generated new TSK 0
> I0320 12:29:00.827468 439 master.cc:225] Master@127.0.0.1:44269 shutting
> down...
> I0320 12:29:01.020676 439 raft_consensus.cc:2012] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 1
> LEADER]: Raft consensus shutting down.
> I0320 12:29:01.021024 439 raft_consensus.cc:2039] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 1
> FOLLOWER]: Raft consensus is shut down!
> I0320 12:29:01.021750 439 tablet_replica.cc:262] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96: stopping
> tablet replica
> I0320 12:29:01.021996 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> CompactRowSetsOp(00000000000000000000000000000000)
> I0320 12:29:01.022163 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> MinorDeltaCompactionOp(00000000000000000000000000000000)
> I0320 12:29:01.022305 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> MajorDeltaCompactionOp(00000000000000000000000000000000)
> I0320 12:29:01.022439 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> UndoDeltaBlockGCOp(00000000000000000000000000000000)
> I0320 12:29:01.022673 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> FlushMRSOp(00000000000000000000000000000000)
> I0320 12:29:01.022807 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> FlushDeltaMemStoresOp(00000000000000000000000000000000)
> I0320 12:29:01.022928 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> LogGCOp(00000000000000000000000000000000)
> I0320 12:29:01.134024 439 master.cc:236] Master@127.0.0.1:44269 shutdown
> complete.
> I0320 12:29:01.171110 439 system_ntp.cc:143] NTP initialized. Skew: 500ppm
> Current error: 75257us
> I0320 12:29:01.171545 439 fs_manager.cc:260] Metadata directory not provided
> I0320 12:29:01.171741 439 fs_manager.cc:263] Using existing metadata
> directory in first data directory
> I0320 12:29:01.179345 439 fs_manager.cc:397] Time spent opening directory
> manager: real 0.007s user 0.000s sys 0.008s
> I0320 12:29:01.180353 439 file_cache.cc:470] Constructed file cache lbm
> with capacity 419430
> I0320 12:29:01.203125 439 fs_manager.cc:417] Time spent opening block
> manager: real 0.015s user 0.000s sys 0.000s
> I0320 12:29:01.203403 439 fs_manager.cc:428] Opened local filesystem:
> /tmp/kudutest-1000/master-test.MasterTest.TestDumpStacksOnRpcQueueOverflow.1521574137899614-439/Master
> uuid: "55f12dd184874ef1906983634a1dda96"
> format_stamp: "Formatted at 2018-03-20 19:28:58 on adar-ThinkPad-T540p"
> I0320 12:29:01.203735 439 fs_report.cc:347] Block manager report
> --------------------
> 1 data directories:
> /tmp/kudutest-1000/master-test.MasterTest.TestDumpStacksOnRpcQueueOverflow.1521574137899614-439/Master/data
> Total live blocks: 0
> Total live bytes: 0
> Total live bytes (after alignment): 0
> Total number of LBM containers: 0 (0 full)
> Did not check for missing blocks
> Did not check for orphaned blocks
> Total full LBM containers with extra space: 0 (0 repaired)
> Total full LBM container extra space in bytes: 0 (0 repaired)
> Total incomplete LBM containers: 0 (0 repaired)
> Total LBM partial records: 0 (0 repaired)
> I0320 12:29:01.518903 439 rpc_server.cc:201] RPC server started. Bound to:
> 127.0.0.1:44269
> I0320 12:29:01.519835 439 webserver.cc:173] Starting webserver on
> 127.0.0.1:35093
> I0320 12:29:01.519968 439 webserver.cc:184] Document root disabled
> I0320 12:29:01.535214 439 webserver.cc:311] Webserver started. Bound to:
> http://127.0.0.1:35093/
> I0320 12:29:01.567597 549 tablet_bootstrap.cc:436] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96:
> Bootstrap starting.
> I0320 12:29:01.611582 549 tablet_bootstrap.cc:436] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96:
> Bootstrap replayed 1/1 log segments. Stats: ops{read=4 overwritten=0
> applied=4 ignored=1} inserts{seen=2 ignored=0} mutations{seen=0 ignored=0}
> orphaned_commits=0. Pending: 0 replicates
> I0320 12:29:01.612310 549 tablet_bootstrap.cc:436] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96:
> Bootstrap complete.
> I0320 12:29:01.613600 549 raft_consensus.cc:304] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 1
> FOLLOWER]: Replica starting. Triggering 0 pending transactions. Active
> config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid:
> "55f12dd184874ef1906983634a1dda96" member_type: VOTER }
> I0320 12:29:01.613976 549 raft_consensus.cc:605] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 1
> FOLLOWER]: Becoming Follower/Learner. State: Replica:
> 55f12dd184874ef1906983634a1dda96, State: Initialized, Role: FOLLOWER
> I0320 12:29:01.614390 549 consensus_queue.cc:226] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0,
> Majority replicated index: 0, Committed index: 4, Last appended: 1.4, Last
> appended by leader: 4, Current term: 0, Majority size: -1, State: 0, Mode:
> NON_LEADER, active raft config: opid_index: -1 OBSOLETE_local: true peers {
> permanent_uuid: "55f12dd184874ef1906983634a1dda96" member_type: VOTER }
> I0320 12:29:01.614800 549 raft_consensus.cc:344] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 1
> FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
> I0320 12:29:01.614998 549 raft_consensus.cc:436] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 1
> FOLLOWER]: Starting leader election (initial election of a single-replica
> configuration)
> I0320 12:29:01.619002 549 raft_consensus.cc:2700] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96: Snoozing
> failure detection for 1.502s (starting election)
> I0320 12:29:01.619308 549 raft_consensus.cc:2752] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 1
> FOLLOWER]: Advancing to term 2
> I0320 12:29:01.625046 549 raft_consensus.cc:458] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 2
> FOLLOWER]: Starting leader election with config: opid_index: -1
> OBSOLETE_local: true peers { permanent_uuid:
> "55f12dd184874ef1906983634a1dda96" member_type: VOTER }
> I0320 12:29:01.629127 549 leader_election.cc:258] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [CANDIDATE]: Term 2 election: Election decided. Result: candidate won.
> I0320 12:29:01.637392 551 raft_consensus.cc:2700] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96: Snoozing
> failure detection for 1.879s (election complete)
> I0320 12:29:01.637658 551 raft_consensus.cc:2507] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 2
> FOLLOWER]: Leader election won for term 2
> I0320 12:29:01.657527 551 raft_consensus.cc:572] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 2
> LEADER]: Becoming Leader. State: Replica: 55f12dd184874ef1906983634a1dda96,
> State: Running, Role: LEADER
> I0320 12:29:01.657930 551 consensus_queue.cc:203] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [LEADER]:
> Queue going to LEADER mode. State: All replicated index: 0, Majority
> replicated index: 4, Committed index: 4, Last appended: 1.4, Last appended by
> leader: 4, Current term: 2, Majority size: 1, State: 0, Mode: LEADER, active
> raft config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid:
> "55f12dd184874ef1906983634a1dda96" member_type: VOTER }
> I0320 12:29:01.672679 553 sys_catalog.cc:335] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started.
> Latest consensus state: current_term: 2 leader_uuid:
> "55f12dd184874ef1906983634a1dda96" committed_config { opid_index: -1
> OBSOLETE_local: true peers { permanent_uuid:
> "55f12dd184874ef1906983634a1dda96" member_type: VOTER } }
> I0320 12:29:01.672747 549 sys_catalog.cc:335] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: SysCatalogTable state changed. Reason: Started TabletReplica.
> Latest consensus state: current_term: 2 leader_uuid:
> "55f12dd184874ef1906983634a1dda96" committed_config { opid_index: -1
> OBSOLETE_local: true peers { permanent_uuid:
> "55f12dd184874ef1906983634a1dda96" member_type: VOTER } }
> I0320 12:29:01.673079 553 sys_catalog.cc:338] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: This master's current role is: LEADER
> I0320 12:29:01.673100 549 sys_catalog.cc:338] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: This master's current role is: LEADER
> I0320 12:29:01.678683 555 sys_catalog.cc:335] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: SysCatalogTable state changed. Reason: New leader
> 55f12dd184874ef1906983634a1dda96. Latest consensus state: current_term: 2
> leader_uuid: "55f12dd184874ef1906983634a1dda96" committed_config {
> opid_index: -1 OBSOLETE_local: true peers { permanent_uuid:
> "55f12dd184874ef1906983634a1dda96" member_type: VOTER } }
> I0320 12:29:01.681085 555 sys_catalog.cc:338] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: This master's current role is: LEADER
> I0320 12:29:01.681375 549 sys_catalog.cc:422] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96
> [sys.catalog]: configured and running, proceeding with master startup.
> I0320 12:29:01.716922 558 catalog_manager.cc:502] Waiting for catalog
> manager background task thread to start: Service unavailable: Catalog manager
> is not initialized. State: 1
> I0320 12:29:01.726768 559 catalog_manager.cc:972] Loading table and tablet
> metadata into memory...
> I0320 12:29:01.729962 559 catalog_manager.cc:983] Initializing Kudu
> internal certificate authority...
> I0320 12:29:01.734299 559 catalog_manager.cc:992] Loading token signing
> keys...
> I0320 12:29:01.738445 559 catalog_manager.cc:3882] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96: Loaded
> TSK: 0
> W0320 12:29:01.879313 533 service_pool.cc:130] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items.
> I0320 12:29:01.879936 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.897538 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.898228 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.899801 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.900344 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.901034 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.901525 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.902161 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.903232 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.904125 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.904739 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.906430 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.907002 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.907941 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.908489 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.909440 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.909982 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> I0320 12:29:01.923619 533 service_pool.cc:133] GetTableLocations request on
> kudu.master.MasterService from 127.0.0.1:35832 dropped due to backpressure.
> The service queue is full; it has 1 items. Contents of service queue:
> Call kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832
> (request call id 2)
> W0320 12:29:02.895246 537 debug-util.cc:396] Leaking SignalData structure
> 0x7b080007a100 after lost signal to thread 442
> W0320 12:29:02.895696 537 debug-util.cc:396] Leaking SignalData structure
> 0x7b0800067f00 after lost signal to thread 546
> I0320 12:29:02.895265 542 rpcz_store.cc:265] Call
> kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832 (request
> call id 1) took 1017ms. Request Metrics: {}
> I0320 12:29:03.911542 542 rpcz_store.cc:265] Call
> kudu.master.MasterService.GetTableLocations from 127.0.0.1:35832 (request
> call id 2) took 2033ms. Request Metrics: {}
> ../../src/kudu/master/master-test.cc:843: Failure
> Expected: dump_count
> Which is: 0
> To be equal to: 1
> I0320 12:29:03.913710 439 master.cc:225] Master@127.0.0.1:44269 shutting
> down...
> I0320 12:29:03.916647 439 raft_consensus.cc:2012] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 2
> LEADER]: Raft consensus shutting down.
> I0320 12:29:03.916927 439 raft_consensus.cc:2039] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96 [term 2
> FOLLOWER]: Raft consensus is shut down!
> I0320 12:29:03.917110 439 tablet_replica.cc:262] T
> 00000000000000000000000000000000 P 55f12dd184874ef1906983634a1dda96: stopping
> tablet replica
> I0320 12:29:03.917285 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> CompactRowSetsOp(00000000000000000000000000000000)
> I0320 12:29:03.917426 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> MinorDeltaCompactionOp(00000000000000000000000000000000)
> I0320 12:29:03.917557 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> MajorDeltaCompactionOp(00000000000000000000000000000000)
> I0320 12:29:03.917688 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> UndoDeltaBlockGCOp(00000000000000000000000000000000)
> I0320 12:29:03.917836 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> FlushMRSOp(00000000000000000000000000000000)
> I0320 12:29:03.917964 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> FlushDeltaMemStoresOp(00000000000000000000000000000000)
> I0320 12:29:03.918082 439 maintenance_manager.cc:235] P
> 55f12dd184874ef1906983634a1dda96: Unregistered op
> LogGCOp(00000000000000000000000000000000)
> I0320 12:29:04.307595 439 master.cc:236] Master@127.0.0.1:44269 shutdown
> complete.
> I0320 12:29:04.320631 439 test_util.cc:119]
> -----------------------------------------------
> I0320 12:29:04.320791 439 test_util.cc:120] Had fatal failures, leaving
> test files at
> /tmp/kudutest-1000/master-test.MasterTest.TestDumpStacksOnRpcQueueOverflow.1521574137899614-439
> [ FAILED ] MasterTest.TestDumpStacksOnRpcQueueOverflow (6288 ms)
> [----------] 1 test from MasterTest (6288 ms total)
> [----------] Global test environment tear-down
> [==========] 1 test from 1 test case ran. (6289 ms total)
> [ PASSED ] 0 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] MasterTest.TestDumpStacksOnRpcQueueOverflow
> 1 FAILED TEST
> {noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
