runtime: add trace logs and fix few bugs

Add tracing logs in Runtime::enter and other critical points.

Pass trace_scheduler feature down to eonix_runtime crate, fixing the
problem that the feature is not working.

When the task is blocked, we set CURRENT_TASK to None as well.

In early initialization stage, the stack is placed in identically mapped
physical address. VirtIO driver might try converting the given buffer
paths back to physical ones, which will generate errors. So BSP and AP
should allocate an another stack and switch to it. We use TaskContext
for the fix.

Signed-off-by: greatbridf <greatbridf@icloud.com>

Cargo.toml

@@ -39,7 +39,7 @@ virtio-drivers = { version = "0.11.0" }
 default = []
 trace_pci = []
 trace_syscall = []
-trace_scheduler = []
+trace_scheduler = ["eonix_runtime/trace_scheduler"]
 log_trace = ["trace_pci", "trace_syscall", "trace_scheduler"]
 log_debug = []
 smp = []

crates/eonix_runtime/src/scheduler.rs

@@ -10,6 +10,7 @@ use core::{
     task::{Context, Poll, Waker},
 };
 use eonix_hal::processor::halt;
+use eonix_log::println_trace;
 use eonix_sync::{LazyLock, Spin, SpinIrq as _};
 use intrusive_collections::RBTree;
 use pointers::BorrowedArc;
@@ -99,7 +100,10 @@ impl Runtime {
     }
 
     fn remove_and_enqueue_current(&self, rq: &mut impl DerefMut<Target = dyn ReadyQueue>) {
-        let Some(current) = self.current() else {
+        let Some(current) = CURRENT_TASK
+            .swap(None)
+            .map(|cur| unsafe { Arc::from_raw(cur.as_ptr()) })
+        else {
             return;
         };
 
@@ -111,18 +115,23 @@ impl Runtime {
             }
         }) {
             Ok(TaskState::READY_RUNNING) => {
-                let current = unsafe {
-                    Arc::from_raw(
-                        CURRENT_TASK
-                            .swap(None)
-                            .expect("Current task should be present")
-                            .as_ptr(),
-                    )
-                };
+                println_trace!(
+                    "trace_scheduler",
+                    "Re-enqueueing task {:?} (CPU{})",
+                    current.id,
+                    eonix_hal::processor::CPU::local().cpuid(),
+                );
 
                 rq.put(current);
             }
-            Ok(_) => {}
+            Ok(_) => {
+                println_trace!(
+                    "trace_scheduler",
+                    "Current task {:?} (CPU{}) is blocked, not re-enqueueing",
+                    current.id,
+                    eonix_hal::processor::CPU::local().cpuid(),
+                );
+            }
             _ => unreachable!(),
         }
     }
@@ -174,6 +183,13 @@ impl Runtime {
                 continue;
             };
 
+            println_trace!(
+                "trace_scheduler",
+                "Switching to task {:?} (CPU{})",
+                next.id,
+                eonix_hal::processor::CPU::local().cpuid(),
+            );
+
             let old_state = next.state.swap(TaskState::RUNNING);
             assert_eq!(
                 old_state,
@@ -195,6 +211,12 @@ impl Runtime {
                     "Current task should be at least in RUNNING state"
                 );
 
+                println_trace!(
+                    "trace_scheduler",
+                    "Task {:?} finished execution, removing...",
+                    Task::current().id,
+                );
+
                 self.remove_task(&Task::current());
 
                 CURRENT_TASK.set(None);

src/lib.rs

@@ -28,15 +28,16 @@ use core::{
 };
 use eonix_hal::{
     arch_exported::bootstrap::shutdown,
+    context::TaskContext,
     processor::{halt, CPU, CPU_COUNT},
-    traits::trap::IrqState,
+    traits::{context::RawTaskContext, trap::IrqState},
     trap::disable_irqs_save,
 };
 use eonix_mm::address::PRange;
-use eonix_runtime::scheduler::RUNTIME;
+use eonix_runtime::{executor::Stack, scheduler::RUNTIME};
 use kernel::{
     mem::GlobalPageAlloc,
-    task::{ProcessBuilder, ProcessList, ProgramLoader, ThreadBuilder},
+    task::{KernelStack, ProcessBuilder, ProcessList, ProgramLoader, ThreadBuilder},
     vfs::{
         dentry::Dentry,
         mount::{do_mount, MS_NOATIME, MS_NODEV, MS_NOSUID, MS_RDONLY},
@@ -115,8 +116,21 @@ fn kernel_init(mut data: eonix_hal::bootstrap::BootStrapData) -> ! {
 
     drop(data);
 
-    RUNTIME.enter();
-    shutdown_system();
+    let mut ctx = TaskContext::new();
+    let stack_bottom = {
+        let stack = KernelStack::new();
+        let bottom = stack.get_bottom().addr().get();
+        core::mem::forget(stack);
+
+        bottom
+    };
+    ctx.set_interrupt_enabled(true);
+    ctx.set_program_counter(standard_main as usize);
+    ctx.set_stack_pointer(stack_bottom);
+
+    unsafe {
+        TaskContext::switch_to_noreturn(&mut ctx);
+    }
 }
 
 #[eonix_hal::ap_main]
@@ -128,6 +142,24 @@ fn kernel_ap_main(_stack_range: PRange) -> ! {
 
     println_debug!("AP{} started", CPU::local().cpuid());
 
+    let mut ctx = TaskContext::new();
+    let stack_bottom = {
+        let stack = KernelStack::new();
+        let bottom = stack.get_bottom().addr().get();
+        core::mem::forget(stack);
+
+        bottom
+    };
+    ctx.set_interrupt_enabled(true);
+    ctx.set_program_counter(standard_main as usize);
+    ctx.set_stack_pointer(stack_bottom);
+
+    unsafe {
+        TaskContext::switch_to_noreturn(&mut ctx);
+    }
+}
+
+fn standard_main() -> ! {
     RUNTIME.enter();
     shutdown_system();
 }