Re: IOMMU faults after S3

["Marek Marczykowski-Górecki" <marmarek@invisiblethingslab.com>]

[-- Attachment #1.1: Type: text/plain, Size: 5240 bytes --]

On Thu, Apr 02, 2026 at 10:39:41AM +0200, Jan Beulich wrote:
> On 02.04.2026 10:08, Marek Marczykowski-Górecki wrote:
> > The xl dmesg output (from MTL this time):
> > 
> >     (XEN) [  123.477511] Entering ACPI S3 state.
> >     (XEN) [18446743903.571842] _disable_pit_irq:2649: using_pit: 0, cpu_has_apic: 1
> >     (XEN) [18446743903.571856] _disable_pit_irq:2659: cpuidle_using_deep_cstate: 1, boot_cpu_has(X86_FEATURE_XEN_ARAT): 0

> Hmm, but what you didn't log is whether __hpet_setup_msi_irq() actually
> succeeded everywhere. (And if it did, also logging HPET_Tn_ROUTE() values
> might be a good idea, if only to double check.)

Updated output:

    (XEN) [18446743899.720395] _disable_pit_irq:2649: using_pit: 0, cpu_has_apic: 1
    (XEN) [18446743899.720409] _disable_pit_irq:2659: cpuidle_using_deep_cstate: 1, boot_cpu_has(X86_FEATURE_XEN_ARAT): 0
    (XEN) [18446743899.720420] _disable_pit_irq:2662: init: 0
    (XEN) [18446743899.720431] hpet_broadcast_resume:663: hpet_events: ffff83046bc1f080
    (XEN) [18446743899.720579] hpet_broadcast_resume:674: num_hpets_used: 8
    (XEN) [18446743899.720587] hpet_broadcast_resume:692: cfg: 0x1
    (XEN) [18446743899.720599] hpet_broadcast_resume:697: i:0, hpet_events[i].msi.irq: 122, hpet_events[i].flags: 0
    (XEN) [18446743899.720612] hpet_msi_write:283: iommu_intremap: 2 (iommu_intremap_off: 0), HPET_Tn_ROUTE(ch->idx): 0x110
    (XEN) [18446743899.720638] hpet_msi_write:287: iommu_update_ire_from_msi rc: 0
    (XEN) [18446743899.720649] hpet_broadcast_resume:701: i:0, __hpet_setup_msi_irq ret: 0
    (XEN) [18446743899.720665] hpet_broadcast_resume:711: i:0, cfg: 0xc134
    (XEN) [18446743899.720674] hpet_broadcast_resume:697: i:1, hpet_events[i].msi.irq: 123, hpet_events[i].flags: 0
    (XEN) [18446743899.720684] hpet_msi_write:283: iommu_intremap: 2 (iommu_intremap_off: 0), HPET_Tn_ROUTE(ch->idx): 0x130
    (XEN) [18446743899.720707] hpet_msi_write:287: iommu_update_ire_from_msi rc: 0
    (XEN) [18446743899.720717] hpet_broadcast_resume:701: i:1, __hpet_setup_msi_irq ret: 0
    (XEN) [18446743899.720728] hpet_broadcast_resume:711: i:1, cfg: 0xc104
    (XEN) [18446743899.720737] hpet_broadcast_resume:697: i:2, hpet_events[i].msi.irq: 124, hpet_events[i].flags: 0
    (XEN) [18446743899.720747] hpet_msi_write:283: iommu_intremap: 2 (iommu_intremap_off: 0), HPET_Tn_ROUTE(ch->idx): 0x150
    (XEN) [18446743899.720771] hpet_msi_write:287: iommu_update_ire_from_msi rc: 0
    (XEN) [18446743899.720781] hpet_broadcast_resume:701: i:2, __hpet_setup_msi_irq ret: 0
    (XEN) [18446743899.720797] hpet_broadcast_resume:711: i:2, cfg: 0xc104
    (XEN) [18446743899.720805] hpet_broadcast_resume:697: i:3, hpet_events[i].msi.irq: 125, hpet_events[i].flags: 0
    (XEN) [18446743899.720816] hpet_msi_write:283: iommu_intremap: 2 (iommu_intremap_off: 0), HPET_Tn_ROUTE(ch->idx): 0x170
    (XEN) [18446743899.720838] hpet_msi_write:287: iommu_update_ire_from_msi rc: 0
    (XEN) [18446743899.720848] hpet_broadcast_resume:701: i:3, __hpet_setup_msi_irq ret: 0
    (XEN) [18446743899.720863] hpet_broadcast_resume:711: i:3, cfg: 0xc104
    (XEN) [18446743899.720872] hpet_broadcast_resume:697: i:4, hpet_events[i].msi.irq: 126, hpet_events[i].flags: 0
    (XEN) [18446743899.720882] hpet_msi_write:283: iommu_intremap: 2 (iommu_intremap_off: 0), HPET_Tn_ROUTE(ch->idx): 0x190
    (XEN) [18446743899.720905] hpet_msi_write:287: iommu_update_ire_from_msi rc: 0
    (XEN) [18446743899.720915] hpet_broadcast_resume:701: i:4, __hpet_setup_msi_irq ret: 0
    (XEN) [18446743899.720931] hpet_broadcast_resume:711: i:4, cfg: 0xc104
    (XEN) [18446743899.720939] hpet_broadcast_resume:697: i:5, hpet_events[i].msi.irq: 127, hpet_events[i].flags: 0
    (XEN) [18446743899.720949] hpet_msi_write:283: iommu_intremap: 2 (iommu_intremap_off: 0), HPET_Tn_ROUTE(ch->idx): 0x1b0
    (XEN) [18446743899.720971] hpet_msi_write:287: iommu_update_ire_from_msi rc: 0
    (XEN) [18446743899.720981] hpet_broadcast_resume:701: i:5, __hpet_setup_msi_irq ret: 0
    (XEN) [18446743899.720997] hpet_broadcast_resume:711: i:5, cfg: 0xc104
    (XEN) [18446743899.721006] hpet_broadcast_resume:697: i:6, hpet_events[i].msi.irq: 128, hpet_events[i].flags: 0
    (XEN) [18446743899.721016] hpet_msi_write:283: iommu_intremap: 2 (iommu_intremap_off: 0), HPET_Tn_ROUTE(ch->idx): 0x1d0
    (XEN) [18446743899.721039] hpet_msi_write:287: iommu_update_ire_from_msi rc: 0
    (XEN) [18446743899.721048] hpet_broadcast_resume:701: i:6, __hpet_setup_msi_irq ret: 0
    (XEN) [18446743899.721064] hpet_broadcast_resume:711: i:6, cfg: 0xc104
    (XEN) [18446743899.721072] hpet_broadcast_resume:697: i:7, hpet_events[i].msi.irq: 129, hpet_events[i].flags: 0
    (XEN) [18446743899.721082] hpet_msi_write:283: iommu_intremap: 2 (iommu_intremap_off: 0), HPET_Tn_ROUTE(ch->idx): 0x1f0
    (XEN) [18446743899.721105] hpet_msi_write:287: iommu_update_ire_from_msi rc: 0
    (XEN) [18446743899.721115] hpet_broadcast_resume:701: i:7, __hpet_setup_msi_irq ret: 0
    (XEN) [18446743899.721130] hpet_broadcast_resume:711: i:7, cfg: 0xc104

And the current debug diff attached.

-- 
Best Regards,
Marek Marczykowski-Górecki
Invisible Things Lab

[-- Attachment #1.2: xen-debug.diff --]
[-- Type: text/plain, Size: 4846 bytes --]

diff --git a/xen/arch/x86/cpu-policy.c b/xen/arch/x86/cpu-policy.c
index 5273fe0ae435..9916afd5ed68 100644
--- a/xen/arch/x86/cpu-policy.c
+++ b/xen/arch/x86/cpu-policy.c
@@ -364,6 +364,7 @@ static void __init calculate_host_policy(void)
     struct cpu_policy *p = &host_cpu_policy;
     unsigned int max_extd_leaf;
 
+    printk("%s:%d\n", __func__, __LINE__);
     *p = raw_cpu_policy;
 
     p->basic.max_leaf =
diff --git a/xen/arch/x86/cpu/intel.c b/xen/arch/x86/cpu/intel.c
index 18b3c79dc97f..51a3d1c4b5f3 100644
--- a/xen/arch/x86/cpu/intel.c
+++ b/xen/arch/x86/cpu/intel.c
@@ -671,6 +671,7 @@ const struct cpu_dev __initconst_cf_clobber intel_cpu_dev = {
 
 void __init intel_init_arat(void)
 {
+    printk("%s:%d: opt_arat: %d, cpu_has_arat: %d\n", __func__, __LINE__, opt_arat, cpu_has_arat);
     if ( opt_arat && cpu_has_arat )
         setup_force_cpu_cap(X86_FEATURE_XEN_ARAT);
 }
diff --git a/xen/arch/x86/hpet.c b/xen/arch/x86/hpet.c
index 1ea8ae457424..7731654efa9b 100644
--- a/xen/arch/x86/hpet.c
+++ b/xen/arch/x86/hpet.c
@@ -280,9 +280,11 @@ static int hpet_msi_write(struct hpet_event_channel *ch, struct msi_msg *msg)
 {
     ch->msi.msg = *msg;
 
+    printk("%s:%d: iommu_intremap: %d (iommu_intremap_off: %d), HPET_Tn_ROUTE(ch->idx): %#x\n", __func__, __LINE__, iommu_intremap, iommu_intremap_off, HPET_Tn_ROUTE(ch->idx));
     if ( iommu_intremap != iommu_intremap_off )
     {
         int rc = iommu_update_ire_from_msi(&ch->msi, msg);
+        printk("%s:%d: iommu_update_ire_from_msi rc: %d\n", __func__, __LINE__, rc);
 
         if ( rc < 0 )
             return rc;
@@ -658,6 +660,8 @@ void hpet_broadcast_resume(void)
     u32 cfg;
     unsigned int i, n;
 
+    printk("%s:%d: hpet_events: %p\n", __func__, __LINE__, hpet_events);
+
     if ( !hpet_events )
         return;
 
@@ -667,25 +671,35 @@ void hpet_broadcast_resume(void)
 
     if ( num_hpets_used > 0 )
     {
+        printk("%s:%d: num_hpets_used: %d\n", __func__, __LINE__, num_hpets_used);
         /* Stop HPET legacy interrupts */
         cfg &= ~HPET_CFG_LEGACY;
         n = num_hpets_used;
     }
     else if ( hpet_events->flags & HPET_EVT_DISABLE )
+    {
+        printk("%s:%d: hpet_events->flags: %#x\n", __func__, __LINE__, hpet_events->flags);
         return;
+    }
     else
     {
         /* Start HPET legacy interrupts */
+        printk("%s:%d\n", __func__, __LINE__);
         cfg |= HPET_CFG_LEGACY;
         n = 1;
     }
 
+    printk("%s:%d: cfg: %#x\n", __func__, __LINE__, cfg);
     hpet_write32(cfg, HPET_CFG);
 
     for ( i = 0; i < n; i++ )
     {
+        printk("%s:%d: i:%d, hpet_events[i].msi.irq: %d, hpet_events[i].flags: %#x\n", __func__, __LINE__, i, hpet_events[i].msi.irq, hpet_events[i].flags);
         if ( hpet_events[i].msi.irq >= 0 )
-            __hpet_setup_msi_irq(irq_to_desc(hpet_events[i].msi.irq));
+        {
+            int ret = __hpet_setup_msi_irq(irq_to_desc(hpet_events[i].msi.irq));
+            printk("%s:%d: i:%d, __hpet_setup_msi_irq ret: %d\n", __func__, __LINE__, i, ret);
+        }
 
         /* set HPET Tn as oneshot */
         cfg = hpet_read32(HPET_Tn_CFG(hpet_events[i].idx));
@@ -694,6 +708,7 @@ void hpet_broadcast_resume(void)
         if ( !(hpet_events[i].flags & HPET_EVT_LEGACY) )
             cfg |= HPET_TN_FSB;
         hpet_write32(cfg, HPET_Tn_CFG(hpet_events[i].idx));
+        printk("%s:%d: i:%d, cfg: %#x\n", __func__, __LINE__, i, cfg);
 
         hpet_events[i].next_event = STIME_MAX;
     }
diff --git a/xen/arch/x86/time.c b/xen/arch/x86/time.c
index fed30a919d2c..15113ebdfb6c 100644
--- a/xen/arch/x86/time.c
+++ b/xen/arch/x86/time.c
@@ -2646,6 +2646,7 @@ static int _disable_pit_irq(bool init)
 {
     int ret = 1;
 
+    printk("%s:%d: using_pit: %d, cpu_has_apic: %d\n", __func__, __LINE__, using_pit, cpu_has_apic);
     if ( using_pit || !cpu_has_apic )
         return -1;
 
@@ -2655,8 +2656,10 @@ static int _disable_pit_irq(bool init)
      * XXX dom0 may rely on RTC interrupt delivery, so only enable
      * hpet_broadcast if FSB mode available or if force_hpet_broadcast.
      */
+    printk("%s:%d: cpuidle_using_deep_cstate: %d, boot_cpu_has(X86_FEATURE_XEN_ARAT): %d\n", __func__, __LINE__, cpuidle_using_deep_cstate(), boot_cpu_has(X86_FEATURE_XEN_ARAT));
     if ( cpuidle_using_deep_cstate() && !boot_cpu_has(X86_FEATURE_XEN_ARAT) )
     {
+        printk("%s:%d: init: %d\n", __func__, __LINE__, init);
         init ? hpet_broadcast_init() : hpet_broadcast_resume();
         if ( !hpet_broadcast_is_available() )
         {
diff --git a/xen/source b/xen/source
new file mode 120000
index 000000000000..945c9b46d684
--- /dev/null
+++ b/xen/source
@@ -0,0 +1 @@
+.
\ No newline at end of file

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]