Re: Calculate the frequency of the tsc timecounter

Hi Mike

Please see the output below (I did have to update a few DPRINTF's with
the change to clang, did you want a diff for checking in?)
I appreciate you having a look.

Cheers
Adam

root on sd0a (15cc7df693e2251e.a) swap on sd0b dump on sd0b
vm_impl_init_vmx: created vm_map @ 0xffff800000b99000
vm_resetcpu: resetting vm 1 vcpu 0 to power on defaults
guest eptp = 0x39eb8f01e
vmm_alloc_vpid: allocated VPID/ASID 1
vmx_handle_exit: unhandled exit 2147483681 (unknown)
vcpu @ 0xffff800032ffc000
rax=0x0000000000000000 rbx=0x0000000000000000 rcx=0x0000000000000000
rdx=0x0000000000000000 rbp=0x0000000000000000 rdi=0x0000000000005000
rsi=0x0000000000000000 r8=0x0000000000000000 r9=0x0000000000000000
r10=0x0000000000000000 r11=0x0000000000000000 r12=0x0000000000000000
r13=0x0000000000000000 r14=0x0000000000000000 r15=0x0000000000000000
rip=0x0000000000100000 rsp=0x000000001ffffff8
cr0=0x0000000000000020 (pg cd nw am wp NE et ts em mp pe)
cr2=0x0000000000000000
cr3=0x0000000000000000 (pwt pcd)
cr4=0x0000000000002000 (pke smap smep osxsave pcide fsgsbase smxe
VMXE osxmmexcpt osfxsr pce pge mce pae pse de tsd pvi vme)
--Guest Segment Info--
cs=0x0008 rpl=0 base=0x0000000000000000 limit=0x00000000ffffffff a/r=0xa099
granularity=1 dib=0 l(64 bit)=1 present=1 sys=1 type=code, x only, accessed
code, r/x
ds=0x0010 rpl=0 base=0x0000000000000000 limit=0x00000000ffffffff a/r=0xc093
granularity=1 dib=1 l(64 bit)=0 present=1 sys=1 type=data, r/w, accessed
es=0x0010 rpl=0 base=0x0000000000000000 limit=0x00000000ffffffff a/r=0xc093
granularity=1 dib=1 l(64 bit)=0 present=1 sys=1 type=data, r/w, accessed
fs=0x0010 rpl=0 base=0x0000000000000000 limit=0x00000000ffffffff a/r=0xc093
granularity=1 dib=1 l(64 bit)=0 present=1 sys=1 type=data, r/w, accessed
gs=0x0010 rpl=0 base=0x0000000000000000 limit=0x00000000ffffffff a/r=0xc093
granularity=1 dib=1 l(64 bit)=0 present=1 sys=1 type=data, r/w, accessed
ss=0x0010 rpl=0 base=0x0000000000000000 limit=0x00000000ffffffff a/r=0xc093
granularity=1 dib=1 l(64 bit)=0 present=1 sys=1 type=data, r/w, accessed
tr=0x0000 base=0x0000000000000000 limit=0x0000000000000000 a/r=0x008b
granularity=0 dib=0 l(64 bit)=0 present=1 sys=0 type=tss (busy)
gdtr base=0x0000000000001000 limit=0x0000000000000017
idtr base=0x0000000000000000 limit=0x000000000000ffff
ldtr=0x0000 base=0x0000000000000000 limit=0x0000000000000000 a/r=0x10000
(unusable)
--Guest MSRs @ 0xffffff039b869000 (paddr: 0x000000039b869000)--
MSR 0 @ 0xffffff039b869000 : 0xc0000080 (EFER),
value=0x0000000000000500 (sce LME LMA nxe)
MSR 1 @ 0xffffff039b869010 : 0xc0000081 (STAR), value=0x0000000000000000
MSR 2 @ 0xffffff039b869020 : 0xc0000082 (LSTAR), value=0x0000000000000000
MSR 3 @ 0xffffff039b869030 : 0xc0000083 (CSTAR), value=0x0000000000000000
MSR 4 @ 0xffffff039b869040 : 0xc0000084 (SFMASK), value=0x0000000000000000
MSR 5 @ 0xffffff039b869050 : 0xc0000102 (KGSBASE), value=0x0000000000000000
vcpu @ 0xffff800032ffc000
parent vm @ 0xffffff0395ee7000
mode: VMX
pinbased ctls: 0x7f00000016
true pinbased ctls: 0x7f00000016
EXTERNAL_INT_EXITING: Can set:Yes Can clear:Yes
NMI_EXITING: Can set:Yes Can clear:Yes
VIRTUAL_NMIS: Can set:Yes Can clear:Yes
ACTIVATE_VMX_PREEMPTION_TIMER: Can set:Yes Can clear:Yes
PROCESS_POSTED_INTERRUPTS: Can set:No Can clear:Yes
procbased ctls: 0xfff9fffe0401e172
true procbased ctls: 0xfff9fffe04006172
INTERRUPT_WINDOW_EXITING: Can set:Yes Can clear:Yes
USE_TSC_OFFSETTING: Can set:Yes Can clear:Yes
HLT_EXITING: Can set:Yes Can clear:Yes
INVLPG_EXITING: Can set:Yes Can clear:Yes
MWAIT_EXITING: Can set:Yes Can clear:Yes
RDPMC_EXITING: Can set:Yes Can clear:Yes
RDTSC_EXITING: Can set:Yes Can clear:Yes
CR3_LOAD_EXITING: Can set:Yes Can clear:Yes
CR3_STORE_EXITING: Can set:Yes Can clear:Yes
CR8_LOAD_EXITING: Can set:Yes Can clear:Yes
CR8_STORE_EXITING: Can set:Yes Can clear:Yes
USE_TPR_SHADOW: Can set:Yes Can clear:Yes
NMI_WINDOW_EXITING: Can set:Yes Can clear:Yes
MOV_DR_EXITING: Can set:Yes Can clear:Yes
UNCONDITIONAL_IO_EXITING: Can set:Yes Can clear:Yes
USE_IO_BITMAPS: Can set:Yes Can clear:Yes
MONITOR_TRAP_FLAG: Can set:Yes Can clear:Yes
USE_MSR_BITMAPS: Can set:Yes Can clear:Yes
MONITOR_EXITING: Can set:Yes Can clear:Yes
PAUSE_EXITING: Can set:Yes Can clear:Yes
procbased2 ctls: 0xff00000000
VIRTUALIZE_APIC: Can set:Yes Can clear:Yes
ENABLE_EPT: Can set:Yes Can clear:Yes
DESCRIPTOR_TABLE_EXITING: Can set:Yes Can clear:Yes
ENABLE_RDTSCP: Can set:Yes Can clear:Yes
VIRTUALIZE_X2APIC_MODE: Can set:Yes Can clear:Yes
ENABLE_VPID: Can set:Yes Can clear:Yes
WBINVD_EXITING: Can set:Yes Can clear:Yes
UNRESTRICTED_GUEST: Can set:Yes Can clear:Yes
APIC_REGISTER_VIRTUALIZATION: Can set:No Can clear:Yes
VIRTUAL_INTERRUPT_DELIVERY: Can set:No Can clear:Yes
PAUSE_LOOP_EXITING: Can set:No Can clear:Yes
RDRAND_EXITING: Can set:No Can clear:Yes
ENABLE_INVPCID: Can set:No Can clear:Yes
ENABLE_VM_FUNCTIONS: Can set:No Can clear:Yes
VMCS_SHADOWING: Can set:No Can clear:Yes
ENABLE_ENCLS_EXITING: Can set:No Can clear:Yes
RDSEED_EXITING: Can set:No Can clear:Yes
ENABLE_PML: Can set:No Can clear:Yes
EPT_VIOLATION_VE: Can set:No Can clear:Yes
CONCEAL_VMX_FROM_PT: Can set:No Can clear:Yes
ENABLE_XSAVES_XRSTORS: Can set:No Can clear:Yes
ENABLE_TSC_SCALING: Can set:No Can clear:Yes
entry ctls: 0xffff000011ff
true entry ctls: 0xffff000011fb
LOAD_DEBUG_CONTROLS: Can set:Yes Can clear:Yes
IA32E_MODE_GUEST: Can set:Yes Can clear:Yes
ENTRY_TO_SMM: Can set:Yes Can clear:Yes
DEACTIVATE_DUAL_MONITOR_TREATMENT: Can set:Yes Can clear:Yes
LOAD_IA32_PERF_GLOBAL_CTRL_ON_ENTRY: Can set:Yes Can clear:Yes
LOAD_IA32_PAT_ON_ENTRY: Can set:Yes Can clear:Yes
LOAD_IA32_EFER_ON_ENTRY: Can set:Yes Can clear:Yes
LOAD_IA32_BNDCFGS_ON_ENTRY: Can set:No Can clear:Yes
CONCEAL_VM_ENTRIES_FROM_PT: Can set:No Can clear:Yes
exit ctls: 0x7fffff00036dff
true exit ctls: 0x7fffff00036dfb
SAVE_DEBUG_CONTROLS: Can set:Yes Can clear:Yes
HOST_SPACE_ADDRESS_SIZE: Can set:Yes Can clear:Yes
LOAD_IA32_PERF_GLOBAL_CTRL_ON_EXIT: Can set:Yes Can clear:Yes
ACKNOWLEDGE_INTERRUPT_ON_EXIT: Can set:Yes Can clear:Yes
SAVE_IA32_PAT_ON_EXIT: Can set:Yes Can clear:Yes
LOAD_IA32_PAT_ON_EXIT: Can set:Yes Can clear:Yes
SAVE_IA32_EFER_ON_EXIT: Can set:Yes Can clear:Yes
LOAD_IA32_EFER_ON_EXIT: Can set:Yes Can clear:Yes
SAVE_VMX_PREEMPTION_TIMER: Can set:Yes Can clear:Yes
CLEAR_IA32_BNDCFGS_ON_EXIT: Can set:No Can clear:Yes
CONCEAL_VM_EXITS_FROM_PT: Can set:No Can clear:Yes
--CURRENT VMCS STATE--
VMXON revision : 0x10
CR0 fixed0: 0x80000021
CR0 fixed1: 0xffffffff
CR4 fixed0: 0x2000
CR4 fixed1: 0x667ff
MSR table size: 0x200
VPID (0x0000): 0x0001
G.ES (0x0800): 0x0010 G.CS (0x0802): 0x0008 G.SS (0x0804): 0x0010
G.DS (0x0806): 0x0010 G.FS (0x0808): 0x0010 G.GS (0x080a): 0x0010
LDTR (0x080c): 0x0000 G.TR (0x080e): 0x0000
H.ES (0x0c00): 0x0010 H.CS (0x0c02): 0x0008 H.SS (0x0c04): 0x0010
H.DS (0x0c06): 0x0010 H.FS (0x0c08): 0x0010 H.GS (0x0c0a): 0x0010
I/O Bitmap A (0x2000): 0x0000000000000000
I/O Bitmap B (0x2002): 0x0000000000000000
MSR Bitmap (0x2004): 0x000000039aba4000
Exit Store MSRs (0x2006): 0x000000039b869000
Exit Load MSRs (0x2008): 0x000000039aba3000
Entry Load MSRs (0x200a): 0x000000039b869000
Exec VMCS Ptr (0x200c): 0x0000000000000000
TSC Offset (0x2010): 0x0000000000000000
Virtual APIC Addr (0x2012): 0x0000000000000000
APIC Access Addr (0x2014): 0x0000000000000000
EPT Pointer (0x201a): 0x000000039eb8f01e
Guest PA (0x2400): 0x0000000000000000
VMCS Link Pointer (0x2800): 0xffffffffffffffff
Guest DEBUGCTL (0x2802): 0x0000000000000000
Guest PAT (0x2804): 0x0000000000000000
Guest EFER (0x2806): 0x0000000000000000
Guest Perf Global Ctrl (0x2808): 0x0000000000000000
Guest PDPTE0 (0x280a): 0x0000000000000000
Guest PDPTE1 (0x280c): 0x0000000000000000
Guest PDPTE2 (0x280e): 0x0000000000000000
Guest PDPTE3 (0x2810): 0x0000000000000000
Host PAT (0x2c00): 0x0000000000000000
Host EFER (0x2c02): 0x0000000000000000
Host Perf Global Ctrl (0x2c04): 0x0000000000000000
Pinbased Ctrls (0x4000): 0x0000001f Procbased Ctrls (0x4002): 0x953865f2
Exception Bitmap (0x4004): 0x00000000 #PF Err Code Mask (0x4006): 0x00000000
#PF Err Code Match (0x4008): 0x00000000 CR3 Tgt Count (0x400a): 0x00000000
Exit Ctrls (0x400c): 0x0003efff Exit MSR Store Ct (0x400e): 0x00000006
Exit MSR Load Ct (0x4010): 0x00000006 Entry Ctrls (0x4012): 0x000013fb
Entry MSR Load Ct (0x4014): 0x00000006 Entry Int. Info (0x4016): 0x00000000
Entry Ex. Err Code (0x4018): 0x00000000 Entry Insn Len (0x401a): 0x00000000
TPR Threshold (0x401c): 0x00000000
2ndary Ctrls (0x401e): 0x000000a2

