Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Support Ticket]: Error: running postgres migrations: ERROR go migration: "20230801093422_add_piece_tracker_miner_addr.go": failed to run go migration: pq: Timed out waiting for Alter Table #1789

Open
3 of 10 tasks
dgreuel2002 opened this issue Oct 31, 2023 · 18 comments
Labels
support Support Ticket

Comments

@dgreuel2002
Copy link

Boost component

  • boost daemon - storage providers
  • boost client
  • boost UI
  • boost data-transfer
  • boost index-provider
  • booster-http
  • booster-bitswap
  • LID Database - Yugabyte/LevelDB
  • boostd-data
  • Other

Boost Version

boostd version 2.1.0-rc2+mainnet+git.fa9fc84

lotus version 1.25.0-rc1+mainnet+git.4acf337e6

lotus-miner version 1.25.0-rc1+mainnet+git.4acf337e6

go version go1.20.10 linux/amd64

Describe the problem

boostd-data run yugabyte-migrate --hosts 127.0.1.1 --connect-string="postgresql://yugabyte:yugabyte@127.0.1.1:5433?sslmode=disable" --miner-address FXXXXXX
Error: running postgres migrations: ERROR go migration: "20230801093422_add_piece_tracker_miner_addr.go": failed to run go migration: pq: Timed out waiting for Alter Table

I am unable to migrate my DB....help.

Logging Information

