From 294ce2811878d3d0a9914f681a5eec912a8298f9 Mon Sep 17 00:00:00 2001 From: wkennedy Date: Fri, 11 Oct 2024 17:04:43 -0400 Subject: [PATCH 1/7] Update dependencies and refine OpenTelemetry integration Updated various dependencies across crates to their latest versions and refined OpenTelemetry logging, tracing, and metrics setup. This ensures better compatibility and streamlined functionality within the project. --- sologger-log-context/Cargo.toml | 14 ++-- sologger-log-transformer/Cargo.toml | 12 +-- .../src/log_context_transformer.rs | 12 ++- sologger-log-transport/Cargo.toml | 22 +++--- .../src/opentelemetry_lib.rs | 73 ++++++++----------- sologger/Cargo.toml | 32 ++++---- 6 files changed, 79 insertions(+), 86 deletions(-) diff --git a/sologger-log-context/Cargo.toml b/sologger-log-context/Cargo.toml index baae25f..32055cc 100644 --- a/sologger-log-context/Cargo.toml +++ b/sologger-log-context/Cargo.toml @@ -15,10 +15,10 @@ exclude=["/tests", "/examples", "/benches", "/docs", "/target", "/.github", "/.g doctest = false [dependencies] -log = "0.4.21" -regex = { version = "1.10.4" } -serde = { version = "1.0.197", features = ["serde_derive", "derive"]} -serde_json = {version = "1.0.115"} -serde_derive = "1.0.197" -bs58 = "0.5.0" -lazy_static = "1.4.0" \ No newline at end of file +log = "0.4.22" +regex = { version = "1.11.0" } +serde = { version = "1.0.210", features = ["serde_derive", "derive"]} +serde_json = {version = "1.0.128"} +serde_derive = "1.0.210" +bs58 = "0.5.1" +lazy_static = "1.5.0" \ No newline at end of file diff --git a/sologger-log-transformer/Cargo.toml b/sologger-log-transformer/Cargo.toml index fd89cab..6f389f9 100644 --- a/sologger-log-transformer/Cargo.toml +++ b/sologger-log-transformer/Cargo.toml @@ -15,9 +15,9 @@ exclude=["/tests", "/examples", "/benches", "/docs", "/target", "/.github", "/.g doctest = false [dependencies] -anyhow = "1.0.81" -solana-rpc-client = "1.18.12" -solana-rpc-client-api = "1.18.12" -solana-transaction-status = "1.18.12" -solana-sdk = "1.18.12" -sologger_log_context = "0.1.2" \ No newline at end of file +anyhow = "1.0.89" +solana-rpc-client = "2.0.13" +solana-rpc-client-api = "2.0.13" +solana-transaction-status = "2.0.13" +solana-sdk = "2.0.13" +sologger_log_context = {path = "../sologger-log-context"} \ No newline at end of file diff --git a/sologger-log-transformer/src/log_context_transformer.rs b/sologger-log-transformer/src/log_context_transformer.rs index ab3b99c..c8359e7 100644 --- a/sologger-log-transformer/src/log_context_transformer.rs +++ b/sologger-log-transformer/src/log_context_transformer.rs @@ -270,6 +270,7 @@ mod tests { use solana_rpc_client::rpc_client::RpcClient; use solana_rpc_client_api::config::{RpcBlockConfig, RpcTransactionConfig}; use solana_rpc_client_api::response::{Response, RpcLogsResponse, RpcResponseContext}; + use solana_sdk::clock::UnixTimestamp; use solana_sdk::commitment_config::CommitmentConfig; use solana_sdk::signature::{Keypair, Signature, Signer}; use solana_sdk::system_transaction; @@ -336,6 +337,7 @@ mod tests { transactions: Some(vec![transaction]), signatures: None, rewards: None, + num_reward_partitions: Some(1), block_time: None, block_height: None, }; @@ -471,8 +473,9 @@ mod tests { parent_slot: 0, transactions: vec![transaction_with_status_meta], rewards: vec![], - block_time: None, - block_height: None, + num_partitions: Some(1), + block_time: Some(UnixTimestamp::default()), + block_height: Some(100), }; let logs_contexts = from_version_confirmed_block( confirmed_block, @@ -528,8 +531,9 @@ mod tests { parent_slot: 0, transactions: vec![transaction], rewards: vec![], - block_time: None, - block_height: None, + num_partitions: Some(1), + block_time: Some(UnixTimestamp::default()), + block_height: Some(100), }; let logs_contexts = from_encoded_confirmed_block( confirmed_block, diff --git a/sologger-log-transport/Cargo.toml b/sologger-log-transport/Cargo.toml index b20afed..1d0dd89 100644 --- a/sologger-log-transport/Cargo.toml +++ b/sologger-log-transport/Cargo.toml @@ -16,23 +16,23 @@ doctest = false [dependencies] log = "0.4.19" -opentelemetry-otlp = {version = "0.14.0", features = ["grpc-tonic", "http", "opentelemetry-http", "reqwest-client", "tonic", "logs", "metrics", "trace"], optional = true} -opentelemetry-appender-log = {version = "0.2.0", default-features = false, optional = true} -opentelemetry = {version = "0.21.0", features = ["logs", "metrics", "trace"]} -opentelemetry_sdk = {version = "0.21.2", features = ["rt-tokio", "metrics", "logs", "trace"], optional = true} -opentelemetry-stdout = {version = "0.2.0", features = ["logs", "metrics", "trace"], optional = true} +opentelemetry-otlp = {version = "0.26.0", features = ["grpc-tonic", "http", "opentelemetry-http", "reqwest-client", "tonic", "logs", "metrics", "trace"], optional = true} +opentelemetry-appender-log = {version = "0.26.0", default-features = false, optional = true} +opentelemetry = {version = "0.26.0", features = ["logs", "metrics", "trace"]} +opentelemetry_sdk = {version = "0.26.0", features = ["rt-tokio", "metrics", "logs", "trace"], optional = true} +opentelemetry-stdout = {version = "0.26.0", features = ["logs", "metrics", "trace"], optional = true} opentelemetry_api = { version = "0.20.0", features = ["metrics", "logs", "trace"], optional = true} -opentelemetry-semantic-conventions = {version = "0.13.0", optional = true} +opentelemetry-semantic-conventions = {version = "0.26.0", optional = true} qoollo-logstash-rs = { version = "0.2.0", optional = true } qoollo-log4rs-logstash = { version = "0.2.0", optional = true } -log4rs = { version = "1.3.0", features = ["json_format"] } -anyhow = "1.0.81" -serde = "1.0.197" -serde_json = "1.0.115" +log4rs = { version = "1.3.0", features = ["json_format", "serde_json", "config_parsing"] } +anyhow = "1.0.89" +serde = "1.0.210" +serde_json = "1.0.128" [dev-dependencies] tokio-test = "0.4.3" -tokio = { version = "1.32.0", features = ["macros"] } +tokio = { version = "1.40.0", features = ["macros"] } [features] logstash = ["qoollo-logstash-rs", "qoollo-log4rs-logstash"] diff --git a/sologger-log-transport/src/opentelemetry_lib.rs b/sologger-log-transport/src/opentelemetry_lib.rs index 1648bb6..2bf2389 100644 --- a/sologger-log-transport/src/opentelemetry_lib.rs +++ b/sologger-log-transport/src/opentelemetry_lib.rs @@ -3,14 +3,20 @@ use std::str::FromStr; use anyhow::Result as AnyResult; use log::{Level, trace}; -use opentelemetry::{Key, KeyValue, metrics, trace::Tracer}; -use opentelemetry::global::logger_provider; +use opentelemetry::{Key, KeyValue, metrics, trace::Tracer, global}; use opentelemetry::logs::LogError; +use opentelemetry::metrics::{MeterProvider, MetricsError}; +use opentelemetry::metrics::noop::NoopMeterProvider; +use opentelemetry::trace::TraceError; +use opentelemetry_api::global::logger_provider; +use opentelemetry_api::trace::FutureExt; use opentelemetry_appender_log::OpenTelemetryLogBridge; use opentelemetry_otlp::{Protocol, WithExportConfig}; use opentelemetry_sdk::{Resource, runtime, trace as sdktrace}; -use opentelemetry_sdk::logs::Config; -use opentelemetry_sdk::metrics::MeterProvider; +use opentelemetry_sdk::logs::{BatchConfig, LoggerProvider}; +use opentelemetry_sdk::metrics::{PeriodicReader, SdkMeterProvider}; +use opentelemetry_sdk::trace::{Config, TracerProvider}; +use opentelemetry_stdout::SpanExporter; use serde_json; use crate::opentelemetry_config::OpentelemetryConfig; @@ -18,7 +24,7 @@ use crate::opentelemetry_config::OpentelemetryConfig; /// Initialize the logger with the provided logstash config location pub fn init_logs_opentelemetry_with_config_path( path: &String, -) -> AnyResult { +) -> AnyResult { let config = get_otel_config(path); init_logs_opentelemetry(&config) @@ -28,7 +34,7 @@ pub fn init_logs_opentelemetry_with_config_path( #[cfg(feature = "otel")] pub fn init_logs_opentelemetry( config: &OpentelemetryConfig, -) -> AnyResult { +) -> AnyResult { let log_config: Vec = config .log_config .iter() @@ -37,8 +43,7 @@ pub fn init_logs_opentelemetry( trace!("OLTP log_config: {:?}", log_config); let logger = opentelemetry_otlp::new_pipeline() - .logging() - .with_log_config(Config::default().with_resource(Resource::new(log_config))) + .logging().with_resource(Resource::new(log_config)) .with_exporter( opentelemetry_otlp::new_exporter() .tonic() @@ -47,11 +52,8 @@ pub fn init_logs_opentelemetry( .install_batch(runtime::Tokio) .expect("Failed to initialize opentelemetry logging"); - // Retrieve the global LoggerProvider. - let logger_provider = logger_provider(); - // Create a new OpenTelemetryLogBridge using the above LoggerProvider. - let otel_log_appender = OpenTelemetryLogBridge::new(&logger_provider); + let otel_log_appender = OpenTelemetryLogBridge::new(&logger); log::set_boxed_logger(Box::new(otel_log_appender)).unwrap(); log::set_max_level( Level::from_str(&config.log_level) @@ -63,41 +65,28 @@ pub fn init_logs_opentelemetry( // TODO add configuration #[cfg(feature = "otel")] -pub fn init_tracer(config: &OpentelemetryConfig) -> Result { - opentelemetry_otlp::new_pipeline() - .tracing() - .with_trace_config(opentelemetry_sdk::trace::Config::default().with_resource(Resource::new(vec![KeyValue::new( - opentelemetry_semantic_conventions::resource::SERVICE_NAME, - "basic-otlp-trace-example", - )])),) - .with_exporter( - opentelemetry_otlp::new_exporter() - .tonic() - .with_endpoint(config.traces_endpoint.clone()), - ) - .install_batch(opentelemetry_sdk::runtime::Tokio) +pub fn init_tracer(config: &OpentelemetryConfig) -> Result { + let provider = TracerProvider::builder() + .with_simple_exporter(SpanExporter::default()) + .build(); + + Ok(provider) } // TODO add configuration #[cfg(feature = "otel")] -pub fn init_metrics(config: &OpentelemetryConfig) -> opentelemetry::metrics::Result { - let export_config = opentelemetry_otlp::ExportConfig { - endpoint: config.metrics_endpoint.to_string(), - protocol: Protocol::Grpc, - timeout: Default::default(), - }; - opentelemetry_otlp::new_pipeline() - .metrics(opentelemetry_sdk::runtime::Tokio) - .with_resource(Resource::new(vec![KeyValue::new( - opentelemetry_semantic_conventions::resource::SERVICE_NAME, - "basic-otlp-metrics-example", +pub fn init_metrics(config: &OpentelemetryConfig) -> Result { + let exporter = opentelemetry_stdout::MetricsExporterBuilder::default().build(); + let reader = PeriodicReader::builder(exporter, runtime::Tokio).build(); + let provider = SdkMeterProvider::builder() + .with_reader(reader) + .with_resource(Resource::new([KeyValue::new( + "service.name", + "metrics-basic-example", )])) - .with_exporter( - opentelemetry_otlp::new_exporter() - .tonic() - .with_export_config(export_config), - ) - .build() + .build(); + global::set_meter_provider(provider.clone()); + Ok(provider) } /// Returns the OpentelemetryConfig struct converted from the otel config json diff --git a/sologger/Cargo.toml b/sologger/Cargo.toml index be49800..fb016ba 100644 --- a/sologger/Cargo.toml +++ b/sologger/Cargo.toml @@ -15,22 +15,22 @@ exclude=["/tests", "/examples", "/benches", "/docs", "/target", "/.github", "/.g doctest = false [dependencies] -serde_derive = "1.0.197" -url = "2.5.0" -log = "0.4.21" -bs58 = "0.5.0" -futures-util = "0.3.30" -anyhow = "1.0.81" -serde = { version = "1.0.197" } -serde_json = {version = "1.0.115"} -regex = "1.10.4" -solana-pubsub-client = { version = "1.18.12", optional = true } -solana-rpc-client-api = { version = "1.18.12", optional = true } -solana-sdk = { version = "1.18.12", optional = true } -sologger_log_context = "0.1.2" -sologger_log_transformer = "0.1.4" -sologger_log_transport = { version = "0.1.2", features = ["otel", "logstash"]} -tokio = { version = "1.36.0", features = ["full"] } +serde_derive = "1.0.210" +url = "2.5.2" +log = "0.4.22" +bs58 = "0.5.1" +futures-util = "0.3.31" +anyhow = "1.0.89" +serde = { version = "1.0.210" } +serde_json = {version = "1.0.128"} +regex = "1.11.0" +solana-pubsub-client = { version = "2.0.13", optional = true } +solana-rpc-client-api = { version = "2.0.13", optional = true } +solana-sdk = { version = "2.0.13", optional = true } +sologger_log_context = {path = "../sologger-log-context"} +sologger_log_transformer = {path = "../sologger-log-transformer"} +sologger_log_transport = { path="../sologger-log-transport", features = ["otel", "logstash"]} +tokio = { version = "1.40.0", features = ["full"] } tokio-metrics = { version = "0.3.1", optional = true} tokio-rustls = "0.24.1" From 83a95382a88708876e0dbd91eabe5a3b9e44882f Mon Sep 17 00:00:00 2001 From: wkennedy Date: Fri, 11 Oct 2024 23:21:40 -0400 Subject: [PATCH 2/7] Add error handling tests and benchmarks Enhanced code to include tests for error cases in `from_encoded_transaction`. Added several new unit tests for `LogContext` parsing various log scenarios. Introduced benchmarks for log parsing functions and context transformers to measure performance. --- sologger-log-context/Cargo.toml | 9 +- .../benches/log_context_benchmarks.rs | 74 ++++++++ .../src/sologger_log_context.rs | 161 ++++++++++++++++ sologger-log-transformer/Cargo.toml | 9 +- .../log_context_transformer_benchmarks.rs | 174 ++++++++++++++++++ .../src/log_context_transformer.rs | 65 +++++-- 6 files changed, 478 insertions(+), 14 deletions(-) create mode 100644 sologger-log-context/benches/log_context_benchmarks.rs create mode 100644 sologger-log-transformer/benches/log_context_transformer_benchmarks.rs diff --git a/sologger-log-context/Cargo.toml b/sologger-log-context/Cargo.toml index 32055cc..ee33c0d 100644 --- a/sologger-log-context/Cargo.toml +++ b/sologger-log-context/Cargo.toml @@ -21,4 +21,11 @@ serde = { version = "1.0.210", features = ["serde_derive", "derive"]} serde_json = {version = "1.0.128"} serde_derive = "1.0.210" bs58 = "0.5.1" -lazy_static = "1.5.0" \ No newline at end of file +lazy_static = "1.5.0" + +[dev-dependencies] +criterion = "0.5.1" + +[[bench]] +name = "log_context_benchmarks" +harness = false \ No newline at end of file diff --git a/sologger-log-context/benches/log_context_benchmarks.rs b/sologger-log-context/benches/log_context_benchmarks.rs new file mode 100644 index 0000000..e9ed640 --- /dev/null +++ b/sologger-log-context/benches/log_context_benchmarks.rs @@ -0,0 +1,74 @@ +use criterion::{black_box, criterion_group, criterion_main, Criterion}; +use sologger_log_context::programs_selector::ProgramsSelector; +use sologger_log_context::sologger_log_context::LogContext; + +fn generate_sample_logs(n: usize) -> Vec { + let mut logs = Vec::with_capacity(n); + for i in 0..n { + logs.push(format!("Program 9RX7oz3WN5VRTqekBBHBvEJFVMNRnrCmVy7S6B6S5oU7 invoke [1]")); + logs.push(format!("Program log: Instruction: Initialize {}", i)); + logs.push(format!("Program 11111111111111111111111111111111 invoke [2]")); + logs.push(format!("Program 11111111111111111111111111111111 success")); + logs.push(format!("Program log: Initialized new event. Current value {}", i)); + logs.push(format!("Program 9RX7oz3WN5VRTqekBBHBvEJFVMNRnrCmVy7S6B6S5oU7 consumed 59783 of 200000 compute units")); + logs.push(format!("Program 9RX7oz3WN5VRTqekBBHBvEJFVMNRnrCmVy7S6B6S5oU7 success")); + } + logs +} + +fn bench_parse_logs(c: &mut Criterion) { + let logs = generate_sample_logs(100); + let programs_selector = ProgramsSelector::new(&["*".to_string()]); + + c.bench_function("parse_logs 100 entries", |b| { + b.iter(|| { + LogContext::parse_logs( + black_box(&logs), + black_box("".to_string()), + black_box(&programs_selector), + black_box(1), + black_box("12345".to_string()), + ) + }) + }); +} + +fn bench_get_invoke_program_id(c: &mut Criterion) { + let log = "Program 9RX7oz3WN5VRTqekBBHBvEJFVMNRnrCmVy7S6B6S5oU7 invoke [1]".to_string(); + + c.bench_function("get_invoke_program_id", |b| { + b.iter(|| LogContext::get_invoke_program_id(black_box(&log))) + }); +} + +fn bench_get_program_data(c: &mut Criterion) { + let log = "Program data: f8oPt8jABAy1K0GKz0oSSO8oves0qt09GsKz1QNA3hkOpcvC0rPMywt4KffaIJMAVQlyjQhUVOXGyn09Lxu29Ty1k5m72ijBAAAAAAAAAAAAuZINBxwAAAC7AAAAAAAAAIjnFQEAAAAA".to_string(); + + c.bench_function("get_program_data", |b| { + b.iter(|| LogContext::get_program_data(black_box(&log))) + }); +} + +fn bench_to_json(c: &mut Criterion) { + let log_context = LogContext::new( + "9RX7oz3WN5VRTqekBBHBvEJFVMNRnrCmVy7S6B6S5oU7".to_string(), + 1, + "unique_id".to_string(), + 0, + 1, + "signature".to_string(), + ); + + c.bench_function("to_json", |b| { + b.iter(|| black_box(&log_context).to_json()) + }); +} + +criterion_group!( + benches, + bench_parse_logs, + bench_get_invoke_program_id, + bench_get_program_data, + bench_to_json +); +criterion_main!(benches); \ No newline at end of file diff --git a/sologger-log-context/src/sologger_log_context.rs b/sologger-log-context/src/sologger_log_context.rs index d315bb3..b6a6de5 100644 --- a/sologger-log-context/src/sologger_log_context.rs +++ b/sologger-log-context/src/sologger_log_context.rs @@ -1149,4 +1149,165 @@ mod tests { let log_contexts = LogContext::parse_logs(&raw_logs, "".to_string(), &programs_selector,216778028, "KDhFgTogstghe9P1jVjVepnwfR9ZbcU8a6D21jXBh3PPyfkkd92MmevsWW7qb6QtfmfmWxAPYnL3xZR81xVCmeQ".to_string()); } + + + #[test] + fn log_parser_empty_logs_test() { + let logs: Vec = vec![]; + let programs_selector = ProgramsSelector::new_all_programs(); + + let log_contexts = LogContext::parse_logs( + &logs, + "".to_string(), + &programs_selector, + 1, + "12345".to_string(), + ); + + assert!(log_contexts.is_empty()); + } + + #[test] + fn log_parser_nested_invocations_test() { + let logs: Vec = vec![ + "Program A111111111111111111111111111111111111111 invoke [1]".to_string(), + "Program B222222222222222222222222222222222222222 invoke [2]".to_string(), + "Program C333333333333333333333333333333333333333 invoke [3]".to_string(), + "Program C333333333333333333333333333333333333333 success".to_string(), + "Program B222222222222222222222222222222222222222 success".to_string(), + "Program A111111111111111111111111111111111111111 success".to_string(), + ]; + let programs_selector = ProgramsSelector::new_all_programs(); + + let log_contexts = LogContext::parse_logs( + &logs, + "".to_string(), + &programs_selector, + 1, + "12345".to_string(), + ); + + assert_eq!(log_contexts.len(), 3); + assert_eq!(log_contexts[0].program_id, "A111111111111111111111111111111111111111"); + assert_eq!(log_contexts[1].program_id, "B222222222222222222222222222222222222222"); + assert_eq!(log_contexts[2].program_id, "C333333333333333333333333333333333333333"); + assert_eq!(log_contexts[0].depth, 1); + assert_eq!(log_contexts[1].depth, 2); + assert_eq!(log_contexts[2].depth, 3); + } + + #[test] + fn log_parser_mismatched_invoke_success_test() { + let logs: Vec = vec![ + "Program A111111111111111111111111111111111111111 invoke [1]".to_string(), + "Program B222222222222222222222222222222222222222 invoke [2]".to_string(), + "Program A111111111111111111111111111111111111111 success".to_string(), + ]; + let programs_selector = ProgramsSelector::new_all_programs(); + + let log_contexts = LogContext::parse_logs( + &logs, + "".to_string(), + &programs_selector, + 1, + "12345".to_string(), + ); + + assert_eq!(log_contexts.len(), 2); + assert_eq!(log_contexts[0].program_id, "A111111111111111111111111111111111111111"); + assert_eq!(log_contexts[1].program_id, "B222222222222222222222222222222222222222"); + } + + #[test] + fn log_parser_program_return_test() { + let logs: Vec = vec![ + "Program A111111111111111111111111111111111111111 invoke [1]".to_string(), + "Program return: A111111111111111111111111111111111111111 SomeReturnValue".to_string(), + "Program A111111111111111111111111111111111111111 success".to_string(), + ]; + let programs_selector = ProgramsSelector::new_all_programs(); + + let log_contexts = LogContext::parse_logs( + &logs, + "".to_string(), + &programs_selector, + 1, + "12345".to_string(), + ); + + assert_eq!(log_contexts.len(), 1); + assert_eq!(log_contexts[0].program_id, "A111111111111111111111111111111111111111"); + assert_eq!(log_contexts[0].invoke_result, "SomeReturnValue"); + } + + #[test] + fn log_parser_program_consumption_test() { + let logs: Vec = vec![ + "Program A111111111111111111111111111111111111111 invoke [1]".to_string(), + "Program consumption: 50000".to_string(), + "Program A111111111111111111111111111111111111111 success".to_string(), + ]; + let programs_selector = ProgramsSelector::new_all_programs(); + + let log_contexts = LogContext::parse_logs( + &logs, + "".to_string(), + &programs_selector, + 1, + "12345".to_string(), + ); + + assert_eq!(log_contexts.len(), 1); + assert_eq!(log_contexts[0].program_id, "A111111111111111111111111111111111111111"); + assert_eq!(log_contexts[0].raw_logs.len(), 3); + assert!(log_contexts[0].raw_logs.contains(&"Program consumption: 50000".to_string())); + } + + #[test] + fn log_parser_multiple_instructions_test() { + let logs: Vec = vec![ + "Program A111111111111111111111111111111111111111 invoke [1]".to_string(), + "Program A111111111111111111111111111111111111111 success".to_string(), + "Program B222222222222222222222222222222222222222 invoke [1]".to_string(), + "Program B222222222222222222222222222222222222222 success".to_string(), + ]; + let programs_selector = ProgramsSelector::new_all_programs(); + + let log_contexts = LogContext::parse_logs( + &logs, + "".to_string(), + &programs_selector, + 1, + "12345".to_string(), + ); + + assert_eq!(log_contexts.len(), 2); + assert_eq!(log_contexts[0].program_id, "A111111111111111111111111111111111111111"); + assert_eq!(log_contexts[1].program_id, "B222222222222222222222222222222222222222"); + assert_eq!(log_contexts[0].instruction_index, 0); + assert_eq!(log_contexts[1].instruction_index, 1); + } + + #[test] + fn log_parser_transaction_error_test() { + let logs: Vec = vec![ + "Program A111111111111111111111111111111111111111 invoke [1]".to_string(), + "Program A111111111111111111111111111111111111111 failed: custom program error: 0x1".to_string(), + ]; + let programs_selector = ProgramsSelector::new_all_programs(); + + let log_contexts = LogContext::parse_logs( + &logs, + "Transaction failed".to_string(), + &programs_selector, + 1, + "12345".to_string(), + ); + + assert_eq!(log_contexts.len(), 1); + assert_eq!(log_contexts[0].program_id, "A111111111111111111111111111111111111111"); + assert_eq!(log_contexts[0].transaction_error, "Transaction failed"); + assert_eq!(log_contexts[0].errors.len(), 1); + assert_eq!(log_contexts[0].errors[0], "custom program error: 0x1"); + } } diff --git a/sologger-log-transformer/Cargo.toml b/sologger-log-transformer/Cargo.toml index 6f389f9..d1f5b6d 100644 --- a/sologger-log-transformer/Cargo.toml +++ b/sologger-log-transformer/Cargo.toml @@ -20,4 +20,11 @@ solana-rpc-client = "2.0.13" solana-rpc-client-api = "2.0.13" solana-transaction-status = "2.0.13" solana-sdk = "2.0.13" -sologger_log_context = {path = "../sologger-log-context"} \ No newline at end of file +sologger_log_context = {path = "../sologger-log-context"} + +[dev-dependencies] +criterion = "0.3" + +[[bench]] +name = "log_context_transformer_benchmarks" +harness = false \ No newline at end of file diff --git a/sologger-log-transformer/benches/log_context_transformer_benchmarks.rs b/sologger-log-transformer/benches/log_context_transformer_benchmarks.rs new file mode 100644 index 0000000..c9f6533 --- /dev/null +++ b/sologger-log-transformer/benches/log_context_transformer_benchmarks.rs @@ -0,0 +1,174 @@ +use criterion::{black_box, criterion_group, criterion_main, Criterion}; +use solana_rpc_client_api::response::{Response, RpcLogsResponse, RpcResponseContext}; +use solana_sdk::signature::Signature; +use solana_transaction_status::{ + EncodedConfirmedBlock, EncodedTransaction, EncodedTransactionWithStatusMeta, + TransactionDetails, UiConfirmedBlock, UiMessage, UiParsedMessage, + UiTransaction, UiTransactionStatusMeta, +}; +use solana_transaction_status::option_serializer::OptionSerializer; +use sologger_log_context::programs_selector::ProgramsSelector; +use sologger_log_transformer::log_context_transformer::{from_encoded_confirmed_block, from_rpc_logs_response, from_rpc_response, from_ui_confirmed_block}; + +fn create_mock_ui_confirmed_block() -> UiConfirmedBlock { + let signature = Signature::new_unique(); + + let ui_parsed_message = UiParsedMessage { + account_keys: vec![], + recent_blockhash: "".to_string(), + instructions: vec![], + address_table_lookups: None, + }; + let ui_transaction = UiTransaction { + signatures: vec![signature.to_string()], + message: UiMessage::Parsed(ui_parsed_message), + }; + + let transaction_status_meta = UiTransactionStatusMeta { + err: None, + status: Ok(()), + fee: 0, + pre_balances: vec![], + post_balances: vec![], + inner_instructions: OptionSerializer::None, + log_messages: OptionSerializer::Some(vec![ + "Program 11111111111111111111111111111111 invoke [1]".to_string(), + "Program 11111111111111111111111111111111 success".to_string(), + ]), + pre_token_balances: OptionSerializer::None, + post_token_balances: OptionSerializer::None, + rewards: OptionSerializer::None, + loaded_addresses: OptionSerializer::None, + return_data: OptionSerializer::None, + compute_units_consumed: OptionSerializer::None, + }; + let transaction = EncodedTransactionWithStatusMeta { + transaction: EncodedTransaction::Json(ui_transaction), + meta: Some(transaction_status_meta), + version: None, + }; + + UiConfirmedBlock { + previous_blockhash: "".to_string(), + blockhash: "".to_string(), + parent_slot: 0, + transactions: Some(vec![transaction]), + signatures: None, + rewards: None, + num_reward_partitions: Some(1), + block_time: None, + block_height: None, + } +} + +fn create_mock_encoded_confirmed_block() -> EncodedConfirmedBlock { + let signature = Signature::new_unique(); + + let ui_parsed_message = UiParsedMessage { + account_keys: vec![], + recent_blockhash: "".to_string(), + instructions: vec![], + address_table_lookups: None, + }; + let ui_transaction = UiTransaction { + signatures: vec![signature.to_string()], + message: UiMessage::Parsed(ui_parsed_message), + }; + + let transaction_status_meta = UiTransactionStatusMeta { + err: None, + status: Ok(()), + fee: 0, + pre_balances: vec![], + post_balances: vec![], + inner_instructions: OptionSerializer::None, + log_messages: OptionSerializer::Some(vec![ + "Program 11111111111111111111111111111111 invoke [1]".to_string(), + "Program 11111111111111111111111111111111 success".to_string(), + ]), + pre_token_balances: OptionSerializer::None, + post_token_balances: OptionSerializer::None, + rewards: OptionSerializer::None, + loaded_addresses: OptionSerializer::None, + return_data: OptionSerializer::None, + compute_units_consumed: OptionSerializer::None, + }; + let transaction = EncodedTransactionWithStatusMeta { + transaction: EncodedTransaction::Json(ui_transaction), + meta: Some(transaction_status_meta), + version: None, + }; + + EncodedConfirmedBlock { + previous_blockhash: "".to_string(), + blockhash: "".to_string(), + parent_slot: 0, + transactions: vec![transaction], + rewards: vec![], + num_partitions: Some(1), + block_time: None, + block_height: None, + } +} + +fn create_mock_rpc_logs_response() -> RpcLogsResponse { + RpcLogsResponse { + signature: "pF5oPR8R4vJwU2KeQm8BAAGYcTiikZkpJAmP8TuuVztkL2K6wZhxVKy9t6jSCMSpMMD3VE6Qek1YL5JAFvuBLQw".to_string(), + err: None, + logs: vec!["Program 11111111111111111111111111111111 invoke [1]".to_string(), "Program 11111111111111111111111111111111 success".to_string()], + } +} + +fn bench_from_ui_confirmed_block(c: &mut Criterion) { + let ui_confirmed_block = create_mock_ui_confirmed_block(); + let program_selector = ProgramsSelector::new_all_programs(); + + c.bench_function("from_ui_confirmed_block", |b| { + b.iter(|| { + from_ui_confirmed_block( + black_box(ui_confirmed_block.clone()), + black_box(219907401), + black_box(&program_selector), + ) + }) + }); +} + +fn bench_from_rpc_logs_response(c: &mut Criterion) { + let rpc_logs_response = create_mock_rpc_logs_response(); + let program_selector = ProgramsSelector::new_all_programs(); + + c.bench_function("from_rpc_logs_response", |b| { + b.iter(|| { + from_rpc_logs_response( + black_box(&rpc_logs_response), + black_box(323432), + black_box(&program_selector), + ) + }) + }); +} + +fn bench_from_rpc_response(c: &mut Criterion) { + let rpc_logs_response = create_mock_rpc_logs_response(); + let response = Response { + context: RpcResponseContext { + slot: 12324, + api_version: None, + }, + value: rpc_logs_response, + }; + let program_selector = ProgramsSelector::new_all_programs(); + + c.bench_function("from_rpc_response", |b| { + b.iter(|| from_rpc_response(black_box(&response), black_box(&program_selector))) + }); +} + +criterion_group!( + benches, + bench_from_ui_confirmed_block, + bench_from_rpc_logs_response, + bench_from_rpc_response +); +criterion_main!(benches); \ No newline at end of file diff --git a/sologger-log-transformer/src/log_context_transformer.rs b/sologger-log-transformer/src/log_context_transformer.rs index c8359e7..6672968 100644 --- a/sologger-log-transformer/src/log_context_transformer.rs +++ b/sologger-log-transformer/src/log_context_transformer.rs @@ -272,22 +272,15 @@ mod tests { use solana_rpc_client_api::response::{Response, RpcLogsResponse, RpcResponseContext}; use solana_sdk::clock::UnixTimestamp; use solana_sdk::commitment_config::CommitmentConfig; + use solana_sdk::instruction::InstructionError; + use solana_sdk::message::Message; use solana_sdk::signature::{Keypair, Signature, Signer}; use solana_sdk::system_transaction; - use solana_sdk::transaction::VersionedTransaction; + use solana_sdk::transaction::{Transaction, TransactionError, VersionedTransaction}; use solana_transaction_status::option_serializer::OptionSerializer; - use solana_transaction_status::{ - EncodedConfirmedBlock, - EncodedTransaction, EncodedTransactionWithStatusMeta, TransactionDetails, - TransactionStatusMeta, UiConfirmedBlock, UiMessage, UiParsedMessage, UiTransaction, - UiTransactionEncoding, UiTransactionStatusMeta, VersionedConfirmedBlock, - VersionedTransactionWithStatusMeta, - }; + use solana_transaction_status::{ConfirmedBlock, EncodedConfirmedBlock, EncodedTransaction, EncodedTransactionWithStatusMeta, TransactionDetails, TransactionStatusMeta, UiConfirmedBlock, UiMessage, UiParsedMessage, UiRawMessage, UiTransaction, UiTransactionEncoding, UiTransactionStatusMeta, VersionedConfirmedBlock, VersionedTransactionWithStatusMeta}; - use crate::log_context_transformer::{ - from_encoded_confirmed_block, from_encoded_confirmed_transaction, from_rpc_logs_response, - from_rpc_response, from_ui_confirmed_block, from_version_confirmed_block, - }; + use crate::log_context_transformer::{from_confirmed_block, from_encoded_confirmed_block, from_encoded_confirmed_transaction, from_encoded_transaction, from_rpc_logs_response, from_rpc_response, from_ui_confirmed_block, from_version_confirmed_block}; use sologger_log_context::programs_selector::ProgramsSelector; #[test] @@ -544,4 +537,52 @@ mod tests { assert_eq!(logs_contexts.len(), 1); } + + // Test for error cases in from_encoded_transaction + #[test] + fn test_from_encoded_transaction_error_cases() { + let signature = Signature::new_unique(); + let ui_raw_message = UiRawMessage { + header: Default::default(), + account_keys: vec![], + recent_blockhash: "".to_string(), + instructions: vec![], + address_table_lookups: None, + }; + let ui_transaction = UiTransaction { + signatures: vec![signature.to_string()], + message: UiMessage::Raw(ui_raw_message), + }; + let transaction_status_meta = UiTransactionStatusMeta { + err: Some(TransactionError::AccountNotFound), + status: Err(TransactionError::AccountNotFound), + fee: 0, + pre_balances: vec![], + post_balances: vec![], + inner_instructions: OptionSerializer::None, + log_messages: OptionSerializer::None, + pre_token_balances: OptionSerializer::None, + post_token_balances: OptionSerializer::None, + rewards: OptionSerializer::None, + loaded_addresses: OptionSerializer::None, + return_data: OptionSerializer::None, + compute_units_consumed: OptionSerializer::None, + }; + let transaction = EncodedTransactionWithStatusMeta { + transaction: EncodedTransaction::Json(ui_transaction), + meta: Some(transaction_status_meta), + version: None, + }; + + let result = from_encoded_transaction( + &transaction, + 123, + &ProgramsSelector::new_all_programs(), + ) + .unwrap(); + + assert_eq!(result.len(), 0); + // You might want to add more assertions here to check the error handling + } + } From fd36badc02a32fa83722de765d8046c90b13af70 Mon Sep 17 00:00:00 2001 From: waggins Date: Sun, 13 Oct 2024 13:46:07 -0400 Subject: [PATCH 3/7] Update logs and Dockerfiles; bump crate version to 0.2.0 Refactored log generation to use `to_string` for consistency and added new log entries. Upgraded Dockerfiles to use Rust 1.81.0, ensuring compatibility with newer Rust features. Updated crate version in Cargo.toml indicating significant changes and improvements. --- Dockerfile-logstash | 2 +- Dockerfile-otel | 2 +- sologger-log-context/Cargo.toml | 2 +- .../benches/log_context_benchmarks.rs | 19 ++++++++++++------- 4 files changed, 15 insertions(+), 10 deletions(-) diff --git a/Dockerfile-logstash b/Dockerfile-logstash index 08c7669..c101334 100644 --- a/Dockerfile-logstash +++ b/Dockerfile-logstash @@ -7,7 +7,7 @@ ################################################################################ # Create a stage for building the application. -ARG RUST_VERSION=1.77.0 +ARG RUST_VERSION=1.81.0 ARG APP_NAME=sologger FROM rust:${RUST_VERSION}-slim-bookworm AS build ARG APP_NAME diff --git a/Dockerfile-otel b/Dockerfile-otel index d88eb04..d72c332 100644 --- a/Dockerfile-otel +++ b/Dockerfile-otel @@ -7,7 +7,7 @@ ################################################################################ # Create a stage for building the application. -ARG RUST_VERSION=1.77.0 +ARG RUST_VERSION=1.81.0 ARG APP_NAME=sologger FROM rust:${RUST_VERSION}-slim-bookworm AS build ARG APP_NAME diff --git a/sologger-log-context/Cargo.toml b/sologger-log-context/Cargo.toml index ee33c0d..b64a73a 100644 --- a/sologger-log-context/Cargo.toml +++ b/sologger-log-context/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "sologger_log_context" -version = "0.1.2" +version = "0.2.0" edition = "2021" authors = ["Will Kennedy"] description = "Provides functionality to turn raw logs output by Solana RPCs into structured logs for specified program IDs" diff --git a/sologger-log-context/benches/log_context_benchmarks.rs b/sologger-log-context/benches/log_context_benchmarks.rs index e9ed640..3bf3ffd 100644 --- a/sologger-log-context/benches/log_context_benchmarks.rs +++ b/sologger-log-context/benches/log_context_benchmarks.rs @@ -5,13 +5,18 @@ use sologger_log_context::sologger_log_context::LogContext; fn generate_sample_logs(n: usize) -> Vec { let mut logs = Vec::with_capacity(n); for i in 0..n { - logs.push(format!("Program 9RX7oz3WN5VRTqekBBHBvEJFVMNRnrCmVy7S6B6S5oU7 invoke [1]")); - logs.push(format!("Program log: Instruction: Initialize {}", i)); - logs.push(format!("Program 11111111111111111111111111111111 invoke [2]")); - logs.push(format!("Program 11111111111111111111111111111111 success")); - logs.push(format!("Program log: Initialized new event. Current value {}", i)); - logs.push(format!("Program 9RX7oz3WN5VRTqekBBHBvEJFVMNRnrCmVy7S6B6S5oU7 consumed 59783 of 200000 compute units")); - logs.push(format!("Program 9RX7oz3WN5VRTqekBBHBvEJFVMNRnrCmVy7S6B6S5oU7 success")); + logs.push("Program 9RX7oz3WN5VRTqekBBHBvEJFVMNRnrCmVy7S6B6S5oU7 invoke [1]".to_string()); + logs.push("Program log: Instruction: Initialize".to_string()); + logs.push("Program 11111111111111111111111111111111 invoke [2]".to_string()); + logs.push("Program 11111111111111111111111111111111 success".to_string()); + logs.push("Program log: Initialized new event. Current value".to_string()); + logs.push("Program 9RX7oz3WN5VRTqekBBHBvEJFVMNRnrCmVy7S6B6S5oU7 consumed 59783 of 200000 compute units".to_string()); + logs.push("Program 9RX7oz3WN5VRTqekBBHBvEJFVMNRnrCmVy7S6B6S5oU7 success".to_string()); + logs.push("Program AbcdefGPvbdGVxr1b2hvZbsiqW5xWH25efTNsLJA8knL invoke [1]".to_string()); + logs.push("Program log: Create".to_string()); + logs.push("Program AbcdefGPvbdGVxr1b2hvZbsiqW5xWH25efTNsLJA8knL consumed 5475 of 200000 compute units".to_string()); + logs.push("Program failed to complete: Invoked an instruction with data that is too large (12178014311288245306 > 10240)".to_string()); + logs.push("Program AbcdefGPvbdGVxr1b2hvZbsiqW5xWH25efTNsLJA8knL failed: Program failed to complete".to_string()); } logs } From a9a2aaa22a78fa8ba67a28950bce49b0a952b756 Mon Sep 17 00:00:00 2001 From: waggins Date: Sun, 13 Oct 2024 13:48:37 -0400 Subject: [PATCH 4/7] Upgrade dependencies and bump version to 0.2.0 Updated 'sologger_log_context' and 'criterion' dependencies to newer versions. This change necessitated incrementing the package version to 0.2.0, reflecting significant updates. --- sologger-log-transformer/Cargo.toml | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/sologger-log-transformer/Cargo.toml b/sologger-log-transformer/Cargo.toml index d1f5b6d..e34bd1f 100644 --- a/sologger-log-transformer/Cargo.toml +++ b/sologger-log-transformer/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "sologger_log_transformer" -version = "0.1.4" +version = "0.2.0" edition = "2021" authors = ["Will Kennedy"] description = "Provides utility to extract logs from various Solana API structs, such as blocks, transactions and responses." @@ -20,10 +20,10 @@ solana-rpc-client = "2.0.13" solana-rpc-client-api = "2.0.13" solana-transaction-status = "2.0.13" solana-sdk = "2.0.13" -sologger_log_context = {path = "../sologger-log-context"} +sologger_log_context = "0.2.0" [dev-dependencies] -criterion = "0.3" +criterion = "0.5.1" [[bench]] name = "log_context_transformer_benchmarks" From 8a14d5e5b435bc4dc8c455c2aedcdecf661b106e Mon Sep 17 00:00:00 2001 From: waggins Date: Sun, 13 Oct 2024 13:50:48 -0400 Subject: [PATCH 5/7] Update version to 0.2.0 in Cargo.toml Bump the version number to reflect significant updates or changes. This prepares the crate for new features or important fixes, indicating a major step forward from the previous version. --- sologger-log-transport/Cargo.toml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sologger-log-transport/Cargo.toml b/sologger-log-transport/Cargo.toml index 1d0dd89..e24f186 100644 --- a/sologger-log-transport/Cargo.toml +++ b/sologger-log-transport/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "sologger_log_transport" -version = "0.1.2" +version = "0.2.0" edition = "2021" authors = ["Will Kennedy"] description = "Provides support for both LogStash and OpenTelemetry exports for logs." From bbe780ddab5950e5f54e145d0c34730942c32c45 Mon Sep 17 00:00:00 2001 From: waggins Date: Sun, 13 Oct 2024 13:54:56 -0400 Subject: [PATCH 6/7] Update version to 0.2.0 and use external crate dependencies Incrementing the version to 0.2.0 reflects significant changes. Migrated dependencies from local paths to specified external crate versions, ensuring consistency and simplifying maintenance. --- sologger/Cargo.toml | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/sologger/Cargo.toml b/sologger/Cargo.toml index fb016ba..670e708 100644 --- a/sologger/Cargo.toml +++ b/sologger/Cargo.toml @@ -1,6 +1,6 @@ [package] name = "sologger" -version = "0.1.3" +version = "0.2.0" edition = "2021" authors = ["Will Kennedy"] description = "Configurable standalone service to parse raw logs emitted from a Solana RPC into structured logs and transport Solana logs to either a LogStash or OpenTelemetry endpoint via TCP" @@ -27,9 +27,9 @@ regex = "1.11.0" solana-pubsub-client = { version = "2.0.13", optional = true } solana-rpc-client-api = { version = "2.0.13", optional = true } solana-sdk = { version = "2.0.13", optional = true } -sologger_log_context = {path = "../sologger-log-context"} -sologger_log_transformer = {path = "../sologger-log-transformer"} -sologger_log_transport = { path="../sologger-log-transport", features = ["otel", "logstash"]} +sologger_log_context = "0.2.0" +sologger_log_transformer = "0.2.0" +sologger_log_transport = "0.2.0" tokio = { version = "1.40.0", features = ["full"] } tokio-metrics = { version = "0.3.1", optional = true} tokio-rustls = "0.24.1" From 53fbd6e5bf31cf8e6e24a4ba7ae26982ecc3eb86 Mon Sep 17 00:00:00 2001 From: waggins Date: Sun, 13 Oct 2024 14:10:41 -0400 Subject: [PATCH 7/7] Update Dockerfile bindings and add conditional otel import Updated the Dockerfile to correct the config bindings, ensuring all necessary directories are mounted correctly. Additionally, made the opentelemetry import conditional to only include it when the "enable_otel" feature is active. --- Dockerfile-logstash | 3 ++- sologger/src/logger_lib.rs | 3 ++- 2 files changed, 4 insertions(+), 2 deletions(-) diff --git a/Dockerfile-logstash b/Dockerfile-logstash index c101334..428455d 100644 --- a/Dockerfile-logstash +++ b/Dockerfile-logstash @@ -26,7 +26,8 @@ RUN --mount=type=bind,source=sologger-log-context,target=sologger-log-context \ --mount=type=bind,source=sologger,target=sologger \ --mount=type=bind,source=Cargo.toml,target=Cargo.toml \ --mount=type=bind,source=Cargo.lock,target=Cargo.lock \ - --mount=type=bind,source=config/docker,target=config/docker \ + --mount=type=bind,source=config/docker/,target=config \ + --mount=type=bind,source=config,target=config \ --mount=type=cache,target=/app/target/ \ --mount=type=cache,target=/usr/local/cargo/registry/ \ <