From 635cefcdad0b9db8da1be896f85cc8af56a0efbd Mon Sep 17 00:00:00 2001 From: Gurchetan Singh Date: Fri, 4 Oct 2024 13:31:13 -0700 Subject: [PATCH] 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 Part-of: --- src/gfxstream/guest/platform/include/Sync.h | 2 ++ .../platform/kumquat/VirtGpuKumquatSync.cpp | 2 ++ .../platform/kumquat/VirtGpuKumquatSync.h | 2 ++ .../guest/platform/linux/LinuxSync.cpp | 21 +++++++++++++++++++ .../guest/platform/linux/LinuxSync.h | 2 ++ .../guest/vulkan_enc/ResourceTracker.cpp | 15 +++++++++++++ 6 files changed, 44 insertions(+) diff --git a/src/gfxstream/guest/platform/include/Sync.h b/src/gfxstream/guest/platform/include/Sync.h index 3680fee9ff5..07a0c0e9803 100644 --- a/src/gfxstream/guest/platform/include/Sync.h +++ b/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; diff --git a/src/gfxstream/guest/platform/kumquat/VirtGpuKumquatSync.cpp b/src/gfxstream/guest/platform/kumquat/VirtGpuKumquatSync.cpp index fd1f31c03e2..ee7516c5732 100644 --- a/src/gfxstream/guest/platform/kumquat/VirtGpuKumquatSync.cpp +++ b/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(); } diff --git a/src/gfxstream/guest/platform/kumquat/VirtGpuKumquatSync.h b/src/gfxstream/guest/platform/kumquat/VirtGpuKumquatSync.h index d98516e6f6b..a68ae253751 100644 --- a/src/gfxstream/guest/platform/kumquat/VirtGpuKumquatSync.h +++ b/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; diff --git a/src/gfxstream/guest/platform/linux/LinuxSync.cpp b/src/gfxstream/guest/platform/linux/LinuxSync.cpp index 8138b1ddd9e..15cf3ddafcd 100644 --- a/src/gfxstream/guest/platform/linux/LinuxSync.cpp +++ b/src/gfxstream/guest/platform/linux/LinuxSync.cpp @@ -8,6 +8,9 @@ #include #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); } diff --git a/src/gfxstream/guest/platform/linux/LinuxSync.h b/src/gfxstream/guest/platform/linux/LinuxSync.h index 1b53b23cc1b..ce7d1cffb01 100644 --- a/src/gfxstream/guest/platform/linux/LinuxSync.h +++ b/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; diff --git a/src/gfxstream/guest/vulkan_enc/ResourceTracker.cpp b/src/gfxstream/guest/vulkan_enc/ResourceTracker.cpp index 952eb4d3c67..0f181d9a996 100644 --- a/src/gfxstream/guest/vulkan_enc/ResourceTracker.cpp +++ b/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