gfxstream: use sync_fence_info

This gives logs of the form:

[bootanimation] Fence: bbq-adapter#0(BLAST Consumer:0, status: 1, timestamp (ms): 15391

sync_merge(..) allows userspace to name the fence
and that's what's observed for in-fences.  The goal
is debug potentially long-running fences via the
use of timestamp data.

Perfetto may be used too.

Acked-by: Yonggang Luo <luoyonggang@gmail.com>
Part-of: <https://gitlab.freedesktop.org/mesa/mesa/-/merge_requests/31548>

src/gfxstream/guest/platform/include/Sync.h

@@ -17,6 +17,8 @@ class SyncHelper {
 
     virtual int wait(int syncFd, int timeoutMilliseconds) = 0;
 
+    virtual void debugPrint(int syncFd) = 0;
+
     virtual int dup(int syncFd) = 0;
 
     virtual int close(int syncFd) = 0;

src/gfxstream/guest/platform/kumquat/VirtGpuKumquatSync.cpp

@@ -34,6 +34,8 @@ int VirtGpuKumquatSyncHelper::wait(int syncFd, int timeoutMilliseconds) {
 
 int VirtGpuKumquatSyncHelper::dup(int syncFd) { return ::dup(syncFd); }
 
+void VirtGpuKumquatSyncHelper::debugPrint(int syncFd) { return; }
+
 int VirtGpuKumquatSyncHelper::close(int syncFd) { return ::close(syncFd); }
 
 SyncHelper* kumquatCreateSyncHelper() { return new VirtGpuKumquatSyncHelper(); }

src/gfxstream/guest/platform/kumquat/VirtGpuKumquatSync.h

@@ -15,6 +15,8 @@ class VirtGpuKumquatSyncHelper : public SyncHelper {
 
     int wait(int syncFd, int timeoutMilliseconds) override;
 
+    void debugPrint(int syncFd) override;
+
     int dup(int syncFd) override;
 
     int close(int syncFd) override;

src/gfxstream/guest/platform/linux/LinuxSync.cpp

@@ -8,6 +8,9 @@
 #include <unistd.h>
 
 #include "util/libsync.h"
+#include "util/log.h"
+#include "util/macros.h"
+#include "util/u_process.h"
 
 namespace gfxstream {
 
@@ -17,6 +20,24 @@ int LinuxSyncHelper::wait(int syncFd, int timeoutMilliseconds) {
     return sync_wait(syncFd, timeoutMilliseconds);
 }
 
+void LinuxSyncHelper::debugPrint(int syncFd) {
+    struct sync_file_info* info = sync_file_info(syncFd);
+    if (!info) {
+        mesa_loge("failed to get sync file info");
+        return;
+    }
+
+    struct sync_fence_info* fence_info = (struct sync_fence_info*)info->sync_fence_info;
+
+    for (uint32_t i = 0; i < info->num_fences; i++) {
+        uint64_t time_ms = DIV_ROUND_UP(fence_info[i].timestamp_ns, 1e6);
+        mesa_logi("[%s] Fence: %s, status: %i, timestamp (ms): %llu", util_get_process_name(),
+                  info->name, fence_info[i].status, (unsigned long long)time_ms);
+    }
+
+    free(info);
+}
+
 int LinuxSyncHelper::dup(int syncFd) { return ::dup(syncFd); }
 
 int LinuxSyncHelper::close(int syncFd) { return ::close(syncFd); }

src/gfxstream/guest/platform/linux/LinuxSync.h

@@ -15,6 +15,8 @@ class LinuxSyncHelper : public SyncHelper {
 
     int wait(int syncFd, int timeoutMilliseconds) override;
 
+    void debugPrint(int syncFd) override;
+
     int dup(int syncFd) override;
 
     int close(int syncFd) override;

src/gfxstream/guest/vulkan_enc/ResourceTracker.cpp

@@ -4955,6 +4955,10 @@ VkResult ResourceTracker::on_vkWaitForFences(void* context, VkResult, VkDevice d
 
         timeout -= timeTaken;
         mesa_logd("Done waiting on sync fd: %d", fd);
+
+#if GFXSTREAM_SYNC_DEBUG
+        mSyncHelper->debugPrint(fd);
+#endif
     }
 
     if (!fencesNonExternal.empty()) {
@@ -5270,6 +5274,10 @@ void ResourceTracker::on_vkDestroyImage(void* context, VkDevice device, VkImage
                     mesa_loge("%s: Failed to wait for pending QSRI sync: sterror: %s errno: %d",
                               __func__, strerror(errno), errno);
                 }
+
+#if GFXSTREAM_SYNC_DEBUG
+                mSyncHelper->debugPrint(syncFd);
+#endif
                 mSyncHelper->close(syncFd);
             }
             imageInfo.pendingQsriSyncFds.clear();
@@ -6157,6 +6165,9 @@ VkResult ResourceTracker::on_vkQueueSubmitTemplate(void* context, VkResult input
             // fd == -1 is treated as already signaled
             if (fd != -1) {
                 mSyncHelper->wait(fd, 3000);
+#if GFXSTREAM_SYNC_DEBUG
+                mSyncHelper->debugPrint(fd);
+#endif
             }
         }
 #endif
@@ -6290,6 +6301,10 @@ void ResourceTracker::unwrap_vkAcquireImageANDROID_nativeFenceFd(int fd, int* fd
         // failure, or *never* closes it on failure.
         // """
         // Therefore, assume contract where we need to close fd in this driver
+
+#if GFXSTREAM_SYNC_DEBUG
+        mSyncHelper->debugPrint(fd);
+#endif
         mSyncHelper->close(fd);
     }
 #endif