This commit is contained in:
John Smith 2022-06-11 18:47:58 -04:00
parent 3f7dfa6c6a
commit bcc1bfc1a3
13 changed files with 1244 additions and 498 deletions

1416
Cargo.lock generated

File diff suppressed because it is too large Load Diff

25
scripts/jaeger.sh Executable file
View File

@ -0,0 +1,25 @@
#!/bin/bash
# ensure adb is installed
if command -v docker &> /dev/null; then
echo '[X] docker is available in the path'
else
echo 'docker is not available in the path'
exit 1
fi
# pull jaeger
echo pulling Jaeger
docker pull jaegertracing/all-in-one:1.35
# run jaeger
echo running Jaeger
docker run -d --name jaeger \
-p 16686:16686 \
-p 4317:4317 \
jaegertracing/all-in-one:1.35 --collector.otlp.enabled=true $@
read -p "Press [Enter] key to stop jaeger"
docker stop jaeger
docker rm jaeger

View File

@ -10,6 +10,7 @@ cfg_if! {
if #[cfg(target_arch = "wasm32")] { if #[cfg(target_arch = "wasm32")] {
pub type UpdateCallback = Arc<dyn Fn(VeilidUpdate)>; pub type UpdateCallback = Arc<dyn Fn(VeilidUpdate)>;
} else { } else {
pub type UpdateCallback = Arc<dyn Fn(VeilidUpdate) + Send + Sync>; pub type UpdateCallback = Arc<dyn Fn(VeilidUpdate) + Send + Sync>;
} }
} }
@ -195,7 +196,7 @@ impl VeilidCoreContext {
Self::new_common(update_callback, config).await Self::new_common(update_callback, config).await
} }
#[instrument(err, skip(update_callback))] #[instrument(err, skip_all)]
async fn new_with_config_json( async fn new_with_config_json(
update_callback: UpdateCallback, update_callback: UpdateCallback,
config_json: String, config_json: String,
@ -209,7 +210,7 @@ impl VeilidCoreContext {
Self::new_common(update_callback, config).await Self::new_common(update_callback, config).await
} }
#[instrument(err, skip(update_callback))] #[instrument(err, skip_all)]
async fn new_common( async fn new_common(
update_callback: UpdateCallback, update_callback: UpdateCallback,
config: VeilidConfig, config: VeilidConfig,

View File

@ -2,7 +2,7 @@ use super::key::*;
use crate::intf::*; use crate::intf::*;
use crate::xx::*; use crate::xx::*;
use crate::*; use crate::*;
use chacha20::cipher::{NewCipher, StreamCipher}; use chacha20::cipher::{KeyIvInit, StreamCipher};
use chacha20::XChaCha20; use chacha20::XChaCha20;
use chacha20poly1305 as ch; use chacha20poly1305 as ch;
use chacha20poly1305::aead::{AeadInPlace, NewAead}; use chacha20poly1305::aead::{AeadInPlace, NewAead};

View File

@ -481,7 +481,7 @@ impl Network {
self.inner.lock().network_started = true; self.inner.lock().network_started = true;
// Inform routing table entries that our dial info has changed // Inform routing table entries that our dial info has changed
self.routing_table().send_node_info_updates(); self.routing_table().send_node_info_updates().await;
Ok(()) Ok(())
} }

View File

@ -618,7 +618,7 @@ impl Network {
log_net!(debug "network class changed to {:?}", network_class); log_net!(debug "network class changed to {:?}", network_class);
// Send updates to everyone // Send updates to everyone
routing_table.send_node_info_updates(); routing_table.send_node_info_updates().await;
} }
Ok(()) Ok(())

View File

@ -399,75 +399,73 @@ impl RoutingTable {
} }
// Inform routing table entries that our dial info has changed // Inform routing table entries that our dial info has changed
pub fn send_node_info_updates(&self) { pub async fn send_node_info_updates(&self) {
let this = self.clone(); let this = self.clone();
// Run in background // Run in background only once
intf::spawn(async move { let _ = self
// Run in background only once .clone()
this.clone() .unlocked_inner
.unlocked_inner .node_info_update_single_future
.node_info_update_single_future .single_spawn(async move {
.single_spawn(async move { // Only update if we actually have a valid network class
let netman = this.network_manager();
if matches!(
netman.get_network_class().unwrap_or(NetworkClass::Invalid),
NetworkClass::Invalid
) {
trace!(
"not sending node info update because our network class is not yet valid"
);
return;
}
// Only update if we actually have a valid network class // Get the list of refs to all nodes to update
let netman = this.network_manager(); let node_refs = {
if matches!( let mut inner = this.inner.lock();
netman.get_network_class().unwrap_or(NetworkClass::Invalid), let mut node_refs = Vec::<NodeRef>::with_capacity(inner.bucket_entry_count);
NetworkClass::Invalid let cur_ts = intf::get_timestamp();
) { Self::with_entries(
trace!("not sending node info update because our network class is not yet valid"); &mut *inner,
return; cur_ts,
} BucketEntryState::Unreliable,
|k, e| {
// Get the list of refs to all nodes to update
let node_refs = {
let mut inner = this.inner.lock();
let mut node_refs = Vec::<NodeRef>::with_capacity(inner.bucket_entry_count);
let cur_ts = intf::get_timestamp();
Self::with_entries(&mut *inner, cur_ts, BucketEntryState::Unreliable, |k, e| {
// Only update nodes that haven't seen our node info yet // Only update nodes that haven't seen our node info yet
if !e.has_seen_our_node_info() { if !e.has_seen_our_node_info() {
node_refs.push(NodeRef::new( node_refs.push(NodeRef::new(this.clone(), *k, e, None));
this.clone(),
*k,
e,
None,
));
} }
Option::<()>::None Option::<()>::None
}); },
node_refs );
}; node_refs
};
// Send the updates // Send the updates
log_rtab!("Sending node info updates to {} nodes", node_refs.len()); log_rtab!("Sending node info updates to {} nodes", node_refs.len());
let mut unord = FuturesUnordered::new(); let mut unord = FuturesUnordered::new();
for nr in node_refs { for nr in node_refs {
let rpc = this.rpc_processor(); let rpc = this.rpc_processor();
unord.push(async move { unord.push(async move {
// Update the node // Update the node
if let Err(e) = rpc if let Err(e) = rpc
.rpc_call_node_info_update(Destination::Direct(nr.clone()), None) .rpc_call_node_info_update(Destination::Direct(nr.clone()), None)
.await .await
{ {
// Not fatal, but we should be able to see if this is happening // Not fatal, but we should be able to see if this is happening
trace!("failed to send node info update to {:?}: {}", nr, e); trace!("failed to send node info update to {:?}: {}", nr, e);
return; return;
} }
// Mark the node as updated // Mark the node as updated
nr.set_seen_our_node_info(); nr.set_seen_our_node_info();
}); });
} }
// Wait for futures to complete // Wait for futures to complete
while unord.next().await.is_some() {} while unord.next().await.is_some() {}
log_rtab!("Finished sending node updates"); log_rtab!("Finished sending node updates");
}) })
.await .await;
})
.detach()
} }
// Attempt to empty the routing table // Attempt to empty the routing table
@ -1134,19 +1132,27 @@ impl RoutingTable {
let netman = self.network_manager(); let netman = self.network_manager();
let relay_node_id = netman.relay_node().map(|nr| nr.node_id()); let relay_node_id = netman.relay_node().map(|nr| nr.node_id());
let mut inner = self.inner.lock(); let mut unord = FuturesUnordered::new();
Self::with_entries(&mut *inner, cur_ts, BucketEntryState::Unreliable, |k, e| { {
if e.needs_ping(k, cur_ts, relay_node_id) { let mut inner = self.inner.lock();
let nr = NodeRef::new(self.clone(), *k, e, None);
log_rtab!( Self::with_entries(&mut *inner, cur_ts, BucketEntryState::Unreliable, |k, e| {
" --- ping validating: {:?} ({})", if e.needs_ping(k, cur_ts, relay_node_id) {
nr, let nr = NodeRef::new(self.clone(), *k, e, None);
e.state_debug_info(cur_ts) log_rtab!(
); " --- ping validating: {:?} ({})",
intf::spawn_local(rpc.clone().rpc_call_status(nr)).detach(); nr,
} e.state_debug_info(cur_ts)
Option::<()>::None );
}); unord.push(intf::spawn_local(rpc.clone().rpc_call_status(nr)));
}
Option::<()>::None
});
}
// Wait for futures to complete
while unord.next().await.is_some() {}
Ok(()) Ok(())
} }

