/* To make sure that tpl_gsource has been successfully finalized. */
tpl_bool_t gsource_finalized;
- struct timespec last_commit;
+ double last_commit_time;
int last_commit_bo;
- struct timespec last_release;
+ double last_release_time;
int last_release_bo;
};
};
typedef enum buffer_status {
- RELEASED = 0, // 0
- DEQUEUED, // 1
- ENQUEUED, // 2
- ACQUIRED, // 3
- WAITING_SIGNALED, // 4
- SIGNALED, // 5
- WAITING_VBLANK, // 6
- VBLANK_DONE, // 7
- COMMITTED, // 8
-} buffer_status_t;
+ CREATED = 0, // 0
+ RELEASED, // 1
+ CANCELED, // 2
+ DEQUEUED, // 3
+ ENQUEUED, // 4
+ ACQUIRED, // 5
+ WAITING_SIGNALED, // 6
+ SIGNALED, // 7
+ WAITING_VBLANK, // 8
+ VBLANK_DONE, // 9
+ COMMITTED, // 10
+} buffer_status;
static struct buffer_status_info {
const char status_str[20];
uint32_t threshold_ms; /* The time limit takes to reach this status */
-} buffer_status_info[9] = {
- { "RELEASED", UINT32_MAX }, /* COMMITTED ~ RELEASE will be not traced */
- { "DEQUEUED", UINT32_MAX }, /* RELEASED ~ DEQUEUED will be not traced */
- { "ENQEUEUD", 20 },
+} buffer_status_info[11] = {
+ { "CREATED", UINT32_MAX }, /* CREATED status will be not checked elapsed */
+ { "RELEASED", UINT32_MAX }, /* COMMITTED ~ RELEASE will be not checked elapsed */
+ { "CANCELED", 20 },
+ { "DEQUEUED", UINT32_MAX }, /* RELEASED ~ DEQUEUED will be not checked elapsed */
+ { "ENQUEUED", 20 },
{ "ACQUIRED", 10 },
{ "WAIT_SIG", 10 },
{ "SIGNALED", 20 },
int dx, dy; /* position to attach to wl_surface */
int width, height; /* size to attach to wl_surface */
- buffer_status_t status; /* for tracing buffer status */
+ buffer_status status; /* for tracing buffer status */
+ double changed_time; /* the time when buffer status changed */
/* for damage region */
int num_rects;
tpl_gcond cond;
tpl_wl_egl_surface_t *wl_egl_surface;
-
- struct timespec begin;
- buffer_status_t begin_status;
};
#if TIZEN_FEATURE_ENABLE
#define RELEASE_FROM_LAST_COMMIT 20
#define DEQUEUE_FROM_LAST_RELEASE 20
-static long
-_cal_time_gap(struct timespec begin, struct timespec end)
+static double
+_timespec_to_double(struct timespec *ts)
{
- long gap_ms = 1000 * (end.tv_sec - begin.tv_sec);
- gap_ms = gap_ms + ((end.tv_nsec/1000000) - (begin.tv_nsec/1000000));
- return gap_ms;
+ double sec = (double)ts->tv_sec + ((double)(ts->tv_nsec))/1e9;
+ sec = roundf(sec * 1000) / 1000;
+ return sec;
}
-static void
-_elapsed_between_status(tpl_wl_egl_buffer_t *wl_egl_buffer, long threshold)
+static double
+_get_current_time()
{
- struct timespec end;
- clock_gettime(CLOCK_MONOTONIC, &end);
- long gap = _cal_time_gap(wl_egl_buffer->begin, end);
- if (wl_egl_buffer->begin_status != COMMITTED && gap > threshold) {
- TPL_ERR("bo_name(%d) | %s ~ %s | takes too long time %ld > %ld",
- wl_egl_buffer->bo_name,
- buffer_status_info[wl_egl_buffer->begin_status].status_str,
- buffer_status_info[wl_egl_buffer->status].status_str,
- gap, threshold);
- }
- wl_egl_buffer->begin.tv_sec = end.tv_sec;
- wl_egl_buffer->begin.tv_nsec = end.tv_nsec;
- wl_egl_buffer->begin_status = wl_egl_buffer->status;
+ struct timespec current;
+ clock_gettime(CLOCK_MONOTONIC, ¤t);
+ return _timespec_to_double(¤t);
}
+static uint32_t
+_cal_time_gap_ms(double begin, double end)
+{
+ uint32_t gap_ms = (uint32_t)((end - begin) * 1000);
+ return gap_ms;
+ }
+
static void
-_elapsed_from_last_commit(tpl_wl_egl_surface_t *wl_egl_surface, int bo_name)
+_elapsed_between_status(tpl_wl_egl_buffer_t *wl_egl_buffer,
+ buffer_status cur_status,
+ double cur_time)
{
- struct timespec release;
- clock_gettime(CLOCK_MONOTONIC, &release);
- long gap = _cal_time_gap(wl_egl_surface->last_commit, release);
- if (gap > RELEASE_FROM_LAST_COMMIT) {
- TPL_ERR("last COMMIT(%d) ~ RELEASE(%d) | takes too long time %ld > %d",
- wl_egl_surface->last_commit_bo, bo_name,
- gap, RELEASE_FROM_LAST_COMMIT);
+ uint32_t gap_ms = _cal_time_gap_ms(wl_egl_buffer->changed_time, cur_time);
+
+ buffer_status prev_status = wl_egl_buffer->status;
+ uint32_t threshold = buffer_status_info[cur_status].threshold_ms;
+
+ if (gap_ms > threshold) {
+ TPL_ERR("bo(%d)|%s~%s|takes too long time %u>%u",
+ wl_egl_buffer->bo_name,
+ buffer_status_info[prev_status].status_str,
+ buffer_status_info[cur_status].status_str,
+ gap_ms, threshold);
+ /* print Recorded Time Per Buffer Status */
+ TPL_ERR("%s(%.3lf) ~ %s(%.3lf)",
+ buffer_status_info[prev_status].status_str, wl_egl_buffer->changed_time,
+ buffer_status_info[cur_status].status_str, cur_time);
}
}
static void
-_update_last_commit_time(tpl_wl_egl_surface_t *wl_egl_surface)
+_elapsed_since_last_commit(tpl_wl_egl_surface_t *wl_egl_surface,
+ int bo_name,
+ double cur_time)
{
- struct timespec commit;
- clock_gettime(CLOCK_MONOTONIC, &commit);
- wl_egl_surface->last_commit.tv_sec = commit.tv_sec;
- wl_egl_surface->last_commit.tv_nsec = commit.tv_nsec;
+ uint32_t gap_ms = _cal_time_gap_ms(wl_egl_surface->last_commit_time, cur_time);
+ if (gap_ms > RELEASE_FROM_LAST_COMMIT) {
+ TPL_ERR("LAST_COMMIT(%d)~RELEASE(%d)|takes too long time|%u>%u",
+ wl_egl_surface->last_commit_bo, bo_name,
+ gap_ms, RELEASE_FROM_LAST_COMMIT);
+ TPL_ERR("%s(%.3lf) ~ %s(%.3lf)",
+ "L_COMMIT", wl_egl_surface->last_commit_time,
+ "RELEASE", cur_time);
+ }
}
static void
-_elapsed_from_last_release(tpl_wl_egl_surface_t *wl_egl_surface, int bo_name)
+_elapsed_since_last_release(tpl_wl_egl_surface_t *wl_egl_surface,
+ int bo_name,
+ double cur_time)
{
- struct timespec dequeue;
- clock_gettime(CLOCK_MONOTONIC, &dequeue);
- long gap = _cal_time_gap(wl_egl_surface->last_release, dequeue);
- if (gap > RELEASE_FROM_LAST_COMMIT) {
- TPL_ERR("last RELEASE(%d) ~ DEQUEUE(%d) | takes too long time %ld > %d",
+ uint32_t gap_ms = _cal_time_gap_ms(wl_egl_surface->last_release_time, cur_time);
+ if (gap_ms > DEQUEUE_FROM_LAST_RELEASE) {
+ TPL_ERR("LAST_RELEASE(%d)~DEQUEUE(%d)|takes too long time|%u>%u",
wl_egl_surface->last_release_bo, bo_name,
- gap, DEQUEUE_FROM_LAST_RELEASE);
+ gap_ms, DEQUEUE_FROM_LAST_RELEASE);
+ TPL_ERR("%s(%.3lf) ~ %s(%.3lf)",
+ "L_RELEASE", wl_egl_surface->last_release_time,
+ "DEQUEUE", cur_time);
}
}
static void
-_update_last_release_time(tpl_wl_egl_surface_t *wl_egl_surface)
+_update_buffer_status(tpl_wl_egl_buffer_t *wl_egl_buffer, buffer_status status)
{
- struct timespec release;
- clock_gettime(CLOCK_MONOTONIC, &release);
- wl_egl_surface->last_release.tv_sec = release.tv_sec;
- wl_egl_surface->last_release.tv_nsec = release.tv_nsec;
+ tpl_wl_egl_surface_t *wl_egl_surface = wl_egl_buffer->wl_egl_surface;
+ double current_time = _get_current_time();
+
+ switch (status)
+ {
+ case CREATED:
+ /* do nothing */
+ break;
+
+ case RELEASED:
+ _elapsed_since_last_commit(wl_egl_surface, wl_egl_buffer->bo_name, current_time);
+ wl_egl_surface->last_release_time = current_time;
+ wl_egl_surface->last_release_bo = wl_egl_buffer->bo_name;
+ break;
+
+ case DEQUEUED:
+ /* calculate the time elapsed since the last release
+ * only if it is not a newly created buffer */
+ if (wl_egl_buffer->wl_buffer != NULL)
+ _elapsed_since_last_release(wl_egl_surface, wl_egl_buffer->bo_name, current_time);
+ break;
+
+ case COMMITTED:
+ _elapsed_between_status(wl_egl_buffer, status, current_time);
+ wl_egl_surface->last_commit_time = current_time;
+ wl_egl_surface->last_commit_bo = wl_egl_buffer->bo_name;
+ break;
+
+ default:
+ _elapsed_between_status(wl_egl_buffer, status, current_time);
+ break;
+ }
+
+ wl_egl_buffer->status = status;
+ wl_egl_buffer->changed_time = current_time;
}
static struct tizen_private *
wl_egl_surface->buffers = __tpl_list_alloc();
- _update_last_release_time(wl_egl_surface);
wl_egl_surface->last_release_bo = -1;
+ wl_egl_surface->last_release_time = 0.0;
{
struct tizen_private *tizen_private = wl_egl_tizen_get_tizen_private(wl_egl_window);
tpl_wl_egl_buffer_t wl_egl_buffer(__tpl_list_node_get_data(node));
tpl_gmutex_lock(&wl_egl_buffer->mutex);
- buffer_status_t status = wl_egl_buffer->status;
+ buffer_status status = wl_egl_buffer->status;
if (status == RELEASED) {
tpl_gmutex_unlock(&wl_egl_buffer->mutex);
wl_egl_buffer->tbm_surface, tsq_err);
}
- wl_egl_buffer->status = RELEASED;
+ _update_buffer_status(wl_egl_buffer, RELEASED);
TPL_INFO("[FORCE_RELEASE]", "wl_egl_buffer(%p) status(%s -> %s)",
wl_egl_buffer,
tpl_wl_egl_buffer_t wl_egl_buffer(__tpl_list_node_get_data(node));
tpl_gmutex_lock(&wl_egl_buffer->mutex);
- buffer_status_t status = wl_egl_buffer->status;
+ buffer_status status = wl_egl_buffer->status;
- if (status == RELEASED) {
+ if (status == CREATED ||
+ status == RELEASED ||
+ status == CANCELED) {
tpl_gmutex_unlock(&wl_egl_buffer->mutex);
continue;
}
buffer_status_info[status].status_str,
buffer_status_info[RELEASED].status_str);
- wl_egl_buffer->status = RELEASED;
+ _update_buffer_status(wl_egl_buffer, RELEASED);
tpl_gmutex_unlock(&wl_egl_buffer->mutex);
wl_egl_buffer->bo_name = _get_tbm_surface_bo_name(tbm_surface);
wl_egl_buffer->wl_egl_surface = wl_egl_surface;
- wl_egl_buffer->status = RELEASED;
- wl_egl_buffer->begin_status = wl_egl_buffer->status;
- clock_gettime(CLOCK_MONOTONIC, &wl_egl_buffer->begin);
+ _update_buffer_status(wl_egl_buffer, CREATED);
wl_egl_buffer->acquire_fence_fd = -1;
wl_egl_buffer->commit_sync_fd = -1;
TPL_CHECK_ON_FALSE_ASSERT_FAIL(wl_egl_buffer, "Failed to create/get wl_egl_buffer.");
tpl_gmutex_lock(&wl_egl_buffer->mutex);
- wl_egl_buffer->status = DEQUEUED;
- _elapsed_between_status(wl_egl_buffer, buffer_status_info[wl_egl_buffer->status].threshold_ms);
- _elapsed_from_last_release(wl_egl_surface, wl_egl_buffer->bo_name);
+ _update_buffer_status(wl_egl_buffer, DEQUEUED);
/* If wl_egl_buffer->release_fence_fd is -1,
* the tbm_surface can be used immediately.
wl_egl_buffer = _get_wl_egl_buffer(tbm_surface);
if (wl_egl_buffer) {
tpl_gmutex_lock(&wl_egl_buffer->mutex);
- wl_egl_buffer->status = RELEASED;
- _elapsed_between_status(wl_egl_buffer, buffer_status_info[wl_egl_buffer->status].threshold_ms);
+ _update_buffer_status(wl_egl_buffer, CANCELED);
tpl_gmutex_unlock(&wl_egl_buffer->mutex);
}
}
tpl_gmutex_unlock(&wl_egl_surface->commit_sync.mutex);
- wl_egl_buffer->status = ENQUEUED;
- _elapsed_between_status(wl_egl_buffer, buffer_status_info[wl_egl_buffer->status].threshold_ms);
+ _update_buffer_status(wl_egl_buffer, ENQUEUED);
+
TPL_LOG_T("WL_EGL",
"[ENQ] wl_egl_buffer(%p) tbm_surface(%p) bo(%d) fence(%d)",
wl_egl_buffer, tbm_surface, bo_name, acquire_fence);
tpl_gmutex_lock(&wl_egl_surface->surf_mutex);
tpl_gmutex_lock(&wl_egl_buffer->mutex);
- wl_egl_buffer->status = SIGNALED;
- _elapsed_between_status(wl_egl_buffer, buffer_status_info[wl_egl_buffer->status].threshold_ms);
+ _update_buffer_status(wl_egl_buffer, SIGNALED);
TPL_LOG_D("[FINALIZE]", "wl_egl_surface(%p) wl_egl_buffer(%p) wait_source(%p) fence_fd(%d)",
wl_egl_surface, wl_egl_buffer, wl_egl_buffer->waiting_source,
if (!wl_egl_surface->vblank_enable || wl_egl_surface->vblank_done) {
_thread_wl_surface_commit(wl_egl_surface, wl_egl_buffer);
} else {
- wl_egl_buffer->status = WAITING_VBLANK;
+ _update_buffer_status(wl_egl_buffer, WAITING_VBLANK);
tpl_gmutex_lock(&wl_egl_surface->vblank->mutex);
__tpl_list_push_back(wl_egl_surface->vblank->waiting_buffers,
wl_egl_buffer);
tpl_gmutex_lock(&wl_egl_buffer->mutex);
- wl_egl_buffer->status = ACQUIRED;
- _elapsed_between_status(wl_egl_buffer, buffer_status_info[wl_egl_buffer->status].threshold_ms);
+ _update_buffer_status(wl_egl_buffer, ACQUIRED);
TPL_LOG_T("WL_EGL", "[ACQ] wl_egl_buffer(%p) tbm_surface(%p) bo(%d)",
wl_egl_buffer, tbm_surface,
wl_egl_buffer->acquire_fence_fd,
FD_TYPE_FENCE, &buffer_funcs,
SOURCE_TYPE_DISPOSABLE);
- wl_egl_buffer->status = WAITING_SIGNALED;
- _elapsed_between_status(wl_egl_buffer, buffer_status_info[wl_egl_buffer->status].threshold_ms);
+ _update_buffer_status(wl_egl_buffer, WAITING_SIGNALED);
TRACE_ASYNC_BEGIN(wl_egl_buffer->acquire_fence_fd, "FENCE WAIT fd(%d)",
wl_egl_buffer->acquire_fence_fd);
if (!wl_egl_surface->vblank_enable || wl_egl_surface->vblank_done)
ready_to_commit = TPL_TRUE;
else {
- wl_egl_buffer->status = WAITING_VBLANK;
- _elapsed_between_status(wl_egl_buffer, buffer_status_info[wl_egl_buffer->status].threshold_ms);
+ _update_buffer_status(wl_egl_buffer, WAITING_VBLANK);
tpl_gmutex_lock(&wl_egl_surface->vblank->mutex);
__tpl_list_push_back(wl_egl_surface->vblank->waiting_buffers, wl_egl_buffer);
tpl_gmutex_unlock(&wl_egl_surface->vblank->mutex);
if (!wl_egl_buffer) break;
tpl_gmutex_lock(&wl_egl_buffer->mutex);
- wl_egl_buffer->status = VBLANK_DONE;
- _elapsed_between_status(wl_egl_buffer, buffer_status_info[wl_egl_buffer->status].threshold_ms);
+ _update_buffer_status(wl_egl_buffer, VBLANK_DONE);
_thread_wl_surface_commit(wl_egl_surface, wl_egl_buffer);
tpl_gmutex_unlock(&wl_egl_buffer->mutex);
zwp_linux_buffer_release_v1_destroy(wl_egl_buffer->buffer_release);
wl_egl_buffer->buffer_release = NULL;
-
wl_egl_buffer->release_fence_fd = fence;
- wl_egl_buffer->status = RELEASED;
- _elapsed_between_status(wl_egl_buffer, buffer_status_info[wl_egl_buffer->status].threshold_ms);
- wl_egl_surface->last_release_bo = wl_egl_buffer->bo_name;
- _elapsed_from_last_commit(wl_egl_surface, wl_egl_buffer->bo_name);
- _update_last_release_time(wl_egl_surface);
+
+ _update_buffer_status(wl_egl_buffer, RELEASED);
TRACE_MARK("[FENCED_RELEASE] BO(%d) fence(%d)",
_get_tbm_surface_bo_name(tbm_surface),
zwp_linux_buffer_release_v1_destroy(wl_egl_buffer->buffer_release);
wl_egl_buffer->buffer_release = NULL;
-
wl_egl_buffer->release_fence_fd = -1;
- wl_egl_buffer->status = RELEASED;
- _elapsed_between_status(wl_egl_buffer, buffer_status_info[wl_egl_buffer->status].threshold_ms);
- wl_egl_surface->last_release_bo = wl_egl_buffer->bo_name;
- _elapsed_from_last_commit(wl_egl_surface, wl_egl_buffer->bo_name);
- _update_last_release_time(wl_egl_surface);
+
+ _update_buffer_status(wl_egl_buffer, RELEASED);
TRACE_MARK("[IMMEDIATE_RELEASE] BO(%d)",
_get_tbm_surface_bo_name(tbm_surface));
if (tsq_err != TBM_SURFACE_QUEUE_ERROR_NONE)
TPL_ERR("tbm_surface(%p) tsq_err(%d)", tbm_surface, tsq_err);
- wl_egl_buffer->status = RELEASED;
- _elapsed_between_status(wl_egl_buffer, buffer_status_info[wl_egl_buffer->status].threshold_ms);
- wl_egl_surface->last_release_bo = wl_egl_buffer->bo_name;
- _elapsed_from_last_commit(wl_egl_surface, wl_egl_buffer->bo_name);
- _update_last_release_time(wl_egl_surface);
+ _update_buffer_status(wl_egl_buffer, RELEASED);
TRACE_MARK("[RELEASE] BO(%d)", _get_tbm_surface_bo_name(tbm_surface));
TRACE_ASYNC_END((intptr_t)tbm_surface, "[COMMIT ~ RELEASE] BO(%d)",
wl_egl_buffer->bo_name);
wl_egl_buffer->need_to_commit = TPL_FALSE;
- wl_egl_buffer->status = COMMITTED;
- _elapsed_between_status(wl_egl_buffer, buffer_status_info[wl_egl_buffer->status].threshold_ms);
- _update_last_commit_time(wl_egl_surface);
- wl_egl_surface->last_commit_bo = wl_egl_buffer->bo_name;
+ _update_buffer_status(wl_egl_buffer, COMMITTED);
TPL_LOG_T("WL_EGL",
"[COMMIT] wl_egl_buffer(%p) wl_buffer(%p) tbm_surface(%p) bo(%d)",