You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@kudu.apache.org by "Adar Dembo (JIRA)" <ji...@apache.org> on 2018/03/20 19:32:00 UTC
[jira] [Created] (KUDU-2361)
MasterTest.TestDumpStacksOnRpcQueueOverflow fails in TSAN mode with stress
Adar Dembo created KUDU-2361:
--------------------------------
Summary: 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
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)