Skip to content

Instantly share code, notes, and snippets.

@adembo
Created January 9, 2018 20:22
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save adembo/3b28823884b457f0c4019e9e17a0ab6a to your computer and use it in GitHub Desktop.
Save adembo/3b28823884b457f0c4019e9e17a0ab6a to your computer and use it in GitHub Desktop.
[ RUN ] RaftConsensusITest.Test_KUDU_1735
I0108 19:23:49.615342 20653 test_util.cc:192] Using random seed: 1904123628
I0108 19:23:49.615870 20653 ts_itest-base.cc:113] Starting cluster with:
I0108 19:23:49.615878 20653 ts_itest-base.cc:114] --------------
I0108 19:23:49.615880 20653 ts_itest-base.cc:115] 3 tablet servers
I0108 19:23:49.615883 20653 ts_itest-base.cc:116] 3 replicas per TS
I0108 19:23:49.615885 20653 ts_itest-base.cc:117] --------------
I0108 19:23:49.616251 20653 external_mini_cluster.cc:782] Running /home/adar/Source/kudu/build/debug/bin/kudu-master
/home/adar/Source/kudu/build/debug/bin/kudu-master
--fs_wal_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/wal
--fs_data_dirs=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/data
--block_manager=log
--webserver_interface=localhost
--ipki_ca_key_size=1024
--tsk_num_rsa_bits=512
--rpc_bind_addresses=127.20.43.126:0
--webserver_interface=127.20.43.126
--webserver_port=0
--never_fsync
--ipki_server_key_size=1024
--enable_minidumps=false
--redact=none
--metrics_log_interval_ms=1000
--logtostderr
--logbuflevel=-1
--log_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/logs
--server_dump_info_path=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/data/info.pb
--server_dump_info_format=pb
--rpc_server_allow_ephemeral_ports
--unlock_experimental_flags
--unlock_unsafe_flags
--catalog_manager_wait_for_new_tablets_to_elect_leader=false with env {}
WARNING: Logging before InitGoogleLogging() is written to STDERR
W0108 19:23:49.644559 4510 flags.cc:392] Enabled unsafe flag: --rpc_server_allow_ephemeral_ports=true
W0108 19:23:49.644644 4510 flags.cc:392] Enabled unsafe flag: --never_fsync=true
W0108 19:23:49.645516 4510 flags.cc:392] Enabled experimental flag: --ipki_ca_key_size=1024
W0108 19:23:49.645526 4510 flags.cc:392] Enabled experimental flag: --ipki_server_key_size=1024
W0108 19:23:49.645532 4510 flags.cc:392] Enabled experimental flag: --tsk_num_rsa_bits=512
I0108 19:23:49.646723 4510 master_main.cc:66] Master server non-default flags:
--fs_data_dirs=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/data
--fs_wal_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/wal
--catalog_manager_wait_for_new_tablets_to_elect_leader=false
--ipki_ca_key_size=1024
--ipki_server_key_size=1024
--tsk_num_rsa_bits=512
--rpc_bind_addresses=127.20.43.126:0
--rpc_server_allow_ephemeral_ports=true
--metrics_log_interval_ms=1000
--server_dump_info_format=pb
--server_dump_info_path=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/data/info.pb
--webserver_interface=127.20.43.126
--webserver_port=0
--never_fsync=true
--heap_profile_path=/tmp/kudu-master.4510
--redact=none
--unlock_experimental_flags=true
--unlock_unsafe_flags=true
--enable_minidumps=false
--log_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/logs
--logbuflevel=-1
--logtostderr=true
Master server version:
kudu 1.7.0-SNAPSHOT
revision d17699f411b8c276b8aa77b0f85678b5507d9701
build type DEBUG
built by adar at 08 Jan 2018 19:11:05 PST on adar-ThinkPad-T540p
I0108 19:23:49.649690 4510 master_main.cc:73] Initializing master server...
I0108 19:23:49.649971 4510 system_ntp.cc:143] NTP initialized. Skew: 500ppm Current error: 97923us
I0108 19:23:49.650532 4510 server_base.cc:430] Could not load existing FS layout: Not found: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/data/instance: No such file or directory (error 2)
I0108 19:23:49.650543 4510 server_base.cc:431] Creating new FS layout
I0108 19:23:49.652673 4510 fs_manager.cc:564] Generated new instance metadata in path /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/data/instance:
uuid: "934158dd8ba0430c9f93330ed9667ab8"
format_stamp: "Formatted at 2018-01-09 03:23:49 on adar-ThinkPad-T540p"
I0108 19:23:49.652798 4510 fs_manager.cc:564] Generated new instance metadata in path /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/wal/instance:
uuid: "934158dd8ba0430c9f93330ed9667ab8"
format_stamp: "Formatted at 2018-01-09 03:23:49 on adar-ThinkPad-T540p"
I0108 19:23:49.656039 4510 fs_manager.cc:468] Time spent creating directory manager: real 0.003s user 0.004s sys 0.000s
I0108 19:23:49.656342 4510 env_posix.cc:1596] Not raising process file limit of 1048576; it is already as high as it can go
I0108 19:23:49.656415 4510 file_cache.cc:470] Constructed file cache lbm with capacity 419430
I0108 19:23:49.658530 4510 fs_manager.cc:381] Time spent opening block manager: real 0.001s user 0.000s sys 0.000s
I0108 19:23:49.658604 4510 fs_manager.cc:401] Opened local filesystem: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/data,/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/wal
uuid: "934158dd8ba0430c9f93330ed9667ab8"
format_stamp: "Formatted at 2018-01-09 03:23:49 on adar-ThinkPad-T540p"
I0108 19:23:49.658646 4510 fs_report.cc:347] Block manager report
--------------------
1 data directories: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/data/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)
I0108 19:23:49.684454 4510 master_main.cc:76] Starting Master server...
I0108 19:23:49.684613 4527 process_memory.cc:180] Process hard memory limit is 12.441098 GB
I0108 19:23:49.684641 4527 process_memory.cc:182] Process soft memory limit is 9.952878 GB
I0108 19:23:49.684646 4527 process_memory.cc:185] Process memory pressure threshold is 7.464659 GB
I0108 19:23:49.687853 4510 rpc_server.cc:192] RPC server started. Bound to: 127.20.43.126:33196
I0108 19:23:49.688104 4510 webserver.cc:173] Starting webserver on 127.20.43.126:0
I0108 19:23:49.688112 4510 webserver.cc:184] Document root disabled
I0108 19:23:49.688375 4510 webserver.cc:311] Webserver started. Bound to: http://127.20.43.126:39882/
I0108 19:23:49.688663 4510 server_base.cc:585] Dumped server information to /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/master-0/data/info.pb
I0108 19:23:49.689065 20653 external_mini_cluster.cc:844] Started /home/adar/Source/kudu/build/debug/bin/kudu-master as pid 4510
I0108 19:23:49.689280 20653 external_mini_cluster.cc:782] Running /home/adar/Source/kudu/build/debug/bin/kudu-tserver
/home/adar/Source/kudu/build/debug/bin/kudu-tserver
--fs_wal_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/wal
--fs_data_dirs=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/data
--block_manager=log
--rpc_bind_addresses=127.20.43.65:0
--local_ip_for_outbound_sockets=127.20.43.65
--webserver_interface=127.20.43.65
--webserver_port=0
--tserver_master_addrs=127.20.43.126:33196
--never_fsync
--ipki_server_key_size=1024
--enable_minidumps=false
--redact=none
--metrics_log_interval_ms=1000
--logtostderr
--logbuflevel=-1
--log_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/logs
--server_dump_info_path=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/data/info.pb
--server_dump_info_format=pb
--rpc_server_allow_ephemeral_ports
--unlock_experimental_flags
--unlock_unsafe_flags
--enable_leader_failure_detection=false with env {}
I0108 19:23:49.693470 4586 tablet_bootstrap.cc:434] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8: Bootstrap starting.
I0108 19:23:49.694409 4586 tablet_bootstrap.cc:579] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8: No blocks or log segments found. Creating new log.
I0108 19:23:49.694759 4586 log.cc:520] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8: Log is configured to *not* fsync() on all Append() calls
I0108 19:23:49.695308 4586 tablet_bootstrap.cc:434] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8: No bootstrap required, opened a new log
I0108 19:23:49.695904 4586 raft_consensus.cc:304] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending transactions. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "934158dd8ba0430c9f93330ed9667ab8" member_type: VOTER }
I0108 19:23:49.695940 4586 raft_consensus.cc:330] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I0108 19:23:49.695976 4586 raft_consensus.cc:603] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 934158dd8ba0430c9f93330ed9667ab8, State: Initialized, Role: FOLLOWER
I0108 19:23:49.696171 4586 consensus_queue.cc:218] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [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: "934158dd8ba0430c9f93330ed9667ab8" member_type: VOTER }
I0108 19:23:49.696216 4586 raft_consensus.cc:344] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I0108 19:23:49.696252 4586 raft_consensus.cc:436] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I0108 19:23:49.696277 4586 raft_consensus.cc:2697] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8: Snoozing failure detection for 2.179s (starting election)
I0108 19:23:49.696297 4586 raft_consensus.cc:2749] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [term 0 FOLLOWER]: Advancing to term 1
I0108 19:23:49.696729 4586 raft_consensus.cc:458] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "934158dd8ba0430c9f93330ed9667ab8" member_type: VOTER }
I0108 19:23:49.696890 4586 leader_election.cc:258] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [CANDIDATE]: Term 1 election: Election decided. Result: candidate won.
I0108 19:23:49.697108 4589 raft_consensus.cc:2697] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8: Snoozing failure detection for 1.891s (election complete)
I0108 19:23:49.697129 4589 raft_consensus.cc:2505] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [term 1 FOLLOWER]: Leader election won for term 1
I0108 19:23:49.697274 4589 raft_consensus.cc:570] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [term 1 LEADER]: Becoming Leader. State: Replica: 934158dd8ba0430c9f93330ed9667ab8, State: Running, Role: LEADER
I0108 19:23:49.697396 4589 consensus_queue.cc:195] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [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: "934158dd8ba0430c9f93330ed9667ab8" member_type: VOTER }
I0108 19:23:49.698814 4592 sys_catalog.cc:329] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 934158dd8ba0430c9f93330ed9667ab8. Latest consensus state: current_term: 1 leader_uuid: "934158dd8ba0430c9f93330ed9667ab8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "934158dd8ba0430c9f93330ed9667ab8" member_type: VOTER } }
I0108 19:23:49.698814 4590 sys_catalog.cc:329] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "934158dd8ba0430c9f93330ed9667ab8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "934158dd8ba0430c9f93330ed9667ab8" member_type: VOTER } }
I0108 19:23:49.698835 4592 sys_catalog.cc:332] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [sys.catalog]: This master's current role is: LEADER
I0108 19:23:49.698839 4590 sys_catalog.cc:332] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [sys.catalog]: This master's current role is: LEADER
I0108 19:23:49.698843 4586 sys_catalog.cc:329] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [sys.catalog]: SysCatalogTable state changed. Reason: Started TabletReplica. Latest consensus state: current_term: 1 leader_uuid: "934158dd8ba0430c9f93330ed9667ab8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "934158dd8ba0430c9f93330ed9667ab8" member_type: VOTER } }
I0108 19:23:49.698853 4586 sys_catalog.cc:332] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [sys.catalog]: This master's current role is: LEADER
I0108 19:23:49.699224 4586 sys_catalog.cc:416] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8 [sys.catalog]: configured and running, proceeding with master startup.
I0108 19:23:49.699271 4594 catalog_manager.cc:945] Loading table and tablet metadata into memory...
I0108 19:23:49.699401 4510 master_main.cc:79] Master server successfully started.
I0108 19:23:49.700625 4594 catalog_manager.cc:956] Initializing Kudu internal certificate authority...
I0108 19:23:49.711830 4594 catalog_manager.cc:843] Generated new certificate authority record
I0108 19:23:49.712419 4594 catalog_manager.cc:965] Loading token signing keys...
WARNING: Logging before InitGoogleLogging() is written to STDERR
W0108 19:23:49.716632 4587 flags.cc:392] Enabled unsafe flag: --enable_leader_failure_detection=false
W0108 19:23:49.716737 4587 flags.cc:392] Enabled unsafe flag: --rpc_server_allow_ephemeral_ports=true
W0108 19:23:49.716770 4587 flags.cc:392] Enabled unsafe flag: --never_fsync=true
W0108 19:23:49.717543 4587 flags.cc:392] Enabled experimental flag: --ipki_server_key_size=1024
W0108 19:23:49.717593 4587 flags.cc:392] Enabled experimental flag: --local_ip_for_outbound_sockets=127.20.43.65
I0108 19:23:49.717854 4594 catalog_manager.cc:3717] T 00000000000000000000000000000000 P 934158dd8ba0430c9f93330ed9667ab8: Generated new TSK 0
I0108 19:23:49.718742 4587 tablet_server_main.cc:72] Tablet server non-default flags:
--enable_leader_failure_detection=false
--fs_data_dirs=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/data
--fs_wal_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/wal
--ipki_server_key_size=1024
--rpc_bind_addresses=127.20.43.65:0
--rpc_server_allow_ephemeral_ports=true
--metrics_log_interval_ms=1000
--server_dump_info_format=pb
--server_dump_info_path=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/data/info.pb
--webserver_interface=127.20.43.65
--webserver_port=0
--tserver_master_addrs=127.20.43.126:33196
--never_fsync=true
--heap_profile_path=/tmp/kudu-tserver.4587
--redact=none
--unlock_experimental_flags=true
--unlock_unsafe_flags=true
--enable_minidumps=false
--local_ip_for_outbound_sockets=127.20.43.65
--log_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/logs
--logbuflevel=-1
--logtostderr=true
Tablet server version:
kudu 1.7.0-SNAPSHOT
revision d17699f411b8c276b8aa77b0f85678b5507d9701
build type DEBUG
built by adar at 08 Jan 2018 19:11:05 PST on adar-ThinkPad-T540p
I0108 19:23:49.721513 4587 tablet_server_main.cc:79] Initializing tablet server...
I0108 19:23:49.721901 4587 system_ntp.cc:143] NTP initialized. Skew: 500ppm Current error: 97923us
I0108 19:23:49.722293 4587 server_base.cc:430] Could not load existing FS layout: Not found: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/data/instance: No such file or directory (error 2)
I0108 19:23:49.722304 4587 server_base.cc:431] Creating new FS layout
I0108 19:23:49.724303 4587 fs_manager.cc:564] Generated new instance metadata in path /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/data/instance:
uuid: "105506f2d42649b7b3fbbf617635e4ee"
format_stamp: "Formatted at 2018-01-09 03:23:49 on adar-ThinkPad-T540p"
I0108 19:23:49.724452 4587 fs_manager.cc:564] Generated new instance metadata in path /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/wal/instance:
uuid: "105506f2d42649b7b3fbbf617635e4ee"
format_stamp: "Formatted at 2018-01-09 03:23:49 on adar-ThinkPad-T540p"
I0108 19:23:49.727409 4587 fs_manager.cc:468] Time spent creating directory manager: real 0.003s user 0.000s sys 0.004s
I0108 19:23:49.727700 4587 env_posix.cc:1596] Not raising process file limit of 1048576; it is already as high as it can go
I0108 19:23:49.727789 4587 file_cache.cc:470] Constructed file cache lbm with capacity 419430
I0108 19:23:49.729856 4587 fs_manager.cc:381] Time spent opening block manager: real 0.001s user 0.000s sys 0.000s
I0108 19:23:49.729953 4587 fs_manager.cc:401] Opened local filesystem: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/data,/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/wal
uuid: "105506f2d42649b7b3fbbf617635e4ee"
format_stamp: "Formatted at 2018-01-09 03:23:49 on adar-ThinkPad-T540p"
I0108 19:23:49.730020 4587 fs_report.cc:347] Block manager report
--------------------
1 data directories: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/data/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)
I0108 19:23:49.778887 4587 ts_tablet_manager.cc:298] Loaded tablet metadata (0 live tablets)
I0108 19:23:49.778952 4587 tablet_server_main.cc:84] Starting tablet server...
I0108 19:23:49.783094 4587 rpc_server.cc:192] RPC server started. Bound to: 127.20.43.65:36477
I0108 19:23:49.783339 4587 webserver.cc:173] Starting webserver on 127.20.43.65:0
I0108 19:23:49.783347 4587 webserver.cc:184] Document root disabled
I0108 19:23:49.783577 4587 webserver.cc:311] Webserver started. Bound to: http://127.20.43.65:36255/
I0108 19:23:49.783860 4587 server_base.cc:585] Dumped server information to /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-0/data/info.pb
I0108 19:23:49.784063 4729 process_memory.cc:180] Process hard memory limit is 12.441098 GB
I0108 19:23:49.784093 4587 tablet_server_main.cc:87] Tablet server successfully started.
I0108 19:23:49.784102 4729 process_memory.cc:182] Process soft memory limit is 9.952878 GB
I0108 19:23:49.784107 4729 process_memory.cc:185] Process memory pressure threshold is 7.464659 GB
I0108 19:23:49.790702 4728 heartbeater.cc:329] Connected to a master server at 127.20.43.126:33196
I0108 19:23:49.790782 4728 heartbeater.cc:406] Registering TS with master...
I0108 19:23:49.790990 4728 heartbeater.cc:439] Master 127.20.43.126:33196 requested a full tablet report, sending...
I0108 19:23:49.791697 4538 ts_manager.cc:81] Registered new tserver with Master: 105506f2d42649b7b3fbbf617635e4ee (127.20.43.65:36477)
I0108 19:23:49.792516 20653 external_mini_cluster.cc:844] Started /home/adar/Source/kudu/build/debug/bin/kudu-tserver as pid 4587
I0108 19:23:49.792621 4538 master_service.cc:242] Signed X509 certificate for tserver {username='adar'} at 127.20.43.65:39180
I0108 19:23:49.792765 20653 external_mini_cluster.cc:782] Running /home/adar/Source/kudu/build/debug/bin/kudu-tserver
/home/adar/Source/kudu/build/debug/bin/kudu-tserver
--fs_wal_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/wal
--fs_data_dirs=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/data
--block_manager=log
--rpc_bind_addresses=127.20.43.66:0
--local_ip_for_outbound_sockets=127.20.43.66
--webserver_interface=127.20.43.66
--webserver_port=0
--tserver_master_addrs=127.20.43.126:33196
--never_fsync
--ipki_server_key_size=1024
--enable_minidumps=false
--redact=none
--metrics_log_interval_ms=1000
--logtostderr
--logbuflevel=-1
--log_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/logs
--server_dump_info_path=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/data/info.pb
--server_dump_info_format=pb
--rpc_server_allow_ephemeral_ports
--unlock_experimental_flags
--unlock_unsafe_flags
--enable_leader_failure_detection=false with env {}
WARNING: Logging before InitGoogleLogging() is written to STDERR
W0108 19:23:49.819020 4753 flags.cc:392] Enabled unsafe flag: --enable_leader_failure_detection=false
W0108 19:23:49.819118 4753 flags.cc:392] Enabled unsafe flag: --rpc_server_allow_ephemeral_ports=true
W0108 19:23:49.819147 4753 flags.cc:392] Enabled unsafe flag: --never_fsync=true
W0108 19:23:49.819905 4753 flags.cc:392] Enabled experimental flag: --ipki_server_key_size=1024
W0108 19:23:49.819948 4753 flags.cc:392] Enabled experimental flag: --local_ip_for_outbound_sockets=127.20.43.66
I0108 19:23:49.821012 4753 tablet_server_main.cc:72] Tablet server non-default flags:
--enable_leader_failure_detection=false
--fs_data_dirs=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/data
--fs_wal_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/wal
--ipki_server_key_size=1024
--rpc_bind_addresses=127.20.43.66:0
--rpc_server_allow_ephemeral_ports=true
--metrics_log_interval_ms=1000
--server_dump_info_format=pb
--server_dump_info_path=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/data/info.pb
--webserver_interface=127.20.43.66
--webserver_port=0
--tserver_master_addrs=127.20.43.126:33196
--never_fsync=true
--heap_profile_path=/tmp/kudu-tserver.4753
--redact=none
--unlock_experimental_flags=true
--unlock_unsafe_flags=true
--enable_minidumps=false
--local_ip_for_outbound_sockets=127.20.43.66
--log_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/logs
--logbuflevel=-1
--logtostderr=true
Tablet server version:
kudu 1.7.0-SNAPSHOT
revision d17699f411b8c276b8aa77b0f85678b5507d9701
build type DEBUG
built by adar at 08 Jan 2018 19:11:05 PST on adar-ThinkPad-T540p
I0108 19:23:49.823675 4753 tablet_server_main.cc:79] Initializing tablet server...
I0108 19:23:49.824025 4753 system_ntp.cc:143] NTP initialized. Skew: 500ppm Current error: 97923us
I0108 19:23:49.824419 4753 server_base.cc:430] Could not load existing FS layout: Not found: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/data/instance: No such file or directory (error 2)
I0108 19:23:49.824429 4753 server_base.cc:431] Creating new FS layout
I0108 19:23:49.826326 4753 fs_manager.cc:564] Generated new instance metadata in path /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/data/instance:
uuid: "66799ed6903f449baf51114c0a22d360"
format_stamp: "Formatted at 2018-01-09 03:23:49 on adar-ThinkPad-T540p"
I0108 19:23:49.826467 4753 fs_manager.cc:564] Generated new instance metadata in path /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/wal/instance:
uuid: "66799ed6903f449baf51114c0a22d360"
format_stamp: "Formatted at 2018-01-09 03:23:49 on adar-ThinkPad-T540p"
I0108 19:23:49.829352 4753 fs_manager.cc:468] Time spent creating directory manager: real 0.003s user 0.004s sys 0.000s
I0108 19:23:49.829625 4753 env_posix.cc:1596] Not raising process file limit of 1048576; it is already as high as it can go
I0108 19:23:49.829710 4753 file_cache.cc:470] Constructed file cache lbm with capacity 419430
I0108 19:23:49.831650 4753 fs_manager.cc:381] Time spent opening block manager: real 0.001s user 0.000s sys 0.000s
I0108 19:23:49.831735 4753 fs_manager.cc:401] Opened local filesystem: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/data,/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/wal
uuid: "66799ed6903f449baf51114c0a22d360"
format_stamp: "Formatted at 2018-01-09 03:23:49 on adar-ThinkPad-T540p"
I0108 19:23:49.831799 4753 fs_report.cc:347] Block manager report
--------------------
1 data directories: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/data/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)
I0108 19:23:49.850148 4753 ts_tablet_manager.cc:298] Loaded tablet metadata (0 live tablets)
I0108 19:23:49.850224 4753 tablet_server_main.cc:84] Starting tablet server...
I0108 19:23:49.854017 4753 rpc_server.cc:192] RPC server started. Bound to: 127.20.43.66:43029
I0108 19:23:49.854241 4753 webserver.cc:173] Starting webserver on 127.20.43.66:0
I0108 19:23:49.854249 4753 webserver.cc:184] Document root disabled
I0108 19:23:49.854466 4753 webserver.cc:311] Webserver started. Bound to: http://127.20.43.66:32846/
I0108 19:23:49.854735 4753 server_base.cc:585] Dumped server information to /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/data/info.pb
I0108 19:23:49.854923 4753 tablet_server_main.cc:87] Tablet server successfully started.
I0108 19:23:49.854889 4892 process_memory.cc:180] Process hard memory limit is 12.441098 GB
I0108 19:23:49.854940 4892 process_memory.cc:182] Process soft memory limit is 9.952878 GB
I0108 19:23:49.854945 4892 process_memory.cc:185] Process memory pressure threshold is 7.464659 GB
I0108 19:23:49.855715 20653 external_mini_cluster.cc:844] Started /home/adar/Source/kudu/build/debug/bin/kudu-tserver as pid 4753
I0108 19:23:49.856050 20653 external_mini_cluster.cc:782] Running /home/adar/Source/kudu/build/debug/bin/kudu-tserver
/home/adar/Source/kudu/build/debug/bin/kudu-tserver
--fs_wal_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/wal
--fs_data_dirs=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/data
--block_manager=log
--rpc_bind_addresses=127.20.43.67:0
--local_ip_for_outbound_sockets=127.20.43.67
--webserver_interface=127.20.43.67
--webserver_port=0
--tserver_master_addrs=127.20.43.126:33196
--never_fsync
--ipki_server_key_size=1024
--enable_minidumps=false
--redact=none
--metrics_log_interval_ms=1000
--logtostderr
--logbuflevel=-1
--log_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/logs
--server_dump_info_path=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/data/info.pb
--server_dump_info_format=pb
--rpc_server_allow_ephemeral_ports
--unlock_experimental_flags
--unlock_unsafe_flags
--enable_leader_failure_detection=false with env {}
I0108 19:23:49.860021 4891 heartbeater.cc:329] Connected to a master server at 127.20.43.126:33196
I0108 19:23:49.860097 4891 heartbeater.cc:406] Registering TS with master...
I0108 19:23:49.860301 4891 heartbeater.cc:439] Master 127.20.43.126:33196 requested a full tablet report, sending...
I0108 19:23:49.860790 4538 ts_manager.cc:81] Registered new tserver with Master: 66799ed6903f449baf51114c0a22d360 (127.20.43.66:43029)
I0108 19:23:49.861198 4538 master_service.cc:242] Signed X509 certificate for tserver {username='adar'} at 127.20.43.66:37745
WARNING: Logging before InitGoogleLogging() is written to STDERR
W0108 19:23:49.883039 4894 flags.cc:392] Enabled unsafe flag: --enable_leader_failure_detection=false
W0108 19:23:49.883139 4894 flags.cc:392] Enabled unsafe flag: --rpc_server_allow_ephemeral_ports=true
W0108 19:23:49.883188 4894 flags.cc:392] Enabled unsafe flag: --never_fsync=true
W0108 19:23:49.883947 4894 flags.cc:392] Enabled experimental flag: --ipki_server_key_size=1024
W0108 19:23:49.884013 4894 flags.cc:392] Enabled experimental flag: --local_ip_for_outbound_sockets=127.20.43.67
I0108 19:23:49.885097 4894 tablet_server_main.cc:72] Tablet server non-default flags:
--enable_leader_failure_detection=false
--fs_data_dirs=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/data
--fs_wal_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/wal
--ipki_server_key_size=1024
--rpc_bind_addresses=127.20.43.67:0
--rpc_server_allow_ephemeral_ports=true
--metrics_log_interval_ms=1000
--server_dump_info_format=pb
--server_dump_info_path=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/data/info.pb
--webserver_interface=127.20.43.67
--webserver_port=0
--tserver_master_addrs=127.20.43.126:33196
--never_fsync=true
--heap_profile_path=/tmp/kudu-tserver.4894
--redact=none
--unlock_experimental_flags=true
--unlock_unsafe_flags=true
--enable_minidumps=false
--local_ip_for_outbound_sockets=127.20.43.67
--log_dir=/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/logs
--logbuflevel=-1
--logtostderr=true
Tablet server version:
kudu 1.7.0-SNAPSHOT
revision d17699f411b8c276b8aa77b0f85678b5507d9701
build type DEBUG
built by adar at 08 Jan 2018 19:11:05 PST on adar-ThinkPad-T540p
I0108 19:23:49.887814 4894 tablet_server_main.cc:79] Initializing tablet server...
I0108 19:23:49.888237 4894 system_ntp.cc:143] NTP initialized. Skew: 500ppm Current error: 97923us
I0108 19:23:49.888659 4894 server_base.cc:430] Could not load existing FS layout: Not found: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/data/instance: No such file or directory (error 2)
I0108 19:23:49.888669 4894 server_base.cc:431] Creating new FS layout
I0108 19:23:49.890595 4894 fs_manager.cc:564] Generated new instance metadata in path /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/data/instance:
uuid: "40674ac21662425caef90648e22b6ffb"
format_stamp: "Formatted at 2018-01-09 03:23:49 on adar-ThinkPad-T540p"
I0108 19:23:49.890738 4894 fs_manager.cc:564] Generated new instance metadata in path /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/wal/instance:
uuid: "40674ac21662425caef90648e22b6ffb"
format_stamp: "Formatted at 2018-01-09 03:23:49 on adar-ThinkPad-T540p"
I0108 19:23:49.893512 4894 fs_manager.cc:468] Time spent creating directory manager: real 0.003s user 0.000s sys 0.000s
I0108 19:23:49.893780 4894 env_posix.cc:1596] Not raising process file limit of 1048576; it is already as high as it can go
I0108 19:23:49.893864 4894 file_cache.cc:470] Constructed file cache lbm with capacity 419430
I0108 19:23:49.895736 4894 fs_manager.cc:381] Time spent opening block manager: real 0.001s user 0.000s sys 0.000s
I0108 19:23:49.895804 4894 fs_manager.cc:401] Opened local filesystem: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/data,/tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/wal
uuid: "40674ac21662425caef90648e22b6ffb"
format_stamp: "Formatted at 2018-01-09 03:23:49 on adar-ThinkPad-T540p"
I0108 19:23:49.895848 4894 fs_report.cc:347] Block manager report
--------------------
1 data directories: /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/data/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)
I0108 19:23:49.924206 4894 ts_tablet_manager.cc:298] Loaded tablet metadata (0 live tablets)
I0108 19:23:49.924396 4894 tablet_server_main.cc:84] Starting tablet server...
I0108 19:23:49.928423 4894 rpc_server.cc:192] RPC server started. Bound to: 127.20.43.67:32905
I0108 19:23:49.928668 4894 webserver.cc:173] Starting webserver on 127.20.43.67:0
I0108 19:23:49.928678 4894 webserver.cc:184] Document root disabled
I0108 19:23:49.928908 4894 webserver.cc:311] Webserver started. Bound to: http://127.20.43.67:38163/
I0108 19:23:49.929196 4894 server_base.cc:585] Dumped server information to /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-2/data/info.pb
I0108 19:23:49.929388 5024 process_memory.cc:180] Process hard memory limit is 12.441098 GB
I0108 19:23:49.929419 4894 tablet_server_main.cc:87] Tablet server successfully started.
I0108 19:23:49.929430 5024 process_memory.cc:182] Process soft memory limit is 9.952878 GB
I0108 19:23:49.929435 5024 process_memory.cc:185] Process memory pressure threshold is 7.464659 GB
I0108 19:23:49.929606 20653 external_mini_cluster.cc:844] Started /home/adar/Source/kudu/build/debug/bin/kudu-tserver as pid 4894
I0108 19:23:49.934310 5023 heartbeater.cc:329] Connected to a master server at 127.20.43.126:33196
I0108 19:23:49.934388 5023 heartbeater.cc:406] Registering TS with master...
I0108 19:23:49.934582 5023 heartbeater.cc:439] Master 127.20.43.126:33196 requested a full tablet report, sending...
I0108 19:23:49.935048 4538 ts_manager.cc:81] Registered new tserver with Master: 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905)
I0108 19:23:49.935621 4538 master_service.cc:242] Signed X509 certificate for tserver {username='adar'} at 127.20.43.67:57515
I0108 19:23:49.935816 20653 external_mini_cluster.cc:483] 3 TS(s) registered with all masters
I0108 19:23:49.941920 4538 catalog_manager.cc:1207] Servicing CreateTable request from {username='adar'} at 127.0.0.1:57102:
name: "TestTable"
schema {
columns {
name: "key"
type: INT32
is_key: true
is_nullable: false
encoding: AUTO_ENCODING
compression: DEFAULT_COMPRESSION
cfile_block_size: 0
}
columns {
name: "int_val"
type: INT32
is_key: false
is_nullable: false
encoding: AUTO_ENCODING
compression: DEFAULT_COMPRESSION
cfile_block_size: 0
}
columns {
name: "string_val"
type: STRING
is_key: false
is_nullable: true
encoding: AUTO_ENCODING
compression: DEFAULT_COMPRESSION
cfile_block_size: 0
}
}
num_replicas: 3
split_rows_range_bounds {
}
partition_schema {
range_schema {
columns {
name: "key"
}
}
}
I0108 19:23:49.950719 4644 tablet_service.cc:756] Processing CreateTablet for tablet f41268d2f2a34714b485f913b08498be (table=TestTable [id=c24d3bcd1ab24a08a022fb9673eb915d]), partition=RANGE (key) PARTITION UNBOUNDED
I0108 19:23:49.950719 4823 tablet_service.cc:756] Processing CreateTablet for tablet f41268d2f2a34714b485f913b08498be (table=TestTable [id=c24d3bcd1ab24a08a022fb9673eb915d]), partition=RANGE (key) PARTITION UNBOUNDED
I0108 19:23:49.950721 4958 tablet_service.cc:756] Processing CreateTablet for tablet f41268d2f2a34714b485f913b08498be (table=TestTable [id=c24d3bcd1ab24a08a022fb9673eb915d]), partition=RANGE (key) PARTITION UNBOUNDED
I0108 19:23:49.953241 4823 ts_tablet_manager.cc:1070] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Registered tablet (data state: TABLET_DATA_READY)
I0108 19:23:49.953241 4958 ts_tablet_manager.cc:1070] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb: Registered tablet (data state: TABLET_DATA_READY)
I0108 19:23:49.953241 4644 ts_tablet_manager.cc:1070] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee: Registered tablet (data state: TABLET_DATA_READY)
I0108 19:23:49.953430 5040 ts_tablet_manager.cc:928] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb: Bootstrapping tablet
I0108 19:23:49.953435 5039 ts_tablet_manager.cc:928] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee: Bootstrapping tablet
I0108 19:23:49.953536 5040 tablet_bootstrap.cc:434] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb: Bootstrap starting.
I0108 19:23:49.953536 5039 tablet_bootstrap.cc:434] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee: Bootstrap starting.
I0108 19:23:49.953809 5041 ts_tablet_manager.cc:928] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Bootstrapping tablet
I0108 19:23:49.953908 5041 tablet_bootstrap.cc:434] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Bootstrap starting.
I0108 19:23:49.954394 5039 tablet_bootstrap.cc:579] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee: No blocks or log segments found. Creating new log.
I0108 19:23:49.954566 5041 tablet_bootstrap.cc:579] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: No blocks or log segments found. Creating new log.
I0108 19:23:49.954761 5039 log.cc:520] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee: Log is configured to *not* fsync() on all Append() calls
I0108 19:23:49.954890 5041 log.cc:520] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Log is configured to *not* fsync() on all Append() calls
I0108 19:23:49.955319 5039 tablet_bootstrap.cc:434] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee: No bootstrap required, opened a new log
I0108 19:23:49.955322 5041 tablet_bootstrap.cc:434] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: No bootstrap required, opened a new log
I0108 19:23:49.955409 5039 ts_tablet_manager.cc:945] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee: Time spent bootstrapping tablet: real 0.002s user 0.000s sys 0.000s
I0108 19:23:49.955409 5041 ts_tablet_manager.cc:945] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Time spent bootstrapping tablet: real 0.002s user 0.000s sys 0.000s
I0108 19:23:49.955574 5040 tablet_bootstrap.cc:579] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb: No blocks or log segments found. Creating new log.
I0108 19:23:49.955845 5040 log.cc:520] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb: Log is configured to *not* fsync() on all Append() calls
I0108 19:23:49.956050 5041 raft_consensus.cc:304] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending transactions. Active config: opid_index: -1 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } } peers { permanent_uuid: "66799ed6903f449baf51114c0a22d360" member_type: VOTER last_known_addr { host: "127.20.43.66" port: 43029 } }
I0108 19:23:49.956050 5039 raft_consensus.cc:304] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 0 FOLLOWER]: Replica starting. Triggering 0 pending transactions. Active config: opid_index: -1 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } } peers { permanent_uuid: "66799ed6903f449baf51114c0a22d360" member_type: VOTER last_known_addr { host: "127.20.43.66" port: 43029 } }
I0108 19:23:49.956089 5039 raft_consensus.cc:603] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 105506f2d42649b7b3fbbf617635e4ee, State: Initialized, Role: FOLLOWER
I0108 19:23:49.956089 5041 raft_consensus.cc:603] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 66799ed6903f449baf51114c0a22d360, State: Initialized, Role: FOLLOWER
I0108 19:23:49.956250 5041 consensus_queue.cc:218] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360 [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: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } } peers { permanent_uuid: "66799ed6903f449baf51114c0a22d360" member_type: VOTER last_known_addr { host: "127.20.43.66" port: 43029 } }
I0108 19:23:49.956250 5039 consensus_queue.cc:218] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [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: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } } peers { permanent_uuid: "66799ed6903f449baf51114c0a22d360" member_type: VOTER last_known_addr { host: "127.20.43.66" port: 43029 } }
I0108 19:23:49.956249 5040 tablet_bootstrap.cc:434] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb: No bootstrap required, opened a new log
I0108 19:23:49.956318 5040 ts_tablet_manager.cc:945] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb: Time spent bootstrapping tablet: real 0.003s user 0.000s sys 0.000s
I0108 19:23:49.956455 4728 heartbeater.cc:431] Master 127.20.43.126:33196 was elected leader, sending a full tablet report...
I0108 19:23:49.956456 4891 heartbeater.cc:431] Master 127.20.43.126:33196 was elected leader, sending a full tablet report...
I0108 19:23:49.956562 5039 ts_tablet_manager.cc:973] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee: Time spent starting tablet: real 0.001s user 0.000s sys 0.000s
I0108 19:23:49.956581 5041 ts_tablet_manager.cc:973] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Time spent starting tablet: real 0.001s user 0.000s sys 0.000s
I0108 19:23:49.956818 5040 raft_consensus.cc:304] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending transactions. Active config: opid_index: -1 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } } peers { permanent_uuid: "66799ed6903f449baf51114c0a22d360" member_type: VOTER last_known_addr { host: "127.20.43.66" port: 43029 } }
I0108 19:23:49.956862 5040 raft_consensus.cc:603] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 40674ac21662425caef90648e22b6ffb, State: Initialized, Role: FOLLOWER
I0108 19:23:49.957032 5040 consensus_queue.cc:218] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb [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: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } } peers { permanent_uuid: "66799ed6903f449baf51114c0a22d360" member_type: VOTER last_known_addr { host: "127.20.43.66" port: 43029 } }
I0108 19:23:49.957247 5023 heartbeater.cc:431] Master 127.20.43.126:33196 was elected leader, sending a full tablet report...
I0108 19:23:49.957334 5040 ts_tablet_manager.cc:973] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb: Time spent starting tablet: real 0.001s user 0.000s sys 0.000s
I0108 19:23:49.963505 20653 external_mini_cluster.cc:483] 3 TS(s) registered with all masters
I0108 19:23:49.964164 20653 ts_itest-base.cc:233] Waiting for 1 tablets on tserver 105506f2d42649b7b3fbbf617635e4ee to finish bootstrapping
I0108 19:23:49.967515 20653 ts_itest-base.cc:233] Waiting for 1 tablets on tserver 66799ed6903f449baf51114c0a22d360 to finish bootstrapping
I0108 19:23:49.970690 20653 ts_itest-base.cc:233] Waiting for 1 tablets on tserver 40674ac21662425caef90648e22b6ffb to finish bootstrapping
I0108 19:23:49.977082 4678 tablet_service.cc:1106] Received Run Leader Election RPC: tablet_id: "f41268d2f2a34714b485f913b08498be"
dest_uuid: "105506f2d42649b7b3fbbf617635e4ee"
from {username='adar'} at 127.0.0.1:52238
I0108 19:23:49.977164 4678 raft_consensus.cc:436] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 0 FOLLOWER]: Starting forced leader election (received explicit request)
I0108 19:23:49.977217 4678 raft_consensus.cc:2749] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 0 FOLLOWER]: Advancing to term 1
I0108 19:23:49.977788 4678 raft_consensus.cc:458] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 FOLLOWER]: Starting forced leader election with config: opid_index: -1 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } } peers { permanent_uuid: "66799ed6903f449baf51114c0a22d360" member_type: VOTER last_known_addr { host: "127.20.43.66" port: 43029 } }
I0108 19:23:49.978232 4678 leader_election.cc:231] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [CANDIDATE]: Term 1 election: Requesting vote from peer 40674ac21662425caef90648e22b6ffb
I0108 19:23:49.978353 4678 leader_election.cc:231] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [CANDIDATE]: Term 1 election: Requesting vote from peer 66799ed6903f449baf51114c0a22d360
I0108 19:23:49.982161 4980 tablet_service.cc:994] Received RequestConsensusVote() RPC: tablet_id: "f41268d2f2a34714b485f913b08498be" candidate_uuid: "105506f2d42649b7b3fbbf617635e4ee" candidate_term: 1 candidate_status { last_received { term: 0 index: 0 } } ignore_live_leader: true dest_uuid: "40674ac21662425caef90648e22b6ffb"
I0108 19:23:49.982161 4847 tablet_service.cc:994] Received RequestConsensusVote() RPC: tablet_id: "f41268d2f2a34714b485f913b08498be" candidate_uuid: "105506f2d42649b7b3fbbf617635e4ee" candidate_term: 1 candidate_status { last_received { term: 0 index: 0 } } ignore_live_leader: true dest_uuid: "66799ed6903f449baf51114c0a22d360"
I0108 19:23:49.982244 4847 raft_consensus.cc:2749] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360 [term 0 FOLLOWER]: Advancing to term 1
I0108 19:23:49.982244 4980 raft_consensus.cc:2749] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb [term 0 FOLLOWER]: Advancing to term 1
I0108 19:23:49.982971 4847 raft_consensus.cc:2215] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360 [term 1 FOLLOWER]: Leader election vote request: Granting yes vote for candidate 105506f2d42649b7b3fbbf617635e4ee in term 1.
I0108 19:23:49.982971 4980 raft_consensus.cc:2215] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb [term 1 FOLLOWER]: Leader election vote request: Granting yes vote for candidate 105506f2d42649b7b3fbbf617635e4ee in term 1.
I0108 19:23:49.983227 4606 leader_election.cc:363] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [CANDIDATE]: Term 1 election: Vote granted by peer 40674ac21662425caef90648e22b6ffb
I0108 19:23:49.983259 4606 leader_election.cc:258] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [CANDIDATE]: Term 1 election: Election decided. Result: candidate won.
I0108 19:23:49.983295 4608 leader_election.cc:363] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [CANDIDATE]: Term 1 election: Vote granted by peer 66799ed6903f449baf51114c0a22d360
I0108 19:23:49.983439 5046 raft_consensus.cc:2505] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 FOLLOWER]: Leader election won for term 1
I0108 19:23:49.983542 5046 raft_consensus.cc:570] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: Becoming Leader. State: Replica: 105506f2d42649b7b3fbbf617635e4ee, State: Running, Role: LEADER
I0108 19:23:49.983736 5046 consensus_queue.cc:195] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [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: 2, State: 0, Mode: LEADER, active raft config: opid_index: -1 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } } peers { permanent_uuid: "66799ed6903f449baf51114c0a22d360" member_type: VOTER last_known_addr { host: "127.20.43.66" port: 43029 } }
I0108 19:23:49.986074 4535 catalog_manager.cc:3452] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee reported cstate change: term changed from 0 to 1, leader changed from <none> to 105506f2d42649b7b3fbbf617635e4ee (127.20.43.65). New cstate: current_term: 1 leader_uuid: "105506f2d42649b7b3fbbf617635e4ee" committed_config { opid_index: -1 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } health_report { overall_health: UNKNOWN } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } health_report { overall_health: HEALTHY } } peers { permanent_uuid: "66799ed6903f449baf51114c0a22d360" member_type: VOTER last_known_addr { host: "127.20.43.66" port: 43029 } health_report { overall_health: UNKNOWN } } }
I0108 19:23:49.993693 20653 cluster_itest_util.cc:245] Not converged past 1 yet: 1.1 0.0 0.0
I0108 19:23:50.095695 20653 cluster_itest_util.cc:245] Not converged past 1 yet: 1.1 0.0 0.0
I0108 19:23:50.297564 20653 cluster_itest_util.cc:245] Not converged past 1 yet: 1.1 0.0 0.0
I0108 19:23:50.367527 4980 raft_consensus.cc:1058] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb [term 1 FOLLOWER]: Refusing update from remote peer 105506f2d42649b7b3fbbf617635e4ee: Log matching property violated. Preceding OpId in replica: term: 0 index: 0. Preceding OpId from leader: term: 1 index: 1. (index mismatch)
I0108 19:23:50.367992 5046 consensus_queue.cc:1014] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [LEADER]: Connected to new peer: Peer: permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 }, Status: LMP_MISMATCH, Last received: 0.0, Next index: 1, Last known committed idx: 0, Time since last communication: 0.000s
I0108 19:23:50.371400 4847 raft_consensus.cc:1058] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360 [term 1 FOLLOWER]: Refusing update from remote peer 105506f2d42649b7b3fbbf617635e4ee: Log matching property violated. Preceding OpId in replica: term: 0 index: 0. Preceding OpId from leader: term: 1 index: 1. (index mismatch)
I0108 19:23:50.371814 5053 consensus_queue.cc:1014] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [LEADER]: Connected to new peer: Peer: permanent_uuid: "66799ed6903f449baf51114c0a22d360" member_type: VOTER last_known_addr { host: "127.20.43.66" port: 43029 }, Status: LMP_MISMATCH, Last received: 0.0, Next index: 1, Last known committed idx: 0, Time since last communication: 0.000s
I0108 19:23:50.600021 4888 generic_service.cc:110] {username='adar'} at 127.0.0.1:40822 changed flags via RPC: fault_crash_before_append_commit from '0' to '1.0'
I0108 19:23:50.600762 5020 generic_service.cc:110] {username='adar'} at 127.0.0.1:44236 changed flags via RPC: fault_crash_before_append_commit from '0' to '1.0'
I0108 19:23:50.601794 4678 consensus_peers.cc:444] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 66799ed6903f449baf51114c0a22d360 (127.20.43.66:43029): Closing peer: 66799ed6903f449baf51114c0a22d360
I0108 19:23:50.601824 4678 consensus_peers.cc:444] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Closing peer: 40674ac21662425caef90648e22b6ffb
I0108 19:23:50.601984 4678 consensus_queue.cc:195] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 1, Committed index: 1, Last appended: 1.1, Last appended by leader: 0, Current term: 1, Majority size: 2, State: 0, Mode: LEADER, active raft config: opid_index: 2 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } }
I0108 19:23:50.602730 4980 raft_consensus.cc:1058] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb [term 1 FOLLOWER]: Refusing update from remote peer 105506f2d42649b7b3fbbf617635e4ee: Log matching property violated. Preceding OpId in replica: term: 1 index: 1. Preceding OpId from leader: term: 1 index: 2. (index mismatch)
I0108 19:23:50.603027 5053 consensus_queue.cc:1014] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [LEADER]: Connected to new peer: Peer: permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 }, Status: LMP_MISMATCH, Last received: 1.1, Next index: 2, Last known committed idx: 1, Time since last communication: 0.000s
I0108 19:23:50.604293 5050 raft_consensus.cc:2652] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: Committing config change with OpId 1.2: config changed from index -1 to 2, VOTER 66799ed6903f449baf51114c0a22d360 (127.20.43.66) evicted. New config: { opid_index: 2 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } } }
I0108 19:23:50.604583 4980 raft_consensus.cc:2652] T f41268d2f2a34714b485f913b08498be P 40674ac21662425caef90648e22b6ffb [term 1 FOLLOWER]: Committing config change with OpId 1.2: config changed from index -1 to 2, VOTER 66799ed6903f449baf51114c0a22d360 (127.20.43.66) evicted. New config: { opid_index: 2 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } } }
W0108 19:23:50.605128 4980 fault_injection.cc:41] FAULT INJECTION ENABLED!
W0108 19:23:50.605136 4980 fault_injection.cc:42] THIS SERVER MAY CRASH!
E0108 19:23:50.605150 4980 fault_injection.cc:57] Injecting fault: FLAGS_fault_crash_before_append_commit (process will exit)
I0108 19:23:50.605689 4538 catalog_manager.cc:3452] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee reported cstate change: config changed from index -1 to 2, VOTER 66799ed6903f449baf51114c0a22d360 (127.20.43.66) evicted. New cstate: current_term: 1 leader_uuid: "105506f2d42649b7b3fbbf617635e4ee" committed_config { opid_index: 2 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } health_report { overall_health: HEALTHY } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } health_report { overall_health: HEALTHY } } }
I0108 19:23:50.606914 4538 catalog_manager.cc:2811] Sending DeleteTablet(TABLET_DATA_TOMBSTONED) for tablet f41268d2f2a34714b485f913b08498be on 66799ed6903f449baf51114c0a22d360 (127.20.43.66:43029) (TS 66799ed6903f449baf51114c0a22d360 not found in new config with opid_index 2)
I0108 19:23:50.607043 4538 catalog_manager.cc:3123] Sending ChangeConfig:ADD_PEER:NON_VOTER on tablet f41268d2f2a34714b485f913b08498be (attempt 1)
I0108 19:23:50.607412 4823 tablet_service.cc:797] Processing DeleteTablet for tablet f41268d2f2a34714b485f913b08498be with delete_type TABLET_DATA_TOMBSTONED (TS 66799ed6903f449baf51114c0a22d360 not found in new config with opid_index 2) from {username='adar'} at 127.0.0.1:40818
I0108 19:23:50.607492 4823 tablet_replica.cc:261] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: stopping tablet replica
I0108 19:23:50.607574 4823 maintenance_manager.cc:233] P 66799ed6903f449baf51114c0a22d360: Unregistered op CompactRowSetsOp(f41268d2f2a34714b485f913b08498be)
I0108 19:23:50.607601 4823 maintenance_manager.cc:233] P 66799ed6903f449baf51114c0a22d360: Unregistered op MinorDeltaCompactionOp(f41268d2f2a34714b485f913b08498be)
I0108 19:23:50.607602 4678 consensus_peers.cc:444] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Closing peer: 40674ac21662425caef90648e22b6ffb
I0108 19:23:50.607611 4823 maintenance_manager.cc:233] P 66799ed6903f449baf51114c0a22d360: Unregistered op MajorDeltaCompactionOp(f41268d2f2a34714b485f913b08498be)
I0108 19:23:50.607620 4823 maintenance_manager.cc:233] P 66799ed6903f449baf51114c0a22d360: Unregistered op UndoDeltaBlockGCOp(f41268d2f2a34714b485f913b08498be)
I0108 19:23:50.607651 4823 maintenance_manager.cc:233] P 66799ed6903f449baf51114c0a22d360: Unregistered op FlushMRSOp(f41268d2f2a34714b485f913b08498be)
I0108 19:23:50.607664 4823 maintenance_manager.cc:233] P 66799ed6903f449baf51114c0a22d360: Unregistered op FlushDeltaMemStoresOp(f41268d2f2a34714b485f913b08498be)
I0108 19:23:50.607672 4823 maintenance_manager.cc:233] P 66799ed6903f449baf51114c0a22d360: Unregistered op LogGCOp(f41268d2f2a34714b485f913b08498be)
W0108 19:23:50.607678 4509 connection.cc:511] client connection to 127.20.43.67:32905 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
I0108 19:23:50.607691 4678 consensus_queue.cc:195] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [LEADER]: Queue going to LEADER mode. State: All replicated index: 0, Majority replicated index: 2, Committed index: 2, Last appended: 1.2, Last appended by leader: 0, Current term: 1, Majority size: 2, State: 0, Mode: LEADER, active raft config: opid_index: 3 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } } peers { permanent_uuid: "66799ed6903f449baf51114c0a22d360" member_type: NON_VOTER last_known_addr { host: "127.20.43.66" port: 43029 } attrs { promote: true } }
I0108 19:23:50.607704 4823 raft_consensus.cc:2012] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360 [term 1 FOLLOWER]: Raft consensus shutting down.
W0108 19:23:50.607715 4521 connection.cc:511] server connection from 127.20.43.67:57515 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
W0108 19:23:50.607743 4606 connection.cc:511] client connection to 127.20.43.67:32905 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
W0108 19:23:50.607803 4520 connection.cc:511] client connection to 127.20.43.67:32905 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
I0108 19:23:50.607812 4823 raft_consensus.cc:2039] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360 [term 1 FOLLOWER]: Raft consensus is shut down!
W0108 19:23:50.607677 4505 connection.cc:511] client connection to 127.20.43.67:32905 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
W0108 19:23:50.608439 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 1 times.
I0108 19:23:50.608494 4823 ts_tablet_manager.cc:1262] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Deleting tablet data with delete state TABLET_DATA_TOMBSTONED
W0108 19:23:50.608753 4608 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 66799ed6903f449baf51114c0a22d360 (127.20.43.66:43029): Couldn't send request to peer 66799ed6903f449baf51114c0a22d360 for tablet f41268d2f2a34714b485f913b08498be. Error code: TABLET_NOT_RUNNING (12). Status: Illegal state: Tablet not RUNNING: STOPPED. Retrying in the next heartbeat period. Already tried 1 times.
I0108 19:23:50.609501 4823 ts_tablet_manager.cc:1275] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: tablet deleted: last-logged OpId: 1.1
I0108 19:23:50.609521 4823 log.cc:981] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Deleting WAL directory at /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653/raft_consensus-itest-cluster/ts-1/wal/wals/f41268d2f2a34714b485f913b08498be
I0108 19:23:50.609840 4522 catalog_manager.cc:2789] TS 66799ed6903f449baf51114c0a22d360 (127.20.43.66:43029): tablet f41268d2f2a34714b485f913b08498be (table TestTable [id=c24d3bcd1ab24a08a022fb9673eb915d]) successfully deleted
W0108 19:23:51.162482 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 2 times.
W0108 19:23:51.224109 4608 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 66799ed6903f449baf51114c0a22d360 (127.20.43.66:43029): Couldn't send request to peer 66799ed6903f449baf51114c0a22d360 for tablet f41268d2f2a34714b485f913b08498be. Error code: TABLET_NOT_FOUND (6). Status: Illegal state: Tablet not RUNNING: STOPPED. Retrying in the next heartbeat period. Already tried 2 times.
W0108 19:23:51.554770 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 3 times.
I0108 19:23:51.607784 5061 ts_tablet_manager.cc:628] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Initiating tablet copy from peer 105506f2d42649b7b3fbbf617635e4ee (127.20.43.65:36477)
I0108 19:23:51.607959 5061 tablet_copy_client.cc:237] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: tablet copy: Beginning tablet copy session from remote peer at address 127.20.43.65:36477
I0108 19:23:51.611279 4705 tablet_copy_service.cc:133] P 105506f2d42649b7b3fbbf617635e4ee: Received BeginTabletCopySession request for tablet f41268d2f2a34714b485f913b08498be from peer 66799ed6903f449baf51114c0a22d360 ({username='adar'} at 127.20.43.66:59206)
I0108 19:23:51.611330 4705 tablet_copy_service.cc:154] P 105506f2d42649b7b3fbbf617635e4ee: Beginning new tablet copy session on tablet f41268d2f2a34714b485f913b08498be from peer 66799ed6903f449baf51114c0a22d360 at {username='adar'} at 127.20.43.66:59206: session id = 66799ed6903f449baf51114c0a22d360-f41268d2f2a34714b485f913b08498be
I0108 19:23:51.612149 4705 tablet_copy_source_session.cc:202] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee: Tablet Copy: opened 0 blocks and 1 log segments
I0108 19:23:51.612885 5061 ts_tablet_manager.cc:1262] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Deleting tablet data with delete state TABLET_DATA_COPYING
I0108 19:23:51.616247 5061 ts_tablet_manager.cc:1275] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: tablet deleted: last-logged OpId: 1.1
I0108 19:23:51.616914 5061 ts_tablet_manager.cc:1070] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Registered tablet (data state: TABLET_DATA_COPYING)
I0108 19:23:51.617017 5061 tablet_copy_client.cc:529] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: tablet copy: Starting download of 0 data blocks...
I0108 19:23:51.617087 5061 tablet_copy_client.cc:492] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: tablet copy: Starting download of 1 WAL segments...
I0108 19:23:51.617918 5061 tablet_copy_client.cc:397] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: tablet copy: Tablet Copy complete. Replacing tablet superblock.
I0108 19:23:51.618672 5061 ts_tablet_manager.cc:928] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Bootstrapping tablet
I0108 19:23:51.618723 5061 tablet_bootstrap.cc:434] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Bootstrap starting.
I0108 19:23:51.620755 5061 tablet_bootstrap.cc:434] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Bootstrap replayed 1/1 log segments. Stats: ops{read=3 overwritten=0 applied=2 ignored=0} inserts{seen=0 ignored=0} mutations{seen=0 ignored=0} orphaned_commits=0. Pending: 1 replicates
I0108 19:23:51.620895 5061 tablet_bootstrap.cc:434] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Bootstrap complete.
I0108 19:23:51.620970 5061 ts_tablet_manager.cc:945] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Time spent bootstrapping tablet: real 0.002s user 0.004s sys 0.000s
I0108 19:23:51.621232 5061 raft_consensus.cc:304] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360 [term 1 NON_PARTICIPANT]: Replica starting. Triggering 1 pending transactions. Active config: opid_index: 2 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } }
I0108 19:23:51.621368 5061 raft_consensus.cc:603] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360 [term 1 LEARNER]: Becoming Follower/Learner. State: Replica: 66799ed6903f449baf51114c0a22d360, State: Initialized, Role: LEARNER
I0108 19:23:51.621474 5061 consensus_queue.cc:218] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360 [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated index: 0, Majority replicated index: 0, Committed index: 2, Last appended: 1.3, Last appended by leader: 3, Current term: 0, Majority size: -1, State: 0, Mode: NON_LEADER, active raft config: opid_index: 3 OBSOLETE_local: false peers { permanent_uuid: "40674ac21662425caef90648e22b6ffb" member_type: VOTER last_known_addr { host: "127.20.43.67" port: 32905 } } peers { permanent_uuid: "105506f2d42649b7b3fbbf617635e4ee" member_type: VOTER last_known_addr { host: "127.20.43.65" port: 36477 } } peers { permanent_uuid: "66799ed6903f449baf51114c0a22d360" member_type: NON_VOTER last_known_addr { host: "127.20.43.66" port: 43029 } attrs { promote: true } }
I0108 19:23:51.621662 5061 ts_tablet_manager.cc:973] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360: Time spent starting tablet: real 0.001s user 0.000s sys 0.000s
I0108 19:23:51.622140 4705 tablet_copy_service.cc:323] P 105506f2d42649b7b3fbbf617635e4ee: Request end of tablet copy session 66799ed6903f449baf51114c0a22d360-f41268d2f2a34714b485f913b08498be received from {username='adar'} at 127.20.43.66:59206
I0108 19:23:51.622169 4705 tablet_copy_service.cc:411] P 105506f2d42649b7b3fbbf617635e4ee: Ending tablet copy session 66799ed6903f449baf51114c0a22d360-f41268d2f2a34714b485f913b08498be on tablet f41268d2f2a34714b485f913b08498be with peer 66799ed6903f449baf51114c0a22d360
I0108 19:23:52.016310 4847 raft_consensus.cc:1003] T f41268d2f2a34714b485f913b08498be P 66799ed6903f449baf51114c0a22d360 [term 1 LEARNER]: Deduplicated request from leader. Original: 1.2->[1.3-1.3] Dedup: 1.3->[]
I0108 19:23:52.016893 5066 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:52.148799 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 4 times.
I0108 19:23:52.441526 5059 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:52.593415 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 5 times.
I0108 19:23:52.839110 5066 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:53.215488 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 6 times.
I0108 19:23:53.408123 5070 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:53.593786 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 7 times.
I0108 19:23:54.000304 5071 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:54.191427 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 8 times.
I0108 19:23:54.467224 5071 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:54.619477 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 9 times.
I0108 19:23:54.880774 5071 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:55.211257 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 10 times.
I0108 19:23:55.278110 5071 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
I0108 19:23:55.741228 5059 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:55.789295 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 11 times.
I0108 19:23:56.172940 5059 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:56.227315 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 12 times.
W0108 19:23:56.694993 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 13 times.
I0108 19:23:56.711614 5075 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:57.137699 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 14 times.
I0108 19:23:57.304023 5076 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:57.567953 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 15 times.
I0108 19:23:57.725823 5076 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
I0108 19:23:58.103355 5071 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:58.182140 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 16 times.
W0108 19:23:58.578418 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 17 times.
I0108 19:23:58.716414 5071 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:59.188541 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 18 times.
I0108 19:23:59.333031 5081 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:23:59.622692 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 19 times.
I0108 19:23:59.944083 5082 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:24:00.148403 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 20 times.
I0108 19:24:00.333788 5082 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
W0108 19:24:00.539796 4606 consensus_peers.cc:422] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee -> Peer 40674ac21662425caef90648e22b6ffb (127.20.43.67:32905): Couldn't send request to peer 40674ac21662425caef90648e22b6ffb for tablet f41268d2f2a34714b485f913b08498be. Status: Network error: Client connection negotiation failed: client connection to 127.20.43.67:32905: connect: Connection refused (error 111). Retrying in the next heartbeat period. Already tried 21 times.
I0108 19:24:00.711150 5082 raft_consensus.cc:843] T f41268d2f2a34714b485f913b08498be P 105506f2d42649b7b3fbbf617635e4ee [term 1 LEADER]: attempt to promote peer 66799ed6903f449baf51114c0a22d360: notified when committed config had opid index 3, but now the committed config has opid index 2. Doing nothing.
../../src/kudu/integration-tests/raft_consensus-itest.cc:2436: Failure
Failed
Bad status: Timed out: Process did not crash within 10.000s
I0108 19:24:00.713665 20653 external_mini_cluster.cc:974] Killing /home/adar/Source/kudu/build/debug/bin/kudu-tserver with pid 4587
W0108 19:24:00.716301 4507 connection.cc:511] client connection to 127.20.43.65:36477 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
W0108 19:24:00.716315 4763 connection.cc:511] client connection to 127.20.43.65:36477 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
W0108 19:24:00.716357 4522 connection.cc:511] client connection to 127.20.43.65:36477 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
I0108 19:24:00.716375 20653 external_mini_cluster.cc:974] Killing /home/adar/Source/kudu/build/debug/bin/kudu-tserver with pid 4753
W0108 19:24:00.716315 4762 connection.cc:511] server connection from 127.20.43.65:57706 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
W0108 19:24:00.716430 4522 catalog_manager.cc:2553] TS 105506f2d42649b7b3fbbf617635e4ee (127.20.43.65:36477): ChangeConfig:ADD_PEER:NON_VOTER RPC failed for tablet f41268d2f2a34714b485f913b08498be: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
I0108 19:24:00.716447 4522 catalog_manager.cc:2589] Scheduling retry of ChangeConfig:ADD_PEER:NON_VOTER RPC for tablet f41268d2f2a34714b485f913b08498be with cas_config_opid_index 2 with a delay of 32 ms (attempt = 1)
W0108 19:24:00.716606 4522 connection.cc:511] server connection from 127.20.43.65:39180 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
W0108 19:24:00.716300 4509 connection.cc:511] client connection to 127.20.43.65:36477 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
W0108 19:24:00.718425 4507 connection.cc:511] client connection to 127.20.43.66:43029 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
W0108 19:24:00.718441 4509 connection.cc:511] client connection to 127.20.43.66:43029 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
W0108 19:24:00.718459 4522 connection.cc:511] client connection to 127.20.43.66:43029 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
W0108 19:24:00.718466 4523 connection.cc:511] server connection from 127.20.43.66:37745 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
I0108 19:24:00.718540 20653 external_mini_cluster.cc:974] Killing /home/adar/Source/kudu/build/debug/bin/kudu-master with pid 4510
W0108 19:24:00.720639 4509 connection.cc:511] client connection to 127.20.43.126:33196 recv error: Network error: failed to read from TLS socket: Connection reset by peer (error 104)
I0108 19:24:00.720849 20653 test_util.cc:115] -----------------------------------------------
I0108 19:24:00.720876 20653 test_util.cc:116] Had fatal failures, leaving test files at /tmp/kudutest-1000/raft_consensus-itest.RaftConsensusITest.Test_KUDU_1735.1515468125868773-20653
[ FAILED ] RaftConsensusITest.Test_KUDU_1735 (11106 ms)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment