Debug print for trace MSI Interrupt routing settings, Linux-3.2.0+

msidebug.diff

diff --git a/arch/x86/kernel/apic/apic.c b/arch/x86/kernel/apic/apic.c
index a2fd72e..025c861 100644
--- a/arch/x86/kernel/apic/apic.c
+++ b/arch/x86/kernel/apic/apic.c
@@ -1414,6 +1414,7 @@ void __init bsp_end_local_APIC_setup(void)
 #ifdef CONFIG_X86_X2APIC
 void check_x2apic(void)
 {
+	printk("%s:%d\n", __func__, __LINE__);
 	if (x2apic_enabled()) {
 		pr_info("x2apic enabled by BIOS, switching to x2apic ops\n");
 		x2apic_preenabled = x2apic_mode = 1;
diff --git a/arch/x86/kernel/apic/io_apic.c b/arch/x86/kernel/apic/io_apic.c
index 3c31fa9..8040ce6 100644
--- a/arch/x86/kernel/apic/io_apic.c
+++ b/arch/x86/kernel/apic/io_apic.c
@@ -403,6 +403,25 @@ __ioapic_write_entry(int apic, int pin, struct IO_APIC_route_entry e)
 {
 	union entry_union eu = {{0, 0}};
 
+	printk("%s: apic=%d pin=%d\n", __func__, apic, pin);
+	
+	printk(KERN_DEBUG " Dst Mask Trig IRR Pol"
+	       " Stat Dmod Deli Vect:\n");
+	
+	printk(KERN_DEBUG " %02X  ",
+	       e.dest
+		);
+	printk("%1d    %1d    %1d   %1d   %1d    "
+	       "%1d    %1d    %02X\n",
+	       e.mask,
+	       e.trigger,
+	       e.irr,
+	       e.polarity,
+	       e.delivery_status,
+	       e.dest_mode,
+	       e.delivery_mode,
+	       e.vector
+		);
 	eu.entry = e;
 	io_apic_write(apic, 0x11 + 2*pin, eu.w2);
 	io_apic_write(apic, 0x10 + 2*pin, eu.w1);
@@ -411,6 +430,7 @@ __ioapic_write_entry(int apic, int pin, struct IO_APIC_route_entry e)
 static void ioapic_write_entry(int apic, int pin, struct IO_APIC_route_entry e)
 {
 	unsigned long flags;
+	printk("%s: apic=%d pin=%d\n", __func__, apic, pin);
 	raw_spin_lock_irqsave(&ioapic_lock, flags);
 	__ioapic_write_entry(apic, pin, e);
 	raw_spin_unlock_irqrestore(&ioapic_lock, flags);
@@ -425,7 +445,7 @@ static void ioapic_mask_entry(int apic, int pin)
 {
 	unsigned long flags;
 	union entry_union eu = { .entry.mask = 1 };
-
+	printk("%s: apic=%d pin=%d\n", __func__, apic, pin);
 	raw_spin_lock_irqsave(&ioapic_lock, flags);
 	io_apic_write(apic, 0x10 + 2*pin, eu.w1);
 	io_apic_write(apic, 0x11 + 2*pin, eu.w2);
@@ -458,7 +478,8 @@ __add_pin_to_irq_node(struct irq_cfg *cfg, int node, int apic, int pin)
 	}
 	entry->apic = apic;
 	entry->pin = pin;
-
+	printk("%s cfg->vector=%d node=%d apic=%d pin=%d\n",
+	       __func__, cfg->vector, node, apic, pin);
 	*last = entry;
 	return 0;
 }
@@ -578,6 +599,9 @@ static void unmask_ioapic_irq(struct irq_data *data)
  */
 static void __eoi_ioapic_pin(int apic, int pin, int vector, struct irq_cfg *cfg)
 {
+	printk("%s apic=%d pin=%d vector=%d cfg=%p\n",
+	       __func__, apic, pin, vector, cfg);
+	
 	if (mpc_ioapic_ver(apic) >= 0x20) {
 		/*
 		 * Intr-remapping uses pin number as the virtual vector
@@ -624,6 +648,8 @@ static void clear_IO_APIC_pin(unsigned int apic, unsigned int pin)
 {
 	struct IO_APIC_route_entry entry;
 
+	printk("%s apic=%u pin=%u\n", __func__, apic, pin);
+	
 	/* Check delivery_mode to be sure we're not clearing an SMI pin */
 	entry = ioapic_read_entry(apic, pin);
 	if (entry.delivery_mode == dest_SMI)
@@ -744,6 +770,8 @@ void mask_ioapic_entries(void)
 {
 	int apic, pin;
 
+	printk("%s\n", __func__);
+
 	for (apic = 0; apic < nr_ioapics; apic++) {
 		if (!ioapics[apic].saved_registers)
 			continue;
@@ -767,6 +795,8 @@ int restore_ioapic_entries(void)
 {
 	int apic, pin;
 
+	printk("%s\n", __func__);
+	
 	for (apic = 0; apic < nr_ioapics; apic++) {
 		if (!ioapics[apic].saved_registers)
 			continue;
@@ -1130,7 +1160,10 @@ __assign_irq_vector(int irq, struct irq_cfg *cfg, const struct cpumask *mask)
 	unsigned int old_vector;
 	int cpu, err;
 	cpumask_var_t tmp_mask;
-
+	char buf[10];
+	
+	cpumask_scnprintf(buf, sizeof(buf), mask);
+	printk("%s irq=%d cfg=%p mask=%s\n", __func__, irq, cfg, buf);
 	if (cfg->move_in_progress)
 		return -EBUSY;
 
@@ -1143,6 +1176,7 @@ __assign_irq_vector(int irq, struct irq_cfg *cfg, const struct cpumask *mask)
 		cpumask_and(tmp_mask, cfg->domain, tmp_mask);
 		if (!cpumask_empty(tmp_mask)) {
 			free_cpumask_var(tmp_mask);
+			printk("%s !cpumask_empty\n", __func__);
 			return 0;
 		}
 	}
@@ -1187,6 +1221,10 @@ next:
 		err = 0;
 		break;
 	}
+	cpumask_scnprintf(buf, sizeof(buf), tmp_mask);
+	printk("%s irq=%d old_vector=%d current_vector=%d tmp_mask=%s\n",
+	       __func__, irq, old_vector, current_vector, buf);
+	
 	free_cpumask_var(tmp_mask);
 	return err;
 }
@@ -1196,6 +1234,10 @@ int assign_irq_vector(int irq, struct irq_cfg *cfg, const struct cpumask *mask)
 	int err;
 	unsigned long flags;
 
+	char buf[10];
+	cpumask_scnprintf(buf, sizeof(buf), mask);
+	printk("%s irq=%d cfg=%p mask=%s\n", __func__, irq, cfg, buf);
+	
 	raw_spin_lock_irqsave(&vector_lock, flags);
 	err = __assign_irq_vector(irq, cfg, mask);
 	raw_spin_unlock_irqrestore(&vector_lock, flags);
@@ -1235,6 +1277,8 @@ void __setup_vector_irq(int cpu)
 	int irq, vector;
 	struct irq_cfg *cfg;
 
+	printk("%s cpu=%d\n", __func__, cpu);
+	
 	/*
 	 * vector_lock will make sure that we don't run into irq vector
 	 * assignments that might be happening on another cpu in parallel,
@@ -1257,10 +1301,14 @@ void __setup_vector_irq(int cpu)
 			continue;
 		vector = cfg->vector;
 		per_cpu(vector_irq, cpu)[vector] = irq;
+		printk("%s cpu=%d vector=%d irq=%d\n",
+		       __func__, cpu, vector, irq);
 	}
 	/* Mark the free vectors */
 	for (vector = 0; vector < NR_VECTORS; ++vector) {
 		irq = per_cpu(vector_irq, cpu)[vector];
+		printk("%s cpu=%d vector=%d irq=%d\n",
+		       __func__, cpu, vector, irq);
 		if (irq < 0)
 			continue;
 
@@ -1303,7 +1351,10 @@ static void ioapic_register_intr(unsigned int irq, struct irq_cfg *cfg,
 	struct irq_chip *chip = &ioapic_chip;
 	irq_flow_handler_t hdl;
 	bool fasteoi;
-
+	
+	printk("%s irq=%d cfg->vector=%d trigger=%lu\n",
+	       __func__, irq, cfg->vector, trigger);
+	
 	if ((trigger == IOAPIC_AUTO && IO_APIC_irq_trigger(irq)) ||
 	    trigger == IOAPIC_LEVEL) {
 		irq_set_status_flags(irq, IRQ_LEVEL);
@@ -1406,6 +1457,13 @@ static int setup_ioapic_entry(int irq, struct IO_APIC_route_entry *entry,
 	entry->trigger	     = attr->trigger;
 	entry->polarity	     = attr->polarity;
 
+	printk("%s "
+	       "delivery_mode=%d dest_mode=%d dest=%d vector=%d "
+	       "mask=%d trigger=%d polarity=%d\n",
+	       __func__,
+	       entry->delivery_mode, entry->dest_mode, entry->dest, entry->vector,
+	       entry->mask, entry->trigger, entry->polarity);
+	
 	/*
 	 * Mask level triggered irqs.
 	 * Use IRQ_DELAYED_DISABLE for edge triggered irqs.
@@ -1436,13 +1494,20 @@ static void setup_ioapic_irq(unsigned int irq, struct irq_cfg *cfg,
 		return;
 
 	dest = apic->cpu_mask_to_apicid_and(cfg->domain, apic->target_cpus());
-
+/*
 	apic_printk(APIC_VERBOSE,KERN_DEBUG
 		    "IOAPIC[%d]: Set routing entry (%d-%d -> 0x%x -> "
 		    "IRQ %d Mode:%i Active:%i Dest:%d)\n",
 		    attr->ioapic, mpc_ioapic_id(attr->ioapic), attr->ioapic_pin,
 		    cfg->vector, irq, attr->trigger, attr->polarity, dest);
-
+*/
+	printk("%s "
+	       "ioapic=%d mpc_ioapic_id=%d pin=%d "
+	       "vector=%d irq=%d trigger=%d polarity=%d dest=%d\n",
+	       __func__,
+	       attr->ioapic, mpc_ioapic_id(attr->ioapic), attr->ioapic_pin,
+	       cfg->vector, irq, attr->trigger, attr->polarity, dest);
+	
 	if (setup_ioapic_entry(irq, &entry, dest, cfg->vector, attr)) {
 		pr_warn("Failed to setup ioapic entry for ioapic  %d, pin %d\n",
 			mpc_ioapic_id(attr->ioapic), attr->ioapic_pin);
@@ -2316,7 +2381,10 @@ int __ioapic_set_affinity(struct irq_data *data, const struct cpumask *mask,
 			  unsigned int *dest_id)
 {
 	struct irq_cfg *cfg = data->chip_data;
-
+	char buf[10];
+	cpumask_scnprintf(buf, sizeof(buf), mask);
+	printk("%s data=%p mask=%s\n", __func__, data, buf);
+	
 	if (!cpumask_intersects(mask, cpu_online_mask))
 		return -1;
 
@@ -2326,6 +2394,7 @@ int __ioapic_set_affinity(struct irq_data *data, const struct cpumask *mask,
 	cpumask_copy(data->affinity, mask);
 
 	*dest_id = apic->cpu_mask_to_apicid_and(mask, cfg->domain);
+	printk("%s dest_id=%d\n", __func__, *dest_id);
 	return 0;
 }
 
@@ -2739,6 +2808,8 @@ static inline void __init unlock_ExtINT_logic(void)
 	struct IO_APIC_route_entry entry0, entry1;
 	unsigned char save_control, save_freq_select;
 
+	printk("%s\n", __func__);
+	
 	pin  = find_isa_irq_pin(8, mp_INT);
 	if (pin == -1) {
 		WARN_ON_ONCE(1);
@@ -3053,6 +3124,8 @@ unsigned int create_irq_nr(unsigned int from, int node)
 	unsigned int ret = 0;
 	int irq;
 
+	printk("%s from=%d node=%d\n", __func__, from, node);
+	
 	if (from < nr_irqs_gsi)
 		from = nr_irqs_gsi;
 
@@ -3064,7 +3137,7 @@ unsigned int create_irq_nr(unsigned int from, int node)
 		free_irq_at(irq, NULL);
 		return 0;
 	}
-
+	printk("%s irq=%d\n", __func__, irq);
 	raw_spin_lock_irqsave(&vector_lock, flags);
 	if (!__assign_irq_vector(irq, cfg, apic->target_cpus()))
 		ret = irq;
@@ -3179,6 +3252,13 @@ static int msi_compose_msg(struct pci_dev *pdev, unsigned int irq,
 				MSI_DATA_DELIVERY_LOWPRI) |
 			MSI_DATA_VECTOR(cfg->vector);
 	}
+	{
+		char buf[10];
+		cpumask_scnprintf(buf, sizeof(buf), apic->target_cpus());
+		printk("%s irq=%d cfg->vector=%d dest=%d target_cpus=%s\n",
+		       __func__, irq, cfg->vector, dest, buf);
+	}
+
 	return err;
 }
 
@@ -3189,7 +3269,11 @@ msi_set_affinity(struct irq_data *data, const struct cpumask *mask, bool force)
 	struct irq_cfg *cfg = data->chip_data;
 	struct msi_msg msg;
 	unsigned int dest;
-
+	char buf[10];
+	cpumask_scnprintf(buf, sizeof(buf), mask);
+	printk("%s data=%p mask=%s force=%d\n",
+	       __func__, data, buf, force);
+	
 	if (__ioapic_set_affinity(data, mask, &dest))
 		return -1;
 
@@ -3200,8 +3284,29 @@ msi_set_affinity(struct irq_data *data, const struct cpumask *mask, bool force)
 	msg.address_lo &= ~MSI_ADDR_DEST_ID_MASK;
 	msg.address_lo |= MSI_ADDR_DEST_ID(dest);
 
+	printk("%s address_lo=%x dest_mode=%s redirection=%s dest_id=%u\n",
+	       __func__,
+	       msg.address_lo,
+	       (msg.address_lo & MSI_ADDR_DEST_MODE_LOGICAL) ?
+	       "logical" : "physical",
+	       (msg.address_lo & MSI_ADDR_REDIRECTION_LOWPRI) ?
+	       "lowpri" : "cpu",
+	       (msg.address_lo & MSI_ADDR_DEST_ID_MASK)
+	       >> MSI_ADDR_DEST_ID_SHIFT);
+
+	printk("%s data=%x trigger=%s level=%s delivery_mode=%s vector=%u\n",
+	       __func__,
+	       msg.data,
+	       (msg.data & MSI_DATA_TRIGGER_LEVEL) ?
+	       "level" : "edge",
+	       (msg.data & MSI_DATA_LEVEL_ASSERT) ?
+	       "assert" : "deassert",
+	       (msg.data & MSI_DATA_DELIVERY_LOWPRI) ?
+	       "lowpri" : "fixed",
+	       msg.data & MSI_DATA_VECTOR_MASK);
+	
 	__write_msi_msg(data->msi_desc, &msg);
-
+	
 	return 0;
 }
 #endif /* CONFIG_SMP */
@@ -3254,11 +3359,36 @@ static int setup_msi_irq(struct pci_dev *dev, struct msi_desc *msidesc, int irq)
 	struct msi_msg msg;
 	int ret;
 
+	printk("%s dev=%p msidesc=%p irq=%d\n",
+	       __func__, dev, msidesc, irq);
+	
 	ret = msi_compose_msg(dev, irq, &msg, -1);
 	if (ret < 0)
 		return ret;
 
 	irq_set_msi_desc(irq, msidesc);
+
+	printk("%s address_lo=%x dest_mode=%s redirection=%s dest_id=%u\n",
+	       __func__,
+	       msg.address_lo,
+	       (msg.address_lo & MSI_ADDR_DEST_MODE_LOGICAL) ?
+	       "logical" : "physical",
+	       (msg.address_lo & MSI_ADDR_REDIRECTION_LOWPRI) ?
+	       "lowpri" : "cpu",
+	       (msg.address_lo & MSI_ADDR_DEST_ID_MASK)
+	       >> MSI_ADDR_DEST_ID_SHIFT);
+
+	printk("%s data=%x trigger=%s level=%s delivery_mode=%s vector=%u\n",
+	       __func__,
+	       msg.data,
+	       (msg.data & MSI_DATA_TRIGGER_LEVEL) ?
+	       "level" : "edge",
+	       (msg.data & MSI_DATA_LEVEL_ASSERT) ?
+	       "assert" : "deassert",
+	       (msg.data & MSI_DATA_DELIVERY_LOWPRI) ?
+	       "lowpri" : "fixed",
+	       msg.data & MSI_DATA_VECTOR_MASK);
+	
 	write_msi_msg(irq, &msg);
 
 	if (irq_remapped(irq_get_chip_data(irq))) {
@@ -3269,7 +3399,23 @@ static int setup_msi_irq(struct pci_dev *dev, struct msi_desc *msidesc, int irq)
 	irq_set_chip_and_handler_name(irq, chip, handle_edge_irq, "edge");
 
 	dev_printk(KERN_DEBUG, &dev->dev, "irq %d for MSI/MSI-X\n", irq);
-
+	printk("%s "
+	       "msidesc.msi_attrib.is_msix=%d "
+	       "msidesc.msi_attrib.multiple=%d "
+	       "msidesc.msi_attrib.pos=%d "
+	       "msidesc.msi_attrib.entry_nr=%d "
+	       "msidesc.msi_attrib.default_irq=%d "
+	       "msidesc.masked=%d "
+	       "msidesc.irq=%d\n",
+	       __func__,
+	       msidesc->msi_attrib.is_msix,
+	       msidesc->msi_attrib.multiple,
+	       msidesc->msi_attrib.pos,
+ 	       msidesc->msi_attrib.entry_nr,
+ 	       msidesc->msi_attrib.default_irq,
+ 	       msidesc->masked,
+ 	       msidesc->irq);
+	
 	return 0;
 }
 
@@ -3280,11 +3426,15 @@ int native_setup_msi_irqs(struct pci_dev *dev, int nvec, int type)
 	struct msi_desc *msidesc;
 	struct intel_iommu *iommu = NULL;
 
+	printk("%s dev=%p nvec=%d type=%d\n",
+	       __func__, dev, nvec, type);
+
 	/* x86 doesn't support multiple MSI yet */
 	if (type == PCI_CAP_ID_MSI && nvec > 1)
 		return 1;
 
 	node = dev_to_node(&dev->dev);
+	printk("%s node=%d\n", __func__, node);
 	irq_want = nr_irqs_gsi;
 	sub_handle = 0;
 	list_for_each_entry(msidesc, &dev->msi_list, list) {
diff --git a/arch/x86/kernel/apic/probe_32.c b/arch/x86/kernel/apic/probe_32.c
index 0787bb3..b6d5577 100644
--- a/arch/x86/kernel/apic/probe_32.c
+++ b/arch/x86/kernel/apic/probe_32.c
@@ -210,6 +210,7 @@ void __init default_setup_apic_routing(void)
 
 void __init generic_apic_probe(void)
 {
+	printk("%s:%d\n", __func__, __LINE__);
 	if (!cmdline_apic) {
 		struct apic **drv;
 
@@ -223,6 +224,7 @@ void __init generic_apic_probe(void)
 		if (drv == __apicdrivers_end)
 			panic("Didn't find an APIC driver");
 	}
+	printk("%s:%d %s\n", __func__, __LINE__, apic->name);
 	printk(KERN_INFO "Using APIC driver %s\n", apic->name);
 }
 
diff --git a/arch/x86/kernel/apic/probe_64.c b/arch/x86/kernel/apic/probe_64.c
index 3fe9866..2e933fb 100644
--- a/arch/x86/kernel/apic/probe_64.c
+++ b/arch/x86/kernel/apic/probe_64.c
@@ -48,6 +48,8 @@ void __init default_setup_apic_routing(void)
 		}
 	}
 
+	printk("%s:%d apic->name:%s\n", __func__, __LINE__, apic->name);
+
 	if (is_vsmp_box()) {
 		/* need to update phys_pkg_id */
 		apic->phys_pkg_id = apicid_phys_pkg_id;
diff --git a/arch/x86/kernel/irq.c b/arch/x86/kernel/irq.c
index 429e0c9..ec30e93 100644
--- a/arch/x86/kernel/irq.c
+++ b/arch/x86/kernel/irq.c
@@ -169,7 +169,7 @@ u64 arch_irq_stat(void)
 
 
 /*
- * do_IRQ handles all normal device IRQ's (the special
+ * do_IRQhandles all normal device IRQ's (the special
  * SMP cross-CPU interrupts have their own specific
  * handlers).
  */
diff --git a/arch/x86/kernel/irq_64.c b/arch/x86/kernel/irq_64.c
index acf8fbf..3f6ad6f 100644
--- a/arch/x86/kernel/irq_64.c
+++ b/arch/x86/kernel/irq_64.c
@@ -57,7 +57,7 @@ bool handle_irq(unsigned irq, struct pt_regs *regs)
 	desc = irq_to_desc(irq);
 	if (unlikely(!desc))
 		return false;
-
+	
 	generic_handle_irq_desc(irq, desc);
 	return true;
 }
diff --git a/arch/x86/kernel/irqinit.c b/arch/x86/kernel/irqinit.c
index b3300e6..0dc0379 100644
--- a/arch/x86/kernel/irqinit.c
+++ b/arch/x86/kernel/irqinit.c
@@ -158,7 +158,7 @@ void setup_vector_irq(int cpu)
 	for (irq = 0; irq < legacy_pic->nr_legacy_irqs; irq++)
 		per_cpu(vector_irq, cpu)[IRQ0_VECTOR + irq] = irq;
 #endif
-
+	printk("%s cpu=%d\n", __func__, cpu);
 	__setup_vector_irq(cpu);
 }
 
diff --git a/arch/x86/kernel/setup.c b/arch/x86/kernel/setup.c
index afaf384..a0656dd 100644
--- a/arch/x86/kernel/setup.c
+++ b/arch/x86/kernel/setup.c
@@ -999,7 +999,7 @@ void __init setup_arch(char **cmdline_p)
 #ifdef CONFIG_X86_64
 	map_vsyscall();
 #endif
-
+	printk("%s:%d\n", __func__, __LINE__);
 	generic_apic_probe();
 
 	early_quirks();