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

Gabriel L. Somlo
2017-03-17T13:23:56Z

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