am ee5fb929: am ba607d53: Add Fence::waitForever which logs a warning timeout, and use it

* commit 'ee5fb9299b6a7d81af6c2c1e598c4e9fd71a8ba9':
  Add Fence::waitForever which logs a warning timeout, and use it

include/ui/Fence.h

@@ -62,6 +62,13 @@ public:
     // indefinitely for the fence to signal.
     int wait(unsigned int timeout);
 
+    // waitForever is a convenience function for waiting forever for a fence to
+    // signal (just like wait(TIMEOUT_NEVER)), but issuing an error to the
+    // system log and fence state to the kernel log if the wait lasts longer
+    // than warningTimeout. The logname argument should be a string identifying
+    // the caller and will be included in the log message.
+    int waitForever(unsigned int warningTimeout, const char* logname);
+
     // TIMEOUT_NEVER may be passed to the wait method to indicate that it
     // should wait indefinitely for the fence to signal.
     enum { TIMEOUT_NEVER = -1 };

libs/gui/BufferItemConsumer.cpp

@@ -63,7 +63,7 @@ status_t BufferItemConsumer::acquireBuffer(BufferItem *item, bool waitForFence)
     }
 
     if (waitForFence && item->mFence.get()) {
-        err = item->mFence->wait(Fence::TIMEOUT_NEVER);
+        err = item->mFence->waitForever(1000, "BufferItemConsumer::acquireBuffer");
         if (err != OK) {
             BI_LOGE("Failed to wait for fence of acquired buffer: %s (%d)",
                     strerror(-err), err);

libs/gui/CpuConsumer.cpp

@@ -78,7 +78,7 @@ status_t CpuConsumer::lockNextBuffer(LockedBuffer *nativeBuffer) {
     int buf = b.mBuf;
 
     if (b.mFence.get()) {
-        err = b.mFence->wait(Fence::TIMEOUT_NEVER);
+        err = b.mFence->waitForever(1000, "CpuConsumer::lockNextBuffer");
         if (err != OK) {
             CC_LOGE("Failed to wait for fence of acquired buffer: %s (%d)",
                     strerror(-err), err);

libs/gui/SurfaceTexture.cpp

@@ -812,7 +812,8 @@ status_t SurfaceTexture::doGLFenceWaitLocked() const {
                 return UNKNOWN_ERROR;
             }
         } else {
-            status_t err = mCurrentFence->wait(Fence::TIMEOUT_NEVER);
+            status_t err = mCurrentFence->waitForever(1000,
+                    "SurfaceTexture::doGLFenceWaitLocked");
             if (err != NO_ERROR) {
                 ST_LOGE("doGLFenceWait: error waiting for fence: %d", err);
                 return err;

libs/gui/SurfaceTextureClient.cpp

@@ -129,15 +129,18 @@ int SurfaceTextureClient::hook_queueBuffer(ANativeWindow* window,
 int SurfaceTextureClient::hook_dequeueBuffer_DEPRECATED(ANativeWindow* window,
         ANativeWindowBuffer** buffer) {
     SurfaceTextureClient* c = getSelf(window);
+    ANativeWindowBuffer* buf;
     int fenceFd = -1;
-    int result = c->dequeueBuffer(buffer, &fenceFd);
+    int result = c->dequeueBuffer(&buf, &fenceFd);
     sp<Fence> fence(new Fence(fenceFd));
-    int waitResult = fence->wait(Fence::TIMEOUT_NEVER);
+    int waitResult = fence->waitForever(1000, "dequeueBuffer_DEPRECATED");
     if (waitResult != OK) {
-        ALOGE("hook_dequeueBuffer_DEPRECATED: Fence::wait returned an "
+        ALOGE("dequeueBuffer_DEPRECATED: Fence::wait returned an error: %d",
-                "error: %d", waitResult);
+                waitResult);
+        c->cancelBuffer(buf, -1);
         return waitResult;
     }
+    *buffer = buf;
     return result;
 }
 
@@ -751,7 +754,7 @@ status_t SurfaceTextureClient::lock(
         sp<GraphicBuffer> backBuffer(GraphicBuffer::getSelf(out));
         sp<Fence> fence(new Fence(fenceFd));
 
-        err = fence->wait(Fence::TIMEOUT_NEVER);
+        err = fence->waitForever(1000, "SurfaceTextureClient::lock");
         if (err != OK) {
             ALOGE("Fence::wait failed (%s)", strerror(-err));
             cancelBuffer(out, fenceFd);

libs/ui/Fence.cpp

@@ -50,6 +50,20 @@ int Fence::wait(unsigned int timeout) {
     return sync_wait(mFenceFd, timeout);
 }
 
+int Fence::waitForever(unsigned int warningTimeout, const char* logname) {
+    ATRACE_CALL();
+    if (mFenceFd == -1) {
+        return NO_ERROR;
+    }
+    int err = sync_wait(mFenceFd, warningTimeout);
+    if (err == -ETIME) {
+        ALOGE("%s: fence %d didn't signal in %u ms", logname, mFenceFd,
+                warningTimeout);
+        err = sync_wait(mFenceFd, TIMEOUT_NEVER);
+    }
+    return err;
+}
+
 sp<Fence> Fence::merge(const String8& name, const sp<Fence>& f1,
         const sp<Fence>& f2) {
     ATRACE_CALL();

services/surfaceflinger/DisplayHardware/HWComposer.cpp

@@ -686,7 +686,7 @@ int HWComposer::fbPost(int32_t id,
         return setFramebufferTarget(id, acquireFence, buffer);
     } else {
         if (acquireFence != NULL) {
-            acquireFence->wait(Fence::TIMEOUT_NEVER);
+            acquireFence->waitForever(1000, "HWComposer::fbPost");
         }
         return mFbDev->post(mFbDev, buffer->handle);
     }