[PATCH v2] accel/kvm: Turn DPRINTF macro use into tracepoints

Jai Arora posted 1 patch 12 months ago
Patches applied successfully (tree, apply log)
git fetch https://github.com/patchew-project/qemu tags/patchew/20231129172109.207516-1-arorajai2798@gmail.com
Maintainers: Paolo Bonzini <pbonzini@redhat.com>
There is a newer version of this series
accel/kvm/kvm-all.c    | 33 +++++++++++----------------------
accel/kvm/trace-events |  8 +++++++-
2 files changed, 18 insertions(+), 23 deletions(-)
[PATCH v2] accel/kvm: Turn DPRINTF macro use into tracepoints
Posted by Jai Arora 12 months ago
Patch removes DRPINTF macro and adds multiple tracepoints
to capture different kvm events.

Resolves: https://gitlab.com/qemu-project/qemu/-/issues/1827

Signed-off-by: Jai Arora <arorajai2798@gmail.com>
---
 accel/kvm/kvm-all.c    | 33 +++++++++++----------------------
 accel/kvm/trace-events |  8 +++++++-
 2 files changed, 18 insertions(+), 23 deletions(-)

diff --git a/accel/kvm/kvm-all.c b/accel/kvm/kvm-all.c
index e39a810a4e..0801ca7933 100644
--- a/accel/kvm/kvm-all.c
+++ b/accel/kvm/kvm-all.c
@@ -69,16 +69,6 @@
 #define KVM_GUESTDBG_BLOCKIRQ 0
 #endif
 
-//#define DEBUG_KVM
-
-#ifdef DEBUG_KVM
-#define DPRINTF(fmt, ...) \
-    do { fprintf(stderr, fmt, ## __VA_ARGS__); } while (0)
-#else
-#define DPRINTF(fmt, ...) \
-    do { } while (0)
-#endif
-
 struct KVMParkedVcpu {
     unsigned long vcpu_id;
     int kvm_fd;
@@ -331,7 +321,7 @@ static int do_kvm_destroy_vcpu(CPUState *cpu)
     struct KVMParkedVcpu *vcpu = NULL;
     int ret = 0;
 
-    DPRINTF("kvm_destroy_vcpu\n");
+    trace_kvm_destroy_vcpu();
 
     ret = kvm_arch_destroy_vcpu(cpu);
     if (ret < 0) {
@@ -341,7 +331,7 @@ static int do_kvm_destroy_vcpu(CPUState *cpu)
     mmap_size = kvm_ioctl(s, KVM_GET_VCPU_MMAP_SIZE, 0);
     if (mmap_size < 0) {
         ret = mmap_size;
-        DPRINTF("KVM_GET_VCPU_MMAP_SIZE failed\n");
+        trace_kvm_failed_get_vcpu_mmap_size();
         goto err;
     }
 
@@ -443,7 +433,6 @@ int kvm_init_vcpu(CPUState *cpu, Error **errp)
                                    PAGE_SIZE * KVM_DIRTY_LOG_PAGE_OFFSET);
         if (cpu->kvm_dirty_gfns == MAP_FAILED) {
             ret = -errno;
-            DPRINTF("mmap'ing vcpu dirty gfns failed: %d\n", ret);
             goto err;
         }
     }
@@ -2821,7 +2810,7 @@ int kvm_cpu_exec(CPUState *cpu)
     struct kvm_run *run = cpu->kvm_run;
     int ret, run_ret;
 
-    DPRINTF("kvm_cpu_exec()\n");
+    trace_kvm_cpu_exec();
 
     if (kvm_arch_process_async_events(cpu)) {
         qatomic_set(&cpu->exit_request, 0);
@@ -2848,7 +2837,7 @@ int kvm_cpu_exec(CPUState *cpu)
 
         kvm_arch_pre_run(cpu, run);
         if (qatomic_read(&cpu->exit_request)) {
-            DPRINTF("interrupt exit requested\n");
+	    trace_kvm_interrupt_exit_request();
             /*
              * KVM requires us to reenter the kernel after IO exits to complete
              * instruction emulation. This self-signal will ensure that we
@@ -2878,7 +2867,7 @@ int kvm_cpu_exec(CPUState *cpu)
 
         if (run_ret < 0) {
             if (run_ret == -EINTR || run_ret == -EAGAIN) {
-                DPRINTF("io window exit\n");
+                trace_kvm_io_window_exit();
                 kvm_eat_signals(cpu);
                 ret = EXCP_INTERRUPT;
                 break;
@@ -2900,7 +2889,7 @@ int kvm_cpu_exec(CPUState *cpu)
         trace_kvm_run_exit(cpu->cpu_index, run->exit_reason);
         switch (run->exit_reason) {
         case KVM_EXIT_IO:
-            DPRINTF("handle_io\n");
+            trace_kvm_run_exit_reason("handle_io\n");
             /* Called outside BQL */
             kvm_handle_io(run->io.port, attrs,
                           (uint8_t *)run + run->io.data_offset,
@@ -2910,7 +2899,7 @@ int kvm_cpu_exec(CPUState *cpu)
             ret = 0;
             break;
         case KVM_EXIT_MMIO:
-            DPRINTF("handle_mmio\n");
+            trace_kvm_run_exit_reason("handle_mmio\n");
             /* Called outside BQL */
             address_space_rw(&address_space_memory,
                              run->mmio.phys_addr, attrs,
@@ -2920,11 +2909,11 @@ int kvm_cpu_exec(CPUState *cpu)
             ret = 0;
             break;
         case KVM_EXIT_IRQ_WINDOW_OPEN:
-            DPRINTF("irq_window_open\n");
+            trace_kvm_run_exit_reason("irq_window_open\n");
             ret = EXCP_INTERRUPT;
             break;
         case KVM_EXIT_SHUTDOWN:
-            DPRINTF("shutdown\n");
+            trace_kvm_run_exit_reason("shutdown\n");
             qemu_system_reset_request(SHUTDOWN_CAUSE_GUEST_RESET);
             ret = EXCP_INTERRUPT;
             break;
@@ -2976,14 +2965,14 @@ int kvm_cpu_exec(CPUState *cpu)
                 ret = 0;
                 break;
             default:
-                DPRINTF("kvm_arch_handle_exit\n");
+                trace_kvm_exit_system_event("kvm_arch_handle_exit\n");
                 ret = kvm_arch_handle_exit(cpu, run);
                 break;
             }
             break;
         default:
-            DPRINTF("kvm_arch_handle_exit\n");
             ret = kvm_arch_handle_exit(cpu, run);
+            trace_kvm_run_exit_reason("kvm_arch_handle_exit\n");
             break;
         }
     } while (ret == 0);
diff --git a/accel/kvm/trace-events b/accel/kvm/trace-events
index 399aaeb0ec..e7b9e9bcc1 100644
--- a/accel/kvm/trace-events
+++ b/accel/kvm/trace-events
@@ -25,4 +25,10 @@ kvm_dirty_ring_reaper(const char *s) "%s"
 kvm_dirty_ring_reap(uint64_t count, int64_t t) "reaped %"PRIu64" pages (took %"PRIi64" us)"
 kvm_dirty_ring_reaper_kick(const char *reason) "%s"
 kvm_dirty_ring_flush(int finished) "%d"
-
+kvm_destroy_vcpu(void) ""
+kvm_failed_get_vcpu_mmap_size(void) ""
+kvm_cpu_exec(void) ""
+kvm_interrupt_exit_request(void) ""
+kvm_io_window_exit(void) ""
+kvm_run_exit_reason(const char *s) "%s"
+kvm_exit_system_event(const char *s) "%s"
-- 
2.25.1
Re: [PATCH v2] accel/kvm: Turn DPRINTF macro use into tracepoints
Posted by Alex Bennée 12 months ago
Jai Arora <arorajai2798@gmail.com> writes:

> Patch removes DRPINTF macro and adds multiple tracepoints
> to capture different kvm events.
>
> Resolves: https://gitlab.com/qemu-project/qemu/-/issues/1827
>
> Signed-off-by: Jai Arora <arorajai2798@gmail.com>
> ---
>  accel/kvm/kvm-all.c    | 33 +++++++++++----------------------
>  accel/kvm/trace-events |  8 +++++++-
>  2 files changed, 18 insertions(+), 23 deletions(-)
>
> diff --git a/accel/kvm/kvm-all.c b/accel/kvm/kvm-all.c
> index e39a810a4e..0801ca7933 100644
> --- a/accel/kvm/kvm-all.c
> +++ b/accel/kvm/kvm-all.c
> @@ -69,16 +69,6 @@
>  #define KVM_GUESTDBG_BLOCKIRQ 0
>  #endif
>  
> -//#define DEBUG_KVM
> -
> -#ifdef DEBUG_KVM
> -#define DPRINTF(fmt, ...) \
> -    do { fprintf(stderr, fmt, ## __VA_ARGS__); } while (0)
> -#else
> -#define DPRINTF(fmt, ...) \
> -    do { } while (0)
> -#endif
> -
>  struct KVMParkedVcpu {
>      unsigned long vcpu_id;
>      int kvm_fd;
> @@ -331,7 +321,7 @@ static int do_kvm_destroy_vcpu(CPUState *cpu)
>      struct KVMParkedVcpu *vcpu = NULL;
>      int ret = 0;
>  
> -    DPRINTF("kvm_destroy_vcpu\n");
> +    trace_kvm_destroy_vcpu();
>  
>      ret = kvm_arch_destroy_vcpu(cpu);
>      if (ret < 0) {
> @@ -341,7 +331,7 @@ static int do_kvm_destroy_vcpu(CPUState *cpu)
>      mmap_size = kvm_ioctl(s, KVM_GET_VCPU_MMAP_SIZE, 0);
>      if (mmap_size < 0) {
>          ret = mmap_size;
> -        DPRINTF("KVM_GET_VCPU_MMAP_SIZE failed\n");
> +        trace_kvm_failed_get_vcpu_mmap_size();
>          goto err;
>      }
>  
> @@ -443,7 +433,6 @@ int kvm_init_vcpu(CPUState *cpu, Error **errp)
>                                     PAGE_SIZE * KVM_DIRTY_LOG_PAGE_OFFSET);
>          if (cpu->kvm_dirty_gfns == MAP_FAILED) {
>              ret = -errno;
> -            DPRINTF("mmap'ing vcpu dirty gfns failed: %d\n", ret);
>              goto err;
>          }
>      }
> @@ -2821,7 +2810,7 @@ int kvm_cpu_exec(CPUState *cpu)
>      struct kvm_run *run = cpu->kvm_run;
>      int ret, run_ret;
>  
> -    DPRINTF("kvm_cpu_exec()\n");
> +    trace_kvm_cpu_exec();
>  
>      if (kvm_arch_process_async_events(cpu)) {
>          qatomic_set(&cpu->exit_request, 0);
> @@ -2848,7 +2837,7 @@ int kvm_cpu_exec(CPUState *cpu)
>  
>          kvm_arch_pre_run(cpu, run);
>          if (qatomic_read(&cpu->exit_request)) {
> -            DPRINTF("interrupt exit requested\n");
> +	    trace_kvm_interrupt_exit_request();
>              /*
>               * KVM requires us to reenter the kernel after IO exits to complete
>               * instruction emulation. This self-signal will ensure that we
> @@ -2878,7 +2867,7 @@ int kvm_cpu_exec(CPUState *cpu)
>  
>          if (run_ret < 0) {
>              if (run_ret == -EINTR || run_ret == -EAGAIN) {
> -                DPRINTF("io window exit\n");
> +                trace_kvm_io_window_exit();
>                  kvm_eat_signals(cpu);
>                  ret = EXCP_INTERRUPT;
>                  break;
> @@ -2900,7 +2889,7 @@ int kvm_cpu_exec(CPUState *cpu)
>          trace_kvm_run_exit(cpu->cpu_index, run->exit_reason);

As we trace the ->exit_reason here I think the individual legs that just
echo a static string don't add much value. Maybe delete them rather than
convert them?

>          switch (run->exit_reason) {
>          case KVM_EXIT_IO:
> -            DPRINTF("handle_io\n");
> +            trace_kvm_run_exit_reason("handle_io\n");
>              /* Called outside BQL */
>              kvm_handle_io(run->io.port, attrs,
>                            (uint8_t *)run + run->io.data_offset,
> @@ -2910,7 +2899,7 @@ int kvm_cpu_exec(CPUState *cpu)
>              ret = 0;
>              break;
>          case KVM_EXIT_MMIO:
> -            DPRINTF("handle_mmio\n");
> +            trace_kvm_run_exit_reason("handle_mmio\n");
>              /* Called outside BQL */
>              address_space_rw(&address_space_memory,
>                               run->mmio.phys_addr, attrs,
> @@ -2920,11 +2909,11 @@ int kvm_cpu_exec(CPUState *cpu)
>              ret = 0;
>              break;
>          case KVM_EXIT_IRQ_WINDOW_OPEN:
> -            DPRINTF("irq_window_open\n");
> +            trace_kvm_run_exit_reason("irq_window_open\n");
>              ret = EXCP_INTERRUPT;
>              break;
>          case KVM_EXIT_SHUTDOWN:
> -            DPRINTF("shutdown\n");
> +            trace_kvm_run_exit_reason("shutdown\n");
>              qemu_system_reset_request(SHUTDOWN_CAUSE_GUEST_RESET);
>              ret = EXCP_INTERRUPT;
>              break;
> @@ -2976,14 +2965,14 @@ int kvm_cpu_exec(CPUState *cpu)
>                  ret = 0;
>                  break;
>              default:
> -                DPRINTF("kvm_arch_handle_exit\n");
> +                trace_kvm_exit_system_event("kvm_arch_handle_exit\n");

Instead of this it would be more useful trace run->system_event.type in
the leg above.

>                  ret = kvm_arch_handle_exit(cpu, run);
>                  break;
>              }
>              break;
>          default:
> -            DPRINTF("kvm_arch_handle_exit\n");
>              ret = kvm_arch_handle_exit(cpu, run);
> +            trace_kvm_run_exit_reason("kvm_arch_handle_exit\n");

I think this can be deleted as we'll know the path it takes based on exit_reason/system_event.type

>              break;
>          }
>      } while (ret == 0);
> diff --git a/accel/kvm/trace-events b/accel/kvm/trace-events
> index 399aaeb0ec..e7b9e9bcc1 100644
> --- a/accel/kvm/trace-events
> +++ b/accel/kvm/trace-events
> @@ -25,4 +25,10 @@ kvm_dirty_ring_reaper(const char *s) "%s"
>  kvm_dirty_ring_reap(uint64_t count, int64_t t) "reaped %"PRIu64" pages (took %"PRIi64" us)"
>  kvm_dirty_ring_reaper_kick(const char *reason) "%s"
>  kvm_dirty_ring_flush(int finished) "%d"
> -
> +kvm_destroy_vcpu(void) ""
> +kvm_failed_get_vcpu_mmap_size(void) ""
> +kvm_cpu_exec(void) ""
> +kvm_interrupt_exit_request(void) ""
> +kvm_io_window_exit(void) ""
> +kvm_run_exit_reason(const char *s) "%s"
> +kvm_exit_system_event(const char *s) "%s"

Otherwise it looks like a good clean-up.

-- 
Alex Bennée
Virtualisation Tech Lead @ Linaro