Add some trace points for IOTLB translation for vhost. After vhost-user
is setup, the only IO path that QEMU will participate should be the
IOMMU translation, so it'll be good we can track this with explicit
timestamps when needed to see how long time we take to do the
translation, and whether there's anything stuck inside.  It might be
useful for triaging vhost-user problems.

Signed-off-by: Peter Xu <peterx@redhat.com>
---
 hw/virtio/trace-events | 1 +
 hw/virtio/vhost.c      | 7 +++++++
 2 files changed, 8 insertions(+)

diff --git a/hw/virtio/trace-events b/hw/virtio/trace-events
index 742ff0f90b..933eaab133 100644
--- a/hw/virtio/trace-events
+++ b/hw/virtio/trace-events
@@ -5,6 +5,7 @@ vhost_commit(bool started, bool changed) "Started: %d Changed: %d"
 vhost_region_add_section(const char *name, uint64_t gpa, uint64_t size, uint64_t host) "%s: 0x%"PRIx64"+0x%"PRIx64" @ 0x%"PRIx64
 vhost_region_add_section_abut(const char *name, uint64_t new_size) "%s: 0x%"PRIx64
 vhost_section(const char *name, int r) "%s:%d"
+vhost_iotlb_miss(void *dev, int step) "%p step %d"
 
 # hw/virtio/virtio.c
 virtqueue_alloc_element(void *elem, size_t sz, unsigned in_num, unsigned out_num) "elem %p size %zd in_num %u out_num %u"
diff --git a/hw/virtio/vhost.c b/hw/virtio/vhost.c
index d8d0ef92e1..aa68f79510 100644
--- a/hw/virtio/vhost.c
+++ b/hw/virtio/vhost.c
@@ -839,12 +839,15 @@ int vhost_device_iotlb_miss(struct vhost_dev *dev, uint64_t iova, int write)
 
     rcu_read_lock();
 
+    trace_vhost_iotlb_miss(dev, 1);
+
     iotlb = address_space_get_iotlb_entry(dev->vdev->dma_as,
                                           iova, write);
     if (iotlb.target_as != NULL) {
         ret = vhost_memory_region_lookup(dev, iotlb.translated_addr,
                                          &uaddr, &len);
         if (ret) {
+            trace_vhost_iotlb_miss(dev, 3);
             error_report("Fail to lookup the translated address "
                          "%"PRIx64, iotlb.translated_addr);
             goto out;
@@ -856,10 +859,14 @@ int vhost_device_iotlb_miss(struct vhost_dev *dev, uint64_t iova, int write)
         ret = vhost_backend_update_device_iotlb(dev, iova, uaddr,
                                                 len, iotlb.perm);
         if (ret) {
+            trace_vhost_iotlb_miss(dev, 4);
             error_report("Fail to update device iotlb");
             goto out;
         }
     }
+
+    trace_vhost_iotlb_miss(dev, 2);
+
 out:
     rcu_read_unlock();
 
-- 
2.14.3

On Wed, Mar 21, 2018 at 11:21:24AM +0800, Peter Xu wrote:
> Add some trace points for IOTLB translation for vhost. After vhost-user
> is setup, the only IO path that QEMU will participate should be the
> IOMMU translation, so it'll be good we can track this with explicit
> timestamps when needed to see how long time we take to do the
> translation, and whether there's anything stuck inside.  It might be
> useful for triaging vhost-user problems.
> 
> Signed-off-by: Peter Xu <peterx@redhat.com>

Could you rebase pls?

> ---
>  hw/virtio/trace-events | 1 +
>  hw/virtio/vhost.c      | 7 +++++++
>  2 files changed, 8 insertions(+)
> 
> diff --git a/hw/virtio/trace-events b/hw/virtio/trace-events
> index 742ff0f90b..933eaab133 100644
> --- a/hw/virtio/trace-events
> +++ b/hw/virtio/trace-events
> @@ -5,6 +5,7 @@ vhost_commit(bool started, bool changed) "Started: %d Changed: %d"
>  vhost_region_add_section(const char *name, uint64_t gpa, uint64_t size, uint64_t host) "%s: 0x%"PRIx64"+0x%"PRIx64" @ 0x%"PRIx64
>  vhost_region_add_section_abut(const char *name, uint64_t new_size) "%s: 0x%"PRIx64
>  vhost_section(const char *name, int r) "%s:%d"
> +vhost_iotlb_miss(void *dev, int step) "%p step %d"
>  
>  # hw/virtio/virtio.c
>  virtqueue_alloc_element(void *elem, size_t sz, unsigned in_num, unsigned out_num) "elem %p size %zd in_num %u out_num %u"
> diff --git a/hw/virtio/vhost.c b/hw/virtio/vhost.c
> index d8d0ef92e1..aa68f79510 100644
> --- a/hw/virtio/vhost.c
> +++ b/hw/virtio/vhost.c
> @@ -839,12 +839,15 @@ int vhost_device_iotlb_miss(struct vhost_dev *dev, uint64_t iova, int write)
>  
>      rcu_read_lock();
>  
> +    trace_vhost_iotlb_miss(dev, 1);
> +
>      iotlb = address_space_get_iotlb_entry(dev->vdev->dma_as,
>                                            iova, write);
>      if (iotlb.target_as != NULL) {
>          ret = vhost_memory_region_lookup(dev, iotlb.translated_addr,
>                                           &uaddr, &len);
>          if (ret) {
> +            trace_vhost_iotlb_miss(dev, 3);
>              error_report("Fail to lookup the translated address "
>                           "%"PRIx64, iotlb.translated_addr);
>              goto out;
> @@ -856,10 +859,14 @@ int vhost_device_iotlb_miss(struct vhost_dev *dev, uint64_t iova, int write)
>          ret = vhost_backend_update_device_iotlb(dev, iova, uaddr,
>                                                  len, iotlb.perm);
>          if (ret) {
> +            trace_vhost_iotlb_miss(dev, 4);
>              error_report("Fail to update device iotlb");
>              goto out;
>          }
>      }
> +
> +    trace_vhost_iotlb_miss(dev, 2);
> +
>  out:
>      rcu_read_unlock();
>  
> -- 
> 2.14.3