github/acrn-hypervisor
1
0
Fork 0
mirror of https://github.com/projectacrn/acrn-hypervisor.git synced 2025-06-26 07:21:37 +00:00
Code Issues Projects Releases Wiki Activity

hv: dbg: sample vmexit data per-pCPU and per-vCPU

Browse Source 
this feature is used to sample vmexit data per physical CPU
and per virtual CPU of VM, command used in HV console as following:
  1. vmexit clear --> to clear current vmexit buffer
  2. vmexit -->output current vmexit info
  3. vmexit enable | disable, by default enabled.

Tracked-On: #5232
Signed-off-by: Minggui Cao <minggui.cao@intel.com>
This commit is contained in:
Minggui Cao 2020-08-06 11:19:09 +08:00 committed by wenlingz
parent b3767a4a32
commit 8ae4c90747
8 changed files with 570 additions and 2 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
hypervisor/common/hv_main.c
View File

@ -44,8 +44,9 @@ void vcpu_thread(struct thread_object *obj)
reset_event(&vcpu->events[VCPU_EVENT_VIRTUAL_INTERRUPT]);
profiling_vmenter_handler(vcpu);
TRACE_2L(TRACE_VM_ENTER, 0UL, 0UL);
sample_vmexit_end(basic_exit_reason, vcpu);
ret = run_vcpu(vcpu);
if (ret != 0) {
pr_fatal("vcpu resume failed");
@ -57,6 +58,7 @@ void vcpu_thread(struct thread_object *obj)
}
basic_exit_reason = vcpu->arch.exit_reason & 0xFFFFU;
TRACE_2L(TRACE_VM_EXIT, basic_exit_reason, vcpu_get_rip(vcpu));
sample_vmexit_begin(basic_exit_reason, vcpu);
vcpu->arch.nrexits++;

537
hypervisor/debug/shell.c
View File

