From 4e2f8322cc6ee7ef06a1d5718405964e8da14d18 Mon Sep 17 00:00:00 2001 From: Tamir Duberstein Date: Thu, 27 Apr 2023 16:17:55 -0400 Subject: [PATCH 1/7] Build tests with all features Remove mem::forget::() calls in tests which fail to compile when HashMap is provided by hashbrown: info: running `cargo check --all-targets --no-default-features` on aya-obj (11/23) Checking aya-obj v0.1.0 (/home/tamird/src/aya/aya-obj) error[E0505]: cannot move out of `map` because it is borrowed --> aya-obj/src/relocation.rs:594:21 | 578 | let map = fake_legacy_map(1); | --- binding `map` declared here 579 | let maps_by_symbol = HashMap::from([(1, ("test_map", Some(1), &map))]); | ---- borrow of `map` occurs here ... 594 | mem::forget(map); | ^^^ move out of `map` occurs here 595 | } | - borrow might be used here, when `maps_by_symbol` is dropped and runs the destructor for type `hashbrown::HashMap, &maps::Map)>` error[E0505]: cannot move out of `map_1` because it is borrowed --> aya-obj/src/relocation.rs:655:21 | 632 | let map_1 = fake_legacy_map(1); | ----- binding `map_1` declared here ... 635 | (1, ("test_map_1", Some(1), &map_1)), | ------ borrow of `map_1` occurs here ... 655 | mem::forget(map_1); | ^^^^^ move out of `map_1` occurs here 656 | mem::forget(map_2); 657 | } | - borrow might be used here, when `maps_by_symbol` is dropped and runs the destructor for type `hashbrown::HashMap, &maps::Map)>` error[E0505]: cannot move out of `map_2` because it is borrowed --> aya-obj/src/relocation.rs:656:21 | 633 | let map_2 = fake_legacy_map(2); | ----- binding `map_2` declared here ... 636 | (2, ("test_map_2", Some(2), &map_2)), | ------ borrow of `map_2` occurs here ... 656 | mem::forget(map_2); | ^^^^^ move out of `map_2` occurs here 657 | } | - borrow might be used here, when `maps_by_symbol` is dropped and runs the destructor for type `hashbrown::HashMap, &maps::Map)>` error[E0505]: cannot move out of `map` because it is borrowed --> aya-obj/src/relocation.rs:694:21 | 678 | let map = fake_btf_map(1); | --- binding `map` declared here 679 | let maps_by_symbol = HashMap::from([(1, ("test_map", Some(1), &map))]); | ---- borrow of `map` occurs here ... 694 | mem::forget(map); | ^^^ move out of `map` occurs here 695 | } | - borrow might be used here, when `maps_by_symbol` is dropped and runs the destructor for type `hashbrown::HashMap, &maps::Map)>` error[E0505]: cannot move out of `map_1` because it is borrowed --> aya-obj/src/relocation.rs:755:21 | 732 | let map_1 = fake_btf_map(1); | ----- binding `map_1` declared here ... 735 | (1, ("test_map_1", Some(1), &map_1)), | ------ borrow of `map_1` occurs here ... 755 | mem::forget(map_1); | ^^^^^ move out of `map_1` occurs here 756 | mem::forget(map_2); 757 | } | - borrow might be used here, when `maps_by_symbol` is dropped and runs the destructor for type `hashbrown::HashMap, &maps::Map)>` error[E0505]: cannot move out of `map_2` because it is borrowed --> aya-obj/src/relocation.rs:756:21 | 733 | let map_2 = fake_btf_map(2); | ----- binding `map_2` declared here ... 736 | (2, ("test_map_2", Some(2), &map_2)), | ------ borrow of `map_2` occurs here ... 756 | mem::forget(map_2); | ^^^^^ move out of `map_2` occurs here 757 | } | - borrow might be used here, when `maps_by_symbol` is dropped and runs the destructor for type `hashbrown::HashMap, &maps::Map)>` For more information about this error, try `rustc --explain E0505`. error: could not compile `aya-obj` due to 6 previous errors warning: build failed, waiting for other jobs to finish... error: process didn't exit successfully: `/home/tamird/.rustup/toolchains/stable-x86_64-unknown-linux-gnu/bin/cargo check --all-targets --manifest-path aya-obj/Cargo.toml --no-default-features` (exit status: 101) --- .github/workflows/build-aya.yml | 2 +- aya-obj/src/relocation.rs | 10 ---------- 2 files changed, 1 insertion(+), 11 deletions(-) diff --git a/.github/workflows/build-aya.yml b/.github/workflows/build-aya.yml index c7bc3d9e..4e742c85 100644 --- a/.github/workflows/build-aya.yml +++ b/.github/workflows/build-aya.yml @@ -32,7 +32,7 @@ jobs: - uses: taiki-e/install-action@cargo-hack - name: Check - run: cargo hack check --feature-powerset --ignore-private + run: cargo hack check --all-targets --feature-powerset --ignore-private - uses: Swatinem/rust-cache@v1 - name: Prereqs diff --git a/aya-obj/src/relocation.rs b/aya-obj/src/relocation.rs index 55eccb5a..6422ed38 100644 --- a/aya-obj/src/relocation.rs +++ b/aya-obj/src/relocation.rs @@ -590,8 +590,6 @@ mod test { assert_eq!(fun.instructions[0].src_reg(), BPF_PSEUDO_MAP_FD as u8); assert_eq!(fun.instructions[0].imm, 1); - - mem::forget(map); } #[test] @@ -651,9 +649,6 @@ mod test { assert_eq!(fun.instructions[1].src_reg(), BPF_PSEUDO_MAP_FD as u8); assert_eq!(fun.instructions[1].imm, 2); - - mem::forget(map_1); - mem::forget(map_2); } #[test] @@ -690,8 +685,6 @@ mod test { assert_eq!(fun.instructions[0].src_reg(), BPF_PSEUDO_MAP_FD as u8); assert_eq!(fun.instructions[0].imm, 1); - - mem::forget(map); } #[test] @@ -751,8 +744,5 @@ mod test { assert_eq!(fun.instructions[1].src_reg(), BPF_PSEUDO_MAP_FD as u8); assert_eq!(fun.instructions[1].imm, 2); - - mem::forget(map_1); - mem::forget(map_2); } } From 490d7d587ad90b899aff2a30d65db8641ceb32df Mon Sep 17 00:00:00 2001 From: Tamir Duberstein Date: Wed, 19 Apr 2023 11:33:41 -0400 Subject: [PATCH 2/7] aya-log, aya-log-common: Remove duplicate struct Previously `struct TagLenValue` was defined in both aya-log and aya-log-common where the former implemented reading and the latter writing; the reading logic doesn't need the struct, so remove it. --- aya-log/src/lib.rs | 104 ++++++++++++++++++++------------------------- 1 file changed, 46 insertions(+), 58 deletions(-) diff --git a/aya-log/src/lib.rs b/aya-log/src/lib.rs index 83521cce..a2efba68 100644 --- a/aya-log/src/lib.rs +++ b/aya-log/src/lib.rs @@ -216,7 +216,7 @@ trait Format { impl Format for u32 { fn format(&self, last_hint: Option) -> Result { - match last_hint.map(|h| h.0) { + match last_hint.map(|DisplayHintWrapper(dh)| dh) { Some(DisplayHint::Default) => Ok(DefaultFormatter::format(self)), Some(DisplayHint::LowerHex) => Ok(LowerHexFormatter::format(self)), Some(DisplayHint::UpperHex) => Ok(UpperHexFormatter::format(self)), @@ -231,7 +231,7 @@ impl Format for u32 { impl Format for [u8; 6] { fn format(&self, last_hint: Option) -> Result { - match last_hint.map(|h| h.0) { + match last_hint.map(|DisplayHintWrapper(dh)| dh) { Some(DisplayHint::Default) => Err(()), Some(DisplayHint::LowerHex) => Err(()), Some(DisplayHint::UpperHex) => Err(()), @@ -246,7 +246,7 @@ impl Format for [u8; 6] { impl Format for [u8; 16] { fn format(&self, last_hint: Option) -> Result { - match last_hint.map(|h| h.0) { + match last_hint.map(|DisplayHintWrapper(dh)| dh) { Some(DisplayHint::Default) => Err(()), Some(DisplayHint::LowerHex) => Err(()), Some(DisplayHint::UpperHex) => Err(()), @@ -261,7 +261,7 @@ impl Format for [u8; 16] { impl Format for [u16; 8] { fn format(&self, last_hint: Option) -> Result { - match last_hint.map(|h| h.0) { + match last_hint.map(|DisplayHintWrapper(dh)| dh) { Some(DisplayHint::Default) => Err(()), Some(DisplayHint::LowerHex) => Err(()), Some(DisplayHint::UpperHex) => Err(()), @@ -278,7 +278,7 @@ macro_rules! impl_format { ($type:ident) => { impl Format for $type { fn format(&self, last_hint: Option) -> Result { - match last_hint.map(|h| h.0) { + match last_hint.map(|DisplayHintWrapper(dh)| dh) { Some(DisplayHint::Default) => Ok(DefaultFormatter::format(self)), Some(DisplayHint::LowerHex) => Ok(LowerHexFormatter::format(self)), Some(DisplayHint::UpperHex) => Ok(UpperHexFormatter::format(self)), @@ -308,7 +308,7 @@ macro_rules! impl_format_float { ($type:ident) => { impl Format for $type { fn format(&self, last_hint: Option) -> Result { - match last_hint.map(|h| h.0) { + match last_hint.map(|DisplayHintWrapper(dh)| dh) { Some(DisplayHint::Default) => Ok(DefaultFormatter::format(self)), Some(DisplayHint::LowerHex) => Err(()), Some(DisplayHint::UpperHex) => Err(()), @@ -367,26 +367,26 @@ fn log_buf(mut buf: &[u8], logger: &dyn Log) -> Result<(), ()> { let mut num_args = None; for _ in 0..LOG_FIELDS { - let (attr, rest) = unsafe { TagLenValue::<'_, RecordFieldWrapper>::try_read(buf)? }; + let (RecordFieldWrapper(tag), value, rest) = try_read(buf)?; - match attr.tag.0 { + match tag { RecordField::Target => { - target = Some(std::str::from_utf8(attr.value).map_err(|_| ())?); + target = Some(std::str::from_utf8(value).map_err(|_| ())?); } RecordField::Level => { - level = unsafe { ptr::read_unaligned(attr.value.as_ptr() as *const _) } + level = unsafe { ptr::read_unaligned(value.as_ptr() as *const _) } } RecordField::Module => { - module = Some(std::str::from_utf8(attr.value).map_err(|_| ())?); + module = Some(std::str::from_utf8(value).map_err(|_| ())?); } RecordField::File => { - file = Some(std::str::from_utf8(attr.value).map_err(|_| ())?); + file = Some(std::str::from_utf8(value).map_err(|_| ())?); } RecordField::Line => { - line = Some(u32::from_ne_bytes(attr.value.try_into().map_err(|_| ())?)); + line = Some(u32::from_ne_bytes(value.try_into().map_err(|_| ())?)); } RecordField::NumArgs => { - num_args = Some(usize::from_ne_bytes(attr.value.try_into().map_err(|_| ())?)); + num_args = Some(usize::from_ne_bytes(value.try_into().map_err(|_| ())?)); } } @@ -396,101 +396,101 @@ fn log_buf(mut buf: &[u8], logger: &dyn Log) -> Result<(), ()> { let mut full_log_msg = String::new(); let mut last_hint: Option = None; for _ in 0..num_args.ok_or(())? { - let (attr, rest) = unsafe { TagLenValue::<'_, ArgumentWrapper>::try_read(buf)? }; + let (ArgumentWrapper(tag), value, rest) = try_read(buf)?; - match attr.tag.0 { + match tag { Argument::DisplayHint => { - last_hint = Some(unsafe { ptr::read_unaligned(attr.value.as_ptr() as *const _) }); + last_hint = Some(unsafe { ptr::read_unaligned(value.as_ptr() as *const _) }); } Argument::I8 => { full_log_msg.push_str( - &i8::from_ne_bytes(attr.value.try_into().map_err(|_| ())?) + &i8::from_ne_bytes(value.try_into().map_err(|_| ())?) .format(last_hint.take())?, ); } Argument::I16 => { full_log_msg.push_str( - &i16::from_ne_bytes(attr.value.try_into().map_err(|_| ())?) + &i16::from_ne_bytes(value.try_into().map_err(|_| ())?) .format(last_hint.take())?, ); } Argument::I32 => { full_log_msg.push_str( - &i32::from_ne_bytes(attr.value.try_into().map_err(|_| ())?) + &i32::from_ne_bytes(value.try_into().map_err(|_| ())?) .format(last_hint.take())?, ); } Argument::I64 => { full_log_msg.push_str( - &i64::from_ne_bytes(attr.value.try_into().map_err(|_| ())?) + &i64::from_ne_bytes(value.try_into().map_err(|_| ())?) .format(last_hint.take())?, ); } Argument::Isize => { full_log_msg.push_str( - &isize::from_ne_bytes(attr.value.try_into().map_err(|_| ())?) + &isize::from_ne_bytes(value.try_into().map_err(|_| ())?) .format(last_hint.take())?, ); } Argument::U8 => { full_log_msg.push_str( - &u8::from_ne_bytes(attr.value.try_into().map_err(|_| ())?) + &u8::from_ne_bytes(value.try_into().map_err(|_| ())?) .format(last_hint.take())?, ); } Argument::U16 => { full_log_msg.push_str( - &u16::from_ne_bytes(attr.value.try_into().map_err(|_| ())?) + &u16::from_ne_bytes(value.try_into().map_err(|_| ())?) .format(last_hint.take())?, ); } Argument::U32 => { full_log_msg.push_str( - &u32::from_ne_bytes(attr.value.try_into().map_err(|_| ())?) + &u32::from_ne_bytes(value.try_into().map_err(|_| ())?) .format(last_hint.take())?, ); } Argument::U64 => { full_log_msg.push_str( - &u64::from_ne_bytes(attr.value.try_into().map_err(|_| ())?) + &u64::from_ne_bytes(value.try_into().map_err(|_| ())?) .format(last_hint.take())?, ); } Argument::Usize => { full_log_msg.push_str( - &usize::from_ne_bytes(attr.value.try_into().map_err(|_| ())?) + &usize::from_ne_bytes(value.try_into().map_err(|_| ())?) .format(last_hint.take())?, ); } Argument::F32 => { full_log_msg.push_str( - &f32::from_ne_bytes(attr.value.try_into().map_err(|_| ())?) + &f32::from_ne_bytes(value.try_into().map_err(|_| ())?) .format(last_hint.take())?, ); } Argument::F64 => { full_log_msg.push_str( - &f64::from_ne_bytes(attr.value.try_into().map_err(|_| ())?) + &f64::from_ne_bytes(value.try_into().map_err(|_| ())?) .format(last_hint.take())?, ); } Argument::ArrU8Len6 => { - let value: [u8; 6] = attr.value.try_into().map_err(|_| ())?; + let value: [u8; 6] = value.try_into().map_err(|_| ())?; full_log_msg.push_str(&value.format(last_hint.take())?); } Argument::ArrU8Len16 => { - let value: [u8; 16] = attr.value.try_into().map_err(|_| ())?; + let value: [u8; 16] = value.try_into().map_err(|_| ())?; full_log_msg.push_str(&value.format(last_hint.take())?); } Argument::ArrU16Len8 => { - let data: [u8; 16] = attr.value.try_into().map_err(|_| ())?; + let data: [u8; 16] = value.try_into().map_err(|_| ())?; let mut value: [u16; 8] = Default::default(); for (i, s) in data.chunks_exact(2).enumerate() { value[i] = ((s[1] as u16) << 8) | s[0] as u16; } full_log_msg.push_str(&value.format(last_hint.take())?); } - Argument::Str => match str::from_utf8(attr.value) { + Argument::Str => match str::from_utf8(value) { Ok(v) => { full_log_msg.push_str(v); } @@ -515,35 +515,23 @@ fn log_buf(mut buf: &[u8], logger: &dyn Log) -> Result<(), ()> { 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::()..]; +fn try_read(mut buf: &[u8]) -> Result<(T, &[u8], &[u8]), ()> { + if buf.len() < mem::size_of::() + mem::size_of::() { + return Err(()); + } - let len = usize::from_ne_bytes(buf[..mem::size_of::()].try_into().unwrap()); - buf = &buf[mem::size_of::()..]; + let tag = unsafe { ptr::read_unaligned(buf.as_ptr() as *const T) }; + buf = &buf[mem::size_of::()..]; - if buf.len() < len { - return Err(()); - } + let len = usize::from_ne_bytes(buf[..mem::size_of::()].try_into().unwrap()); + buf = &buf[mem::size_of::()..]; - Ok(( - TagLenValue { - tag, - value: &buf[..len], - }, - &buf[len..], - )) + if buf.len() < len { + return Err(()); } + + let (value, rest) = buf.split_at(len); + Ok((tag, value, rest)) } #[cfg(test)] From 4d098ef413dee3fe1cd260f19f7f90e69a06f06c Mon Sep 17 00:00:00 2001 From: Tamir Duberstein Date: Wed, 19 Apr 2023 12:24:00 -0400 Subject: [PATCH 3/7] aya-log-pbf-macros: ensure WriteToBuf is used Previously any old `write` method could be selected. --- aya-log-ebpf-macros/src/expand.rs | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/aya-log-ebpf-macros/src/expand.rs b/aya-log-ebpf-macros/src/expand.rs index 1989fe97..eefcbb72 100644 --- a/aya-log-ebpf-macros/src/expand.rs +++ b/aya-log-ebpf-macros/src/expand.rs @@ -151,12 +151,11 @@ pub(crate) fn log(args: LogArgs, level: Option) -> Result(record_len) #( .and_then(|record_len| { if record_len >= buf.buf.len() { return Err(()); } - { #values_iter }.write(&mut buf.buf[record_len..]).map(|len| record_len + len) + aya_log_ebpf::WriteToBuf::write({ #values_iter }, &mut buf.buf[record_len..]).map(|len| record_len + len) }) )* } { unsafe { ::aya_log_ebpf::AYA_LOGS.output( From e4537e389ad7ac6f09fc89349444e37fe01e4af4 Mon Sep 17 00:00:00 2001 From: Tamir Duberstein Date: Wed, 19 Apr 2023 16:16:53 -0400 Subject: [PATCH 4/7] aya-log: check errors in tests --- aya-log/src/lib.rs | 20 ++++++++++---------- 1 file changed, 10 insertions(+), 10 deletions(-) diff --git a/aya-log/src/lib.rs b/aya-log/src/lib.rs index a2efba68..affeae49 100644 --- a/aya-log/src/lib.rs +++ b/aya-log/src/lib.rs @@ -564,7 +564,7 @@ mod test { .expect("could not write to the buffer"); let logger = logger(); - let _ = log_buf(&input, logger); + let () = log_buf(&input, logger).unwrap(); testing_logger::validate(|captured_logs| { assert_eq!(captured_logs.len(), 1); assert_eq!(captured_logs[0].body, "test"); @@ -583,7 +583,7 @@ mod test { "test".write(&mut input[len..]).unwrap(); let logger = logger(); - let _ = log_buf(&input, logger); + let () = log_buf(&input, logger).unwrap(); testing_logger::validate(|captured_logs| { assert_eq!(captured_logs.len(), 1); assert_eq!(captured_logs[0].body, "hello test"); @@ -601,7 +601,7 @@ mod test { 14.write(&mut input[len..]).unwrap(); let logger = logger(); - let _ = log_buf(&input, logger); + let () = log_buf(&input, logger).unwrap(); testing_logger::validate(|captured_logs| { assert_eq!(captured_logs.len(), 1); assert_eq!(captured_logs[0].body, "default hint: 14"); @@ -619,7 +619,7 @@ mod test { 200.write(&mut input[len..]).unwrap(); let logger = logger(); - let _ = log_buf(&input, logger); + let () = log_buf(&input, logger).unwrap(); testing_logger::validate(|captured_logs| { assert_eq!(captured_logs.len(), 1); assert_eq!(captured_logs[0].body, "lower hex: c8"); @@ -637,7 +637,7 @@ mod test { 200.write(&mut input[len..]).unwrap(); let logger = logger(); - let _ = log_buf(&input, logger); + let () = log_buf(&input, logger).unwrap(); testing_logger::validate(|captured_logs| { assert_eq!(captured_logs.len(), 1); assert_eq!(captured_logs[0].body, "upper hex: C8"); @@ -656,7 +656,7 @@ mod test { 167772161u32.write(&mut input[len..]).unwrap(); let logger = logger(); - let _ = log_buf(&input, logger); + let () = log_buf(&input, logger).unwrap(); testing_logger::validate(|captured_logs| { assert_eq!(captured_logs.len(), 1); assert_eq!(captured_logs[0].body, "ipv4: 10.0.0.1"); @@ -679,7 +679,7 @@ mod test { ipv6_arr.write(&mut input[len..]).unwrap(); let logger = logger(); - let _ = log_buf(&input, logger); + let () = log_buf(&input, logger).unwrap(); testing_logger::validate(|captured_logs| { assert_eq!(captured_logs.len(), 1); assert_eq!(captured_logs[0].body, "ipv6: 2001:db8::1:1"); @@ -701,7 +701,7 @@ mod test { ipv6_arr.write(&mut input[len..]).unwrap(); let logger = logger(); - let _ = log_buf(&input, logger); + let () = log_buf(&input, logger).unwrap(); testing_logger::validate(|captured_logs| { assert_eq!(captured_logs.len(), 1); assert_eq!(captured_logs[0].body, "ipv6: 2001:db8::1:1"); @@ -721,7 +721,7 @@ mod test { mac_arr.write(&mut input[len..]).unwrap(); let logger = logger(); - let _ = log_buf(&input, logger); + let () = log_buf(&input, logger).unwrap(); testing_logger::validate(|captured_logs| { assert_eq!(captured_logs.len(), 1); assert_eq!(captured_logs[0].body, "mac: 00:00:5e:00:53:af"); @@ -741,7 +741,7 @@ mod test { mac_arr.write(&mut input[len..]).unwrap(); let logger = logger(); - let _ = log_buf(&input, logger); + let () = log_buf(&input, logger).unwrap(); testing_logger::validate(|captured_logs| { assert_eq!(captured_logs.len(), 1); assert_eq!(captured_logs[0].body, "mac: 00:00:5E:00:53:AF"); From a4a69a6bcfe87d3c066f2cc341b74039f53dcc9e Mon Sep 17 00:00:00 2001 From: Tamir Duberstein Date: Wed, 19 Apr 2023 16:41:27 -0400 Subject: [PATCH 5/7] aya-log, aya-log-common: economize bytes - Replace all `#[repr(usize)]` with `#[repr(u8)]`; this saves 3*(sizeof(word)-1) bytes per log message. - Encode payload length as u16 rather than usize; this saves sizeof(word)-1 bytes per log message. This is safe because the maximum size of a log message is less than (1 << 16 - 1). This changes `level` to a require field in every log message. It was already always present, but was treated as optional when reading. --- aya-log-common/src/lib.rs | 62 ++++++++++++++++++++++++++------------- aya-log/src/lib.rs | 41 ++++++++++++++++---------- 2 files changed, 67 insertions(+), 36 deletions(-) diff --git a/aya-log-common/src/lib.rs b/aya-log-common/src/lib.rs index 976462dd..9b85c65e 100644 --- a/aya-log-common/src/lib.rs +++ b/aya-log-common/src/lib.rs @@ -1,6 +1,6 @@ #![no_std] -use core::{cmp, mem, ptr, slice}; +use core::{mem, num, ptr, slice}; use num_enum::IntoPrimitive; @@ -8,8 +8,10 @@ pub const LOG_BUF_CAPACITY: usize = 8192; pub const LOG_FIELDS: usize = 6; -#[repr(usize)] -#[derive(Copy, Clone, Eq, PartialEq, Debug, Hash)] +pub type LogValueLength = u16; + +#[repr(u8)] +#[derive(Copy, Clone, Eq, PartialEq, Debug, Hash, IntoPrimitive)] pub enum Level { /// The "error" level. /// @@ -33,7 +35,7 @@ pub enum Level { Trace, } -#[repr(usize)] +#[repr(u8)] #[derive(Copy, Clone, Debug)] pub enum RecordField { Target = 1, @@ -46,7 +48,7 @@ pub enum RecordField { /// Types which are supported by aya-log and can be safely sent from eBPF /// programs to userspace. -#[repr(usize)] +#[repr(u8)] #[derive(Copy, Clone, Debug)] pub enum Argument { DisplayHint, @@ -111,26 +113,29 @@ where } pub(crate) fn write(&self, mut buf: &mut [u8]) -> Result { - let size = mem::size_of::() + mem::size_of::() + self.value.len(); - let remaining = cmp::min(buf.len(), LOG_BUF_CAPACITY); - // Check if the size doesn't exceed the buffer bounds. - if size > remaining { + // Break the abstraction to please the verifier. + if buf.len() > LOG_BUF_CAPACITY { + buf = &mut buf[..LOG_BUF_CAPACITY]; + } + let Self { tag, value } = self; + let len = value.len(); + let wire_len: LogValueLength = value + .len() + .try_into() + .map_err(|num::TryFromIntError { .. }| ())?; + let size = mem::size_of_val(tag) + mem::size_of_val(&wire_len) + len; + if size > buf.len() { 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 _, *tag) }; + buf = &mut buf[mem::size_of_val(tag)..]; - unsafe { ptr::write_unaligned(buf.as_mut_ptr() as *mut _, self.value.len()) }; - buf = &mut buf[mem::size_of::()..]; + unsafe { ptr::write_unaligned(buf.as_mut_ptr() as *mut _, wire_len) }; + buf = &mut buf[mem::size_of_val(&wire_len)..]; + + unsafe { ptr::copy_nonoverlapping(value.as_ptr(), buf.as_mut_ptr(), len) }; - let len = cmp::min(buf.len(), self.value.len()); - // The verifier isn't happy with `len` being unbounded, so compare it - // with `LOG_BUF_CAPACITY`. - if len > LOG_BUF_CAPACITY { - return Err(()); - } - buf[..len].copy_from_slice(&self.value[..len]); Ok(size) } } @@ -210,10 +215,11 @@ pub fn write_record_header( line: u32, num_args: usize, ) -> Result { + let level: u8 = level.into(); 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::Level, &level.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()), @@ -224,3 +230,17 @@ pub fn write_record_header( Ok(size) } + +#[cfg(test)] +mod test { + use super::*; + + fn log_value_length_sufficient() { + assert!( + LOG_BUF_CAPACITY >= LogValueLength::MAX.into(), + "{} < {}", + LOG_BUF_CAPACITY, + LogValueLength::MAX + ); + } +} diff --git a/aya-log/src/lib.rs b/aya-log/src/lib.rs index affeae49..989f24d5 100644 --- a/aya-log/src/lib.rs +++ b/aya-log/src/lib.rs @@ -59,9 +59,11 @@ use std::{ const MAP_NAME: &str = "AYA_LOGS"; -use aya_log_common::{Argument, DisplayHint, RecordField, LOG_BUF_CAPACITY, LOG_FIELDS}; +use aya_log_common::{ + Argument, DisplayHint, Level, LogValueLength, RecordField, LOG_BUF_CAPACITY, LOG_FIELDS, +}; use bytes::BytesMut; -use log::{error, Level, Log, Record}; +use log::{error, Log, Record}; use thiserror::Error; use aya::{ @@ -116,9 +118,7 @@ impl BpfLogger { let log = logger.clone(); tokio::spawn(async move { - let mut buffers = (0..10) - .map(|_| BytesMut::with_capacity(LOG_BUF_CAPACITY)) - .collect::>(); + let mut buffers = vec![BytesMut::with_capacity(LOG_BUF_CAPACITY); 10]; loop { let events = buf.read_events(&mut buffers).await.unwrap(); @@ -360,7 +360,7 @@ pub enum Error { fn log_buf(mut buf: &[u8], logger: &dyn Log) -> Result<(), ()> { let mut target = None; - let mut level = Level::Trace; + let mut level = None; let mut module = None; let mut file = None; let mut line = None; @@ -371,16 +371,25 @@ fn log_buf(mut buf: &[u8], logger: &dyn Log) -> Result<(), ()> { match tag { RecordField::Target => { - target = Some(std::str::from_utf8(value).map_err(|_| ())?); + target = Some(str::from_utf8(value).map_err(|_| ())?); } RecordField::Level => { - level = unsafe { ptr::read_unaligned(value.as_ptr() as *const _) } + level = Some({ + let level = unsafe { ptr::read_unaligned(value.as_ptr() as *const _) }; + match level { + Level::Error => log::Level::Error, + Level::Warn => log::Level::Warn, + Level::Info => log::Level::Info, + Level::Debug => log::Level::Debug, + Level::Trace => log::Level::Trace, + } + }) } RecordField::Module => { - module = Some(std::str::from_utf8(value).map_err(|_| ())?); + module = Some(str::from_utf8(value).map_err(|_| ())?); } RecordField::File => { - file = Some(std::str::from_utf8(value).map_err(|_| ())?); + file = Some(str::from_utf8(value).map_err(|_| ())?); } RecordField::Line => { line = Some(u32::from_ne_bytes(value.try_into().map_err(|_| ())?)); @@ -505,7 +514,7 @@ fn log_buf(mut buf: &[u8], logger: &dyn Log) -> Result<(), ()> { &Record::builder() .args(format_args!("{full_log_msg}")) .target(target.ok_or(())?) - .level(level) + .level(level.ok_or(())?) .module_path(module) .file(file) .line(line) @@ -516,16 +525,18 @@ fn log_buf(mut buf: &[u8], logger: &dyn Log) -> Result<(), ()> { } fn try_read(mut buf: &[u8]) -> Result<(T, &[u8], &[u8]), ()> { - if buf.len() < mem::size_of::() + mem::size_of::() { + if buf.len() < mem::size_of::() + mem::size_of::() { return Err(()); } let tag = unsafe { 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::()..]; + let len = + LogValueLength::from_ne_bytes(buf[..mem::size_of::()].try_into().unwrap()); + buf = &buf[mem::size_of::()..]; + let len: usize = len.into(); if buf.len() < len { return Err(()); } @@ -538,7 +549,7 @@ fn try_read(mut buf: &[u8]) -> Result<(T, &[u8], &[u8]), ()> { mod test { use super::*; use aya_log_common::{write_record_header, WriteToBuf}; - use log::logger; + use log::{logger, Level}; fn new_log(args: usize) -> Result<(usize, Vec), ()> { let mut buf = vec![0; 8192]; From 9a1a720a74fd458b4865e1139dd2f4ca84994ef2 Mon Sep 17 00:00:00 2001 From: Tamir Duberstein Date: Wed, 19 Apr 2023 13:36:34 -0400 Subject: [PATCH 6/7] aya-log-common: generalize TagLenValue This allows logging values backed by generators. --- aya-log-common/src/lib.rs | 93 +++++++++++++++++++++------------------ 1 file changed, 49 insertions(+), 44 deletions(-) diff --git a/aya-log-common/src/lib.rs b/aya-log-common/src/lib.rs index 9b85c65e..80bab66a 100644 --- a/aya-log-common/src/lib.rs +++ b/aya-log-common/src/lib.rs @@ -1,6 +1,6 @@ #![no_std] -use core::{mem, num, ptr, slice}; +use core::{mem, num, ptr}; use num_enum::IntoPrimitive; @@ -98,58 +98,65 @@ pub enum DisplayHint { UpperMac, } -struct TagLenValue<'a, T> { - tag: T, - value: &'a [u8], +struct TagLenValue { + pub tag: T, + pub value: V, } -impl<'a, T> TagLenValue<'a, T> +impl TagLenValue where - T: Copy, + V: IntoIterator, + ::IntoIter: ExactSizeIterator, { - #[inline(always)] - pub(crate) fn new(tag: T, value: &'a [u8]) -> TagLenValue<'a, T> { - TagLenValue { tag, value } - } - - pub(crate) fn write(&self, mut buf: &mut [u8]) -> Result { + pub(crate) fn write(self, mut buf: &mut [u8]) -> Result { // Break the abstraction to please the verifier. if buf.len() > LOG_BUF_CAPACITY { buf = &mut buf[..LOG_BUF_CAPACITY]; } let Self { tag, value } = self; + let value = value.into_iter(); let len = value.len(); let wire_len: LogValueLength = value .len() .try_into() .map_err(|num::TryFromIntError { .. }| ())?; - let size = mem::size_of_val(tag) + mem::size_of_val(&wire_len) + len; + let size = mem::size_of_val(&tag) + mem::size_of_val(&wire_len) + len; if size > buf.len() { return Err(()); } - unsafe { ptr::write_unaligned(buf.as_mut_ptr() as *mut _, *tag) }; - buf = &mut buf[mem::size_of_val(tag)..]; + let tag_size = mem::size_of_val(&tag); + unsafe { ptr::write_unaligned(buf.as_mut_ptr() as *mut _, tag) }; + buf = &mut buf[tag_size..]; unsafe { ptr::write_unaligned(buf.as_mut_ptr() as *mut _, wire_len) }; buf = &mut buf[mem::size_of_val(&wire_len)..]; - unsafe { ptr::copy_nonoverlapping(value.as_ptr(), buf.as_mut_ptr(), len) }; + buf.iter_mut().zip(value).for_each(|(dst, src)| { + *dst = src; + }); Ok(size) } } +impl TagLenValue { + #[inline(always)] + pub(crate) fn new(tag: T, value: V) -> TagLenValue { + TagLenValue { tag, value } + } +} + pub trait WriteToBuf { #[allow(clippy::result_unit_err)] - fn write(&self, buf: &mut [u8]) -> Result; + fn write(self, buf: &mut [u8]) -> Result; } macro_rules! impl_write_to_buf { ($type:ident, $arg_type:expr) => { impl WriteToBuf for $type { - fn write(&self, buf: &mut [u8]) -> Result { - TagLenValue::::new($arg_type, &self.to_ne_bytes()).write(buf) + fn write(self, buf: &mut [u8]) -> Result { + TagLenValue::new($arg_type, self.to_ne_bytes()).write(buf) } } }; @@ -171,35 +178,34 @@ impl_write_to_buf!(f32, Argument::F32); impl_write_to_buf!(f64, Argument::F64); impl WriteToBuf for [u8; 16] { - fn write(&self, buf: &mut [u8]) -> Result { - TagLenValue::::new(Argument::ArrU8Len16, self).write(buf) + fn write(self, buf: &mut [u8]) -> Result { + TagLenValue::new(Argument::ArrU8Len16, self).write(buf) } } impl WriteToBuf for [u16; 8] { - fn write(&self, buf: &mut [u8]) -> Result { - let ptr = self.as_ptr().cast::(); - let bytes = unsafe { slice::from_raw_parts(ptr, 16) }; - TagLenValue::::new(Argument::ArrU16Len8, bytes).write(buf) + fn write(self, buf: &mut [u8]) -> Result { + let bytes = unsafe { core::mem::transmute::<_, [u8; 16]>(self) }; + TagLenValue::new(Argument::ArrU16Len8, bytes).write(buf) } } impl WriteToBuf for [u8; 6] { - fn write(&self, buf: &mut [u8]) -> Result { - TagLenValue::::new(Argument::ArrU8Len6, self).write(buf) + fn write(self, buf: &mut [u8]) -> Result { + TagLenValue::new(Argument::ArrU8Len6, self).write(buf) } } -impl WriteToBuf for str { - fn write(&self, buf: &mut [u8]) -> Result { - TagLenValue::::new(Argument::Str, self.as_bytes()).write(buf) +impl WriteToBuf for &str { + fn write(self, buf: &mut [u8]) -> Result { + TagLenValue::new(Argument::Str, self.as_bytes().iter().copied()).write(buf) } } impl WriteToBuf for DisplayHint { - fn write(&self, buf: &mut [u8]) -> Result { - let v: u8 = (*self).into(); - TagLenValue::::new(Argument::DisplayHint, &v.to_ne_bytes()).write(buf) + fn write(self, buf: &mut [u8]) -> Result { + let v: u8 = self.into(); + TagLenValue::new(Argument::DisplayHint, v.to_ne_bytes()).write(buf) } } @@ -217,17 +223,16 @@ pub fn write_record_header( ) -> Result { let level: u8 = level.into(); let mut size = 0; - for attr in [ - TagLenValue::::new(RecordField::Target, target.as_bytes()), - TagLenValue::::new(RecordField::Level, &level.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()), - TagLenValue::::new(RecordField::NumArgs, &num_args.to_ne_bytes()), - ] { - size += attr.write(&mut buf[size..])?; - } - + size += TagLenValue::new(RecordField::Target, target.as_bytes().iter().copied()) + .write(&mut buf[size..])?; + size += TagLenValue::new(RecordField::Level, level.to_ne_bytes()).write(&mut buf[size..])?; + size += TagLenValue::new(RecordField::Module, module.as_bytes().iter().copied()) + .write(&mut buf[size..])?; + size += TagLenValue::new(RecordField::File, file.as_bytes().iter().copied()) + .write(&mut buf[size..])?; + size += TagLenValue::new(RecordField::Line, line.to_ne_bytes()).write(&mut buf[size..])?; + size += + TagLenValue::new(RecordField::NumArgs, num_args.to_ne_bytes()).write(&mut buf[size..])?; Ok(size) } From d9f966ec9e49f4439710559cac852bde62810975 Mon Sep 17 00:00:00 2001 From: Tamir Duberstein Date: Wed, 19 Apr 2023 17:33:00 -0400 Subject: [PATCH 7/7] aya-log-common: support logging byte slices These only support LowerHex and UpperHex hints for now. --- aya-log-common/src/lib.rs | 7 ++ aya-log/src/lib.rs | 132 ++++++++++++++++++++++--- test/integration-ebpf/src/log.rs | 2 + test/integration-test/src/tests/log.rs | 8 +- 4 files changed, 131 insertions(+), 18 deletions(-) diff --git a/aya-log-common/src/lib.rs b/aya-log-common/src/lib.rs index 80bab66a..f833f3c1 100644 --- a/aya-log-common/src/lib.rs +++ b/aya-log-common/src/lib.rs @@ -75,6 +75,7 @@ pub enum Argument { /// `[u16; 8]` array which represents an IPv6 address. ArrU16Len8, + Bytes, Str, } @@ -196,6 +197,12 @@ impl WriteToBuf for [u8; 6] { } } +impl WriteToBuf for &[u8] { + fn write(self, buf: &mut [u8]) -> Result { + TagLenValue::new(Argument::Bytes, self.iter().copied()).write(buf) + } +} + impl WriteToBuf for &str { fn write(self, buf: &mut [u8]) -> Result { TagLenValue::new(Argument::Str, self.as_bytes().iter().copied()).write(buf) diff --git a/aya-log/src/lib.rs b/aya-log/src/lib.rs index 989f24d5..92d686bb 100644 --- a/aya-log/src/lib.rs +++ b/aya-log/src/lib.rs @@ -160,6 +160,20 @@ where } } +pub struct LowerHexDebugFormatter; +impl Formatter<&[T]> for LowerHexDebugFormatter +where + T: LowerHex, +{ + fn format(v: &[T]) -> String { + let mut s = String::new(); + for v in v { + let () = core::fmt::write(&mut s, format_args!("{v:x}")).unwrap(); + } + s + } +} + pub struct UpperHexFormatter; impl Formatter for UpperHexFormatter where @@ -170,6 +184,20 @@ where } } +pub struct UpperHexDebugFormatter; +impl Formatter<&[T]> for UpperHexDebugFormatter +where + T: UpperHex, +{ + fn format(v: &[T]) -> String { + let mut s = String::new(); + for v in v { + let () = core::fmt::write(&mut s, format_args!("{v:X}")).unwrap(); + } + s + } +} + pub struct Ipv4Formatter; impl Formatter for Ipv4Formatter where @@ -214,6 +242,16 @@ trait Format { fn format(&self, last_hint: Option) -> Result; } +impl Format for &[u8] { + fn format(&self, last_hint: Option) -> Result { + match last_hint.map(|DisplayHintWrapper(dh)| dh) { + Some(DisplayHint::LowerHex) => Ok(LowerHexDebugFormatter::format(self)), + Some(DisplayHint::UpperHex) => Ok(UpperHexDebugFormatter::format(self)), + _ => Err(()), + } + } +} + impl Format for u32 { fn format(&self, last_hint: Option) -> Result { match last_hint.map(|DisplayHintWrapper(dh)| dh) { @@ -499,6 +537,9 @@ fn log_buf(mut buf: &[u8], logger: &dyn Log) -> Result<(), ()> { } full_log_msg.push_str(&value.format(last_hint.take())?); } + Argument::Bytes => { + full_log_msg.push_str(&value.format(last_hint.take())?); + } Argument::Str => match str::from_utf8(value) { Ok(v) => { full_log_msg.push_str(v); @@ -568,11 +609,11 @@ mod test { #[test] fn test_str() { testing_logger::setup(); - let (len, mut input) = new_log(1).unwrap(); + let (mut len, mut input) = new_log(1).unwrap(); - "test" - .write(&mut input[len..]) - .expect("could not write to the buffer"); + len += "test".write(&mut input[len..]).unwrap(); + + _ = len; let logger = logger(); let () = log_buf(&input, logger).unwrap(); @@ -588,10 +629,10 @@ mod test { testing_logger::setup(); let (mut len, mut input) = new_log(2).unwrap(); - len += "hello " - .write(&mut input[len..]) - .expect("could not write to the buffer"); - "test".write(&mut input[len..]).unwrap(); + len += "hello ".write(&mut input[len..]).unwrap(); + len += "test".write(&mut input[len..]).unwrap(); + + _ = len; let logger = logger(); let () = log_buf(&input, logger).unwrap(); @@ -602,6 +643,49 @@ mod test { }); } + #[test] + fn test_bytes() { + testing_logger::setup(); + let (mut len, mut input) = new_log(2).unwrap(); + + len += DisplayHint::LowerHex.write(&mut input[len..]).unwrap(); + len += [0xde, 0xad].write(&mut input[len..]).unwrap(); + + _ = len; + + let logger = logger(); + let () = log_buf(&input, logger).unwrap(); + testing_logger::validate(|captured_logs| { + assert_eq!(captured_logs.len(), 1); + assert_eq!(captured_logs[0].body, "dead"); + assert_eq!(captured_logs[0].level, Level::Info); + }); + } + + #[test] + fn test_bytes_with_args() { + testing_logger::setup(); + let (mut len, mut input) = new_log(5).unwrap(); + + len += DisplayHint::LowerHex.write(&mut input[len..]).unwrap(); + len += [0xde, 0xad].write(&mut input[len..]).unwrap(); + + len += " ".write(&mut input[len..]).unwrap(); + + len += DisplayHint::UpperHex.write(&mut input[len..]).unwrap(); + len += [0xbe, 0xef].write(&mut input[len..]).unwrap(); + + _ = len; + + let logger = logger(); + let () = log_buf(&input, logger).unwrap(); + testing_logger::validate(|captured_logs| { + assert_eq!(captured_logs.len(), 1); + assert_eq!(captured_logs[0].body, "dead BEEF"); + assert_eq!(captured_logs[0].level, Level::Info); + }); + } + #[test] fn test_display_hint_default() { testing_logger::setup(); @@ -609,7 +693,9 @@ mod test { len += "default hint: ".write(&mut input[len..]).unwrap(); len += DisplayHint::Default.write(&mut input[len..]).unwrap(); - 14.write(&mut input[len..]).unwrap(); + len += 14.write(&mut input[len..]).unwrap(); + + _ = len; let logger = logger(); let () = log_buf(&input, logger).unwrap(); @@ -627,7 +713,9 @@ mod test { len += "lower hex: ".write(&mut input[len..]).unwrap(); len += DisplayHint::LowerHex.write(&mut input[len..]).unwrap(); - 200.write(&mut input[len..]).unwrap(); + len += 200.write(&mut input[len..]).unwrap(); + + _ = len; let logger = logger(); let () = log_buf(&input, logger).unwrap(); @@ -645,7 +733,9 @@ mod test { len += "upper hex: ".write(&mut input[len..]).unwrap(); len += DisplayHint::UpperHex.write(&mut input[len..]).unwrap(); - 200.write(&mut input[len..]).unwrap(); + len += 200.write(&mut input[len..]).unwrap(); + + _ = len; let logger = logger(); let () = log_buf(&input, logger).unwrap(); @@ -664,7 +754,9 @@ mod test { len += "ipv4: ".write(&mut input[len..]).unwrap(); len += DisplayHint::Ipv4.write(&mut input[len..]).unwrap(); // 10.0.0.1 as u32 - 167772161u32.write(&mut input[len..]).unwrap(); + len += 167772161u32.write(&mut input[len..]).unwrap(); + + _ = len; let logger = logger(); let () = log_buf(&input, logger).unwrap(); @@ -687,7 +779,9 @@ mod test { 0x20, 0x01, 0x0d, 0xb8, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x01, 0x00, 0x01, ]; - ipv6_arr.write(&mut input[len..]).unwrap(); + len += ipv6_arr.write(&mut input[len..]).unwrap(); + + _ = len; let logger = logger(); let () = log_buf(&input, logger).unwrap(); @@ -709,7 +803,9 @@ mod test { let ipv6_arr: [u16; 8] = [ 0x2001, 0x0db8, 0x0000, 0x0000, 0x0000, 0x0000, 0x0001, 0x0001, ]; - ipv6_arr.write(&mut input[len..]).unwrap(); + len += ipv6_arr.write(&mut input[len..]).unwrap(); + + _ = len; let logger = logger(); let () = log_buf(&input, logger).unwrap(); @@ -729,7 +825,9 @@ mod test { len += DisplayHint::LowerMac.write(&mut input[len..]).unwrap(); // 00:00:5e:00:53:af as byte array let mac_arr: [u8; 6] = [0x00, 0x00, 0x5e, 0x00, 0x53, 0xaf]; - mac_arr.write(&mut input[len..]).unwrap(); + len += mac_arr.write(&mut input[len..]).unwrap(); + + _ = len; let logger = logger(); let () = log_buf(&input, logger).unwrap(); @@ -749,7 +847,9 @@ mod test { len += DisplayHint::UpperMac.write(&mut input[len..]).unwrap(); // 00:00:5E:00:53:AF as byte array let mac_arr: [u8; 6] = [0x00, 0x00, 0x5e, 0x00, 0x53, 0xaf]; - mac_arr.write(&mut input[len..]).unwrap(); + len += mac_arr.write(&mut input[len..]).unwrap(); + + _ = len; let logger = logger(); let () = log_buf(&input, logger).unwrap(); diff --git a/test/integration-ebpf/src/log.rs b/test/integration-ebpf/src/log.rs index d4570103..7192d5c7 100644 --- a/test/integration-ebpf/src/log.rs +++ b/test/integration-ebpf/src/log.rs @@ -17,6 +17,8 @@ pub fn test_log(ctx: ProbeContext) { trace!(&ctx, "mac lc: {:mac}, mac uc: {:MAC}", mac, mac); let hex = 0x2f; warn!(&ctx, "hex lc: {:x}, hex uc: {:X}", hex, hex); + let hex = [0xde, 0xad, 0xbe, 0xef].as_slice(); + debug!(&ctx, "hex lc: {:x}, hex uc: {:X}", hex, hex); } #[panic_handler] diff --git a/test/integration-test/src/tests/log.rs b/test/integration-test/src/tests/log.rs index fd99d859..811952a3 100644 --- a/test/integration-test/src/tests/log.rs +++ b/test/integration-test/src/tests/log.rs @@ -104,12 +104,12 @@ async fn log() { // Call the function that the uprobe is attached to, so it starts logging. trigger_ebpf_program(); - captured_logs.wait_expected_len(5).await; + captured_logs.wait_expected_len(6).await; let records = captured_logs .lock() .expect("Failed to acquire a lock for reading logs"); - assert_eq!(records.len(), 5); + assert_eq!(records.len(), 6); assert_eq!(records[0].body, "Hello from eBPF!"); assert_eq!(records[0].level, Level::Debug); @@ -133,4 +133,8 @@ async fn log() { assert_eq!(records[4].body, "hex lc: 2f, hex uc: 2F"); assert_eq!(records[4].level, Level::Warn); assert_eq!(records[4].target, "log"); + + assert_eq!(records[5].body, "hex lc: deadbeef, hex uc: DEADBEEF"); + assert_eq!(records[5].level, Level::Debug); + assert_eq!(records[5].target, "log"); }