Log Analysis 4 of N
Conditions:
- This is a comparison of how interrupts are set up
- Intel platform with driver from 12.6.x that works properly because AppleVTD is enabled
- The same number of MSI interrupts were found and registered, but here we see that each interrupt was remapped by AppleVTD
- The log messages that look like ir[0x90] 0x0 -> 0x890003 are actually from AppleVTD::IOPCISetMSIInterrupt
- This I believe is Interrupt Remapping, which is the primary function of DMAR (DMA Remap Table)
- However, I don't think the driver calls this function directly; regardless, the interrupts "should" still work but it really seems that this is where the system goes off the rails
Bash:
# alloc_rx_rings just finished as we can see by the "exit" sign <==
2022-11-27 11:41:17.697786-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) <== AppleEthernetAquantiaAqtion::alloc_rx_rings:0x00000001
# setup_intr function now begins as we can see by the 'entry' sign ==>
2022-11-27 11:41:17.697788-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) ==> AppleEthernetAquantiaAqtion::setup_intr
2022-11-27 11:41:17.697813-0800 0x6d9 kernel: (IOPCIFamily) ir[0x89] 0x0 -> 0x890003
2022-11-27 11:41:17.697816-0800 0x6d9 kernel: (IOPCIFamily) ir[0x89] 0x0 -> 0x890003
2022-11-27 11:41:17.697818-0800 0x6d9 kernel: (IOPCIFamily) ir[0x8a] 0x0 -> 0x8a0003
2022-11-27 11:41:17.697821-0800 0x6d9 kernel: (IOPCIFamily) ir[0x8a] 0x0 -> 0x8a0003
2022-11-27 11:41:17.697822-0800 0x6d9 kernel: (IOPCIFamily) ir[0x8b] 0x0 -> 0x8b0003
2022-11-27 11:41:17.697825-0800 0x6d9 kernel: (IOPCIFamily) ir[0x8b] 0x0 -> 0x8b0003
2022-11-27 11:41:17.697826-0800 0x6d9 kernel: (IOPCIFamily) ir[0x8c] 0x0 -> 0x8c0003
2022-11-27 11:41:17.697829-0800 0x6d9 kernel: (IOPCIFamily) ir[0x8c] 0x0 -> 0x8c0003
2022-11-27 11:41:17.697831-0800 0x6d9 kernel: (IOPCIFamily) ir[0x8d] 0x0 -> 0x8d0003
2022-11-27 11:41:17.697833-0800 0x6d9 kernel: (IOPCIFamily) ir[0x8d] 0x0 -> 0x8d0003
2022-11-27 11:41:17.697835-0800 0x6d9 kernel: (IOPCIFamily) ir[0x8e] 0x0 -> 0x8e0003
2022-11-27 11:41:17.697837-0800 0x6d9 kernel: (IOPCIFamily) ir[0x8e] 0x0 -> 0x8e0003
2022-11-27 11:41:17.697839-0800 0x6d9 kernel: (IOPCIFamily) ir[0x8f] 0x0 -> 0x8f0003
2022-11-27 11:41:17.697841-0800 0x6d9 kernel: (IOPCIFamily) ir[0x8f] 0x0 -> 0x8f0003
2022-11-27 11:41:17.697866-0800 0x6d9 kernel: (IOPCIFamily) setTunnelL1Enable(0x10000026c) 2->0
2022-11-27 11:41:17.697869-0800 0x6d9 kernel: (IOPCIFamily) setTunnelL1Enable(0x10000026c) 2->0
2022-11-27 11:41:17.697874-0800 0x6d9 kernel: (IOPCIFamily) setTunnelL1Enable(0x10000026c) 2->0
2022-11-27 11:41:17.697877-0800 0x6d9 kernel: (IOPCIFamily) setTunnelL1Enable(0x10000026c) 2->0
2022-11-27 11:41:17.697890-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - MSI Interrupt found. Line = 0x00000000, type = 0x00010000
2022-11-27 11:41:17.697919-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - MSI Interrupt found. Line = 0x00000001, type = 0x00010000
2022-11-27 11:41:17.697931-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - MSI Interrupt found. Line = 0x00000002, type = 0x00010000
2022-11-27 11:41:17.697941-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - MSI Interrupt found. Line = 0x00000003, type = 0x00010000
2022-11-27 11:41:17.697950-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - MSI Interrupt found. Line = 0x00000004, type = 0x00010000
2022-11-27 11:41:17.697961-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - MSI Interrupt found. Line = 0x00000005, type = 0x00010000
2022-11-27 11:41:17.697971-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - MSI Interrupt found. Line = 0x00000006, type = 0x00010000
2022-11-27 11:41:17.697990-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - Interrupt source registered
2022-11-27 11:41:17.697993-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - Interrupt source registered
2022-11-27 11:41:17.697995-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - Interrupt source registered
2022-11-27 11:41:17.697997-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - Interrupt source registered
2022-11-27 11:41:17.697999-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - Interrupt source registered
2022-11-27 11:41:17.698001-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - Interrupt source registered
2022-11-27 11:41:17.698003-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) setup_intr - Interrupt source registered
# success
2022-11-27 11:41:17.698005-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) <== AppleEthernetAquantiaAqtion::setup_intr status = 0x00000001
# now the next step starts, which is initializing the hardware
2022-11-27 11:41:17.698007-0800 0x6d9 kernel: (AppleEthernetAquantiaAqtion) ==> AppleEthernetAquantiaAqtion::init_enet_hw
Here is the function IOPCISetMSIInterrupt:
C:
IOPCISetMSIInterrupt(uint32_t vector, uint32_t count, uint32_t * msiData)
{
AppleVTD * vtd;
uint64_t present;
uint64_t destVector;
uint64_t destID;
uint64_t levelTrigger;
uint64_t irte;
uint64_t prior;
uint32_t idx;
bool inval;
if (!(vtd = OSDynamicCast(AppleVTD, IOMapper::gSystem))) return (kIOReturnUnsupported);
if (!vtd->fIRTable) return (kIOReturnUnsupported);
if ((vector + count) > kIRCount) panic("IOPCISetMSIInterrupt(%d, %d)", vector, count);
inval = false;
for (idx = vector; idx < (vector + count); idx++)
{
extern int cpu_to_lapic[];
int destShift;
levelTrigger = 0;
present = (msiData != 0);
destVector = (0xFF & idx);
destID = (uint64_t)cpu_to_lapic[((idx & 0xFF00) >> 8)];
/* In x2APIC mode, the destination starts at bit 32; legacy xAPIC: bit 40 */
destShift = vtd->x2apic_mode ? 32 : 40;
irte = (destID << destShift) // destID
| (destVector << 16) // vector
| (0 << 5) // fixed delivery mode
| (levelTrigger << 4) // trigger
| (0 << 3) // redir
| (0 << 2) // phys dest
| (1 << 1) // faults ena
| (present << 0); // present
prior = vtd->fIRTable[idx].data;
VTLOG("ir[0x%x] 0x%qx -> 0x%qx\n", idx, prior, irte);
// msi should only be set once and removed
if (!(1 & (prior ^ irte))) panic("msi irte 0x%qx prior 0x%qx", irte, prior);
if (irte != prior)
{
vtd->fIRTable[idx].data = irte;
__mfence();
if (1 & prior) inval = true;
}
}
if (inval) vtd->interruptInvalidate(vector, count);
if (msiData)
{
/* WARNING: If x2APIC is enabled, this MUST be in remappable format! */
msiData[0] = 0xfee00000 // addr lo
| ((vector & 0x7fff) << 5) // handle[14:0]
| (1 << 4) // remap format
| (1 << 3) // SHV (add subhandle to vector)
| ((vector & 0x8000) >> 13); // b2 handle[15]
msiData[1] = 0; // addr hi
msiData[2] = 0; // data (subhandle)
}
return (kIOReturnSuccess);
}