Insn Error (0x4400): 0x00000000 Exit Reason (0x4402): 0x80000021
Exit Int. Info (0x4404): 0x00000000 Exit Int. Err Code (0x4406): 0x00000000
IDT vect info (0x4408): 0x00000000 IDT vect err code (0x440a): 0x00000000
Insn Len (0x440c): 0x00000000 Exit Insn Info (0x440e): 0x00000000
G. ES Lim (0x4800): 0xffffffff G. CS Lim (0x4802): 0xffffffff
G. SS Lim (0x4804): 0xffffffff G. DS Lim (0x4806): 0xffffffff
G. FS Lim (0x4808): 0xffffffff G. GS Lim (0x480a): 0xffffffff
G. LDTR Lim (0x480c): 0x00000000 G. TR Lim (0x480e): 0x00000000
G. GDTR Lim (0x4810): 0x00000017 G. IDTR Lim (0x4812): 0x0000ffff
G. ES AR (0x4814): 0x0000c093 G. CS AR (0x4816): 0x0000a099
G. SS AR (0x4818): 0x0000c093 G. DS AR (0x481a): 0x0000c093
G. FS AR (0x481c): 0x0000c093 G. GS AR (0x481e): 0x0000c093
G. LDTR AR (0x4820): 0x00010000 G. TR AR (0x4822): 0x0000008b
G. Int St. (0x4824): 0x00000000 G. Act St. (0x4826): 0x00000000
G. SMBASE (0x4828): 0x00000000 G. SYSENTER CS (0x482a): 0x00000000
VMX Preempt Timer (0x482e): 0x00000000
H. SYSENTER CS (0x4c00): 0x00000000
CR0 Mask (0x6000): 0x0000000000000020
CR4 Mask (0x6002): 0x0000000000002000
CR0 RD Shadow (0x6004): 0x0000000000000000
CR4 RD Shadow (0x6006): 0x0000000000000000
Max CR3 target count: 0x4
CR3 Target (0x6008): 0x0000000000000000
CR3 Target (0x600a): 0x0000000000000000
CR3 Target (0x600c): 0x0000000000000000
CR3 Target (0x600e): 0x0000000000000000
G. Exit Qual (0x6400): 0x0000000000000000
I/O RCX (0x6402): 0x0000000000000000
I/O RSI (0x6404): 0x0000000000000000
I/O RDI (0x6406): 0x0000000000000000
I/O RIP (0x6408): 0x0000000000000000
G. Lin Addr (0x640a): 0x0000000000000000
G. CR0 (0x6800): 0x0000000000000020
G. CR3 (0x6802): 0x0000000000000000
G. CR4 (0x6804): 0x0000000000002000
G. ES Base (0x6806): 0x0000000000000000
G. CS Base (0x6808): 0x0000000000000000
G. SS Base (0x680a): 0x0000000000000000
G. DS Base (0x680c): 0x0000000000000000
G. FS Base (0x680e): 0x0000000000000000
G. GS Base (0x6810): 0x0000000000000000
G. LDTR Base (0x6812): 0x0000000000000000
G. TR Base (0x6814): 0x0000000000000000
G. GDTR Base (0x6816): 0x0000000000001000
G. IDTR Base (0x6818): 0x0000000000000000
G. DR7 (0x681a): 0x0000000000000000
G. RSP (0x681c): 0x000000001ffffff8
G. RIP (0x681e): 0x0000000000100000
G. RFLAGS (0x6820): 0x0000000000000002
G. Pend Dbg Exc (0x6822): 0x0000000000000000
G. SYSENTER ESP (0x6824): 0x0000000000000000
G. SYSENTER EIP (0x6826): 0x0000000000000000
H. CR0 (0x6c00): 0x0000000080010033
H. CR3 (0x6c02): 0x000000039eb96000
H. CR4 (0x6c04): 0x00000000000426b0
H. FS Base (0x6c06): 0x0000000000000000
H. GS Base (0x6c08): 0x0000000000000000
H. TR Base (0x6c0a): 0xffff800021ffc040
H. GDTR Base (0x6c0c): 0xffff800021ffc000
H. IDTR Base (0x6c0e): 0xffff800000010000
H. SYSENTER ESP (0x6c10): 0x0000000000000000
H. SYSENTER EIP (0x6c12): 0x0000000000000000
H. RSP (0x6c14): 0xffff800032ffba7e
H. RIP (0x6c16): 0xffffffff812813ad

