Re: [PATCH v5 untested] kvm: better MWAIT emulation for guests

[Gabriel L. Somlo]

On Fri, Mar 17, 2017 at 04:03:59AM +0200, Michael S. Tsirkin wrote:
> On Thu, Mar 16, 2017 at 05:14:15PM -0400, Gabriel L. Somlo wrote:
> > On Thu, Mar 16, 2017 at 04:17:11PM -0400, Gabriel L. Somlo wrote:
> > > On Thu, Mar 16, 2017 at 09:27:56PM +0200, Michael S. Tsirkin wrote:
> > > > On Thu, Mar 16, 2017 at 03:24:41PM -0400, Gabriel L. Somlo wrote:
> > > > > On Thu, Mar 16, 2017 at 08:29:32PM +0200, Michael S. Tsirkin wrote:
> > > > > > Let's take a step back and try to figure out how is
> > > > > > mwait called. How about dumping code of VCPUs
> > > > > > around mwait?  gdb disa command will do this.
> > > > > 
> > > > > Started guest with '-s', tried to attach from gdb with
> > > > > "target remote localhost:1234", got
> > > > > "remote 'g' packet reply is too long: <lengthy string of numbers>"
> > > > 
> > > > Try
> > > > 
> > > > set arch x86-64:x86-64
> > > 
> > > 'set architecture i386:x86-64:intel' is what worked for me;
> > > 
> > > Been rooting around for a while, can't find mwait or monitor :(
> > > 
> > > Guess I'll have to recompile KVM to actually issue an invalid opcode,
> > > so OS X will print a panic message with the exact address :)
> > > 
> > > Stay tuned...
> > 
> > OK, so I found a few instances. The one closest to where a random
> > interrupt from gdb landed, was this one:
> > 
> > ...
> >    0xffffff7f813ff379:  mov    0x90(%r15),%rax
> >    0xffffff7f813ff380:  mov    0x18(%rax),%rsi
> >    0xffffff7f813ff384:  xor    %ecx,%ecx
> >    0xffffff7f813ff386:  mov    %rsi,%rax
> >    0xffffff7f813ff389:  xor    %edx,%edx
> >    0xffffff7f813ff38b:  monitor %rax,%rcx,%rdx
> >    0xffffff7f813ff38e:  test   %r14,%r14
> >    0xffffff7f813ff391:  je     0xffffff7f813ff3ad
> >    0xffffff7f813ff393:  movq   $0x0,0x8(%r14)
> >    0xffffff7f813ff39b:  movl   $0x0,(%r14)
> >    0xffffff7f813ff3a2:  test   %ebx,%ebx
> >    0xffffff7f813ff3a4:  je     0xffffff7f813ff3b2
> >    0xffffff7f813ff3a6:  mfence 
> >    0xffffff7f813ff3a9:  wbinvd
> >    0xffffff7f813ff3ab:  jmp    0xffffff7f813ff3b2
> >    0xffffff7f813ff3ad:  cmpl   $0x0,(%rsi)
> 
> Seems to do cmpl - could indicate it uses different bytes
> for signalling? Radim's test monitors and
> modifies the same byte...
> 
> >    0xffffff7f813ff3b0:  jne    0xffffff7f813ff3d6
> >    0xffffff7f813ff3b2:  mov    %r12d,%eax
> >    0xffffff7f813ff3b5:  imul   $0x148,%rax,%rax
> >    0xffffff7f813ff3bc:  lea    0x153bd(%rip),%rcx        # 0xffffff7f81414780
> >    0xffffff7f813ff3c3:  mov    (%rcx),%rcx 
> >    0xffffff7f813ff3c6:  mov    0x20(%rcx),%rcx
> >    0xffffff7f813ff3ca:  mov    0xc(%rcx,%rax,1),%eax
> >    0xffffff7f813ff3ce:  mov    $0x1,%ecx
> >    0xffffff7f813ff3d3:  mwait  %rax,%rcx
> > => 0xffffff7f813ff3d6:  lfence
> >    0xffffff7f813ff3d9:  rdtsc  
> >    0xffffff7f813ff3db:  lfence 
> >    0xffffff7f813ff3de:  mov    %rax,%rbx
> >    0xffffff7f813ff3e1:  mov    %rdx,%r15
> > ...
> 
> OK nice, so it's actually using 1 for ECX. Now what's rax?
> Can you check that with gdb pls, then try that value with
> Radim's test?

