Repository: theseus-os/Theseus (language: rust)

Issue:
APIC timer calibration is inaccurate on KVM --> timeslice period is too short
The APIC timer calibration is wrong or somehow inaccurate when running on KVM (`make run host=yes`), which results in the timeslice period being VERY short, and effectively just  context switching on all CPUs incessantly. Thus, it looks as if the system makes no progress or is hung, but in reality it's running correctly.

By choosing a fixed, very large APIC LVT timer calibration value (e.g., `cfg(apic_timer_fixed)` setting a value of 0x10000000), the system works perfectly well... 

_Originally posted by @kevinaboos in https://github.com/theseus-os/Theseus/issues/676#issuecomment-1295695879_
      


Discussion / hints:
how can I get started solving this?
Sorry for the delay, I missed your question. This is a difficult issue to debug as I myself am not sure of the exact cause.

I would start by using a variety of timer sources (PIT, RTC, HPET, TSC) to calibrate the local apic timer to see if there is a huge difference in the calibration value; perhaps we are just making a minor math mistake or there is some other issue stemming from our reliance on PIT. 

I would also review Intel's Local APIC documentation to make sure we're understanding how things work in x2apic mode, and double check that we're not making any mistakes when initializing x2apic registers on each local apic. Sorry I don't have a clearer path forward on this issue; it requires some pretty in-depth knowledge about how Local APIC works on x2apic systems.

Fix patch:
diff --git a/kernel/apic/src/lib.rs b/kernel/apic/src/lib.rs
index fed8438473..4aff77166a 100644
--- a/kernel/apic/src/lib.rs
+++ b/kernel/apic/src/lib.rs
@@ -19,10 +19,24 @@ use log::{error, info, debug, trace};
 /// A unique identifier for a CPU core.
 pub type CpuId = u8;
 
-/// The IRQ number reserved for Local APIC timer interrupts in the IDT.
-pub const LOCAL_APIC_LVT_IRQ: u8 = 0x22;
+// Values for the `IA32_APIC_BASE` MSR.
+const IA32_APIC_IS_BSP:                u64 = 1 << 8;
+const IA32_APIC_XAPIC_ENABLE:          u64 = 1 << 11;
+const IA32_APIC_X2APIC_ENABLE:         u64 = 1 << 10;
+
+// Value for the APIC spurious interrupt vector register.
+const APIC_SW_ENABLE:                  u32 = 1 << 8;
 /// The IRQ number reserved for spurious APIC interrupts (as recommended by OS dev wiki).
-pub const APIC_SPURIOUS_INTERRUPT_IRQ: u8 = 0xFF;
+pub const APIC_SPURIOUS_INTERRUPT_IRQ: u8  = 0xFF;
+
+// APIC timer register values.
+const APIC_TIMER_DISABLE:              u32 = 1 << 16;
+const _APIC_TIMER_MODE_ONESHOT:        u32 = 0b00 << 17;
+const APIC_TIMER_MODE_PERIODIC:        u32 = 0b01 << 17;
+const _APIC_TIMER_MODE_TSC_DEADLINE:   u32 = 0b10 << 17;
+/// The IRQ number reserved for Local APIC timer interrupts in the IDT.
+pub const LOCAL_APIC_LVT_IRQ:          u8  = 0x22;
+
 
 /// The interrupt chip that is currently configured on this machine. 
 /// The default is `InterruptChip::PIC`, but the typical case is `APIC` or `X2APIC`,
@@ -59,7 +73,7 @@ pub fn bootstrap_cpu() -> Option<CpuId> {
 /// Returns true if the currently executing CPU is the bootstrap CPU, 
 /// i.e., the first procesor to run after system power-on.
 pub fn is_bootstrap_cpu() -> bool {
-    rdmsr(IA32_APIC_BASE) & IA32_APIC_BASE_MSR_IS_BSP == IA32_APIC_BASE_MSR_IS_BSP
+    rdmsr(IA32_APIC_BASE) & IA32_APIC_IS_BSP == IA32_APIC_IS_BSP
 }
 
 /// Returns true if the machine has support for x2apic
@@ -96,6 +110,65 @@ pub fn get_my_apic() -> Option<&'static RwLockIrqSafe<LocalApic>> {
     LOCAL_APICS.get(&current_cpu())
 }
 