On Tue, Aug 1, 2017 at 3:04 PM, Mike Larkin <mlarkin@azathoth.net> wrote:
> On Tue, Aug 01, 2017 at 07:32:19AM +0800, Adam Steen wrote:
>> On Tue, Aug 1, 2017 at 7:26 AM, Adam Steen <adam@adamsteen.com.au> wrote:
>> > Mike Belopuhov wrote:
>> >
>> >> To be able to use TSC as a timecounter source on OpenBSD or Solo5
>> >> you'd have to improve the in-kernel measurement of the TSC frequency
>> >> first. I've tried to perform 10 measurements and take an average and
>> >> it does improve accuracy, however I believe we need to poach another
>> >> bit from Linux and re-calibrate TSC via HPET:
>> >>
>> >> http://elixir.free-electrons.com/linux/v4.12.4/source/arch/x86/kernel/tsc.c#L409
>> >>
>> >> I think this is the most sane thing we can do. Here's a complete
>> >> procedure that Linux kernel undertakes:
>> >>
>> >> http://elixir.free-electrons.com/linux/v4.12.4/source/arch/x86/kernel/tsc.c#L751
>> >>
>> >> Regards,
>> >> Mike
>> >
>> > Looks like i have more sort out!
>> >
>> > Mike Larkin wrote:
>> >> If you point me to a bootable image that causes this failure, I might be
>> >> able to figure out what vmm(4) doesn't like.
>> >>
>> >> Nothing in lines 122-134 of the file indicated above should cause this.
>> >
>> > This is where things get a little more interesting, Solo5
>> > (https://github.com/adamsteen/solo5) is actually two parts Solo5 the
>> > Unikernel and ukvm the userland side of a hypervisor (currently
>> > running with kvm and bhyve), I have been porting to run ukvm directly
>> > with vmm. I expect the cause of "vmx_handle_exit: unhandled exit
>> > 2147483681 (unknown)" is the register setup in
>> > https://github.com/adamsteen/solo5/blob/master/ukvm/ukvm_hv_openbsd_x86_64.c,
>> > lines 118-147
>> >
>> > the constants are ukvm constants.
>> >
>> > struct vm_resetcpu_params vrp = {
>> > .vrp_vm_id = hvb->vcp_id,
>> > .vrp_vcpu_id = hvb->vcpu_id,
>> > .vrp_init_state = {
>> > .vrs_gprs[VCPU_REGS_RFLAGS] = X86_RFLAGS_INIT,
>> > .vrs_gprs[VCPU_REGS_RIP] = gpa_ep,
>> > .vrs_gprs[VCPU_REGS_RSP] = hv->mem_size - 8,
>> > .vrs_gprs[VCPU_REGS_RDI] = X86_BOOT_INFO_BASE,
>> > .vrs_crs[VCPU_REGS_CR0] = X86_CR0_INIT,
>> > .vrs_crs[VCPU_REGS_CR3] = X86_CR3_INIT,
>> > .vrs_crs[VCPU_REGS_CR4] = X86_CR4_INIT,
>> > .vrs_sregs[VCPU_REGS_CS] = sreg_to_vsi(&ukvm_x86_sreg_code),
>> > .vrs_sregs[VCPU_REGS_DS] = sreg_to_vsi(&ukvm_x86_sreg_data),
>> > .vrs_sregs[VCPU_REGS_ES] = sreg_to_vsi(&ukvm_x86_sreg_data),
>> > .vrs_sregs[VCPU_REGS_FS] = sreg_to_vsi(&ukvm_x86_sreg_data),
>> > .vrs_sregs[VCPU_REGS_GS] = sreg_to_vsi(&ukvm_x86_sreg_data),
>> > .vrs_sregs[VCPU_REGS_SS] = sreg_to_vsi(&ukvm_x86_sreg_data),
>> > .vrs_gdtr = { 0x0, X86_GDTR_LIMIT, 0x0, X86_GDT_BASE},
>> > .vrs_idtr = { 0x0, 0xFFFF, 0x0, 0x0},
>> > .vrs_sregs[VCPU_REGS_LDTR] = sreg_to_vsi(&ukvm_x86_sreg_unusable),
>> > .vrs_sregs[VCPU_REGS_TR] = sreg_to_vsi(&ukvm_x86_sreg_tr),
>> > .vrs_msrs[VCPU_REGS_EFER] = X86_EFER_INIT,
>> > .vrs_msrs[VCPU_REGS_STAR] = 0ULL,
>> > .vrs_msrs[VCPU_REGS_LSTAR] = 0ULL,
>> > .vrs_msrs[VCPU_REGS_CSTAR] = 0ULL,
>> > .vrs_msrs[VCPU_REGS_SFMASK] = 0ULL,
>> > .vrs_msrs[VCPU_REGS_KGSBASE] = 0ULL,
>> > .vrs_crs[VCPU_REGS_XCR0] = XCR0_X87
>> > }
>> > };
>> >
>> > the three specific OpenBSD files are
>> > https://github.com/adamsteen/solo5/blob/master/ukvm/ukvm_hv_openbsd.h
>> > https://github.com/adamsteen/solo5/blob/master/ukvm/ukvm_hv_openbsd.c
>> > https://github.com/adamsteen/solo5/blob/master/ukvm/ukvm_hv_openbsd_x86_64.c
>> > with small changes in ukvm/ukvm_elf.c and ukvm/ukvm_module_net.c
>> >
>> > I could upload a binary image for you but It won't run with vmd its
>> > has ukvm specific hypercalls designed to simplify things.
>> >
>> > Cheers
>> > Adam
>> >
>> > ps i am currently trying to document the differences in what vmm is
>> > expecting and ukvm is expecting.
>>
>
> I'd recommend enabling VMM_DEBUG and seeing if that prints more useful
> information after the unhandled exit. That error code is usually because of
> invalid VMCS content, but since you're rolling your own vmm interface, it's
> not clear what might have been missed. If you send me that information
> (from dmesg, it will be a lot) I may be able to help.
>
> -ml
>
>
>> One more thing
>>
>> Please note currently i have to build the bootable binary image of
>> solo5 with a cross compiler as i have not figured out the
>> discrepancies between OpenBSD's ld and solo5's linker script.
>>
>> Cheers
>> Adam