I1031 02:03:52.677731 168868 log.cc:1111] Time spent Fsync log took a long time: real 0.300s    user 0.000s     sys 0.000s
I1031 02:03:52.849469 169004 tablet_service.cc:918] Aborting transactions that started prior to <max> for tablet id 4f93a8e68fd045618969fc96b3b45246 excluding transaction with id dc84d1e9-541f-493e-8933-0958557f39b5
I1031 02:03:52.857981 168864 tablet.cc:2138] T 4f93a8e68fd045618969fc96b3b45246 P 21db39ed13d3416d8744d35dff7d7b3c: Alter schema from Schema [
        0:piececid[string NOT NULL HASH],
        1:createdat[int64 NULLABLE VALUE],
        2:updatedat[int64 NULLABLE VALUE]
]
properties: contain_counters: false is_transactional: true consistency_level: STRONG use_mangled_column_name: false is_ysql_catalog_table: false retain_delete_markers: false partitioning_version: 1 version 15 to Schema [
        0:piececid[string NOT NULL HASH],
        1:createdat[int64 NULLABLE VALUE],
        2:updatedat[int64 NULLABLE VALUE]
]
properties: contain_counters: false is_transactional: true consistency_level: STRONG use_mangled_column_name: false is_ysql_catalog_table: false retain_delete_markers: false partitioning_version: 1 version 16
I1031 02:03:52.858052 168864 doc_read_context.cc:48] T 4f93a8e68fd045618969fc96b3b45246 P 21db39ed13d3416d8744d35dff7d7b3c: DocReadContext, copy and add: [4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16], added: 16
I1031 02:03:52.946087 169137 pg_create_table.cc:97] PgCreateTable: creating a transactional table: yugabyte.piecetracker/{ database_oid: 13297 object_oid: 17424 }
I1031 02:03:52.954474 2126384 tablet_service.cc:1458] Processing CreateTablet for T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c (table=piecetracker [id=000033f1000030008000000000004410]), partition=hash_split: [0x0000, 0xFFFF]
I1031 02:03:52.954500 2126384 ts_tablet_manager.cc:2470] Get and update data/wal directory assignment map for table: 000033f1000030008000000000004410 and tablet 535b0253c5f64329ab458f1b96fa240d
I1031 02:03:52.956259 2126384 ts_tablet_manager.cc:830] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Created tablet metadata for table: 000033f1000030008000000000004410
I1031 02:03:52.956271 2126384 consensus_meta.cc:317] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Updating active role from UNKNOWN_ROLE to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I1031 02:03:52.957393 2126384 ts_tablet_manager.cc:1939] P 21db39ed13d3416d8744d35dff7d7b3c: Registered tablet 535b0253c5f64329ab458f1b96fa240d
I1031 02:03:52.957530 2126719 ts_tablet_manager.cc:1570] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Bootstrapping tablet
I1031 02:03:52.957656 2126719 consensus_meta.cc:317] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Updating active role from UNKNOWN_ROLE to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I1031 02:03:52.957722 2126719 retryable_requests.cc:251] Wal dir is not created, skip initializing RetryableRequestsManager for 535b0253c5f64329ab458f1b96fa240d
I1031 02:03:52.957731 2126719 tablet_peer.cc:1545] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [state=BOOTSTRAPPING]: Changed state from NOT_STARTED to BOOTSTRAPPING
I1031 02:03:52.957742 2126719 tablet_bootstrap_if.cc:96] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Bootstrap starting.
I1031 02:03:52.957765 2126719 tablet.cc:486] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Schema version for piecetracker is 0
I1031 02:03:52.957901 2126719 transaction_participant.cc:164] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Create
I1031 02:03:52.957939 2126719 docdb_rocksdb_util.cc:326] FLAGS_rocksdb_max_background_flushes was not set, automatically configuring 4 max background flushes
I1031 02:03:52.957947 2126719 docdb_rocksdb_util.cc:361] FLAGS_rocksdb_max_background_compactions was not set, automatically configuring 4 background compactions.
I1031 02:03:52.957952 2126719 docdb_rocksdb_util.cc:374] FLAGS_rocksdb_base_background_compactions was not set, automatically configuring 4 base background compactions.
I1031 02:03:52.957963 2126719 docdb_rocksdb_util.cc:616] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [R]: Write buffer size: 134217728
I1031 02:03:52.957998 2126719 tablet.cc:613] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Creating RocksDB database in dir /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004410/tablet-535b0253c5f64329ab458f1b96fa240d
I1031 02:03:52.960121 2126719 tablet.cc:805] Opening RocksDB at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004410/tablet-535b0253c5f64329ab458f1b96fa240d
I1031 02:03:52.960201 2126719 db_impl.cc:934] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [R]: Creating manifest 1
I1031 02:03:52.962750 2126719 version_set.cc:2918] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [R]: Recovered from manifest file:/filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004410/tablet-535b0253c5f64329ab458f1b96fa240d/MANIFEST-000001 succeeded,manifest_file_number is 1, next_file_number is 3, last_sequence is 1125899906842624, log_number is 0,prev_log_number is 0,max_column_family is 0, flushed_values is <NULL>
I1031 02:03:52.962762 2126719 version_set.cc:2926] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [R]: Column family [default] (ID 0), log number is 0
I1031 02:03:52.964258 2126719 tablet.cc:820] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Opening intents DB at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004410/tablet-535b0253c5f64329ab458f1b96fa240d.intents
I1031 02:03:52.964336 2126719 db_impl.cc:934] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [I]: Creating manifest 1
I1031 02:03:52.966713 2126719 version_set.cc:2918] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [I]: Recovered from manifest file:/filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004410/tablet-535b0253c5f64329ab458f1b96fa240d.intents/MANIFEST-000001 succeeded,manifest_file_number is 1, next_file_number is 3, last_sequence is 1125899906842624, log_number is 0,prev_log_number is 0,max_column_family is 0, flushed_values is <NULL>
I1031 02:03:52.966724 2126719 version_set.cc:2926] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [I]: Column family [default] (ID 0), log number is 0
I1031 02:03:52.968262 2126720 transaction_loader.cc:103] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Load transactions start
I1031 02:03:52.968267 2126719 tablet.cc:872] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Successfully opened a RocksDB database at /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004410/tablet-535b0253c5f64329ab458f1b96fa240d, obj: 0x17abaa3bb500
I1031 02:03:52.968300 2126720 transaction_loader.cc:167] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: LoadTransactions done: loaded 0 transactions
I1031 02:03:52.968305 2126719 tablet_bootstrap.cc:658] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Time spent opening tablet: real 0.010s    user 0.000s     sys 0.002s
I1031 02:03:52.968376 2126719 tablet_bootstrap.cc:578] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: No blocks or log segments found. Creating new log.
I1031 02:03:52.968400 2126719 log.cc:1369] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Setting log wal retention time to 0 seconds
I1031 02:03:52.969653 2126719 tablet_bootstrap_if.cc:96] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: No bootstrap required, opened a new log
I1031 02:03:52.969666 2126719 log.cc:1369] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Setting log wal retention time to 0 seconds
I1031 02:03:52.969674 2126719 ts_tablet_manager.cc:1618] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Time spent bootstrapping tablet: real 0.012s    user 0.000s     sys 0.003s
I1031 02:03:52.969761 2126719 transaction_participant.cc:254] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Start
I1031 02:03:52.969796 2126720 transaction_participant.cc:1319] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: LoadFinished: starting transaction status resolution
I1031 02:03:52.971603 2126719 consensus_meta.cc:317] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Updating active role from FOLLOWER to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I1031 02:03:52.971634 2126719 raft_consensus.cc:483] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending operations. Active config: opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } }
I1031 02:03:52.971650 2126719 raft_consensus.cc:512] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Consensus starting up: Expiring fail detector timer to make a prompt election more likely
I1031 02:03:52.971657 2126719 raft_consensus.cc:1120] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 21db39ed13d3416d8744d35dff7d7b3c, State: 1, Role: FOLLOWER, Watermarks: {Received: 0.0 Committed: 0.0} Leader: 0.0, new leader: , initial_fd_wait: <uninitialized>
I1031 02:03:52.971666 2126719 consensus_meta.cc:317] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Updating active role from FOLLOWER to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I1031 02:03:52.971683 2126719 consensus_queue.cc:272] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated op: 0.0, Majority replicated op: 0.0, Committed index: 0.0, Last applied: 0.0, Last appended: 0.0, Current term: 0, Majority size: -1, State: QUEUE_OPEN, Mode: NON_LEADER
I1031 02:03:52.971694 2126719 raft_consensus.cc:3417] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Calling mark dirty synchronously for reason code CONSENSUS_STARTED
I1031 02:03:52.971817 2126719 tablet_peer.cc:1545] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [state=RUNNING]: Changed state from BOOTSTRAPPING to RUNNING
I1031 02:03:52.972348 169147 raft_consensus.cc:629] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Triggering leader pre-election, mode=ELECT_EVEN_IF_LEADER_IS_ALIVE
I1031 02:03:52.972369 169147 raft_consensus.cc:3471] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Snoozing leader timeout detection for 3.255s
I1031 02:03:52.972383 169147 raft_consensus.cc:669] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Starting pre-election with config: opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } }
I1031 02:03:52.972424 169147 leader_election.cc:242] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [CANDIDATE]: Term 1 pre-election: Election decided. Result: candidate won.
I1031 02:03:52.972460 2126714 raft_consensus.cc:3471] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Snoozing leader timeout detection for 3.028s
I1031 02:03:52.972512 2126714 raft_consensus.cc:3364] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Leader pre-election won for term 1
I1031 02:03:52.972520 2126714 raft_consensus.cc:629] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Triggering leader election, mode=ELECT_EVEN_IF_LEADER_IS_ALIVE
I1031 02:03:52.972527 2126714 raft_consensus.cc:3471] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Snoozing leader timeout detection for 3.061s
I1031 02:03:52.972534 2126714 raft_consensus.cc:3532] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Advancing to term 1
I1031 02:03:52.972955 2126719 db_impl.cc:2602] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [R]: SetOptions() on column family [default], inputs: [{level0_stop_writes_trigger, 2147483647}, {level0_slowdown_writes_trigger, 2147483647}]
I1031 02:03:52.972970 2126719 db_impl.cc:2606] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [R]: [default] SetOptions succeeded
I1031 02:03:52.974040 2126719 db_impl.cc:2602] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [R]: SetOptions() on column family [default], inputs: [{disable_auto_compactions, false}]
I1031 02:03:52.974050 2126719 db_impl.cc:2606] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [R]: [default] SetOptions succeeded
I1031 02:03:52.974293 2126714 consensus_meta.cc:317] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Updating active role from FOLLOWER to FOLLOWER. Consensus state: current_term: 1 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I1031 02:03:52.974330 2126714 raft_consensus.cc:669] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 1 FOLLOWER]: Starting election with config: opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } }
I1031 02:03:52.975072 2126719 db_impl.cc:2602] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [I]: SetOptions() on column family [default], inputs: [{level0_stop_writes_trigger, 2147483647}, {level0_slowdown_writes_trigger, 2147483647}]
I1031 02:03:52.975083 2126719 db_impl.cc:2606] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [I]: [default] SetOptions succeeded
I1031 02:03:52.976102 2126719 db_impl.cc:2602] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [I]: SetOptions() on column family [default], inputs: [{disable_auto_compactions, false}]
I1031 02:03:52.976112 2126719 db_impl.cc:2606] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [I]: [default] SetOptions succeeded
I1031 02:03:52.976130 2126719 tablet_peer.cc:1426] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [state=RUNNING]: Registered log gc
I1031 02:03:52.976143 2126719 ts_tablet_manager.cc:1695] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Time spent starting tablet: real 0.006s user 0.001s     sys 0.001s
I1031 02:03:52.976154 2126719 ts_tablet_manager.cc:3075] Deleted transition in progress creating tablet for tablet 535b0253c5f64329ab458f1b96fa240d
I1031 02:03:52.976339 2126714 leader_election.cc:242] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [CANDIDATE]: Term 1 election: Election decided. Result: candidate won.
I1031 02:03:52.976362 2126714 raft_consensus.cc:3471] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 1 FOLLOWER]: Snoozing leader timeout detection for 3.181s
I1031 02:03:52.976372 2126714 raft_consensus.cc:3378] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 1 FOLLOWER]: Leader election won for term 1
I1031 02:03:52.976378 2126714 replica_state.cc:1168] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 1 FOLLOWER]: Reset our lease: 679786.828s
I1031 02:03:52.976388 2126714 replica_state.cc:1467] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 1 FOLLOWER]: SetLeaderNoOpCommittedUnlocked(0), committed: 0.0, received: 0.0
I1031 02:03:52.976397 2126714 consensus_meta.cc:317] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Updating active role from FOLLOWER to LEADER. Consensus state: current_term: 1 leader_uuid: "21db39ed13d3416d8744d35dff7d7b3c" config { opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I1031 02:03:52.976416 2126714 raft_consensus.cc:3417] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: Calling mark dirty synchronously for reason code NEW_LEADER_ELECTED
I1031 02:03:52.976428 2126714 raft_consensus.cc:1061] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: Becoming Leader. State: Replica: 21db39ed13d3416d8744d35dff7d7b3c, State: 1, Role: LEADER, Watermarks: {Received: 0.0 Committed: 0.0} Leader: 0.0
I1031 02:03:52.976444 2126714 consensus_queue.cc:254] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [LEADER]: Queue going to LEADER mode. State: All replicated op: 0.0, Majority replicated op: 0.0, Committed index: 0.0, Last applied: 0.0, Last appended: 0.0, Current term: 1, Majority size: 1, State: QUEUE_OPEN, Mode: LEADER, active raft config: opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } }
I1031 02:03:52.976464 2126714 raft_consensus.cc:1079] Sending NO_OP at op 0.0
I1031 02:03:52.976819 168864 replica_state.cc:1467] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: SetLeaderNoOpCommittedUnlocked(1), committed: 0.0, received: 1.1
I1031 02:03:52.976847 168864 replica_state.cc:787] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: Advanced the committed_op_id across terms. Last committed operation was: 0.0 New committed index is: 1.1
I1031 02:03:53.018636 169137 table_creator.cc:405] Created table yugabyte.piecetracker of type PGSQL_TABLE_TYPE
I1031 02:03:53.165849 169040 tablet_service.cc:918] Aborting transactions that started prior to <max> for tablet id 8ad7954465a54cc8ae80907eaa42fe52 excluding transaction with id dc84d1e9-541f-493e-8933-0958557f39b5
I1031 02:03:53.172645 168864 tablet.cc:2138] T 8ad7954465a54cc8ae80907eaa42fe52 P 21db39ed13d3416d8744d35dff7d7b3c: Alter schema from Schema [
        0:createdat[int64 NOT NULL HASH],
        1:ybidxbasectid[binary NOT NULL RANGE_ASC_NULL_FIRST]
]
properties: contain_counters: false is_transactional: true consistency_level: STRONG use_mangled_column_name: false is_ysql_catalog_table: false retain_delete_markers: false partitioning_version: 1 version 6 to Schema [
        0:createdat[int64 NOT NULL HASH],
        1:ybidxbasectid[binary NOT NULL RANGE_ASC_NULL_FIRST]
]
properties: contain_counters: false is_transactional: true consistency_level: STRONG use_mangled_column_name: false is_ysql_catalog_table: false retain_delete_markers: false partitioning_version: 1 version 7
I1031 02:03:53.172713 168864 doc_read_context.cc:48] T 8ad7954465a54cc8ae80907eaa42fe52 P 21db39ed13d3416d8744d35dff7d7b3c: DocReadContext, copy and add: [0, 1, 2, 3, 4, 5, 6, 7], added: 7
I1031 02:03:53.206823 169004 pg_create_table.cc:97] PgCreateTable: creating a transactional index: yugabyte.piecetrackercreatedat/{ database_oid: 13297 object_oid: 17427 }
I1031 02:03:53.220696 168864 tablet.cc:2138] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Alter schema from Schema [
        0:ybrowid[binary NOT NULL HASH],
        1:piececid[string NULLABLE VALUE],
        2:createdat[int64 NULLABLE VALUE],
        3:updatedat[int64 NULLABLE VALUE]
]
properties: contain_counters: false is_transactional: true consistency_level: STRONG use_mangled_column_name: false num_tablets: 1 is_ysql_catalog_table: false retain_delete_markers: false partitioning_version: 1 version 0 to Schema [
        0:ybrowid[binary NOT NULL HASH],
        1:piececid[string NULLABLE VALUE],
        2:createdat[int64 NULLABLE VALUE],
        3:updatedat[int64 NULLABLE VALUE]
]
properties: contain_counters: false is_transactional: true consistency_level: STRONG use_mangled_column_name: false num_tablets: 1 is_ysql_catalog_table: false retain_delete_markers: false partitioning_version: 1 version 1
I1031 02:03:53.220750 168864 doc_read_context.cc:48] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: DocReadContext, copy and add: [0, 1], added: 1
I1031 02:03:53.226569 169137 tablet_service.cc:1458] Processing CreateTablet for T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c (table=piecetrackercreatedat [id=000033f1000030008000000000004413]), partition=hash_split: [0x0000, 0xFFFF]
I1031 02:03:53.226603 169137 ts_tablet_manager.cc:2470] Get and update data/wal directory assignment map for table: 000033f1000030008000000000004413 and tablet d69a11d17bb34b2abb429e404d506db0
I1031 02:03:53.228343 169137 ts_tablet_manager.cc:830] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Created tablet metadata for table: 000033f1000030008000000000004413
I1031 02:03:53.228359 169137 consensus_meta.cc:317] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Updating active role from UNKNOWN_ROLE to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I1031 02:03:53.229523 169137 ts_tablet_manager.cc:1939] P 21db39ed13d3416d8744d35dff7d7b3c: Registered tablet d69a11d17bb34b2abb429e404d506db0
I1031 02:03:53.229550 2126719 ts_tablet_manager.cc:1570] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Bootstrapping tablet
I1031 02:03:53.229635 2126719 consensus_meta.cc:317] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Updating active role from UNKNOWN_ROLE to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I1031 02:03:53.229683 2126719 retryable_requests.cc:251] Wal dir is not created, skip initializing RetryableRequestsManager for d69a11d17bb34b2abb429e404d506db0
I1031 02:03:53.229698 2126719 tablet_peer.cc:1545] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [state=BOOTSTRAPPING]: Changed state from NOT_STARTED to BOOTSTRAPPING
I1031 02:03:53.229707 2126719 tablet_bootstrap_if.cc:96] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Bootstrap starting.
I1031 02:03:53.229727 2126719 tablet.cc:486] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Schema version for piecetrackercreatedat is 0
I1031 02:03:53.229851 2126719 transaction_participant.cc:164] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Create
I1031 02:03:53.229880 2126719 docdb_rocksdb_util.cc:616] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [R]: Write buffer size: 134217728
I1031 02:03:53.229904 2126719 tablet.cc:613] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Creating RocksDB database in dir /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004413/tablet-d69a11d17bb34b2abb429e404d506db0
I1031 02:03:53.231984 2126719 tablet.cc:805] Opening RocksDB at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004413/tablet-d69a11d17bb34b2abb429e404d506db0
I1031 02:03:53.232045 2126719 db_impl.cc:934] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [R]: Creating manifest 1
I1031 02:03:53.234458 2126719 version_set.cc:2918] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [R]: Recovered from manifest file:/filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004413/tablet-d69a11d17bb34b2abb429e404d506db0/MANIFEST-000001 succeeded,manifest_file_number is 1, next_file_number is 3, last_sequence is 1125899906842624, log_number is 0,prev_log_number is 0,max_column_family is 0, flushed_values is <NULL>
I1031 02:03:53.234469 2126719 version_set.cc:2926] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [R]: Column family [default] (ID 0), log number is 0
I1031 02:03:53.235898 2126719 tablet.cc:820] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Opening intents DB at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004413/tablet-d69a11d17bb34b2abb429e404d506db0.intents
I1031 02:03:53.235967 2126719 db_impl.cc:934] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [I]: Creating manifest 1
I1031 02:03:53.238286 2126719 version_set.cc:2918] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [I]: Recovered from manifest file:/filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004413/tablet-d69a11d17bb34b2abb429e404d506db0.intents/MANIFEST-000001 succeeded,manifest_file_number is 1, next_file_number is 3, last_sequence is 1125899906842624, log_number is 0,prev_log_number is 0,max_column_family is 0, flushed_values is <NULL>
I1031 02:03:53.238297 2126719 version_set.cc:2926] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [I]: Column family [default] (ID 0), log number is 0
I1031 02:03:53.239931 2126727 transaction_loader.cc:103] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Load transactions start
I1031 02:03:53.239935 2126719 tablet.cc:872] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Successfully opened a RocksDB database at /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004413/tablet-d69a11d17bb34b2abb429e404d506db0, obj: 0x17abbf1ed500
I1031 02:03:53.239969 2126727 transaction_loader.cc:167] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: LoadTransactions done: loaded 0 transactions
I1031 02:03:53.239974 2126719 tablet_bootstrap.cc:658] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Time spent opening tablet: real 0.010s    user 0.002s     sys 0.000s
I1031 02:03:53.240047 2126719 tablet_bootstrap.cc:578] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: No blocks or log segments found. Creating new log.
I1031 02:03:53.240068 2126719 log.cc:1369] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Setting log wal retention time to 0 seconds
I1031 02:03:53.241278 2126719 tablet_bootstrap_if.cc:96] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: No bootstrap required, opened a new log
I1031 02:03:53.241291 2126719 log.cc:1369] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Setting log wal retention time to 0 seconds
I1031 02:03:53.241298 2126719 ts_tablet_manager.cc:1618] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Time spent bootstrapping tablet: real 0.012s    user 0.002s     sys 0.000s
I1031 02:03:53.241355 2126719 transaction_participant.cc:254] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Start
I1031 02:03:53.241389 2126727 transaction_participant.cc:1319] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: LoadFinished: starting transaction status resolution
I1031 02:03:53.242969 2126719 consensus_meta.cc:317] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Updating active role from FOLLOWER to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I1031 02:03:53.242990 2126719 raft_consensus.cc:483] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending operations. Active config: opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } }
I1031 02:03:53.243002 2126719 raft_consensus.cc:512] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Consensus starting up: Expiring fail detector timer to make a prompt election more likely
I1031 02:03:53.243006 2126719 raft_consensus.cc:1120] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 21db39ed13d3416d8744d35dff7d7b3c, State: 1, Role: FOLLOWER, Watermarks: {Received: 0.0 Committed: 0.0} Leader: 0.0, new leader: , initial_fd_wait: <uninitialized>
I1031 02:03:53.243013 2126719 consensus_meta.cc:317] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Updating active role from FOLLOWER to FOLLOWER. Consensus state: current_term: 0 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I1031 02:03:53.243027 2126719 consensus_queue.cc:272] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [NON_LEADER]: Queue going to NON_LEADER mode. State: All replicated op: 0.0, Majority replicated op: 0.0, Committed index: 0.0, Last applied: 0.0, Last appended: 0.0, Current term: 0, Majority size: -1, State: QUEUE_OPEN, Mode: NON_LEADER
I1031 02:03:53.243034 2126719 raft_consensus.cc:3417] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Calling mark dirty synchronously for reason code CONSENSUS_STARTED
I1031 02:03:53.243042 2126719 tablet_peer.cc:1545] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [state=RUNNING]: Changed state from BOOTSTRAPPING to RUNNING
I1031 02:03:53.243446 169147 raft_consensus.cc:629] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Triggering leader pre-election, mode=ELECT_EVEN_IF_LEADER_IS_ALIVE
I1031 02:03:53.243467 169147 raft_consensus.cc:3471] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Snoozing leader timeout detection for 3.299s
I1031 02:03:53.243479 169147 raft_consensus.cc:669] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Starting pre-election with config: opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } }
I1031 02:03:53.243506 169147 leader_election.cc:242] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [CANDIDATE]: Term 1 pre-election: Election decided. Result: candidate won.
I1031 02:03:53.243531 2126714 raft_consensus.cc:3471] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Snoozing leader timeout detection for 3.143s
I1031 02:03:53.243582 2126714 raft_consensus.cc:3364] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Leader pre-election won for term 1
I1031 02:03:53.243589 2126714 raft_consensus.cc:629] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Triggering leader election, mode=ELECT_EVEN_IF_LEADER_IS_ALIVE
I1031 02:03:53.243597 2126714 raft_consensus.cc:3471] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Snoozing leader timeout detection for 3.289s
I1031 02:03:53.243603 2126714 raft_consensus.cc:3532] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 0 FOLLOWER]: Advancing to term 1
I1031 02:03:53.243976 2126719 db_impl.cc:2602] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [R]: SetOptions() on column family [default], inputs: [{level0_stop_writes_trigger, 2147483647}, {level0_slowdown_writes_trigger, 2147483647}]
I1031 02:03:53.243985 2126719 db_impl.cc:2606] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [R]: [default] SetOptions succeeded
I1031 02:03:53.245129 2126719 db_impl.cc:2602] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [R]: SetOptions() on column family [default], inputs: [{disable_auto_compactions, false}]
I1031 02:03:53.245138 2126719 db_impl.cc:2606] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [R]: [default] SetOptions succeeded
I1031 02:03:53.245411 2126714 consensus_meta.cc:317] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Updating active role from FOLLOWER to FOLLOWER. Consensus state: current_term: 1 leader_uuid: "" config { opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I1031 02:03:53.245447 2126714 raft_consensus.cc:669] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 1 FOLLOWER]: Starting election with config: opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } }
I1031 02:03:53.246124 2126719 db_impl.cc:2602] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [I]: SetOptions() on column family [default], inputs: [{level0_stop_writes_trigger, 2147483647}, {level0_slowdown_writes_trigger, 2147483647}]
I1031 02:03:53.246137 2126719 db_impl.cc:2606] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [I]: [default] SetOptions succeeded
I1031 02:03:53.247128 2126719 db_impl.cc:2602] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [I]: SetOptions() on column family [default], inputs: [{disable_auto_compactions, false}]
I1031 02:03:53.247136 2126719 db_impl.cc:2606] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [I]: [default] SetOptions succeeded
I1031 02:03:53.247148 2126719 tablet_peer.cc:1426] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [state=RUNNING]: Registered log gc
I1031 02:03:53.247154 2126719 ts_tablet_manager.cc:1695] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Time spent starting tablet: real 0.006s user 0.001s     sys 0.001s
I1031 02:03:53.247164 2126719 ts_tablet_manager.cc:3075] Deleted transition in progress creating tablet for tablet d69a11d17bb34b2abb429e404d506db0
I1031 02:03:53.247437 2126714 leader_election.cc:242] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [CANDIDATE]: Term 1 election: Election decided. Result: candidate won.
I1031 02:03:53.247457 2126714 raft_consensus.cc:3471] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 1 FOLLOWER]: Snoozing leader timeout detection for 3.144s
I1031 02:03:53.247465 2126714 raft_consensus.cc:3378] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 1 FOLLOWER]: Leader election won for term 1
I1031 02:03:53.247471 2126714 replica_state.cc:1168] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 1 FOLLOWER]: Reset our lease: 679787.100s
I1031 02:03:53.247480 2126714 replica_state.cc:1467] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 1 FOLLOWER]: SetLeaderNoOpCommittedUnlocked(0), committed: 0.0, received: 0.0
I1031 02:03:53.247489 2126714 consensus_meta.cc:317] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Updating active role from FOLLOWER to LEADER. Consensus state: current_term: 1 leader_uuid: "21db39ed13d3416d8744d35dff7d7b3c" config { opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } } }, has_pending_config = 0
I1031 02:03:53.247507 2126714 raft_consensus.cc:3417] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: Calling mark dirty synchronously for reason code NEW_LEADER_ELECTED
I1031 02:03:53.247517 2126714 raft_consensus.cc:1061] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: Becoming Leader. State: Replica: 21db39ed13d3416d8744d35dff7d7b3c, State: 1, Role: LEADER, Watermarks: {Received: 0.0 Committed: 0.0} Leader: 0.0
I1031 02:03:53.247530 2126714 consensus_queue.cc:254] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [LEADER]: Queue going to LEADER mode. State: All replicated op: 0.0, Majority replicated op: 0.0, Committed index: 0.0, Last applied: 0.0, Last appended: 0.0, Current term: 1, Majority size: 1, State: QUEUE_OPEN, Mode: LEADER, active raft config: opid_index: -1 peers { permanent_uuid: "21db39ed13d3416d8744d35dff7d7b3c" member_type: VOTER last_known_private_addr { host: "127.0.1.1" port: 9100 } last_known_broadcast_addr { host: "127.0.1.1" port: 9100 } cloud_info { placement_cloud: "cloud1" placement_region: "datacenter1" placement_zone: "rack1" } }
I1031 02:03:53.247550 2126714 raft_consensus.cc:1079] Sending NO_OP at op 0.0
I1031 02:03:53.247866 168864 replica_state.cc:1467] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: SetLeaderNoOpCommittedUnlocked(1), committed: 0.0, received: 1.1
I1031 02:03:53.247890 168864 replica_state.cc:787] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: Advanced the committed_op_id across terms. Last committed operation was: 0.0 New committed index is: 1.1
I1031 02:03:53.280046 169004 table_creator.cc:405] Created index yugabyte.piecetrackercreatedat of type PGSQL_TABLE_TYPE
I1031 02:03:55.206732 168881 reactor.cc:590] TabletServer_R005: DEBUG: Closing idle connection: Connection (0x000017ac7edb3b18) server 127.0.1.1:39283 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:04:06.206013 168877 reactor.cc:590] TabletServer_R001: DEBUG: Closing idle connection: Connection (0x000017abbf6ff218) server 127.0.1.1:40309 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:04:17.306095 168882 reactor.cc:590] TabletServer_R006: DEBUG: Closing idle connection: Connection (0x000017ac185d1b18) server 127.0.1.1:44485 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:04:19.159258 2126713 log.cc:1111] Time spent Fsync log took a long time: real 0.124s   user 0.000s     sys 0.000s
I1031 02:04:25.350040 2126713 log.cc:1111] Time spent Fsync log took a long time: real 0.122s   user 0.000s     sys 0.000s
I1031 02:04:28.306533 168884 reactor.cc:590] TabletServer_R008: DEBUG: Closing idle connection: Connection (0x000017ac303dfe78) server 127.0.1.1:41077 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:04:39.306900 168888 reactor.cc:590] TabletServer_R012: DEBUG: Closing idle connection: Connection (0x000017ac7e5c4918) server 127.0.1.1:44309 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:04:48.843652 2126713 log.cc:1111] Time spent Fsync log took a long time: real 0.113s   user 0.000s     sys 0.000s
I1031 02:04:50.405828 168878 reactor.cc:590] TabletServer_R002: DEBUG: Closing idle connection: Connection (0x000017abbee0a7f8) server 127.0.1.1:45835 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:04:53.022375 2126713 log.cc:1111] Time spent Fsync log took a long time: real 0.131s   user 0.000s     sys 0.000s
I1031 02:04:53.390187 169040 client_master_rpc.cc:78] 0x000017aba1725470 -> IsAlterTableDone: Failed: Timed out (yb/client/client_master_rpc.cc:43): Request IsAlterTableDone timed out after deadline expired
W1031 02:04:53.390247 169040 yb_rpc.cc:335] Call yb.tserver.PgClientService.AlterTable 127.0.0.1:50618 => 127.0.1.1:9100 (request call id 378) took 60003ms (client timeout 60000ms).
I1031 02:04:53.390260 169010 client-internal.cc:2590] New master addresses: [127.0.1.1:7100]
I1031 02:04:53.485462 169361 tablet_service.cc:1536] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Processing DeleteTablet with delete_type TABLET_DATA_DELETED (Table deleted at 2023-10-31 02:04:53 UTC) from 127.0.1.1:45649
I1031 02:04:53.485499 169361 tablet_peer.cc:464] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [state=RUNNING]: Initiating TabletPeer shutdown
I1031 02:04:53.485510 169361 tablet.cc:1045] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: StartShutdown
I1031 02:04:53.485538 168873 poller.cc:66] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Poll stopped: Aborted (yb/rpc/scheduler.cc:65): Task aborted
I1031 02:04:53.485569 169361 transaction_participant.cc:215] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Shutdown
I1031 02:04:53.485579 169361 tablet_peer.cc:481] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [state=QUIESCING]: Started shutdown from state: RUNNING
I1031 02:04:53.485594 169361 maintenance_manager.cc:198] Unregistered op LogGCOp(535b0253c5f64329ab458f1b96fa240d)
I1031 02:04:53.485602 169361 raft_consensus.cc:2759] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: Shutdown.
I1031 02:04:53.485618 169361 raft_consensus.cc:2790] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: Raft consensus is shut down!
I1031 02:04:53.485626 169361 tablet_peer.cc:613] Aborting transactions that started prior to <max> for tablet id 535b0253c5f64329ab458f1b96fa240d
I1031 02:04:53.487730 169361 tablet.cc:1061] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: CompleteShutdown
I1031 02:04:53.487743 169361 tablet.cc:1045] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: StartShutdown
I1031 02:04:53.487758 169361 db_impl.cc:800] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [R]: Shutting down RocksDB at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004410/tablet-535b0253c5f64329ab458f1b96fa240d
I1031 02:04:53.487766 169361 db_impl.cc:800] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [I]: Shutting down RocksDB at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004410/tablet-535b0253c5f64329ab458f1b96fa240d.intents
I1031 02:04:53.487839 169361 db_impl.cc:828] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [I]: Skipping mem table flush - disable_flush_on_shutdown_ is set
I1031 02:04:53.487987 169361 db_impl.cc:923] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [I]: Shutdown done
I1031 02:04:53.488078 169361 db_impl.cc:923] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [R]: Shutdown done
I1031 02:04:53.488114 169361 tablet.cc:1045] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: StartShutdown
I1031 02:04:53.488353 169361 raft_consensus.cc:2759] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: Shutdown.
I1031 02:04:53.488401 169361 ts_tablet_manager.cc:2990] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Deleting tablet data with delete state TABLET_DATA_DELETED
I1031 02:04:53.488411 169361 docdb_rocksdb_util.cc:616] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Write buffer size: 134217728
I1031 02:04:53.488426 169361 tablet_metadata.cc:721] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Destroying regular db at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004410/tablet-535b0253c5f64329ab458f1b96fa240d
I1031 02:04:53.488629 169361 tablet_metadata.cc:727] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Successfully destroyed regular DB at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004410/tablet-535b0253c5f64329ab458f1b96fa240d
I1031 02:04:53.488788 169361 tablet_metadata.cc:744] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Successfully destroyed provisional records DB at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004410/tablet-535b0253c5f64329ab458f1b96fa240d.intents
I1031 02:04:53.491986 169361 ts_tablet_manager.cc:3000] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Tablet deleted. Last logged OpId: 1.5
I1031 02:04:53.492004 169361 log.cc:1610] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Deleting WAL dir /filecoin/boost/var/data/yb-data/tserver/wals/table-000033f1000030008000000000004410/tablet-535b0253c5f64329ab458f1b96fa240d
I1031 02:04:53.492208 169361 consensus_meta.cc:126] T 535b0253c5f64329ab458f1b96fa240d Deleting consensus metadata
I1031 02:04:53.492233 169361 tablet_bootstrap_if.cc:96] T 535b0253c5f64329ab458f1b96fa240d P 21db39ed13d3416d8744d35dff7d7b3c: Deleted tablet blocks from disk
I1031 02:04:53.492246 169361 ts_tablet_manager.cc:2622] Unregister data/wal directory assignment map for table: 000033f1000030008000000000004410 and tablet 535b0253c5f64329ab458f1b96fa240d
I1031 02:04:53.492255 169361 ts_tablet_manager.cc:3075] Deleted transition in progress deleting tablet for tablet 535b0253c5f64329ab458f1b96fa240d
I1031 02:04:53.494093 169004 tablet_service.cc:1536] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Processing DeleteTablet with delete_type TABLET_DATA_DELETED (Table deleted at 2023-10-31 02:04:53 UTC) from 127.0.1.1:44771
I1031 02:04:53.494107 169004 tablet_peer.cc:464] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [state=RUNNING]: Initiating TabletPeer shutdown
I1031 02:04:53.494114 169004 tablet.cc:1045] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: StartShutdown
I1031 02:04:53.494134 168872 poller.cc:66] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Poll stopped: Aborted (yb/rpc/scheduler.cc:65): Task aborted
I1031 02:04:53.494161 169004 transaction_participant.cc:215] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Shutdown
I1031 02:04:53.494166 169004 tablet_peer.cc:481] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [state=QUIESCING]: Started shutdown from state: RUNNING
I1031 02:04:53.494172 169004 maintenance_manager.cc:198] Unregistered op LogGCOp(d69a11d17bb34b2abb429e404d506db0)
I1031 02:04:53.494175 169004 raft_consensus.cc:2759] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: Shutdown.
I1031 02:04:53.494182 169004 raft_consensus.cc:2790] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: Raft consensus is shut down!
I1031 02:04:53.494186 169004 tablet_peer.cc:613] Aborting transactions that started prior to <max> for tablet id d69a11d17bb34b2abb429e404d506db0
I1031 02:04:53.494863 169004 tablet.cc:1061] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: CompleteShutdown
I1031 02:04:53.494869 169004 tablet.cc:1045] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: StartShutdown
I1031 02:04:53.494876 169004 db_impl.cc:800] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [R]: Shutting down RocksDB at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004413/tablet-d69a11d17bb34b2abb429e404d506db0
I1031 02:04:53.494880 169004 db_impl.cc:800] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [I]: Shutting down RocksDB at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004413/tablet-d69a11d17bb34b2abb429e404d506db0.intents
I1031 02:04:53.494904 169004 db_impl.cc:828] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [I]: Skipping mem table flush - disable_flush_on_shutdown_ is set
I1031 02:04:53.494961 169004 db_impl.cc:923] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [I]: Shutdown done
I1031 02:04:53.495004 169004 db_impl.cc:923] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [R]: Shutdown done
I1031 02:04:53.495021 169004 tablet.cc:1045] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: StartShutdown
I1031 02:04:53.495213 169004 raft_consensus.cc:2759] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c [term 1 LEADER]: Shutdown.
I1031 02:04:53.495232 169004 ts_tablet_manager.cc:2990] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Deleting tablet data with delete state TABLET_DATA_DELETED
I1031 02:04:53.495237 169004 docdb_rocksdb_util.cc:616] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Write buffer size: 134217728
I1031 02:04:53.495244 169004 tablet_metadata.cc:721] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Destroying regular db at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004413/tablet-d69a11d17bb34b2abb429e404d506db0
I1031 02:04:53.495333 169004 tablet_metadata.cc:727] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Successfully destroyed regular DB at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004413/tablet-d69a11d17bb34b2abb429e404d506db0
I1031 02:04:53.495410 169004 tablet_metadata.cc:744] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Successfully destroyed provisional records DB at: /filecoin/boost/var/data/yb-data/tserver/data/rocksdb/table-000033f1000030008000000000004413/tablet-d69a11d17bb34b2abb429e404d506db0.intents
I1031 02:04:53.498061 169004 ts_tablet_manager.cc:3000] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Tablet deleted. Last logged OpId: 1.4
I1031 02:04:53.498071 169004 log.cc:1610] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Deleting WAL dir /filecoin/boost/var/data/yb-data/tserver/wals/table-000033f1000030008000000000004413/tablet-d69a11d17bb34b2abb429e404d506db0
I1031 02:04:53.498150 169004 consensus_meta.cc:126] T d69a11d17bb34b2abb429e404d506db0 Deleting consensus metadata
I1031 02:04:53.498164 169004 tablet_bootstrap_if.cc:96] T d69a11d17bb34b2abb429e404d506db0 P 21db39ed13d3416d8744d35dff7d7b3c: Deleted tablet blocks from disk
I1031 02:04:53.498170 169004 ts_tablet_manager.cc:2622] Unregister data/wal directory assignment map for table: 000033f1000030008000000000004413 and tablet d69a11d17bb34b2abb429e404d506db0
I1031 02:04:53.498175 169004 ts_tablet_manager.cc:3075] Deleted transition in progress deleting tablet for tablet d69a11d17bb34b2abb429e404d506db0
I1031 02:05:01.305889 168877 reactor.cc:590] TabletServer_R001: DEBUG: Closing idle connection: Connection (0x000017abd3429c38) server 127.0.1.1:35367 => 127.0.1.1:9100 - it has been idle for 65.003s
I1031 02:05:12.306499 168882 reactor.cc:590] TabletServer_R006: DEBUG: Closing idle connection: Connection (0x000017ac7edb37b8) server 127.0.1.1:43265 => 127.0.1.1:9100 - it has been idle for 65.003s
I1031 02:05:23.405758 168881 reactor.cc:590] TabletServer_R005: DEBUG: Closing idle connection: Connection (0x000017ac7ebb47f8) server 127.0.1.1:37715 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:05:24.768067 168868 log.cc:1111] Time spent Fsync log took a long time: real 0.181s    user 0.000s     sys 0.000s
I1031 02:05:34.505748 168877 reactor.cc:590] TabletServer_R001: DEBUG: Closing idle connection: Connection (0x000017ac7e5c4a38) server 127.0.1.1:38693 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:05:45.507325 168890 reactor.cc:590] TabletServer_R014: DEBUG: Closing idle connection: Connection (0x000017ac7edb3c38) server 127.0.1.1:32949 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:05:56.506985 168891 reactor.cc:590] TabletServer_R015: DEBUG: Closing idle connection: Connection (0x000017abbe6dab58) server 127.0.1.1:44167 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:05:58.006551 168887 reactor.cc:590] TabletServer_R011: DEBUG: Closing idle connection: Connection (0x000017ac7e948fd8) server 127.0.1.1:35009 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:05:58.306340 168888 reactor.cc:590] TabletServer_R012: DEBUG: Closing idle connection: Connection (0x000017ac7ec0b0f8) server 127.0.1.1:39993 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:05:58.307255 168890 reactor.cc:590] TabletServer_R014: DEBUG: Closing idle connection: Connection (0x000017ac7e5c4378) server 127.0.1.1:39227 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:05:58.405655 168880 reactor.cc:590] TabletServer_R004: DEBUG: Closing idle connection: Connection (0x000017ac7e5c58d8) server 127.0.1.1:45917 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:05:58.505643 168877 reactor.cc:590] TabletServer_R001: DEBUG: Closing idle connection: Connection (0x000017acec14d338) server 127.0.1.1:45649 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:05:58.506033 168883 reactor.cc:590] TabletServer_R007: DEBUG: Closing idle connection: Connection (0x000017abbf0a7b18) server 127.0.1.1:41505 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:05:58.506747 168888 reactor.cc:590] TabletServer_R012: DEBUG: Closing idle connection: Connection (0x000017abcc53b218) server 127.0.1.1:44771 => 127.0.1.1:9100 - it has been idle for 65.099s
I1031 02:05:58.606515 168885 reactor.cc:590] TabletServer_R009: DEBUG: Closing idle connection: Connection (0x000017ac504f4018) server 127.0.1.1:36203 => 127.0.1.1:9100 - it has been idle for 65.099s

Repo Steps

I am trying to migrate from 2.0.0 to 2.1.0-rc2+mainnet+git.fa9fc84

I followed steps, when i run boostd-data it tells me i need to migrate. I run the migrate and get the timeout on alter table.

@dgreuel2002 dgreuel2002 added the support Support Ticket label Oct 31, 2023
@LexLuthr
Copy link
Collaborator

Please provide details about your Yugabyte deployment.

  1. CPU
  2. Memory
  3. Storage type
  4. Machine type (VM? Kubernetes?)
  5. OS
  6. Number of nodes
  7. NTP/Chrony is configured?
  8. Filesystem used by Yugabyte storage

@dgreuel2002
Copy link
Author

dgreuel2002 commented Nov 3, 2023

  1. AMD Ryzen Threadripper 3960X 24-Core Processor
  2. 256 GB of Ram (8x32GB - DDR4-3600)
  3. NVME
  4. Headless Server Linux
  5. Ubuntu VERSION="20.04.6 LTS (Focal Fossa)"
  6. 1
  7. Yes

@dgreuel2002
Copy link
Author

dgreuel2002 commented Nov 3, 2023

I connected to database, some tables return data and some time out....

./ycqlsh
Connected to local cluster at 127.0.1.1:9042.
[ycqlsh 5.0.1 | Cassandra 3.9-SNAPSHOT | CQL spec 3.4.2 | Native protocol v4]
Use HELP for help.
ycqlsh> SELECT COUNT(*) FROM idx.piecedeal;

 count
