Add logs to stage1

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<u8> = 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)
  }

oak_containers_stage1/src/dice.rs

@@ -87,20 +87,27 @@ fn read_stage0_dice_data(start: PhysAddr) -> anyhow::Result<Stage0DiceData> {
  let length = std::mem::size_of::<Stage0DiceData>();
  // 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<Stage0DiceData> {
  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,13 +133,16 @@ fn read_stage0_dice_data(start: PhysAddr) -> anyhow::Result<Stage0DiceData> {
  source.zeroize();
  result
  };
+ println!("Read DICE data: Magic={}", result.magic);
 
  if result.magic != STAGE0_MAGIC {
  anyhow::bail!("invalid DICE data");
  }
 
  // 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)
 }
 

oak_containers_stage1/src/image.rs

@@ -35,6 +35,7 @@ pub fn switch(init: &str) -> Result<!> {
  let args: Vec<CString> = 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!()
 }

oak_containers_stage1/src/main.rs

@@ -57,6 +57,8 @@ struct Args {
 #[tokio::main]
 async fn main() -> Result<(), Box<dyn Error>> {
  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<dyn Error>> {
  )
  .context("error mounting /dev")?;
 
+ println!("Creating /dev/ram0");
  Command::new("/mke2fs")
  .args(["/dev/ram0"])
  .spawn()?
@@ -77,6 +80,8 @@ async fn main() -> Result<(), Box<dyn Error>> {
  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<dyn Error>> {
  )
  .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<dyn Error>> {
  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<dyn Error>> {
  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