目前想通过ftrace统计vmx出来次数，还有更好的统计工具使用。
目录
cd /sys/kernel/debug/tracing
查看与vmx相关的函数函数统计：
cat available_filter_functions | grep vmx_exit
不清楚具体原因，我这里抓不到vm_exit,所以就用下面的vmx_* 连带把所有的vmx都抓了。
具体操作：
trace-cmd record -l vmx_* -p function_graph
guest vmx记录：
heaven 跑 640*360 low 基于 vdi1.0 分支。
root@jet-dev:~# trace-cmd report | head -20
cpus=12
qemu-system-x86-1723 [006] 2246.741148: funcgraph_entry: 0.942 us | vmx_read_l1_tsc_offset();
qemu-system-x86-1723 [006] 2246.741149: funcgraph_entry: 0.178 us | vmx_handle_exit_irqoff();
qemu-system-x86-1723 [006] 2246.741150: funcgraph_entry: | vmx_handle_exit() {
qemu-system-x86-1723 [006] 2246.741150: funcgraph_entry: | vmx_get_cs_db_l_bits() {
qemu-system-x86-1723 [006] 2246.741150: funcgraph_entry: 0.126 us | vmx_read_guest_seg_ar();
qemu-system-x86-1723 [006] 2246.741150: funcgraph_exit: 0.314 us | }
qemu-system-x86-1723 [006] 2246.741151: funcgraph_entry: 0.122 us | vmx_get_rflags();
qemu-system-x86-1723 [006] 2246.741151: funcgraph_entry: 0.088 us | vmx_cache_reg();
qemu-system-x86-1723 [006] 2246.741151: funcgraph_entry: 0.084 us | vmx_decache_cr4_guest_bits();
qemu-system-x86-1723 [006] 2246.741151: funcgraph_entry: | vmx_get_cpl() {
qemu-system-x86-1723 [006] 2246.741151: funcgraph_entry: 0.113 us | vmx_read_guest_seg_ar();
qemu-system-x86-1723 [006] 2246.741152: funcgraph_exit: 0.284 us | }
qemu-system-x86-1723 [006] 2246.741152: funcgraph_entry: 0.091 us | vmx_decache_cr3();
qemu-system-x86-1723 [006] 2246.741152: funcgraph_entry: | vmx_get_cpl() {
qemu-system-x86-1723 [006] 2246.741152: funcgraph_entry: 0.102 us | vmx_read_guest_seg_ar();
qemu-system-x86-1723 [006] 2246.741152: funcgraph_exit: 0.263 us | }
qemu-system-x86-1723 [006] 2246.741152: funcgraph_entry: 0.080 us | vmx_get_rflags();
qemu-system-x86-1723 [006] 2246.741153: funcgraph_entry: 0.086 us | vmx_decache_cr4_guest_bits();
qemu-system-x86-1723 [006] 2246.741153: funcgraph_exit: 3.506 us | }
![[attachments/Pasted image 20220819095006.png]]
每秒运行了多少次 vmx_vcpu_load()
root@jet-dev:~# trace-cmd report | grep 'vmx_vcpu_run()' | grep 2248 | wc -l
81056
一个完整周期如下：
qemu-system-x86-1723 [006] 2246.741163: funcgraph_entry: 0.090 us | vmx_read_l1_tsc_offset();
qemu-system-x86-1723 [006] 2246.741163: funcgraph_entry: 0.110 us | vmx_handle_exit_irqoff();
qemu-system-x86-1723 [006] 2246.741163: funcgraph_entry: | vmx_handle_exit() {
qemu-system-x86-1723 [006] 2246.741163: funcgraph_entry: | vmx_get_cs_db_l_bits() {
qemu-system-x86-1723 [006] 2246.741163: funcgraph_entry: 0.097 us | vmx_read_guest_seg_ar();
qemu-system-x86-1723 [006] 2246.741163: funcgraph_exit: 0.245 us | }
qemu-system-x86-1723 [006] 2246.741163: funcgraph_entry: 0.096 us | vmx_get_rflags();
qemu-system-x86-1723 [006] 2246.741164: funcgraph_entry: 0.087 us | vmx_cache_reg();
qemu-system-x86-1723 [006] 2246.741164: funcgraph_entry: 0.081 us | vmx_decache_cr4_guest_bits();
qemu-system-x86-1723 [006] 2246.741164: funcgraph_entry: | vmx_get_cpl() {
qemu-system-x86-1723 [006] 2246.741164: funcgraph_entry: 0.096 us | vmx_read_guest_seg_ar();
qemu-system-x86-1723 [006] 2246.741164: funcgraph_exit: 0.242 us | }
qemu-system-x86-1723 [006] 2246.741164: funcgraph_entry: 0.080 us | vmx_decache_cr3();
qemu-system-x86-1723 [006] 2246.741165: funcgraph_entry: | vmx_get_cpl() {
qemu-system-x86-1723 [006] 2246.741165: funcgraph_entry: 0.093 us | vmx_read_guest_seg_ar();
qemu-system-x86-1723 [006] 2246.741165: funcgraph_exit: 0.236 us | }
qemu-system-x86-1723 [006] 2246.741165: funcgraph_entry: 0.079 us | vmx_get_rflags();
qemu-system-x86-1723 [006] 2246.741165: funcgraph_entry: 0.085 us | vmx_decache_cr4_guest_bits();
qemu-system-x86-1723 [006] 2246.741165: funcgraph_exit: 2.450 us | }
qemu-system-x86-1723 [006] 2246.741166: funcgraph_entry: 0.080 us | vmx_get_rflags();
qemu-system-x86-1723 [006] 2246.741166: funcgraph_entry: | vmx_vcpu_put() {
qemu-system-x86-1723 [006] 2246.741166: funcgraph_entry: 0.081 us | vmx_vcpu_pi_put();
qemu-system-x86-1723 [006] 2246.741166: funcgraph_entry: 0.213 us | vmx_prepare_switch_to_host();
qemu-system-x86-1723 [006] 2246.741166: funcgraph_exit: 0.506 us | }
qemu-system-x86-1723 [006] 2246.741167: funcgraph_entry: | vmx_vcpu_load() {
qemu-system-x86-1723 [006] 2246.741167: funcgraph_entry: 0.096 us | vmx_vcpu_load_vmcs();
qemu-system-x86-1723 [006] 2246.741167: funcgraph_exit: 0.259 us | }
![[attachments/Pasted image 20220819094153.png]]
一次周期大概5.063us 一秒钟 5.063 * 81056 = 410.386ms 。
因为ftrace也要占用性能，个人觉得记录这么多的调用，应该花费了这些所有耗时的一半左右，正常vmx_exit -> vmx_entry 消耗的时间可能是上面记录时间的40-50%。
如果统计中断的话，每秒大概2768次，每次1~2us 1.8 x 2768 = 4982.4ms -> 2vcpu 每个2.5ms。（未考虑ftrace带来的性能损失）。
通过hwlat的tracers，可以跟踪kvm的一些信息。
trace-cmd record -e kvm* -p hwlat
![[attachments/Pasted image 20220821143552.png]] 这里追钟了一个完整的退出到进入的消息。
查询退出原因分析：
trace-cmd report | grep kvm_exit | grep -v "EPT_MISCONFIG"
评论区