From 5582da19e8e42c369dd1063e62767bc052b3ed96 Mon Sep 17 00:00:00 2001 From: Tiziano Santoro Date: Mon, 15 Jan 2024 20:40:11 +0000 Subject: [PATCH] Add logs to stage1 Ref #4652 --- oak_containers_stage1/src/client.rs | 5 +++++ oak_containers_stage1/src/dice.rs | 15 +++++++++++++-- oak_containers_stage1/src/image.rs | 1 + oak_containers_stage1/src/main.rs | 10 ++++++++++ 4 files changed, 29 insertions(+), 2 deletions(-) diff --git a/oak_containers_stage1/src/client.rs b/oak_containers_stage1/src/client.rs index fa12f531fd8..4c9e427b490 100644 --- a/oak_containers_stage1/src/client.rs +++ b/oak_containers_stage1/src/client.rs @@ -45,6 +45,7 @@ impl LauncherClient { .context("couldn't form streaming connection")? .into_inner(); + println!("get_oak_system_image: got stream"); let mut image_buf: Vec = Vec::new(); while let Some(mut load_response) = stream .message() @@ -53,6 +54,10 @@ impl LauncherClient { { image_buf.append(&mut load_response.image_chunk); } + println!( + "get_oak_system_image: stream terminated, got {} bytes", + image_buf.len() + ); Ok(image_buf) } diff --git a/oak_containers_stage1/src/dice.rs b/oak_containers_stage1/src/dice.rs index f6b797604c5..f65c6ac9622 100644 --- a/oak_containers_stage1/src/dice.rs +++ b/oak_containers_stage1/src/dice.rs @@ -87,20 +87,27 @@ fn read_stage0_dice_data(start: PhysAddr) -> anyhow::Result { let length = std::mem::size_of::(); // Linux presents an inclusive end address. let end = start + (length as u64 - 1); + + println!("Reading DICE data from physical memory. Start={start:p}, End={end:p}"); + // Ensure that the exact memory range is marked as reserved. if !read_memory_ranges()?.iter().any(|range| { range.start == start && range.end == end && range.type_description == EXPECTED_E820_TYPE }) { anyhow::bail!("DICE data range is not reserved"); } + println!("DICE data range is reserved"); // Open a file representing the physical memory. - let dice_file = OpenOptions::new() + let dice_file_descriptor = OpenOptions::new() .read(true) .write(true) .open(PHYS_MEM_PATH) .context("couldn't open DICE memory device for reading")?; + println!("Opened DICE memory device for reading: FD={dice_file_descriptor:?}"); + + println!("Mapping DICE data into virtual memory"); // Safety: we have checked that the exact memory range is marked as reserved so the Linux kernel // will not use it for anything else. let start_ptr = unsafe { @@ -109,10 +116,11 @@ fn read_stage0_dice_data(start: PhysAddr) -> anyhow::Result { length.try_into()?, ProtFlags::PROT_READ | ProtFlags::PROT_WRITE, MapFlags::MAP_SHARED, - dice_file.as_raw_fd(), + dice_file_descriptor.as_raw_fd(), start.as_u64().try_into()?, )? }; + println!("Mapped DICE data into virtual memory: Start={start_ptr:p}"); let result = { // Safety: we have checked the length, know it is backed by physical memory and is reserved. @@ -125,6 +133,7 @@ fn read_stage0_dice_data(start: PhysAddr) -> anyhow::Result { source.zeroize(); result }; + println!("Read DICE data: Magic={}", result.magic); if result.magic != STAGE0_MAGIC { anyhow::bail!("invalid DICE data"); @@ -132,6 +141,8 @@ fn read_stage0_dice_data(start: PhysAddr) -> anyhow::Result { // Safety: we have just mapped this memory, and the slice over it has been dropped. unsafe { munmap(start_ptr, length)? }; + println!("Unmapped DICE data from virtual memory"); + Ok(result) } diff --git a/oak_containers_stage1/src/image.rs b/oak_containers_stage1/src/image.rs index bf4fa391a06..47c3254c3c7 100644 --- a/oak_containers_stage1/src/image.rs +++ b/oak_containers_stage1/src/image.rs @@ -35,6 +35,7 @@ pub fn switch(init: &str) -> Result { let args: Vec = std::env::args_os() .map(|arg| CString::new(arg.as_bytes()).unwrap()) .collect(); + println!("Switching to {init} with args {args:?}"); execv(CString::new(init).unwrap().as_c_str(), &args[..])?; unreachable!() } diff --git a/oak_containers_stage1/src/main.rs b/oak_containers_stage1/src/main.rs index f23880c667e..b29f52949ba 100644 --- a/oak_containers_stage1/src/main.rs +++ b/oak_containers_stage1/src/main.rs @@ -57,6 +57,8 @@ struct Args { #[tokio::main] async fn main() -> Result<(), Box> { let args = Args::parse(); + + println!("Mounting /dev"); if !Path::new("/dev").try_exists()? { create_dir("/dev").context("error creating /dev")?; } @@ -69,6 +71,7 @@ async fn main() -> Result<(), Box> { ) .context("error mounting /dev")?; + println!("Creating /dev/ram0"); Command::new("/mke2fs") .args(["/dev/ram0"]) .spawn()? @@ -77,6 +80,8 @@ async fn main() -> Result<(), Box> { if !Path::new("/rootfs").try_exists()? { create_dir("/rootfs").context("error creating /rootfs")?; } + + println!("Mounting /dev/ram0 to /rootfs"); mount( Some("/dev/ram0"), "/rootfs", @@ -86,6 +91,7 @@ async fn main() -> Result<(), Box> { ) .context("error mounting ramdrive to /rootfs")?; + println!("Mounting /sys"); // Mount /sys so that we can read the memory map. if !Path::new("/sys").try_exists()? { create_dir("/sys").context("error creating /sys")?; @@ -102,10 +108,12 @@ async fn main() -> Result<(), Box> { let mut dice_builder = dice::extract_stage0_dice_data(args.dice_addr)?; // Unmount /sys and /dev as they are no longer needed. + println!("Unmounting /sys and /dev"); umount("/sys").context("failed to unmount /sys")?; umount("/dev").context("failed to unmount /dev")?; // switch_root(8) magic + println!("Switching root"); chdir("/rootfs").context("failed to chdir to /rootfs")?; mount( Some("/rootfs"), @@ -118,10 +126,12 @@ async fn main() -> Result<(), Box> { chroot(".").context("failed to chroot to .")?; chdir("/").context("failed to chdir to /")?; + println!("Creating launcher client"); let mut client = LauncherClient::new(args.launcher_addr.parse()?) .await .context("error creating the launcher client")?; + println!("Fetching system image"); let buf = client .get_oak_system_image() .await