gaspersic/solana
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

Adjust log level for counter metrics (#4323)

Browse Source
This commit is contained in:
Pankaj Garg
2019-05-17 07:00:06 -07:00
committed by GitHub
parent e920191de0
commit b2ce5dc9f5
14 changed files with 120 additions and 74 deletions
Download Patch File Download Diff File Expand all files Collapse all files

14
core/src/banking_stage.rs
View File

@ -15,7 +15,7 @@ use crate::service::Service;
use crate::sigverify_stage::VerifiedPackets; use crate::sigverify_stage::VerifiedPackets;
use bincode::deserialize; use bincode::deserialize;
use itertools::Itertools; use itertools::Itertools;
use solana_metrics::inc_new_counter_info; use solana_metrics::{inc_new_counter_debug, inc_new_counter_info, inc_new_counter_warn};
use solana_runtime::accounts_db::ErrorCounters; use solana_runtime::accounts_db::ErrorCounters;
use solana_runtime::bank::Bank; use solana_runtime::bank::Bank;
use solana_runtime::locked_accounts_results::LockedAccountsResults; use solana_runtime::locked_accounts_results::LockedAccountsResults;
@ -187,7 +187,7 @@ impl BankingStage {
inc_new_counter_info!("banking_stage-rebuffered_packets", rebuffered_packets); inc_new_counter_info!("banking_stage-rebuffered_packets", rebuffered_packets);
inc_new_counter_info!("banking_stage-consumed_buffered_packets", new_tx_count); inc_new_counter_info!("banking_stage-consumed_buffered_packets", new_tx_count);
inc_new_counter_info!("banking_stage-process_transactions", new_tx_count); inc_new_counter_debug!("banking_stage-process_transactions", new_tx_count);
Ok(unprocessed_packets) Ok(unprocessed_packets)
} }
@ -359,7 +359,7 @@ impl BankingStage {
debug!("processed: {} ", processed_transactions.len()); debug!("processed: {} ", processed_transactions.len());
// unlock all the accounts with errors which are filtered by the above `filter_map` // unlock all the accounts with errors which are filtered by the above `filter_map`
if !processed_transactions.is_empty() { if !processed_transactions.is_empty() {
inc_new_counter_info!( inc_new_counter_warn!(
"banking_stage-record_transactions", "banking_stage-record_transactions",
processed_transactions.len() processed_transactions.len()
); );
@ -664,7 +664,7 @@ impl BankingStage {
timing::duration_as_ms(&recv_start.elapsed()), timing::duration_as_ms(&recv_start.elapsed()),
count, count,
); );
inc_new_counter_info!("banking_stage-transactions_received", count); inc_new_counter_debug!("banking_stage-transactions_received", count);
let proc_start = Instant::now(); let proc_start = Instant::now();
let mut new_tx_count = 0; let mut new_tx_count = 0;
let mut mms_iter = mms.into_iter(); let mut mms_iter = mms.into_iter();
@ -711,7 +711,7 @@ impl BankingStage {
} }
} }
inc_new_counter_info!( inc_new_counter_debug!(
"banking_stage-time_ms", "banking_stage-time_ms",
timing::duration_as_ms(&proc_start.elapsed()) as usize timing::duration_as_ms(&proc_start.elapsed()) as usize
); );
@ -725,8 +725,8 @@ impl BankingStage {
new_tx_count, new_tx_count,
(new_tx_count as f32) / (total_time_s) (new_tx_count as f32) / (total_time_s)
); );
inc_new_counter_info!("banking_stage-process_packets", count); inc_new_counter_debug!("banking_stage-process_packets", count);
inc_new_counter_info!("banking_stage-process_transactions", new_tx_count); inc_new_counter_debug!("banking_stage-process_transactions", new_tx_count);
*recv_start = Instant::now(); *recv_start = Instant::now();

4
core/src/blocktree_processor.rs
View File

@ -3,7 +3,7 @@ use crate::blocktree::Blocktree;
use crate::entry::{Entry, EntrySlice}; use crate::entry::{Entry, EntrySlice};
use crate::leader_schedule_cache::LeaderScheduleCache; use crate::leader_schedule_cache::LeaderScheduleCache;
use rayon::prelude::*; use rayon::prelude::*;
use solana_metrics::{datapoint, inc_new_counter_info}; use solana_metrics::{datapoint, inc_new_counter_debug};
use solana_runtime::bank::Bank; use solana_runtime::bank::Bank;
use solana_runtime::locked_accounts_results::LockedAccountsResults; use solana_runtime::locked_accounts_results::LockedAccountsResults;
use solana_sdk::genesis_block::GenesisBlock; use solana_sdk::genesis_block::GenesisBlock;
@ -26,7 +26,7 @@ fn par_execute_entries(
bank: &Bank, bank: &Bank,
entries: &[(&Entry, LockedAccountsResults<Transaction>)], entries: &[(&Entry, LockedAccountsResults<Transaction>)],
) -> Result<()> { ) -> Result<()> {
inc_new_counter_info!("bank-par_execute_entries-count", entries.len()); inc_new_counter_debug!("bank-par_execute_entries-count", entries.len());
let results: Vec<Result<()>> = entries let results: Vec<Result<()>> = entries
.into_par_iter() .into_par_iter()
.map(|(e, locked_accounts)| { .map(|(e, locked_accounts)| {

11
core/src/broadcast_stage.rs
View File

@ -10,7 +10,10 @@ use crate::result::{Error, Result};
use crate::service::Service; use crate::service::Service;
use crate::staking_utils; use crate::staking_utils;
use rayon::prelude::*; use rayon::prelude::*;
use solana_metrics::{datapoint, inc_new_counter_info}; use solana_metrics::{
datapoint, inc_new_counter_debug, inc_new_counter_error, inc_new_counter_info,
inc_new_counter_warn,
};
use solana_sdk::hash::Hash; use solana_sdk::hash::Hash;
use solana_sdk::pubkey::Pubkey; use solana_sdk::pubkey::Pubkey;
use solana_sdk::timing::duration_as_ms; use solana_sdk::timing::duration_as_ms;
@ -77,7 +80,7 @@ impl Broadcast {
.unwrap() .unwrap()
.sorted_tvu_peers(staking_utils::staked_nodes_at_epoch(&bank, bank_epoch).as_ref()); .sorted_tvu_peers(staking_utils::staked_nodes_at_epoch(&bank, bank_epoch).as_ref());
inc_new_counter_info!("broadcast_service-num_peers", broadcast_table.len() + 1); inc_new_counter_warn!("broadcast_service-num_peers", broadcast_table.len() + 1);
// Layer 1, leader nodes are limited to the fanout size. // Layer 1, leader nodes are limited to the fanout size.
broadcast_table.truncate(DATA_PLANE_FANOUT); broadcast_table.truncate(DATA_PLANE_FANOUT);
@ -126,7 +129,7 @@ impl Broadcast {
// Send out data // Send out data
ClusterInfo::broadcast(&self.id, contains_last_tick, &broadcast_table, sock, &blobs)?; ClusterInfo::broadcast(&self.id, contains_last_tick, &broadcast_table, sock, &blobs)?;
inc_new_counter_info!("streamer-broadcast-sent", blobs.len()); inc_new_counter_debug!("streamer-broadcast-sent", blobs.len());
// send out erasures // send out erasures
ClusterInfo::broadcast(&self.id, false, &broadcast_table, sock, &coding)?; ClusterInfo::broadcast(&self.id, false, &broadcast_table, sock, &coding)?;
@ -198,7 +201,7 @@ impl BroadcastStage {
Error::RecvTimeoutError(RecvTimeoutError::Timeout) => (), Error::RecvTimeoutError(RecvTimeoutError::Timeout) => (),
Error::ClusterInfoError(ClusterInfoError::NoPeers) => (), // TODO: Why are the unit-tests throwing hundreds of these? Error::ClusterInfoError(ClusterInfoError::NoPeers) => (), // TODO: Why are the unit-tests throwing hundreds of these?
_ => { _ => {
inc_new_counter_info!("streamer-broadcaster-error", 1, 1); inc_new_counter_error!("streamer-broadcaster-error", 1, 1);
error!("broadcaster error: {:?}", e); error!("broadcaster error: {:?}", e);
} }
} }

54
core/src/cluster_info.rs
View File

@ -29,7 +29,7 @@ use core::cmp;
use hashbrown::HashMap; use hashbrown::HashMap;
use rand::{thread_rng, Rng}; use rand::{thread_rng, Rng};
use rayon::prelude::*; use rayon::prelude::*;
use solana_metrics::{datapoint, inc_new_counter_info}; use solana_metrics::{datapoint, inc_new_counter_debug, inc_new_counter_error};
use solana_netutil::{ use solana_netutil::{
bind_in_range, bind_to, find_available_port_in_range, multi_bind_in_range, PortRange, bind_in_range, bind_to, find_available_port_in_range, multi_bind_in_range, PortRange,
}; };
@ -661,7 +661,7 @@ impl ClusterInfo {
) -> Result<()> { ) -> Result<()> {
if broadcast_table.is_empty() { if broadcast_table.is_empty() {
debug!("{}:not enough peers in cluster_info table", id); debug!("{}:not enough peers in cluster_info table", id);
inc_new_counter_info!("cluster_info-broadcast-not_enough_peers_error", 1); inc_new_counter_error!("cluster_info-broadcast-not_enough_peers_error", 1);
Err(ClusterInfoError::NoPeers)?; Err(ClusterInfoError::NoPeers)?;
} }
@ -678,7 +678,7 @@ impl ClusterInfo {
e?; e?;
} }
inc_new_counter_info!("cluster_info-broadcast-max_idx", blobs.len()); inc_new_counter_debug!("cluster_info-broadcast-max_idx", blobs.len());
Ok(()) Ok(())
} }
@ -724,7 +724,7 @@ impl ClusterInfo {
wblob.set_forwarded(was_forwarded); wblob.set_forwarded(was_forwarded);
for e in errs { for e in errs {
if let Err(e) = &e { if let Err(e) = &e {
inc_new_counter_info!("cluster_info-retransmit-send_to_error", 1, 1); inc_new_counter_error!("cluster_info-retransmit-send_to_error", 1, 1);
error!("retransmit result {:?}", e); error!("retransmit result {:?}", e);
} }
e?; e?;
@ -1017,14 +1017,14 @@ impl ClusterInfo {
let blob = blocktree.get_data_blob(slot, blob_index); let blob = blocktree.get_data_blob(slot, blob_index);
if let Ok(Some(mut blob)) = blob { if let Ok(Some(mut blob)) = blob {
inc_new_counter_info!("cluster_info-window-request-ledger", 1); inc_new_counter_debug!("cluster_info-window-request-ledger", 1);
blob.meta.set_addr(from_addr); blob.meta.set_addr(from_addr);
return vec![Arc::new(RwLock::new(blob))]; return vec![Arc::new(RwLock::new(blob))];
} }
} }
inc_new_counter_info!("cluster_info-window-request-fail", 1); inc_new_counter_debug!("cluster_info-window-request-fail", 1);
trace!( trace!(
"{}: failed RequestWindowIndex {} {} {}", "{}: failed RequestWindowIndex {} {} {}",
me.id, me.id,
@ -1112,7 +1112,7 @@ impl ClusterInfo {
from_addr: &SocketAddr, from_addr: &SocketAddr,
) -> Vec<SharedBlob> { ) -> Vec<SharedBlob> {
let self_id = me.read().unwrap().gossip.id; let self_id = me.read().unwrap().gossip.id;
inc_new_counter_info!("cluster_info-pull_request", 1); inc_new_counter_debug!("cluster_info-pull_request", 1);
if caller.contact_info().is_none() { if caller.contact_info().is_none() {
return vec![]; return vec![];
} }
@ -1122,7 +1122,7 @@ impl ClusterInfo {
"PullRequest ignored, I'm talking to myself: me={} remoteme={}", "PullRequest ignored, I'm talking to myself: me={} remoteme={}",
self_id, from.id self_id, from.id
); );
inc_new_counter_info!("cluster_info-window-request-loopback", 1); inc_new_counter_debug!("cluster_info-window-request-loopback", 1);
return vec![]; return vec![];
} }
let now = timestamp(); let now = timestamp();
@ -1138,10 +1138,10 @@ impl ClusterInfo {
// This may or may not be correct for everybody, but it's better than leaving the remote with // This may or may not be correct for everybody, but it's better than leaving the remote with
// an unspecified address in our table // an unspecified address in our table
if from.gossip.ip().is_unspecified() { if from.gossip.ip().is_unspecified() {
inc_new_counter_info!("cluster_info-window-request-updates-unspec-gossip", 1); inc_new_counter_debug!("cluster_info-window-request-updates-unspec-gossip", 1);
from.gossip = *from_addr; from.gossip = *from_addr;
} }
inc_new_counter_info!("cluster_info-pull_request-rsp", len); inc_new_counter_debug!("cluster_info-pull_request-rsp", len);
to_shared_blob(rsp, from.gossip).ok().into_iter().collect() to_shared_blob(rsp, from.gossip).ok().into_iter().collect()
} }
fn handle_pull_response(me: &Arc<RwLock<Self>>, from: &Pubkey, data: Vec<CrdsValue>) { fn handle_pull_response(me: &Arc<RwLock<Self>>, from: &Pubkey, data: Vec<CrdsValue>) {
@ -1153,8 +1153,8 @@ impl ClusterInfo {
.unwrap() .unwrap()
.gossip .gossip
.process_pull_response(from, data, timestamp()); .process_pull_response(from, data, timestamp());
inc_new_counter_info!("cluster_info-pull_request_response", 1); inc_new_counter_debug!("cluster_info-pull_request_response", 1);
inc_new_counter_info!("cluster_info-pull_request_response-size", len); inc_new_counter_debug!("cluster_info-pull_request_response-size", len);
report_time_spent("ReceiveUpdates", &now.elapsed(), &format!(" len: {}", len)); report_time_spent("ReceiveUpdates", &now.elapsed(), &format!(" len: {}", len));
} }
@ -1164,17 +1164,17 @@ impl ClusterInfo {
data: Vec<CrdsValue>, data: Vec<CrdsValue>,
) -> Vec<SharedBlob> { ) -> Vec<SharedBlob> {
let self_id = me.read().unwrap().gossip.id; let self_id = me.read().unwrap().gossip.id;
inc_new_counter_info!("cluster_info-push_message", 1, 0, 1000); inc_new_counter_debug!("cluster_info-push_message", 1, 0, 1000);
let prunes: Vec<_> = me let prunes: Vec<_> = me
.write() .write()
.unwrap() .unwrap()
.gossip .gossip
.process_push_message(data, timestamp()); .process_push_message(data, timestamp());
if !prunes.is_empty() { if !prunes.is_empty() {
inc_new_counter_info!("cluster_info-push_message-prunes", prunes.len()); inc_new_counter_debug!("cluster_info-push_message-prunes", prunes.len());
let ci = me.read().unwrap().lookup(from).cloned(); let ci = me.read().unwrap().lookup(from).cloned();
let pushes: Vec<_> = me.write().unwrap().new_push_requests(); let pushes: Vec<_> = me.write().unwrap().new_push_requests();
inc_new_counter_info!("cluster_info-push_message-pushes", pushes.len()); inc_new_counter_debug!("cluster_info-push_message-pushes", pushes.len());
let mut rsp: Vec<_> = ci let mut rsp: Vec<_> = ci
.and_then(|ci| { .and_then(|ci| {
let mut prune_msg = PruneData { let mut prune_msg = PruneData {
@ -1231,7 +1231,7 @@ impl ClusterInfo {
"{}: Ignored received repair request from ME {}", "{}: Ignored received repair request from ME {}",
self_id, from.id, self_id, from.id,
); );
inc_new_counter_info!("cluster_info-handle-repair--eq", 1); inc_new_counter_debug!("cluster_info-handle-repair--eq", 1);
return vec![]; return vec![];
} }
@ -1245,7 +1245,7 @@ impl ClusterInfo {
let (res, label) = { let (res, label) = {
match &request { match &request {
Protocol::RequestWindowIndex(from, slot, blob_index) => { Protocol::RequestWindowIndex(from, slot, blob_index) => {
inc_new_counter_info!("cluster_info-request-window-index", 1); inc_new_counter_debug!("cluster_info-request-window-index", 1);
( (
Self::run_window_request( Self::run_window_request(
from, from,
@ -1260,7 +1260,7 @@ impl ClusterInfo {
} }
Protocol::RequestHighestWindowIndex(_, slot, highest_index) => { Protocol::RequestHighestWindowIndex(_, slot, highest_index) => {
inc_new_counter_info!("cluster_info-request-highest-window-index", 1); inc_new_counter_debug!("cluster_info-request-highest-window-index", 1);
( (
Self::run_highest_window_request( Self::run_highest_window_request(
&from_addr, &from_addr,
@ -1272,7 +1272,7 @@ impl ClusterInfo {
) )
} }
Protocol::RequestOrphan(_, slot) => { Protocol::RequestOrphan(_, slot) => {
inc_new_counter_info!("cluster_info-request-orphan", 1); inc_new_counter_debug!("cluster_info-request-orphan", 1);
( (
Self::run_orphan(&from_addr, blocktree, *slot, MAX_ORPHAN_REPAIR_RESPONSES), Self::run_orphan(&from_addr, blocktree, *slot, MAX_ORPHAN_REPAIR_RESPONSES),
"RequestOrphan", "RequestOrphan",
@ -1297,7 +1297,7 @@ impl ClusterInfo {
// TODO verify messages faster // TODO verify messages faster
Protocol::PullRequest(filter, caller) => { Protocol::PullRequest(filter, caller) => {
if !caller.verify() { if !caller.verify() {
inc_new_counter_info!("cluster_info-gossip_pull_request_verify_fail", 1); inc_new_counter_error!("cluster_info-gossip_pull_request_verify_fail", 1);
vec![] vec![]
} else { } else {
Self::handle_pull_request(me, filter, caller, from_addr) Self::handle_pull_request(me, filter, caller, from_addr)
@ -1307,7 +1307,7 @@ impl ClusterInfo {
data.retain(|v| { data.retain(|v| {
let ret = v.verify(); let ret = v.verify();
if !ret { if !ret {
inc_new_counter_info!("cluster_info-gossip_pull_response_verify_fail", 1); inc_new_counter_error!("cluster_info-gossip_pull_response_verify_fail", 1);
} }
ret ret
}); });
@ -1318,7 +1318,7 @@ impl ClusterInfo {
data.retain(|v| { data.retain(|v| {
let ret = v.verify(); let ret = v.verify();
if !ret { if !ret {
inc_new_counter_info!("cluster_info-gossip_push_msg_verify_fail", 1); inc_new_counter_error!("cluster_info-gossip_push_msg_verify_fail", 1);
} }
ret ret
}); });
@ -1326,8 +1326,8 @@ impl ClusterInfo {
} }
Protocol::PruneMessage(from, data) => { Protocol::PruneMessage(from, data) => {
if data.verify() { if data.verify() {
inc_new_counter_info!("cluster_info-prune_message", 1); inc_new_counter_debug!("cluster_info-prune_message", 1);
inc_new_counter_info!("cluster_info-prune_message-size", data.prunes.len()); inc_new_counter_debug!("cluster_info-prune_message-size", data.prunes.len());
match me.write().unwrap().gossip.process_prune_msg( match me.write().unwrap().gossip.process_prune_msg(
&from, &from,
&data.destination, &data.destination,
@ -1336,16 +1336,16 @@ impl ClusterInfo {
timestamp(), timestamp(),
) { ) {
Err(CrdsGossipError::PruneMessageTimeout) => { Err(CrdsGossipError::PruneMessageTimeout) => {
inc_new_counter_info!("cluster_info-prune_message_timeout", 1) inc_new_counter_debug!("cluster_info-prune_message_timeout", 1)
} }
Err(CrdsGossipError::BadPruneDestination) => { Err(CrdsGossipError::BadPruneDestination) => {
inc_new_counter_info!("cluster_info-bad_prune_destination", 1) inc_new_counter_debug!("cluster_info-bad_prune_destination", 1)
} }
Err(_) => (), Err(_) => (),
Ok(_) => (), Ok(_) => (),
} }
} else { } else {
inc_new_counter_info!("cluster_info-gossip_prune_msg_verify_fail", 1); inc_new_counter_debug!("cluster_info-gossip_prune_msg_verify_fail", 1);
} }
vec![] vec![]
} }

4
core/src/cluster_info_vote_listener.rs
View File

@ -4,7 +4,7 @@ use crate::result::Result;
use crate::service::Service; use crate::service::Service;
use crate::sigverify_stage::VerifiedPackets; use crate::sigverify_stage::VerifiedPackets;
use crate::{packet, sigverify}; use crate::{packet, sigverify};
use solana_metrics::inc_new_counter_info; use solana_metrics::inc_new_counter_debug;
use std::sync::atomic::{AtomicBool, Ordering}; use std::sync::atomic::{AtomicBool, Ordering};
use std::sync::mpsc::Sender; use std::sync::mpsc::Sender;
use std::sync::{Arc, Mutex, RwLock}; use std::sync::{Arc, Mutex, RwLock};
@ -56,7 +56,7 @@ impl ClusterInfoVoteListener {
let (votes, new_ts) = cluster_info.read().unwrap().get_votes(last_ts); let (votes, new_ts) = cluster_info.read().unwrap().get_votes(last_ts);
if poh_recorder.lock().unwrap().bank().is_some() { if poh_recorder.lock().unwrap().bank().is_some() {
last_ts = new_ts; last_ts = new_ts;
inc_new_counter_info!("cluster_info_vote_listener-recv_count", votes.len()); inc_new_counter_debug!("cluster_info_vote_listener-recv_count", votes.len());
let msgs = packet::to_packets(&votes); let msgs = packet::to_packets(&votes);
if !msgs.is_empty() { if !msgs.is_empty() {
let r = if sigverify_disabled { let r = if sigverify_disabled {

4
core/src/fetch_stage.rs
View File

@ -4,7 +4,7 @@ use crate::poh_recorder::PohRecorder;
use crate::result::{Error, Result}; use crate::result::{Error, Result};
use crate::service::Service; use crate::service::Service;
use crate::streamer::{self, PacketReceiver, PacketSender}; use crate::streamer::{self, PacketReceiver, PacketSender};
use solana_metrics::inc_new_counter_info; use solana_metrics::{inc_new_counter_debug, inc_new_counter_info};
use solana_sdk::timing::DEFAULT_TICKS_PER_SLOT; use solana_sdk::timing::DEFAULT_TICKS_PER_SLOT;
use std::net::UdpSocket; use std::net::UdpSocket;
use std::sync::atomic::AtomicBool; use std::sync::atomic::AtomicBool;
@ -66,7 +66,7 @@ impl FetchStage {
.unwrap() .unwrap()
.would_be_leader(DEFAULT_TICKS_PER_SLOT * 2) .would_be_leader(DEFAULT_TICKS_PER_SLOT * 2)
{ {
inc_new_counter_info!("fetch_stage-honor_forwards", len); inc_new_counter_debug!("fetch_stage-honor_forwards", len);
for packets in batch { for packets in batch {
if sendr.send(packets).is_err() { if sendr.send(packets).is_err() {
return Err(Error::SendError); return Err(Error::SendError);

4
core/src/packet.rs
View File

@ -4,7 +4,7 @@ use crate::result::{Error, Result};
use bincode; use bincode;
use byteorder::{ByteOrder, LittleEndian}; use byteorder::{ByteOrder, LittleEndian};
use serde::Serialize; use serde::Serialize;
use solana_metrics::inc_new_counter_info; use solana_metrics::inc_new_counter_debug;
use solana_sdk::hash::Hash; use solana_sdk::hash::Hash;
pub use solana_sdk::packet::PACKET_DATA_SIZE; pub use solana_sdk::packet::PACKET_DATA_SIZE;
use solana_sdk::pubkey::Pubkey; use solana_sdk::pubkey::Pubkey;
@ -245,7 +245,7 @@ impl Packets {
} }
} }
self.packets.truncate(i); self.packets.truncate(i);
inc_new_counter_info!("packets-recv_count", i); inc_new_counter_debug!("packets-recv_count", i);
Ok(i) Ok(i)
} }

4
core/src/replay_stage.rs
View File

@ -14,7 +14,7 @@ use crate::result::{Error, Result};
use crate::rpc_subscriptions::RpcSubscriptions; use crate::rpc_subscriptions::RpcSubscriptions;
use crate::service::Service; use crate::service::Service;
use hashbrown::HashMap; use hashbrown::HashMap;
use solana_metrics::{datapoint, inc_new_counter_info}; use solana_metrics::{datapoint, inc_new_counter_error, inc_new_counter_info};
use solana_runtime::bank::Bank; use solana_runtime::bank::Bank;
use solana_sdk::hash::Hash; use solana_sdk::hash::Hash;
use solana_sdk::pubkey::Pubkey; use solana_sdk::pubkey::Pubkey;
@ -286,7 +286,7 @@ impl ReplayStage {
} else { } else {
info!("debug to verify entries {}", len); info!("debug to verify entries {}", len);
//TODO: mark this fork as failed //TODO: mark this fork as failed
inc_new_counter_info!("replicate-stage_failed_process_entries", len); inc_new_counter_error!("replicate-stage_failed_process_entries", len);
} }
Ok(()) Ok(())
} }

4
core/src/retransmit_stage.rs
View File

@ -10,7 +10,7 @@ use crate::service::Service;
use crate::staking_utils; use crate::staking_utils;
use crate::streamer::BlobReceiver; use crate::streamer::BlobReceiver;
use crate::window_service::{should_retransmit_and_persist, WindowService}; use crate::window_service::{should_retransmit_and_persist, WindowService};
use solana_metrics::{datapoint, inc_new_counter_info}; use solana_metrics::{datapoint, inc_new_counter_error};
use solana_runtime::epoch_schedule::EpochSchedule; use solana_runtime::epoch_schedule::EpochSchedule;
use solana_sdk::hash::Hash; use solana_sdk::hash::Hash;
use std::net::UdpSocket; use std::net::UdpSocket;
@ -89,7 +89,7 @@ fn retransmitter(
Error::RecvTimeoutError(RecvTimeoutError::Disconnected) => break, Error::RecvTimeoutError(RecvTimeoutError::Disconnected) => break,
Error::RecvTimeoutError(RecvTimeoutError::Timeout) => (), Error::RecvTimeoutError(RecvTimeoutError::Timeout) => (),
_ => { _ => {
inc_new_counter_info!("streamer-retransmit-error", 1, 1); inc_new_counter_error!("streamer-retransmit-error", 1, 1);
} }
} }
} }

8
core/src/sigverify.rs
View File

@ -6,7 +6,7 @@
use crate::packet::{Packet, Packets}; use crate::packet::{Packet, Packets};
use crate::result::Result; use crate::result::Result;
use solana_metrics::inc_new_counter_info; use solana_metrics::inc_new_counter_debug;
use solana_sdk::pubkey::Pubkey; use solana_sdk::pubkey::Pubkey;
use solana_sdk::short_vec::decode_len; use solana_sdk::short_vec::decode_len;
use solana_sdk::signature::Signature; use solana_sdk::signature::Signature;
@ -178,7 +178,7 @@ pub fn ed25519_verify_cpu(batches: &[Packets]) -> Vec<Vec<u8>> {
.into_par_iter() .into_par_iter()
.map(|p| p.packets.par_iter().map(verify_packet).collect()) .map(|p| p.packets.par_iter().map(verify_packet).collect())
.collect(); .collect();
inc_new_counter_info!("ed25519_verify_cpu", count); inc_new_counter_debug!("ed25519_verify_cpu", count);
rv rv
} }
@ -190,7 +190,7 @@ pub fn ed25519_verify_disabled(batches: &[Packets]) -> Vec<Vec<u8>> {
.into_par_iter() .into_par_iter()
.map(|p| vec![1u8; p.packets.len()]) .map(|p| vec![1u8; p.packets.len()])
.collect(); .collect();
inc_new_counter_info!("ed25519_verify_disabled", count); inc_new_counter_debug!("ed25519_verify_disabled", count);
rv rv
} }
@ -279,7 +279,7 @@ pub fn ed25519_verify(batches: &[Packets]) -> Vec<Vec<u8>> {
} }
} }
} }
inc_new_counter_info!("ed25519_verify_gpu", count); inc_new_counter_debug!("ed25519_verify_gpu", count);
rvs rvs
} }

14
core/src/window_service.rs
View File

@ -9,7 +9,7 @@ use crate::repair_service::{RepairService, RepairStrategy};
use crate::result::{Error, Result}; use crate::result::{Error, Result};
use crate::service::Service; use crate::service::Service;
use crate::streamer::{BlobReceiver, BlobSender}; use crate::streamer::{BlobReceiver, BlobSender};
use solana_metrics::inc_new_counter_info; use solana_metrics::{inc_new_counter_debug, inc_new_counter_error};
use solana_runtime::bank::Bank; use solana_runtime::bank::Bank;
use solana_sdk::hash::Hash; use solana_sdk::hash::Hash;
use solana_sdk::pubkey::Pubkey; use solana_sdk::pubkey::Pubkey;
@ -34,7 +34,7 @@ fn retransmit_blobs(blobs: &[SharedBlob], retransmit: &BlobSender, id: &Pubkey)
} }
if !retransmit_queue.is_empty() { if !retransmit_queue.is_empty() {
inc_new_counter_info!( inc_new_counter_debug!(
"streamer-recv_window-retransmit", "streamer-recv_window-retransmit",
retransmit_queue.len(), retransmit_queue.len(),
0, 0,
@ -88,13 +88,13 @@ pub fn should_retransmit_and_persist(
}; };
if blob.id() == *my_id { if blob.id() == *my_id {
inc_new_counter_info!("streamer-recv_window-circular_transmission", 1); inc_new_counter_debug!("streamer-recv_window-circular_transmission", 1);
false false
} else if slot_leader_id == None { } else if slot_leader_id == None {
inc_new_counter_info!("streamer-recv_window-unknown_leader", 1); inc_new_counter_debug!("streamer-recv_window-unknown_leader", 1);
true true
} else if slot_leader_id != Some(blob.id()) { } else if slot_leader_id != Some(blob.id()) {
inc_new_counter_info!("streamer-recv_window-wrong_leader", 1); inc_new_counter_debug!("streamer-recv_window-wrong_leader", 1);
false false
} else { } else {
true true
@ -119,7 +119,7 @@ where
blobs.append(&mut blob) blobs.append(&mut blob)
} }
let now = Instant::now(); let now = Instant::now();
inc_new_counter_info!("streamer-recv_window-recv", blobs.len(), 0, 1000); inc_new_counter_debug!("streamer-recv_window-recv", blobs.len(), 0, 1000);
blobs.retain(|blob| { blobs.retain(|blob| {
blob_filter(&blob.read().unwrap()) blob_filter(&blob.read().unwrap())
@ -223,7 +223,7 @@ impl WindowService {
Error::RecvTimeoutError(RecvTimeoutError::Disconnected) => break, Error::RecvTimeoutError(RecvTimeoutError::Disconnected) => break,
Error::RecvTimeoutError(RecvTimeoutError::Timeout) => (), Error::RecvTimeoutError(RecvTimeoutError::Timeout) => (),
_ => { _ => {
inc_new_counter_info!("streamer-window-error", 1, 1); inc_new_counter_error!("streamer-window-error", 1, 1);
error!("window error: {:?}", e); error!("window error: {:?}", e);
} }
} }

39
metrics/src/counter.rs
View File

@ -63,6 +63,32 @@ macro_rules! inc_new_counter {
}}; }};
} }
#[macro_export]
macro_rules! inc_new_counter_error {
($name:expr, $count:expr) => {{
inc_new_counter!($name, $count, log::Level::Error, 0, 0);
}};
($name:expr, $count:expr, $lograte:expr) => {{
inc_new_counter!($name, $count, log::Level::Error, $lograte, 0);
}};
($name:expr, $count:expr, $lograte:expr, $metricsrate:expr) => {{
inc_new_counter!($name, $count, log::Level::Error, $lograte, $metricsrate);
}};
}
#[macro_export]
macro_rules! inc_new_counter_warn {
($name:expr, $count:expr) => {{
inc_new_counter!($name, $count, log::Level::Warn, 0, 0);
}};
($name:expr, $count:expr, $lograte:expr) => {{
inc_new_counter!($name, $count, log::Level::Warn, $lograte, 0);
}};
($name:expr, $count:expr, $lograte:expr, $metricsrate:expr) => {{
inc_new_counter!($name, $count, log::Level::Warn, $lograte, $metricsrate);
}};
}
#[macro_export] #[macro_export]
macro_rules! inc_new_counter_info { macro_rules! inc_new_counter_info {
($name:expr, $count:expr) => {{ ($name:expr, $count:expr) => {{
@ -76,6 +102,19 @@ macro_rules! inc_new_counter_info {
}}; }};
} }
#[macro_export]
macro_rules! inc_new_counter_debug {
($name:expr, $count:expr) => {{
inc_new_counter!($name, $count, log::Level::Debug, 0, 0);
}};
($name:expr, $count:expr, $lograte:expr) => {{
inc_new_counter!($name, $count, log::Level::Debug, $lograte, 0);
}};
($name:expr, $count:expr, $lograte:expr, $metricsrate:expr) => {{
inc_new_counter!($name, $count, log::Level::Debug, $lograte, $metricsrate);
}};
}
impl Counter { impl Counter {
fn default_log_rate() -> usize { fn default_log_rate() -> usize {
let v = env::var("SOLANA_DEFAULT_LOG_RATE") let v = env::var("SOLANA_DEFAULT_LOG_RATE")

8
runtime/src/accounts.rs
View File

@ -8,7 +8,7 @@ use crate::message_processor::has_duplicates;
use bincode::serialize; use bincode::serialize;
use hashbrown::{HashMap, HashSet}; use hashbrown::{HashMap, HashSet};
use log::*; use log::*;
use solana_metrics::inc_new_counter_info; use solana_metrics::inc_new_counter_error;
use solana_sdk::account::Account; use solana_sdk::account::Account;
use solana_sdk::fee_calculator::FeeCalculator; use solana_sdk::fee_calculator::FeeCalculator;
use solana_sdk::hash::{Hash, Hasher}; use solana_sdk::hash::{Hash, Hasher};
@ -477,9 +477,11 @@ impl Accounts {
}) })
.collect(); .collect();
if error_counters.account_in_use != 0 { if error_counters.account_in_use != 0 {
inc_new_counter_info!( inc_new_counter_error!(
"bank-process_transactions-account_in_use", "bank-process_transactions-account_in_use",
error_counters.account_in_use error_counters.account_in_use,
0,
100
); );
} }
rv rv

22
runtime/src/bank.rs
View File

@ -14,7 +14,9 @@ use crate::status_cache::StatusCache;
use bincode::serialize; use bincode::serialize;
use hashbrown::HashMap; use hashbrown::HashMap;
use log::*; use log::*;
use solana_metrics::{datapoint, inc_new_counter_info}; use solana_metrics::{
datapoint, inc_new_counter_debug, inc_new_counter_error, inc_new_counter_info,
};
use solana_sdk::account::Account; use solana_sdk::account::Account;
use solana_sdk::fee_calculator::FeeCalculator; use solana_sdk::fee_calculator::FeeCalculator;
use solana_sdk::genesis_block::GenesisBlock; use solana_sdk::genesis_block::GenesisBlock;
@ -385,7 +387,7 @@ impl Bank {
self.tick_height.fetch_add(1, Ordering::SeqCst); self.tick_height.fetch_add(1, Ordering::SeqCst);
self.tick_height.load(Ordering::SeqCst) as u64 self.tick_height.load(Ordering::SeqCst) as u64
}; };
inc_new_counter_info!("bank-register_tick-registered", 1); inc_new_counter_debug!("bank-register_tick-registered", 1);
// Register a new block hash if at the last tick in the slot // Register a new block hash if at the last tick in the slot
if current_tick_height % self.ticks_per_slot == self.ticks_per_slot - 1 { if current_tick_height % self.ticks_per_slot == self.ticks_per_slot - 1 {
@ -603,20 +605,20 @@ impl Bank {
} }
if err_count > 0 { if err_count > 0 {
debug!("{} errors of {} txs", err_count, err_count + tx_count); debug!("{} errors of {} txs", err_count, err_count + tx_count);
inc_new_counter_info!( inc_new_counter_error!(
"bank-process_transactions-account_not_found", "bank-process_transactions-account_not_found",
error_counters.account_not_found, error_counters.account_not_found,
0, 0,
1000 1000
); );
inc_new_counter_info!("bank-process_transactions-error_count", err_count, 0, 1000); inc_new_counter_error!("bank-process_transactions-error_count", err_count, 0, 1000);
} }
self.increment_transaction_count(tx_count); self.increment_transaction_count(tx_count);
inc_new_counter_info!("bank-process_transactions-txs", tx_count, 0, 1000); inc_new_counter_info!("bank-process_transactions-txs", tx_count, 0, 1000);
if 0 != error_counters.blockhash_not_found { if 0 != error_counters.blockhash_not_found {
inc_new_counter_info!( inc_new_counter_error!(
"bank-process_transactions-error-blockhash_not_found", "bank-process_transactions-error-blockhash_not_found",
error_counters.blockhash_not_found, error_counters.blockhash_not_found,
0, 0,
@ -624,7 +626,7 @@ impl Bank {
); );
} }
if 0 != error_counters.invalid_account_index { if 0 != error_counters.invalid_account_index {
inc_new_counter_info!( inc_new_counter_error!(
"bank-process_transactions-error-invalid_account_index", "bank-process_transactions-error-invalid_account_index",
error_counters.invalid_account_index, error_counters.invalid_account_index,
0, 0,
@ -632,7 +634,7 @@ impl Bank {
); );
} }
if 0 != error_counters.reserve_blockhash { if 0 != error_counters.reserve_blockhash {
inc_new_counter_info!( inc_new_counter_error!(
"bank-process_transactions-error-reserve_blockhash", "bank-process_transactions-error-reserve_blockhash",
error_counters.reserve_blockhash, error_counters.reserve_blockhash,
0, 0,
@ -640,7 +642,7 @@ impl Bank {
); );
} }
if 0 != error_counters.duplicate_signature { if 0 != error_counters.duplicate_signature {
inc_new_counter_info!( inc_new_counter_error!(
"bank-process_transactions-error-duplicate_signature", "bank-process_transactions-error-duplicate_signature",
error_counters.duplicate_signature, error_counters.duplicate_signature,
0, 0,
@ -648,7 +650,7 @@ impl Bank {
); );
} }
if 0 != error_counters.insufficient_funds { if 0 != error_counters.insufficient_funds {
inc_new_counter_info!( inc_new_counter_error!(
"bank-process_transactions-error-insufficient_funds", "bank-process_transactions-error-insufficient_funds",
error_counters.insufficient_funds, error_counters.insufficient_funds,
0, 0,
@ -656,7 +658,7 @@ impl Bank {
); );
} }
if 0 != error_counters.account_loaded_twice { if 0 != error_counters.account_loaded_twice {
inc_new_counter_info!( inc_new_counter_error!(
"bank-process_transactions-account_loaded_twice", "bank-process_transactions-account_loaded_twice",
error_counters.account_loaded_twice, error_counters.account_loaded_twice,
0, 0,