-------
  4719

(1 rows)
ycqlsh> SELECT COUNT(*) FROM idx.piecemetadata ;

 count
-------
  3893

(1 rows)
ycqlsh> SELECT COUNT(*) FROM idx.pieceblockoffsetsize ;
OperationTimedOut: errors={'127.0.1.1:9042': 'Client request timeout. See Session.execute[_async](timeout)'}, last_host=127.0.1.1:9042
ycqlsh> SELECT COUNT(*) FROM idx.payloadtopieces;
OperationTimedOut: errors={'127.0.1.1:9042': 'Client request timeout. See Session.execute[_async](timeout)'}, last_host=127.0.1.1:9042
ycqlsh>


The Yuga GUI looks ok...shows tablets under tables

image
image
image
image

@LexLuthr
Copy link
Collaborator

LexLuthr commented Nov 3, 2023

@dgreuel2002 I wouldn't trust the GUI for now. We have seen similar behaviour on a completely broken cluster. It sounds like there is something wrong with your Yugabyte node if you cannot run a Count query. I would suggest checking out #1797 once and ensure that your deployment is correct.
The best people to help us with this would be Yugabyte team itself. Can you please join the Yugabyte slack https://communityinviter.com/apps/yugabyte-db/register and start a new help thread there? I will also monitor the thread and keep an eye on things from Boost perspective.