View File

@ -14,6 +14,9 @@ path = "src/main.rs"
tracing = { version = "^0", features = ["log", "attributes"] } tracing = { version = "^0", features = ["log", "attributes"] }
tracing-subscriber = { version = "^0", features = ["env-filter"] } tracing-subscriber = { version = "^0", features = ["env-filter"] }
tracing-appender = "^0" tracing-appender = "^0"
tracing-opentelemetry = "^0"
opentelemetry = { version = "^0", features = ["rt-async-std"] }
opentelemetry-otlp = { version = "^0", features = ["grpc-sys"] }
clap = "^3" clap = "^3"
async-std = { version = "^1", features = ["unstable"] } async-std = { version = "^1", features = ["unstable"] }
async-tungstenite = { version = "^0", features = ["async-std-runtime", "async-tls"] } async-tungstenite = { version = "^0", features = ["async-std-runtime", "async-tls"] }

View File

@ -61,6 +61,14 @@ fn do_clap_matches(default_config_path: &OsStr) -> Result<clap::ArgMatches, clap
.conflicts_with("debug") .conflicts_with("debug")
.help("Turn on trace logging on the terminal"), .help("Turn on trace logging on the terminal"),
) )
.arg(
Arg::new("otlp")
.long("otlp")
.takes_value(true)
.value_name("endpoint")
.default_missing_value("http://localhost:4317")
.help("Turn on OpenTelemetry tracing"),
)
.arg( .arg(
Arg::new("subnode-index") Arg::new("subnode-index")
.long("subnode-index") .long("subnode-index")
@ -197,6 +205,19 @@ pub fn process_command_line() -> Result<(Settings, ArgMatches), String> {
settingsrw.logging.terminal.enabled = true; settingsrw.logging.terminal.enabled = true;
settingsrw.logging.terminal.level = LogLevel::Trace; settingsrw.logging.terminal.level = LogLevel::Trace;
} }
if matches.occurrences_of("otlp") != 0 {
settingsrw.logging.otlp.enabled = true;
settingsrw.logging.otlp.grpc_endpoint = Some(
ParsedUrl::from_str(
&matches
.value_of("otlp")
.expect("should not be null because of default missing value")
.to_string(),
)
.map_err(|e| format!("failed to parse OTLP url: {}", e))?,
);
settingsrw.logging.otlp.level = LogLevel::Trace;
}
if matches.is_present("attach") { if matches.is_present("attach") {
settingsrw.auto_attach = !matches!(matches.value_of("attach"), Some("true")); settingsrw.auto_attach = !matches!(matches.value_of("attach"), Some("true"));
} }

View File

@ -58,18 +58,21 @@ fn main() -> Result<(), String> {
// Handle non-normal server modes // Handle non-normal server modes
if !matches!(server_mode, ServerMode::Normal) { if !matches!(server_mode, ServerMode::Normal) {
// Init combined console/file logger
let _logs = VeilidLogs::setup(settings.clone())?;
// run the server to set the node id and quit // run the server to set the node id and quit
return task::block_on(async { run_veilid_server(settings, server_mode).await }) return task::block_on(async {
.map(|v| { // Init combined console/file logger
println!("{}", success); let _logs = VeilidLogs::setup(settings.clone())?;
v
}) run_veilid_server(settings, server_mode).await
.map_err(|e| { })
println!("{}", failure); .map(|v| {
e println!("{}", success);
}); v
})
.map_err(|e| {
println!("{}", failure);
e
});
} }
// --- Daemon Mode ---- // --- Daemon Mode ----
@ -83,9 +86,6 @@ fn main() -> Result<(), String> {
} }
} }
// Init combined console/file logger
let _logs = VeilidLogs::setup(settings.clone())?;
// --- Normal Startup --- // --- Normal Startup ---
ctrlc::set_handler(move || { ctrlc::set_handler(move || {
shutdown(); shutdown();
@ -93,5 +93,10 @@ fn main() -> Result<(), String> {
.expect("Error setting Ctrl-C handler"); .expect("Error setting Ctrl-C handler");
// Run the server loop // Run the server loop
task::block_on(async { run_veilid_server(settings, server_mode).await }) task::block_on(async {
// Init combined console/file logger
let _logs = VeilidLogs::setup(settings.clone())?;
run_veilid_server(settings, server_mode).await
})
} }

View File

@ -36,6 +36,10 @@ logging:
api: api:
enabled: false enabled: false
level: 'info' level: 'info'
otlp:
enabled: false
level: 'trace'
grpc_endpoint: 'http://localhost:4317'
testing: testing:
subnode_index: 0 subnode_index: 0
core: core:
@ -427,6 +431,13 @@ pub struct Api {
pub level: LogLevel, pub level: LogLevel,
} }
#[derive(Debug, Deserialize, Serialize)]
pub struct Otlp {
pub enabled: bool,
pub level: LogLevel,
pub grpc_endpoint: Option<ParsedUrl>,
}
#[derive(Debug, Deserialize, Serialize)] #[derive(Debug, Deserialize, Serialize)]
pub struct ClientApi { pub struct ClientApi {
pub enabled: bool, pub enabled: bool,
@ -439,6 +450,7 @@ pub struct Logging {
pub terminal: Terminal, pub terminal: Terminal,
pub file: File, pub file: File,
pub api: Api, pub api: Api,
pub otlp: Otlp,
} }
#[derive(Debug, Deserialize, Serialize)] #[derive(Debug, Deserialize, Serialize)]
@ -889,6 +901,9 @@ impl Settings {
set_config_value!(inner.logging.file.level, value); set_config_value!(inner.logging.file.level, value);
set_config_value!(inner.logging.api.enabled, value); set_config_value!(inner.logging.api.enabled, value);
set_config_value!(inner.logging.api.level, value); set_config_value!(inner.logging.api.level, value);
set_config_value!(inner.logging.otlp.enabled, value);
set_config_value!(inner.logging.otlp.level, value);
set_config_value!(inner.logging.otlp.grpc_endpoint, value);
set_config_value!(inner.testing.subnode_index, value); set_config_value!(inner.testing.subnode_index, value);
set_config_value!(inner.core.protected_store.allow_insecure_fallback, value); set_config_value!(inner.core.protected_store.allow_insecure_fallback, value);
set_config_value!( set_config_value!(
@ -1404,6 +1419,12 @@ mod tests {
assert_eq!(s.logging.file.level, LogLevel::Info); assert_eq!(s.logging.file.level, LogLevel::Info);
assert_eq!(s.logging.api.enabled, false); assert_eq!(s.logging.api.enabled, false);
assert_eq!(s.logging.api.level, LogLevel::Info); assert_eq!(s.logging.api.level, LogLevel::Info);
assert_eq!(s.logging.otlp.enabled, false);
assert_eq!(s.logging.otlp.level, LogLevel::Trace);
assert_eq!(
s.logging.otlp.grpc_endpoint,
Some(ParsedUrl::from_str("http://127.0.0.1:4317").unwrap())
);
assert_eq!(s.testing.subnode_index, 0); assert_eq!(s.testing.subnode_index, 0);
assert_eq!( assert_eq!(

View File

@ -95,16 +95,16 @@ pub fn run_daemon(settings: Settings, _matches: ArgMatches) -> Result<(), String
daemon daemon
}; };
// Init combined console/file logger
let _logs = VeilidLogs::setup(settings.clone())?;
// Daemonize
daemon
.start()
.map_err(|e| format!("Failed to daemonize: {}", e))?;
// Now, run the server // Now, run the server
task::block_on(async { task::block_on(async {
// Init combined console/file logger
let _logs = VeilidLogs::setup(settings.clone())?;
// Daemonize
daemon
.start()
.map_err(|e| format!("Failed to daemonize: {}", e))?;
// Catch signals // Catch signals
let signals = Signals::new(&[SIGHUP, SIGTERM, SIGINT, SIGQUIT]) let signals = Signals::new(&[SIGHUP, SIGTERM, SIGINT, SIGQUIT])
.map_err(|e| format!("failed to init signals: {}", e))?; .map_err(|e| format!("failed to init signals: {}", e))?;

View File

@ -1,5 +1,6 @@
use crate::settings::*; use crate::settings::*;
use cfg_if::*; use cfg_if::*;
use opentelemetry_otlp::WithExportConfig;
use std::path::*; use std::path::*;
use tracing::*; use tracing::*;
use tracing_appender::*; use tracing_appender::*;
@ -34,6 +35,7 @@ impl VeilidLogs {
let subscriber = Registry::default(); let subscriber = Registry::default();
// Terminal logger
let subscriber = subscriber.with(if settingsr.logging.terminal.enabled { let subscriber = subscriber.with(if settingsr.logging.terminal.enabled {
let terminal_max_log_level: level_filters::LevelFilter = let terminal_max_log_level: level_filters::LevelFilter =
convert_loglevel(settingsr.logging.terminal.level) convert_loglevel(settingsr.logging.terminal.level)
@ -53,6 +55,46 @@ impl VeilidLogs {
None None
}); });
// OpenTelemetry logger
let subscriber = subscriber.with(if settingsr.logging.otlp.enabled {
let otlp_max_log_level: level_filters::LevelFilter =
convert_loglevel(settingsr.logging.otlp.level)
.to_tracing_level()
.into();
let grpc_endpoint = match &settingsr.logging.otlp.grpc_endpoint {
Some(v) => &v.urlstring,
None => {
return Err("missing OTLP GRPC endpoint url".to_owned());
}
};
// Required for GRPC dns resolution to work
std::env::set_var("GRPC_DNS_RESOLVER", "native");
let tracer = opentelemetry_otlp::new_pipeline()
.tracing()
.with_exporter(
opentelemetry_otlp::new_exporter()
.grpcio()
.with_endpoint(grpc_endpoint),
)
.install_batch(opentelemetry::runtime::AsyncStd)
.map_err(|e| format!("failed to install OpenTelemetry tracer: {}", e))?;
let ignore_list = ignore_list.clone();
Some(
tracing_opentelemetry::layer()
.with_tracer(tracer)
.with_filter(otlp_max_log_level)
.with_filter(filter::FilterFn::new(move |metadata| {
logfilter(metadata, &ignore_list)
})),
)
} else {
None
});
// File logger
let mut guard = None; let mut guard = None;
let subscriber = subscriber.with(if settingsr.logging.file.enabled { let subscriber = subscriber.with(if settingsr.logging.file.enabled {
let file_max_log_level: level_filters::LevelFilter = let file_max_log_level: level_filters::LevelFilter =
@ -98,6 +140,7 @@ impl VeilidLogs {
None None
}); });
// API logger
let subscriber = subscriber.with(if settingsr.logging.api.enabled { let subscriber = subscriber.with(if settingsr.logging.api.enabled {
// Get layer from veilid core, filtering is done by ApiTracingLayer automatically // Get layer from veilid core, filtering is done by ApiTracingLayer automatically
Some(veilid_core::ApiTracingLayer::get()) Some(veilid_core::ApiTracingLayer::get())
@ -105,6 +148,7 @@ impl VeilidLogs {
None None
}); });
// Systemd Journal logger
cfg_if! { cfg_if! {
if #[cfg(target_os = "linux")] { if #[cfg(target_os = "linux")] {
let subscriber = subscriber.with(if settingsr.logging.system.enabled { let subscriber = subscriber.with(if settingsr.logging.system.enabled {