Mesa (main): venus: print warnings when stuck in busy waits

[GitLab Mirror]

Module: Mesa
Branch: main
Commit: a94192f69d1d9388ad2e27ccbdc92dccc660ee6a
URL:    http://cgit.freedesktop.org/mesa/mesa/commit/?id=a94192f69d1d9388ad2e27ccbdc92dccc660ee6a

Author: Chia-I Wu <olvaffe at gmail.com>
Date:   Wed Jul 28 11:13:38 2021 -0700

venus: print warnings when stuck in busy waits

The first warning is printed after stuck in vn_relax for at least about
3.5s.  The actual time can be much longer depending on the
kernel/load/hw.

Signed-off-by: Chia-I Wu <olvaffe at gmail.com>
Reviewed-by: Yiwei Zhang <zzyiwei at chromium.org>
Reviewed-by: Ryan Neph <ryanneph at google.com>
Part-of: <https://gitlab.freedesktop.org/mesa/mesa/-/merge_requests/12115>

---

 src/virtio/vulkan/vn_common.c | 13 ++++++++++++-
 src/virtio/vulkan/vn_common.h |  2 +-
 src/virtio/vulkan/vn_device.c |  2 +-
 src/virtio/vulkan/vn_queue.c  |  2 +-
 src/virtio/vulkan/vn_ring.c   |  4 ++--
 5 files changed, 17 insertions(+), 6 deletions(-)

diff --git a/src/virtio/vulkan/vn_common.c b/src/virtio/vulkan/vn_common.c
index 91ba2f6e9c2..e728a7971d2 100644
--- a/src/virtio/vulkan/vn_common.c
+++ b/src/virtio/vulkan/vn_common.c
@@ -62,10 +62,15 @@ vn_log_result(struct vn_instance *instance,
 }
 
 void
-vn_relax(uint32_t *iter)
+vn_relax(uint32_t *iter, const char *reason)
 {
+   /* Yield for the first 2^busy_wait_order times and then sleep for
+    * base_sleep_us microseconds for the same number of times.  After that,
+    * keep doubling both sleep length and count.
+    */
    const uint32_t busy_wait_order = 4;
    const uint32_t base_sleep_us = 10;
+   const uint32_t warn_order = 12;
 
    (*iter)++;
    if (*iter < (1 << busy_wait_order)) {
@@ -73,6 +78,12 @@ vn_relax(uint32_t *iter)
       return;
    }
 
+   /* warn occasionally if we have slept at least 1.28ms for 2048 times (plus
+    * another 2047 shorter sleeps)
+    */
+   if (unlikely(*iter % (1 << warn_order) == 0))
+      vn_log(NULL, "stuck in %s wait with iter at %d", reason, *iter);
+
    const uint32_t shift = util_last_bit(*iter) - busy_wait_order - 1;
    os_time_sleep(base_sleep_us << shift);
 }
diff --git a/src/virtio/vulkan/vn_common.h b/src/virtio/vulkan/vn_common.h
index 80780efccc2..0a357f3c6bf 100644
--- a/src/virtio/vulkan/vn_common.h
+++ b/src/virtio/vulkan/vn_common.h
@@ -133,7 +133,7 @@ vn_log_result(struct vn_instance *instance,
               const char *where);
 
 void
-vn_relax(uint32_t *iter);
+vn_relax(uint32_t *iter, const char *reason);
 
 static_assert(sizeof(vn_object_id) >= sizeof(uintptr_t), "");
 
diff --git a/src/virtio/vulkan/vn_device.c b/src/virtio/vulkan/vn_device.c
index bb9f1fc8039..d20a6c6ba04 100644
--- a/src/virtio/vulkan/vn_device.c
+++ b/src/virtio/vulkan/vn_device.c
@@ -303,7 +303,7 @@ vn_instance_wait_roundtrip(struct vn_instance *instance,
       const uint32_t cur = atomic_load_explicit(ptr, memory_order_acquire);
       if (cur >= roundtrip_seqno || roundtrip_seqno - cur >= INT32_MAX)
          break;
-      vn_relax(&iter);
+      vn_relax(&iter, "roundtrip");
    } while (true);
 }
 
diff --git a/src/virtio/vulkan/vn_queue.c b/src/virtio/vulkan/vn_queue.c
index 21aea4d0df4..26ccc9be09c 100644
--- a/src/virtio/vulkan/vn_queue.c
+++ b/src/virtio/vulkan/vn_queue.c
@@ -613,7 +613,7 @@ vn_update_sync_result(VkResult result, int64_t abs_timeout, uint32_t *iter)
           os_time_get_nano() >= abs_timeout)
          result = VK_TIMEOUT;
       else
-         vn_relax(iter);
+         vn_relax(iter, "client");
       break;
    default:
       assert(result == VK_SUCCESS || result < 0);
diff --git a/src/virtio/vulkan/vn_ring.c b/src/virtio/vulkan/vn_ring.c
index 2448836fad9..29a2884776e 100644
--- a/src/virtio/vulkan/vn_ring.c
+++ b/src/virtio/vulkan/vn_ring.c
@@ -100,7 +100,7 @@ vn_ring_wait_seqno(const struct vn_ring *ring, uint32_t seqno)
       const uint32_t head = vn_ring_load_head(ring);
       if (vn_ring_ge_seqno(ring, head, seqno))
          return head;
-      vn_relax(&iter);
+      vn_relax(&iter, "ring seqno");
    } while (true);
 }
 
@@ -115,7 +115,7 @@ vn_ring_wait_space(const struct vn_ring *ring, uint32_t size)
       const uint32_t head = vn_ring_load_head(ring);
       if (ring->cur + size - head <= VN_RING_BUFFER_SIZE)
          return head;
-      vn_relax(&iter);
+      vn_relax(&iter, "ring space");
    } while (true);
 }