libui: print more fence information when fence is timeout

The original log is not enough when fence is timeout. It only print
the log name and fd. It is useless to help us to check which sync
point is abnormal. Then it cause this fence can not be signaled.
Therefore we print more detail when fence is timeout.

Bug: 146024475
Test: call sleep function in SurfaceFlinger. Then check the fence log

Change-Id: I2e711bfe8f00d7723c2d8e4184e0da5e69c8fc4d

1 files changed, 20 insertions, 2 deletions

diff --git a/libs/ui/Fence.cpp b/libs/ui/Fence.cpp
index 4ce891e148..33ab7c470e 100644
--- a/libs/ui/Fence.cpp
+++ b/libs/ui/Fence.cpp
@@ -62,8 +62,26 @@ status_t Fence::waitForever(const char* logname) {
     int warningTimeout = 3000;
     int err = sync_wait(mFenceFd, warningTimeout);
     if (err < 0 && errno == ETIME) {
-        ALOGE("%s: fence %d didn't signal in %u ms", logname, mFenceFd.get(),
-                warningTimeout);
+        ALOGE("waitForever: %s: fence %d didn't signal in %u ms", logname, mFenceFd.get(),
+              warningTimeout);
+
+        struct sync_file_info* finfo = sync_file_info(mFenceFd);
+        if (finfo) {
+            // status: active(0) signaled(1) error(<0)
+            ALOGI("waitForever: fence(%s) status(%d)", finfo->name, finfo->status);
+
+            struct sync_fence_info* pinfo = sync_get_fence_info(finfo);
+            for (uint32_t i = 0; i < finfo->num_fences; i++) {
+                uint64_t ts_sec = pinfo[i].timestamp_ns / 1000000000LL;
+                uint64_t ts_usec = (pinfo[i].timestamp_ns % 1000000000LL) / 1000LL;
+
+                ALOGI("waitForever: sync point: timeline(%s) drv(%s) status(%d) timestamp(%" PRIu64
+                      ".%06" PRIu64 ")",
+                      pinfo[i].obj_name, pinfo[i].driver_name, pinfo[i].status, ts_sec, ts_usec);
+            }
+            sync_file_info_free(finfo);
+        }
+
         err = sync_wait(mFenceFd, TIMEOUT_NEVER);
     }
     return err < 0 ? -errno : status_t(NO_ERROR);