Re: High vm-exit latencies during kvm boot-up/shutdown

[Jan Kiszka <jan.kiszka-kv7WeFo6aLtBDgjK7y7TUQ@public.gmane.org>]

Avi Kivity wrote:
> Jan Kiszka wrote:
>> Avi Kivity wrote:
>>> Please post a disassembly of your vmx_vcpu_run so we can interpret the
>>> offsets.
>>>     
>> Here it comes:
>>
>> 00002df0 <vmx_vcpu_run>:
>>     2df0:       55                      push   %ebp
>>     2df1:       89 e5                   mov    %esp,%ebp
>>     2df3:       53                      push   %ebx
>>     2df4:       83 ec 08                sub    $0x8,%esp
>>     2df7:       e8 fc ff ff ff          call   2df8 <vmx_vcpu_run+0x8>
>>     2dfc:       8b 5d 08                mov    0x8(%ebp),%ebx
>>     2dff:       0f 20 c0                mov    %cr0,%eax
>>     2e02:       89 44 24 04             mov    %eax,0x4(%esp)
>>     2e06:       c7 04 24 00 6c 00 00    movl   $0x6c00,(%esp)
>>     2e0d:       e8 be d8 ff ff          call   6d0 <vmcs_writel>
>>   
> 
> first trace
> 
> 
>>     2e12:       8b 83 80 0d 00 00       mov    0xd80(%ebx),%eax
>>     2e18:       ba 14 6c 00 00          mov    $0x6c14,%edx
>>     2e1d:       89 d9                   mov    %ebx,%ecx
>>     2e1f:       60                      pusha
>>     2e20:       51                      push   %ecx
>>     2e21:       0f 79 d4                vmwrite %esp,%edx
>>     2e24:       83 f8 00                cmp    $0x0,%eax
>>     2e27:       8b 81 78 01 00 00       mov    0x178(%ecx),%eax
>>     2e2d:       0f 22 d0                mov    %eax,%cr2
>>     2e30:       8b 81 50 01 00 00       mov    0x150(%ecx),%eax
>>     2e36:       8b 99 5c 01 00 00       mov    0x15c(%ecx),%ebx
>>     2e3c:       8b 91 58 01 00 00       mov    0x158(%ecx),%edx
>>     2e42:       8b b1 68 01 00 00       mov    0x168(%ecx),%esi
>>     2e48:       8b b9 6c 01 00 00       mov    0x16c(%ecx),%edi
>>     2e4e:       8b a9 64 01 00 00       mov    0x164(%ecx),%ebp
>>     2e54:       8b 89 54 01 00 00       mov    0x154(%ecx),%ecx
>>     2e5a:       75 05                   jne    2e61 <vmx_vcpu_run+0x71>
>>     2e5c:       0f 01 c2                vmlaunch
>>     2e5f:       eb 03                   jmp    2e64 <vmx_vcpu_run+0x74>
>>     2e61:       0f 01 c3                vmresume
>>     2e64:       87 0c 24                xchg   %ecx,(%esp)
>>     2e67:       89 81 50 01 00 00       mov    %eax,0x150(%ecx)
>>     2e6d:       89 99 5c 01 00 00       mov    %ebx,0x15c(%ecx)
>>     2e73:       ff 34 24                pushl  (%esp)
>>     2e76:       8f 81 54 01 00 00       popl   0x154(%ecx)
>>     2e7c:       89 91 58 01 00 00       mov    %edx,0x158(%ecx)
>>     2e82:       89 b1 68 01 00 00       mov    %esi,0x168(%ecx)
>>     2e88:       89 b9 6c 01 00 00       mov    %edi,0x16c(%ecx)
>>     2e8e:       89 a9 64 01 00 00       mov    %ebp,0x164(%ecx)
>>     2e94:       0f 20 d0                mov    %cr2,%eax
>>     2e97:       89 81 78 01 00 00       mov    %eax,0x178(%ecx)
>>     2e9d:       8b 0c 24                mov    (%esp),%ecx
>>     2ea0:       59                      pop    %ecx
>>     2ea1:       61                      popa
>>     2ea2:       0f 96 c0                setbe  %al
>>     2ea5:       88 83 84 0d 00 00       mov    %al,0xd84(%ebx)
>>     2eab:       c7 04 24 24 48 00 00    movl   $0x4824,(%esp)
>>     2eb2:       e8 49 d2 ff ff          call   100 <vmcs_read32>
>>   
> 
> second trace
> 
>>     2eb7:       a8 03                   test   $0x3,%al
>>     2eb9:       0f 94 c0                sete   %al
>>     2ebc:       0f b6 c0                movzbl %al,%eax
>>     2ebf:       89 83 28 01 00 00       mov    %eax,0x128(%ebx)
>>     2ec5:       b8 7b 00 00 00          mov    $0x7b,%eax
>>     2eca:       8e d8                   mov    %eax,%ds
>>     2ecc:       8e c0                   mov    %eax,%es
>>     2ece:       c7 83 80 0d 00 00 01    movl   $0x1,0xd80(%ebx)
>>     2ed5:       00 00 00
>>     2ed8:       c7 04 24 04 44 00 00    movl   $0x4404,(%esp)
>>     2edf:       e8 1c d2 ff ff          call   100 <vmcs_read32>
>>     2ee4:       25 00 07 00 00          and    $0x700,%eax
>>     2ee9:       3d 00 02 00 00          cmp    $0x200,%eax
>>     2eee:       75 02                   jne    2ef2 <vmx_vcpu_run+0x102>
>>     2ef0:       cd 02                   int    $0x2
>>     2ef2:       83 c4 08                add    $0x8,%esp
>>     2ef5:       5b                      pop    %ebx
>>     2ef6:       5d                      pop    %ebp
>>     2ef7:       c3                      ret
>>     2ef8:       90                      nop
>>     2ef9:       8d b4 26 00 00 00 00    lea    0x0(%esi),%esi
>>
>> Note that the first, unresolved call here goes to mcount().
>>
>>   
> 
> (the -r option to objdump is handy)

Great, one never stops learning. :)

> 
> Exiting on a pending interrupt is controlled by the vmcs word
> PIN_BASED_EXEC_CONTROL, bit PIN_BASED_EXT_INTR_MASK.  Can you check (via
> vmcs_read32()) that the bit is indeed set?
> 
> [if not, a guest can just enter a busy loop and kill a processor]
> 

I traced it right before and after the asm block, and in all cases
(including those with low latency exits) it's just 0x1f, which should be
fine.

Earlier, I also checked GUEST_INTERRUPTIBILITY_INFO and
GUEST_ACTIVITY_STATE, but found neither some suspicious state nor a
difference compared to fast exits.

Jan

-- 
Siemens AG, Corporate Technology, CT SE 2
Corporate Competence Center Embedded Linux

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >> http://get.splunk.com/