Runtime tests cause QEMU to exit with `1` if run after `exit_boot_services()`

[timrobertsdev]

rustc --version: rustc 1.57.0-nightly (fdf65053e 2021-09-07)
qemu-system-x86_64 --version: QEMU emulator version 4.2.1 (Debian 1:4.2-3ubuntu6.17)

Running ./build.py run after moving the runtime::test() call to after exit_boot_services() results in QEMU hanging for a few seconds and then exiting with Subprocess qemu-system-x86_64 exited with error code 1. I left the original runtime::test() call in efi_main() and then added two more, both in shutdown(), one before we exit boot services and one after. The first two calls execute and succeed, the third crashes.

I've been attempting to investigate why, but I've been having a little trouble getting rust-gdb and rust-lldb to recognize the symbols in the uefi-test-runner.efi binary. Oddly enough, objdump -freports that it is flagged as HAS_DEBUG, but objdump -t wasn't able to find any symbols. Attemping image dump symtab in rust-lldb results in num-symbols = 0. I've probably got something setup incorrectly on my end, any advice would be greatly appreciated.

[nicholasbishop]

Confirmed this, not sure yet what's going wrong. Here is a bit more detail:

With this diff I see the hang and exit code 1 as you described:

--- a/uefi-test-runner/src/main.rs
+++ b/uefi-test-runner/src/main.rs
@@ -140,6 +140,8 @@ fn shutdown(image: uefi::Handle, mut st: SystemTable<Boot>) -> ! {
         .exit_boot_services(image, &mut mmap_storage[..])
         .expect_success("Failed to exit boot services");
 
+    runtime::test(unsafe { st.runtime_services() });
+
     #[cfg(target_arch = "x86_64")]
     {
         if cfg!(feature = "qemu") {

However, if I move the runtime::test call down to just before the reset, it exits cleanly:

--- a/uefi-test-runner/src/main.rs
+++ b/uefi-test-runner/src/main.rs
@@ -150,6 +150,8 @@ fn shutdown(image: uefi::Handle, mut st: SystemTable<Boot>) -> ! {
         }
     }
 
+    runtime::test(unsafe { st.runtime_services() });
+
     // Shut down the system
     let rt = unsafe { st.runtime_services() };
     rt.reset(ResetType::Shutdown, Status::SUCCESS, None);

[nicholasbishop]

I think I see the problem. In uefi-test-runner/src/runtime/vars.rs, there's a call to CString16::try_from. This function requires allocation, but the allocator implementation in src/alloc.rs only works while boot services are active. Once boot services are exited, the allocator will start returning null, so use of dynamic structures like Vec will panic. This should probably be better documented, I'll see about doing that.

[nicholasbishop]

OK, put up a PR here to add some documentation about the fact that the allocator (and logger) won't work once boot services is exited. That won't make a problem like this immediately obvious maybe, since there's no logger to print out the fact that the allocator can't be used then :) But hopefully the info is at least a little easier to find.

I also opened a separate issue for your question about debugging. I don't know the answer, but would like to :)

Closing this since testing the runtime var stuff prior to exiting boot services as currently implemented does work correctly, and I think the mystery of the crash is solved.

[nicholasbishop]

Another followup, put up a PR to stop allocating in that test: #291