+/// The delivery mode used when an interrupt is sent to a CPU core.
+///
+/// This value can be used in the following APIC registers:
+/// * timer
+/// * CMCI (corrected machine check error)
+/// * lint0
+/// * lint1
+/// * performance monitoring counters
+/// * thermal sensor
+#[derive(Clone, Copy, Debug)]
+#[repr(u32)]
+pub enum LapicDeliveryMode {
+    /// Delivers the interrupt (as normal) to the IRQ specified in the vector field.
+    Fixed  = 0b000,
+    /// Delivers an SMI interrupt to the CPU; the vector field should be 0x00.
+    Smi    = 0b010,
+    /// Delivers an NMI interrupt to the CPU; the vector field is ignored.
+    Nmi    = 0b100,
+    /// Delivers an INIT request to the CPU; the vector field should be 0x00.
+    Init   = 0b101,
+    /// Causes the CPU to respond to the interrupts as if it originated from
+    /// an external interrupt controller (e.g., the PIC).
+    ExtInt = 0b111,
+    // all other values are reserved
+}
+impl LapicDeliveryMode {
+    fn as_register_value(&self) -> u32 {
+        (*self as u32) << 8
+    }
+}
+
+/// The possible values for the Local APIC Timer Divide Configuration Register.
+#[derive(Clone, Copy, Debug)]
+#[repr(u32)]
+pub enum LapicTimerDivide {
+    By1   = 1,
+    By2   = 2,
+    By4   = 4,
+    By8   = 8,
+    By16  = 16,
+    By32  = 32,
+    By64  = 64,
+    By128 = 128,
+}
+impl LapicTimerDivide {
+    fn as_register_value(&self) -> u32 {
+        // Note: bit 2 is always 0.
+        match self {
+            Self::By1   => 0b1011,
+            Self::By2   => 0b0000,
+            Self::By4   => 0b0001,
+            Self::By8   => 0b0010,
+            Self::By16  => 0b0011,
+            Self::By32  => 0b1000,
+            Self::By64  => 0b1001,
+            Self::By128 => 0b1010,
+        }
+    }
+}
 
 /// The possible destination shorthand values for IPI ICR.
 /// 
@@ -171,17 +244,6 @@ fn map_apic(page_table: &mut PageTable) -> Result<MappedPages, &'static str> {
 }
 
 
-
-const IA32_APIC_XAPIC_ENABLE: u64 = 1 << 11; // 0x800
-const IA32_APIC_X2APIC_ENABLE: u64 = 1 << 10; // 0x400
-const IA32_APIC_BASE_MSR_IS_BSP: u64 = 1 << 8; // 0x100
-const APIC_SW_ENABLE: u32 = 1 << 8;
-const APIC_TIMER_PERIODIC:  u32 = 0x2_0000;
-const APIC_DISABLE: u32 = 0x1_0000;
-const APIC_NMI: u32 = 4 << 8;
-
-
-
 /// A structure that offers access to APIC/xAPIC through its I/O registers.
 ///
 /// Definitions are based on Intel's x86 Manual Vol 3a, Table 10-1. 
