2019-07-01 06:24:21

by Yi Wang

[permalink] [raw]
Subject: [PATCH 0/4] kvm: x86: introduce CONFIG_KVM_DEBUG

This series introduce CONFIG_KVM_DEBUG, using which we can make
the invoking *_debug in KVM simly and uniform.

FYI: the former discussion can been found in:
https://www.spinics.net/lists/kvm/msg187026.html

Yi Wang (4):
kvm: x86: Add CONFIG_KVM_DEBUG
kvm: x86: allow set apic and ioapic debug dynamically
kvm: x86: replace MMU_DEBUG with CONFIG_KVM_DEBUG
kvm: x86: convert TSC pr_debugs to be gated by CONFIG_KVM_DEBUG

arch/x86/kvm/Kconfig | 8 ++++++++
arch/x86/kvm/ioapic.c | 2 +-
arch/x86/kvm/lapic.c | 5 ++++-
arch/x86/kvm/mmu.c | 5 ++---
arch/x86/kvm/x86.c | 18 ++++++++++++------
5 files changed, 27 insertions(+), 11 deletions(-)

--
1.8.3.1


2019-07-01 06:24:35

by Yi Wang

[permalink] [raw]
Subject: [PATCH 2/4] kvm: x86: allow set apic and ioapic debug dynamically

There are two *_debug() macros in kvm apic source file:
- ioapic_debug, which is disable using #if 0
- apic_debug, which is commented

Maybe it's better to control these two macros using CONFIG_KVM_DEBUG,
which can be set in make menuconfig.

Signed-off-by: Yi Wang <[email protected]>
---
arch/x86/kvm/ioapic.c | 2 +-
arch/x86/kvm/lapic.c | 5 ++++-
2 files changed, 5 insertions(+), 2 deletions(-)

diff --git a/arch/x86/kvm/ioapic.c b/arch/x86/kvm/ioapic.c
index 1add1bc..8099253 100644
--- a/arch/x86/kvm/ioapic.c
+++ b/arch/x86/kvm/ioapic.c
@@ -45,7 +45,7 @@
#include "lapic.h"
#include "irq.h"

-#if 0
+#ifdef CONFIG_KVM_DEBUG
#define ioapic_debug(fmt,arg...) printk(KERN_WARNING fmt,##arg)
#else
#define ioapic_debug(fmt, arg...)
diff --git a/arch/x86/kvm/lapic.c b/arch/x86/kvm/lapic.c
index 4924f83..dfff5c6 100644
--- a/arch/x86/kvm/lapic.c
+++ b/arch/x86/kvm/lapic.c
@@ -54,8 +54,11 @@
#define PRIu64 "u"
#define PRIo64 "o"

-/* #define apic_debug(fmt,arg...) printk(KERN_WARNING fmt,##arg) */
+#ifdef CONFIG_KVM_DEBUG
+#define apic_debug(fmt,arg...) printk(KERN_WARNING fmt,##arg)
+#else
#define apic_debug(fmt, arg...) do {} while (0)
+#endif

/* 14 is the version for Xeon and Pentium 8.4.8*/
#define APIC_VERSION (0x14UL | ((KVM_APIC_LVT_NUM - 1) << 16))
--
1.8.3.1

2019-07-01 06:24:45

by Yi Wang

[permalink] [raw]
Subject: [PATCH 3/4] kvm: x86: replace MMU_DEBUG with CONFIG_KVM_DEBUG

As CONFIG_KVM_DEBUG has been introduced in the former
patch, it's better to replace MMU_DEBUG with CONFIG_KVM_DEBUG.

Signed-off-by: Yi Wang <[email protected]>
---
arch/x86/kvm/mmu.c | 5 ++---
1 file changed, 2 insertions(+), 3 deletions(-)

diff --git a/arch/x86/kvm/mmu.c b/arch/x86/kvm/mmu.c
index 1e9ba81..d54214e 100644
--- a/arch/x86/kvm/mmu.c
+++ b/arch/x86/kvm/mmu.c
@@ -68,9 +68,8 @@ enum {
AUDIT_POST_SYNC
};

-#undef MMU_DEBUG

-#ifdef MMU_DEBUG
+#ifdef CONFIG_KVM_DEBUG
static bool dbg = 0;
module_param(dbg, bool, 0644);

@@ -1994,7 +1993,7 @@ int kvm_test_age_hva(struct kvm *kvm, unsigned long hva)
return kvm_handle_hva(kvm, hva, 0, kvm_test_age_rmapp);
}

-#ifdef MMU_DEBUG
+#ifdef CONFIG_KVM_DEBUG
static int is_empty_shadow_page(u64 *spt)
{
u64 *pos;
--
1.8.3.1

2019-07-01 06:25:52

by Yi Wang

[permalink] [raw]
Subject: [PATCH 4/4] kvm: x86: convert TSC pr_debugs to be gated by CONFIG_KVM_DEBUG

There are some pr_debug in TSC code, which may affect
performance, so it may make sense to wrap them using a new
macro tsc_debug which takes effect only when CONFIG_KVM_DEBUG
is defined.

Signed-off-by: Yi Wang <[email protected]>
---
arch/x86/kvm/x86.c | 18 ++++++++++++------
1 file changed, 12 insertions(+), 6 deletions(-)

diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c
index 83aefd7..1505e53 100644
--- a/arch/x86/kvm/x86.c
+++ b/arch/x86/kvm/x86.c
@@ -74,6 +74,12 @@
#define CREATE_TRACE_POINTS
#include "trace.h"

+#ifdef CONFIG_KVM_DEBUG
+#define tsc_debug(x...) pr_debug(x)
+#else
+#define tsc_debug(x...)
+#endif
+
#define MAX_IO_MSRS 256
#define KVM_MAX_MCE_BANKS 32
u64 __read_mostly kvm_mce_cap_supported = MCG_CTL_P | MCG_SER_P;
@@ -1522,7 +1528,7 @@ static void kvm_get_time_scale(uint64_t scaled_hz, uint64_t base_hz,
*pshift = shift;
*pmultiplier = div_frac(scaled64, tps32);

- pr_debug("%s: base_hz %llu => %llu, shift %d, mul %u\n",
+ tsc_debug("%s: base_hz %llu => %llu, shift %d, mul %u\n",
__func__, base_hz, scaled_hz, shift, *pmultiplier);
}

@@ -1603,7 +1609,7 @@ static int kvm_set_tsc_khz(struct kvm_vcpu *vcpu, u32 user_tsc_khz)
thresh_lo = adjust_tsc_khz(tsc_khz, -tsc_tolerance_ppm);
thresh_hi = adjust_tsc_khz(tsc_khz, tsc_tolerance_ppm);
if (user_tsc_khz < thresh_lo || user_tsc_khz > thresh_hi) {
- pr_debug("kvm: requested TSC rate %u falls outside tolerance [%u,%u]\n", user_tsc_khz, thresh_lo, thresh_hi);
+ tsc_debug("kvm: requested TSC rate %u falls outside tolerance [%u,%u]\n", user_tsc_khz, thresh_lo, thresh_hi);
use_scaling = 1;
}
return set_tsc_khz(vcpu, user_tsc_khz, use_scaling);
@@ -1766,12 +1772,12 @@ void kvm_write_tsc(struct kvm_vcpu *vcpu, struct msr_data *msr)
vcpu->arch.virtual_tsc_khz == kvm->arch.last_tsc_khz) {
if (!kvm_check_tsc_unstable()) {
offset = kvm->arch.cur_tsc_offset;
- pr_debug("kvm: matched tsc offset for %llu\n", data);
+ tsc_debug("kvm: matched tsc offset for %llu\n", data);
} else {
u64 delta = nsec_to_cycles(vcpu, elapsed);
data += delta;
offset = kvm_compute_tsc_offset(vcpu, data);
- pr_debug("kvm: adjusted tsc offset by %llu\n", delta);
+ tsc_debug("kvm: adjusted tsc offset by %llu\n", delta);
}
matched = true;
already_matched = (vcpu->arch.this_tsc_generation == kvm->arch.cur_tsc_generation);
@@ -1790,7 +1796,7 @@ void kvm_write_tsc(struct kvm_vcpu *vcpu, struct msr_data *msr)
kvm->arch.cur_tsc_write = data;
kvm->arch.cur_tsc_offset = offset;
matched = false;
- pr_debug("kvm: new tsc generation %llu, clock %llu\n",
+ tsc_debug("kvm: new tsc generation %llu, clock %llu\n",
kvm->arch.cur_tsc_generation, data);
}

@@ -6860,7 +6866,7 @@ static void kvm_timer_init(void)
cpufreq_register_notifier(&kvmclock_cpufreq_notifier_block,
CPUFREQ_TRANSITION_NOTIFIER);
}
- pr_debug("kvm: max_tsc_khz = %ld\n", max_tsc_khz);
+ tsc_debug("kvm: max_tsc_khz = %ld\n", max_tsc_khz);

cpuhp_setup_state(CPUHP_AP_X86_KVM_CLK_ONLINE, "x86/kvm/clk:online",
kvmclock_cpu_online, kvmclock_cpu_down_prep);
--
1.8.3.1

2019-07-01 07:16:54

by Yi Wang

[permalink] [raw]
Subject: [PATCH 1/4] kvm: x86: Add CONFIG_KVM_DEBUG

There are some *_debug functions in KVM, it may be
better to introduce CONFIG_DEBUG_KVM to replace the
*_debug macro, which can avoid bloating and slowing KVM,
as Sean suggested.

Signed-off-by: Yi Wang <[email protected]>
---
arch/x86/kvm/Kconfig | 8 ++++++++
1 file changed, 8 insertions(+)

diff --git a/arch/x86/kvm/Kconfig b/arch/x86/kvm/Kconfig
index fc04241..7e76eb2 100644
--- a/arch/x86/kvm/Kconfig
+++ b/arch/x86/kvm/Kconfig
@@ -95,6 +95,14 @@ config KVM_MMU_AUDIT
This option adds a R/W kVM module parameter 'mmu_audit', which allows
auditing of KVM MMU events at runtime.

+config KVM_DEBUG
+ bool "Enable KVM debugging"
+ default n
+ depends on KVM
+ ---help---
+ Say Y here if you want to enable verbose KVM debug output.
+
+
# OK, it's a little counter-intuitive to do this, but it puts it neatly under
# the virtualization menu.
source "drivers/vhost/Kconfig"
--
1.8.3.1

2019-07-03 16:25:14

by Paolo Bonzini

[permalink] [raw]
Subject: Re: [PATCH 2/4] kvm: x86: allow set apic and ioapic debug dynamically

On 01/07/19 08:21, Yi Wang wrote:
> There are two *_debug() macros in kvm apic source file:
> - ioapic_debug, which is disable using #if 0
> - apic_debug, which is commented
>
> Maybe it's better to control these two macros using CONFIG_KVM_DEBUG,
> which can be set in make menuconfig.
>
> Signed-off-by: Yi Wang <[email protected]>
> ---
> arch/x86/kvm/ioapic.c | 2 +-
> arch/x86/kvm/lapic.c | 5 ++++-
> 2 files changed, 5 insertions(+), 2 deletions(-)
>
> diff --git a/arch/x86/kvm/ioapic.c b/arch/x86/kvm/ioapic.c
> index 1add1bc..8099253 100644
> --- a/arch/x86/kvm/ioapic.c
> +++ b/arch/x86/kvm/ioapic.c
> @@ -45,7 +45,7 @@
> #include "lapic.h"
> #include "irq.h"
>
> -#if 0
> +#ifdef CONFIG_KVM_DEBUG
> #define ioapic_debug(fmt,arg...) printk(KERN_WARNING fmt,##arg)
> #else
> #define ioapic_debug(fmt, arg...)
> diff --git a/arch/x86/kvm/lapic.c b/arch/x86/kvm/lapic.c
> index 4924f83..dfff5c6 100644
> --- a/arch/x86/kvm/lapic.c
> +++ b/arch/x86/kvm/lapic.c
> @@ -54,8 +54,11 @@
> #define PRIu64 "u"
> #define PRIo64 "o"
>
> -/* #define apic_debug(fmt,arg...) printk(KERN_WARNING fmt,##arg) */
> +#ifdef CONFIG_KVM_DEBUG
> +#define apic_debug(fmt,arg...) printk(KERN_WARNING fmt,##arg)
> +#else
> #define apic_debug(fmt, arg...) do {} while (0)
> +#endif
>
> /* 14 is the version for Xeon and Pentium 8.4.8*/
> #define APIC_VERSION (0x14UL | ((KVM_APIC_LVT_NUM - 1) << 16))
>

I would just drop all of them. I've never used them in years, the kvm
tracepoints are enough.

Paolo

2019-07-03 16:25:51

by Paolo Bonzini

[permalink] [raw]
Subject: Re: [PATCH 4/4] kvm: x86: convert TSC pr_debugs to be gated by CONFIG_KVM_DEBUG

On 01/07/19 08:21, Yi Wang wrote:
> There are some pr_debug in TSC code, which may affect
> performance, so it may make sense to wrap them using a new
> macro tsc_debug which takes effect only when CONFIG_KVM_DEBUG
> is defined.
>
> Signed-off-by: Yi Wang <[email protected]>
> ---
> arch/x86/kvm/x86.c | 18 ++++++++++++------
> 1 file changed, 12 insertions(+), 6 deletions(-)
>
> diff --git a/arch/x86/kvm/x86.c b/arch/x86/kvm/x86.c
> index 83aefd7..1505e53 100644
> --- a/arch/x86/kvm/x86.c
> +++ b/arch/x86/kvm/x86.c
> @@ -74,6 +74,12 @@
> #define CREATE_TRACE_POINTS
> #include "trace.h"
>
> +#ifdef CONFIG_KVM_DEBUG
> +#define tsc_debug(x...) pr_debug(x)
> +#else
> +#define tsc_debug(x...)
> +#endif
> +
> #define MAX_IO_MSRS 256
> #define KVM_MAX_MCE_BANKS 32
> u64 __read_mostly kvm_mce_cap_supported = MCG_CTL_P | MCG_SER_P;
> @@ -1522,7 +1528,7 @@ static void kvm_get_time_scale(uint64_t scaled_hz, uint64_t base_hz,
> *pshift = shift;
> *pmultiplier = div_frac(scaled64, tps32);
>
> - pr_debug("%s: base_hz %llu => %llu, shift %d, mul %u\n",
> + tsc_debug("%s: base_hz %llu => %llu, shift %d, mul %u\n",
> __func__, base_hz, scaled_hz, shift, *pmultiplier);
> }

Just remove this.

> @@ -1603,7 +1609,7 @@ static int kvm_set_tsc_khz(struct kvm_vcpu *vcpu, u32 user_tsc_khz)
> thresh_lo = adjust_tsc_khz(tsc_khz, -tsc_tolerance_ppm);
> thresh_hi = adjust_tsc_khz(tsc_khz, tsc_tolerance_ppm);
> if (user_tsc_khz < thresh_lo || user_tsc_khz > thresh_hi) {
> - pr_debug("kvm: requested TSC rate %u falls outside tolerance [%u,%u]\n", user_tsc_khz, thresh_lo, thresh_hi);
> + tsc_debug("kvm: requested TSC rate %u falls outside tolerance [%u,%u]\n", user_tsc_khz, thresh_lo, thresh_hi);

This is okay as a pr_debug, it only happens once per VM and only if it
is configured wrong.

> use_scaling = 1;
> }
> return set_tsc_khz(vcpu, user_tsc_khz, use_scaling);
> @@ -1766,12 +1772,12 @@ void kvm_write_tsc(struct kvm_vcpu *vcpu, struct msr_data *msr)
> vcpu->arch.virtual_tsc_khz == kvm->arch.last_tsc_khz) {
> if (!kvm_check_tsc_unstable()) {
> offset = kvm->arch.cur_tsc_offset;
> - pr_debug("kvm: matched tsc offset for %llu\n", data);
> + tsc_debug("kvm: matched tsc offset for %llu\n", data);
> } else {
> u64 delta = nsec_to_cycles(vcpu, elapsed);
> data += delta;
> offset = kvm_compute_tsc_offset(vcpu, data);
> - pr_debug("kvm: adjusted tsc offset by %llu\n", delta);
> + tsc_debug("kvm: adjusted tsc offset by %llu\n", delta);

Again just drop these, there are tracepoints for it.
> }
> matched = true;
> already_matched = (vcpu->arch.this_tsc_generation == kvm->arch.cur_tsc_generation);
> @@ -1790,7 +1796,7 @@ void kvm_write_tsc(struct kvm_vcpu *vcpu, struct msr_data *msr)
> kvm->arch.cur_tsc_write = data;
> kvm->arch.cur_tsc_offset = offset;
> matched = false;
> - pr_debug("kvm: new tsc generation %llu, clock %llu\n",
> + tsc_debug("kvm: new tsc generation %llu, clock %llu\n",
> kvm->arch.cur_tsc_generation, data);

Drop.

> }
>
> @@ -6860,7 +6866,7 @@ static void kvm_timer_init(void)
> cpufreq_register_notifier(&kvmclock_cpufreq_notifier_block,
> CPUFREQ_TRANSITION_NOTIFIER);
> }
> - pr_debug("kvm: max_tsc_khz = %ld\n", max_tsc_khz);
> + tsc_debug("kvm: max_tsc_khz = %ld\n", max_tsc_khz);

Drop.

Thanks,

Paolo

> cpuhp_setup_state(CPUHP_AP_X86_KVM_CLK_ONLINE, "x86/kvm/clk:online",
> kvmclock_cpu_online, kvmclock_cpu_down_prep);
>

2019-07-03 16:28:23

by Paolo Bonzini

[permalink] [raw]
Subject: Re: [PATCH 0/4] kvm: x86: introduce CONFIG_KVM_DEBUG

On 01/07/19 08:21, Yi Wang wrote:
> This series introduce CONFIG_KVM_DEBUG, using which we can make
> the invoking *_debug in KVM simly and uniform.
>
> FYI: the former discussion can been found in:
> https://www.spinics.net/lists/kvm/msg187026.html

Basically everything except MMU_DEBUG can just be deleted, they are
little more than debugging printk that were left in the code.

For MMU_DEBUG, the way to go is to add more tracepoints, but then
converting all pgprintk occurrences to tracepoints would be wrong. You
can only find the "right" tracepoints when debugging MMU code. I do
have a couple patches in this area, I will send them when possible.

Paolo

> Yi Wang (4):
> kvm: x86: Add CONFIG_KVM_DEBUG
> kvm: x86: allow set apic and ioapic debug dynamically
> kvm: x86: replace MMU_DEBUG with CONFIG_KVM_DEBUG
> kvm: x86: convert TSC pr_debugs to be gated by CONFIG_KVM_DEBUG
>
> arch/x86/kvm/Kconfig | 8 ++++++++
> arch/x86/kvm/ioapic.c | 2 +-
> arch/x86/kvm/lapic.c | 5 ++++-
> arch/x86/kvm/mmu.c | 5 ++---
> arch/x86/kvm/x86.c | 18 ++++++++++++------
> 5 files changed, 27 insertions(+), 11 deletions(-)
>

2019-07-03 16:30:24

by Liran Alon

[permalink] [raw]
Subject: Re: [PATCH 2/4] kvm: x86: allow set apic and ioapic debug dynamically



> On 3 Jul 2019, at 19:23, Paolo Bonzini <[email protected]> wrote:
>
> On 01/07/19 08:21, Yi Wang wrote:
>> There are two *_debug() macros in kvm apic source file:
>> - ioapic_debug, which is disable using #if 0
>> - apic_debug, which is commented
>>
>> Maybe it's better to control these two macros using CONFIG_KVM_DEBUG,
>> which can be set in make menuconfig.
>>
>> Signed-off-by: Yi Wang <[email protected]>
>> ---
>> arch/x86/kvm/ioapic.c | 2 +-
>> arch/x86/kvm/lapic.c | 5 ++++-
>> 2 files changed, 5 insertions(+), 2 deletions(-)
>>
>> diff --git a/arch/x86/kvm/ioapic.c b/arch/x86/kvm/ioapic.c
>> index 1add1bc..8099253 100644
>> --- a/arch/x86/kvm/ioapic.c
>> +++ b/arch/x86/kvm/ioapic.c
>> @@ -45,7 +45,7 @@
>> #include "lapic.h"
>> #include "irq.h"
>>
>> -#if 0
>> +#ifdef CONFIG_KVM_DEBUG
>> #define ioapic_debug(fmt,arg...) printk(KERN_WARNING fmt,##arg)
>> #else
>> #define ioapic_debug(fmt, arg...)
>> diff --git a/arch/x86/kvm/lapic.c b/arch/x86/kvm/lapic.c
>> index 4924f83..dfff5c6 100644
>> --- a/arch/x86/kvm/lapic.c
>> +++ b/arch/x86/kvm/lapic.c
>> @@ -54,8 +54,11 @@
>> #define PRIu64 "u"
>> #define PRIo64 "o"
>>
>> -/* #define apic_debug(fmt,arg...) printk(KERN_WARNING fmt,##arg) */
>> +#ifdef CONFIG_KVM_DEBUG
>> +#define apic_debug(fmt,arg...) printk(KERN_WARNING fmt,##arg)
>> +#else
>> #define apic_debug(fmt, arg...) do {} while (0)
>> +#endif
>>
>> /* 14 is the version for Xeon and Pentium 8.4.8*/
>> #define APIC_VERSION (0x14UL | ((KVM_APIC_LVT_NUM - 1) << 16))
>>
>
> I would just drop all of them. I've never used them in years, the kvm
> tracepoints are enough.
>
> Paolo

As someone who have done many LAPIC/IOAPIC debugging, I tend to agree. :)

-Liran

2019-07-04 12:21:49

by Paolo Bonzini

[permalink] [raw]
Subject: Re: [PATCH 2/4] kvm: x86: allow set apic and ioapic debug dynamically

On 04/07/19 04:00, [email protected] wrote:
> Do you mean we can remove ioapic_debug and apic_debug totally? If so,
> I would like to send a v2 patch to delete these two macros. :-)
>

Yes, please.

Paolo

2019-07-04 12:22:33

by Paolo Bonzini

[permalink] [raw]
Subject: Re: [PATCH 0/4] kvm: x86: introduce CONFIG_KVM_DEBUG

On 04/07/19 04:11, [email protected] wrote:
>> For MMU_DEBUG, the way to go is to add more tracepoints, but then
>> converting all pgprintk occurrences to tracepoints would be wrong. You
>> can only find the "right" tracepoints when debugging MMU code. I do
>> have a couple patches in this area, I will send them when possible.
>
> Agreed. Hoping your patches.

I sent them earlier, see "KVM: some x86 MMU cleanup and new tracepoints".

Paolo

2019-07-04 12:24:22

by Paolo Bonzini

[permalink] [raw]
Subject: Re: [PATCH 0/4] kvm: x86: introduce CONFIG_KVM_DEBUG

On 04/07/19 04:11, [email protected] wrote:
>> For MMU_DEBUG, the way to go is to add more tracepoints, but then
>> converting all pgprintk occurrences to tracepoints would be wrong. You
>> can only find the "right" tracepoints when debugging MMU code. I do
>> have a couple patches in this area, I will send them when possible.
>
> Agreed. Hoping your patches.

I have now sent them, see "KVM: some x86 MMU cleanup and new tracepoints".

Paolo