All of lore.kernel.org
 help / color / mirror / Atom feed
* Re: [Qemu-devel] [QUESTION]stuck in SeaBIOS and vm cannot be reset any more
@ 2016-08-11  2:13 Xulei (Stone)
  2016-08-11 13:37 ` Paolo Bonzini
  0 siblings, 1 reply; 5+ messages in thread
From: Xulei (Stone) @ 2016-08-11  2:13 UTC (permalink / raw)
  To: Paolo Bonzini, Kevin O'Connor, Paolo Bonzini; +Cc: seabios, qemu-devel



 
> On 09/08/2016 10:04, Xulei (Stone) wrote:
> > Following your suggestion, i'm now sure it is caused by missing SMI.
> > I have tried adding dprintf() like this:
> >
> > --- a/roms/seabios/src/fw/smm.c
> > +++ b/roms/seabios/src/fw/smm.c
> > @@ -65,7 +65,8 @@ handle_smi(u16 cs)
> >      u8 cmd = inb(PORT_SMI_CMD);
> >      struct smm_layout *smm = MAKE_FLATPTR(cs, 0);
> >      u32 rev = smm->cpu.i32.smm_rev & SMM_REV_MASK;
> > -    dprintf(DEBUG_HDL_smi, "handle_smi cmd=%x smbase=%p\n", cmd,
> smm);
> > +    if(cmd == 0x00) {
> > +    	dprintf(1, "handle_smi cmd=%x smbase=%p\n", cmd, smm);
> > +    }
> >
> >      if (smm == (void*)BUILD_SMM_INIT_ADDR) {
> >          // relocate SMBASE to 0xa0000 @@ -147,14 +148,14 @@
> > smm_relocate_and_restore(void)  {
> >      /* init APM status port */
> >      outb(0x01, PORT_SMI_STATUS);
> > +   dprintf(1,"before SMI====\n");
> >
> >      /* raise an SMI interrupt */
> >      outb(0x00, PORT_SMI_CMD);
> > +    dprintf(1,"after SMI=====\n");
> >
> >      /* wait until SMM code executed */
> >      while (inb(PORT_SMI_STATUS) != 0x00)
> >          ;
> > +   dprintf(1,"smm code executes complete====\n");
> >
> > And the failed case log output like this:
> > 2016-08-03 16:23:15PCI: Using 00:02.0 for primary VGA
> > 2016-08-03 16:23:15smm_device_setup start
> > 2016-08-03 16:23:15init smm
> > 2016-08-03 16:23:15before SMI====
> > 2016-08-03 16:23:15after SMI=====
> >
> > So, it's obviously that after outb(0x01, PORT_SMI_STATUS), bios does
> > not handle_smi, so PORT_SMI_STATUS is always 0x01. What's more, when
> > this problem happens, rebooting vm cannot restore it any more. My vm
> > is always stuck at the same place until i destroy it.
> >
> > And I have already tried kernel commit c43203cab1e which still can not
> > solve this problem.
> > Any idea, Kevin and Paolo?
> 
> 0xb2 is handled within QEMU, so it may be useful to make sure that QEMU is
> sending the KVM_SMI ioctl.  From there the best tool is still KVM tracing and
> printk.  I suggest replacing the dprintf with a simple outb like outb(0x21,
> 0x402) (before) and outb(0x23, 0x402) (after).  They show as "!" and "#" in the
> trace, and they are easy to spot in the KVM trace.

Following your suggestion, I found this problem may be caused by the flag of 
HF_SMM_MASK. I'm now sure QEMU is sending the KVM_SMI ioctl, and 
kmod already handles this ioctl.

I add printk in inject_pending_event(), like this:

/* try to inject new event if pending */
+  if(get_smi)
+    printk(KERN_INFO "is_smm:%d\n", is_smm(vcpu));
+
   if (vcpu->arch.smi_pending && !is_smm(vcpu)) {
           vcpu->arch.smi_pending = false;
           process_smi(vcpu);
   }

Then I found that the normal output is (is_smm is 0):
2016-08-11T09:44:45.090078+08:00|info|kernel[-]|[1269634.151054get smi ioctl from qemu
2016-08-11T09:44:45.090097+08:00|info|kernel[-]|[1269634.151056in process_smi_request
2016-08-11T09:44:45.090114+08:00|info|kernel[-]|[1269634.151057is_smm:0
2016-08-11T09:44:45.090131+08:00|info|kernel[-]|[1269634.151058process smi
2016-08-11T09:44:45.090914+08:00|info|kernel[-]|[1269634.151575get smi ioctl from qemu
2016-08-11T09:44:45.090947+08:00|info|kernel[-]|[1269634.151578in process_smi_request
2016-08-11T09:44:45.090972+08:00|info|kernel[-]|[1269634.151579is_smm:0

When problem occurs the output is (is_smm is 1):
2016-08-11T10:07:11.755982+08:00|info|kernel[-]|[1270981.916056get smi ioctl from qemu
2016-08-11T10:07:11.756035+08:00|info|kernel[-]|[1270981.916062in process_smi_request
2016-08-11T10:07:11.756078+08:00|info|kernel[-]|[1270981.916064is_smm:1
2016-08-11T10:07:13.896977+08:00|info|kernel[-]|[1270984.058117get smi ioctl from qemu
2016-08-11T10:07:13.897063+08:00|info|kernel[-]|[1270984.058121in process_smi_request
2016-08-11T10:07:13.897091+08:00|info|kernel[-]|[1270984.058123is_smm:1

So, it seems kvm cannot set HF_SMM_MASK flag correctly when we continuously reset VM.
Any futher suggestion? Paolo :)
> Paolo

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [Qemu-devel] [QUESTION]stuck in SeaBIOS and vm cannot be reset any more
  2016-08-11  2:13 [Qemu-devel] [QUESTION]stuck in SeaBIOS and vm cannot be reset any more Xulei (Stone)
@ 2016-08-11 13:37 ` Paolo Bonzini
  0 siblings, 0 replies; 5+ messages in thread
From: Paolo Bonzini @ 2016-08-11 13:37 UTC (permalink / raw)
  To: Xulei (Stone), Kevin O'Connor, Paolo Bonzini; +Cc: seabios, qemu-devel



On 11/08/2016 04:13, Xulei (Stone) wrote:
> Following your suggestion, I found this problem may be caused by the flag of 
> HF_SMM_MASK. I'm now sure QEMU is sending the KVM_SMI ioctl, and 
> kmod already handles this ioctl.
> 
> I add printk in inject_pending_event(), like this:
> 
> /* try to inject new event if pending */
> +  if(get_smi)
> +    printk(KERN_INFO "is_smm:%d\n", is_smm(vcpu));
> +
>    if (vcpu->arch.smi_pending && !is_smm(vcpu)) {
>            vcpu->arch.smi_pending = false;
>            process_smi(vcpu);
>    }
> 
> Then I found that the normal output is (is_smm is 0):
> 2016-08-11T09:44:45.090078+08:00|info|kernel[-]|[1269634.151054get smi ioctl from qemu
> 2016-08-11T09:44:45.090097+08:00|info|kernel[-]|[1269634.151056in process_smi_request
> 2016-08-11T09:44:45.090114+08:00|info|kernel[-]|[1269634.151057is_smm:0
> 2016-08-11T09:44:45.090131+08:00|info|kernel[-]|[1269634.151058process smi
> 2016-08-11T09:44:45.090914+08:00|info|kernel[-]|[1269634.151575get smi ioctl from qemu
> 2016-08-11T09:44:45.090947+08:00|info|kernel[-]|[1269634.151578in process_smi_request
> 2016-08-11T09:44:45.090972+08:00|info|kernel[-]|[1269634.151579is_smm:0
> 
> When problem occurs the output is (is_smm is 1):
> 2016-08-11T10:07:11.755982+08:00|info|kernel[-]|[1270981.916056get smi ioctl from qemu
> 2016-08-11T10:07:11.756035+08:00|info|kernel[-]|[1270981.916062in process_smi_request
> 2016-08-11T10:07:11.756078+08:00|info|kernel[-]|[1270981.916064is_smm:1
> 2016-08-11T10:07:13.896977+08:00|info|kernel[-]|[1270984.058117get smi ioctl from qemu
> 2016-08-11T10:07:13.897063+08:00|info|kernel[-]|[1270984.058121in process_smi_request
> 2016-08-11T10:07:13.897091+08:00|info|kernel[-]|[1270984.058123is_smm:1
> 
> So, it seems kvm cannot set HF_SMM_MASK flag correctly when we continuously reset VM.
> Any futher suggestion? Paolo :)

I guess a KVM_SET_VCPU_EVENTS is missing at reset time.

Paolo

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [Qemu-devel] [QUESTION]stuck in SeaBIOS and vm cannot be reset any more
@ 2016-08-12  1:07 Xulei (Stone)
  0 siblings, 0 replies; 5+ messages in thread
From: Xulei (Stone) @ 2016-08-12  1:07 UTC (permalink / raw)
  To: Paolo Bonzini, Kevin O'Connor, Paolo Bonzini; +Cc: seabios, qemu-devel, kvm

> On 11/08/2016 04:13, Xulei (Stone) wrote:
> > Following your suggestion, I found this problem may be caused by the
> > flag of HF_SMM_MASK. I'm now sure QEMU is sending the KVM_SMI ioctl,
> > and kmod already handles this ioctl.
> >
> > I add printk in inject_pending_event(), like this:
> >
> > /* try to inject new event if pending */
> > +  if(get_smi)
> > +    printk(KERN_INFO "is_smm:%d\n", is_smm(vcpu));
> > +
> >    if (vcpu->arch.smi_pending && !is_smm(vcpu)) {
> >            vcpu->arch.smi_pending = false;
> >            process_smi(vcpu);
> >    }
> >
> > Then I found that the normal output is (is_smm is 0):
> > 2016-08-11T09:44:45.090078+08:00|info|kernel[-]|[1269634.151054get smi
> > ioctl from qemu
> > 2016-08-11T09:44:45.090097+08:00|info|kernel[-]|[1269634.151056in
> > process_smi_request
> > 2016-08-11T09:44:45.090114+08:00|info|kernel[-]|[1269634.151057is_smm:
> > 0
> > 2016-08-11T09:44:45.090131+08:00|info|kernel[-]|[1269634.151058process
> > smi 2016-08-11T09:44:45.090914+08:00|info|kernel[-]|[1269634.151575get
> > smi ioctl from qemu
> > 2016-08-11T09:44:45.090947+08:00|info|kernel[-]|[1269634.151578in
> > process_smi_request
> > 2016-08-11T09:44:45.090972+08:00|info|kernel[-]|[1269634.151579is_smm:
> > 0
> >
> > When problem occurs the output is (is_smm is 1):
> > 2016-08-11T10:07:11.755982+08:00|info|kernel[-]|[1270981.916056get smi
> > ioctl from qemu
> > 2016-08-11T10:07:11.756035+08:00|info|kernel[-]|[1270981.916062in
> > process_smi_request
> > 2016-08-11T10:07:11.756078+08:00|info|kernel[-]|[1270981.916064is_smm:
> > 1 2016-08-11T10:07:13.896977+08:00|info|kernel[-]|[1270984.058117get
> > smi ioctl from qemu
> > 2016-08-11T10:07:13.897063+08:00|info|kernel[-]|[1270984.058121in
> > process_smi_request
> > 2016-08-11T10:07:13.897091+08:00|info|kernel[-]|[1270984.058123is_smm:
> > 1
> >
> > So, it seems kvm cannot set HF_SMM_MASK flag correctly when we
> continuously reset VM.
> > Any futher suggestion? Paolo :)
> 
> I guess a KVM_SET_VCPU_EVENTS is missing at reset time.

This maybe a kvm bug of SMM supporting feature: 
assuming kvm SMI injection process is interrupted at the point 
between process_smi() and bios executing RSM. Then bios runs from
the beginning again because of resetting and kvm keeps is_smm() =1.
When bios writes 0xb2 to raise a SMI, kvm thinks is_smm() = 1, and 
will not process this request, and also will not call kvm_vcpu_reset()
to clear HF_SMM_MASK flag any more. Bios will not executing RSM
because of it does not get this SMI injecting from kvm. This condition 
cannot break until we destroy this VM.

After testing 2 days, following patch can solve this problem, but obviously 
it is not a suitable solution:
static int kvm_vcpu_ioctl_smi(struct kvm_vcpu *vcpu)
{
+   if (is_smm(vcpu)) {
+   vcpu->arch.hflags &= ~HF_SMM_MASK;
+   vcpu->arch.smi_pending = 0;
+   }
	kvm_make_request(KVM_REQ_SMI, vcpu);

	return 0;
}

Paolo, could you post a suitable patch to solve this problem based on
the information I mentioned above?

> Paolo

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [Qemu-devel] [QUESTION]stuck in SeaBIOS and vm cannot be reset any more
  2016-08-09  8:04 Xulei (Stone)
@ 2016-08-09  8:08 ` Paolo Bonzini
  0 siblings, 0 replies; 5+ messages in thread
From: Paolo Bonzini @ 2016-08-09  8:08 UTC (permalink / raw)
  To: Xulei (Stone), Kevin O'Connor, Paolo Bonzini; +Cc: seabios, qemu-devel



On 09/08/2016 10:04, Xulei (Stone) wrote:
> Following your suggestion, i'm now sure it is caused by missing SMI.
> I have tried adding dprintf() like this:
> 
> --- a/roms/seabios/src/fw/smm.c
> +++ b/roms/seabios/src/fw/smm.c
> @@ -65,7 +65,8 @@ handle_smi(u16 cs)
>      u8 cmd = inb(PORT_SMI_CMD);
>      struct smm_layout *smm = MAKE_FLATPTR(cs, 0);
>      u32 rev = smm->cpu.i32.smm_rev & SMM_REV_MASK;
> -    dprintf(DEBUG_HDL_smi, "handle_smi cmd=%x smbase=%p\n", cmd, smm);
> +    if(cmd == 0x00) {
> +    	dprintf(1, "handle_smi cmd=%x smbase=%p\n", cmd, smm);
> +    }
> 
>      if (smm == (void*)BUILD_SMM_INIT_ADDR) {
>          // relocate SMBASE to 0xa0000
> @@ -147,14 +148,14 @@ smm_relocate_and_restore(void)  {
>      /* init APM status port */
>      outb(0x01, PORT_SMI_STATUS);
> +   dprintf(1,"before SMI====\n");
> 
>      /* raise an SMI interrupt */
>      outb(0x00, PORT_SMI_CMD);
> +    dprintf(1,"after SMI=====\n");
> 
>      /* wait until SMM code executed */
>      while (inb(PORT_SMI_STATUS) != 0x00)
>          ;
> +   dprintf(1,"smm code executes complete====\n");
> 
> And the failed case log output like this:
> 2016-08-03 16:23:15PCI: Using 00:02.0 for primary VGA
> 2016-08-03 16:23:15smm_device_setup start
> 2016-08-03 16:23:15init smm
> 2016-08-03 16:23:15before SMI====
> 2016-08-03 16:23:15after SMI=====
> 
> So, it's obviously that after outb(0x01, PORT_SMI_STATUS), bios does not
> handle_smi, so PORT_SMI_STATUS is always 0x01. What's more, when this
> problem happens, rebooting vm cannot restore it any more. My vm is always 
> stuck at the same place until i destroy it.
> 
> And I have already tried kernel commit c43203cab1e which still can not 
> solve this problem.
> Any idea, Kevin and Paolo?

0xb2 is handled within QEMU, so it may be useful to make sure that QEMU
is sending the KVM_SMI ioctl.  From there the best tool is still KVM
tracing and printk.  I suggest replacing the dprintf with a simple outb
like outb(0x21, 0x402) (before) and outb(0x23, 0x402) (after).  They
show as "!" and "#" in the trace, and they are easy to spot in the KVM
trace.

Paolo

^ permalink raw reply	[flat|nested] 5+ messages in thread

* Re: [Qemu-devel] [QUESTION]stuck in SeaBIOS and vm cannot be reset any more
@ 2016-08-09  8:04 Xulei (Stone)
  2016-08-09  8:08 ` Paolo Bonzini
  0 siblings, 1 reply; 5+ messages in thread
From: Xulei (Stone) @ 2016-08-09  8:04 UTC (permalink / raw)
  To: Kevin O'Connor, Paolo Bonzini; +Cc: seabios, qemu-devel

>On Tue, Aug 02, 2016 at 04:18:30AM +0000, Xulei (Stone) wrote:
>> >On Fri, Jul 29, 2016 at 04:04:59AM +0000, Xulei (Stone) wrote:
>> >> After one day, the vm is stuck. Looking from the following seabios
>> >> log, it seems seabios stops at "PCI: Using 00:02.0 for primary
>> >> VGA", and can not execute handle_smp() any more.
>> >> What may be the reason?
>> >
>> >More debugging info would be necessary to find this problem.  You
>> >could try reproducing and attaching gdb (
>> >http://www.seabios.org/Debugging#Debugging_with_gdb_on_QEMU ).
>> >Alternatively, a kvm trace log may help.
>> >
>> kvm trace (seems useful) indicates that cpu 0 keeps always to access
0x00b3 ioport.
>> 0x00b3 is PORT_SMI_STATUS, so i guess my bios is stuck in the
>> function smm_relocate_and_restore {
>>       ...
>>       /* wait until SMM code executed */
>>     while (inb(PORT_SMI_STATUS) != 0x00)
>>       ...
>> }
>
>I'd try adding dprintf() statements around all the code at the top of
>smm_relocate_and_restore() and enable the dprintf() at the top of
>handle_smi().
>
>It would also be useful if you can extract the log from the last two
>working reboots to compare it to the failed case.

Following your suggestion, i'm now sure it is caused by missing SMI.
I have tried adding dprintf() like this:

--- a/roms/seabios/src/fw/smm.c
+++ b/roms/seabios/src/fw/smm.c
@@ -65,7 +65,8 @@ handle_smi(u16 cs)
     u8 cmd = inb(PORT_SMI_CMD);
     struct smm_layout *smm = MAKE_FLATPTR(cs, 0);
     u32 rev = smm->cpu.i32.smm_rev & SMM_REV_MASK;
-    dprintf(DEBUG_HDL_smi, "handle_smi cmd=%x smbase=%p\n", cmd, smm);
+    if(cmd == 0x00) {
+    	dprintf(1, "handle_smi cmd=%x smbase=%p\n", cmd, smm);
+    }

     if (smm == (void*)BUILD_SMM_INIT_ADDR) {
         // relocate SMBASE to 0xa0000
@@ -147,14 +148,14 @@ smm_relocate_and_restore(void)  {
     /* init APM status port */
     outb(0x01, PORT_SMI_STATUS);
+   dprintf(1,"before SMI====\n");

     /* raise an SMI interrupt */
     outb(0x00, PORT_SMI_CMD);
+    dprintf(1,"after SMI=====\n");

     /* wait until SMM code executed */
     while (inb(PORT_SMI_STATUS) != 0x00)
         ;
+   dprintf(1,"smm code executes complete====\n");

And the failed case log output like this:
2016-08-03 16:23:15PCI: Using 00:02.0 for primary VGA
2016-08-03 16:23:15smm_device_setup start
2016-08-03 16:23:15init smm
2016-08-03 16:23:15before SMI====
2016-08-03 16:23:15after SMI=====

So, it's obviously that after outb(0x01, PORT_SMI_STATUS), bios does not
handle_smi, so PORT_SMI_STATUS is always 0x01. What's more, when this
problem happens, rebooting vm cannot restore it any more. My vm is always 
stuck at the same place until i destroy it.

And I have already tried kernel commit c43203cab1e which still can not 
solve this problem.
Any idea, Kevin and Paolo?
> >
> >-Kevin

^ permalink raw reply	[flat|nested] 5+ messages in thread

end of thread, other threads:[~2016-08-12  1:07 UTC | newest]

Thread overview: 5+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2016-08-11  2:13 [Qemu-devel] [QUESTION]stuck in SeaBIOS and vm cannot be reset any more Xulei (Stone)
2016-08-11 13:37 ` Paolo Bonzini
  -- strict thread matches above, loose matches on Subject: below --
2016-08-12  1:07 Xulei (Stone)
2016-08-09  8:04 Xulei (Stone)
2016-08-09  8:08 ` Paolo Bonzini

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.