@@ -334,6 +396,9 @@ pub struct LocalApic {
     processor_id: u8,
     /// Whether this Local APIC is the BootStrap Processor (the first CPU to boot up).
     is_bootstrap_cpu: bool,
+    /// The value that should be written to the APIC timer's initial count register
+    /// when enabling the LVT timer.
+    initial_timer_count: u32,
 }
 impl fmt::Debug for LocalApic {
     fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
@@ -342,7 +407,7 @@ impl fmt::Debug for LocalApic {
             .field("apic_id", &self.apic_id)
             .field("processor_id", &self.processor_id)
             .field("is_bootstrap_cpu", &self.is_bootstrap_cpu)
-            .finish()
+            .finish_non_exhaustive()
     }
 }
 impl Drop for LocalApic {
@@ -396,7 +461,7 @@ impl LocalApic {
         };
 
         // Check whether the caller's expectations about BSP vs AP were met.
-        let is_bootstrap_cpu = rdmsr(IA32_APIC_BASE) & IA32_APIC_BASE_MSR_IS_BSP == IA32_APIC_BASE_MSR_IS_BSP;
+        let is_bootstrap_cpu = rdmsr(IA32_APIC_BASE) & IA32_APIC_IS_BSP == IA32_APIC_IS_BSP;
         if should_be_bsp && !is_bootstrap_cpu {
             return Err(LapicInitError::NotBSP);
         }
@@ -431,6 +496,7 @@ impl LocalApic {
             processor_id,
             apic_id: CpuId::MAX, // placeholder, is replaced below.
             is_bootstrap_cpu,
+            initial_timer_count: 0, // set in `calibrate_lapic_timer()`
         };
 
         // Now that the APIC hardware is enabled, we can safely obtain this Local APIC's ID.
@@ -498,10 +564,10 @@ impl LocalApic {
                 // NOTE: we're not yet using logical or cluster mode APIC addressing, only physical APIC addressing.
                 
                 unsafe {
-                    wrmsr(IA32_X2APIC_LVT_TIMER,  APIC_DISABLE as u64);
-                    wrmsr(IA32_X2APIC_LVT_PMI,    APIC_NMI as u64);
-                    wrmsr(IA32_X2APIC_LVT_LINT0,  APIC_DISABLE as u64);
-                    wrmsr(IA32_X2APIC_LVT_LINT1,  APIC_DISABLE as u64);
+                    wrmsr(IA32_X2APIC_LVT_TIMER,  APIC_TIMER_DISABLE as u64);
+                    wrmsr(IA32_X2APIC_LVT_PMI,    LapicDeliveryMode::Nmi.as_register_value() as u64);
+                    wrmsr(IA32_X2APIC_LVT_LINT0,  APIC_TIMER_DISABLE as u64);
+                    wrmsr(IA32_X2APIC_LVT_LINT1,  APIC_TIMER_DISABLE as u64);
                     wrmsr(IA32_X2APIC_TPR,        0);
                     
                     // set bit 8 to start receiving interrupts (still need to "sti")
@@ -517,10 +583,10 @@ impl LocalApic {
                 // Init xAPIC to a clean known state.
                 // See <http://wiki.osdev.org/APIC#Logical_Destination_Mode>
                 regs.destination_format.write(0xFFFF_FFFF);
-                regs.lvt_timer.write(APIC_DISABLE);
-                regs.lvt_perf_monitor.write(APIC_NMI);
-                regs.lvt_lint0.write(APIC_DISABLE);
-                regs.lvt_lint1.write(APIC_DISABLE);
+                regs.lvt_timer.write(APIC_TIMER_DISABLE);
+                regs.lvt_perf_monitor.write(LapicDeliveryMode::Nmi.as_register_value());
+                regs.lvt_lint0.write(APIC_TIMER_DISABLE);
+                regs.lvt_lint1.write(APIC_TIMER_DISABLE);
                 regs.task_priority.write(0);
 
                 // set bit 8 to allow receiving interrupts (still need to "sti")
@@ -530,32 +596,34 @@ impl LocalApic {
     }
 
     /// Returns the number of APIC ticks that occurred during the given number of `microseconds`.
-    fn calibrate_lapic_timer(&mut self, microseconds: u32) -> u64 {
+    ///
+    /// The number of ticks must be a `u32` due to the size of the APIC timer count register.
+    fn calibrate_lapic_timer(&mut self, microseconds: u32) -> u32 {
         // Start with the max counter value, since we're counting down
-        const INITIAL_COUNT: u64 = 0xFFFF_FFFF;
+        const INITIAL_COUNT: u32 = 0xFFFF_FFFF;
 
         let end_count = match &mut self.inner {
             LapicType::X2Apic => {
                 unsafe { 
-                    wrmsr(IA32_X2APIC_DIV_CONF, 3); // set divide value to 16
-                    wrmsr(IA32_X2APIC_INIT_COUNT, INITIAL_COUNT);
+                    wrmsr(IA32_X2APIC_DIV_CONF, LapicTimerDivide::By16.as_register_value() as u64);
+                    wrmsr(IA32_X2APIC_INIT_COUNT, INITIAL_COUNT as u64);
                 }
 
                 // wait for the given period using the PIT clock
                 pit_wait(microseconds).unwrap();
 
-                unsafe { wrmsr(IA32_X2APIC_LVT_TIMER, APIC_DISABLE as u64); } // stop apic timer
-                rdmsr(IA32_X2APIC_CUR_COUNT)
+                unsafe { wrmsr(IA32_X2APIC_LVT_TIMER, APIC_TIMER_DISABLE as u64); } // stop apic timer
+                rdmsr(IA32_X2APIC_CUR_COUNT) as u32
             }
             LapicType::XApic(regs) => {
-                regs.timer_divide.write(3); // set divide value to 16
+                regs.timer_divide.write(LapicTimerDivide::By16.as_register_value());
                 regs.timer_initial_count.write(INITIAL_COUNT as u32);
 
                 // wait for the given period using the PIT clock
                 pit_wait(microseconds).unwrap();
 
-                regs.lvt_timer.write(APIC_DISABLE); // stop apic timer
-                regs.timer_current_count.read() as u64
+                regs.lvt_timer.write(APIC_TIMER_DISABLE); // stop apic timer
+                regs.timer_current_count.read()
             }
         };
         
@@ -571,50 +639,67 @@ impl LocalApic {
             self.calibrate_lapic_timer(CONFIG_TIMESLICE_PERIOD_MICROSECONDS)
         };
         trace!("LocalApic {}, timer period count: {} ({:#X})", self.apic_id, apic_period, apic_period);
+        self.initial_timer_count = apic_period;
 
         match &mut self.inner {
             LapicType::X2Apic => unsafe {
-                wrmsr(IA32_X2APIC_DIV_CONF, 3); // set divide value to 16 ( ... how does 3 => 16 )
+                wrmsr(IA32_X2APIC_DIV_CONF, LapicTimerDivide::By16.as_register_value() as u64);
                 
                 // map X2APIC timer to the `LOCAL_APIC_LVT_IRQ` interrupt handler in the IDT
-                wrmsr(IA32_X2APIC_LVT_TIMER, LOCAL_APIC_LVT_IRQ as u64 | APIC_TIMER_PERIODIC as u64); 
-                wrmsr(IA32_X2APIC_INIT_COUNT, apic_period); 
+                wrmsr(IA32_X2APIC_LVT_TIMER, LOCAL_APIC_LVT_IRQ as u64 | APIC_TIMER_MODE_PERIODIC as u64); 
+                wrmsr(IA32_X2APIC_INIT_COUNT, apic_period as u64); 
     
                 wrmsr(IA32_X2APIC_LVT_THERMAL, 0);
                 wrmsr(IA32_X2APIC_ESR, 0);
     
                 // os dev wiki guys say that setting this again as a last step helps on some strange hardware.
-                wrmsr(IA32_X2APIC_DIV_CONF, 3);
+                wrmsr(IA32_X2APIC_DIV_CONF, LapicTimerDivide::By16.as_register_value() as u64);
             }
             LapicType::XApic(regs) => {
-                regs.timer_divide.write(3); // set divide value to 16 ( ... how does 3 => 16 )
+                regs.timer_divide.write(LapicTimerDivide::By16.as_register_value());
                 // map APIC timer to an interrupt handler in the IDT
-                regs.lvt_timer.write(LOCAL_APIC_LVT_IRQ as u32 | APIC_TIMER_PERIODIC); 
+                regs.lvt_timer.write(LOCAL_APIC_LVT_IRQ as u32 | APIC_TIMER_MODE_PERIODIC); 
                 regs.timer_initial_count.write(apic_period as u32); 
 
                 regs.lvt_thermal.write(0);
                 regs.lvt_error.write(0);
 
                 // os dev wiki guys say that setting this again as a last step helps on some strange hardware.
-                regs.timer_divide.write(3);
+                regs.timer_divide.write(LapicTimerDivide::By16.as_register_value());
             }
         }
     }
 
     /// Enable (unmask) or disable (mask) the LVT timer interrupt on this lapic.
-    /// 
-    /// This does **not** modify the timer's current count value.
     pub fn enable_lvt_timer(&mut self, enable: bool) {
-        let value = if enable {
-            LOCAL_APIC_LVT_IRQ as u32 | APIC_TIMER_PERIODIC
+        // From section 10.5.4 of Intel SDM:
+        //   Changing the mode of the APIC timer (from one-shot to periodic or vice versa)
+        //   by writing to the timer LVT entry does not start the timer.
+        //   To start the timer, it is necessary to write to the initial-count register.
+        //
+        // Thus, when enabling the timer, we must immeditely write the initial count again.
+        if enable {
+            let timer_enable = LOCAL_APIC_LVT_IRQ as u32 | APIC_TIMER_MODE_PERIODIC;
+            match &mut self.inner {
+                LapicType::X2Apic => unsafe {
+                    wrmsr(IA32_X2APIC_LVT_TIMER, timer_enable as u64);
+                    wrmsr(IA32_X2APIC_INIT_COUNT, self.initial_timer_count as u64);
+                }
+                LapicType::XApic(regs) => {
+                    regs.lvt_timer.write(timer_enable);
+                    regs.timer_initial_count.write(self.initial_timer_count);
+                }
+            }
         } else {
-            APIC_DISABLE
-        };
-        match &mut self.inner {
-            LapicType::X2Apic => unsafe {
-                wrmsr(IA32_X2APIC_LVT_TIMER, value as u64)
-            },
-            LapicType::XApic(regs) => regs.lvt_timer.write(value),
+            let timer_disable = APIC_TIMER_DISABLE;
+            match &mut self.inner {
+                LapicType::X2Apic => unsafe {
+                    wrmsr(IA32_X2APIC_LVT_TIMER, timer_disable as u64);
+                }
+                LapicType::XApic(regs) => {
+                    regs.lvt_timer.write(timer_disable);
+                }
+            }
         }
     }
 
@@ -724,10 +809,11 @@ impl LocalApic {
     }
 
     /// Set the NonMaskableInterrupt redirect for this LocalApic.
+    ///
     /// Argument `lint` can be either 0 or 1, since each local APIC has two LVT LINTs
     /// (Local Vector Table Local INTerrupts)
     pub fn set_nmi(&mut self, lint: LvtLint, flags: u16) {
-        let value = (flags << 12) as u32 | APIC_NMI; // or APIC_NMI | 0x2000 ??
+        let value = (flags << 12) as u32 | LapicDeliveryMode::Nmi.as_register_value();
         match &mut self.inner {
             LapicType::X2Apic => unsafe { wrmsr(lint.msr(), value as u64) },
             LapicType::XApic(regs) => match lint {


Test patch: