Initial commit

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

aya-log/Cargo.toml

@@ -0,0 +1,2 @@
+[workspace]
+members = ["aya-log", "aya-log-common", "xtask"]

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"

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 {}

aya-log/aya-log-ebpf/.cargo/config.toml

@@ -0,0 +1,6 @@
+[build]
+target-dir = "../target"
+target = "bpfel-unknown-none"
+
+[unstable]
+build-std = ["core"]

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 = []

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<LogBuf> = 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::<RecordField>() + mem::size_of::<usize>(),
+            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::<RecordField>()..];
+
+        let len = self.pos - mem::size_of::<RecordField>() - mem::size_of::<usize>();
+        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<usize, ()> {
+        let size = mem::size_of::<RecordField>() + mem::size_of::<usize>() + 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::<RecordField>()..];
+
+        unsafe { ptr::write_unaligned(buf.as_mut_ptr() as *mut _, self.value.len()) };
+        buf = &mut buf[mem::size_of::<usize>()..];
+
+        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<usize, ()> {
+    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::<u32>() as u32,
+                value_size: mem::size_of::<u32>() as u32,
+                max_entries,
+                map_flags: flags,
+                id: 0,
+                pinning: 0,
+            },
+        }
+    }
+
+    #[inline(always)]
+    pub fn output<C: BpfContext>(
+        &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(())
+        }
+    }
+}

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())
+    }}
+}

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"

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<T: Log + 'static>(bpf: &mut Bpf, logger: T) -> Result<BpfLogger, Error> {
+        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::<Vec<_>>();
+
+                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::<T>() + mem::size_of::<usize>() {
+            return Err(());
+        }
+
+        let tag = ptr::read_unaligned(buf.as_ptr() as *const T);
+        buf = &buf[mem::size_of::<T>()..];
+
+        let len = usize::from_ne_bytes(buf[..mem::size_of::<usize>()].try_into().unwrap());
+        buf = &buf[mem::size_of::<usize>()..];
+
+        if buf.len() < len {
+            return Err(());
+        }
+
+        Ok((
+            TagLenValue {
+                tag,
+                value: &buf[..len],
+            },
+            &buf[len..],
+        ))
+    }
+}