@davidd8 davidd8 added this to the Boost v2 stability milestone Nov 6, 2023
@davidd8
Copy link
Collaborator

davidd8 commented Nov 27, 2023

@LexLuthr @dgreuel2002, any updates here, has this issue been resolved?

@davidd8 davidd8 changed the title [Support Ticket]: [Support Ticket]: Error: running postgres migrations: ERROR go migration: "20230801093422_add_piece_tracker_miner_addr.go": failed to run go migration: pq: Timed out waiting for Alter Table Nov 27, 2023
@dgreuel2002
Copy link
Author

dgreuel2002 commented Nov 29, 2023

@davidd8 There has been no updates. I applied to be a part of Yugabyte slack and I didnt get the email. I just tried registering with another email address and it worked. I will submit the ticket on Yuga Slack now.

@ddorian
Copy link

ddorian commented Nov 29, 2023

Can we know which ALTER TABLE statement failed? Because there are 3 in the migration.

@LexLuthr
Copy link
Collaborator

@dgreuel2002 I am assuming you haven't started migration yet. If that is the case, then I would recommend removing the current YB deployment and doing another one from scratch. Deployment using yugabyted is now supported so it should be an easy task.

@dgreuel2002
Copy link
Author

dgreuel2002 commented Feb 20, 2024

