Skip to content

Instantly share code, notes, and snippets.

@brianlong
Created September 10, 2020 12:44
Show Gist options
  • Save brianlong/ce96d20ebe554460edcf34abba15e40e to your computer and use it in GitHub Desktop.
Save brianlong/ce96d20ebe554460edcf34abba15e40e to your computer and use it in GitHub Desktop.
stack backtrace:
[2020-09-10T12:24:05.948229058Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-txs", "counts": 66418645, "samples": 72530000, "now": 1599740645948, "events": 1}
[2020-09-10T12:24:05.948260339Z INFO solana_metrics::counter] COUNTER:{"name": "bank-process_transactions-sigs", "counts": 75578998, "samples": 72530000, "now": 1599740645948, "events": 1}
[2020-09-10T12:24:05.949498353Z INFO solana_ledger::blockstore] slot 35012034 is full, last: 145
[2020-09-10T12:24:05.951303326Z INFO solana_ledger::blockstore] slot 35012035 is full, last: 137
[2020-09-10T12:24:05.951395939Z INFO solana_core::replay_stage] bank frozen: 35012033
[2020-09-10T12:24:05.951405651Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=35012033i fetch_entries_time=1123i fetch_entries_fail_time=0i entry_poh_verification_time=57677i entry_transaction_verification_time=9141i replay_time=479786i replay_total_elapsed=553054i total_entries=349i total_shreds=164i
[2020-09-10T12:24:05.951433807Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=0i
[2020-09-10T12:24:05.954691968Z INFO solana_runtime::bank] bank frozen: 35012033 hash: CVSAfBKLmcmTa2tH2cihrqzxiWXzaBPriZFG896ySbUL accounts_delta: 3HikmpHtpTj2DPUYXKQNgFEazqLogmeJFYvcXDjV7kVh signature_count: 290 last_blockhash: 7U5qDRBQh1JW9K4EtjQ8s1nW6BdXuFGdFsJCVqgKHx1F capitalization: 1288319183568669505
[2020-09-10T12:24:05.954717461Z INFO solana_runtime::bank] accounts hash slot: 35012033 stats: BankHashStats { num_updated_accounts: 497, num_removed_accounts: 0, num_lamports_stored: 571549340216335645, total_data_len: 907572, num_executable_accounts: 0 }
[2020-09-10T12:24:05.961874477Z INFO solana_metrics::metrics] datapoint: tower-observed slot=35012025i root=35011988i
[2020-09-10T12:24:05.975880053Z INFO solana_metrics::metrics] datapoint: best_slot slot=35012033i best_slot=35012033i
[2020-09-10T12:24:05.975905908Z INFO solana_metrics::metrics] datapoint: bank_weight slot=35012033i weight="DB41D21985694946479AE"
[2020-09-10T12:24:05.975883643Z INFO solana_core::replay_stage] 71bhKKL89U3dNHzuZVZ7KarqV6XtHEgjXjvJTsguD11B slot_weight: 35012033 16566598998264848843045294 3507437239608989785191613384626 35012032
[2020-09-10T12:24:05.975962418Z INFO solana_core::replay_stage] validator fork confirmed 35012030 964ms
[2020-09-10T12:24:05.975974512Z INFO solana_core::replay_stage] validator fork confirmed 35012029 1503ms
[2020-09-10T12:24:05.975977144Z INFO solana_metrics::metrics] datapoint: validator-confirmation duration_ms=964i
[2020-09-10T12:24:05.975980951Z INFO solana_core::replay_stage] validator fork confirmed 35012031 819ms
[2020-09-10T12:24:05.975982429Z INFO solana_metrics::metrics] datapoint: validator-confirmation duration_ms=1503i
[2020-09-10T12:24:05.975996557Z INFO solana_metrics::metrics] datapoint: validator-confirmation duration_ms=819i
[2020-09-10T12:24:05.975990787Z INFO solana_core::replay_stage] validator fork confirmed 35012028 1585ms
[2020-09-10T12:24:05.976014491Z INFO solana_metrics::metrics] datapoint: validator-confirmation duration_ms=1585i
[2020-09-10T12:24:05.976016017Z INFO solana_core::replay_stage] voting: 35012033 16566598998264848843045294
[2020-09-10T12:24:05.976840182Z INFO solana_metrics::metrics] datapoint: tower-vote latest=35012033i root=35011996i
[2020-09-10T12:24:05.978238436Z INFO solana_core::replay_stage] new root 35011996
[2020-09-10T12:24:05.989046915Z INFO solana_metrics::metrics] datapoint: block-commitment-cache aggregate-commitment-ms=10i
[2020-09-10T12:24:05.992370383Z INFO solana_core::replay_stage] vote bank: Some((35012033, NoSwitch)) reset bank: 35012033
[2020-09-10T12:24:05.992412313Z INFO solana_metrics::metrics] datapoint: blocks_produced num_blocks_on_fork=211701i num_dropped_blocks_on_fork=30536i
[2020-09-10T12:24:05.992569435Z INFO solana_core::poh_recorder] reset poh from: 536XqLbpD2Yupv3DsAeEK9yspq9LMdnDbQe5fqpFfU6J,2240770196,35012032 to: 7U5qDRBQh1JW9K4EtjQ8s1nW6BdXuFGdFsJCVqgKHx1F,35012033
[2020-09-10T12:24:05.992590676Z INFO solana_core::replay_stage] 71bhKKL89U3dNHzuZVZ7KarqV6XtHEgjXjvJTsguD11B reset PoH to tick 2240770176 (within slot 35012033). My next leader slot is 35018312
[2020-09-10T12:24:05.992619640Z INFO solana_metrics::metrics] datapoint: replay-loop-timing-stats total_elapsed_us=1263000i compute_bank_stats_elapsed=114185i select_vote_and_reset_forks_elapsed=51i start_leader_elapsed=4i reset_bank_elapsed=1950i voting_elapsed=61736i select_forks_elapsed=7i compute_slot_stats_elapsed=118i generate_new_bank_forks_elapsed=16154i replay_active_banks_elapsed=864508i reset_duplicate_slots_elapsed=3610i
[2020-09-10T12:24:05.993410015Z INFO solana_core::replay_stage] new fork:35012034 parent:35012033 root:35011996
[2020-09-10T12:24:05.994372562Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=35012034i block_height=28604465i
[2020-09-10T12:24:06.072359889Z INFO solana_core::replay_stage] bank frozen: 35012034
[2020-09-10T12:24:06.072365169Z INFO solana_metrics::metrics] datapoint: replay-slot-stats slot=35012034i fetch_entries_time=768i fetch_entries_fail_time=0i entry_poh_verification_time=42764i entry_transaction_verification_time=8365i replay_time=24668i replay_total_elapsed=76736i total_entries=313i total_shreds=146i
[2020-09-10T12:24:06.072406951Z INFO solana_metrics::metrics] datapoint: collect_rent_eagerly accounts=0i
[2020-09-10T12:24:06.078500032Z INFO solana_runtime::bank] bank frozen: 35012034 hash: 2g26Wu7MRtcXGet49CkWxkhiRnhCmwSnyUNUUV5mDAsU accounts_delta: 5PMsNQyxATo1tn75DtZ81wiFxgs9AWHWFBxW5DSjAjrz signature_count: 252 last_blockhash: JDY4Q9VcQgVVkjGGRQmYvuVqnJbJ6qNKzkYUBq6keCLE capitalization: 1288319183567409505
[2020-09-10T12:24:06.078526610Z INFO solana_runtime::bank] accounts hash slot: 35012034 stats: BankHashStats { num_updated_accounts: 448, num_removed_accounts: 0, num_lamports_stored: 960503757941320576, total_data_len: 862800, num_executable_accounts: 0 }
[2020-09-10T12:24:06.084000344Z INFO solana_metrics::metrics] datapoint: tower-observed slot=35012025i root=35011988i
[2020-09-10T12:24:06.097389508Z INFO solana_metrics::metrics] datapoint: best_slot slot=35012034i best_slot=35012034i
[2020-09-10T12:24:06.097412949Z INFO solana_metrics::metrics] datapoint: bank_weight slot=35012034i weight="BC16D0863CB7C271503F6"
[2020-09-10T12:24:06.097388170Z INFO solana_core::replay_stage] 71bhKKL89U3dNHzuZVZ7KarqV6XtHEgjXjvJTsguD11B slot_weight: 35012034 14211612046609305878987766 3507451451221036394497492372392 35012033
[2020-09-10T12:24:06.097450597Z INFO solana_core::replay_stage] voting: 35012034 14211612046609305878987766
[2020-09-10T12:24:06.098512259Z INFO solana_metrics::metrics] datapoint: tower-vote latest=35012034i root=35011997i
[2020-09-10T12:24:06.103491153Z INFO solana_core::replay_stage] new root 35011997
0: backtrace::backtrace::libunwind::trace
at ./cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/libunwind.rs:86
1: backtrace::backtrace::trace_unsynchronized
at ./cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/mod.rs:66
2: std::sys_common::backtrace::_print_fmt
at src/libstd/sys_common/backtrace.rs:78
3: <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt
at src/libstd/sys_common/backtrace.rs:59
[2020-09-10T12:24:06.114594691Z INFO solana_metrics::metrics] datapoint: block-commitment-cache aggregate-commitment-ms=10i
[2020-09-10T12:24:06.115642325Z INFO solana_metrics::metrics] datapoint: shred_fetch_tvu_forwards index_overrun=0i shred_count=1017i slot_bad_deserialize=0i index_bad_deserialize=0i index_out_of_bounds=0i slot_out_of_range=0i duplicate_shred=244i
[2020-09-10T12:24:06.121112622Z INFO solana_core::replay_stage] vote bank: Some((35012034, NoSwitch)) reset bank: 35012034
[2020-09-10T12:24:06.121150375Z INFO solana_metrics::metrics] datapoint: blocks_produced num_blocks_on_fork=211702i num_dropped_blocks_on_fork=30536i
[2020-09-10T12:24:06.121298761Z INFO solana_core::poh_recorder] reset poh from: 7kPnu8qWMRTYYQxRMVu2957jgDPnUEXWTkVbztg7DPeh,2240770191,35012033 to: JDY4Q9VcQgVVkjGGRQmYvuVqnJbJ6qNKzkYUBq6keCLE,35012034
[2020-09-10T12:24:06.121319861Z INFO solana_core::replay_stage] 71bhKKL89U3dNHzuZVZ7KarqV6XtHEgjXjvJTsguD11B reset PoH to tick 2240770240 (within slot 35012034). My next leader slot is 35018312
[2020-09-10T12:24:06.121998698Z INFO solana_core::replay_stage] new fork:35012035 parent:35012034 root:35011997
4: core::fmt::write
at src/libcore/fmt/mod.rs:1076
5: std::io::Write::write_fmt
at src/libstd/io/mod.rs:1537
6: std::sys_common::backtrace::_print
at src/libstd/sys_common/backtrace.rs:62
7: std::sys_common::backtrace::print
at src/libstd/sys_common/backtrace.rs:49
[2020-09-10T12:24:06.122851885Z INFO solana_metrics::metrics] datapoint: bank-new_from_parent-heights slot_height=35012035i block_height=28604466i
8: std::panicking::default_hook::{{closure}}
at src/libstd/panicking.rs:198
9: std::panicking::default_hook
at src/libstd/panicking.rs:218
[2020-09-10T12:24:06.140037646Z INFO solana_metrics::counter] COUNTER:{"name": "gossip_pull_request-sent_requests", "counts": 140257924, "samples": 870000, "now": 1599740646140, "events": 427}
[2020-09-10T12:24:06.140070580Z INFO solana_metrics::counter] COUNTER:{"name": "gossip_pull_request-dropped_requests", "counts": 4572429, "samples": 870000, "now": 1599740646140, "events": 0}
10: solana_metrics::metrics::set_panic_hook::{{closure}}::{{closure}}
11: std::panicking::rust_panic_with_hook
at src/libstd/panicking.rs:490
12: rust_begin_unwind
at src/libstd/panicking.rs:388
13: core::panicking::panic_fmt
at src/libcore/panicking.rs:101
14: core::option::expect_none_failed
at src/libcore/option.rs:1272
15: <tarpc::rpc::server::filter::ChannelFilter<S,K,F> as futures_core::stream::Stream>::poll_next
16: <futures_util::stream::stream::map::Map<St,F> as futures_core::stream::Stream>::poll_next
17: <futures_util::stream::stream::buffer_unordered::BufferUnordered<St> as futures_core::stream::Stream>::poll_next
18: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll
19: solana_banks_server::rpc_banks_service::start_abortable_tcp_server::{{closure}}::{{closure}}::{{closure}}
20: <futures_util::future::poll_fn::PollFn<F> as core::future::future::Future>::poll
21: <core::future::from_generator::GenFuture<T> as core::future::future::Future>::poll
22: tokio::runtime::thread_pool::ThreadPool::block_on
23: tokio::runtime::context::enter
24: tokio::runtime::Runtime::block_on
25: solana_banks_server::rpc_banks_service::RpcBanksService::run
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
[2020-09-10T12:24:06.160245547Z ERROR solana_metrics::metrics] datapoint: panic program="validator" thread="solana-rpc-banks" one=1i message="panicked at 'called `Result::unwrap()` on an `Err` value: Os { code: 107, kind: NotConnected, message: \"Transport endpoint is not connected\" }', banks-server/src/banks_server.rs:248:38" location="banks-server/src/banks_server.rs:248:38"
[2020-09-10T12:24:06.161718841Z INFO solana_metrics::metrics] submitting 376 points
[2020-09-10T12:24:06.541800503Z INFO solana_metrics::counter] COUNTER:{"name": "vote-native", "counts": 75535001, "samples": 75535000, "now": 1599740646541, "events": 1}
[2020-09-10T12:24:08.805868077Z INFO solana_validator] solana-validator 1.3.9 e45f1df5
[2020-09-10T12:24:08.805897403Z INFO solana_validator] Starting validator with: ArgsOs {
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment