// Copyright (C) Parity Technologies (UK) Ltd. and Dijital Kurdistan Tech Institute // This file is part of Pezkuwi. // Pezkuwi is free software: you can redistribute it and/or modify // it under the terms of the GNU General Public License as published by // the Free Software Foundation, either version 3 of the License, or // (at your option) any later version. // Pezkuwi is distributed in the hope that it will be useful, // but WITHOUT ANY WARRANTY; without even the implied warranty of // MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the // GNU General Public License for more details. // You should have received a copy of the GNU General Public License // along with Pezkuwi. If not, see . #![deny(unused_crate_dependencies)] #![deny(missing_docs)] #![deny(clippy::dbg_macro)] //! A wrapper around `tracing` macros, to provide semi automatic //! `traceID` annotation without codebase turnover. //! //! # Usage //! //! The API follows the [`tracing` //! API](https://docs.rs/tracing/latest/tracing/index.html), but the docs contain //! more detail than you probably need to know, so here's the quick version. //! //! Most common usage is of the form: //! //! ```rs //! gum::warn!( //! target: LOG_TARGET, //! worker_pid = %idle_worker.pid, //! ?error, //! "failed to send a handshake to the spawned worker", //! ); //! ``` //! //! ### Log levels //! //! All of the [`tracing` macros](https://docs.rs/tracing/latest/tracing/index.html#macros) are available. //! In decreasing order of priority they are: //! //! - `error!` //! - `warn!` //! - `info!` //! - `debug!` //! - `trace!` //! //! ### `target` //! //! The `LOG_TARGET` should be defined once per crate, e.g.: //! //! ```rs //! const LOG_TARGET: &str = "teyrchain::pvf"; //! ``` //! //! This should be of the form `::`, where the `::` is optional. //! //! The target and subtarget are used when debugging by specializing the Grafana Loki query to //! filter specific subsystem logs. The more specific the query is the better when approaching the //! query response limit. //! //! ### Fields //! //! Here's the rundown on how fields work: //! //! - Fields on spans and events are specified using the `syntax field_name = field_value`. //! - Local variables may be used as field values without an assignment, similar to struct //! initializers. //! - The `?` sigil is shorthand that specifies a field should be recorded using its `fmt::Debug` //! implementation. //! - The `%` sigil operates similarly, but indicates that the value should be recorded using its //! `fmt::Display` implementation. //! //! For full details, again see [the tracing //! docs](https://docs.rs/tracing/latest/tracing/index.html#recording-fields). //! //! ### Viewing traces //! //! When testing, //! //! ```rs //! pezsp_tracing::init_for_tests(); //! ``` //! //! should enable all trace logs. //! //! Alternatively, you can do: //! //! ```rs //! pezsp_tracing::try_init_simple(); //! ``` //! //! On the command line you specify `RUST_LOG` with the desired target and trace level: //! //! ```sh //! RUST_LOG=teyrchain::pvf=trace cargo test //! ``` //! //! On the other hand if you want all `teyrchain` logs, specify `teyrchain=trace`, which will also //! include logs from `teyrchain::pvf` and other subtargets. pub use tracing::{enabled, event, Level}; // jaeger dependency /// Alias for the 16 byte unique identifier used with jaeger. pub(crate) type TraceIdentifier = u128; /// A helper to convert the hash to the fixed size representation /// needed for jaeger. #[inline] pub fn hash_to_trace_identifier(hash: Hash) -> TraceIdentifier { let mut buf = [0u8; 16]; buf.copy_from_slice(&hash.as_ref()[0..16]); // The slice bytes are copied in reading order, so if interpreted // in string form by a human, that means lower indices have higher // values and hence corresponds to BIG endian ordering of the individual // bytes. u128::from_be_bytes(buf) as TraceIdentifier } #[doc(hidden)] pub use pezkuwi_primitives::{CandidateHash, Hash}; pub use gum_proc_macro::{debug, error, info, trace, warn, warn_if_frequent}; #[cfg(test)] mod tests; const FREQ_SMOOTHING_FACTOR: f32 = 0.5; /// Exponential moving average #[derive(Debug, Default)] struct EmaBucket { current: f32, count: u32, } impl EmaBucket { fn update(&mut self, value: f32, alpha: f32) { if self.count == 0 { self.current = value; } else { self.current += alpha * (value - self.current); } self.count += 1; } } /// Utility struct to compare the rate of its own calls. pub struct Freq { ema: EmaBucket, last: u64, } impl Freq { /// Initiates a new instance pub fn new() -> Self { Self { ema: Default::default(), last: Default::default() } } /// Compares the rate of its own calls with the passed one. pub fn is_frequent(&mut self, max_rate: Times) -> bool { self.record(); // Two attempts is not enough to call something as frequent. if self.ema.count < 3 { return false; } let rate = 1000.0 / self.ema.current; // Current EMA represents interval in ms rate > max_rate.into() } fn record(&mut self) { let now = coarsetime::Clock::now_since_epoch().as_millis() as u64; if self.last > 0 { self.ema.update((now - self.last) as f32, FREQ_SMOOTHING_FACTOR); } self.last = now; } } /// Represents frequency per second, minute, hour and day pub enum Times { /// Per second PerSecond(u32), /// Per minute PerMinute(u32), /// Per hour PerHour(u32), /// Per day PerDay(u32), } impl From for f32 { fn from(value: Times) -> Self { match value { Times::PerSecond(v) => v as f32, Times::PerMinute(v) => v as f32 / 60.0, Times::PerHour(v) => v as f32 / (60.0 * 60.0), Times::PerDay(v) => v as f32 / (60.0 * 60.0 * 24.0), } } }