On Tue, Mar 07, 2017 at 07:11:22AM -0700, Jan Beulich wrote:
>>>> On 07.03.17 at 05:24, <chao....@intel.com> wrote:
>> On Tue, Mar 07, 2017 at 02:16:50AM -0700, Jan Beulich wrote:
>>>>>> On 07.03.17 at 06:52, <osstest-ad...@xenproject.org> wrote:
>>>> flight 106504 xen-unstable real [real]
>>>> http://logs.test-lab.xenproject.org/osstest/logs/106504/
>>>>
>>>> Regressions :-(
>>>>
>>>> Tests which did not succeed and are blocking,
>>>> including tests which could not be run:
>>>> [...]
>>>> test-amd64-amd64-xl-qemuu-debianhvm-amd64-xsm 16 guest-stop fail REGR.
>>>> vs.
>>>> 106482
>>>
>>>Here we go:
>>>
>>>(XEN) d15v0: intack: 02:48 pt: 38
>>>(XEN) vIRR: 00000000 00000000 00000000 00000000 00000000 00000000 00010000
>> 00000000
>>>(XEN) PIR: 00000000 00000000 00000000 00000000 00000000 00000000 00000000
>> 00000000
>>>(XEN) Assertion 'intack.vector >= pt_vector' failed at intr.c:360
>>>(XEN) ----[ Xen-4.9-unstable x86_64 debug=y Not tainted ]----
>>>(XEN) CPU: 0
>>>(XEN) RIP: e008:[<ffff82d0802039e8>] vmx_intr_assist+0x5fa/0x61a
>>>(XEN) RFLAGS: 0000000000010292 CONTEXT: hypervisor (d15v0)
>>>(XEN) rax: ffff82d0804754a8 rbx: ffff83007f375680 rcx: 0000000000000000
>>>(XEN) rdx: ffff83007cd3ffff rsi: 000000000000000a rdi: ffff82d0803316d8
>>>(XEN) rbp: ffff83007cd3ff08 rsp: ffff83007cd3fea8 r8: ffff830277db8000
>>>(XEN) r9: 0000000000000001 r10: 0000000000000000 r11: 0000000000000001
>>>(XEN) r12: 00000000ffffffff r13: ffff82d0802b5b02 r14: ffff82d0802b5b02
>>>(XEN) r15: ffff83027d82e000 cr0: 0000000080050033 cr4: 00000000001526e0
>>>(XEN) cr3: 0000000259135000 cr2: 000000000164f034
>>>(XEN) ds: 0000 es: 0000 fs: 0000 gs: 0000 ss: 0000 cs: e008
>>>(XEN) Xen code around <ffff82d0802039e8> (vmx_intr_assist+0x5fa/0x61a):
>>>(XEN) fb ff ff e9 49 fc ff ff <0f> 0b 89 ce 48 89 df e8 2a 21 00 00 e9 49
>>>fe
>> ff
>>>(XEN) Xen stack trace from rsp=ffff83007cd3fea8:
>>>(XEN) ffff82d08044ab00 00000038ffffffff ffff83007cd3ffff ffff83027d82e000
>>>(XEN) ffff83007cd3fef8 ffff82d080133a3d ffff83007f375000 ffff83007f375000
>>>(XEN) ffff83007f7fc000 ffff83026df78000 0000000000000000 ffff83027d82e000
>>>(XEN) ffff83007cd3fdb0 ffff82d080213191 0000000000000004 00000000000000c2
>>>(XEN) 0000000000000020 0000000000000002 ffff880029994000 ffffffff81ade0a0
>>>(XEN) 0000000000000246 0000000000000000 ffff88002d000008 0000000000000004
>>>(XEN) 000000000000006c 0000000000000000 00000000000003f8 00000000000003f8
>>>(XEN) ffffffff81ade0a0 0000beef0000beef ffffffff81389ac4 000000bf0000beef
>>>(XEN) 0000000000000002 ffff88002f403e08 000000000000beef 000000000000beef
>>>(XEN) 000000000000beef 000000000000beef 000000000000beef 0000000000000000
>>>(XEN) ffff83007f375000 0000000000000000 00000000001526e0
>>>(XEN) Xen call trace:
>>>(XEN) [<ffff82d0802039e8>] vmx_intr_assist+0x5fa/0x61a
>>>(XEN) [<ffff82d080213191>] vmx_asm_vmexit_handler+0x41/0x120
>>>(XEN)
>>>(XEN)
>>>(XEN) ****************************************
>>>(XEN) Panic on CPU 0:
>>>(XEN) Assertion 'intack.vector >= pt_vector' failed at intr.c:360
>>>(XEN) ****************************************
>>>
>>>I didn't make an attempt at interpreting this yet, but I wonder if it
>>>is more than coincidence that - just like the first time the ASSERT()
>>>triggered - this is again a guest-stop of a qemuu-debianhvm.
>>>
>>
>> Cc: xuquan.
>>
>> Exciting! I have been monitoring osstest for about one months through
>> a python script. But I always crawl the flights one time a day.
>>
>> From the output, the pt_vector is 0x38 and the intack.vector is
>> 0x30. these two values are same with they were in the first time.
>> And only one bit 0x30 is set in vIRR. PIR is NULL. So maybe
>> our suspicion that PIR is not synced to vIRR is wrong. The 0x38 bit
>> is not present in vIRR is strange. Is it possible that we clear the 0x38 bit
>> just after we return from pt_update_irq()?
>
>That would be done how?
>
>> Or, just like I suspected that
>> it is caused by pt_update_irq() sets 0x30 but wrongly returns 0x38.
>
>Same here, and as expressed earlier: I'm lacking a plausible theory
>on how this could be happening. In particular ...
>
>> Do you think it worths a try to disable guest's LAPIC timer and
>> force it use IRQ0 along with changing RTE very frequently?
>
>... if this is the LAPIC timer, then the RTE isn't being read afaics
>(pt_irq_vector() should be taking its very first return path in that
>case). Nor am I aware that any Linux version would move around
>one of its timer interrupts very frequently. But then again 0x30
>or 0x38 wouldn't be use for the LAPIC timer anyway, but rather
>a vector in the fixed range (0xEF on 4.10). So I think part of the
>problem is to understand which timer's vector we're dealing with
>here.
>
I have written a xtf test case (many codes are from hvmloader) to
trigger this assertion. The test case is in attachments. Bottom is the output
of this test. This test initializes PIT channel0 to generate periodic timer
interrupt at 1000hz per second. The timer interrupt is delivered to vCPU0. And
vCPU1 is used to change IOAPIC RTE 2 frequently.
The assertion can be triggered by guest. To fix assertion failure,
I propose to remove this assertion for the reason below:
1. Operations in this test case are very intrusive and abnormal. It updates
RTE frequently without disabling interrupt source. In this case, I think
software can't assume hardware works correctly.
2. If we remove this assertion(means we admit pt_vector may be different
from (or bigger than) the vector we set in vIRR in a rare case), the side
effect is that we won't decrease the counter pt->ending_intr_nr in
pt_intr_post() and one more timer interrupt in number is injected to guest.
3. We read RTE 3 times. 1st happens when we set vIRR. 2nd happens when
pt_update_irq() returns. 3rd happens in pt_intr_post(). If guest changes
the vector in RTE during the window, it will also incur losing or getting
more periodic timer interrupt.
(d1) [ 1409.741660] --- Xen Test Framework ---
(d1) [ 1409.741869] Environment: HVM 32bit (No paging)
(d1) [ 1409.741964] Test periodic-timer
(d1) [ 1409.742077] activate cpu1
(XEN) [ 1423.581228] d1v0: intack: 02:48 pt: 38
(XEN) [ 1423.581234] vIRR: 00000000 00000000 00000000 00000000 00000000
00000000 00010000 00000000
(XEN) [ 1423.581246] PIR: 00000000 00000000 00000000 00000000 00000000
00000000 00000000 00000000
(XEN) [ 1423.581286] Assertion 'intack.vector >= pt_vector' failed at intr.c:360
(XEN) [ 1423.581294] ----[ Xen-4.9-unstable x86_64 debug=y Not tainted ]----
(XEN) [ 1423.581370] CPU: 58
(XEN) [ 1423.581375] RIP: e008:[<ffff82d0801fe405>]
vmx_intr_assist+0x605/0x625
(XEN) [ 1423.581389] RFLAGS: 0000000000010296 CONTEXT: hypervisor (d1v0)
(XEN) [ 1423.581398] rax: ffff830837e0402c rbx: ffff83006a093680 rcx:
0000000000000000
(XEN) [ 1423.581404] rdx: ffff831075e17fff rsi: 000000000000000a rdi:
ffff82d08032f6b8
(XEN) [ 1423.581410] rbp: ffff831075e17f08 rsp: ffff831075e17e98 r8:
ffff83083e000000
(XEN) [ 1423.581416] r9: 0000000000000001 r10: 0000000000000000 r11:
0000000000000001
(XEN) [ 1423.581422] r12: 00000000ffffffff r13: ffff82d0802a4c31 r14:
ffff82c000408200
(XEN) [ 1423.581427] r15: 0000000000004016 cr0: 000000008005003b cr4:
00000000003526e0
(XEN) [ 1423.581432] cr3: 000000081e2bf000 cr2: 0000000000000000
(XEN) [ 1423.581437] ds: 0000 es: 0000 fs: 0000 gs: 0000 ss: 0000 cs:
e008
(XEN) [ 1423.581446] Xen code around <ffff82d0801fe405>
(vmx_intr_assist+0x605/0x625):
(XEN) [ 1423.581450] fb ff ff e9 5e fc ff ff <0f> 0b 89 ce 48 89 df e8 03 21
00 00 e9 62 fe ff
(XEN) [ 1423.581470] Xen stack trace from rsp=ffff831075e17e98:
(XEN) [ 1423.581473] ffff831075e17f08 ffff82d08034c700 ffff82d000000030
ffffffffffffffff
(XEN) [ 1423.581483] ffff831075e17fff 0000000000000000 ffff831075e17ef8
ffff82d0801340ff
(XEN) [ 1423.581491] ffff83006a093000 ffff83006a093000 ffff83006a093000
ffff830837e04148
(XEN) [ 1423.581500] 0000014b740caab6 0000000001c9c380 ffff831075e17e28
ffff82d08020da51
(XEN) [ 1423.581509] 0000000000000000 0000000000000000 0000000000000000
0000000000000000
(XEN) [ 1423.581515] 0000000000000000 00000000fee00000 0000000000000000
0000000000000000
(XEN) [ 1423.581522] 0000000000000000 0000000000000000 0000000000000004
000000000010260d
(XEN) [ 1423.581529] 0000000000000001 0000000000000000 0000000000000000
0000beef0000beef
(XEN) [ 1423.581536] 0000000000102928 000000bf0000beef 0000000000000206
0000000000115fa0
(XEN) [ 1423.581544] 000000000000beef 000000000000beef 000000000000beef
000000000000beef
(XEN) [ 1423.581551] 000000000000beef 000000000000003a ffff83006a093000
00000037b7a91900
(XEN) [ 1423.581559] 00000000003526e0
(XEN) [ 1423.581564] Xen call trace:
(XEN) [ 1423.581570] [<ffff82d0801fe405>] vmx_intr_assist+0x605/0x625
(XEN) [ 1423.581580] [<ffff82d08020da51>] vmx_asm_vmexit_handler+0x41/0x120
(XEN) [ 1423.581584]
(XEN) [ 1423.827761]
(XEN) [ 1423.829753] ****************************************
(XEN) [ 1423.835210] Panic on CPU 58:
(XEN) [ 1423.838591] Assertion 'intack.vector >= pt_vector' failed at intr.c:360
(XEN) [ 1423.845698] ****************************************
diff --git a/tests/periodic-timer/Makefile b/tests/periodic-timer/Makefile
new file mode 100644
index 0000000..56c42ea
--- /dev/null
+++ b/tests/periodic-timer/Makefile
@@ -0,0 +1,11 @@
+include $(ROOT)/build/common.mk
+
+NAME := periodic-timer
+CATEGORY := special
+TEST-ENVS := hvm32
+
+TEST-EXTRA-CFG := extra.cfg.in
+
+obj-perenv += main.o entry.o
+
+include $(ROOT)/build/gen.mk
diff --git a/tests/periodic-timer/entry.S b/tests/periodic-timer/entry.S
new file mode 100644
index 0000000..8a32f76
--- /dev/null
+++ b/tests/periodic-timer/entry.S
@@ -0,0 +1,15 @@
+#include <arch/idt.h>
+#include <arch/page.h>
+#include <arch/processor.h>
+#include <arch/segment.h>
+#include <xtf/asm_macros.h>
+#include <arch/msr-index.h>
+
+ .align 16
+ .code32
+
+ENTRY(handle_external_int)
+ SAVE_ALL
+ call pt_interrupt_handler
+ RESTORE_ALL
+ iret
diff --git a/tests/periodic-timer/extra.cfg.in
b/tests/periodic-timer/extra.cfg.in
new file mode 100644
index 0000000..8cfbab9
--- /dev/null
+++ b/tests/periodic-timer/extra.cfg.in
@@ -0,0 +1 @@
+vcpus=2
diff --git a/tests/periodic-timer/main.c b/tests/periodic-timer/main.c
new file mode 100644
index 0000000..0098b89
--- /dev/null
+++ b/tests/periodic-timer/main.c
@@ -0,0 +1,283 @@
+/**
+ * @file tests/periodic-timer/main.c
+ * @ref test-periodic-timer
+ *
+ * @page test-periodic-timer periodic-timer
+ *
+ * @todo Docs for test-periodic-timer
+ *
+ * @see tests/periodic-timer/main.c
+ */
+#include <xtf.h>
+#include <arch/barrier.h>
+#include <arch/idt.h>
+#include <xtf/asm_macros.h>
+#include <arch/msr-index.h>
+
+#define COUNTER_FREQ 1193181
+#define MAX_PIT_HZ COUNTER_FREQ
+#define MIN_PIT_HZ 18
+#define PIT_CTRL_PORT 0x43
+#define PIT_CHANNEL0 0x40
+
+#define IOAPIC_REGSEL ((uint32_t *)0xfec00000)
+#define IOAPIC_IOWIN ((uint32_t *)0xfec00010)
+
+#define AP_START_EIP 0x1000UL
+extern char ap_boot_start[], ap_boot_end[];
+
+asm (
+ " .text \n"
+ " .code16 \n"
+ "ap_boot_start: .code16 \n"
+ " mov %cs,%ax \n"
+ " mov %ax,%ds \n"
+ " lgdt gdt_desr-ap_boot_start\n"
+ " xor %ax, %ax \n"
+ " inc %ax \n"
+ " lmsw %ax \n"
+ " ljmpl $0x08,$1f \n"
+ "gdt_desr: \n"
+ " .word gdt_end - gdt - 1 \n"
+ " .long gdt \n"
+ "ap_boot_end: .code32 \n"
+ "1: mov $0x10,%eax \n"
+ " mov %eax,%ds \n"
+ " mov %eax,%es \n"
+ " mov %eax,%ss \n"
+ " movl $stack_top,%esp \n"
+ " movl %esp,%ebp \n"
+ " call test_ap_main \n"
+ "1: hlt \n"
+ " jmp 1b \n"
+ " \n"
+ " .align 8 \n"
+ "gdt: \n"
+ " .quad 0x0000000000000000 \n"
+ " .quad 0x00cf9a000000ffff \n" /* 0x08: Flat code segment */
+ " .quad 0x00cf92000000ffff \n" /* 0x10: Flat data segment */
+ "gdt_end: \n"
+ " \n"
+ " .bss \n"
+ " .align 8 \n"
+ "stack: \n"
+ " .skip 0x4000 \n"
+ "stack_top: \n"
+ " .text \n"
+ );
+
+const char test_title[] = "Test periodic-timer";
+
+int init_pit(int freq)
+{
+ uint16_t reload;
+
+ if ( (freq < MIN_PIT_HZ) || (freq > MAX_PIT_HZ) )
+ return -1;
+
+ reload = COUNTER_FREQ / freq;
+
+ asm volatile("cli");
+ outb(0x34, PIT_CTRL_PORT);
+ outb(reload & 0xff, PIT_CHANNEL0);
+ outb(reload >> 8, PIT_CHANNEL0);
+ asm volatile("sti");
+ return 0;
+}
+
+struct ioapic_entry {
+ union {
+ struct {
+ uint32_t vector : 8,
+ dlm : 3,
+ dm : 1,
+ dls : 1,
+ pol : 1,
+ irr : 1,
+ tri : 1,
+ mask : 1,
+ rsvd1 : 15;
+ uint32_t rsvd2 : 24,
+ dest : 8;
+ } fields;
+ struct {
+ uint32_t lo;
+ uint32_t hi;
+ } bits;
+ };
+} __attribute__ ((packed));
+
+void writel(uint32_t data, uint32_t *addr)
+{
+ *addr = data;
+}
+
+#define readl(data, addr) (data) = *(addr)
+
+int write_IOAPIC_entry(struct ioapic_entry *ent, int pin)
+{
+ asm volatile("cli");
+ writel(0x11 + 2*pin, IOAPIC_REGSEL);
+ writel(ent->bits.hi, IOAPIC_IOWIN);
+ wmb();
+ writel(0x10 + 2*pin, IOAPIC_REGSEL);
+ writel(ent->bits.lo, IOAPIC_IOWIN);
+ wmb();
+ asm volatile("sti");
+ return 0;
+}
+
+void handle_external_int(void);
+
+#define rdmsr(msr, val1, val2) \
+ __asm__ __volatile__("rdmsr" \
+ : "=a" (val1), "=d" (val2) \
+ : "c" (msr))
+
+#define wrmsr(msr, val1, val2) \
+ __asm__ __volatile__("wrmsr" \
+ : \
+ : "c" (msr), "a" (val1), "d" (val2))
+
+static inline void wrmsrl(unsigned int msr, uint64_t val)
+{
+ uint32_t lo, hi;
+ lo = (uint32_t)val;
+ hi = (uint32_t)(val >> 32);
+ wrmsr(msr, lo, hi);
+}
+
+#define APIC_BASE_ADDR_MASK 0xfffff000
+#define APIC_BASE_ADDR(a) (a & APIC_BASE_ADDR_MASK)
+#define APIC_BASE_MSR 0x1b
+#define APIC_GLOBAL_ENABLE_MASK 0x800
+#define APIC_EOI 0xB0
+#define APIC_SVR 0xF0
+#define APIC_SOFT_ENABLE_MASK 0x100
+
+uint32_t apic_base_addr;
+
+void enable_lapic(void)
+{
+ uint32_t lo, hi;
+ uint64_t apic_base_msr;
+ uint32_t svr;
+ rdmsr(APIC_BASE_MSR, lo, hi);
+ apic_base_msr = lo | ((uint64_t) hi <<32);
+ apic_base_addr = APIC_BASE_ADDR(apic_base_msr);
+ wrmsrl(APIC_BASE_MSR, apic_base_msr | APIC_GLOBAL_ENABLE_MASK);
+ readl(svr, (uint32_t *)(apic_base_addr + APIC_SVR));
+ writel(svr | APIC_SOFT_ENABLE_MASK, (uint32_t *)(apic_base_addr +
APIC_SVR));
+}
+
+void ack_APIC_irq(unsigned long apic_base)
+{
+ writel(0, (uint32_t *)(apic_base + APIC_EOI));
+}
+
+uint32_t lapic_read(uint32_t reg)
+{
+ return *(volatile uint32_t *)(apic_base_addr + reg);
+}
+
+void lapic_write(uint32_t reg, uint32_t val)
+{
+ *(volatile uint32_t *)(apic_base_addr + reg) = val;
+}
+
+#define APIC_ICR 0x300
+#define APIC_ICR2 0x310
+#define APIC_ICR_BUSY 0x01000
+#define APIC_DM_INIT 0x500
+#define APIC_DM_STARTUP 0x600
+
+static inline void cpu_relax(void)
+{
+ asm volatile ( "rep; nop" ::: "memory" );
+}
+
+static void lapic_wait_ready(void)
+{
+ while ( lapic_read(APIC_ICR) & APIC_ICR_BUSY )
+ cpu_relax();
+}
+
+void pt_interrupt_handler(void)
+{
+ ack_APIC_irq(apic_base_addr);
+}
+
+static void boot_cpu(int cpu)
+{
+ unsigned int icr2 = (cpu * 2) << 24;
+ lapic_wait_ready();
+ lapic_write(APIC_ICR2, icr2);
+ lapic_write(APIC_ICR, APIC_DM_INIT);
+ lapic_wait_ready();
+ lapic_write(APIC_ICR2, icr2);
+ lapic_write(APIC_ICR, APIC_DM_STARTUP | (AP_START_EIP >> 12));
+ lapic_wait_ready();
+ lapic_write(APIC_ICR2, icr2);
+ lapic_write(APIC_ICR, APIC_DM_STARTUP | (AP_START_EIP >> 12));
+ lapic_wait_ready();
+}
+
+void smp_initialize(void)
+{
+ memcpy((void*)AP_START_EIP, ap_boot_start,
+ ap_boot_end - ap_boot_start);
+ boot_cpu(1);
+}
+
+struct ioapic_entry ent;
+void test_main(void)
+{
+ struct xtf_idte idte =
+ {
+ .addr = (unsigned long)handle_external_int,
+ .cs = __KERN_CS,
+ .dpl = 0,
+ };
+
+ /* setup idt entry */
+ xtf_set_idte(0x30, &idte);
+ xtf_set_idte(0x38, &idte);
+
+ //asm volatile(".byte 0xcd,0x30\n");
+
+ memset(&ent, 0, sizeof(ent));
+ ent.fields.vector = 0x38;
+ write_IOAPIC_entry(&ent, 2);
+ enable_lapic();
+
+ printk("activate cpu1\n");
+ smp_initialize();
+ init_pit(1000);
+
+ while (1)
+ cpu_relax();
+
+ xtf_success(NULL);
+}
+
+void test_ap_main(void)
+{
+ struct ioapic_entry ent2;
+ memcpy(&ent2, &ent, sizeof(ent2));
+ ent2.fields.vector = 0x30;
+ while (1)
+ {
+ write_IOAPIC_entry(&ent2, 2);
+ write_IOAPIC_entry(&ent, 2);
+ }
+}
+
+/*
+ * Local variables:
+ * mode: C
+ * c-file-style: "BSD"
+ * c-basic-offset: 4
+ * tab-width: 4
+ * indent-tabs-mode: nil
+ * End:
+ */
_______________________________________________
Xen-devel mailing list
Xen-devel@lists.xen.org
https://lists.xen.org/xen-devel
