On Tue, Nov 18, 2014 at 05:20:44PM +0000, Jan Beulich wrote:
> >>> On 18.11.14 at 18:03, <li...@eikelenboom.it> wrote:
> > Tuesday, November 18, 2014, 5:16:50 PM, you wrote:
> >> 1) test_and_[set|clear]_bit sometimes return unexpected values.
> >> [But this might be invalid as the addition of the ffff8303faaf25a8
> >> might be correct - as the second dpci the softirq is processing
> >> could be the MSI one]
> >
> > Would there be an easy way to stress test this function separately in some
> > debugging function to see if it indeed is returning unexpected values ?
>
> I don't think there's a reasonable chance of these functions to return
> "unexpected" values - they're being used elsewhere, and you'd have
> had other problems in the past if they didn't behave as expected.
Interestingly most of the 'test_and_[set|clear]_bit operate on 'unsigned long'
while we do 'unsigned int' here. But the 'test_and'' are all btXl so double-word
safe.
The fact that Sander is able to get 'test_and_clear_bit(STATE_SCHED)' to return
zero - when in fact it should return a positive value - implies that some actor
is messing with the 'state' outside our raise/softirq dialogue.
pt_irq_guest_eoi does pirq_dpci->state = 0 unconditionally!
Lets see if this debug + potential patch helps. This should be applied
on top of the other patch you had. Just in case I am attaching all four
to this email.
>From 8093140e374fceb9121ccd07726fb3898b212bfb Mon Sep 17 00:00:00 2001
From: Konrad Rzeszutek Wilk <konrad.w...@oracle.com>
Date: Tue, 18 Nov 2014 15:08:15 -0500
Subject: [PATCH 4/5] DEBUG4: Add an 'stamp' and potential fix.
Signed-off-by: Konrad Rzeszutek Wilk <konrad.w...@oracle.com>
---
xen/drivers/passthrough/io.c | 57 +++++++++++++++++++++++++++++++-------------
xen/include/xen/hvm/irq.h | 1 +
2 files changed, 41 insertions(+), 17 deletions(-)
diff --git a/xen/drivers/passthrough/io.c b/xen/drivers/passthrough/io.c
index b786bd2..8a8fc62 100644
--- a/xen/drivers/passthrough/io.c
+++ b/xen/drivers/passthrough/io.c
@@ -26,6 +26,8 @@
#include <asm/hvm/iommu.h>
#include <asm/hvm/support.h>
#include <xen/hvm/irq.h>
+#include <xen/console.h>
+
static DEFINE_PER_CPU(struct list_head, dpci_list);
@@ -61,21 +63,29 @@ struct _debug_f {
struct list_head list;
unsigned int state;
struct hvm_pirq_dpci *dpci;
+ unsigned long stamp;
};
struct __debug {
struct _debug_f ok;
struct _debug_f poison;
struct _debug_f raise;
+ struct _debug_f busy_raise;
struct _debug_f reset;
struct _debug_f zombie_softirq;
struct _debug_f zombie_raise;
+ struct _debug_f timeout;
+ struct _debug_f clear;
};
static DEFINE_PER_CPU(struct __debug, _d);
void _record(struct _debug_f *d, struct hvm_pirq_dpci *pirq_dpci)
{
+
+ if (pirq_dpci->pirq)
+ return;
+
if (pirq_dpci->dom)
d->domid = pirq_dpci->dom->domain_id;
else
@@ -86,6 +96,7 @@ void _record(struct _debug_f *d, struct hvm_pirq_dpci
*pirq_dpci)
d->list.prev = pirq_dpci->softirq_list.prev;
d->state = pirq_dpci->state;
d->dpci = pirq_dpci;
+ d->stamp = pirq_dpci->stamp++;
}
enum {
@@ -95,6 +106,9 @@ enum {
OK_SOFTIRQ,
OK_RAISE,
OK_RESET,
+ OK_TIMEOUT,
+ OK_BUSY,
+ OK_CLEAR,
};
static void dump_record(struct _debug_f *d, unsigned int type)
@@ -106,7 +120,11 @@ static void dump_record(struct _debug_f *d, unsigned int
type)
[OK_SOFTIRQ] = "OK-softirq",
[OK_RAISE] = "OK-raise ",
[OK_RESET] = "OK-reset ",
+ [OK_TIMEOUT] = "OK-timeout",
+ [OK_BUSY] = "OK-busy ",
+ [OK_CLEAR] = "OK-clear ",
};
+#if 0
#define LONG(x) [_HVM_IRQ_DPCI_##x] = #x
static const char *const names_flag[] = {
LONG(MACH_PCI_SHIFT),
@@ -117,6 +135,7 @@ static void dump_record(struct _debug_f *d, unsigned int
type)
};
#undef LONG
unsigned int i;
+#endif
s_time_t now;
if ( d->domid == 0 )
@@ -126,20 +145,21 @@ static void dump_record(struct _debug_f *d, unsigned int
type)
BUG();
now = NOW();
- printk("d%d %s %lumsec ago, state:%x, %ld count, [prev:%p, next:%p] %p",
+ printk("d%d %s %lumsec ago, state:%x, %ld count, [prev:%p, next:%p] %p
%lx",
d->domid, names[type],
(unsigned long)((now - d->last) / MILLISECS(1)),
- d->state, d->count, d->list.prev, d->list.next, d->dpci);
+ d->state, d->count, d->list.prev, d->list.next, d->dpci, d->stamp);
if ( d->dpci )
{
struct hvm_pirq_dpci *pirq_dpci = d->dpci;
-
+#if 0
for ( i = 0; i <= _HVM_IRQ_DPCI_GUEST_MSI_SHIFT; i++ )
if ( pirq_dpci->flags & (1 << i) )
printk("%s ", names_flag[i]);
printk(" PIRQ:%d", pirq_dpci->pirq);
+#endif
if (pirq_dpci->line)
printk(" LINE: %d", pirq_dpci->line);
}
@@ -159,7 +179,10 @@ static void dump_debug(unsigned char key)
printk("CPU%02d: \n" ,cpu);
dump_record(&d->ok, OK_SOFTIRQ);
dump_record(&d->raise, OK_RAISE);
+ dump_record(&d->busy_raise, OK_RAISE);
dump_record(&d->reset, OK_RESET);
+ dump_record(&d->timeout, OK_TIMEOUT);
+ dump_record(&d->clear, OK_TIMEOUT);
dump_record(&d->poison, ERR_POISON);
dump_record(&d->zombie_softirq, Z_SOFTIRQ);
dump_record(&d->zombie_raise, Z_RAISE);
@@ -184,8 +207,10 @@ static void raise_softirq_for(struct hvm_pirq_dpci
*pirq_dpci)
return;
}
if ( test_and_set_bit(STATE_SCHED, &pirq_dpci->state) )
+ {
+ _record(&d->busy_raise, pirq_dpci);
return;
-
+ }
_record(&d->raise, pirq_dpci);
get_knownalive_domain(pirq_dpci->dom);
@@ -264,10 +289,14 @@ bool_t pt_irq_need_timer(uint32_t flags)
static int pt_irq_guest_eoi(struct domain *d, struct hvm_pirq_dpci *pirq_dpci,
void *arg)
{
+ struct __debug *debug = &__get_cpu_var(_d);
+
if ( __test_and_clear_bit(_HVM_IRQ_DPCI_EOI_LATCH_SHIFT,
&pirq_dpci->flags) )
{
- pirq_dpci->state = 0;
+ _record(&debug->clear, pirq_dpci);
+ pt_pirq_softirq_reset(pirq_dpci);
+ /* pirq_dpci->state = 0; <= OUCH! */
pirq_dpci->pending = 0;
pirq_guest_eoi(dpci_pirq(pirq_dpci));
}
@@ -280,11 +309,13 @@ static void pt_irq_time_out(void *data)
struct hvm_pirq_dpci *irq_map = data;
const struct hvm_irq_dpci *dpci;
const struct dev_intx_gsi_link *digl;
-
+ struct __debug *d = &__get_cpu_var(_d);
spin_lock(&irq_map->dom->event_lock);
dpci = domain_get_irq_dpci(irq_map->dom);
ASSERT(dpci);
+
+ _record(&d->timeout, irq_map);
list_for_each_entry ( digl, &irq_map->digl_list, list )
{
unsigned int guest_gsi = hvm_pci_intx_gsi(digl->device, digl->intx);
@@ -302,6 +333,9 @@ static void pt_irq_time_out(void *data)
pt_pirq_iterate(irq_map->dom, pt_irq_guest_eoi, NULL);
spin_unlock(&irq_map->dom->event_lock);
+ console_start_sync();
+ dump_debug((char)0);
+ console_end_sync();
}
struct hvm_irq_dpci *domain_get_irq_dpci(const struct domain *d)
@@ -901,8 +935,6 @@ unlock:
spin_unlock(&d->event_lock);
}
-#include <xen/console.h>
-
/*
* Note: 'pt_pirq_softirq_reset' can clear the STATE_SCHED before we get to
* doing it. If that is the case we let 'pt_pirq_softirq_reset' do
ref-counting.
@@ -919,26 +951,17 @@ static void dpci_softirq(void)
struct hvm_pirq_dpci *dpci;
} l[4];
unsigned int i = 0;
-#if DIFF_LIST
- struct hvm_pirq_dpci *n;
-#endif
debug = &per_cpu(_d, cpu);
local_irq_disable();
list_splice_init(&per_cpu(dpci_list, cpu), &our_list);
local_irq_enable();
-#if DIFF_LIST
- list_for_each_entry_safe(pirq_dpci, n, &our_list, softirq_list)
-#else
while ( !list_empty(&our_list) )
-#endif
{
struct domain *d;
struct list_head *entry;
-#ifndef DIFF_LIST
pirq_dpci = list_entry(our_list.next, struct hvm_pirq_dpci,
softirq_list);
-#endif
entry = &pirq_dpci->softirq_list;
if ( i <= 3 )
{
diff --git a/xen/include/xen/hvm/irq.h b/xen/include/xen/hvm/irq.h
index 1fb1292..f5b6061 100644
--- a/xen/include/xen/hvm/irq.h
+++ b/xen/include/xen/hvm/irq.h
@@ -102,6 +102,7 @@ struct hvm_pirq_dpci {
struct list_head softirq_list;
unsigned int pirq;
unsigned int line;
+ unsigned long stamp;
};
void pt_pirq_init(struct domain *, struct hvm_pirq_dpci *);
--
1.9.3
>From b8c267ea34663a9585e1aee9c09dede240b546f9 Mon Sep 17 00:00:00 2001
From: Konrad Rzeszutek Wilk <konrad.w...@oracle.com>
Date: Fri, 14 Nov 2014 12:15:26 -0500
Subject: [PATCH 1/5] dpci: Add ZOMBIE state.
Signed-off-by: Konrad Rzeszutek Wilk <konrad.w...@oracle.com>
---
xen/drivers/passthrough/io.c | 29 ++++++++++++++++++++++-------
1 file changed, 22 insertions(+), 7 deletions(-)
diff --git a/xen/drivers/passthrough/io.c b/xen/drivers/passthrough/io.c
index efc66dc..8e9141e 100644
--- a/xen/drivers/passthrough/io.c
+++ b/xen/drivers/passthrough/io.c
@@ -50,20 +50,25 @@ static DEFINE_PER_CPU(struct list_head, dpci_list);
enum {
STATE_SCHED,
- STATE_RUN
+ STATE_RUN,
+ STATE_ZOMBIE
};
/*
* This can be called multiple times, but the softirq is only raised once.
- * That is until the STATE_SCHED state has been cleared. The state can be
- * cleared by: the 'dpci_softirq' (when it has executed 'hvm_dirq_assist'),
- * or by 'pt_pirq_softirq_reset' (which will try to clear the state before
- * the softirq had a chance to run).
+ * That is until the STATE_SCHED and STATE_ZOMBIE state has been cleared. The
+ * STATE_SCHED and STATE_ZOMBIE state can be cleared by the 'dpci_softirq'
+ * (when it has executed 'hvm_dirq_assist'). The STATE_SCHED can be cleared
+ * by 'pt_pirq_softirq_reset' (which will try to clear the state before the
+ * softirq had a chance to run).
*/
static void raise_softirq_for(struct hvm_pirq_dpci *pirq_dpci)
{
unsigned long flags;
+ if ( test_bit(STATE_ZOMBIE, &pirq_dpci->state) )
+ return;
+
if ( test_and_set_bit(STATE_SCHED, &pirq_dpci->state) )
return;
@@ -85,7 +90,7 @@ static void raise_softirq_for(struct hvm_pirq_dpci *pirq_dpci)
*/
bool_t pt_pirq_softirq_active(struct hvm_pirq_dpci *pirq_dpci)
{
- if ( pirq_dpci->state & ((1 << STATE_RUN) | (1 << STATE_SCHED)) )
+ if ( pirq_dpci->state & ((1 << STATE_RUN) | (1 << STATE_SCHED) | (1 <<
STATE_ZOMBIE) ) )
return 1;
/*
@@ -109,7 +114,7 @@ static void pt_pirq_softirq_reset(struct hvm_pirq_dpci
*pirq_dpci)
ASSERT(spin_is_locked(&d->event_lock));
- switch ( cmpxchg(&pirq_dpci->state, 1 << STATE_SCHED, 0) )
+ switch ( cmpxchg(&pirq_dpci->state, 1 << STATE_SCHED, 1 << STATE_ZOMBIE ) )
{
case (1 << STATE_SCHED):
/*
@@ -120,6 +125,7 @@ static void pt_pirq_softirq_reset(struct hvm_pirq_dpci
*pirq_dpci)
/* fallthrough. */
case (1 << STATE_RUN):
case (1 << STATE_RUN) | (1 << STATE_SCHED):
+ case (1 << STATE_RUN) | (1 << STATE_SCHED) | (1 << STATE_ZOMBIE):
/*
* The reason it is OK to reset 'dom' when STATE_RUN bit is set is due
* to a shortcut the 'dpci_softirq' implements. It stashes the 'dom'
@@ -779,6 +785,7 @@ unlock:
static void dpci_softirq(void)
{
unsigned int cpu = smp_processor_id();
+ unsigned int reset = 0;
LIST_HEAD(our_list);
local_irq_disable();
@@ -805,7 +812,15 @@ static void dpci_softirq(void)
hvm_dirq_assist(d, pirq_dpci);
put_domain(d);
}
+ else
+ reset = 1;
+
clear_bit(STATE_RUN, &pirq_dpci->state);
+ if ( reset )
+ {
+ clear_bit(STATE_ZOMBIE, &pirq_dpci->state);
+ reset = 0;
+ }
}
}
--
1.9.3
>From a4171fa12583eabd126bc5b4c305f49b2fb2b515 Mon Sep 17 00:00:00 2001
From: Konrad Rzeszutek Wilk <konrad.w...@oracle.com>
Date: Fri, 14 Nov 2014 15:00:39 -0500
Subject: [PATCH 2/5] debug:
Signed-off-by: Konrad Rzeszutek Wilk <konrad.w...@oracle.com>
---
xen/drivers/passthrough/io.c | 180 ++++++++++++++++++++++++++++++++++++++++++-
xen/include/xen/hvm/irq.h | 2 +
2 files changed, 178 insertions(+), 4 deletions(-)
diff --git a/xen/drivers/passthrough/io.c b/xen/drivers/passthrough/io.c
index 8e9141e..23e5ed1 100644
--- a/xen/drivers/passthrough/io.c
+++ b/xen/drivers/passthrough/io.c
@@ -54,6 +54,117 @@ enum {
STATE_ZOMBIE
};
+struct _debug_f {
+ unsigned int domid;
+ unsigned long count;
+ s_time_t last;
+ struct list_head list;
+ unsigned int state;
+ struct hvm_pirq_dpci *dpci;
+};
+
+struct __debug {
+ struct _debug_f ok;
+ struct _debug_f poison;
+ struct _debug_f raise;
+ struct _debug_f reset;
+ struct _debug_f zombie_softirq;
+ struct _debug_f zombie_raise;
+};
+
+static DEFINE_PER_CPU(struct __debug, _d);
+
+void _record(struct _debug_f *d, struct hvm_pirq_dpci *pirq_dpci)
+{
+ if (pirq_dpci->dom)
+ d->domid = pirq_dpci->dom->domain_id;
+ else
+ d->domid = 0xdead;
+ d->count ++;
+ d->last = NOW();
+ d->list.next = pirq_dpci->softirq_list.next;
+ d->list.prev = pirq_dpci->softirq_list.prev;
+ d->state = pirq_dpci->state;
+ d->dpci = pirq_dpci;
+}
+
+enum {
+ Z_SOFTIRQ,
+ Z_RAISE,
+ ERR_POISON,
+ OK_SOFTIRQ,
+ OK_RAISE,
+ OK_RESET,
+};
+
+static void dump_record(struct _debug_f *d, unsigned int type)
+{
+ static const char *const names[] = {
+ [Z_SOFTIRQ] = "Z-softirq ",
+ [Z_RAISE] = "Z-raise ",
+ [ERR_POISON] = "ERR-poison",
+ [OK_SOFTIRQ] = "OK-softirq",
+ [OK_RAISE] = "OK-raise ",
+ [OK_RESET] = "OK-reset ",
+ };
+#define LONG(x) [_HVM_IRQ_DPCI_##x] = #x
+ static const char *const names_flag[] = {
+ LONG(MACH_PCI_SHIFT),
+ LONG(MAPPED_SHIFT),
+ LONG(EOI_LATCH_SHIFT),
+ LONG(GUEST_PCI_SHIFT),
+ LONG(GUEST_MSI_SHIFT),
+ };
+#undef LONG
+ unsigned int i;
+ s_time_t now;
+
+ if ( d->domid == 0 )
+ return;
+
+ if ( type >= ARRAY_SIZE(names) )
+ BUG();
+
+ now = NOW();
+ printk("d%d %s %lumsec ago, state:%x, %ld count, [prev:%p, next:%p] ",
+ d->domid, names[type],
+ (unsigned long)((now - d->last) / MILLISECS(1)),
+ d->state, d->count, d->list.prev, d->list.next);
+
+ if ( d->dpci )
+ {
+ struct hvm_pirq_dpci *pirq_dpci = d->dpci;
+
+ for ( i = 0; i <= _HVM_IRQ_DPCI_GUEST_MSI_SHIFT; i++ )
+ if ( pirq_dpci->flags & 1 << _HVM_IRQ_DPCI_TRANSLATE_SHIFT )
+ printk("%s ", names_flag[i]);
+
+ printk(" PIRQ:%d", pirq_dpci->pirq);
+ if (pirq_dpci->line)
+ printk(" LINE: %d", pirq_dpci->line);
+ }
+ printk("\n");
+ memset(d, 0, sizeof(struct _debug_f));
+}
+
+static void dump_debug(unsigned char key)
+{
+ unsigned int cpu;
+
+ for_each_online_cpu ( cpu )
+ {
+ struct __debug *d;
+ d = &per_cpu(_d, cpu);
+
+ printk("CPU%02d: \n" ,cpu);
+ dump_record(&d->ok, OK_SOFTIRQ);
+ dump_record(&d->raise, OK_RAISE);
+ dump_record(&d->reset, OK_RESET);
+ dump_record(&d->poison, ERR_POISON);
+ dump_record(&d->zombie_softirq, Z_SOFTIRQ);
+ dump_record(&d->zombie_raise, Z_RAISE);
+ }
+}
/*
* This can be called multiple times, but the softirq is only raised once.
* That is until the STATE_SCHED and STATE_ZOMBIE state has been cleared. The
@@ -65,13 +176,18 @@ enum {
static void raise_softirq_for(struct hvm_pirq_dpci *pirq_dpci)
{
unsigned long flags;
+ struct __debug *d = &__get_cpu_var(_d);
if ( test_bit(STATE_ZOMBIE, &pirq_dpci->state) )
+ {
+ _record(&d->zombie_raise, pirq_dpci);
return;
-
+ }
if ( test_and_set_bit(STATE_SCHED, &pirq_dpci->state) )
return;
+ _record(&d->raise, pirq_dpci);
+
get_knownalive_domain(pirq_dpci->dom);
local_irq_save(flags);
@@ -111,9 +227,12 @@ bool_t pt_pirq_softirq_active(struct hvm_pirq_dpci
*pirq_dpci)
static void pt_pirq_softirq_reset(struct hvm_pirq_dpci *pirq_dpci)
{
struct domain *d = pirq_dpci->dom;
+ struct __debug *debug = &__get_cpu_var(_d);
ASSERT(spin_is_locked(&d->event_lock));
+ _record(&debug->reset, pirq_dpci);
+
switch ( cmpxchg(&pirq_dpci->state, 1 << STATE_SCHED, 1 << STATE_ZOMBIE ) )
{
case (1 << STATE_SCHED):
@@ -277,6 +396,7 @@ int pt_irq_create_bind(
* As such on every 'pt_irq_create_bind' call we MUST set it.
*/
pirq_dpci->dom = d;
+ pirq_dpci->pirq = pirq;
/* bind after hvm_irq_dpci is setup to avoid race with irq
handler*/
rc = pirq_guest_bind(d->vcpu[0], info, 0);
if ( rc == 0 && pt_irq_bind->u.msi.gtable )
@@ -291,6 +411,7 @@ int pt_irq_create_bind(
* to be scheduled but we must deal with the one that may
be
* in the queue.
*/
+ pirq_dpci->line = __LINE__;
pt_pirq_softirq_reset(pirq_dpci);
}
}
@@ -300,6 +421,7 @@ int pt_irq_create_bind(
pirq_dpci->gmsi.gvec = 0;
pirq_dpci->dom = NULL;
pirq_dpci->flags = 0;
+ pirq_dpci->pirq = -pirq;
pirq_cleanup_check(info, d);
spin_unlock(&d->event_lock);
return rc;
@@ -544,6 +666,7 @@ int pt_irq_destroy_bind(
* See comment in pt_irq_create_bind's PT_IRQ_TYPE_MSI before the
* call to pt_pirq_softirq_reset.
*/
+ pirq_dpci->line = __LINE__;
pt_pirq_softirq_reset(pirq_dpci);
pirq_cleanup_check(pirq, d);
@@ -778,6 +901,8 @@ unlock:
spin_unlock(&d->event_lock);
}
+#include <xen/console.h>
+
/*
* Note: 'pt_pirq_softirq_reset' can clear the STATE_SCHED before we get to
* doing it. If that is the case we let 'pt_pirq_softirq_reset' do
ref-counting.
@@ -787,6 +912,9 @@ static void dpci_softirq(void)
unsigned int cpu = smp_processor_id();
unsigned int reset = 0;
LIST_HEAD(our_list);
+ struct __debug *debug;
+
+ debug = &per_cpu(_d, cpu);
local_irq_disable();
list_splice_init(&per_cpu(dpci_list, cpu), &our_list);
@@ -796,9 +924,22 @@ static void dpci_softirq(void)
{
struct hvm_pirq_dpci *pirq_dpci;
struct domain *d;
+ struct list_head *entry;
pirq_dpci = list_entry(our_list.next, struct hvm_pirq_dpci,
softirq_list);
- list_del(&pirq_dpci->softirq_list);
+ entry = &pirq_dpci->softirq_list;
+ if ( entry->next == LIST_POISON1 || entry->next == LIST_POISON2 ||
+ entry->prev == LIST_POISON2 || entry->prev == LIST_POISON2 )
+ {
+ _record(&debug->poison, pirq_dpci);
+ console_start_sync();
+ dump_debug((char)0);
+ console_end_sync();
+ domain_crash(pirq_dpci->dom);
+ break;
+ }
+ _record(&debug->ok, pirq_dpci);
+ list_del(entry);
d = pirq_dpci->dom;
smp_mb(); /* 'd' MUST be saved before we set/clear the bits. */
@@ -813,8 +954,10 @@ static void dpci_softirq(void)
put_domain(d);
}
else
+ {
+ _record(&debug->zombie_softirq, pirq_dpci);
reset = 1;
-
+ }
clear_bit(STATE_RUN, &pirq_dpci->state);
if ( reset )
{
@@ -833,6 +976,7 @@ static int cpu_callback(
{
case CPU_UP_PREPARE:
INIT_LIST_HEAD(&per_cpu(dpci_list, cpu));
+ memset(&per_cpu(_d, cpu), 0, sizeof(struct __debug));
break;
case CPU_UP_CANCELED:
case CPU_DEAD:
@@ -854,15 +998,43 @@ static struct notifier_block cpu_nfb = {
.notifier_call = cpu_callback,
};
+#include <xen/keyhandler.h>
+
+static struct keyhandler dump_debug_keyhandler = {
+ .diagnostic = 1,
+ .u.fn = dump_debug,
+ .desc = "dpci debug stats"
+};
+static struct timer debug_timer;
+static s_time_t last_time = 0;
+static unsigned int debug_cnt = 0;
+
+static void debug_timer_fn(void *d)
+{
+ if ( ( debug_cnt ++ % 10 ) == 0 )
+ printk("--MARK--\n");
+
+ last_time = NOW();
+ set_timer(&debug_timer, last_time + SECONDS(1));
+}
+
static int __init setup_dpci_softirq(void)
{
unsigned int cpu;
for_each_online_cpu(cpu)
+ {
INIT_LIST_HEAD(&per_cpu(dpci_list, cpu));
-
+ memset(&per_cpu(_d, cpu), 0, sizeof(struct __debug));
+ }
open_softirq(HVM_DPCI_SOFTIRQ, dpci_softirq);
register_cpu_notifier(&cpu_nfb);
+
+ init_timer(&debug_timer, debug_timer_fn, NULL, smp_processor_id());
+ last_time = NOW();
+ set_timer(&debug_timer, NOW() + SECONDS(1));
+ register_keyhandler('k', &dump_debug_keyhandler);
+
return 0;
}
__initcall(setup_dpci_softirq);
diff --git a/xen/include/xen/hvm/irq.h b/xen/include/xen/hvm/irq.h
index 9709397..1fb1292 100644
--- a/xen/include/xen/hvm/irq.h
+++ b/xen/include/xen/hvm/irq.h
@@ -100,6 +100,8 @@ struct hvm_pirq_dpci {
struct hvm_gmsi_info gmsi;
struct timer timer;
struct list_head softirq_list;
+ unsigned int pirq;
+ unsigned int line;
};
void pt_pirq_init(struct domain *, struct hvm_pirq_dpci *);
--
1.9.3
>From 3163117e2ceb8dfcc11545dcc385aa3d147614e8 Mon Sep 17 00:00:00 2001
From: Konrad Rzeszutek Wilk <konrad.w...@oracle.com>
Date: Mon, 17 Nov 2014 17:32:43 -0500
Subject: [PATCH 3/5] DEBUG 2
---
xen/drivers/passthrough/io.c | 42 ++++++++++++++++++++++++++++++++++--------
1 file changed, 34 insertions(+), 8 deletions(-)
diff --git a/xen/drivers/passthrough/io.c b/xen/drivers/passthrough/io.c
index 23e5ed1..b786bd2 100644
--- a/xen/drivers/passthrough/io.c
+++ b/xen/drivers/passthrough/io.c
@@ -126,17 +126,17 @@ static void dump_record(struct _debug_f *d, unsigned int
type)
BUG();
now = NOW();
- printk("d%d %s %lumsec ago, state:%x, %ld count, [prev:%p, next:%p] ",
+ printk("d%d %s %lumsec ago, state:%x, %ld count, [prev:%p, next:%p] %p",
d->domid, names[type],
(unsigned long)((now - d->last) / MILLISECS(1)),
- d->state, d->count, d->list.prev, d->list.next);
+ d->state, d->count, d->list.prev, d->list.next, d->dpci);
if ( d->dpci )
{
struct hvm_pirq_dpci *pirq_dpci = d->dpci;
for ( i = 0; i <= _HVM_IRQ_DPCI_GUEST_MSI_SHIFT; i++ )
- if ( pirq_dpci->flags & 1 << _HVM_IRQ_DPCI_TRANSLATE_SHIFT )
+ if ( pirq_dpci->flags & (1 << i) )
printk("%s ", names_flag[i]);
printk(" PIRQ:%d", pirq_dpci->pirq);
@@ -545,9 +545,9 @@ int pt_irq_create_bind(
if ( iommu_verbose )
dprintk(XENLOG_G_INFO,
- "d%d: bind: m_gsi=%u g_gsi=%u dev=%02x.%02x.%u intx=%u\n",
+ "d%d: bind: m_gsi=%u g_gsi=%u dev=%02x.%02x.%u intx=%u
%p\n",
d->domain_id, pirq, guest_gsi, bus,
- PCI_SLOT(device), PCI_FUNC(device), intx);
+ PCI_SLOT(device), PCI_FUNC(device), intx, pirq_dpci);
break;
}
@@ -913,26 +913,52 @@ static void dpci_softirq(void)
unsigned int reset = 0;
LIST_HEAD(our_list);
struct __debug *debug;
-
+ struct hvm_pirq_dpci *pirq_dpci;
+ struct __x {
+ struct list_head l;
+ struct hvm_pirq_dpci *dpci;
+ } l[4];
+ unsigned int i = 0;
+#if DIFF_LIST
+ struct hvm_pirq_dpci *n;
+#endif
debug = &per_cpu(_d, cpu);
local_irq_disable();
list_splice_init(&per_cpu(dpci_list, cpu), &our_list);
local_irq_enable();
-
+#if DIFF_LIST
+ list_for_each_entry_safe(pirq_dpci, n, &our_list, softirq_list)
+#else
while ( !list_empty(&our_list) )
+#endif
{
- struct hvm_pirq_dpci *pirq_dpci;
struct domain *d;
struct list_head *entry;
+#ifndef DIFF_LIST
pirq_dpci = list_entry(our_list.next, struct hvm_pirq_dpci,
softirq_list);
+#endif
entry = &pirq_dpci->softirq_list;
+ if ( i <= 3 )
+ {
+ struct __x *p;
+
+ p = &l[i];
+ p->dpci = pirq_dpci;
+ p->l.prev = entry->prev;
+ p->l.next = entry->next;
+ i++;
+ }
if ( entry->next == LIST_POISON1 || entry->next == LIST_POISON2 ||
entry->prev == LIST_POISON2 || entry->prev == LIST_POISON2 )
{
+ unsigned int j;
+
_record(&debug->poison, pirq_dpci);
console_start_sync();
+ for (j=0; j < i;j++)
+ printk(" %u: %p [p:%p, n:%p]\n", j, l[j].dpci, l[j].l.prev,
l[j].l.next);
dump_debug((char)0);
console_end_sync();
domain_crash(pirq_dpci->dom);
--
1.9.3
>From 8093140e374fceb9121ccd07726fb3898b212bfb Mon Sep 17 00:00:00 2001
From: Konrad Rzeszutek Wilk <konrad.w...@oracle.com>
Date: Tue, 18 Nov 2014 15:08:15 -0500
Subject: [PATCH 4/5] DEBUG4: Add an 'stamp' and potential fix.
Signed-off-by: Konrad Rzeszutek Wilk <konrad.w...@oracle.com>
---
xen/drivers/passthrough/io.c | 57 +++++++++++++++++++++++++++++++-------------
xen/include/xen/hvm/irq.h | 1 +
2 files changed, 41 insertions(+), 17 deletions(-)
diff --git a/xen/drivers/passthrough/io.c b/xen/drivers/passthrough/io.c
index b786bd2..8a8fc62 100644
--- a/xen/drivers/passthrough/io.c
+++ b/xen/drivers/passthrough/io.c
@@ -26,6 +26,8 @@
#include <asm/hvm/iommu.h>
#include <asm/hvm/support.h>
#include <xen/hvm/irq.h>
+#include <xen/console.h>
+
static DEFINE_PER_CPU(struct list_head, dpci_list);
@@ -61,21 +63,29 @@ struct _debug_f {
struct list_head list;
unsigned int state;
struct hvm_pirq_dpci *dpci;
+ unsigned long stamp;
};
struct __debug {
struct _debug_f ok;
struct _debug_f poison;
struct _debug_f raise;
+ struct _debug_f busy_raise;
struct _debug_f reset;
struct _debug_f zombie_softirq;
struct _debug_f zombie_raise;
+ struct _debug_f timeout;
+ struct _debug_f clear;
};
static DEFINE_PER_CPU(struct __debug, _d);
void _record(struct _debug_f *d, struct hvm_pirq_dpci *pirq_dpci)
{
+
+ if (pirq_dpci->pirq)
+ return;
+
if (pirq_dpci->dom)
d->domid = pirq_dpci->dom->domain_id;
else
@@ -86,6 +96,7 @@ void _record(struct _debug_f *d, struct hvm_pirq_dpci
*pirq_dpci)
d->list.prev = pirq_dpci->softirq_list.prev;
d->state = pirq_dpci->state;
d->dpci = pirq_dpci;
+ d->stamp = pirq_dpci->stamp++;
}
enum {
@@ -95,6 +106,9 @@ enum {
OK_SOFTIRQ,
OK_RAISE,
OK_RESET,
+ OK_TIMEOUT,
+ OK_BUSY,
+ OK_CLEAR,
};
static void dump_record(struct _debug_f *d, unsigned int type)
@@ -106,7 +120,11 @@ static void dump_record(struct _debug_f *d, unsigned int
type)
[OK_SOFTIRQ] = "OK-softirq",
[OK_RAISE] = "OK-raise ",
[OK_RESET] = "OK-reset ",
+ [OK_TIMEOUT] = "OK-timeout",
+ [OK_BUSY] = "OK-busy ",
+ [OK_CLEAR] = "OK-clear ",
};
+#if 0
#define LONG(x) [_HVM_IRQ_DPCI_##x] = #x
static const char *const names_flag[] = {
LONG(MACH_PCI_SHIFT),
@@ -117,6 +135,7 @@ static void dump_record(struct _debug_f *d, unsigned int
type)
};
#undef LONG
unsigned int i;
+#endif
s_time_t now;
if ( d->domid == 0 )
@@ -126,20 +145,21 @@ static void dump_record(struct _debug_f *d, unsigned int
type)
BUG();
now = NOW();
- printk("d%d %s %lumsec ago, state:%x, %ld count, [prev:%p, next:%p] %p",
+ printk("d%d %s %lumsec ago, state:%x, %ld count, [prev:%p, next:%p] %p
%lx",
d->domid, names[type],
(unsigned long)((now - d->last) / MILLISECS(1)),
- d->state, d->count, d->list.prev, d->list.next, d->dpci);
+ d->state, d->count, d->list.prev, d->list.next, d->dpci, d->stamp);
if ( d->dpci )
{
struct hvm_pirq_dpci *pirq_dpci = d->dpci;
-
+#if 0
for ( i = 0; i <= _HVM_IRQ_DPCI_GUEST_MSI_SHIFT; i++ )
if ( pirq_dpci->flags & (1 << i) )
printk("%s ", names_flag[i]);
printk(" PIRQ:%d", pirq_dpci->pirq);
+#endif
if (pirq_dpci->line)
printk(" LINE: %d", pirq_dpci->line);
}
@@ -159,7 +179,10 @@ static void dump_debug(unsigned char key)
printk("CPU%02d: \n" ,cpu);
dump_record(&d->ok, OK_SOFTIRQ);
dump_record(&d->raise, OK_RAISE);
+ dump_record(&d->busy_raise, OK_RAISE);
dump_record(&d->reset, OK_RESET);
+ dump_record(&d->timeout, OK_TIMEOUT);
+ dump_record(&d->clear, OK_TIMEOUT);
dump_record(&d->poison, ERR_POISON);
dump_record(&d->zombie_softirq, Z_SOFTIRQ);
dump_record(&d->zombie_raise, Z_RAISE);
@@ -184,8 +207,10 @@ static void raise_softirq_for(struct hvm_pirq_dpci
*pirq_dpci)
return;
}
if ( test_and_set_bit(STATE_SCHED, &pirq_dpci->state) )
+ {
+ _record(&d->busy_raise, pirq_dpci);
return;
-
+ }
_record(&d->raise, pirq_dpci);
get_knownalive_domain(pirq_dpci->dom);
@@ -264,10 +289,14 @@ bool_t pt_irq_need_timer(uint32_t flags)
static int pt_irq_guest_eoi(struct domain *d, struct hvm_pirq_dpci *pirq_dpci,
void *arg)
{
+ struct __debug *debug = &__get_cpu_var(_d);
+
if ( __test_and_clear_bit(_HVM_IRQ_DPCI_EOI_LATCH_SHIFT,
&pirq_dpci->flags) )
{
- pirq_dpci->state = 0;
+ _record(&debug->clear, pirq_dpci);
+ pt_pirq_softirq_reset(pirq_dpci);
+ /* pirq_dpci->state = 0; <= OUCH! */
pirq_dpci->pending = 0;
pirq_guest_eoi(dpci_pirq(pirq_dpci));
}
@@ -280,11 +309,13 @@ static void pt_irq_time_out(void *data)
struct hvm_pirq_dpci *irq_map = data;
const struct hvm_irq_dpci *dpci;
const struct dev_intx_gsi_link *digl;
-
+ struct __debug *d = &__get_cpu_var(_d);
spin_lock(&irq_map->dom->event_lock);
dpci = domain_get_irq_dpci(irq_map->dom);
ASSERT(dpci);
+
+ _record(&d->timeout, irq_map);
list_for_each_entry ( digl, &irq_map->digl_list, list )
{
unsigned int guest_gsi = hvm_pci_intx_gsi(digl->device, digl->intx);
@@ -302,6 +333,9 @@ static void pt_irq_time_out(void *data)
pt_pirq_iterate(irq_map->dom, pt_irq_guest_eoi, NULL);
spin_unlock(&irq_map->dom->event_lock);
+ console_start_sync();
+ dump_debug((char)0);
+ console_end_sync();
}
struct hvm_irq_dpci *domain_get_irq_dpci(const struct domain *d)
@@ -901,8 +935,6 @@ unlock:
spin_unlock(&d->event_lock);
}
-#include <xen/console.h>
-
/*
* Note: 'pt_pirq_softirq_reset' can clear the STATE_SCHED before we get to
* doing it. If that is the case we let 'pt_pirq_softirq_reset' do
ref-counting.
@@ -919,26 +951,17 @@ static void dpci_softirq(void)
struct hvm_pirq_dpci *dpci;
} l[4];
unsigned int i = 0;
-#if DIFF_LIST
- struct hvm_pirq_dpci *n;
-#endif
debug = &per_cpu(_d, cpu);
local_irq_disable();
list_splice_init(&per_cpu(dpci_list, cpu), &our_list);
local_irq_enable();
-#if DIFF_LIST
- list_for_each_entry_safe(pirq_dpci, n, &our_list, softirq_list)
-#else
while ( !list_empty(&our_list) )
-#endif
{
struct domain *d;
struct list_head *entry;
-#ifndef DIFF_LIST
pirq_dpci = list_entry(our_list.next, struct hvm_pirq_dpci,
softirq_list);
-#endif
entry = &pirq_dpci->softirq_list;
if ( i <= 3 )
{
diff --git a/xen/include/xen/hvm/irq.h b/xen/include/xen/hvm/irq.h
index 1fb1292..f5b6061 100644
--- a/xen/include/xen/hvm/irq.h
+++ b/xen/include/xen/hvm/irq.h
@@ -102,6 +102,7 @@ struct hvm_pirq_dpci {
struct list_head softirq_list;
unsigned int pirq;
unsigned int line;
+ unsigned long stamp;
};
void pt_pirq_init(struct domain *, struct hvm_pirq_dpci *);
--
1.9.3
>From 8e0edc1e6d51eeb5a401f686adccefa623332bcd Mon Sep 17 00:00:00 2001
From: Konrad Rzeszutek Wilk <konrad.w...@oracle.com>
Date: Tue, 18 Nov 2014 15:29:12 -0500
Subject: [PATCH 5/5] debug: Remove the --MARK-- code.
We could use it to check every 1msec for some case and print
data, but we never used it.
Signed-off-by: Konrad Rzeszutek Wilk <konrad.w...@oracle.com>
---
xen/drivers/passthrough/io.c | 15 ---------------
1 file changed, 15 deletions(-)
diff --git a/xen/drivers/passthrough/io.c b/xen/drivers/passthrough/io.c
index 8a8fc62..aad5607 100644
--- a/xen/drivers/passthrough/io.c
+++ b/xen/drivers/passthrough/io.c
@@ -1054,18 +1054,6 @@ static struct keyhandler dump_debug_keyhandler = {
.u.fn = dump_debug,
.desc = "dpci debug stats"
};
-static struct timer debug_timer;
-static s_time_t last_time = 0;
-static unsigned int debug_cnt = 0;
-
-static void debug_timer_fn(void *d)
-{
- if ( ( debug_cnt ++ % 10 ) == 0 )
- printk("--MARK--\n");
-
- last_time = NOW();
- set_timer(&debug_timer, last_time + SECONDS(1));
-}
static int __init setup_dpci_softirq(void)
{
@@ -1079,9 +1067,6 @@ static int __init setup_dpci_softirq(void)
open_softirq(HVM_DPCI_SOFTIRQ, dpci_softirq);
register_cpu_notifier(&cpu_nfb);
- init_timer(&debug_timer, debug_timer_fn, NULL, smp_processor_id());
- last_time = NOW();
- set_timer(&debug_timer, NOW() + SECONDS(1));
register_keyhandler('k', &dump_debug_keyhandler);
return 0;
--
1.9.3
_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
http://lists.xen.org/xen-devel
