Log Deep Dive -- DRAFT
Slots 72677728-72677739
On 8-April-2021, I investigated my log file to get a better understanding of activity around a sequence of four skipped slots from my validator node. it was a good learning experience and this article is intended to show what I learned and help you better understand your logs.
See the Solana Documentation for a discussion of capitalized terms like Fork, Slot, Shred, etc.
Life Cycle of a Slot
The Solana Validator logs are very busy and it can be difficult to see the signal through the noise. Before digging deep into the skipped Slot sequence further below, here are some important milestones in the life-cycle of a successful Slot:
The first milestone is seen when the current leader transmits the first Shreds for a new Slot. The first Shreds look like this in your logs
INFO solana_metrics::metrics] datapoint: retransmit-first-shred slot=73210778i
After receiving new Shreds, your validator will create a new Fork for the slot. In your logs, you will see this
INFO solana_core::replay_stage] new fork:73210778 parent:73210777 root:73210740Normally, the new Fork will build on the Block from the prior Slot.
When the leader has filled a Block with Shreds, the leader will freeze the Bank indicating that the transactions are ready for verification and Voting. For example,
INFO solana_core::replay_stage] bank frozen: 73210778
Finally, after the transactions and Block are determined to be valid, your validator will vote on the Fork. Votes look like this:
INFO solana_core::replay_stage] voting: 73210778 0
On the "happy path" for each Slot, you will see those events in sequential order with a smooth transition from one Slot to the next.
Skipped Slot Investigation
Given the following slot sequence, I am DDnA and I skipped all four of my slots:
`% solana block-production -v | grep -B 8 -A 8 DDnA`
72677728 5XKJwdKB2Hs7pkEXzifAysjSk6q7Rt6k5KfHwmAMPtoQ
72677729 5XKJwdKB2Hs7pkEXzifAysjSk6q7Rt6k5KfHwmAMPtoQ
72677730 5XKJwdKB2Hs7pkEXzifAysjSk6q7Rt6k5KfHwmAMPtoQ
72677731 5XKJwdKB2Hs7pkEXzifAysjSk6q7Rt6k5KfHwmAMPtoQ
72677732 DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp SKIPPED
72677733 DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp SKIPPED
72677734 DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp SKIPPED
72677735 DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp SKIPPED
72677736 EaRH6eMWnXKXhw1tqve6eUXnsoWYUFKeSbXUyBEqyPYJ
72677737 EaRH6eMWnXKXhw1tqve6eUXnsoWYUFKeSbXUyBEqyPYJ
72677738 EaRH6eMWnXKXhw1tqve6eUXnsoWYUFKeSbXUyBEqyPYJ
72677739 EaRH6eMWnXKXhw1tqve6eUXnsoWYUFKeSbXUyBEqyPYJ
Here is a summary of the significant milestones within this sequence:
From the worksheet shown above, the most important event happens at 37.817. 5XKJ has not delivered a frozen bank for 727 within 800ms. DDnA thinks that 5XKJ has gone missing and DDnA creates a new fork building on the the work of Dq3p in 727.
At 38.498, 5XKJ delivered the frozen Bank for 728 and DDnA created a second Fork for 729 at 38.512. We now have TWO FORKS in play!
From this point on, 5XKJ continues to send updates for its Fork while DDnA is building on the alternate Fork. At 39.144, DDnA detects the partition and is finally ready to drop its own Fork and vote in the heavier 731 Fork.
A little time passes while DDnA resolves the Forks and it starts Voting again at 738.
Summary
For context, DDnA is located in New York, USA and 5XKJ is located in Frankfurt, Germany. Average ping times between the two nodes are about 87ms (43.5ms one-way). My logs reflect the times that events arrived at my node (i.e. network latency is embedded within the times).
Due to propagation delays, DDnA did not receive the required frozen_bank event from 5XKJ in a timely manner. After 800ms, roughly two slots plus some grace ticks, DDnA believed that 5XKJ went missing and then DDnA created a new fork. Please notice that this happened within the allotted time of 5XKJ's slots 728-731. I believe that this is an intentional design feature -- the next leader in line can make up a little "lost time" if the prior leader is missing.
Because DDnA is in the US and 5KXJ is in Europe, the other European validators may have had a chance to vote on frozen banks that DDnA didn't see in time. When the two forks were resolved, 5XKJ's fork was the heaviest and DDnA lost out.
In the end, the skipped Slots were caused by propagation issues or inefficiencies with Turbine (Solana's propagation library) that caused DDnA to not see the events in time. I originally suspected that proof-of-history played a role, but I do not think that is the case here.
Finally, if you find this type of article useful, please send feedback using the chat widget on the lower right-corner of this page. Thanks!
Log Entries
$ sudo cat /var/log/syslog | grep -B 100 -A 300 'fork:7267773'
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.155339404Z INFO solana_metrics::metrics] datapoint: retransmit-num_nodes count=686i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.155348986Z INFO solana_metrics::metrics] datapoint: retransmit-stage total_time=308385i epoch_fetch=1217i epoch_cache_update=5226i total_batches=2796i total_packets=3130i retransmit_total=65410i compute_turbine=214881i repair_total=85i discard_total=2i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.155356027Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677724i num_shreds=1034i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.155353976Z INFO solana_core::retransmit_stage] retransmit: top packets_by_source: {106: "89.33.8.229:8006", 152: "85.190.150.50:8005", 157: "188.34.134.28:8005", 186: "89.202.64.28:5639", 231: "173.231.58.226:8006"} len: 337
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.155360806Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677725i num_shreds=626i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.155375824Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677726i num_shreds=659i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.155379821Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677727i num_shreds=811i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.167678821Z INFO solana_core::replay_stage] bank frozen: 72677726
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.167681865Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677726i fetch_entries_time=1574i fetch_entries_fail_time=0i entry_poh_verification_time=31251i entry_transaction_verification_time=3687i replay_time=244666i replay_total_elapsed=483630i total_entries=485i total_shreds=411i load_us=131305i execute_us=261621i store_us=98908i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.167760226Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=60i latest_slot_elapsed=0i read_lock_elapsed=0i load_account_elapsed=5i iterator_elapsed=6i num_keys_iterated=50i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.169376139Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=50i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.171129988Z INFO solana_runtime::bank] bank frozen: 72677726 hash: 3WYKdgMUuUCo3PCxkMjZ5ixyQg6aHx3yC6LyiHYnYCsk accounts_delta: FEC8SrFccrW66EFt8bJHK4FmdA5fF8adG6p8ad9XJCBY signature_count: 584 last_blockhash: AdHToBv5QCqVvufD3bimhG8YdxaYFmzRjq8VDjvj1m4J capitalization: 492620116409391886
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.171149441Z INFO solana_runtime::bank] accounts hash slot: 72677726 stats: BankHashStats { num_updated_accounts: 1911, num_removed_accounts: 3, num_lamports_stored: 2400628005591458, total_data_len: 257077185, num_executable_accounts: 2 }
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.171170485Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=871i same_account_writes_size=171104876i unique_account_writes_size=85972309i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.171305461Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=43i num_slots=92i total_unique_writes_size=5135042619i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.177665591Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677723i root=72677673i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.178045139Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677726i best_slot=72677726i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.178044654Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677726 0 0 72677725
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.178050735Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677726i weight="0"
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.178072045Z INFO solana_core::replay_stage] voting: 72677726 0
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.178087520Z INFO solana_metrics::metrics] datapoint: tower-vote latest=72677726i root=72677676i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.181765475Z INFO solana_metrics::metrics] datapoint: recycler_total_allocated_count name="gossip-receiver-recycler-shrink-stats" count=243000i recycled_len=0i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.182125189Z INFO solana_core::replay_stage] new root 72677676
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.186232896Z INFO solana_metrics::metrics] datapoint: block-commitment-cache aggregate-commitment-ms=4i highest-confirmed-root=72677671i highest-confirmed-slot=72677723i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.186806267Z INFO solana_core::replay_stage] vote bank: Some((72677726, SameFork)) reset bank: 72677726
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.186820867Z INFO solana_metrics::metrics] datapoint: blocks_produced num_blocks_on_fork=1008i num_dropped_blocks_on_fork=133i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.187837325Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=639i slot=72677727i last_index=488i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.188557139Z INFO solana_core::poh_recorder] reset poh from: GZTTc4DTLuWwbHD4VkwC1Bt1NRxkzrApVsyLMzpLZhpZ,4651374555,72677725 to: AdHToBv5QCqVvufD3bimhG8YdxaYFmzRjq8VDjvj1m4J,72677726
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.188571497Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp reset PoH to tick 4651374528 (within slot 72677726). My next leader slot is 72677732
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.188590971Z INFO solana_metrics::metrics] datapoint: replay-loop-timing-stats total_elapsed_us=1021000i collect_frozen_banks_elapsed=184i compute_bank_stats_elapsed=18017i select_vote_and_reset_forks_elapsed=28i start_leader_elapsed=5i reset_bank_elapsed=9173i voting_elapsed=68092i select_forks_elapsed=4i compute_slot_stats_elapsed=62i generate_new_bank_forks_elapsed=5688i replay_active_banks_elapsed=618384i reset_duplicate_slots_elapsed=1427i wait_receive_elapsed=300176i heaviest_fork_failures_elapsed=0i bank_count=3i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.188889127Z INFO solana_core::replay_stage] new fork:72677727 parent:72677726 root:72677676
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.189507133Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677727i block_height=66301583i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.190213516Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings hash_accounts=129774i store_accounts=73543i update_index=8097i handle_reclaims=0i append_accounts=0i find_storage=0i num_accounts=4216i total_data=582730934i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.190222763Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings2 recycle_store_count=0i current_recycle_store_count=1000i current_recycle_store_bytes=270479360i create_store_count=0i store_get_slot_store=0i store_find_existing=0i dropped_stores=0i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.190482670Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=259i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.190487517Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677727i from_genesis=1613440030i corrected=1617841295i ancestor_timestamp=1617841294i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.208058032Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=3i process_packets_count=0i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=0i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.213162856Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 702584, "samples": 374000, "now": 1617841296213, "events": 1}
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.255854230Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=2i process_packets_count=308i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=47i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.263583493Z INFO solana_metrics::counter] COUNTER:{"name": "vote-native", "counts": 475001, "samples": 475000, "now": 1617841296263, "events": 1}
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.315640343Z INFO solana_metrics::metrics] datapoint: optimistic_slot_elapsed average_elapsed_ms=297i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.315655432Z INFO solana_metrics::metrics] datapoint: optimistic_slot slot=72677725i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.317523485Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-txs", "counts": 574565, "samples": 365000, "now": 1617841296317, "events": 1}
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.317535891Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-sigs", "counts": 692179, "samples": 365000, "now": 1617841296317, "events": 1}
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.391358300Z INFO solana_core::replay_stage] bank frozen: 72677727
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.391363224Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677727i fetch_entries_time=1262i fetch_entries_fail_time=0i entry_poh_verification_time=13405i entry_transaction_verification_time=3132i replay_time=182586i replay_total_elapsed=200824i total_entries=446i total_shreds=489i load_us=96128i execute_us=217737i store_us=57991i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.391453356Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=76i latest_slot_elapsed=0i read_lock_elapsed=0i load_account_elapsed=13i iterator_elapsed=9i num_keys_iterated=47i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.391574672Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=45i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.393317789Z INFO solana_runtime::bank] bank frozen: 72677727 hash: Ha4yf3RL9epFufy7sfdCHAAtURxPSHiumM5kbxV7sktR accounts_delta: HDsHs3wkwNB8hmYwQNJytMem66tnM7eUnhUt94mmPmGU signature_count: 895 last_blockhash: J9AXkttd9Vu9ZGWoWjVsSSxb1E56d1q6FiZA585wvhCs capitalization: 492620116407154386
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.393336143Z INFO solana_runtime::bank] accounts hash slot: 72677727 stats: BankHashStats { num_updated_accounts: 2085, num_removed_accounts: 8, num_lamports_stored: 2615415874726037, total_data_len: 133906489, num_executable_accounts: 6 }
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.393353523Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=582i same_account_writes_size=60621862i unique_account_writes_size=73284627i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.393481593Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=44i num_slots=93i total_unique_writes_size=5208327246i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.400181132Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677725i root=72677675i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.400673192Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677727i best_slot=72677727i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.400672114Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677727 0 0 72677726
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.400677697Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677727i weight="0"
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.400690238Z INFO solana_core::replay_stage] validator fork confirmed 72677725 1103ms
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.400700337Z INFO solana_core::replay_stage] validator fork confirmed 72677724 2220ms
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.400700838Z INFO solana_metrics::metrics] datapoint: validator-confirmation duration_ms=1103i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.400713117Z INFO solana_core::replay_stage] voting: 72677727 0
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.400715648Z INFO solana_metrics::metrics] datapoint: validator-confirmation duration_ms=2220i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.400728518Z INFO solana_metrics::metrics] datapoint: tower-vote latest=72677727i root=72677677i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.405061155Z INFO solana_core::replay_stage] new root 72677677
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.405226294Z INFO solana_core::replay_stage] vote bank: Some((72677727, SameFork)) reset bank: 72677727
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.405240271Z INFO solana_metrics::metrics] datapoint: blocks_produced num_blocks_on_fork=1009i num_dropped_blocks_on_fork=133i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.406440402Z INFO solana_core::poh_recorder] reset poh from: CYxmsz9DZhbkFR157gtn8mPk9supFMEkb442qxXwsVFQ,4651374567,72677726 to: J9AXkttd9Vu9ZGWoWjVsSSxb1E56d1q6FiZA585wvhCs,72677727
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.406452823Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp reset PoH to tick 4651374592 (within slot 72677727). My next leader slot is 72677732
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.409081883Z INFO solana_metrics::metrics] datapoint: block-commitment-cache aggregate-commitment-ms=3i highest-confirmed-root=72677673i highest-confirmed-slot=72677725i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.500488251Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=0i process_packets_count=310i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=47i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.501954978Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=1i process_packets_count=303i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=48i current_buffered_packets_count=1i rebuffered_packets_count=0i
Apr 8 00:21:36 solana-production-nyc kernel: [34169.402866] [UFW BLOCK] IN=enp24s0f0 OUT= MAC=3c:ec:ef:4e:1b:5a:00:23:9c:db:17:f0:08:00 SRC=162.142.125.25 DST=45.159.5.250 LEN=44 TOS=0x00 PREC=0x00 TTL=44 ID=32153 PROTO=TCP SPT=60421 DPT=23 WINDOW=1024 RES=0x00 SYN URGP=0
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.593307136Z INFO solana_metrics::metrics] datapoint: poh-service ticks=182i hashes=2292800i elapsed_ms=353i total_sleep_ms=166i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.800180453Z INFO solana_metrics::metrics] datapoint: cluster_info_stats entrypoint=28i entrypoint2=0i push_vote_read=80i get_votes=5337i get_accounts_hash=0i all_tvu_peers=0i tvu_peers=1995i new_push_requests_num=12536i table_size=339128i purged_values_size=128657i failed_inserts_size=6664i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.800199495Z INFO solana_metrics::metrics] datapoint: cluster_info_stats2 gossip_packets_dropped_count=0i retransmit_peers=1759i repair_peers=6528i new_push_requests=14260i new_push_requests2=893i purge=50107i process_gossip_packets_time=1112647i handle_batch_ping_messages_time=269i handle_batch_pong_messages_time=18i handle_batch_prune_messages_time=4178i handle_batch_pull_requests_time=615981i handle_batch_pull_responses_time=8105i handle_batch_push_messages_time=328511i process_pull_resp=4144i filter_pull_resp=3046i process_pull_resp_count=12i pull_response_fail_insert=213i pull_response_fail_timeout=0i pull_response_success=200i process_pull_resp_timeout=0i push_response_count=2656i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.800207631Z INFO solana_metrics::metrics] datapoint: cluster_info_stats3 process_pull_resp_len=432i process_pull_requests=379i pull_request_ping_pong_check_failed_count=0i generate_pull_responses=584960i process_prune=248i process_push_message=42604i prune_received_cache=8263i epoch_slots_lookup=165i new_pull_requests=138201i mark_pull_request=0i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.800211124Z INFO solana_metrics::metrics] datapoint: cluster_info_stats4 skip_push_message_shred_version=0i skip_pull_response_shred_version=0i skip_pull_shred_version=0i push_message_count=3442i push_message_value_count=4544i new_pull_requests_count=5120i prune_message_count=429i prune_message_len=660i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.800215014Z INFO solana_metrics::metrics] datapoint: cluster_info_stats5 pull_requests_count=3695i packets_received_count=8010i packets_received_prune_messages_count=429i packets_received_pull_requests_count=3695i packets_received_pull_responses_count=432i packets_received_push_messages_count=3442i packets_received_verified_count=8010i packets_sent_gossip_requests_count=5610i packets_sent_prune_messages_count=2656i packets_sent_pull_requests_count=5120i packets_sent_pull_responses_count=5853i packets_sent_push_messages_count=12536i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.954157510Z INFO solana_metrics::metrics] datapoint: retransmit-first-shred slot=72677728i
Apr 8 00:21:36 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:36.992506924Z INFO solana_metrics::metrics] datapoint: shred_fetch index_overrun=0i shred_count=34i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=0i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.009384011Z INFO solana_core::replay_stage] new fork:72677728 parent:72677727 root:72677677
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.009914617Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677728i block_height=66301584i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.010856118Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=276i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.010860978Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677728i from_genesis=1613440031i corrected=1617841296i ancestor_timestamp=1617841295i
Apr 8 00:21:37 solana-production-nyc solana_exporter[1674]: I0408 00:21:37.132987 1674 slots.go:116] confirmed slot 72677673 (offset 101673, +2), epoch 168 (from slot 72576000 to 73008000, 330327 remaining)
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.155424694Z INFO solana_metrics::metrics] datapoint: shred_fetch_tvu_forwards index_overrun=0i shred_count=420i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=0i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.191821082Z INFO solana_metrics::metrics] datapoint: shred_fetch_repair index_overrun=0i shred_count=45i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=2i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.235759129Z INFO solana_metrics::metrics] datapoint: replay-loop-timing-stats total_elapsed_us=1047000i collect_frozen_banks_elapsed=118i compute_bank_stats_elapsed=7335i select_vote_and_reset_forks_elapsed=5i start_leader_elapsed=0i reset_bank_elapsed=1232i voting_elapsed=4509i select_forks_elapsed=1i compute_slot_stats_elapsed=22i generate_new_bank_forks_elapsed=5098i replay_active_banks_elapsed=227091i reset_duplicate_slots_elapsed=1144i wait_receive_elapsed=800448i heaviest_fork_failures_elapsed=0i bank_count=1i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.240216686Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings hash_accounts=33174i store_accounts=18113i update_index=2927i handle_reclaims=0i append_accounts=0i find_storage=0i num_accounts=2312i total_data=142083954i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.240230079Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings2 recycle_store_count=0i current_recycle_store_count=1000i current_recycle_store_bytes=270479360i create_store_count=0i store_get_slot_store=0i store_find_existing=0i dropped_stores=0i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.259526773Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=2i process_packets_count=282i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=65i current_buffered_packets_count=1i rebuffered_packets_count=0i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.308767598Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=3i process_packets_count=0i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=0i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.312810763Z INFO solana_metrics::metrics] datapoint: retransmit-first-shred slot=72677729i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.501500260Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=0i process_packets_count=384i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=68i current_buffered_packets_count=3i rebuffered_packets_count=0i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.504327195Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=1i process_packets_count=408i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=65i current_buffered_packets_count=3i rebuffered_packets_count=0i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.599581473Z INFO solana_metrics::metrics] datapoint: poh-service ticks=184i hashes=2308096i elapsed_ms=349i total_sleep_ms=174i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.679537151Z INFO solana_metrics::metrics] datapoint: optimistic_slot_elapsed average_elapsed_ms=1363i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.679553137Z INFO solana_metrics::metrics] datapoint: optimistic_slot slot=72677727i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.743482701Z INFO solana_metrics::metrics] datapoint: optimistic_slot_elapsed average_elapsed_ms=63i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.743495517Z INFO solana_metrics::metrics] datapoint: optimistic_slot slot=72677726i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.782536480Z INFO solana_metrics::metrics] datapoint: retransmit-first-shred slot=72677730i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.816620326Z INFO solana_core::replay_stage] new fork:72677732 parent:72677727 (leader) root:72677677
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.816622064Z INFO solana_metrics::metrics] datapoint: replay_stage-new_leader slot=72677732i leader="DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp"
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.816633696Z INFO solana_metrics::metrics] datapoint: replay_stage-my_leader_slot slot=72677732i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.817178918Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677732i block_height=66301584i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.818363576Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=293i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.818368875Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677732i from_genesis=1613440032i corrected=1617841297i ancestor_timestamp=1617841295i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.818695623Z INFO solana_core::replay_stage] LEADER CHANGE at slot: 72677732 leader: DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp. I am now the leader
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.818941505Z INFO solana_metrics::metrics] datapoint: cluster_info-num_nodes live_count=683i broadcast_count=686i
Apr 8 00:21:37 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:37.909082228Z INFO solana_metrics::counter] COUNTER:{"name": "vote-native", "counts": 476001, "samples": 476000, "now": 1617841297909, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.017240016Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_num_to_commit", "counts": 7156, "samples": 13000, "now": 1617841298017, "events": 0}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.017255946Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_retryable_record_txs", "counts": 41, "samples": 13000, "now": 1617841298017, "events": 0}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.022816671Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-dropped_tx_before_forwarding", "counts": 288, "samples": 13000, "now": 1617841298022, "events": 0}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.051267060Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-account_in_use", "counts": 11205, "samples": 9000, "now": 1617841298051, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.051399784Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 704684, "samples": 375000, "now": 1617841298051, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.065544612Z INFO solana_metrics::metrics] datapoint: shred_fetch index_overrun=0i shred_count=31i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=0i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.079351150Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-error_count", "counts": 129553, "samples": 38000, "now": 1617841298079, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana_exporter[1674]: I0408 00:21:38.133638 1674 slots.go:112] slot has not advanced at 72677673, skipping
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.133775033Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_num_to_commit", "counts": 7350, "samples": 14000, "now": 1617841298133, "events": 0}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.133798038Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_retryable_record_txs", "counts": 41, "samples": 14000, "now": 1617841298133, "events": 0}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.137667923Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-dropped_tx_before_forwarding", "counts": 336, "samples": 14000, "now": 1617841298137, "events": 0}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.158390951Z INFO solana_metrics::metrics] datapoint: shred_fetch_tvu_forwards index_overrun=0i shred_count=1005i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=0i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.158680063Z INFO solana_metrics::metrics] datapoint: retransmit-num_nodes count=686i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.158685288Z INFO solana_metrics::metrics] datapoint: retransmit-stage total_time=148734i epoch_fetch=761i epoch_cache_update=4488i total_batches=1348i total_packets=1457i retransmit_total=32224i compute_turbine=100165i repair_total=65i discard_total=1i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.158690043Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677728i num_shreds=702i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.158692795Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677729i num_shreds=459i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.158695243Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677730i num_shreds=296i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.158702332Z INFO solana_core::retransmit_stage] retransmit: top packets_by_source: {54: "51.195.7.49:8005", 78: "89.202.64.28:5639", 80: "85.190.150.50:8005", 91: "188.34.134.28:8005", 119: "173.231.58.226:8006"} len: 214
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.161349392Z INFO solana_core::poh_recorder] poh_record: max_tick_height 4651374912 reached, clearing working_bank 72677732
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.161377464Z INFO solana_metrics::metrics] datapoint: leader-slot-start-to-cleared-elapsed-ms slot=72677732i elapsed=342i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.161387573Z INFO solana_core::banking_stage] process transactions: max height reached slot: 72677732 height: 4651374912
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.161433425Z INFO solana_core::banking_stage] process transactions: max height reached slot: 72677732 height: 4651374912
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.161508193Z INFO solana_metrics::metrics] datapoint: broadcast-process-shreds-stats slot=72677732i shredding_time=14167i receive_time=303245i num_data_shreds=363i slot_broadcast_time=343074i get_leader_schedule_time=1595i serialize_shreds_time=1307i gen_data_time=12583i gen_coding_time=10490i sign_coding_time=9208i coding_send_time=10490i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.161515895Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=674i slot=72677732i last_index=362i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.161679617Z INFO solana_core::replay_stage] bank frozen: 72677732
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.161683472Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677732i fetch_entries_time=0i fetch_entries_fail_time=0i entry_poh_verification_time=0i entry_transaction_verification_time=0i replay_time=0i replay_total_elapsed=239156i total_entries=0i total_shreds=0i load_us=0i execute_us=0i store_us=0i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.161709029Z INFO solana_metrics::metrics] datapoint: broadcast-insert-shreds-stats slot=72677732i end_to_end_elapsed=343275i insert_shreds_elapsed=38663i num_shreds=726i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.161878802Z INFO solana_metrics::metrics] datapoint: broadcast-transmit-shreds-stats slot=72677732i end_to_end_elapsed=343444i transmit_elapsed=26246i send_mmsg_elapsed=3756i get_peers_elapsed=163695i num_shreds=726i shred_select=13048i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.161965394Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=263i latest_slot_elapsed=0i read_lock_elapsed=0i load_account_elapsed=34i iterator_elapsed=20i num_keys_iterated=234i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.162527307Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=232i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.169564891Z INFO solana_runtime::bank] bank frozen: 72677732 hash: 7NdRMUXiDUQHSfkJjaC1TJ6dimjHSrJVckUwyhFV8u9p accounts_delta: 3gg2Dm2uKMC7sJ3UQwV3sALYtpZB5aQAAVnyubjYF3tk signature_count: 743 last_blockhash: 6wzoSi6kUZrAZtt9NE5u4cT2h4pyg8aqKkG341oXZqcf capitalization: 492620116405294447
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.169584825Z INFO solana_runtime::bank] accounts hash slot: 72677732 stats: BankHashStats { num_updated_accounts: 2746, num_removed_accounts: 4, num_lamports_stored: 2660741718234308, total_data_len: 160205830, num_executable_accounts: 4 }
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.169601183Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=1079i same_account_writes_size=101738191i unique_account_writes_size=58467639i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.169729970Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=45i num_slots=95i total_unique_writes_size=5297307677i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.173960984Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677727i root=72677677i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.174345555Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677732i best_slot=72677732i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.174349430Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677732i weight="0"
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.174347819Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677732 0 0 72677727
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.174376242Z INFO solana_core::replay_stage] voting: 72677732 0
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.174389683Z INFO solana_metrics::metrics] datapoint: tower-vote latest=72677732i root=72677677i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.178421213Z INFO solana_core::replay_stage] vote bank: Some((72677732, SameFork)) reset bank: 72677732
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.178434870Z INFO solana_metrics::metrics] datapoint: blocks_produced num_blocks_on_fork=1010i num_dropped_blocks_on_fork=137i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.179082984Z INFO solana_metrics::metrics] datapoint: retransmit-first-shred slot=72677731i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.182352851Z INFO solana_metrics::metrics] datapoint: block-commitment-cache aggregate-commitment-ms=4i highest-confirmed-root=72677675i highest-confirmed-slot=72677727i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.183095013Z INFO solana_core::poh_recorder] reset poh from: 2XpyCEbM4Q49tREnMxnr3m8EdXPhEKRgHrirmrrZ2xa7,4651374915,72677732 to: 6wzoSi6kUZrAZtt9NE5u4cT2h4pyg8aqKkG341oXZqcf,72677732
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.183112114Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp reset PoH to tick 4651374912 (within slot 72677732). My next leader slot is 72677733
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.183129572Z INFO solana_core::replay_stage] new fork:72677733 parent:72677732 (leader) root:72677677
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.183130513Z INFO solana_metrics::metrics] datapoint: replay_stage-new_leader slot=72677733i leader="DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp"
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.183139011Z INFO solana_metrics::metrics] datapoint: replay_stage-my_leader_slot slot=72677733i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.183695030Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677733i block_height=66301585i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.184782539Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=239i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.184786128Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677733i from_genesis=1613440033i corrected=1617841298i ancestor_timestamp=1617841297i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.196752937Z INFO solana_metrics::metrics] datapoint: shred_fetch_repair index_overrun=0i shred_count=66i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=1i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.227505595Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=1286i slot=72677728i last_index=475i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.243376716Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings hash_accounts=62321i store_accounts=29653i update_index=5195i handle_reclaims=0i append_accounts=0i find_storage=0i num_accounts=3492i total_data=236000025i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.243383288Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings2 recycle_store_count=0i current_recycle_store_count=1000i current_recycle_store_bytes=270479360i create_store_count=0i store_get_slot_store=0i store_find_existing=0i dropped_stores=0i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.248912681Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 705984, "samples": 376000, "now": 1617841298248, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.276578547Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=2i process_packets_count=717i new_tx_count=128i dropped_batches_count=0i newly_buffered_packets_count=84i current_buffered_packets_count=0i rebuffered_packets_count=587i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.282089731Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-account_in_use", "counts": 12246, "samples": 10000, "now": 1617841298282, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.285852038Z INFO solana_metrics::metrics] datapoint: replay-loop-timing-stats total_elapsed_us=1050000i collect_frozen_banks_elapsed=208i compute_bank_stats_elapsed=4864i select_vote_and_reset_forks_elapsed=13i start_leader_elapsed=3799i reset_bank_elapsed=4699i voting_elapsed=4040i select_forks_elapsed=7i compute_slot_stats_elapsed=8i generate_new_bank_forks_elapsed=3384i replay_active_banks_elapsed=85985i reset_duplicate_slots_elapsed=1900i wait_receive_elapsed=935089i heaviest_fork_failures_elapsed=0i bank_count=1i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.304720226Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-error_count", "counts": 130673, "samples": 39000, "now": 1617841298304, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.344136995Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-error-instruction_error", "counts": 110433, "samples": 28000, "now": 1617841298344, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.351428973Z INFO solana_metrics::metrics] datapoint: recv-window-insert-shreds num_shreds=2704i total_elapsed=205773i insert_lock_elapsed=2195i insert_shreds_elapsed=56921i shred_recovery_elapsed=78690i chaining_elapsed=68i commit_working_sets_elapsed=7288i write_batch_elapsed=49836i num_inserted=1126i num_repair=62i num_recovered=764i num_recovered_inserted=764i num_recovered_failed_sig=0i num_recovered_failed_invalid=0i num_recovered_exists=0i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.361127584Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=3i process_packets_count=846i new_tx_count=846i dropped_batches_count=0i newly_buffered_packets_count=0i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.385675729Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_num_to_commit", "counts": 7535, "samples": 15000, "now": 1617841298385, "events": 0}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.385692295Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_retryable_record_txs", "counts": 44, "samples": 15000, "now": 1617841298385, "events": 0}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.386902430Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-dropped_tx_before_forwarding", "counts": 388, "samples": 15000, "now": 1617841298386, "events": 0}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.413356576Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 707644, "samples": 377000, "now": 1617841298413, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.441165955Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-account_in_use", "counts": 13340, "samples": 11000, "now": 1617841298441, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.451091480Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-error_count", "counts": 131950, "samples": 40000, "now": 1617841298451, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.489843956Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_num_to_commit", "counts": 7637, "samples": 16000, "now": 1617841298489, "events": 0}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.489861607Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_retryable_record_txs", "counts": 44, "samples": 16000, "now": 1617841298489, "events": 0}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.492223844Z INFO solana_metrics::metrics] datapoint: recycler_total_allocated_count name="gossip-receiver-recycler-shrink-stats" count=244000i recycled_len=0i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.497587765Z INFO solana_core::replay_stage] bank frozen: 72677728
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.497595970Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677728i fetch_entries_time=3317i fetch_entries_fail_time=0i entry_poh_verification_time=46191i entry_transaction_verification_time=5288i replay_time=256844i replay_total_elapsed=1486683i total_entries=421i total_shreds=476i load_us=135732i execute_us=299705i store_us=102120i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.497687269Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=79i latest_slot_elapsed=1i read_lock_elapsed=0i load_account_elapsed=4i iterator_elapsed=8i num_keys_iterated=53i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.497809788Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=53i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.504968413Z INFO solana_runtime::bank] bank frozen: 72677728 hash: 8Jit5DrWRpMkL5GhsdUzfFUzujQ7cCzZgN2g2wvkvQga accounts_delta: rA2wW77XzLmQ1FiNyR78U28EmqxHqYjELMjzrw9xTjz signature_count: 838 last_blockhash: HQuerqGQr7ZghoCou8u7ZPNjXSXDpWHtTyf5cNbPpTAa capitalization: 492620116405058167
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.504984684Z INFO solana_runtime::bank] accounts hash slot: 72677728 stats: BankHashStats { num_updated_accounts: 2727, num_removed_accounts: 2, num_lamports_stored: 7489555550863604, total_data_len: 236171113, num_executable_accounts: 0 }
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.505002398Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=1185i same_account_writes_size=140707033i unique_account_writes_size=95464080i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.505148642Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=45i num_slots=96i total_unique_writes_size=5415688144i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.506306919Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=1i process_packets_count=669i new_tx_count=294i dropped_batches_count=0i newly_buffered_packets_count=73i current_buffered_packets_count=0i rebuffered_packets_count=649i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.508101763Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=0i process_packets_count=693i new_tx_count=299i dropped_batches_count=0i newly_buffered_packets_count=67i current_buffered_packets_count=0i rebuffered_packets_count=663i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.509227666Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677727i root=72677677i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.509490057Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677728i best_slot=72677728i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.509493651Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677728i weight="0"
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.509490594Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677728 0 0 72677727
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.509513717Z INFO solana_core::replay_stage] validator fork confirmed 72677726 2825ms
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.509519174Z INFO solana_core::replay_stage] validator fork confirmed 72677727 2318ms
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.509520416Z INFO solana_metrics::metrics] datapoint: validator-confirmation duration_ms=2825i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.509523547Z INFO solana_metrics::metrics] datapoint: validator-confirmation duration_ms=2318i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.511708614Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-dropped_tx_before_forwarding", "counts": 464, "samples": 16000, "now": 1617841298511, "events": 5}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.511910211Z INFO solana_core::replay_stage] Waiting to switch vote to 72677728, resetting to slot None on same fork for now
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.512176623Z INFO solana_core::replay_stage] new fork:72677729 parent:72677728 root:72677677
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.512629914Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677729i block_height=66301585i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.512920890Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=1206i slot=72677729i last_index=300i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.514045689Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=264i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.514051280Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677729i from_genesis=1613440031i corrected=1617841296i ancestor_timestamp=1617841296i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.536634484Z INFO solana_metrics::counter] COUNTER:{"name": "broadcast_service-entries_received", "counts": 5345, "samples": 3000, "now": 1617841298536, "events": 2}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.536889699Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 708958, "samples": 378000, "now": 1617841298536, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.546965228Z INFO solana_core::poh_recorder] poh_record: max_tick_height 4651374976 reached, clearing working_bank 72677733
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.547009790Z INFO solana_metrics::metrics] datapoint: leader-slot-start-to-cleared-elapsed-ms slot=72677733i elapsed=362i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.547022476Z INFO solana_core::banking_stage] process transactions: max height reached slot: 72677733 height: 4651374976
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.547016907Z INFO solana_core::banking_stage] process transactions: max height reached slot: 72677733 height: 4651374976
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.547026243Z INFO solana_core::banking_stage] process transactions: max height reached slot: 72677733 height: 4651374976
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.547098537Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=365i slot=72677733i last_index=186i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.547123775Z INFO solana_metrics::metrics] datapoint: broadcast-process-shreds-stats slot=72677733i shredding_time=11367i receive_time=330975i num_data_shreds=187i slot_broadcast_time=358643i get_leader_schedule_time=910i serialize_shreds_time=747i gen_data_time=10365i gen_coding_time=4858i sign_coding_time=7817i coding_send_time=4858i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.547306671Z INFO solana_metrics::metrics] datapoint: broadcast-insert-shreds-stats slot=72677733i end_to_end_elapsed=358823i insert_shreds_elapsed=26810i num_shreds=374i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.547490477Z INFO solana_metrics::metrics] datapoint: broadcast-transmit-shreds-stats slot=72677733i end_to_end_elapsed=359008i transmit_elapsed=18152i send_mmsg_elapsed=3189i get_peers_elapsed=115845i num_shreds=374i shred_select=7007i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.602299047Z INFO solana_metrics::metrics] datapoint: poh-service ticks=180i hashes=2257920i elapsed_ms=356i total_sleep_ms=123i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.626737235Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=844i slot=72677730i last_index=212i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.757185440Z INFO solana_core::replay_stage] bank frozen: 72677729
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.757188021Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677729i fetch_entries_time=1291i fetch_entries_fail_time=0i entry_poh_verification_time=13568i entry_transaction_verification_time=1417i replay_time=219627i replay_total_elapsed=236187i total_entries=256i total_shreds=301i load_us=111510i execute_us=216681i store_us=78182i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.757262888Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=58i latest_slot_elapsed=0i read_lock_elapsed=0i load_account_elapsed=6i iterator_elapsed=7i num_keys_iterated=41i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.757354069Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=40i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.762342331Z INFO solana_runtime::bank] bank frozen: 72677729 hash: FErw3QU3enqKENzrzjstUrJLXGYizFzhtgg4XN2DfxSf accounts_delta: cs1uRzCeMZfbMUxDJyu1cPymJ6JFjvifDU5nJmAV3mS signature_count: 408 last_blockhash: AE3S6SEkoKMDiwMBiPFqPD9udJpz67YLSUPbsb9R3jZp capitalization: 492620116404036948
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.762361259Z INFO solana_runtime::bank] accounts hash slot: 72677729 stats: BankHashStats { num_updated_accounts: 1774, num_removed_accounts: 2, num_lamports_stored: 1843266157019987, total_data_len: 205914939, num_executable_accounts: 2 }
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.762381383Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=721i same_account_writes_size=124087147i unique_account_writes_size=81827792i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.762507608Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=45i num_slots=97i total_unique_writes_size=5510962181i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.762539272Z INFO solana_core::replay_stage] bank frozen: 72677733
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.762541322Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677733i fetch_entries_time=0i fetch_entries_fail_time=0i entry_poh_verification_time=0i entry_transaction_verification_time=0i replay_time=0i replay_total_elapsed=577403i total_entries=0i total_shreds=0i load_us=0i execute_us=0i store_us=0i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.762655175Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=94i latest_slot_elapsed=0i read_lock_elapsed=0i load_account_elapsed=14i iterator_elapsed=9i num_keys_iterated=56i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.762886088Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=54i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.766649005Z INFO solana_runtime::bank] bank frozen: 72677733 hash: DRcdSKjaU8gSXNYArbK8Shi4jTPWyT3qwzkH1uq3j1YM accounts_delta: Gb7hvNKDiVQNCLtabaReAF84ML634XmbLq1hu3B3BQ67 signature_count: 329 last_blockhash: 7CVmycpJperteEbenV3FmgYdNe3iBtRvCg6kmm5PscYw capitalization: 492620116404470728
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.766668705Z INFO solana_runtime::bank] accounts hash slot: 72677733 stats: BankHashStats { num_updated_accounts: 1515, num_removed_accounts: 6, num_lamports_stored: 1716898563722953, total_data_len: 163870265, num_executable_accounts: 0 }
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.766742040Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=553i same_account_writes_size=96855164i unique_account_writes_size=67014936i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.766803003Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=45i num_slots=97i total_unique_writes_size=5511101693i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.771066281Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677727i root=72677677i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.771375263Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677729i best_slot=72677729i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.771379109Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677729i weight="0"
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.771377731Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677729 0 0 72677728
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.775681715Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677732i root=72677677i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.775947691Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677733i best_slot=72677733i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.775951212Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677733i weight="0"
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.775951274Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677733 0 0 72677732
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.775991256Z INFO solana_core::replay_stage] voting: 72677733 0
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.776005846Z INFO solana_metrics::metrics] datapoint: tower-vote latest=72677733i root=72677677i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.781680997Z INFO solana_core::replay_stage] vote bank: Some((72677733, SameFork)) reset bank: 72677733
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.781700629Z INFO solana_metrics::metrics] datapoint: blocks_produced num_blocks_on_fork=1011i num_dropped_blocks_on_fork=137i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.781778768Z INFO solana_core::poh_recorder] reset poh from: HrqU57uxiG1f3cnTWcaMjRJkg4ZZiSnNZWji7PVYuygP,4651375018,72677733 to: 7CVmycpJperteEbenV3FmgYdNe3iBtRvCg6kmm5PscYw,72677733
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.781791663Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp reset PoH to tick 4651374976 (within slot 72677733). My next leader slot is 72677734
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.781808476Z INFO solana_core::replay_stage] new fork:72677734 parent:72677733 (leader) root:72677677
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.781809572Z INFO solana_metrics::metrics] datapoint: replay_stage-new_leader slot=72677734i leader="DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp"
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.781817565Z INFO solana_metrics::metrics] datapoint: replay_stage-my_leader_slot slot=72677734i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.782794646Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677734i block_height=66301586i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.784239380Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=308i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.784243055Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677734i from_genesis=1613440033i corrected=1617841298i ancestor_timestamp=1617841298i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.784707556Z INFO solana_core::replay_stage] new fork:72677730 parent:72677729 root:72677677
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.784967112Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677730i block_height=66301586i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.785296193Z INFO solana_metrics::metrics] datapoint: block-commitment-cache aggregate-commitment-ms=4i highest-confirmed-root=72677675i highest-confirmed-slot=72677727i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.786453254Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=240i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.786457456Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677730i from_genesis=1613440032i corrected=1617841297i ancestor_timestamp=1617841296i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.804912995Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-txs", "counts": 576665, "samples": 366000, "now": 1617841298804, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.804931307Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-sigs", "counts": 694718, "samples": 366000, "now": 1617841298804, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.822593004Z INFO solana_metrics::metrics] datapoint: cluster_info-num_nodes live_count=683i broadcast_count=686i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.830681714Z INFO solana_metrics::metrics] datapoint: cluster_slots_service-timing lowest_slot_elapsed=1425i update_completed_slots_elapsed=24575i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.867908198Z INFO solana_metrics::counter] COUNTER:{"name": "vote-native", "counts": 477001, "samples": 477000, "now": 1617841298867, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.876898032Z INFO solana_core::replay_stage] bank frozen: 72677730
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.876902697Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677730i fetch_entries_time=1113i fetch_entries_fail_time=0i entry_poh_verification_time=8508i entry_transaction_verification_time=1393i replay_time=79116i replay_total_elapsed=90396i total_entries=180i total_shreds=213i load_us=46684i execute_us=98518i store_us=33688i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.877008085Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=80i latest_slot_elapsed=1i read_lock_elapsed=0i load_account_elapsed=12i iterator_elapsed=9i num_keys_iterated=47i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.877137810Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=47i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.878552963Z INFO solana_runtime::bank] bank frozen: 72677730 hash: 51nWeLmgtzRF3ytbSmFXHy6xTNzeCh6dVgMt6bWva5h3 accounts_delta: A2v7KMqkZftCM5Ss4LarG39BUhJZBrnhotpM92ovKpeF signature_count: 297 last_blockhash: FE3ZSL3ayQXiSsJyGgrueZRsAZbZp6rm9G68ZZ1snktr capitalization: 492620116403294448
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.878573585Z INFO solana_runtime::bank] accounts hash slot: 72677730 stats: BankHashStats { num_updated_accounts: 820, num_removed_accounts: 0, num_lamports_stored: 751123556187745, total_data_len: 89033046, num_executable_accounts: 0 }
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.878594978Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=279i same_account_writes_size=54254262i unique_account_writes_size=34778784i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.878706745Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=45i num_slots=99i total_unique_writes_size=5567180070i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.883196627Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677727i root=72677677i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.883460190Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677730i best_slot=72677730i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.883459905Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677730 0 0 72677729
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.883465194Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677730i weight="0"
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.885852878Z INFO solana_core::replay_stage] Waiting to switch vote to 72677730, resetting to slot None on same fork for now
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.886210469Z INFO solana_core::replay_stage] new fork:72677731 parent:72677730 root:72677677
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.887150098Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677731i block_height=66301587i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.888502765Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=278i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.888507394Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677731i from_genesis=1613440032i corrected=1617841297i ancestor_timestamp=1617841297i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.925612527Z INFO solana_core::repair_service] repair_stats: [(72677727, 8), (72677730, 22), (72677728, 75), (72677731, 20), (72677729, 35), (72677726, 1), (72677733, 4), (72677734, 2), (72677732, 3), (72677729, 3)]
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.925640477Z INFO solana_metrics::metrics] datapoint: serve_repair-repair repair-total=173i shred-count=161i highest-shred-count=12i orphan-count=0i repair-highest-slot=72677734i repair-orphan=0i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.925654408Z INFO solana_metrics::metrics] datapoint: serve_repair-repair-timing set-root-elapsed=18i get-votes-elapsed=1410i add-votes-elapsed=2373i get-best-orphans-elapsed=1081i get-best-shreds-elapsed=9340i send-repairs-elapsed=18370i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.943025981Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_count", "counts": 4001, "samples": 4000, "now": 1617841298943, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.943045192Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions", "counts": 7887, "samples": 4000, "now": 1617841298943, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.969330522Z INFO solana_core::replay_stage] Waiting to switch vote to 72677730, resetting to slot None on same fork for now
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.969393813Z INFO solana_metrics::metrics] datapoint: cluster_info_stats entrypoint=27i entrypoint2=0i push_vote_read=46i get_votes=6984i get_accounts_hash=0i all_tvu_peers=0i tvu_peers=49596i new_push_requests_num=14265i table_size=338970i purged_values_size=128267i failed_inserts_size=7375i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.969408640Z INFO solana_metrics::metrics] datapoint: cluster_info_stats2 gossip_packets_dropped_count=0i retransmit_peers=2509i repair_peers=13660i new_push_requests=18892i new_push_requests2=693i purge=50558i process_gossip_packets_time=1540365i handle_batch_ping_messages_time=298i handle_batch_pong_messages_time=29i handle_batch_prune_messages_time=4424i handle_batch_pull_requests_time=1046113i handle_batch_pull_responses_time=50684i handle_batch_push_messages_time=247527i process_pull_resp=25560i filter_pull_resp=22574i process_pull_resp_count=20i pull_response_fail_insert=1537i pull_response_fail_timeout=0i pull_response_success=1992i process_pull_resp_timeout=0i push_response_count=1798i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.969416505Z INFO solana_metrics::metrics] datapoint: cluster_info_stats3 process_pull_resp_len=3629i process_pull_requests=539i pull_request_ping_pong_check_failed_count=0i generate_pull_responses=1015903i process_prune=268i process_push_message=29934i prune_received_cache=5344i epoch_slots_lookup=173i new_pull_requests=141111i mark_pull_request=2i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.969420914Z INFO solana_metrics::metrics] datapoint: cluster_info_stats4 skip_push_message_shred_version=0i skip_pull_response_shred_version=0i skip_pull_shred_version=0i push_message_count=2511i push_message_value_count=3234i new_pull_requests_count=5120i prune_message_count=387i prune_message_len=626i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.969424707Z INFO solana_metrics::metrics] datapoint: cluster_info_stats5 pull_requests_count=6591i packets_received_count=13132i packets_received_prune_messages_count=387i packets_received_pull_requests_count=6591i packets_received_pull_responses_count=3629i packets_received_push_messages_count=2511i packets_received_verified_count=13132i packets_sent_gossip_requests_count=6990i packets_sent_prune_messages_count=1798i packets_sent_pull_requests_count=5120i packets_sent_pull_responses_count=946i packets_sent_push_messages_count=14265i
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.974162784Z INFO solana_core::replay_stage] Waiting to switch vote to 72677730, resetting to slot None on same fork for now
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.981451225Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 710590, "samples": 379000, "now": 1617841298981, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.981597023Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-error_count", "counts": 133356, "samples": 41000, "now": 1617841298981, "events": 1}
Apr 8 00:21:38 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:38.991958648Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-account_in_use", "counts": 14456, "samples": 12000, "now": 1617841298991, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.002533225Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_num_to_commit", "counts": 7865, "samples": 17000, "now": 1617841299002, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.002546029Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_retryable_record_txs", "counts": 47, "samples": 17000, "now": 1617841299002, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.003343264Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-dropped_tx_before_forwarding", "counts": 508, "samples": 17000, "now": 1617841299003, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.006833995Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=833i slot=72677731i last_index=224i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.030085349Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 711607, "samples": 380000, "now": 1617841299030, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.030365428Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-error_count", "counts": 134367, "samples": 42000, "now": 1617841299030, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.045944678Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-account_in_use", "counts": 15461, "samples": 13000, "now": 1617841299045, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.048163172Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_num_to_commit", "counts": 7882, "samples": 18000, "now": 1617841299048, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.048174909Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_retryable_record_txs", "counts": 47, "samples": 18000, "now": 1617841299048, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.051604768Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-dropped_tx_before_forwarding", "counts": 536, "samples": 18000, "now": 1617841299051, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.083671678Z INFO solana_core::replay_stage] bank frozen: 72677731
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.083673348Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677731i fetch_entries_time=1346i fetch_entries_fail_time=0i entry_poh_verification_time=12371i entry_transaction_verification_time=1512i replay_time=67606i replay_total_elapsed=190887i total_entries=236i total_shreds=225i load_us=30839i execute_us=69644i store_us=26511i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.083766677Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=74i latest_slot_elapsed=0i read_lock_elapsed=0i load_account_elapsed=9i iterator_elapsed=7i num_keys_iterated=51i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.083879895Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=50i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.085724632Z INFO solana_runtime::bank] bank frozen: 72677731 hash: E86NboUjE3GwxhJHmAem6GgDcCymJw4UxTvnSxCte8FH accounts_delta: 4g8mjbVCmwWBYEiraAPSUve9jEgkH6sWeYwk2w9jDzYU signature_count: 237 last_blockhash: E3z7zREhMmqbGC9aiHvxenpqQjv4qS7X6DZi828UdFaz capitalization: 492620116402701948
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.085741275Z INFO solana_runtime::bank] accounts hash slot: 72677731 stats: BankHashStats { num_updated_accounts: 737, num_removed_accounts: 3, num_lamports_stored: 820435796912290, total_data_len: 66531387, num_executable_accounts: 2 }
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.085757653Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=177i same_account_writes_size=25561873i unique_account_writes_size=40969349i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.085847780Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=45i num_slots=100i total_unique_writes_size=5637026551i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.090305176Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 712805, "samples": 381000, "now": 1617841299090, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.090460339Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677727i root=72677677i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.090744644Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677731i best_slot=72677731i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.090750849Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677731i weight="0"
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.090746440Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677731 0 0 72677730
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.090908113Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-error_count", "counts": 135532, "samples": 43000, "now": 1617841299090, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.093212274Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot None on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.097559511Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot None on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.106540403Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-account_in_use", "counts": 16495, "samples": 14000, "now": 1617841299106, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.106580480Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_num_to_commit", "counts": 7934, "samples": 19000, "now": 1617841299106, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.106587116Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_retryable_record_txs", "counts": 47, "samples": 19000, "now": 1617841299106, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.112258651Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-dropped_tx_before_forwarding", "counts": 581, "samples": 19000, "now": 1617841299112, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana_exporter[1674]: I0408 00:21:39.132907 1674 slots.go:116] confirmed slot 72677675 (offset 101675, +2), epoch 168 (from slot 72576000 to 73008000, 330325 remaining)
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.133388306Z INFO solana_core::poh_recorder] poh_record: max_tick_height 4651375040 reached, clearing working_bank 72677734
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.133419990Z INFO solana_metrics::metrics] datapoint: leader-slot-start-to-cleared-elapsed-ms slot=72677734i elapsed=349i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.133431392Z INFO solana_core::banking_stage] process transactions: max height reached slot: 72677734 height: 4651375040
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.133448592Z INFO solana_core::banking_stage] process transactions: max height reached slot: 72677734 height: 4651375040
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.133455745Z INFO solana_core::banking_stage] process transactions: max height reached slot: 72677734 height: 4651375040
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.133505037Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=352i slot=72677734i last_index=180i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.133532472Z INFO solana_metrics::metrics] datapoint: broadcast-process-shreds-stats slot=72677734i shredding_time=10104i receive_time=320899i num_data_shreds=181i slot_broadcast_time=346217i get_leader_schedule_time=803i serialize_shreds_time=707i gen_data_time=9159i gen_coding_time=4155i sign_coding_time=7652i coding_send_time=4155i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.133686137Z INFO solana_metrics::metrics] datapoint: broadcast-insert-shreds-stats slot=72677734i end_to_end_elapsed=346371i insert_shreds_elapsed=22020i num_shreds=362i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.133788017Z INFO solana_core::replay_stage] bank frozen: 72677734
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.133789542Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677734i fetch_entries_time=0i fetch_entries_fail_time=0i entry_poh_verification_time=0i entry_transaction_verification_time=0i replay_time=0i replay_total_elapsed=255061i total_entries=0i total_shreds=0i load_us=0i execute_us=0i store_us=0i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.133842262Z INFO solana_metrics::metrics] datapoint: broadcast-transmit-shreds-stats slot=72677734i end_to_end_elapsed=346526i transmit_elapsed=16581i send_mmsg_elapsed=2572i get_peers_elapsed=116483i num_shreds=362i shred_select=6506i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.133873101Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=70i latest_slot_elapsed=0i read_lock_elapsed=0i load_account_elapsed=7i iterator_elapsed=7i num_keys_iterated=53i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.134003772Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=53i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.135595688Z INFO solana_runtime::bank] bank frozen: 72677734 hash: GrBRXYMPEkx94UtWtiVZ3Lz11jY61ufGQUbuabtSt5Uj accounts_delta: 55ZHnwLWD4vEvDJrYEJ6HHNcXP6wGutNgV7yKzZgtpW6 signature_count: 268 last_blockhash: AYK8z5mauYfhMaERjCBHuc9i7WLzwKjmg8wuTQBhQBpT capitalization: 492620116403800728
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.135612455Z INFO solana_runtime::bank] accounts hash slot: 72677734 stats: BankHashStats { num_updated_accounts: 1140, num_removed_accounts: 5, num_lamports_stored: 2769866930071214, total_data_len: 126252676, num_executable_accounts: 7 }
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.135629616Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=461i same_account_writes_size=74627971i unique_account_writes_size=51624705i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.135734321Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=45i num_slots=100i total_unique_writes_size=5638474531i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.139537284Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677733i root=72677677i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.139841334Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677734i best_slot=72677731i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.139845596Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677734i weight="0"
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.139842998Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677734 0 0 72677733
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.142269309Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677734) on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.142278311Z INFO solana_core::replay_stage] vote bank: None reset bank: 72677734
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.142287363Z INFO solana_metrics::metrics] datapoint: blocks_produced num_blocks_on_fork=1012i num_dropped_blocks_on_fork=137i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.144043329Z INFO solana_core::poh_recorder] reset poh from: BGNaYm9iCx2434Fea2qvtiTkJKqVPdsK2JJrmf6iv5xJ,4651375041,72677734 to: AYK8z5mauYfhMaERjCBHuc9i7WLzwKjmg8wuTQBhQBpT,72677734
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.144056024Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp reset PoH to tick 4651375040 (within slot 72677734). My next leader slot is 72677735
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.144061792Z WARN solana_core::replay_stage] PARTITION DETECTED waiting to join heaviest fork: 72677731 last vote: 72677733, reset slot: 72677734
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.144070354Z INFO solana_metrics::metrics] datapoint: replay_stage-partition slot=72677734i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.144077309Z INFO solana_core::replay_stage] new fork:72677735 parent:72677734 (leader) root:72677677
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.144077846Z INFO solana_metrics::metrics] datapoint: replay_stage-new_leader slot=72677735i leader="DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp"
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.144086634Z INFO solana_metrics::metrics] datapoint: replay_stage-my_leader_slot slot=72677735i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.145029936Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677735i block_height=66301587i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.146246160Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=220i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.146250652Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677735i from_genesis=1613440034i corrected=1617841299i ancestor_timestamp=1617841298i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.149071612Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677734) on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.151969016Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677734) on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.183323137Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 713928, "samples": 382000, "now": 1617841299183, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.188388375Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-error-blockhash_not_found", "counts": 4523, "samples": 1000, "now": 1617841299188, "events": 4}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.198871676Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-error_count", "counts": 136666, "samples": 44000, "now": 1617841299198, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.245902748Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_num_to_commit", "counts": 7975, "samples": 20000, "now": 1617841299245, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.245919169Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_retryable_record_txs", "counts": 52, "samples": 20000, "now": 1617841299245, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.251076150Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings hash_accounts=201979i store_accounts=125164i update_index=12531i handle_reclaims=7i append_accounts=0i find_storage=0i num_accounts=7940i total_data=835273967i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.251091590Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings2 recycle_store_count=0i current_recycle_store_count=1000i current_recycle_store_bytes=270479360i create_store_count=0i store_get_slot_store=0i store_find_existing=0i dropped_stores=0i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.257179268Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-dropped_tx_before_forwarding", "counts": 675, "samples": 20000, "now": 1617841299257, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.258820372Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677734) on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.279382096Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=2i process_packets_count=973i new_tx_count=587i dropped_batches_count=0i newly_buffered_packets_count=134i current_buffered_packets_count=0i rebuffered_packets_count=1485i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.315256004Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-account_in_use", "counts": 17590, "samples": 15000, "now": 1617841299315, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.322544614Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 715236, "samples": 383000, "now": 1617841299322, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.324100228Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-error_count", "counts": 137899, "samples": 45000, "now": 1617841299324, "events": 6}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.342355332Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_num_to_commit", "counts": 8044, "samples": 21000, "now": 1617841299342, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.342371019Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_retryable_record_txs", "counts": 52, "samples": 21000, "now": 1617841299342, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.354114241Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-dropped_tx_before_forwarding", "counts": 713, "samples": 21000, "now": 1617841299354, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.358913687Z INFO solana_metrics::metrics] datapoint: replay-loop-timing-stats total_elapsed_us=1073000i collect_frozen_banks_elapsed=239i compute_bank_stats_elapsed=26627i select_vote_and_reset_forks_elapsed=25090i start_leader_elapsed=4689i reset_bank_elapsed=1910i voting_elapsed=5681i select_forks_elapsed=2i compute_slot_stats_elapsed=60i generate_new_bank_forks_elapsed=9409i replay_active_banks_elapsed=643474i reset_duplicate_slots_elapsed=2067i wait_receive_elapsed=336036i heaviest_fork_failures_elapsed=0i bank_count=5i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.362186114Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677734) on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.365580487Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-account_in_use", "counts": 19122, "samples": 16000, "now": 1617841299365, "events": 3}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.372675450Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=3i process_packets_count=377i new_tx_count=377i dropped_batches_count=0i newly_buffered_packets_count=0i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.381715049Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 716883, "samples": 384000, "now": 1617841299381, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.398137929Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-error_count", "counts": 139561, "samples": 46000, "now": 1617841299398, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.420062478Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_num_to_commit", "counts": 8080, "samples": 22000, "now": 1617841299420, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.420077725Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_retryable_record_txs", "counts": 52, "samples": 22000, "now": 1617841299420, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.425946912Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-dropped_tx_before_forwarding", "counts": 761, "samples": 22000, "now": 1617841299425, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.451451546Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-account_in_use", "counts": 20197, "samples": 17000, "now": 1617841299451, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.458567760Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 718078, "samples": 385000, "now": 1617841299458, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.459500766Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-error_count", "counts": 140701, "samples": 47000, "now": 1617841299459, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.467318429Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677734) on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.480353559Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_num_to_commit", "counts": 8124, "samples": 23000, "now": 1617841299480, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.480373161Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-record_transactions_retryable_record_txs", "counts": 52, "samples": 23000, "now": 1617841299480, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.481028163Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-dropped_tx_before_forwarding", "counts": 782, "samples": 23000, "now": 1617841299481, "events": 0}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.502203820Z INFO solana_core::poh_recorder] poh_record: max_tick_height 4651375104 reached, clearing working_bank 72677735
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.502249128Z INFO solana_metrics::metrics] datapoint: leader-slot-start-to-cleared-elapsed-ms slot=72677735i elapsed=355i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.502260398Z INFO solana_core::banking_stage] process transactions: max height reached slot: 72677735 height: 4651375104
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.502327030Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=359i slot=72677735i last_index=134i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.502363802Z INFO solana_metrics::metrics] datapoint: broadcast-process-shreds-stats slot=72677735i shredding_time=10285i receive_time=329972i num_data_shreds=135i slot_broadcast_time=352829i get_leader_schedule_time=653i serialize_shreds_time=449i gen_data_time=9658i gen_coding_time=2971i sign_coding_time=6783i coding_send_time=2971i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.502507455Z INFO solana_metrics::metrics] datapoint: broadcast-insert-shreds-stats slot=72677735i end_to_end_elapsed=352971i insert_shreds_elapsed=16864i num_shreds=270i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.502641637Z INFO solana_core::replay_stage] bank frozen: 72677735
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.502643748Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677735i fetch_entries_time=0i fetch_entries_fail_time=0i entry_poh_verification_time=0i entry_transaction_verification_time=0i replay_time=0i replay_total_elapsed=356073i total_entries=0i total_shreds=0i load_us=0i execute_us=0i store_us=0i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.502656262Z INFO solana_metrics::metrics] datapoint: broadcast-transmit-shreds-stats slot=72677735i end_to_end_elapsed=353118i transmit_elapsed=13123i send_mmsg_elapsed=2115i get_peers_elapsed=76026i num_shreds=270i shred_select=4683i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.502726220Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=69i latest_slot_elapsed=0i read_lock_elapsed=0i load_account_elapsed=9i iterator_elapsed=8i num_keys_iterated=49i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.502836295Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=47i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.504940072Z INFO solana_runtime::bank] bank frozen: 72677735 hash: EjCmnkkX1JHcrktgijgBzf9BWikYQxowLoEp2WTvzDCA accounts_delta: Cneszg295HFdtmgApo7KtNpCSEiwYnen7dfkbTCBkyeV signature_count: 196 last_blockhash: CgZTj8v8oKYvAcPSUT3PMhMGi9gLLQiuqspGRyTipYZG capitalization: 492620116403310728
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.504957287Z INFO solana_runtime::bank] accounts hash slot: 72677735 stats: BankHashStats { num_updated_accounts: 834, num_removed_accounts: 3, num_lamports_stored: 18987253402811117, total_data_len: 159044533, num_executable_accounts: 0 }
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.504974300Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=402i same_account_writes_size=81807948i unique_account_writes_size=77236585i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.505095225Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=45i num_slots=101i total_unique_writes_size=5715711116i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.505141977Z INFO solana_core::banking_stage] process transactions: max height reached slot: 72677735 height: 4651375104
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.509065955Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677733i root=72677677i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.509375914Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677735i best_slot=72677731i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.509375753Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677735 0 0 72677734
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.509380561Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677735i weight="0"
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.509619554Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=1i process_packets_count=916i new_tx_count=574i dropped_batches_count=0i newly_buffered_packets_count=151i current_buffered_packets_count=1i rebuffered_packets_count=2384i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.511791052Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.511800709Z INFO solana_core::replay_stage] vote bank: None reset bank: 72677735
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.511810617Z INFO solana_metrics::metrics] datapoint: blocks_produced num_blocks_on_fork=1013i num_dropped_blocks_on_fork=137i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.512768561Z INFO solana_core::poh_recorder] reset poh from: 2KB1DHmEwkTBHthXmo79XJiG7oSoXAZZvcKgkCSTz5WX,4651375105,72677735 to: CgZTj8v8oKYvAcPSUT3PMhMGi9gLLQiuqspGRyTipYZG,72677735
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.512782363Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp reset PoH to tick 4651375104 (within slot 72677735). My next leader slot is 72677780
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.512802713Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=0i process_packets_count=1041i new_tx_count=576i dropped_batches_count=0i newly_buffered_packets_count=162i current_buffered_packets_count=0i rebuffered_packets_count=1691i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.515542510Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.518135959Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.606719147Z INFO solana_metrics::metrics] datapoint: poh-service ticks=182i hashes=2283008i elapsed_ms=353i total_sleep_ms=131i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.620772308Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.723484164Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.826163919Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.867384755Z INFO solana_metrics::counter] COUNTER:{"name": "banking_stage-forwarded_packets", "counts": 33414, "samples": 22000, "now": 1617841299867, "events": 1}
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.868039588Z INFO solana_metrics::metrics] datapoint: optimistic_slot_elapsed average_elapsed_ms=2124i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.868050125Z INFO solana_metrics::metrics] datapoint: optimistic_slot slot=72677728i
Apr 8 00:21:39 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:39.928951406Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.031597045Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:40 solana-production-nyc solana_exporter[1674]: I0408 00:21:40.133453 1674 slots.go:112] slot has not advanced at 72677675, skipping
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.134318533Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.237124352Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.255827200Z INFO solana_metrics::counter] COUNTER:{"name": "fetch_stage-discard_forwards", "counts": 21083, "samples": 8000, "now": 1617841300255, "events": 1}
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.286656342Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=2i process_packets_count=541i new_tx_count=288i dropped_batches_count=0i newly_buffered_packets_count=86i current_buffered_packets_count=1i rebuffered_packets_count=1416i
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.339845468Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.439921366Z INFO solana_metrics::metrics] datapoint: replay-loop-timing-stats total_elapsed_us=1081000i collect_frozen_banks_elapsed=172i compute_bank_stats_elapsed=5244i select_vote_and_reset_forks_elapsed=29866i start_leader_elapsed=0i reset_bank_elapsed=987i voting_elapsed=0i select_forks_elapsed=1i compute_slot_stats_elapsed=8i generate_new_bank_forks_elapsed=3077i replay_active_banks_elapsed=2553i reset_duplicate_slots_elapsed=1859i wait_receive_elapsed=1035482i heaviest_fork_failures_elapsed=0i bank_count=1i
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.442580231Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.470255668Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=3i process_packets_count=100i new_tx_count=100i dropped_batches_count=0i newly_buffered_packets_count=0i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.514493335Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=1i process_packets_count=340i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=89i current_buffered_packets_count=1i rebuffered_packets_count=0i
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.517656954Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=0i process_packets_count=301i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=90i current_buffered_packets_count=1i rebuffered_packets_count=0i
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.545291375Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.612983141Z INFO solana_metrics::metrics] datapoint: poh-service ticks=184i hashes=2308096i elapsed_ms=349i total_sleep_ms=182i
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.648045468Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.680595710Z INFO solana_metrics::metrics] datapoint: optimistic_slot_elapsed average_elapsed_ms=812i
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.680606865Z INFO solana_metrics::metrics] datapoint: optimistic_slot slot=72677729i
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.689500749Z INFO solana_metrics::metrics] datapoint: recycler_total_allocated_count name="gossip-receiver-recycler-shrink-stats" count=245000i recycled_len=0i
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.750757915Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.853404053Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.956072951Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.986043738Z INFO solana_metrics::metrics] datapoint: optimistic_slot_elapsed average_elapsed_ms=305i
Apr 8 00:21:40 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:40.986058323Z INFO solana_metrics::metrics] datapoint: optimistic_slot slot=72677730i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.058691666Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.071613696Z INFO solana_metrics::metrics] datapoint: cluster_info_stats entrypoint=0i entrypoint2=0i push_vote_read=0i get_votes=5120i get_accounts_hash=0i all_tvu_peers=0i tvu_peers=20225i new_push_requests_num=16580i table_size=338850i purged_values_size=128894i failed_inserts_size=8156i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.071628366Z INFO solana_metrics::metrics] datapoint: cluster_info_stats2 gossip_packets_dropped_count=0i retransmit_peers=134i repair_peers=1784i new_push_requests=17986i new_push_requests2=612i purge=52159i process_gossip_packets_time=1596695i handle_batch_ping_messages_time=382i handle_batch_pong_messages_time=34i handle_batch_prune_messages_time=9421i handle_batch_pull_requests_time=1078471i handle_batch_pull_responses_time=38124i handle_batch_push_messages_time=270269i process_pull_resp=17941i filter_pull_resp=17500i process_pull_resp_count=20i pull_response_fail_insert=967i pull_response_fail_timeout=661i pull_response_success=1278i process_pull_resp_timeout=661i push_response_count=1944i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.071635552Z INFO solana_metrics::metrics] datapoint: cluster_info_stats3 process_pull_resp_len=3024i process_pull_requests=296i pull_request_ping_pong_check_failed_count=0i generate_pull_responses=1049150i process_prune=497i process_push_message=45623i prune_received_cache=7924i epoch_slots_lookup=41i new_pull_requests=137543i mark_pull_request=3i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.071639927Z INFO solana_metrics::metrics] datapoint: cluster_info_stats4 skip_push_message_shred_version=0i skip_pull_response_shred_version=0i skip_pull_shred_version=0i push_message_count=4206i push_message_value_count=5295i new_pull_requests_count=5120i prune_message_count=391i prune_message_len=550i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.071643139Z INFO solana_metrics::metrics] datapoint: cluster_info_stats5 pull_requests_count=7168i packets_received_count=14809i packets_received_prune_messages_count=391i packets_received_pull_requests_count=7168i packets_received_pull_responses_count=3024i packets_received_push_messages_count=4206i packets_received_verified_count=14809i packets_sent_gossip_requests_count=9152i packets_sent_prune_messages_count=1944i packets_sent_pull_requests_count=5120i packets_sent_pull_responses_count=4304i packets_sent_push_messages_count=16580i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.100148515Z INFO solana_metrics::metrics] datapoint: shred_fetch_tvu_forwards index_overrun=0i shred_count=365i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=0i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.100787575Z INFO solana_metrics::metrics] datapoint: retransmit-first-shred slot=72677736i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.100876776Z INFO solana_metrics::metrics] datapoint: retransmit-num_nodes count=686i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.100880511Z INFO solana_metrics::metrics] datapoint: retransmit-stage total_time=46111i epoch_fetch=460i epoch_cache_update=2491i total_batches=385i total_packets=377i retransmit_total=11165i compute_turbine=28228i repair_total=25i discard_total=5i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.100884952Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677730i num_shreds=22i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.100887288Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677731i num_shreds=354i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.100889297Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677736i num_shreds=1i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.100891110Z INFO solana_core::retransmit_stage] retransmit: top packets_by_source: {13: "35.243.134.140:11005", 18: "85.190.150.50:8005", 21: "188.34.134.28:8005", 23: "89.202.64.28:5639", 25: "173.231.58.226:8006"} len: 89
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.102278325Z INFO solana_metrics::metrics] datapoint: shred_fetch index_overrun=0i shred_count=13i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=0i
Apr 8 00:21:41 solana-production-nyc solana_exporter[1674]: I0408 00:21:41.132864 1674 slots.go:112] slot has not advanced at 72677675, skipping
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.158957482Z INFO solana_core::replay_stage] new fork:72677736 parent:72677731 root:72677677
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.159958110Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677736i block_height=66301588i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.161087975Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings hash_accounts=31808i store_accounts=18087i update_index=1369i handle_reclaims=2i append_accounts=0i find_storage=0i num_accounts=667i total_data=127572332i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.161093328Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings2 recycle_store_count=0i current_recycle_store_count=1000i current_recycle_store_bytes=270479360i create_store_count=0i store_get_slot_store=0i store_find_existing=0i dropped_stores=0i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.161406805Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=307i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.161413780Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677736i from_genesis=1613440034i corrected=1617841299i ancestor_timestamp=1617841297i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.172117974Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.284829187Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.288636292Z INFO solana_metrics::metrics] datapoint: optimistic_slot_elapsed average_elapsed_ms=302i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.288648397Z INFO solana_metrics::metrics] datapoint: optimistic_slot slot=72677731i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.289772950Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=2i process_packets_count=392i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=102i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.319936655Z INFO solana_metrics::metrics] datapoint: shred_fetch_repair index_overrun=0i shred_count=29i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=4i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.352192451Z INFO solana_metrics::metrics] datapoint: recv-window-insert-shreds num_shreds=656i total_elapsed=51856i insert_lock_elapsed=732i insert_shreds_elapsed=10554i shred_recovery_elapsed=24029i chaining_elapsed=18i commit_working_sets_elapsed=1465i write_batch_elapsed=12402i num_inserted=315i num_repair=12i num_recovered=211i num_recovered_inserted=211i num_recovered_failed_sig=0i num_recovered_failed_invalid=0i num_recovered_exists=0i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.376869849Z INFO solana_metrics::metrics] submitting 766 points
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.387937711Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.490956816Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.610355965Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.719824618Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.764272900Z INFO solana_metrics::metrics] datapoint: retransmit-first-shred slot=72677737i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.764287715Z INFO solana_metrics::metrics] datapoint: replay-loop-timing-stats total_elapsed_us=1049000i collect_frozen_banks_elapsed=149i compute_bank_stats_elapsed=759i select_vote_and_reset_forks_elapsed=22440i start_leader_elapsed=1i reset_bank_elapsed=0i voting_elapsed=0i select_forks_elapsed=3i compute_slot_stats_elapsed=0i generate_new_bank_forks_elapsed=4659i replay_active_banks_elapsed=17836i reset_duplicate_slots_elapsed=1498i wait_receive_elapsed=1000564i heaviest_fork_failures_elapsed=0i bank_count=0i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.764294417Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=1i process_packets_count=271i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=111i current_buffered_packets_count=1i rebuffered_packets_count=0i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.764298465Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=0i process_packets_count=271i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=102i current_buffered_packets_count=1i rebuffered_packets_count=0i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.764302523Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=3i process_packets_count=0i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=0i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.764319171Z INFO solana_metrics::metrics] datapoint: poh-service ticks=184i hashes=2308096i elapsed_ms=349i total_sleep_ms=176i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.823467762Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.850378768Z INFO solana_metrics::metrics] datapoint: retransmit-first-shred slot=72677738i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.925356453Z INFO solana_metrics::metrics] datapoint: cluster_slots_service-timing lowest_slot_elapsed=1758i update_completed_slots_elapsed=27525i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.944465991Z INFO solana_core::repair_service] repair_stats: [(72677736, 32), (72677737, 23), (72677734, 2), (72677735, 3)]
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.944491723Z INFO solana_metrics::metrics] datapoint: serve_repair-repair repair-total=60i shred-count=55i highest-shred-count=5i orphan-count=0i repair-highest-slot=72677735i repair-orphan=0i
Apr 8 00:21:41 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:41.944503259Z INFO solana_metrics::metrics] datapoint: serve_repair-repair-timing set-root-elapsed=0i get-votes-elapsed=659i add-votes-elapsed=1844i get-best-orphans-elapsed=869i get-best-shreds-elapsed=6754i send-repairs-elapsed=6839i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.021467083Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=958i slot=72677736i last_index=329i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.070112954Z INFO solana_core::replay_stage] Waiting to switch vote to 72677731, resetting to slot Some(72677735) on same fork for now
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.102563280Z INFO solana_metrics::metrics] datapoint: shred_fetch_tvu_forwards index_overrun=0i shred_count=1070i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=0i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.118516377Z INFO solana_metrics::metrics] datapoint: shred_fetch index_overrun=0i shred_count=28i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=0i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.124492199Z INFO solana_core::serve_repair] WindowIndexWithNonce took: 15 ms
Apr 8 00:21:42 solana-production-nyc solana_exporter[1674]: I0408 00:21:42.133172 1674 slots.go:112] slot has not advanced at 72677675, skipping
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.178222205Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings hash_accounts=30917i store_accounts=12342i update_index=2605i handle_reclaims=0i append_accounts=0i find_storage=0i num_accounts=1642i total_data=130143555i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.178231624Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings2 recycle_store_count=0i current_recycle_store_count=1000i current_recycle_store_bytes=270479360i create_store_count=0i store_get_slot_store=0i store_find_existing=0i dropped_stores=0i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.199435678Z INFO solana_core::replay_stage] bank frozen: 72677736
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.199439752Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677736i fetch_entries_time=2549i fetch_entries_fail_time=0i entry_poh_verification_time=42928i entry_transaction_verification_time=3735i replay_time=162708i replay_total_elapsed=1037977i total_entries=482i total_shreds=330i load_us=65104i execute_us=173853i store_us=55720i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.199847139Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=391i latest_slot_elapsed=6i read_lock_elapsed=5i load_account_elapsed=48i iterator_elapsed=33i num_keys_iterated=236i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.200396472Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=230i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.207192071Z INFO solana_runtime::bank] bank frozen: 72677736 hash: Aivo3snfhajs8HZ1xXFEfpxYMPVznKB98aLqxyQLvfvK accounts_delta: FiebpberhP8iXVGNAvmxe28sQc6cmrwgPPKB1jsH1Bj2 signature_count: 660 last_blockhash: DonGqJM1S579GxPEvZp1qTvC6yY3SNuYALzqrapvEFVi capitalization: 492620116401050729
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.207213012Z INFO solana_runtime::bank] accounts hash slot: 72677736 stats: BankHashStats { num_updated_accounts: 2399, num_removed_accounts: 0, num_lamports_stored: 1699189092259235, total_data_len: 151256227, num_executable_accounts: 1 }
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.207236774Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=853i same_account_writes_size=107489603i unique_account_writes_size=43766624i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.207348073Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=45i num_slots=102i total_unique_writes_size=5759477740i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.211564634Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677727i root=72677677i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.211926645Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677736i best_slot=72677736i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.211930920Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677736i weight="0"
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.211928810Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677736 0 0 72677731
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.214052168Z INFO solana_core::replay_stage] Couldn't vote on heaviest fork: 72677736, heaviest_fork_failures: [LockedOut(72677736)]
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.214061165Z INFO solana_core::replay_stage] vote bank: None reset bank: 72677736
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.214070485Z INFO solana_metrics::metrics] datapoint: blocks_produced num_blocks_on_fork=1014i num_dropped_blocks_on_fork=137i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.214379050Z INFO solana_core::poh_recorder] reset poh from: FouHbFGTJ7KJS38QiKSXhDWBhMSoNAo2awGpMPmgDLEB,4651375597,72677735 to: DonGqJM1S579GxPEvZp1qTvC6yY3SNuYALzqrapvEFVi,72677736
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.214400092Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp reset PoH to tick 4651375168 (within slot 72677736). My next leader slot is 72677780
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.214741454Z INFO solana_core::replay_stage] new fork:72677737 parent:72677736 root:72677677
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.215747972Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677737i block_height=66301589i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.217036514Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=209i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.217040383Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677737i from_genesis=1613440034i corrected=1617841301i ancestor_timestamp=1617841299i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.222810335Z INFO solana_metrics::metrics] datapoint: retransmit-first-shred slot=72677739i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.262686184Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=819i slot=72677737i last_index=284i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.326276813Z INFO solana_metrics::metrics] datapoint: shred_fetch_repair index_overrun=0i shred_count=40i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=1i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.330299021Z INFO solana_metrics::counter] COUNTER:{"name": "vote-native", "counts": 478001, "samples": 478000, "now": 1617841302330, "events": 1}
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.333123179Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=2i process_packets_count=42i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=13i current_buffered_packets_count=1i rebuffered_packets_count=0i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.410199591Z INFO solana_core::replay_stage] Couldn't vote on heaviest fork: 72677736, heaviest_fork_failures: [LockedOut(72677736)]
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.419308718Z INFO solana_core::replay_stage] bank frozen: 72677737
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.419311910Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677737i fetch_entries_time=1122i fetch_entries_fail_time=0i entry_poh_verification_time=12393i entry_transaction_verification_time=1697i replay_time=183717i replay_total_elapsed=202215i total_entries=242i total_shreds=285i load_us=71779i execute_us=213849i store_us=50986i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.419377320Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=53i latest_slot_elapsed=0i read_lock_elapsed=0i load_account_elapsed=7i iterator_elapsed=7i num_keys_iterated=38i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.419480466Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=37i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.420900455Z INFO solana_runtime::bank] bank frozen: 72677737 hash: FcQxsP1cr8v2K4kTzYZq3h77NRd6H9spLm7HTC6kc11s accounts_delta: 5bdkmWtwm5hQ3J72t8xkEph1pULKxQhtGMgo1j99gKRL signature_count: 506 last_blockhash: GtoRAoZzNfVoVxSZHJjeWrfhtLBTBxGo2r7XDqcBaJcj capitalization: 492620116399785729
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.420919045Z INFO solana_runtime::bank] accounts hash slot: 72677737 stats: BankHashStats { num_updated_accounts: 1681, num_removed_accounts: 4, num_lamports_stored: 2506498533836060, total_data_len: 142760547, num_executable_accounts: 16 }
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.420934033Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=788i same_account_writes_size=95875408i unique_account_writes_size=46885139i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.421038930Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=45i num_slots=103i total_unique_writes_size=5806362879i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.425651602Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677727i root=72677677i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.425969109Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677737i best_slot=72677737i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.425973492Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677737i weight="0"
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.425970370Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677737 0 0 72677736
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.425990307Z INFO solana_core::replay_stage] validator fork confirmed 72677729 3904ms
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.425996745Z INFO solana_core::replay_stage] validator fork confirmed 72677728 5415ms
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.425997400Z INFO solana_metrics::metrics] datapoint: validator-confirmation duration_ms=3904i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.426004339Z INFO solana_metrics::metrics] datapoint: validator-confirmation duration_ms=5415i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.427810160Z INFO solana_core::replay_stage] voting: 72677737 0
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.427817742Z INFO solana_core::replay_stage] LEADER CHANGE at slot: 72677737 leader: EaRH6eMWnXKXhw1tqve6eUXnsoWYUFKeSbXUyBEqyPYJ. I am no longer the leader
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.427833913Z INFO solana_metrics::metrics] datapoint: tower-vote latest=72677737i root=72677677i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.431896579Z INFO solana_core::replay_stage] vote bank: Some((72677737, SwitchProof(11111111111111111111111111111111))) reset bank: 72677737
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.431911883Z INFO solana_metrics::metrics] datapoint: blocks_produced num_blocks_on_fork=1015i num_dropped_blocks_on_fork=137i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.433205349Z INFO solana_core::poh_recorder] reset poh from: BhT3ghCySUxLrZqkWyvb8375RFnxNSYNF9id9Akb853F,4651375207,72677736 to: GtoRAoZzNfVoVxSZHJjeWrfhtLBTBxGo2r7XDqcBaJcj,72677737
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.433218441Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp reset PoH to tick 4651375232 (within slot 72677737). My next leader slot is 72677780
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.433223456Z WARN solana_core::replay_stage] PARTITION resolved heaviest fork: 72677737 last vote: 72677737, reset slot: 72677737
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.433501432Z INFO solana_core::replay_stage] new fork:72677738 parent:72677737 root:72677677
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.434500992Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677738i block_height=66301590i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.435918455Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=321i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.435928697Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677738i from_genesis=1613440035i corrected=1617841301i ancestor_timestamp=1617841301i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.435965726Z INFO solana_metrics::metrics] datapoint: block-commitment-cache aggregate-commitment-ms=4i highest-confirmed-root=72677678i highest-confirmed-slot=72677731i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.445296376Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=607i slot=72677738i last_index=216i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.543241834Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=1i process_packets_count=20i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=5i current_buffered_packets_count=1i rebuffered_packets_count=0i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.543425529Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-txs", "counts": 578671, "samples": 367000, "now": 1617841302543, "events": 1}
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.543437473Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-sigs", "counts": 696993, "samples": 367000, "now": 1617841302543, "events": 1}
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.560909505Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions", "counts": 720087, "samples": 386000, "now": 1617841302560, "events": 1}
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.571640978Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=3i process_packets_count=0i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=0i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.587151153Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=0i process_packets_count=17i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=5i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.614011655Z INFO solana_core::replay_stage] bank frozen: 72677738
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.614013365Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677738i fetch_entries_time=994i fetch_entries_fail_time=0i entry_poh_verification_time=18622i entry_transaction_verification_time=1417i replay_time=155972i replay_total_elapsed=178043i total_entries=267i total_shreds=217i load_us=64512i execute_us=174558i store_us=47801i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.614099717Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=67i latest_slot_elapsed=0i read_lock_elapsed=0i load_account_elapsed=5i iterator_elapsed=8i num_keys_iterated=52i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.614216409Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=52i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.615701001Z INFO solana_runtime::bank] bank frozen: 72677738 hash: C3TNAXY4cu2Uutmzi8ha5EQRF25B1WttXod4NDzabLWA accounts_delta: 9P9w3PyHwBaj2XNRfWfA2HG7ovRDkFqJkn8wm9msgr4o signature_count: 270 last_blockhash: 6k7s4ZysDhDexrBATyd66F2gzYKnVjko3Lts4FRURwc2 capitalization: 492620116399110729
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.615719955Z INFO solana_runtime::bank] accounts hash slot: 72677738 stats: BankHashStats { num_updated_accounts: 1111, num_removed_accounts: 2, num_lamports_stored: 956409376311967, total_data_len: 131300348, num_executable_accounts: 10 }
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.615737842Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=552i same_account_writes_size=96953787i unique_account_writes_size=34346561i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.615852204Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=45i num_slots=104i total_unique_writes_size=5840709440i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.619885848Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677727i root=72677677i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.620129445Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677738i best_slot=72677738i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.620133737Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677738i weight="0"
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.620131050Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677738 0 0 72677737
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.620156821Z INFO solana_core::replay_stage] voting: 72677738 0
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.620169560Z INFO solana_metrics::metrics] datapoint: tower-vote latest=72677738i root=72677677i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.624294314Z INFO solana_core::replay_stage] vote bank: Some((72677738, SameFork)) reset bank: 72677738
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.624310206Z INFO solana_metrics::metrics] datapoint: blocks_produced num_blocks_on_fork=1016i num_dropped_blocks_on_fork=137i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.624668723Z INFO solana_core::poh_recorder] reset poh from: BNp8vJ2DKb8PpwBXTorBpPJJi2TcpfZtc8ek9kpwZ1mj,4651375266,72677737 to: 6k7s4ZysDhDexrBATyd66F2gzYKnVjko3Lts4FRURwc2,72677738
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.624681858Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp reset PoH to tick 4651375296 (within slot 72677738). My next leader slot is 72677780
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.624698930Z INFO solana_metrics::metrics] datapoint: replay-loop-timing-stats total_elapsed_us=1136000i collect_frozen_banks_elapsed=259i compute_bank_stats_elapsed=13556i select_vote_and_reset_forks_elapsed=19083i start_leader_elapsed=12i reset_bank_elapsed=2073i voting_elapsed=8211i select_forks_elapsed=7i compute_slot_stats_elapsed=37i generate_new_bank_forks_elapsed=7973i replay_active_banks_elapsed=582816i reset_duplicate_slots_elapsed=2074i wait_receive_elapsed=500303i heaviest_fork_failures_elapsed=27i bank_count=3i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.625095445Z INFO solana_core::replay_stage] new fork:72677739 parent:72677738 root:72677677
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.625526524Z INFO solana_metrics::metrics] datapoint: poh-service ticks=184i hashes=2308096i elapsed_ms=349i total_sleep_ms=165i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.626006558Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677739i block_height=66301591i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.627359588Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=291i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.627366860Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677739i from_genesis=1613440035i corrected=1617841302i ancestor_timestamp=1617841301i
Apr 8 00:21:42 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:42.628707365Z INFO solana_metrics::metrics] datapoint: block-commitment-cache aggregate-commitment-ms=4i highest-confirmed-root=72677678i highest-confirmed-slot=72677731i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.008640563Z INFO solana_metrics::metrics] datapoint: optimistic_slot_elapsed average_elapsed_ms=1719i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.008656767Z INFO solana_metrics::metrics] datapoint: optimistic_slot slot=72677736i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.045129994Z INFO solana_metrics::metrics] datapoint: shred_insert_is_full total_time_ms=829i slot=72677739i last_index=354i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.074096289Z INFO solana_metrics::metrics] datapoint: cluster_info_stats entrypoint=11i entrypoint2=0i push_vote_read=38i get_votes=4718i get_accounts_hash=0i all_tvu_peers=0i tvu_peers=2333i new_push_requests_num=11618i table_size=338870i purged_values_size=128355i failed_inserts_size=7455i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.074107014Z INFO solana_metrics::metrics] datapoint: cluster_info_stats2 gossip_packets_dropped_count=0i retransmit_peers=4672i repair_peers=8232i new_push_requests=12896i new_push_requests2=673i purge=53839i process_gossip_packets_time=892221i handle_batch_ping_messages_time=287i handle_batch_pong_messages_time=22i handle_batch_prune_messages_time=9448i handle_batch_pull_requests_time=367041i handle_batch_pull_responses_time=19781i handle_batch_push_messages_time=345329i process_pull_resp=7222i filter_pull_resp=5817i process_pull_resp_count=18i pull_response_fail_insert=385i pull_response_fail_timeout=0i pull_response_success=387i process_pull_resp_timeout=0i push_response_count=3224i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.074117384Z INFO solana_metrics::metrics] datapoint: cluster_info_stats3 process_pull_resp_len=797i process_pull_requests=351i pull_request_ping_pong_check_failed_count=1i generate_pull_responses=356900i process_prune=180i process_push_message=39375i prune_received_cache=7661i epoch_slots_lookup=329i new_pull_requests=144264i mark_pull_request=0i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.074122869Z INFO solana_metrics::metrics] datapoint: cluster_info_stats4 skip_push_message_shred_version=0i skip_pull_response_shred_version=0i skip_pull_shred_version=0i push_message_count=3307i push_message_value_count=4436i new_pull_requests_count=5120i prune_message_count=311i prune_message_len=411i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.074127624Z INFO solana_metrics::metrics] datapoint: cluster_info_stats5 pull_requests_count=2653i packets_received_count=7085i packets_received_prune_messages_count=311i packets_received_pull_requests_count=2653i packets_received_pull_responses_count=797i packets_received_push_messages_count=3307i packets_received_verified_count=7085i packets_sent_gossip_requests_count=6231i packets_sent_prune_messages_count=3224i packets_sent_pull_requests_count=5120i packets_sent_pull_responses_count=1285i packets_sent_push_messages_count=11618i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.126582852Z INFO solana_metrics::metrics] datapoint: recycler_total_allocated_count name="gossip-receiver-recycler-shrink-stats" count=246000i recycled_len=0i
Apr 8 00:21:43 solana-production-nyc solana_exporter[1674]: I0408 00:21:43.133594 1674 slots.go:116] confirmed slot 72677678 (offset 101678, +3), epoch 168 (from slot 72576000 to 73008000, 330322 remaining)
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.171634408Z INFO solana_core::replay_stage] bank frozen: 72677739
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.171639068Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=72677739i fetch_entries_time=1788i fetch_entries_fail_time=0i entry_poh_verification_time=32525i entry_transaction_verification_time=4237i replay_time=101698i replay_total_elapsed=544223i total_entries=434i total_shreds=355i load_us=57027i execute_us=143813i store_us=45426i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.171724678Z INFO solana_metrics::metrics] datapoint: load_to_collect_rent_eagerly_scan_elapsed total_elapsed=68i latest_slot_elapsed=1i read_lock_elapsed=0i load_account_elapsed=11i iterator_elapsed=8i num_keys_iterated=41i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.171846758Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=41i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.173447932Z INFO solana_runtime::bank] bank frozen: 72677739 hash: 7EByzfU9Rmh8vUEnRBRM4FTcgtDkEWT6WmSfu2qAH1He accounts_delta: GzYJ3sKjV6sqjWsC9ntLC3Yjfk3yexWK4bqjhiei6Czg signature_count: 567 last_blockhash: AB7z7ZXvqBsEnXgfNBH2cZ6CQgg3nToeLqPyNBtTEBcB capitalization: 492620116397693229
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.173468635Z INFO solana_runtime::bank] accounts hash slot: 72677739 stats: BankHashStats { num_updated_accounts: 1492, num_removed_accounts: 0, num_lamports_stored: 2560596713856966, total_data_len: 106609524, num_executable_accounts: 0 }
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.173492999Z INFO solana_metrics::metrics] datapoint: slot_repeated_writes same_account_writes=444i same_account_writes_size=62989294i unique_account_writes_size=43620230i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.173629484Z INFO solana_metrics::metrics] datapoint: accounts_cache_size num_roots=45i num_slots=105i total_unique_writes_size=5884329670i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.179612383Z INFO solana_metrics::metrics] datapoint: tower-observed slot=72677727i root=72677677i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.180046231Z INFO solana_metrics::metrics] datapoint: best_slot slot=72677739i best_slot=72677739i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.180058545Z INFO solana_metrics::metrics] datapoint: bank_weight slot=72677739i weight="0"
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.180046593Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp slot_weight: 72677739 0 0 72677738
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.180084632Z INFO solana_core::replay_stage] voting: 72677739 0
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.180099698Z INFO solana_metrics::metrics] datapoint: tower-vote latest=72677739i root=72677677i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.185680508Z INFO solana_core::replay_stage] vote bank: Some((72677739, SameFork)) reset bank: 72677739
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.185696156Z INFO solana_metrics::metrics] datapoint: blocks_produced num_blocks_on_fork=1017i num_dropped_blocks_on_fork=137i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.188171361Z INFO solana_metrics::metrics] datapoint: block-commitment-cache aggregate-commitment-ms=4i highest-confirmed-root=72677678i highest-confirmed-slot=72677736i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.189085506Z INFO solana_core::poh_recorder] reset poh from: 3Tz7TJHu2Ty3T7SBLEzU9gTnBS6ph7JX3FywixaxoiMc,4651375397,72677738 to: AB7z7ZXvqBsEnXgfNBH2cZ6CQgg3nToeLqPyNBtTEBcB,72677739
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.189098248Z INFO solana_core::replay_stage] DDnAqxJVFo2GVTujibHt5cjevHMSE9bo8HJaydHoshdp reset PoH to tick 4651375360 (within slot 72677739). My next leader slot is 72677780
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.258212416Z INFO solana_metrics::metrics] datapoint: shred_fetch_tvu_forwards index_overrun=0i shred_count=663i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=0i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.258818458Z INFO solana_metrics::metrics] datapoint: retransmit-first-shred slot=72677740i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.258917946Z INFO solana_metrics::metrics] datapoint: retransmit-num_nodes count=686i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.258922803Z INFO solana_metrics::metrics] datapoint: retransmit-stage total_time=191256i epoch_fetch=745i epoch_cache_update=15049i total_batches=1719i total_packets=1782i retransmit_total=38547i compute_turbine=125108i repair_total=67i discard_total=3i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.258926879Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677736i num_shreds=492i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.258929780Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677737i num_shreds=430i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.258932484Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677738i num_shreds=330i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.258934752Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677739i num_shreds=529i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.258937068Z INFO solana_metrics::metrics] datapoint: retransmit-slot-num-packets slot=72677740i num_shreds=1i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.258938066Z INFO solana_core::retransmit_stage] retransmit: top packets_by_source: {61: "35.243.134.140:11005", 102: "85.190.150.50:8005", 105: "188.34.134.28:8005", 108: "89.202.64.28:5639", 136: "173.231.58.226:8006"} len: 234
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.290465182Z INFO solana_core::replay_stage] new fork:72677740 parent:72677739 root:72677677
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.291558208Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=72677740i block_height=66301592i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.292693733Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings hash_accounts=94629i store_accounts=41694i update_index=6173i handle_reclaims=0i append_accounts=0i find_storage=0i num_accounts=5047i total_data=401783091i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.292703426Z INFO solana_metrics::metrics] datapoint: accounts_db_store_timings2 recycle_store_count=0i current_recycle_store_count=1000i current_recycle_store_bytes=270479360i create_store_count=0i store_get_slot_store=0i store_find_existing=0i dropped_stores=0i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.292992077Z INFO solana_metrics::metrics] datapoint: bank-timestamp get_timestamp_estimate_us=287i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.292997153Z INFO solana_metrics::metrics] datapoint: bank-timestamp-correction slot=72677740i from_genesis=1613440036i corrected=1617841303i ancestor_timestamp=1617841302i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.371804077Z INFO solana_metrics::metrics] datapoint: shred_fetch index_overrun=0i shred_count=21i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=0i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.425218534Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=2i process_packets_count=2i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=2i current_buffered_packets_count=1i rebuffered_packets_count=0i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.546656019Z INFO solana_metrics::metrics] datapoint: shred_fetch_repair index_overrun=0i shred_count=30i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=2i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.572283365Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=3i process_packets_count=0i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=0i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.629085430Z INFO solana_metrics::metrics] datapoint: poh-service ticks=178i hashes=2232832i elapsed_ms=360i total_sleep_ms=135i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.643921387Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=1i process_packets_count=0i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=0i current_buffered_packets_count=0i rebuffered_packets_count=0i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.661852709Z INFO solana_metrics::metrics] datapoint: replay-loop-timing-stats total_elapsed_us=1037000i collect_frozen_banks_elapsed=278i compute_bank_stats_elapsed=6721i select_vote_and_reset_forks_elapsed=15i start_leader_elapsed=5i reset_bank_elapsed=3423i voting_elapsed=5589i select_forks_elapsed=6i compute_slot_stats_elapsed=11i generate_new_bank_forks_elapsed=8516i replay_active_banks_elapsed=209583i reset_duplicate_slots_elapsed=2242i wait_receive_elapsed=800469i heaviest_fork_failures_elapsed=0i bank_count=1i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.685951147Z INFO solana_metrics::metrics] datapoint: banking_stage-loop-stats id=0i process_packets_count=1i new_tx_count=0i dropped_batches_count=0i newly_buffered_packets_count=1i current_buffered_packets_count=1i rebuffered_packets_count=0i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.706500660Z INFO solana_metrics::counter] COUNTER:{"name": "vote-native", "counts": 479001, "samples": 479000, "now": 1617841303706, "events": 1}
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.745217028Z INFO solana_metrics::metrics] datapoint: retransmit-first-shred slot=72677741i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.921025968Z INFO solana_metrics::metrics] datapoint: optimistic_slot_elapsed average_elapsed_ms=912i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.921043464Z INFO solana_metrics::metrics] datapoint: optimistic_slot slot=72677738i
Apr 8 00:21:43 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:43.921046325Z INFO solana_metrics::metrics] datapoint: optimistic_slot slot=72677737i
Apr 8 00:21:44 solana-production-nyc solana_exporter[1674]: I0408 00:21:44.133135 1674 slots.go:112] slot has not advanced at 72677678, skipping
Apr 8 00:21:44 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:44.211089075Z INFO solana_metrics::metrics] datapoint: retransmit-first-shred slot=72677742i
Apr 8 00:21:44 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:44.260869371Z INFO solana_metrics::metrics] datapoint: shred_fetch_tvu_forwards index_overrun=0i shred_count=1471i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=0i
Apr 8 00:21:44 solana-production-nyc solana-validator[32924]: [2021-04-08T00:21:44.286970185Z INFO solana_core::cluster_info]