@ -22,12 +22,13 @@
#include <shell.h>
#include <asm/guest/vmcs.h>
#include <asm/host_pm.h>
#include <asm/tsc.h>
#define TEMP_STR_SIZE 60U
#define MAX_STR_SIZE 256U
#define SHELL_PROMPT_STR "ACRN:\\>"
#define SHELL_LOG_BUF_SIZE (PAGE_SIZE * MAX_PCPU_NUM / 2U)
#define SHELL_LOG_BUF_SIZE (PAGE_SIZE * MAX_PCPU_NUM)
static char shell_log_buf[SHELL_LOG_BUF_SIZE];
/* Input Line Other - Switch to the "other" input line (there are only two
@ -52,6 +53,7 @@ static int32_t shell_cpuid(int32_t argc, char **argv);
static int32_t shell_reboot(int32_t argc, char **argv);
static int32_t shell_rdmsr(int32_t argc, char **argv);
static int32_t shell_wrmsr(int32_t argc, char **argv);
static int32_t shell_show_vmexit_profile(__unused int argc, __unused char **argv);
static struct shell_cmd shell_cmds[] = {
{
@ -156,6 +158,12 @@ static struct shell_cmd shell_cmds[] = {
.help_str = SHELL_CMD_WRMSR_HELP,
.fcn = shell_wrmsr,
},
{
.str = SHELL_CMD_VMEXIT,
.cmd_param = SHELL_CMD_VMEXIT_PARAM,
.help_str = SHELL_CMD_VMEXIT_HELP,
.fcn = shell_show_vmexit_profile,
},
};
/* The initial log level*/
@ -1446,3 +1454,530 @@ static int32_t shell_wrmsr(int32_t argc, char **argv)
return ret;
}
static void get_vmexit_profile_per_pcpu(char *str_arg, size_t str_max)
{
char *str = str_arg;
uint16_t cpu, i;
size_t len, size = str_max;
uint16_t pcpu_num = get_pcpu_nums();
len = snprintf(str, size, "\r\nNow(us) = %16lld\r\n", ticks_to_us(rdtsc()));
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
len = snprintf(str, size, "\r\nREASON");
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
for (cpu = 0U; cpu < pcpu_num; cpu++) {
len = snprintf(str, size, "\t CPU%hu\t US", cpu);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
}
for (i = 0U; i < 64U; i++) {
/* to ignore the 0 count vmexit */
for (cpu = 0U; cpu < pcpu_num; cpu++) {
if (per_cpu(vmexit_cnt, cpu)[i][TOTAL_ARRAY_LEVEL - 1] != 0)
break;
}
if (cpu == pcpu_num)
continue;
len = snprintf(str, size, "\r\n0x%02x", i);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
for (cpu = 0U; cpu < pcpu_num; cpu++) {
len = snprintf(str, size, "\t%10lld\t%10lld",
per_cpu(vmexit_cnt, cpu)[i][TOTAL_ARRAY_LEVEL - 1],
ticks_to_us(per_cpu(vmexit_time, cpu)[i][0]));
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
}
}
snprintf(str, size, "\r\n");
return;
overflow:
printf("buffer size could not be enough! please check!\n");
}
static void get_vmexit_profile_per_vcpu(char *str_arg, size_t str_max)
{
char *str = str_arg;
uint16_t vm_id, i, vcpu_id;
size_t len, size = str_max;
struct acrn_vm *vm;
struct acrn_vcpu *vcpu;
bool has_vmexit = false;
len = snprintf(str, size, "\r\nNow(us) = %16lld; total vmexit per vm/vCPU (count & time):\r\n",
ticks_to_us(rdtsc()));
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
len = snprintf(str, size, "\r\nREASON");
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
for (vm_id = 0U; vm_id < CONFIG_MAX_VM_NUM; vm_id++) {
vm = get_vm_from_vmid(vm_id);
if (is_poweroff_vm(vm))
continue;
foreach_vcpu(vcpu_id, vm, vcpu) {
len = snprintf(str, size, "\t VM%u/vCPU%u\t US", vm_id, vcpu_id);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
}
}
for (i = 0U; i < 64U; i++) {
for (vm_id = 0U; vm_id < CONFIG_MAX_VM_NUM; vm_id++) {
vm = get_vm_from_vmid(vm_id);
if (is_poweroff_vm(vm))
continue;
has_vmexit = false;
foreach_vcpu(vcpu_id, vm, vcpu) {
if (vcpu->vmexit_cnt[i][TOTAL_ARRAY_LEVEL - 1] != 0) {
has_vmexit = true;
break;
}
}
if (has_vmexit)
break;
}
if (vm_id == CONFIG_MAX_VM_NUM)
continue;
len = snprintf(str, size, "\r\n0x%02x", i);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
for (vm_id = 0U; vm_id < CONFIG_MAX_VM_NUM; vm_id++) {
vm = get_vm_from_vmid(vm_id);
if (is_poweroff_vm(vm))
continue;
foreach_vcpu(vcpu_id, vm, vcpu) {
len = snprintf(str, size, "\t%10lld\t%10lld",
vcpu->vmexit_cnt[i][TOTAL_ARRAY_LEVEL - 1],
ticks_to_us(vcpu->vmexit_time[i][0]));
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
}
}
}
snprintf(str, size, "\r\n");
return;
overflow:
printf("buffer size could not be enough! please check!\n");
}
static const char *level_info[MAX_VMEXIT_LEVEL] = {
" 0us - 2us",
" 2us - 4us",
" 4us - 8us",
" 8us - 16us",
" 16us - 32us",
" 32us - 64us",
" 64us - 128us",
" 128us - 256us",
" 256us - 512us",
" 512us -1024us",
"1024us -2048us",
"2048us -4096us",
"4096us -8192us",
"8192us - more",
};
static void get_vmexit_details_per_pcpu(char *str_arg, size_t str_max)
{
char *str = str_arg;
uint16_t cpu, i, level;
size_t len, size = str_max;
uint16_t pcpu_num = get_pcpu_nums();
len = snprintf(str, size, "\r\nNow=%lldus, for detailed latency of each vmexit on each cpu:",
ticks_to_us(rdtsc()));
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
for (i = 0U; i < 64U; i++) {
/* to ignore the 0 count vmexit */
for (cpu = 0U; cpu < pcpu_num; cpu++) {
if (per_cpu(vmexit_cnt, cpu)[i][TOTAL_ARRAY_LEVEL - 1] != 0)
break;
}
if (cpu == pcpu_num)
continue;
len = snprintf(str, size, "\r\n\r\n VMEXIT/0x%02x", i);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
for (cpu = 0U; cpu < pcpu_num; cpu++) {
len = snprintf(str, size, " CPU%hu", cpu);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
}
for (level = 0; level < MAX_VMEXIT_LEVEL; level++) {
/* to ignore the 0 count vmexit */
for (cpu = 0U; cpu < pcpu_num; cpu++) {
if (per_cpu(vmexit_cnt, cpu)[i][level] != 0)
break;
}
if (cpu == pcpu_num)
continue;
len = snprintf(str, size, "\r\n%s", level_info[level]);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
for (cpu = 0U; cpu < pcpu_num; cpu++) {
len = snprintf(str, size, "%12lld", per_cpu(vmexit_cnt, cpu)[i][level]);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
}
}
len = snprintf(str, size, "\r\n Max Lat(us):");
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
for (cpu = 0U; cpu < pcpu_num; cpu++) {
len = snprintf(str, size, "%12lld", per_cpu(vmexit_time, cpu)[i][1]);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
}
}
snprintf(str, size, "\r\n");
return;
overflow:
printf("buffer size could not be enough! please check!\n");
}
static void get_vmexit_details_per_vcpu(char *str_arg, size_t str_max)
{
char *str = str_arg;
uint16_t vm_id, i, level, vcpu_id;
size_t len, size = str_max;
struct acrn_vm *vm;
struct acrn_vcpu *vcpu;
bool has_vmexit = false;
len = snprintf(str, size, "\r\nNow=%lldus, for detailed latency of each vmexit on each VM/vCPU:",
ticks_to_us(rdtsc()));
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
for (i = 0U; i < 64U; i++) {
/* to ignore the 0 count vmexit */
for (vm_id = 0U; vm_id < CONFIG_MAX_VM_NUM; vm_id++) {
vm = get_vm_from_vmid(vm_id);
if (is_poweroff_vm(vm))
continue;
has_vmexit = false;
foreach_vcpu(vcpu_id, vm, vcpu) {
if (vcpu->vmexit_cnt[i][TOTAL_ARRAY_LEVEL - 1] != 0) {
has_vmexit = true;
break;
}
}
if (has_vmexit)
break;
}
if (vm_id == CONFIG_MAX_VM_NUM)
continue;
len = snprintf(str, size, "\r\n\r\n VMEXIT/0x%02x", i);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
for (vm_id = 0U; vm_id < CONFIG_MAX_VM_NUM; vm_id++) {
vm = get_vm_from_vmid(vm_id);
if (is_poweroff_vm(vm))
continue;
foreach_vcpu(vcpu_id, vm, vcpu) {
len = snprintf(str, size, " VM%u/vCPU%u", vm_id, vcpu_id);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
}
}
for (level = 0; level < MAX_VMEXIT_LEVEL; level++) {
/* to ignore the 0 count vmexit */
for (vm_id = 0U; vm_id < CONFIG_MAX_VM_NUM; vm_id++) {
vm = get_vm_from_vmid(vm_id);
if (is_poweroff_vm(vm))
continue;
has_vmexit = false;
foreach_vcpu(vcpu_id, vm, vcpu) {
if (vcpu->vmexit_cnt[i][level] != 0) {
has_vmexit = true;
break;
}
}
if (has_vmexit)
break;
}
if (vm_id == CONFIG_MAX_VM_NUM)
continue;
len = snprintf(str, size, "\r\n%s", level_info[level]);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
for (vm_id = 0U; vm_id < CONFIG_MAX_VM_NUM; vm_id++) {
vm = get_vm_from_vmid(vm_id);
if (is_poweroff_vm(vm))
continue;
foreach_vcpu(vcpu_id, vm, vcpu) {
len = snprintf(str, size, "%12lld", vcpu->vmexit_cnt[i][level]);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
}
}
}
len = snprintf(str, size, "\r\n Max Lat(us):");
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
for (vm_id = 0U; vm_id < CONFIG_MAX_VM_NUM; vm_id++) {
vm = get_vm_from_vmid(vm_id);
if (is_poweroff_vm(vm))
continue;
foreach_vcpu(vcpu_id, vm, vcpu) {
len = snprintf(str, size, "%12lld", vcpu->vmexit_time[i][1]);
if (len >= size) {
goto overflow;
}
size -= len;
str += len;
}
}
}
snprintf(str, size, "\r\n");
return;
overflow:
printf("buffer size could not be enough! please check!\n");
}
static void clear_vmexit_info_buffer(void)
{
uint16_t cpu, vm_id, vcpu_id;
uint16_t pcpu_num = get_pcpu_nums();
struct acrn_vm *vm;
struct acrn_vcpu *vcpu;
for (cpu = 0U; cpu < pcpu_num; cpu++) {
memset(per_cpu(vmexit_cnt, cpu), 0, sizeof(per_cpu(vmexit_cnt, cpu)));
memset(per_cpu(vmexit_time, cpu), 0, sizeof(per_cpu(vmexit_time, cpu)));
}
for (vm_id = 0U; vm_id < CONFIG_MAX_VM_NUM; vm_id++) {
vm = get_vm_from_vmid(vm_id);
if (!is_poweroff_vm(vm)) {
foreach_vcpu(vcpu_id, vm, vcpu) {
memset(vcpu->vmexit_cnt, 0, sizeof(vcpu->vmexit_cnt));
memset(vcpu->vmexit_time, 0, sizeof(vcpu->vmexit_time));
}
}
}
}
/* used to control vmexit sample function */
static bool sample_vmexit_enabled = true;
static int shell_show_vmexit_profile(__unused int argc, __unused char **argv)
{
if (argc == 2) {
if (strcmp(argv[1], "clear") == 0) {
clear_vmexit_info_buffer();
} else if (strcmp(argv[1], "enable") == 0) {
shell_puts("\tenable vmexit sample!\n");
sample_vmexit_enabled = true;
return 0;
} else if (strcmp(argv[1], "disable") == 0) {
shell_puts("\tdisable vmexit sample!\n");
sample_vmexit_enabled = false;
return 0;
}
}
if (!sample_vmexit_enabled) {
shell_puts("\tvmexit sample is disabled!\n");
return 0;
}
get_vmexit_profile_per_pcpu(shell_log_buf, SHELL_LOG_BUF_SIZE);
shell_puts(shell_log_buf);
get_vmexit_details_per_pcpu(shell_log_buf, SHELL_LOG_BUF_SIZE);
shell_puts(shell_log_buf);
get_vmexit_profile_per_vcpu(shell_log_buf, SHELL_LOG_BUF_SIZE);
shell_puts(shell_log_buf);
get_vmexit_details_per_vcpu(shell_log_buf, SHELL_LOG_BUF_SIZE);
shell_puts(shell_log_buf);
return 0;
}
/* to sample vmexit tsc data */
void sample_vmexit_end(uint32_t basic_exit_reason, struct acrn_vcpu *vcpu)
{
if (!sample_vmexit_enabled)
return;
if (vcpu->vmexit_begin != 0UL) {
uint64_t delta = rdtsc() - vcpu->vmexit_begin;
uint32_t us = (uint32_t)ticks_to_us(delta);
uint16_t fls = (uint16_t)(fls32(us) + 1); /* to avoid us = 0 case, then fls=0xFFFF */
uint16_t index = 0;
if (fls >= MAX_VMEXIT_LEVEL) {
index = MAX_VMEXIT_LEVEL - 1;
} else if (fls > 0) { /* if fls == 0, it means the us = 0 */
index = fls - 1;
}
get_cpu_var(vmexit_cnt)[basic_exit_reason][index]++;
get_cpu_var(vmexit_time)[basic_exit_reason][0] += delta;
vcpu->vmexit_cnt[basic_exit_reason][index]++;
vcpu->vmexit_time[basic_exit_reason][0] += delta;
if (us > get_cpu_var(vmexit_time)[basic_exit_reason][1]) {
get_cpu_var(vmexit_time)[basic_exit_reason][1] = us;
}
if (us > vcpu->vmexit_time[basic_exit_reason][1]) {
vcpu->vmexit_time[basic_exit_reason][1] = us;
}
}
}
void sample_vmexit_begin(uint32_t basic_exit_reason, struct acrn_vcpu *vcpu)
{
if (!sample_vmexit_enabled)
return;
vcpu->vmexit_begin = rdtsc();
get_cpu_var(vmexit_cnt)[basic_exit_reason][TOTAL_ARRAY_LEVEL - 1]++;
vcpu->vmexit_cnt[basic_exit_reason][TOTAL_ARRAY_LEVEL - 1]++;
}

5
hypervisor/debug/shell_priv.h
View File

@ -106,4 +106,9 @@ struct shell {
#define SHELL_CMD_WRMSR_PARAM "[-p<pcpu_id>] <msr_index> <value>"
#define SHELL_CMD_WRMSR_HELP "Write value (in hexadecimal) to the MSR at msr_index (in hexadecimal) for CPU"\
" ID pcpu_id"
#define SHELL_CMD_VMEXIT "vmexit"
#define SHELL_CMD_VMEXIT_PARAM NULL
#define SHELL_CMD_VMEXIT_HELP "show vmexit profiling, use: vmexit [clear | enable | disable] enabled by default"
#endif /* SHELL_PRIV_H */

8
hypervisor/include/arch/x86/asm/guest/vcpu.h
View File

@ -307,6 +307,14 @@ struct acrn_vcpu {
uint64_t reg_updated;
struct sched_event events[VCPU_EVENT_NUM];
#ifdef HV_DEBUG
uint64_t vmexit_begin;
uint64_t vmexit_cnt[64][TOTAL_ARRAY_LEVEL];
uint64_t vmexit_time[64][2]; /*0 for total latency, 1 for max latency */
#endif
} __aligned(PAGE_SIZE);
struct vcpu_dump {

6
hypervisor/include/arch/x86/asm/per_cpu.h
View File

@ -20,6 +20,8 @@
#include <asm/security.h>
#include <asm/vm_config.h>
#include <acrn_common.h>
struct per_cpu_region {
/* vmxon_region MUST be 4KB-aligned */
uint8_t vmxon_region[PAGE_SIZE];
@ -27,6 +29,10 @@ struct per_cpu_region {
#ifdef HV_DEBUG
struct shared_buf *sbuf[ACRN_SBUF_ID_MAX];
char logbuf[LOG_MESSAGE_MAX_SIZE];
uint64_t vmexit_cnt[64][TOTAL_ARRAY_LEVEL];
uint64_t vmexit_time[64][2]; /*0 for total latency, 1 for max latency */
uint32_t npk_log_ref;
#endif
uint64_t irq_count[NR_IRQS];

4
hypervisor/include/debug/profiling.h
View File

@ -18,4 +18,8 @@ void profiling_pre_vmexit_handler(struct acrn_vcpu *vcpu);
void profiling_post_vmexit_handler(struct acrn_vcpu *vcpu);
void profiling_setup(void);
/* for vmexit sample */
void sample_vmexit_end(uint32_t basic_exit_reason, struct acrn_vcpu *vcpu);
void sample_vmexit_begin(uint32_t basic_exit_reason, struct acrn_vcpu *vcpu);
#endif /* PROFILING_H */

5
hypervisor/include/public/acrn_common.h
View File

@ -46,6 +46,11 @@
#error "VIOAPIC_RTE_NUM must be larger than 23"
#endif
#ifdef HV_DEBUG
#define MAX_VMEXIT_LEVEL 14 /* from 0 to 14 for counts*/
#define TOTAL_ARRAY_LEVEL (MAX_VMEXIT_LEVEL + 1)
#endif
/* Generic VM flags from guest OS */
#define GUEST_FLAG_SECURE_WORLD_ENABLED (1UL << 0U) /* Whether secure world is enabled */
#define GUEST_FLAG_LAPIC_PASSTHROUGH (1UL << 1U) /* Whether LAPIC is passed through */

3
hypervisor/release/profiling.c
View File

@ -11,3 +11,6 @@ void profiling_vmenter_handler(__unused struct acrn_vcpu *vcpu) {}
void profiling_pre_vmexit_handler(__unused struct acrn_vcpu *vcpu) {}
void profiling_post_vmexit_handler(__unused struct acrn_vcpu *vcpu) {}
void profiling_setup(void) {}
void sample_vmexit_end(__unused uint32_t basic_exit_reason, __unused struct acrn_vcpu *vcpu) {}
void sample_vmexit_begin(__unused uint32_t basic_exit_reason, __unused struct acrn_vcpu *vcpu) {}