@ddorian I am not sure how to see which statement failed? You want Yuga logs? This is the only message in the WARNING LOG. . W0220 00:38:00.328931 65125 yb_rpc.cc:335] Call yb.tserver.PgClientService.AlterTable 127.0.0.1:46512 => 127.0.1.1:9100 (request call id 378) took 60007ms (client timeout 60000ms).

@LexLuthr The migration keeps failing so i would agree that it hasn't been started yet. Just to be clear though, I went from 1.0 to 2.0 and migrated. At that point, i took deals for a solid month. Now I am trying to migrate to 2.1. Is it still safe to nuke and start from scratch if I have take some deals from boost already?!? I am a little confused here.

@LexLuthr
Copy link
Collaborator

@dgreuel2002 Can you please get me the result of the following query using ysqlsh?

SELECT count(*) FROM PieceTracker;

We can try to alter this table manually and let the migration move from this point.

@dgreuel2002
Copy link
Author

dgreuel2002 commented Feb 22, 2024

@LexLuthr

yugabyte=# SELECT count(*) FROM PieceTracker;
 count
-------
  3711
(1 row)

@LexLuthr
Copy link
Collaborator

Can you please also get me select * from goose_db_version;?

@dgreuel2002
Copy link
Author

dgreuel2002 commented Feb 23, 2024