Thread 1 received signal SIGINT, Interrupt.
0xffffff80002c8991 in ?? ()
(gdb) break *0xffffff7f813ff3ce
Breakpoint 1 at 0xffffff7f813ff3ce
(gdb) continue
Continuing.

Thread 3 hit Breakpoint 1, 0xffffff7f813ff3ce in ?? ()
(gdb) p $rax
$1 = 240
(gdb) cont
Continuing.
[Switching to Thread 1]

Thread 1 hit Breakpoint 1, 0xffffff7f813ff3ce in ?? ()
(gdb) p $rax
$2 = 240
(gdb) cont
Continuing.
[Switching to Thread 4]

Thread 4 hit Breakpoint 1, 0xffffff7f813ff3ce in ?? ()
(gdb) p $rax
$3 = 240
(gdb) cont 
Continuing.

Thread 4 hit Breakpoint 1, 0xffffff7f813ff3ce in ?? ()
(gdb) p $rax
$4 = 240
(gdb) 

So, 240 or 0xf0

OK, now on to Radim's test, on the MacPro1,1:

[kvm-unit-tests]$ time TIMEOUT=20 ./x86-run x86/mwait.flat -append '240 1 1'
timeout -k 1s --foreground 20 qemu-kvm -nodefaults -enable-kvm -device pc-testdev -device isa-debug-exit,iobase=0xf4,iosize=0x4 -vnc none -serial stdio -device pci-testdev -kernel x86/mwait.flat -append 240 1 1
enabling apic
PASS: resumed from mwait 10000 times
SUMMARY: 1 tests

real    0m0.746s
user    0m0.542s
sys     0m0.215s
[kvm-unit-tests]$ time TIMEOUT=20 ./x86-run x86/mwait.flat -append '240 1 0'
timeout -k 1s --foreground 20 qemu-kvm -nodefaults -enable-kvm -device pc-testdev -device isa-debug-exit,iobase=0xf4,iosize=0x4 -vnc none -serial stdio -device pci-testdev -kernel x86/mwait.flat -append 240 1 0
enabling apic
PASS: resumed from mwait 10000 times
SUMMARY: 1 tests

real    0m0.743s
user    0m0.528s
sys     0m0.226s
[kvm-unit-tests]$ time TIMEOUT=20 ./x86-run x86/mwait.flat -append '240 1 1' -smp 2
timeout -k 1s --foreground 20 qemu-kvm -nodefaults -enable-kvm -device pc-testdev -device isa-debug-exit,iobase=0xf4,iosize=0x4 -vnc none -serial stdio -device pci-testdev -kernel x86/mwait.flat -append 240 1 1 -smp 2
enabling apic
enabling apic
FAIL: resumed from mwait 10150 times
SUMMARY: 1 tests, 1 unexpected failures

real    0m0.745s
user    0m0.545s
sys     0m0.214s
[kvm-unit-tests]$ time TIMEOUT=20 ./x86-run x86/mwait.flat -append '240 1 0' -smp 2
timeout -k 1s --foreground 20 qemu-kvm -nodefaults -enable-kvm -device pc-testdev -device isa-debug-exit,iobase=0xf4,iosize=0x4 -vnc none -serial stdio -device pci-testdev -kernel x86/mwait.flat -append 240 1 0 -smp 2
enabling apic
enabling apic
FAIL: resumed from mwait 10116 times
SUMMARY: 1 tests, 1 unexpected failures

real    0m0.744s
user    0m0.541s
sys     0m0.217s

HTH,
--Gabriel