diff --git a/aya-log/.gitignore b/aya-log/.gitignore new file mode 100644 index 00000000..54f741e1 --- /dev/null +++ b/aya-log/.gitignore @@ -0,0 +1,13 @@ +### https://raw.github.com/github/gitignore/master/Rust.gitignore + +# Generated by Cargo +# will have compiled files and executables +debug/ +target/ + +# Remove Cargo.lock from gitignore if creating an executable, leave it for libraries +# More information here https://doc.rust-lang.org/cargo/guide/cargo-toml-vs-cargo-lock.html +Cargo.lock + +# These are backup files generated by rustfmt +**/*.rs.bk diff --git a/aya-log/Cargo.toml b/aya-log/Cargo.toml new file mode 100644 index 00000000..a8e5e117 --- /dev/null +++ b/aya-log/Cargo.toml @@ -0,0 +1,2 @@ +[workspace] +members = ["aya-log", "aya-log-common", "xtask"] diff --git a/aya-log/aya-log-common/Cargo.toml b/aya-log/aya-log-common/Cargo.toml new file mode 100644 index 00000000..ff6a3944 --- /dev/null +++ b/aya-log/aya-log-common/Cargo.toml @@ -0,0 +1,14 @@ +[package] +name = "aya-log-common" +version = "0.1.0" +edition = "2018" + +[features] +default = [] +userspace = [ "aya" ] + +[dependencies] +aya = { git = "https://github.com/aya-rs/aya", branch="main", optional=true } + +[lib] +path = "src/lib.rs" \ No newline at end of file diff --git a/aya-log/aya-log-common/src/lib.rs b/aya-log/aya-log-common/src/lib.rs new file mode 100644 index 00000000..837bdbbf --- /dev/null +++ b/aya-log/aya-log-common/src/lib.rs @@ -0,0 +1,44 @@ +#![no_std] + +pub const LOG_BUF_CAPACITY: usize = 1024; + +pub const LOG_FIELDS: usize = 6; + +#[repr(usize)] +#[derive(Copy, Clone, Eq, PartialEq, Debug, Hash)] +pub enum Level { + /// The "error" level. + /// + /// Designates very serious errors. + Error = 1, + /// The "warn" level. + /// + /// Designates hazardous situations. + Warn, + /// The "info" level. + /// + /// Designates useful information. + Info, + /// The "debug" level. + /// + /// Designates lower priority information. + Debug, + /// The "trace" level. + /// + /// Designates very low priority, often extremely verbose, information. + Trace, +} + +#[repr(usize)] +#[derive(Copy, Clone, Debug)] +pub enum RecordField { + Target = 1, + Level, + Module, + File, + Line, + Log, +} + +#[cfg(feature = "userspace")] +unsafe impl aya::Pod for RecordField {} diff --git a/aya-log/aya-log-ebpf/.cargo/config.toml b/aya-log/aya-log-ebpf/.cargo/config.toml new file mode 100644 index 00000000..5d7e5915 --- /dev/null +++ b/aya-log/aya-log-ebpf/.cargo/config.toml @@ -0,0 +1,6 @@ +[build] +target-dir = "../target" +target = "bpfel-unknown-none" + +[unstable] +build-std = ["core"] \ No newline at end of file diff --git a/aya-log/aya-log-ebpf/Cargo.toml b/aya-log/aya-log-ebpf/Cargo.toml new file mode 100644 index 00000000..c005d22b --- /dev/null +++ b/aya-log/aya-log-ebpf/Cargo.toml @@ -0,0 +1,24 @@ +[package] +name = "aya-log-ebpf" +version = "0.1.0" +edition = "2018" + +[dependencies] +aya-bpf = { git = "https://github.com/aya-rs/aya", branch = "main" } +aya-log-common = { path = "../aya-log-common" } +ufmt = "0.1.0" + +[lib] +path = "src/lib.rs" + +[profile.dev] +panic = "abort" +debug = 1 +opt-level = 2 +overflow-checks = false + +[profile.release] +panic = "abort" + +[workspace] +members = [] \ No newline at end of file diff --git a/aya-log/aya-log-ebpf/src/lib.rs b/aya-log/aya-log-ebpf/src/lib.rs new file mode 100644 index 00000000..2b361e40 --- /dev/null +++ b/aya-log/aya-log-ebpf/src/lib.rs @@ -0,0 +1,170 @@ +#![no_std] + +mod macros; + +use core::{cmp, mem, ptr}; + +use aya_bpf::{ + bindings::{bpf_map_def, bpf_map_type::BPF_MAP_TYPE_PERF_EVENT_ARRAY, BPF_F_CURRENT_CPU}, + cty::c_long, + helpers::bpf_perf_event_output, + macros::map, + maps::PerCpuArray, + BpfContext, +}; +pub use aya_log_common::Level; +use aya_log_common::{RecordField, LOG_BUF_CAPACITY}; + +#[doc(hidden)] +#[repr(C)] +pub struct LogBuf { + pub buf: [u8; LOG_BUF_CAPACITY], +} + +#[doc(hidden)] +#[map] +pub static mut AYA_LOG_BUF: PerCpuArray = PerCpuArray::with_max_entries(1, 0); + +#[doc(hidden)] +#[map] +pub static mut AYA_LOGS: LogEventArray = LogEventArray::with_max_entries(1024, 0); + +#[doc(hidden)] +pub struct LogBufWriter<'a> { + pos: usize, + data: &'a mut [u8], +} + +impl<'a> LogBufWriter<'a> { + pub fn new(data: &mut [u8]) -> LogBufWriter<'_> { + LogBufWriter { + pos: mem::size_of::() + mem::size_of::(), + data, + } + } + + pub fn finish(self) -> usize { + let mut buf = self.data; + unsafe { ptr::write_unaligned(buf.as_mut_ptr() as *mut _, RecordField::Log) }; + buf = &mut buf[mem::size_of::()..]; + + let len = self.pos - mem::size_of::() - mem::size_of::(); + unsafe { ptr::write_unaligned(buf.as_mut_ptr() as *mut _, len) }; + + self.pos + } +} + +impl<'a> ufmt::uWrite for LogBufWriter<'a> { + type Error = (); + + fn write_str(&mut self, s: &str) -> Result<(), Self::Error> { + let bytes = s.as_bytes(); + let len = bytes.len(); + let available = self.data.len() - self.pos; + if available < len { + return Err(()); + } + + self.data[self.pos..self.pos + len].copy_from_slice(bytes); + self.pos += len; + Ok(()) + } +} + +struct TagLenValue<'a> { + tag: RecordField, + value: &'a [u8], +} + +impl<'a> TagLenValue<'a> { + #[inline(always)] + pub(crate) fn new(tag: RecordField, value: &'a [u8]) -> TagLenValue<'a> { + TagLenValue { tag, value } + } + + pub(crate) fn try_write(&self, mut buf: &mut [u8]) -> Result { + let size = mem::size_of::() + mem::size_of::() + self.value.len(); + if buf.len() < size { + return Err(()); + } + + unsafe { ptr::write_unaligned(buf.as_mut_ptr() as *mut _, self.tag) }; + buf = &mut buf[mem::size_of::()..]; + + unsafe { ptr::write_unaligned(buf.as_mut_ptr() as *mut _, self.value.len()) }; + buf = &mut buf[mem::size_of::()..]; + + let len = cmp::min(buf.len(), self.value.len()); + buf[..len].copy_from_slice(&self.value[..len]); + Ok(size) + } +} + +#[doc(hidden)] +pub fn write_record_header( + buf: &mut [u8], + target: &str, + level: Level, + module: &str, + file: &str, + line: u32, +) -> Result { + let mut size = 0; + for attr in [ + TagLenValue::new(RecordField::Target, target.as_bytes()), + TagLenValue::new(RecordField::Level, &(level as usize).to_ne_bytes()), + TagLenValue::new(RecordField::Module, module.as_bytes()), + TagLenValue::new(RecordField::File, file.as_bytes()), + TagLenValue::new(RecordField::Line, &line.to_ne_bytes()), + ] { + size += attr.try_write(&mut buf[size..])?; + } + + Ok(size) +} + +#[doc(hidden)] +#[repr(transparent)] +pub struct LogEventArray { + def: bpf_map_def, +} + +impl LogEventArray { + const fn with_max_entries(max_entries: u32, flags: u32) -> LogEventArray { + LogEventArray { + def: bpf_map_def { + type_: BPF_MAP_TYPE_PERF_EVENT_ARRAY, + key_size: mem::size_of::() as u32, + value_size: mem::size_of::() as u32, + max_entries, + map_flags: flags, + id: 0, + pinning: 0, + }, + } + } + + #[inline(always)] + pub fn output( + &mut self, + ctx: &C, + buf: &mut LogBuf, + len: usize, + ) -> Result<(), c_long> { + let ret = unsafe { + bpf_perf_event_output( + ctx.as_ptr(), + &mut self.def as *mut _ as *mut _, + BPF_F_CURRENT_CPU, + buf.buf.as_mut_ptr() as *mut _, + len as u64, + ) + }; + if ret < 0 { + Err(ret) + } else { + Ok(()) + } + } +} diff --git a/aya-log/aya-log-ebpf/src/macros.rs b/aya-log/aya-log-ebpf/src/macros.rs new file mode 100644 index 00000000..e982f67e --- /dev/null +++ b/aya-log/aya-log-ebpf/src/macros.rs @@ -0,0 +1,201 @@ +/// Logs a message at the error level. +/// +/// # Examples +/// +/// ```no_run +/// # let ctx = (); +/// # let err_code = -1; +/// use aya_log_ebpf::error; +/// +/// error!(&ctx, "Error redirecting packet: {}", err_code); +/// error!(&ctx, target: "ingress", "Error redirecting packet: {}", err_code); +/// ``` +#[macro_export] +macro_rules! error { + ($ctx:expr, target: $target:expr, $($arg:tt)+) => ( + $crate::log!($ctx, target: $target, $crate::Level::Error, $($arg)+) + ); + ($ctx:expr, $($arg:tt)+) => ( + $crate::log!($ctx, $crate::Level::Error, $($arg)+) + ) +} + +/// Logs a message at the warn level. +/// +/// # Examples +/// +/// ``` +/// use aya_log_ebpf::warn; +/// +/// # fn main() { +/// let warn_description = "Invalid Input"; +/// +/// warn!("Warning! {}!", warn_description); +/// warn!(target: "input_events", "App received warning: {}", warn_description); +/// # } +/// ``` +#[macro_export] +macro_rules! warn { + ($ctx:expr, target: $target:expr, $($arg:tt)+) => ( + $crate::log!($ctx, target: $target, $crate::Level::Warn, $($arg)+) + ); + ($ctx:expr, $($arg:tt)+) => ( + $crate::log!($ctx, $crate::Level::Warn, $($arg)+) + ) +} + +/// Logs a message at the info level. +/// +/// # Examples +/// +/// ```edition2018 +/// use log::info; +/// +/// # fn main() { +/// # struct Connection { port: u32, speed: u32 } +/// let conn_info = Connection { port: 40, speed: 3 }; +/// +/// info!("Connected to port {} at {} Mb/s", conn_info.port, conn_info.speed); +/// info!(target: "connection_events", "Successfull connection, port: {}, speed: {}", +/// conn_info.port, conn_info.speed); +/// # } +/// ``` +#[macro_export] +macro_rules! info { + ($ctx:expr, target: $target:expr, $($arg:tt)+) => ( + $crate::log!($ctx, target: $target, $crate::Level::Info, $($arg)+) + ); + ($ctx:expr, $($arg:tt)+) => ( + $crate::log!($ctx, $crate::Level::Info, $($arg)+) + ) +} + +/// Logs a message at the debug level. +/// +/// # Examples +/// +/// ```edition2018 +/// use log::debug; +/// +/// # fn main() { +/// # struct Position { x: i64, y: i64 } +/// let pos = Position { x: 3.234, y: -1223 }; +/// +/// debug!("New position: x: {}, y: {}", pos.x, pos.y); +/// debug!(target: "app_events", "New position: x: {}, y: {}", pos.x, pos.y); +/// # } +/// ``` +#[macro_export] +macro_rules! debug { + ($ctx:expr, target: $target:expr, $($arg:tt)+) => ( + $crate::log!($ctx, target: $target, $crate::Level::Debug, $($arg)+) + ); + ($ctx:expr, $($arg:tt)+) => ( + $crate::log!($ctx, $crate::Level::Debug, $($arg)+) + ) +} + +/// Logs a message at the trace level. +/// +/// # Examples +/// +/// ```edition2018 +/// use log::trace; +/// +/// # fn main() { +/// # struct Position { x: i64, y: i64 } +/// let pos = Position { x: 3234, y: -1223 }; +/// +/// trace!("Position is: x: {}, y: {}", pos.x, pos.y); +/// trace!(target: "app_events", "x is {} and y is {}", +/// if pos.x >= 0 { "positive" } else { "negative" }, +/// if pos.y >= 0 { "positive" } else { "negative" }); +/// # } +/// ``` +#[macro_export] +macro_rules! trace { + ($ctx:expr, target: $target:expr, $($arg:tt)+) => ( + $crate::log!($ctx, target: $target, $crate::Level::Trace, $($arg)+) + ); + ($ctx:expr, $($arg:tt)+) => ( + $crate::log!($ctx, $crate::Level::Trace, $($arg)+) + ) +} + +// /// Determines if a message logged at the specified level in that module will +// /// be logged. +// /// +// /// This can be used to avoid expensive computation of log message arguments if +// /// the message would be ignored anyway. +// /// +// /// # Examples +// /// +// /// ```edition2018 +// /// use log::Level::Debug; +// /// use log::{debug, log_enabled}; +// /// +// /// # fn foo() { +// /// if log_enabled!(Debug) { +// /// let data = expensive_call(); +// /// debug!("expensive debug data: {} {}", data.x, data.y); +// /// } +// /// if log_enabled!(target: "Global", Debug) { +// /// let data = expensive_call(); +// /// debug!(target: "Global", "expensive debug data: {} {}", data.x, data.y); +// /// } +// /// # } +// /// # struct Data { x: u32, y: u32 } +// /// # fn expensive_call() -> Data { Data { x: 0, y: 0 } } +// /// # fn main() {} +// /// ``` +// macro_rules! log_enabled { +// (target: $target:expr, $lvl:expr) => {{ +// let lvl = $lvl; +// lvl <= $crate::STATIC_MAX_LEVEL +// }}; +// ($lvl:expr) => { +// log_enabled!(target: __log_module_path!(), $lvl) +// }; +// } + +/// Log a message at the given level. +/// +/// This macro will generically log with the specified `Level` and `format!` +/// based argument list. +/// +/// # Examples +/// +/// ```edition2018 +/// use log::{log, Level}; +/// +/// # fn main() { +/// let data = (42, "Forty-two"); +/// let private_data = "private"; +/// +/// log!(Level::Error, "Received errors: {}, {}", data.0, data.1); +/// log!(target: "app_events", Level::Warn, "App warning: {}, {}, {}", +/// data.0, data.1, private_data); +/// # } +/// ``` +#[macro_export] +macro_rules! log { + ($ctx:expr, target: $target:expr, $lvl:expr, $($arg:tt)+) => ({ + if let Some(buf) = unsafe { $crate::AYA_LOG_BUF.get_mut(0) } { + if let Ok(header_len) = $crate::write_record_header(&mut buf.buf, module_path!(), $lvl, module_path!(), file!(), line!()) { + if let Ok(message_len) = $crate::write_record_message!(&mut buf.buf[header_len..], $($arg)+) { + let _ = unsafe { $crate::AYA_LOGS.output($ctx, buf, header_len + message_len) }; + }; + } + } + }); + ($ctx:expr, $lvl:expr, $($arg:tt)+) => ($crate::log!($ctx, target: __log_module_path!(), $lvl, $($arg)+)) +} + +#[doc(hidden)] +#[macro_export] +macro_rules! write_record_message { + ($buf:expr, $($arg:tt)+) => {{ + let mut writer = $crate::LogBufWriter::new($buf); + ufmt::uwrite!(writer, $($arg)+).map(|_| writer.finish()) + }} +} diff --git a/aya-log/aya-log/Cargo.toml b/aya-log/aya-log/Cargo.toml new file mode 100644 index 00000000..0e1c5736 --- /dev/null +++ b/aya-log/aya-log/Cargo.toml @@ -0,0 +1,16 @@ +[package] +name = "aya-log" +version = "0.1.0" +edition = "2018" +publish = false + +[dependencies] +aya = { git = "https://github.com/aya-rs/aya", branch="main", features=["async_tokio"] } +aya-log-common = { path = "../aya-log-common", features=["userspace"] } +thiserror = "1" +log = "0.4" +bytes = "1.1" +tokio = { version = "1.2.0" } + +[lib] +path = "src/lib.rs" diff --git a/aya-log/aya-log/src/lib.rs b/aya-log/aya-log/src/lib.rs new file mode 100644 index 00000000..5a75724c --- /dev/null +++ b/aya-log/aya-log/src/lib.rs @@ -0,0 +1,202 @@ +//! A logging framework for eBPF programs. +//! +//! This is the user space side of the [Aya] logging framework. For the eBPF +//! side, see the `aya-log-ebpf` crate. +//! +//! `aya-log` provides the [BpfLogger] type, which reads log records created by +//! `aya-log-ebpf` and logs them using the [log] crate. Any logger that +//! implements the [Log] trait can be used with this crate. +//! +//! # Example: +//! +//! This example uses the [simplelog] crate to log messages to the terminal. +//! +//! ```no_run +//! # let mut bpf = aya::Bpf::load(&[], None)?; +//! use aya_log::BpfLogger; +//! use simplelog::{ColorChoice, ConfigBuilder, LevelFilter, TermLogger, TerminalMode}; +//! +//! BpfLogger::init( +//! &mut bpf, +//! TermLogger::new( +//! LevelFilter::Trace, +//! ConfigBuilder::new() +//! .set_target_level(LevelFilter::Error) +//! .set_location_level(LevelFilter::Error) +//! .build(), +//! TerminalMode::Mixed, +//! ColorChoice::Auto, +//! ), +//! ).unwrap(); +//! ``` +//! +//! With the following eBPF code: +//! +//! ```no_run +//! # let ctx = (); +//! use aya_log_ebpf::{debug, error, info, trace, warn}; +//! +//! error!(&ctx, "this is an error message 🚨"); +//! warn!(&ctx, "this is a warning message ⚠ī¸"); +//! info!(&ctx, "this is an info message ℹī¸"); +//! debug!(&ctx, "this is a debug message ī¸đŸ"); +//! trace!(&ctx, "this is a trace message 🔍"); +//! ``` +//! Outputs: +//! +//! ```text +//! 21:58:55 [ERROR] xxx: [src/main.rs:35] this is an error message 🚨 +//! 21:58:55 [WARN] xxx: [src/main.rs:36] this is a warning message ⚠ī¸ +//! 21:58:55 [INFO] xxx: [src/main.rs:37] this is an info message ℹī¸ +//! 21:58:55 [DEBUG] (7) xxx: [src/main.rs:38] this is a debug message ī¸đŸ +//! 21:58:55 [TRACE] (7) xxx: [src/main.rs:39] this is a trace message 🔍 +//! ``` +//! +//! [Aya]: https://docs.rs/aya +//! [simplelog]: https://docs.rs/simplelog +//! [Log]: https://docs.rs/log/0.4.14/log/trait.Log.html +//! [log]: https://docs.rs/log +//! +use std::{convert::TryInto, io, mem, ptr, sync::Arc}; + +use aya_log_common::{RecordField, LOG_BUF_CAPACITY, LOG_FIELDS}; +use bytes::BytesMut; +use log::{Level, Log, Record}; +use thiserror::Error; + +use aya::{ + maps::{ + perf::{AsyncPerfEventArray, PerfBufferError}, + MapError, + }, + util::online_cpus, + Bpf, Pod, +}; + +/// Log messages generated by `aya_log_ebpf` using the [log] crate. +/// +/// For more details see the [module level documentation](crate). +pub struct BpfLogger; + +impl BpfLogger { + /// Starts reading log records created with `aya-log-ebpf` and logs them + /// with the given logger. + pub fn init(bpf: &mut Bpf, logger: T) -> Result { + let logger = Arc::new(logger); + let mut logs: AsyncPerfEventArray<_> = bpf.map_mut("AYA_LOGS")?.try_into()?; + + for cpu_id in online_cpus().map_err(Error::InvalidOnlineCpu)? { + let mut buf = logs.open(cpu_id, None)?; + + let log = logger.clone(); + tokio::spawn(async move { + let mut buffers = (0..10) + .map(|_| BytesMut::with_capacity(LOG_BUF_CAPACITY)) + .collect::>(); + + loop { + let events = buf.read_events(&mut buffers).await.unwrap(); + + #[allow(clippy::needless_range_loop)] + for i in 0..events.read { + let buf = &mut buffers[i]; + log_buf(buf, &*log).unwrap(); + } + } + }); + } + + Ok(BpfLogger {}) + } +} + +#[derive(Error, Debug)] +pub enum Error { + #[error("error opening log event array")] + MapError(#[from] MapError), + + #[error("error opening log buffer")] + PerfBufferError(#[from] PerfBufferError), + + #[error("invalid /sys/devices/system/cpu/online format")] + InvalidOnlineCpu(#[source] io::Error), +} + +fn log_buf(mut buf: &[u8], logger: &dyn Log) -> Result<(), ()> { + let mut target = None; + let mut level = Level::Trace; + let mut module = None; + let mut file = None; + let mut line = None; + let mut log = None; + + for _ in 0..LOG_FIELDS { + let (attr, rest) = unsafe { TagLenValue::<'_, RecordField>::try_read(buf)? }; + + match attr.tag { + RecordField::Target => { + target = Some(std::str::from_utf8(attr.value).map_err(|_| ())?); + } + RecordField::Level => { + level = unsafe { ptr::read_unaligned(attr.value.as_ptr() as *const _) } + } + RecordField::Module => { + module = Some(std::str::from_utf8(attr.value).map_err(|_| ())?); + } + RecordField::File => { + file = Some(std::str::from_utf8(attr.value).map_err(|_| ())?); + } + RecordField::Line => { + line = Some(u32::from_ne_bytes(attr.value.try_into().map_err(|_| ())?)); + } + RecordField::Log => { + log = Some(std::str::from_utf8(attr.value).map_err(|_| ())?); + } + } + + buf = rest; + } + + logger.log( + &Record::builder() + .args(format_args!("{}", log.ok_or(())?)) + .target(target.ok_or(())?) + .level(level) + .module_path(module) + .file(file) + .line(line) + .build(), + ); + Ok(()) +} + +struct TagLenValue<'a, T: Pod> { + tag: T, + value: &'a [u8], +} + +impl<'a, T: Pod> TagLenValue<'a, T> { + unsafe fn try_read(mut buf: &'a [u8]) -> Result<(TagLenValue<'a, T>, &'a [u8]), ()> { + if buf.len() < mem::size_of::() + mem::size_of::() { + return Err(()); + } + + let tag = ptr::read_unaligned(buf.as_ptr() as *const T); + buf = &buf[mem::size_of::()..]; + + let len = usize::from_ne_bytes(buf[..mem::size_of::()].try_into().unwrap()); + buf = &buf[mem::size_of::()..]; + + if buf.len() < len { + return Err(()); + } + + Ok(( + TagLenValue { + tag, + value: &buf[..len], + }, + &buf[len..], + )) + } +}