From 790e7a0e1e101dd86d165d0df58f416f41731a52 Mon Sep 17 00:00:00 2001 From: Drazen Urch Date: Wed, 5 Apr 2023 12:29:41 +0200 Subject: [PATCH] Sphinx packet processing CPU cycles measurement (#3247) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * POC measurement * parent ce76790761ad45a878ad430de54e6ca347f0ca44 author durch 1680116778 +0200 committer durch 1680683399 +0200 Instrument packet processing * Cleanup and format * Feature gate tracing * Add .gitkeep to wallet dist * Squashed commit of the following: commit 0b1b6947e8114b4887b7f8e53ae996fd6cf2b8f2 Author: Jon Häggblad Date: Wed Apr 5 11:28:28 2023 +0200 Replace mobile flag with target_os = android (#3278) * Remove old lock file * Start replacing mobile with android * Regex replace all mobile with android * Remove the mobile feature flag * keep the cfg mobile in tauri commit c79b2cfb786907511ae7160a5c22be694216f8af Author: Jon Häggblad Date: Wed Apr 5 11:27:38 2023 +0200 Service provider directory contract (#3220) * first commit of service provider directory contract proof of concept * *added config set on instantiation, *removed greetQuery test function * commit before mapping change * *changed mapping of service to use client address instead of cosmos addr * commit before mapping change * added acl to delete() * added test for acl in delete() * changed whitelist to standrd_whitelist bool in Service struct * removed old comments and commented out code * rustfmt * wup * wup * Older version of cw-multi-test that works with 1.0.0 * wip * Remove .gitignore * Basic tests for announce and query now works * Restore tests for delete as well * Consolidate tests * Tidy * fmt * Start reworking test helpers * Tidy tests * More test work * More test improvements * More work on tests * Tweaks * Further tests * rustfmt * Add some comments * Initial work on requiring deposit * wip * Work on updating tests for handling funds * Start updating integration tests * Integration tests updated * merge test mods in state * Address review comments * Enable wasm-opt * Unify Result type * consistent amount in error type * WIP: paging output * IndexedMap working * extract to config file * WIP: middle of extracting out types * Extract types * wip * Types now extracted out: * Paged response type too * rustfmt * Start working on switching to cw Admin * Complete switch to Admin * Remove owner from announce msg * remove unused imports * Assert owner * Extract out types to common crate * Fix test compilation * Add query by owner and nym address * Move msg to common crate * rustfmt * tests for service id * service storage tests * state services tests * function rename * tidy * Fix clippy warning * User ServiceId instead and not u32 * Delete by nym address * Emit explicit events * Swap ToString for Display * Move all storage keys to constants.rs * clippy * Test for deleting by name * Tidy integration tests * Remove to_string * Some comments to tests * Integration test for paging * serde snake_csae for NymAddress and ServiceType * Add migrate entry point * Add query contract version * A few more asserts for balance * Make MigrateMsg a struct --------- Co-authored-by: mx commit dd699bce9aaac0ea1a1f3e55c3fad7069f58634f Merge: 5ce017ef3 e6957e7a9 Author: Tommy Verrall <60836166+tommyv1987@users.noreply.github.com> Date: Wed Apr 5 10:18:16 2023 +0100 Merge pull request #3235 from nymtech/feature/performance-active-set-selection Feature/performance active set selection commit 5ce017ef3d2f0eed1c1a4e89bc8458b796fcc687 Author: benedetta davico <46782255+benedettadavico@users.noreply.github.com> Date: Wed Apr 5 10:57:45 2023 +0200 adding vesting tests (#3279) commit 59c1ce26396f05245496ddde0a8de09a2ad00e97 Merge: 4fb63d889 276edfd56 Author: Tommy Verrall <60836166+tommyv1987@users.noreply.github.com> Date: Wed Apr 5 09:50:53 2023 +0100 Merge pull request #3261 from nymtech/feature/refresh-allow-list Feature/refresh allow list commit 4fb63d8892d8dfba0e8d8eb79361283c00009fde Author: Jędrzej Stuczyński Date: Wed Apr 5 09:22:43 2023 +0100 Feature/vesting delegation amount query (#3229) * moved queries and transactions out of contract.rs * added queries for vesting delegation details * nyxd_client support commit 276edfd562251db4b6c600a55210e7b950ccdfd3 Author: Jędrzej Stuczyński Date: Fri Mar 31 15:56:21 2023 +0100 clippy commit 605f8fcde3b02de1fbf0c52f28d88476d0a989ee Author: Jędrzej Stuczyński Date: Fri Mar 31 15:06:12 2023 +0100 updated and cleaned up tests commit f0e4d1a7cf57ea23ae8e236a7ce1908572c92f9f Author: Jędrzej Stuczyński Date: Fri Mar 31 14:01:36 2023 +0100 configurable stored lists locations commit 055ec4bdd5f141dc0ddc393750434096abec4669 Author: Jędrzej Stuczyński Date: Fri Mar 31 12:57:02 2023 +0100 updating stored allow list on file changes commit 5761f9ac7fe07d46c6499bccae69c6231f2cf671 Author: Jędrzej Stuczyński Date: Fri Mar 31 12:15:45 2023 +0100 file watcher commit 32620fd55fe8304c56ae774c61510b2e204b4192 Author: Jędrzej Stuczyński Date: Thu Mar 30 17:47:12 2023 +0100 updating standard list in a timer commit abb5cdbe065a3c078055b6c1920b4b13aa5ded51 Author: Jędrzej Stuczyński Date: Thu Mar 30 16:43:58 2023 +0100 extracted domain and ipnet information to separate struct commit e6957e7a994114bc848bc5a4d9d9a9194cb5e9c7 Author: Jędrzej Stuczyński Date: Tue Mar 28 11:25:43 2023 +0100 use combination of stake and performance for rewarded set selection commit de2406a2c728d289c9124235e64f81e795f81fc7 Author: Jędrzej Stuczyński Date: Tue Mar 28 10:54:14 2023 +0100 Moved MixnodeWithPerformance to helpers * Squashed commit of the following: commit 0b1b6947e8114b4887b7f8e53ae996fd6cf2b8f2 Author: Jon Häggblad Date: Wed Apr 5 11:28:28 2023 +0200 Replace mobile flag with target_os = android (#3278) * Remove old lock file * Start replacing mobile with android * Regex replace all mobile with android * Remove the mobile feature flag * keep the cfg mobile in tauri commit c79b2cfb786907511ae7160a5c22be694216f8af Author: Jon Häggblad Date: Wed Apr 5 11:27:38 2023 +0200 Service provider directory contract (#3220) * first commit of service provider directory contract proof of concept * *added config set on instantiation, *removed greetQuery test function * commit before mapping change * *changed mapping of service to use client address instead of cosmos addr * commit before mapping change * added acl to delete() * added test for acl in delete() * changed whitelist to standrd_whitelist bool in Service struct * removed old comments and commented out code * rustfmt * wup * wup * Older version of cw-multi-test that works with 1.0.0 * wip * Remove .gitignore * Basic tests for announce and query now works * Restore tests for delete as well * Consolidate tests * Tidy * fmt * Start reworking test helpers * Tidy tests * More test work * More test improvements * More work on tests * Tweaks * Further tests * rustfmt * Add some comments * Initial work on requiring deposit * wip * Work on updating tests for handling funds * Start updating integration tests * Integration tests updated * merge test mods in state * Address review comments * Enable wasm-opt * Unify Result type * consistent amount in error type * WIP: paging output * IndexedMap working * extract to config file * WIP: middle of extracting out types * Extract types * wip * Types now extracted out: * Paged response type too * rustfmt * Start working on switching to cw Admin * Complete switch to Admin * Remove owner from announce msg * remove unused imports * Assert owner * Extract out types to common crate * Fix test compilation * Add query by owner and nym address * Move msg to common crate * rustfmt * tests for service id * service storage tests * state services tests * function rename * tidy * Fix clippy warning * User ServiceId instead and not u32 * Delete by nym address * Emit explicit events * Swap ToString for Display * Move all storage keys to constants.rs * clippy * Test for deleting by name * Tidy integration tests * Remove to_string * Some comments to tests * Integration test for paging * serde snake_csae for NymAddress and ServiceType * Add migrate entry point * Add query contract version * A few more asserts for balance * Make MigrateMsg a struct --------- Co-authored-by: mx commit dd699bce9aaac0ea1a1f3e55c3fad7069f58634f Merge: 5ce017ef3 e6957e7a9 Author: Tommy Verrall <60836166+tommyv1987@users.noreply.github.com> Date: Wed Apr 5 10:18:16 2023 +0100 Merge pull request #3235 from nymtech/feature/performance-active-set-selection Feature/performance active set selection commit 5ce017ef3d2f0eed1c1a4e89bc8458b796fcc687 Author: benedetta davico <46782255+benedettadavico@users.noreply.github.com> Date: Wed Apr 5 10:57:45 2023 +0200 adding vesting tests (#3279) commit 59c1ce26396f05245496ddde0a8de09a2ad00e97 Merge: 4fb63d889 276edfd56 Author: Tommy Verrall <60836166+tommyv1987@users.noreply.github.com> Date: Wed Apr 5 09:50:53 2023 +0100 Merge pull request #3261 from nymtech/feature/refresh-allow-list Feature/refresh allow list commit 4fb63d8892d8dfba0e8d8eb79361283c00009fde Author: Jędrzej Stuczyński Date: Wed Apr 5 09:22:43 2023 +0100 Feature/vesting delegation amount query (#3229) * moved queries and transactions out of contract.rs * added queries for vesting delegation details * nyxd_client support commit 276edfd562251db4b6c600a55210e7b950ccdfd3 Author: Jędrzej Stuczyński Date: Fri Mar 31 15:56:21 2023 +0100 clippy commit 605f8fcde3b02de1fbf0c52f28d88476d0a989ee Author: Jędrzej Stuczyński Date: Fri Mar 31 15:06:12 2023 +0100 updated and cleaned up tests commit f0e4d1a7cf57ea23ae8e236a7ce1908572c92f9f Author: Jędrzej Stuczyński Date: Fri Mar 31 14:01:36 2023 +0100 configurable stored lists locations commit 055ec4bdd5f141dc0ddc393750434096abec4669 Author: Jędrzej Stuczyński Date: Fri Mar 31 12:57:02 2023 +0100 updating stored allow list on file changes commit 5761f9ac7fe07d46c6499bccae69c6231f2cf671 Author: Jędrzej Stuczyński Date: Fri Mar 31 12:15:45 2023 +0100 file watcher commit 32620fd55fe8304c56ae774c61510b2e204b4192 Author: Jędrzej Stuczyński Date: Thu Mar 30 17:47:12 2023 +0100 updating standard list in a timer commit abb5cdbe065a3c078055b6c1920b4b13aa5ded51 Author: Jędrzej Stuczyński Date: Thu Mar 30 16:43:58 2023 +0100 extracted domain and ipnet information to separate struct commit e6957e7a994114bc848bc5a4d9d9a9194cb5e9c7 Author: Jędrzej Stuczyński Date: Tue Mar 28 11:25:43 2023 +0100 use combination of stake and performance for rewarded set selection commit de2406a2c728d289c9124235e64f81e795f81fc7 Author: Jędrzej Stuczyński Date: Tue Mar 28 10:54:14 2023 +0100 Moved MixnodeWithPerformance to helpers --- common/bin-common/Cargo.toml | 16 +++++- common/bin-common/src/logging/mod.rs | 39 ++++++++++++++ common/mixnode-common/Cargo.toml | 23 ++++++-- common/mixnode-common/src/lib.rs | 38 ++++++++++++- .../src/packet_processor/processor.rs | 53 +++++++++++++------ mixnode/Cargo.toml | 14 +++++ mixnode/src/commands/sign.rs | 3 +- mixnode/src/main.rs | 29 ++++++++-- .../node/listener/connection_handler/mod.rs | 32 ++++++----- mixnode/src/node/listener/mod.rs | 3 +- mixnode/src/node/mod.rs | 3 +- nym-connect/desktop/Cargo.lock | 1 + 12 files changed, 213 insertions(+), 41 deletions(-) diff --git a/common/bin-common/Cargo.toml b/common/bin-common/Cargo.toml index 29fd632897..a3682644ea 100644 --- a/common/bin-common/Cargo.toml +++ b/common/bin-common/Cargo.toml @@ -18,9 +18,23 @@ semver = "0.11" serde = { workspace = true, features = ["derive"], optional = true } serde_json = { workspace = true, optional = true } +## tracing +tracing-appender = { version = "0.2.2", optional = true } +tracing-subscriber = { version = "0.3.16", features = [ + "env-filter", +], optional = true } +tracing-tree = { version = "0.2.2", optional = true } + + [build-dependencies] -vergen = { version = "=7.4.3", default-features = false, features = ["build", "git", "rustc", "cargo"] } +vergen = { version = "=7.4.3", default-features = false, features = [ + "build", + "git", + "rustc", + "cargo", +] } [features] default = [] output_format = ["serde", "serde_json"] +tracing = ["tracing-appender", "tracing-subscriber", "tracing-tree"] diff --git a/common/bin-common/src/logging/mod.rs b/common/bin-common/src/logging/mod.rs index 1562c91e8b..3698f1210f 100644 --- a/common/bin-common/src/logging/mod.rs +++ b/common/bin-common/src/logging/mod.rs @@ -1,5 +1,16 @@ // Copyright 2022 - Nym Technologies SA // SPDX-License-Identifier: Apache-2.0 +// use tracing_subscriber::{ +// fmt::Layer, layer::SubscriberExt, util::SubscriberInitExt, EnvFilter, Registry, +// }; +// use tracing_tree::HierarchicalLayer; + +#[cfg(feature = "tracing")] +pub use tracing_appender; +#[cfg(feature = "tracing")] +pub use tracing_subscriber; +#[cfg(feature = "tracing")] +pub use tracing_tree; // I'd argue we should start transitioning from `log` to `tracing` pub fn setup_logging() { @@ -24,6 +35,34 @@ pub fn setup_logging() { .init(); } +// TODO: This has to be a macro, running it as a function does not work for the file_appender for some reason +#[cfg(feature = "tracing")] +#[macro_export] +macro_rules! setup_tracing { + ($file_name: expr) => { + use nym_bin_common::logging::tracing_subscriber::layer::SubscriberExt; + use nym_bin_common::logging::tracing_subscriber::util::SubscriberInitExt; + + let file_appender = + nym_bin_common::logging::tracing_appender::rolling::hourly($file_name, "log"); + let (non_blocking, _guard) = + nym_bin_common::logging::tracing_appender::non_blocking(file_appender); + let appender_layer = nym_bin_common::logging::tracing_subscriber::fmt::Layer::new() + .with_ansi(false) + .with_writer(non_blocking); + + nym_bin_common::logging::tracing_subscriber::Registry::default() + .with(nym_bin_common::logging::tracing_subscriber::EnvFilter::from_default_env()) + .with(appender_layer) + .with( + nym_bin_common::logging::tracing_tree::HierarchicalLayer::new(4) + .with_targets(true) + .with_bracketed_fields(true), + ) + .init(); + }; +} + pub fn banner(crate_name: &str, crate_version: &str) -> String { format!( r#" diff --git a/common/mixnode-common/Cargo.toml b/common/mixnode-common/Cargo.toml index 0b0e444731..002b3f73df 100644 --- a/common/mixnode-common/Cargo.toml +++ b/common/mixnode-common/Cargo.toml @@ -13,12 +13,21 @@ humantime-serde = "1.0" log = { workspace = true } rand = "0.8" serde = { version = "1.0", features = ["derive"] } -tokio = { version = "1.24.1", features = ["time", "macros", "rt", "net", "io-util"] } +tokio = { version = "1.24.1", features = [ + "time", + "macros", + "rt", + "net", + "io-util", +] } tokio-util = { version = "0.7.4", features = ["codec"] } url = "2.2" thiserror = "1.0.37" -nym-crypto = { path = "../crypto" } +## tracing +tracing = { version = "0.1.37", optional = true } + +nym-crypto = { path = "../crypto" } nym-network-defaults = { path = "../network-defaults" } nym-sphinx-acknowledgements = { path = "../nymsphinx/acknowledgements" } nym-sphinx-addressing = { path = "../nymsphinx/addressing" } @@ -27,5 +36,13 @@ nym-sphinx-framing = { path = "../nymsphinx/framing" } nym-sphinx-params = { path = "../nymsphinx/params" } nym-sphinx-types = { path = "../nymsphinx/types" } nym-task = { path = "../task" } -validator-client = { path = "../client-libs/validator-client", features = ["nyxd-client"]} +validator-client = { path = "../client-libs/validator-client", features = [ + "nyxd-client", +] } nym-bin-common = { path = "../bin-common" } + +cfg-if = "1.0.0" +cpu-cycles = { path = "../../cpu-cycles", optional = true } + +[features] +cpucycles = ["cpu-cycles", "tracing"] diff --git a/common/mixnode-common/src/lib.rs b/common/mixnode-common/src/lib.rs index 34d43fc458..d4488ba44a 100644 --- a/common/mixnode-common/src/lib.rs +++ b/common/mixnode-common/src/lib.rs @@ -1,5 +1,41 @@ // Copyright 2021 - Nym Technologies SA // SPDX-License-Identifier: Apache-2.0 - pub mod packet_processor; pub mod verloc; + +pub fn cpu_cycles() -> Result> { + cfg_if::cfg_if! { + if #[cfg(feature = "cpucycles")] { + Ok(cpu_cycles::cpucycles()?) + } else { + Err("`cpucycles` feature is not turned on!".into()) + } + } +} + +#[macro_export] +macro_rules! measure { + ( $x:expr ) => {{ + cfg_if::cfg_if! { + if #[cfg(feature = "cpucycles")] { + let start_cycles = $crate::cpu_cycles(); + // if the block needs to return something, we can return it + let r = $x; + let end_cycles = $crate::cpu_cycles(); + let name = if let Some(meta) = tracing::Span::current().metadata() { + meta.name() + } else { + "measure" + }; + match (start_cycles, end_cycles) { + (Ok(start), Ok(end)) => info!("{} cpucycles: {}", name, end - start), + (Err(e), _) => error!("{e}"), + (_, Err(e)) => error!("{e}"), + } + r + } else { + $x + } + } + }}; +} diff --git a/common/mixnode-common/src/packet_processor/processor.rs b/common/mixnode-common/src/packet_processor/processor.rs index 7d041fce3b..98847d8983 100644 --- a/common/mixnode-common/src/packet_processor/processor.rs +++ b/common/mixnode-common/src/packet_processor/processor.rs @@ -1,6 +1,7 @@ // Copyright 2021 - Nym Technologies SA // SPDX-License-Identifier: Apache-2.0 +use crate::measure; use crate::packet_processor::error::MixProcessingError; use log::*; use nym_sphinx_acknowledgements::surb_ack::SurbAck; @@ -14,6 +15,8 @@ use nym_sphinx_types::{ }; use std::convert::TryFrom; use std::sync::Arc; +#[cfg(feature = "cpucycles")] +use tracing::instrument; type ForwardAck = MixPacket; @@ -46,29 +49,41 @@ impl SphinxPacketProcessor { } /// Performs a fresh sphinx unwrapping using no cache. + #[cfg_attr( + feature = "cpucycles", + instrument(skip(self, packet), fields(cpucycles)) + )] fn perform_initial_sphinx_packet_processing( &self, packet: SphinxPacket, ) -> Result { - packet.process(&self.sphinx_key).map_err(|err| { - debug!("Failed to unwrap Sphinx packet: {err}"); - MixProcessingError::SphinxProcessingError(err) + measure!({ + packet.process(&self.sphinx_key).map_err(|err| { + debug!("Failed to unwrap Sphinx packet: {err}"); + MixProcessingError::SphinxProcessingError(err) + }) }) } /// Takes the received framed packet and tries to unwrap it from the sphinx encryption. + #[cfg_attr( + feature = "cpucycles", + instrument(skip(self, received), fields(cpucycles)) + )] fn perform_initial_unwrapping( &self, received: FramedSphinxPacket, ) -> Result { - let packet_mode = received.packet_mode(); - let sphinx_packet = received.into_inner(); + measure!({ + let packet_mode = received.packet_mode(); + let sphinx_packet = received.into_inner(); - if packet_mode.is_old_vpn() { - return Err(MixProcessingError::ReceivedOldTypeVpnPacket); - } + if packet_mode.is_old_vpn() { + return Err(MixProcessingError::ReceivedOldTypeVpnPacket); + } - self.perform_initial_sphinx_packet_processing(sphinx_packet) + self.perform_initial_sphinx_packet_processing(sphinx_packet) + }) } /// Processed received forward hop packet - tries to extract next hop address, sets delay @@ -171,20 +186,26 @@ impl SphinxPacketProcessor { } } + #[cfg_attr( + feature = "cpucycles", + instrument(skip(self, received), fields(cpucycles)) + )] pub fn process_received( &self, received: FramedSphinxPacket, ) -> Result { // explicit packet size will help to correctly parse final hop - let packet_size = received.packet_size(); - let packet_mode = received.packet_mode(); + measure!({ + let packet_size = received.packet_size(); + let packet_mode = received.packet_mode(); - // unwrap the sphinx packet and if possible and appropriate, cache keys - let processed_packet = self.perform_initial_unwrapping(received)?; + // unwrap the sphinx packet and if possible and appropriate, cache keys + let processed_packet = self.perform_initial_unwrapping(received)?; - // for forward packets, extract next hop and set delay (but do NOT delay here) - // for final packets, extract SURBAck - self.perform_final_processing(processed_packet, packet_size, packet_mode) + // for forward packets, extract next hop and set delay (but do NOT delay here) + // for final packets, extract SURBAck + self.perform_final_processing(processed_packet, packet_size, packet_mode) + }) } } diff --git a/mixnode/Cargo.toml b/mixnode/Cargo.toml index 014f862b87..0f9b49d1aa 100644 --- a/mixnode/Cargo.toml +++ b/mixnode/Cargo.toml @@ -36,6 +36,12 @@ tokio = { version = "1.21.2", features = ["rt-multi-thread", "net", "signal"] } tokio-util = { version = "0.7.3", features = ["codec"] } toml = "0.5.8" url = { version = "2.2", features = ["serde"] } +cfg-if = "1.0.0" + +## tracing +tracing = { version = "0.1.37", optional = true } +opentelemetry = { version = "0.19.0", optional = true } + ## internal nym-config = { path = "../common/config" } @@ -63,3 +69,11 @@ tokio = { version = "1.21.2", features = [ nym-sphinx-types = { path = "../common/nymsphinx/types" } nym-sphinx-params = { path = "../common/nymsphinx/params" } + +[features] +cpucycles = [ + "mixnode-common/cpucycles", + "tracing", + "opentelemetry", + "nym-bin-common/tracing", +] diff --git a/mixnode/src/commands/sign.rs b/mixnode/src/commands/sign.rs index 706defb8df..e39d97571d 100644 --- a/mixnode/src/commands/sign.rs +++ b/mixnode/src/commands/sign.rs @@ -8,11 +8,12 @@ use crate::config::{persistence::pathfinder::MixNodePathfinder, Config}; use crate::node::MixNode; use anyhow::{bail, Result}; use clap::{ArgGroup, Args}; -use log::error; use nym_bin_common::output_format::OutputFormat; use nym_config::NymConfig; use nym_crypto::asymmetric::identity; use nym_types::helpers::ConsoleSigningOutput; +#[cfg(feature = "cpucycles")] +use tracing::error; use validator_client::nyxd; use super::version_check; diff --git a/mixnode/src/main.rs b/mixnode/src/main.rs index e9f9f9f59c..ca1780a0cf 100644 --- a/mixnode/src/main.rs +++ b/mixnode/src/main.rs @@ -7,9 +7,15 @@ extern crate rocket; use ::nym_config::defaults::setup_env; use clap::{crate_name, crate_version, Parser}; use lazy_static::lazy_static; +#[cfg(feature = "cpucycles")] +use mixnode_common::measure; use nym_bin_common::build_information::BinaryBuildInformation; +#[allow(unused_imports)] use nym_bin_common::logging::{maybe_print_banner, setup_logging}; - +#[cfg(feature = "cpucycles")] +use nym_bin_common::setup_tracing; +#[cfg(feature = "cpucycles")] +use tracing::instrument; mod commands; mod config; mod node; @@ -35,19 +41,32 @@ struct Cli { command: commands::Commands, } -#[cfg(feature = "cpu-cycles")] -pub fn cpu_cycles() { - info!("{}", cpu_cycles::cpucycles()) +#[cfg(feature = "cpucycles")] +#[instrument(fields(cpucycles))] +fn test_function() { + measure!({}) } #[tokio::main] async fn main() { - setup_logging(); + cfg_if::cfg_if! { + if #[cfg(feature = "cpucycles")] { + setup_tracing!("/tmp/tracing.log"); + } else { + setup_logging(); + } + } + maybe_print_banner(crate_name!(), crate_version!()); let args = Cli::parse(); setup_env(args.config_env_file.as_ref()); commands::execute(args).await; + + cfg_if::cfg_if! { + if #[cfg(feature = "cpucycles")] { + opentelemetry::global::shutdown_tracer_provider(); + }} } #[cfg(test)] diff --git a/mixnode/src/node/listener/connection_handler/mod.rs b/mixnode/src/node/listener/connection_handler/mod.rs index 684793b013..1e12075c13 100644 --- a/mixnode/src/node/listener/connection_handler/mod.rs +++ b/mixnode/src/node/listener/connection_handler/mod.rs @@ -7,7 +7,7 @@ use crate::node::listener::connection_handler::packet_processing::{ use crate::node::packet_delayforwarder::PacketDelayForwardSender; use crate::node::TaskClient; use futures::StreamExt; -use log::{error, info}; +use mixnode_common::measure; use nym_sphinx::forwarding::packet::MixPacket; use nym_sphinx::framing::codec::SphinxCodec; use nym_sphinx::framing::packet::FramedSphinxPacket; @@ -16,6 +16,8 @@ use std::net::SocketAddr; use tokio::net::TcpStream; use tokio::time::Instant; use tokio_util::codec::Framed; +#[cfg(feature = "cpucycles")] +use tracing::{error, info, instrument}; pub(crate) mod packet_processing; @@ -48,6 +50,10 @@ impl ConnectionHandler { .expect("the delay-forwarder has died!"); } + #[cfg_attr( + feature = "cpucycles", + instrument(skip(self, framed_sphinx_packet), fields(cpucycles)) + )] fn handle_received_packet(&self, framed_sphinx_packet: FramedSphinxPacket) { // // TODO: here be replay attack detection - it will require similar key cache to the one in @@ -57,17 +63,19 @@ impl ConnectionHandler { // all processing such, key caching, etc. was done. // however, if it was a forward hop, we still need to delay it - match self.packet_processor.process_received(framed_sphinx_packet) { - Err(err) => debug!("We failed to process received sphinx packet - {err}"), - Ok(res) => match res { - MixProcessingResult::ForwardHop(forward_packet, delay) => { - self.delay_and_forward_packet(forward_packet, delay) - } - MixProcessingResult::FinalHop(..) => { - warn!("Somehow processed a loop cover message that we haven't implemented yet!") - } - }, - } + measure!({ + match self.packet_processor.process_received(framed_sphinx_packet) { + Err(err) => debug!("We failed to process received sphinx packet - {err}"), + Ok(res) => match res { + MixProcessingResult::ForwardHop(forward_packet, delay) => { + self.delay_and_forward_packet(forward_packet, delay) + } + MixProcessingResult::FinalHop(..) => { + warn!("Somehow processed a loop cover message that we haven't implemented yet!") + } + }, + } + }) } pub(crate) async fn handle_connection( diff --git a/mixnode/src/node/listener/mod.rs b/mixnode/src/node/listener/mod.rs index 43732a772f..f8fad07b23 100644 --- a/mixnode/src/node/listener/mod.rs +++ b/mixnode/src/node/listener/mod.rs @@ -2,11 +2,12 @@ // SPDX-License-Identifier: Apache-2.0 use crate::node::listener::connection_handler::ConnectionHandler; -use log::error; use std::net::SocketAddr; use std::process; use tokio::net::TcpListener; use tokio::task::JoinHandle; +#[cfg(feature = "cpucycles")] +use tracing::error; use super::TaskClient; diff --git a/mixnode/src/node/mod.rs b/mixnode/src/node/mod.rs index 28716f120c..d0a28c82af 100644 --- a/mixnode/src/node/mod.rs +++ b/mixnode/src/node/mod.rs @@ -16,7 +16,6 @@ use crate::node::listener::Listener; use crate::node::node_description::NodeDescription; use crate::node::node_statistics::SharedNodeStats; use crate::node::packet_delayforwarder::{DelayForwarder, PacketDelayForwardSender}; -use log::{error, info, warn}; use mixnode_common::verloc::{self, AtomicVerlocResult, VerlocMeasurer}; use nym_bin_common::output_format::OutputFormat; use nym_bin_common::version_checker::parse_version; @@ -28,6 +27,8 @@ use rand::thread_rng; use std::net::SocketAddr; use std::process; use std::sync::Arc; +#[cfg(feature = "cpucycles")] +use tracing::{error, info, warn}; mod http; mod listener; diff --git a/nym-connect/desktop/Cargo.lock b/nym-connect/desktop/Cargo.lock index 0421b9637c..86d829bc7d 100644 --- a/nym-connect/desktop/Cargo.lock +++ b/nym-connect/desktop/Cargo.lock @@ -3276,6 +3276,7 @@ dependencies = [ name = "nym-bin-common" version = "0.3.0" dependencies = [ + "atty", "clap", "clap_complete", "clap_complete_fig",