From patchwork Sat Dec 19 01:08:05 2015 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: "Gonglei (Arei)" X-Patchwork-Id: 7889061 Return-Path: X-Original-To: patchwork-kvm@patchwork.kernel.org Delivered-To: patchwork-parsemail@patchwork1.web.kernel.org Received: from mail.kernel.org (mail.kernel.org [198.145.29.136]) by patchwork1.web.kernel.org (Postfix) with ESMTP id 9E0469F387 for ; Sat, 19 Dec 2015 01:31:45 +0000 (UTC) Received: from mail.kernel.org (localhost [127.0.0.1]) by mail.kernel.org (Postfix) with ESMTP id 54DFB204AF for ; Sat, 19 Dec 2015 01:31:44 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id 912D9204AD for ; Sat, 19 Dec 2015 01:31:42 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S932195AbbLSBbR (ORCPT ); Fri, 18 Dec 2015 20:31:17 -0500 Received: from lhrrgout.huawei.com ([194.213.3.17]:37897 "EHLO lhrrgout.huawei.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1750716AbbLSBbQ convert rfc822-to-8bit (ORCPT ); Fri, 18 Dec 2015 20:31:16 -0500 Received: from 172.24.2.62 (EHLO szxga02-in.huawei.com) ([172.24.2.62]) by lhrrg02-dlp.huawei.com (MOS 4.3.7-GA FastPath queued) with ESMTP id CBT76868; Sat, 19 Dec 2015 01:31:12 +0000 (GMT) Received: from 172.24.1.50 (EHLO szxema411-hub.china.huawei.com) ([172.24.1.50]) by szxrg02-dlp.huawei.com (MOS 4.3.7-GA FastPath queued) with ESMTP id CYH16035; Sat, 19 Dec 2015 09:08:21 +0800 (CST) Received: from SZXEMA503-MBS.china.huawei.com ([169.254.6.106]) by szxema411-hub.china.huawei.com ([10.82.72.70]) with mapi id 14.03.0235.001; Sat, 19 Dec 2015 09:08:04 +0800 From: "Gonglei (Arei)" To: "Kevin O'Connor" , "Xulei (Stone)" , Paolo Bonzini CC: qemu-devel , "seabios@seabios.org" , "Huangweidong (C)" , "kvm@vger.kernel.org" Subject: RE: [Qemu-devel] [PATCH] SeaBios: Fix reset procedure reentrancy problem on qemu-kvm platform Thread-Topic: [Qemu-devel] [PATCH] SeaBios: Fix reset procedure reentrancy problem on qemu-kvm platform Thread-Index: AQHRFygll/XOya/vMUKmfl3iheaxt56i61UAgC7ZleA= Date: Sat, 19 Dec 2015 01:08:05 +0000 Message-ID: <33183CC9F5247A488A2544077AF19020B02B79EE@SZXEMA503-MBS.china.huawei.com> References: <8E78D212B8C25246BE4CE7EA0E645FE5291A08@SZXEMI504-MBS.china.huawei.com> <563955D4.7080000@huawei.com> <20151104174201.GA17784@morn.lan> <8E78D212B8C25246BE4CE7EA0E645FE52977E8@SZXEMI504-MBS.china.huawei.com> <20151109133253.GA1790@morn.lan> <20151109200618.GA29129@morn.lan> <20151109202726.GA31490@morn.lan> <8E78D212B8C25246BE4CE7EA0E645FE52B5BE3@SZXEMI504-MBS.china.huawei.com> <8E78D212B8C25246BE4CE7EA0E645FE52B72B7@SZXEMI504-MBS.china.huawei.com> <20151119134039.GA27717@morn.lan> In-Reply-To: <20151119134039.GA27717@morn.lan> Accept-Language: zh-CN, en-US Content-Language: zh-CN X-MS-Has-Attach: X-MS-TNEF-Correlator: x-originating-ip: [10.177.18.62] MIME-Version: 1.0 X-CFilter-Loop: Reflected X-Mirapoint-Virus-RAPID-Raw: score=unknown(0), refid=str=0001.0A020206.5674AE07.00FE, ss=1, re=0.000, recu=0.000, reip=0.000, cl=1, cld=1, fgs=0, ip=169.254.6.106, so=2013-06-18 04:22:30, dmn=2013-03-21 17:37:32 X-Mirapoint-Loop-Id: c5842d6379a6c7137f99e4979cb6888c X-Mirapoint-Virus-RAPID-Raw: score=unknown(0), refid=str=0001.0A020201.5674B360.00AE, ss=1, re=0.000, recu=0.000, reip=0.000, cl=1, cld=1, fgs=0, ip=169.254.6.106, so=2013-06-18 04:22:30, dmn=2013-03-21 17:37:32 X-Mirapoint-Loop-Id: 86dafcea53583d5c509ca925ac83d4b8 Sender: kvm-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: kvm@vger.kernel.org X-Spam-Status: No, score=-6.9 required=5.0 tests=BAYES_00, RCVD_IN_DNSWL_HI, T_RP_MATCHES_RCVD, UNPARSEABLE_RELAY autolearn=unavailable version=3.3.1 X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on mail.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP Hi Kevin & Paolo, Luckily, I reproduced this problem last night. And I got the below log when SeaBIOS is stuck. [BTW, the whole SeaBIOS log attached] [2015-12-18 10:38:10] >>>>>gonglei: enter smp_setup()... [2015-12-18 10:38:10] >>>>>gonglei: begine to enable local APIC... [2015-12-18 10:38:10] >>>>>gonglei: finish enable local APIC... [2015-12-18 10:38:10] >>>gonglei: cmos_smp_count=8 [2015-12-18 10:38:10] >>> enter handle_smp... [2015-12-18 10:38:10] handle_smp: apic_id=5 [2015-12-18 10:38:10] ===: CountCPUs=2, SMPStack=0x6d84 [2015-12-18 10:38:10] >>> enter handle_smp... [2015-12-18 10:38:10] handle_smp: apic_id=7 [2015-12-18 10:38:10] ===: CountCPUs=3, SMPStack=0x6d84 [2015-12-18 10:38:10] >>> enter handle_smp... [2015-12-18 10:38:10] handle_smp: apic_id=1 [2015-12-18 10:38:10] ===: CountCPUs=4, SMPStack=0x6d84 [2015-12-18 10:38:10] >>> enter handle_smp... [2015-12-18 10:38:10] handle_smp: apic_id=2 [2015-12-18 10:38:10] ===: CountCPUs=5, SMPStack=0x6d84 [2015-12-18 10:38:10] >>> enter handle_smp... [2015-12-18 10:38:10] handle_smp: apic_id=4 [2015-12-18 10:38:10] ===: CountCPUs=6, SMPStack=0x6d84 [2015-12-18 10:38:10] >>> enter handle_smp... [2015-12-18 10:38:10] handle_smp: apic_id=3 [2015-12-18 10:38:10] ===: CountCPUs=7, SMPStack=0x6d84 [2015-12-18 10:38:10] >>> enter handle_smp... [2015-12-18 10:38:10] handle_smp: apic_id=6 [2015-12-18 10:38:10] ===: CountCPUs=8, SMPStack=0x6d84 [2015-12-18 10:38:10] gonglei: finish while [pid 31509 is a vcpu thread used 100% cpu overhead] # cat /proc/31509/stack [] vmx_vcpu_run+0x35c/0x580 [kvm_intel] [] em_push+0x0/0x20 [kvm] [] x86_emulate_instruction+0x20c/0x440 [kvm] [] handle_exception+0xe4/0x1b58 [kvm_intel] [] vcpu_enter_guest+0x565/0x790 [kvm] [] vmx_get_segment_base+0x0/0xb0 [kvm_intel] [] __vcpu_run+0x198/0x260 [kvm] [] kvm_arch_vcpu_ioctl_run+0x68/0x1a0 [kvm] [] vcpu_load+0x4e/0x80 [kvm] [] kvm_vcpu_ioctl+0x38e/0x580 [kvm] [] futex_wake+0xfd/0x110 [] security_file_permission+0x1c/0xa0 [] do_vfs_ioctl+0x8b/0x3b0 [] sys_ioctl+0xa1/0xb0 [] system_call_fastpath+0x16/0x1b [] 0xffffffffffffffff And kvm tracing information: <...>-31509 [035] 154753.180077: kvm_exit: reason EXCEPTION_NMI rip 0x3 info 0 80000306 <...>-31509 [035] 154753.180077: kvm_emulate_insn: 0:3:f0 53 (real) <...>-31509 [035] 154753.180077: kvm_inj_exception: #UD (0x0) <...>-31509 [035] 154753.180077: kvm_entry: vcpu 0 <...>-31509 [035] 154753.180078: kvm_exit: reason EXCEPTION_NMI rip 0x3 info 0 80000306 <...>-31509 [035] 154753.180078: kvm_emulate_insn: 0:3:f0 53 (real) <...>-31509 [035] 154753.180079: kvm_inj_exception: #UD (0x0) <...>-31509 [035] 154753.180079: kvm_entry: vcpu 0 <...>-31509 [035] 154753.180079: kvm_exit: reason EXCEPTION_NMI rip 0x3 info 0 80000306 <...>-31509 [035] 154753.180080: kvm_emulate_insn: 0:3:f0 53 (real) <...>-31509 [035] 154753.180080: kvm_inj_exception: #UD (0x0) <...>-31509 [035] 154753.180080: kvm_entry: vcpu 0 <...>-31509 [035] 154753.180081: kvm_exit: reason EXCEPTION_NMI rip 0x3 info 0 80000306 <...>-31509 [035] 154753.180081: kvm_emulate_insn: 0:3:f0 53 (real) <...>-31509 [035] 154753.180081: kvm_inj_exception: #UD (0x0) <...>-31509 [035] 154753.180081: kvm_entry: vcpu 0 <...>-31509 [035] 154753.180082: kvm_exit: reason EXCEPTION_NMI rip 0x3 info 0 80000306 <...>-31509 [035] 154753.180083: kvm_emulate_insn: 0:3:f0 53 (real) <...>-31509 [035] 154753.180083: kvm_inj_exception: #UD (0x0) <...>-31509 [035] 154753.180083: kvm_entry: vcpu 0 <...>-31509 [035] 154753.180084: kvm_exit: reason EXCEPTION_NMI rip 0x3 info 0 80000306 <...>-31509 [035] 154753.180084: kvm_emulate_insn: 0:3:f0 53 (real) <...>-31509 [035] 154753.180084: kvm_inj_exception: #UD (0x0) <...>-31509 [035] 154753.180084: kvm_entry: vcpu 0 <...>-31509 [035] 154753.180085: kvm_exit: reason EXCEPTION_NMI rip 0x3 info 0 80000306 <...>-31509 [035] 154753.180085: kvm_emulate_insn: 0:3:f0 53 (real) <...>-31509 [035] 154753.180085: kvm_inj_exception: #UD (0x0) <...>-31509 [035] 154753.180085: kvm_entry: vcpu 0 <...>-31509 [035] 154753.180086: kvm_exit: reason EXCEPTION_NMI rip 0x3 info 0 80000306 Now, it's very clear that the guest stuck in yiled(), and then kvm encounter the exception #UD. Do you have any thoughts? Thanks! The Seabios patch below: Regards, -Gonglei > -----Original Message----- > From: Kevin O'Connor [mailto:kevin@koconnor.net] > Sent: Thursday, November 19, 2015 9:41 PM > To: Xulei (Stone) > Cc: Gonglei (Arei); qemu-devel; seabios@seabios.org; Huangweidong (C) > Subject: Re: [Qemu-devel] [PATCH] SeaBios: Fix reset procedure reentrancy > problem on qemu-kvm platform > > On Thu, Nov 19, 2015 at 12:42:50PM +0000, Xulei (Stone) wrote: > > Kevin, > > > > After deeply analyzing, i think there may be 3 possible reasons: > > 1)wrong CountCPUs value. It seems CountCPUs++ in handle_smp() has no > > lock to protect. So, sometimes, 2 or more vcpu may get the same > > current value of CountCPUs. Then we'll get a single incrementation > > instead of 2 or more and "while (cmos_smp_count != CountCPUs)" will > > loop forever; > > The handle_smp() code is called from romlayout.S:entry_smp() which does take > a lock. So, all of handle_smp() should run synchronous. > > > 2)wrong cmos_smp_count value. SeaBIOS rtc reads an incorrect number? > > Not sure - the last time there were problems in this area of the code others > used kvmtrace to try and track this down. Since you are getting dprintf > statements, you could also try outputting cmos_smp_count prior to the loop > (see patch below). > > > 3)yield() stuck. Is it possible that SeaBIOS is stuck during yield? > > I've tested, when yield() is running, SeaBIOS seems has not created > > some other threads except the main thread. So I don't know what's the > > function of yield() here.? > > The yield() allows hardware interrupts to occur. But note that > yield() isn't called in the loop - is is only called after the loop completes. > > If you are only getting this on massive repetitive reboot requests, there are > some other possible explanations: > > - perhaps the SIPI is getting lost because one of the CPUs is still > resetting or still processing a SIPI from the last reboot? > > - the seabios code itself may have been corrupted if the memcpy() in > qemu_prep_reset() got far enough along to clear HaveRunPost, but did > not get far enough along to fully complete the memcpy(). > > If the failure is reproducible, the patch below could help narrow the > possibilities. > > -Kevin > > > --- a/src/fw/smp.c > +++ b/src/fw/smp.c > @@ -125,6 +125,7 @@ smp_setup(void) > > // Wait for other CPUs to process the SIPI. > u8 cmos_smp_count = rtc_read(CMOS_BIOS_SMP_COUNT) + 1; > + dprintf(1, "cmos_smp_count=%d\n", cmos_smp_count); > while (cmos_smp_count != CountCPUs) > asm volatile( > // Release lock and allow other processors to use the stack. > @@ -136,6 +137,7 @@ smp_setup(void) > " jc 1b\n" > : "+m" (SMPLock), "+m" (SMPStack) > : : "cc", "memory"); > + dprintf(1, "finish smp\n"); > yield(); > > // Restore memory. --- To unsubscribe from this list: send the line "unsubscribe kvm" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html diff --git a/roms/seabios/src/boot.c b/roms/seabios/src/boot.c index f23e9e1..552914a 100644 --- a/roms/seabios/src/boot.c +++ b/roms/seabios/src/boot.c @@ -93,7 +93,7 @@ glob_prefix(const char *glob, const char *str) static int find_prio(const char *glob) { - dprintf(1, "Searching bootorder for: %s\n", glob); + //dprintf(1, "Searching bootorder for: %s\n", glob); int i; for (i = 0; i < BootorderCount; i++) if (glob_prefix(glob, Bootorder[i])) diff --git a/roms/seabios/src/fw/smp.c b/roms/seabios/src/fw/smp.c index a466ea6..46ec607 100644 --- a/roms/seabios/src/fw/smp.c +++ b/roms/seabios/src/fw/smp.c @@ -46,12 +46,16 @@ int apic_id_is_present(u8 apic_id) return !!(FoundAPICIDs[apic_id/32] & (1ul << (apic_id % 32))); } +// Atomic lock for shared stack across processors. +u32 SMPLock __VISIBLE; +u32 SMPStack __VISIBLE; + void VISIBLE32FLAT handle_smp(void) { if (!CONFIG_QEMU) return; - + dprintf(1, ">>> enter handle_smp...\n"); // Enable CPU caching setcr0(getcr0() & ~(CR0_CD|CR0_NW)); @@ -70,19 +74,16 @@ handle_smp(void) FoundAPICIDs[apic_id/32] |= (1 << (apic_id % 32)); CountCPUs++; + dprintf(1, "===: CountCPUs=%d, SMPStack=0x%x\n", CountCPUs, SMPStack); } -// Atomic lock for shared stack across processors. -u32 SMPLock __VISIBLE; -u32 SMPStack __VISIBLE; - // find and initialize the CPUs by launching a SIPI to them void smp_setup(void) { if (!CONFIG_QEMU) return; - + dprintf(1, ">>>>>gonglei: enter smp_setup()...\n"); ASSERT32FLAT(); u32 eax, ebx, ecx, cpuid_features; cpuid(1, &eax, &ebx, &ecx, &cpuid_features); @@ -106,7 +107,7 @@ smp_setup(void) u64 new = (0xea | ((u64)SEG_BIOS<<24) | (((u32)entry_smp - BUILD_BIOS_ADDR) << 8)); *(u64*)BUILD_AP_BOOT_ADDR = new; - + dprintf(1, ">>>>>gonglei: begine to enable local APIC...\n"); // enable local APIC u32 val = readl(APIC_SVR); writel(APIC_SVR, val | APIC_ENABLED); @@ -125,10 +126,21 @@ smp_setup(void) writel(APIC_ICR_LOW, 0x000C4500); u32 sipi_vector = BUILD_AP_BOOT_ADDR >> 12; writel(APIC_ICR_LOW, 0x000C4600 | sipi_vector); - + dprintf(1, ">>>>>gonglei: finish enable local APIC...\n"); // Wait for other CPUs to process the SIPI. u8 cmos_smp_count = rtc_read(CMOS_BIOS_SMP_COUNT) + 1; - while (cmos_smp_count != CountCPUs) + dprintf(1, ">>>gonglei: cmos_smp_count=%d\n", cmos_smp_count); + while (cmos_smp_count != CountCPUs) { asm volatile( // Release lock and allow other processors to use the stack. " movl %%esp, %1\n" @@ -139,8 +151,11 @@ smp_setup(void) " jc 1b\n" : "+m" (SMPLock), "+m" (SMPStack) : : "cc", "memory"); + //yield(); + } + dprintf(1, " gonglei: finish while\n"); yield(); - + dprintf(1, " gonglei: finish yield\n"); // Restore memory. *(u64*)BUILD_AP_BOOT_ADDR = old; diff --git a/roms/seabios/src/misc.c b/roms/seabios/src/misc.c index 8caaf31..77f6be3 100644 --- a/roms/seabios/src/misc.c +++ b/roms/seabios/src/misc.c @@ -64,6 +64,10 @@ void VISIBLE16 handle_02(void) { debug_isr(DEBUG_ISR_02); + dprintf(1, "gonglei hand nmi inject, write rtc \n"); } void diff --git a/roms/seabios/src/stacks.c b/roms/seabios/src/stacks.c index 1dbdfe9..c1b5203 100644 --- a/roms/seabios/src/stacks.c +++ b/roms/seabios/src/stacks.c @@ -174,6 +174,7 @@ call16_smm(u32 eax, u32 edx, void *func) static void call32_sloppy_prep(void) { + dprintf(1, ">>> enter call32_sloppy_prep...\n"); // Backup cmos index register and disable nmi u8 cmosindex = inb(PORT_CMOS_INDEX); outb(cmosindex | NMI_DISABLE_BIT, PORT_CMOS_INDEX);