yugabyte=# select * from goose_db_version;
 id | version_id | is_applied |          tstamp
----+------------+------------+---------------------------
  1 |          0 | t          | 2023-10-23 07:20:21.31317
(1 row)


@LexLuthr
Copy link
Collaborator

LexLuthr commented Feb 23, 2024

Please run the following Postgres queries on your tables in the specified order.

  1. Shutdown all boost services.
  2. Shutdown boostd-data
  3. Open a ysqlsh terminal to yugabyte
  4. ALTER TABLE PieceTracker DROP CONSTRAINT piecetracker_pkey;
  5. ALTER TABLE PieceTracker ADD COLUMN MinerAddr TEXT NOT NULL DEFAULT;
  6. UPDATE PieceTracker SET MinerAddr='MINERID'; <<----- Please replace MINERID with your miner ID
  7. ALTER TABLE PieceFlagged DROP CONSTRAINT pieceflagged_pkey;
  8. ALTER TABLE PieceFlagged ADD COLUMN MinerAddr TEXT NOT NULL DEFAULT;
  9. UPDATE PieceFlagged SET MinerAddr='MINERID'; <<------ Please replace MINERID with your miner ID
  10. ALTER TABLE PieceTracker ADD CONSTRAINT piecetracker_pkey PRIMARY KEY (MinerAddr, PieceCid);
  11. ALTER TABLE PieceFlagged ADD CONSTRAINT pieceflagged_pkey PRIMARY KEY (MinerAddr, PieceCid);
  12. INSERT INTO goose_db_version (id, version_id, is_applied, tstamp) VALUES (101, 20230801093422, TRUE, now());
  13. INSERT INTO goose_db_version (id, version_id, is_applied, tstamp) VALUES (102, 20230801093423, TRUE, now());
  14. INSERT INTO goose_db_version (id, version_id, is_applied, tstamp) VALUES (103, 20230810151349, TRUE, now());
  15. Exit the ysqlsh and start boostd-data. Check if the service starts this time.

@dgreuel2002
Copy link
Author

dgreuel2002 commented Feb 24, 2024

@LexLuthr it times out on the first line

yugabyte=# ALTER TABLE PieceTracker DROP CONSTRAINT piecetracker_pkey;

ERROR:  Timed out waiting for Alter Table

@LexLuthr
Copy link
Collaborator

@ddorian Hey! Can you advise something from YB side here?

yugabyte=# SELECT count(*) FROM PieceTracker;
 count
-------
  3711
(1 row)

We are not able to alter the table at all. We are getting a timeout.

@dgreuel2002 Can you restart your YB instance and retry?

@dgreuel2002
Copy link
Author

@LexLuthr I have restarted yuga and same result. See INFO log from yuga logs.
INFOLOG.txt

@ddorian
Copy link

ddorian commented Mar 7, 2024

@dgreuel2002 Can you try increasing --rpc_connection_timeout_ms=150000 of ybtserver and retrying?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
support Support Ticket
Projects
Status: No status
Development

No branches or pull requests

4 participants