hwc: Check for correct screen state before enabling vsync
Sometimes vsync would not be disabled before the display is
blanked.
This was due to the vsync disable ioctl being kicked off in a
thread different from the event control which surfaceflinger
called. So, while the calls from surfaceflinger are in order, the
order of execution wasn't always the same. Hence, making sure
ioctls are called in the same context to ensure order.
Also
- Make blanking/unblanking logs show the operation as a string.
- Add a debug property to dump vsync timestamps (needs framework
reboot)
- Remove a log which showed delay in reading vsync. This log was
unreliable when vsync is disabled and we're still reading from
the sysfs node.
Change-Id: Ibec04e9ffebd0ac6e1d32b7031e3668abd9390ff
CRs-fixed: 443113
diff --git a/libhwcomposer/hwc.cpp b/libhwcomposer/hwc.cpp
index 785e66e..ae7bb95 100644
--- a/libhwcomposer/hwc.cpp
+++ b/libhwcomposer/hwc.cpp
@@ -209,22 +209,24 @@
}
static int hwc_eventControl(struct hwc_composer_device_1* dev, int dpy,
- int event, int enabled)
+ int event, int enable)
{
int ret = 0;
-
hwc_context_t* ctx = (hwc_context_t*)(dev);
private_module_t* m = reinterpret_cast<private_module_t*>(
ctx->mFbDev->common.module);
pthread_mutex_lock(&ctx->vstate.lock);
switch(event) {
case HWC_EVENT_VSYNC:
- if (ctx->vstate.enable == enabled)
+ if (ctx->vstate.enable == enable)
break;
- ctx->vstate.enable = !!enabled;
- pthread_cond_signal(&ctx->vstate.cond);
+ ret = hwc_vsync_control(ctx, dpy, enable);
+ if(ret == 0) {
+ ctx->vstate.enable = !!enable;
+ pthread_cond_signal(&ctx->vstate.cond);
+ }
ALOGD_IF (VSYNC_DEBUG, "VSYNC state changed to %s",
- (enabled)?"ENABLED":"DISABLED");
+ (enable)?"ENABLED":"DISABLED");
break;
default:
ret = -EINVAL;
@@ -241,7 +243,8 @@
ctx->mFbDev->common.module);
Locker::Autolock _l(ctx->mBlankLock);
int ret = 0;
- ALOGD("%s: Doing Dpy=%d, blank=%d", __FUNCTION__, dpy, blank);
+ ALOGD("%s: %s display: %d", __FUNCTION__,
+ blank==1 ? "Blanking":"Unblanking", dpy);
switch(dpy) {
case HWC_DISPLAY_PRIMARY:
if(blank) {
@@ -286,14 +289,16 @@
// Enable HPD here, as during bootup unblank is called
// when SF is completely initialized
ctx->mExtDisplay->setHPD(1);
-
- if(ret < 0) {
- ALOGE("%s: failed. Dpy=%d, blank=%d : %s",
- __FUNCTION__, dpy, blank, strerror(errno));
+ if(ret == 0){
+ ctx->dpyAttr[dpy].isActive = !blank;
+ } else {
+ ALOGE("%s: Failed in %s display: %d error:%s", __FUNCTION__,
+ blank==1 ? "blanking":"unblanking", dpy, strerror(errno));
return ret;
}
- ALOGD("%s: Done Dpy=%d, blank=%d", __FUNCTION__, dpy, blank);
- ctx->dpyAttr[dpy].isActive = !blank;
+
+ ALOGD("%s: Done %s display: %d", __FUNCTION__,
+ blank==1 ? "blanking":"unblanking", dpy);
return 0;
}
diff --git a/libhwcomposer/hwc_utils.cpp b/libhwcomposer/hwc_utils.cpp
index 5193644..e9446ad 100644
--- a/libhwcomposer/hwc_utils.cpp
+++ b/libhwcomposer/hwc_utils.cpp
@@ -98,6 +98,7 @@
pthread_mutex_init(&(ctx->vstate.lock), NULL);
pthread_cond_init(&(ctx->vstate.cond), NULL);
ctx->vstate.enable = false;
+ ctx->vstate.fakevsync = false;
ctx->mExtDispConfiguring = false;
//Right now hwc starts the service but anybody could do it, or it could be
diff --git a/libhwcomposer/hwc_utils.h b/libhwcomposer/hwc_utils.h
index 187c43a..de62b05 100644
--- a/libhwcomposer/hwc_utils.h
+++ b/libhwcomposer/hwc_utils.h
@@ -140,6 +140,7 @@
bool isSecureModePolicy(int mdpVersion);
bool isExternalActive(hwc_context_t* ctx);
bool needsScaling(hwc_layer_1_t const* layer);
+int hwc_vsync_control(hwc_context_t* ctx, int dpy, int enable);
//Helper function to dump logs
void dumpsys_log(android::String8& buf, const char* fmt, ...);
@@ -227,6 +228,7 @@
pthread_mutex_t lock;
pthread_cond_t cond;
bool enable;
+ bool fakevsync;
};
// -----------------------------------------------------------------------------
diff --git a/libhwcomposer/hwc_vsync.cpp b/libhwcomposer/hwc_vsync.cpp
index f83b6d7..559cd7d 100644
--- a/libhwcomposer/hwc_vsync.cpp
+++ b/libhwcomposer/hwc_vsync.cpp
@@ -18,9 +18,6 @@
* limitations under the License.
*/
-// WARNING : Excessive logging, if VSYNC_DEBUG enabled
-#define VSYNC_DEBUG 0
-
#include <cutils/properties.h>
#include <utils/Log.h>
#include <fcntl.h>
@@ -32,11 +29,23 @@
#include "string.h"
#include "external.h"
-using android::LogIfSlow;
namespace qhwc {
#define HWC_VSYNC_THREAD_NAME "hwcVsyncThread"
+int hwc_vsync_control(hwc_context_t* ctx, int dpy, int enable)
+{
+ int ret = 0;
+ if(!ctx->vstate.fakevsync &&
+ ioctl(ctx->dpyAttr[dpy].fd, MSMFB_OVERLAY_VSYNC_CTRL,
+ &enable) < 0) {
+ ALOGE("%s: vsync control failed. Dpy=%d, enable=%d : %s",
+ __FUNCTION__, dpy, enable, strerror(errno));
+ ret = -errno;
+ }
+ return ret;
+}
+
static void *vsync_loop(void *param)
{
const char* vsync_timestamp_fb0 = "/sys/class/graphics/fb0/vsync_event";
@@ -59,14 +68,17 @@
int fd_timestamp = -1;
int ret = 0;
bool fb1_vsync = false;
- bool enabled = false;
- bool fakevsync = false;
- uint32_t log_threshold = ns2ms(ctx->dpyAttr[dpy].vsync_period)*2;
+ bool logvsync = false;
char property[PROPERTY_VALUE_MAX];
if(property_get("debug.hwc.fakevsync", property, NULL) > 0) {
if(atoi(property) == 1)
- fakevsync = true;
+ ctx->vstate.fakevsync = true;
+ }
+
+ if(property_get("debug.hwc.logvsync", property, 0) > 0) {
+ if(atoi(property) == 1)
+ logvsync = true;
}
/* Currently read vsync timestamp from drivers
@@ -77,42 +89,18 @@
ALOGE ("FATAL:%s:not able to open file:%s, %s", __FUNCTION__,
(fb1_vsync) ? vsync_timestamp_fb1 : vsync_timestamp_fb0,
strerror(errno));
- fakevsync = true;
+ ctx->vstate.fakevsync = true;
}
do {
pthread_mutex_lock(&ctx->vstate.lock);
while (ctx->vstate.enable == false) {
- if(enabled) {
- int e = 0;
- if(!fakevsync &&
- ioctl(ctx->dpyAttr[dpy].fd, MSMFB_OVERLAY_VSYNC_CTRL,
- &e) < 0) {
- ALOGE("%s: vsync control failed. Dpy=%d, enabled=%d : %s",
- __FUNCTION__, dpy, enabled, strerror(errno));
- ret = -errno;
- }
- enabled = false;
- }
pthread_cond_wait(&ctx->vstate.cond, &ctx->vstate.lock);
}
pthread_mutex_unlock(&ctx->vstate.lock);
- if (!enabled) {
- int e = 1;
- if(!fakevsync &&
- ioctl(ctx->dpyAttr[dpy].fd, MSMFB_OVERLAY_VSYNC_CTRL,
- &e) < 0) {
- ALOGE("%s: vsync control failed. Dpy=%d, enabled=%d : %s",
- __FUNCTION__, dpy, enabled, strerror(errno));
- ret = -errno;
- }
- enabled = true;
- }
-
- if(!fakevsync) {
+ if (!ctx->vstate.fakevsync) {
for(int i = 0; i < MAX_RETRY_COUNT; i++) {
- ALOGD_IF_SLOW(log_threshold, "Excessive delay reading vsync");
len = pread(fd_timestamp, vdata, MAX_DATA, 0);
if(len < 0 && (errno == EAGAIN ||
errno == EINTR ||
@@ -129,7 +117,7 @@
ALOGE ("FATAL:%s:not able to read file:%s, %s", __FUNCTION__,
vsync_timestamp_fb0, strerror(errno));
close (fd_timestamp);
- fakevsync = true;
+ ctx->vstate.fakevsync = true;
}
// extract timestamp
@@ -140,7 +128,7 @@
ALOGE ("FATAL: %s: vsync timestamp not in correct format: [%s]",
__FUNCTION__,
str);
- fakevsync = true;
+ ctx->vstate.fakevsync = true;
}
} else {
@@ -148,7 +136,7 @@
cur_timestamp = systemTime();
}
// send timestamp to HAL
- ALOGD_IF (VSYNC_DEBUG, "%s: timestamp %llu sent to HWC for %s",
+ ALOGD_IF (logvsync, "%s: timestamp %llu sent to HWC for %s",
__FUNCTION__, cur_timestamp, "fb0");
ctx->proc->vsync(ctx->proc, dpy, cur_timestamp);