[PATCH] weston: Add weston rendering performance log
Quanxian Wang
quanxian.wang at intel.com
Fri Feb 6 01:52:06 PST 2015
With PERF_DEBUG is enabled, the performance log will be recorded
for every key rendering path.
At the same time, with a tool provided, performance chart of weston apps
could be generated.
This patch provides following changes.
1) Add performance log mechanism for server and client.
just like weston_log, weston_plog is used for performance log.
2) Touch performance log is added to monitor touch performance.
3) Some weston native apps performance logs are added.
For example weston-simple-egl, weston-terminal
Performance Anaylis Tools source code is located:
https://github.com/quanxianwang/wr-graph.git
Related tools wiki:
https://wiki.tizen.org/wiki/Wayland_Rendering_Analysis_Tool
Signed-Off-By Quanxian Wang <quanxian.wang at intel.com>
Signed-Off-By Xiaoyanx Zhang <xiaoyanx.zhang at intel.com>
---
clients/perf_log_client.h | 51 ++++++++++++++++++++++++++++++++++++++++++++++
clients/simple-egl.c | 6 ++++++
clients/window.c | 5 +++++
desktop-shell/shell.c | 12 ++++++++---
desktop-shell/shell.h | 1 -
src/compositor.c | 8 ++++++++
src/input.c | 52 +++++++++++++++++++++++++++++++++++++++++++----
src/log.c | 23 ++++++++++++++++++++-
src/perf_log_server.h | 38 ++++++++++++++++++++++++++++++++++
9 files changed, 187 insertions(+), 9 deletions(-)
create mode 100644 clients/perf_log_client.h
create mode 100644 src/perf_log_server.h
diff --git a/clients/perf_log_client.h b/clients/perf_log_client.h
new file mode 100644
index 0000000..919a4c3
--- /dev/null
+++ b/clients/perf_log_client.h
@@ -0,0 +1,51 @@
+#ifndef __PERF_LOG__
+#define __PERF_LOG__
+#include <wayland-client.h>
+#include <time.h>
+#include <stdio.h>
+#include <sys/time.h>
+
+static const char *flag_str[4] = {"start", "end", "id", "point"};
+
+enum PERF_FLAG {
+ PERF_START,
+ PERF_END,
+ PERF_ID,
+ PERF_POINT
+};
+
+#define PERF_LOG(msg, flag) \
+ do { \
+ struct timeval tv; \
+ struct tm *brokendown_time;\
+ char string[128];\
+ gettimeofday(&tv, NULL);\
+ brokendown_time = localtime(&tv.tv_sec);\
+ strftime(string, sizeof(string),\
+ "%H:%M:%S", brokendown_time);\
+ fprintf(stderr, "[%s.%06li] perf_%s:%s\n",\
+ string, tv.tv_usec, flag_str[flag], msg); \
+ } while (0)
+
+inline void
+print_plog(struct wl_proxy *proxy, const char *msg, int flag)
+{
+ char str[32] = {};
+ uint32_t id;
+
+ if (proxy)
+ id = wl_proxy_get_id(proxy);
+ else {
+ PERF_LOG(msg, flag);
+ return;
+ }
+
+ if (msg)
+ sprintf(str, "%s_%d", msg, id);
+ else
+ sprintf(str, "%d", id);
+
+ PERF_LOG(str, flag);
+}
+
+#endif
diff --git a/clients/simple-egl.c b/clients/simple-egl.c
index d3c205f..0450373 100644
--- a/clients/simple-egl.c
+++ b/clients/simple-egl.c
@@ -39,6 +39,7 @@
#include <GLES2/gl2.h>
#include <EGL/egl.h>
#include <EGL/eglext.h>
+#include "perf_log_client.h"
#include "xdg-shell-client-protocol.h"
#include <sys/types.h>
@@ -486,6 +487,9 @@ redraw(void *data, struct wl_callback *callback, uint32_t time)
eglQuerySurface(display->egl.dpy, window->egl_surface,
EGL_BUFFER_AGE_EXT, &buffer_age);
+ print_plog((struct wl_proxy *)window->surface, "client", PERF_START);
+ print_plog((struct wl_proxy *)window->surface, NULL, PERF_ID);
+
glViewport(0, 0, window->geometry.width, window->geometry.height);
glUniformMatrix4fv(window->gl.rotation_uniform, 1, GL_FALSE,
@@ -515,6 +519,8 @@ redraw(void *data, struct wl_callback *callback, uint32_t time)
wl_surface_set_opaque_region(window->surface, NULL);
}
+ print_plog((struct wl_proxy *)window->surface, "client", PERF_END);
+
if (display->swap_buffers_with_damage && buffer_age > 0) {
rect[0] = window->geometry.width / 4 - 1;
rect[1] = window->geometry.height / 4 - 1;
diff --git a/clients/window.c b/clients/window.c
index c5082ba..6b8e883 100644
--- a/clients/window.c
+++ b/clients/window.c
@@ -71,6 +71,7 @@ typedef void *EGLContext;
#include "../shared/os-compatibility.h"
#include "window.h"
+#include "perf_log_client.h"
#include <sys/types.h>
#include "ivi-application-client-protocol.h"
@@ -2393,6 +2394,10 @@ frame_handle_status(struct window_frame *frame, struct input *input,
if ((status & FRAME_STATUS_MOVE) && window->xdg_surface) {
input_ungrab(input);
+
+ print_plog((struct wl_proxy *)window->main_surface->surface,
+ "client process", PERF_END);
+
xdg_surface_move(window->xdg_surface,
input_get_seat(input),
window->display->serial);
diff --git a/desktop-shell/shell.c b/desktop-shell/shell.c
index 26cadb6..65607c6 100644
--- a/desktop-shell/shell.c
+++ b/desktop-shell/shell.c
@@ -39,6 +39,7 @@
#include "workspaces-server-protocol.h"
#include "../shared/config-parser.h"
#include "xdg-shell-server-protocol.h"
+#include "perf_log_server.h"
#define DEFAULT_NUM_WORKSPACES 1
#define DEFAULT_WORKSPACE_CHANGE_ANIMATION_LENGTH 200
@@ -542,9 +543,6 @@ shell_touch_grab_start(struct shell_touch_grab *grab,
shsurf->grabbed = 1;
weston_touch_start_grab(touch, &grab->grab);
- if (shell->child.desktop_shell)
- weston_touch_set_focus(touch->seat,
- get_default_view(shell->grab_surface));
}
static void
@@ -1563,6 +1561,8 @@ touch_move_grab_down(struct weston_touch_grab *grab, uint32_t time,
static void
touch_move_grab_up(struct weston_touch_grab *grab, uint32_t time, int touch_id)
{
+ print_plog(grab->touch->focus->surface->resource,
+ "shell touch up", PERF_START);
struct weston_touch_move_grab *move =
(struct weston_touch_move_grab *) container_of(
grab, struct shell_touch_grab, grab);
@@ -1574,6 +1574,8 @@ touch_move_grab_up(struct weston_touch_grab *grab, uint32_t time, int touch_id)
shell_touch_grab_end(&move->base);
free(move);
}
+ print_plog(grab->touch->focus->surface->resource,
+ "shell touch up", PERF_END);
}
static void
@@ -1582,6 +1584,8 @@ touch_move_grab_motion(struct weston_touch_grab *grab, uint32_t time,
{
struct weston_touch_move_grab *move = (struct weston_touch_move_grab *) grab;
struct shell_surface *shsurf = move->base.shsurf;
+ print_plog(grab->touch->focus->surface->resource,
+ "shell touch motion", PERF_START);
struct weston_surface *es;
int dx = wl_fixed_to_int(grab->touch->grab_x + move->dx);
int dy = wl_fixed_to_int(grab->touch->grab_y + move->dy);
@@ -1594,6 +1598,8 @@ touch_move_grab_motion(struct weston_touch_grab *grab, uint32_t time,
weston_view_set_position(shsurf->view, dx, dy);
weston_compositor_schedule_repaint(es->compositor);
+ print_plog(grab->touch->focus->surface->resource,
+ "shell touch motion", PERF_END);
}
static void
diff --git a/desktop-shell/shell.h b/desktop-shell/shell.h
index 2cfd1d6..c8ce943 100644
--- a/desktop-shell/shell.h
+++ b/desktop-shell/shell.h
@@ -26,7 +26,6 @@
#include <time.h>
#include "compositor.h"
-
#include "desktop-shell-server-protocol.h"
enum animation_type {
diff --git a/src/compositor.c b/src/compositor.c
index c2c975d..200821f 100644
--- a/src/compositor.c
+++ b/src/compositor.c
@@ -61,6 +61,7 @@
#include "../shared/os-compatibility.h"
#include "git-version.h"
#include "version.h"
+#include "perf_log_server.h"
static struct wl_list child_process_list;
static struct weston_compositor *segv_compositor;
@@ -2044,6 +2045,7 @@ weston_output_repaint(struct weston_output *output)
TL_POINT("core_repaint_begin", TLP_OUTPUT(output), TLP_END);
+ PERF_LOG("weston", PERF_START);
/* Rebuild the surface list and update surface transforms up front. */
weston_compositor_build_view_list(ec);
@@ -2088,6 +2090,8 @@ weston_output_repaint(struct weston_output *output)
output->repaint_needed = 0;
weston_compositor_repick(ec);
+ PERF_LOG("weston", PERF_END);
+ PERF_LOG("graphic hardware", PERF_START);
wl_event_loop_dispatch(ec->input_loop, 0);
wl_list_for_each_safe(cb, cnext, &frame_callback_list, link) {
@@ -2126,6 +2130,7 @@ weston_output_finish_frame(struct weston_output *output,
int fd, r;
uint32_t refresh_nsec;
+ PERF_LOG("graphic hardware", PERF_END);
TL_POINT("core_repaint_finished", TLP_OUTPUT(output),
TLP_VBLANK(stamp), TLP_END);
@@ -2472,6 +2477,8 @@ surface_commit(struct wl_client *client, struct wl_resource *resource)
struct weston_surface *surface = wl_resource_get_user_data(resource);
struct weston_subsurface *sub = weston_surface_to_subsurface(surface);
+ print_plog(resource, "client process", PERF_END);
+ print_plog(resource, "wcommit", PERF_START);
if (sub) {
weston_subsurface_commit(sub);
return;
@@ -2483,6 +2490,7 @@ surface_commit(struct wl_client *client, struct wl_resource *resource)
if (sub->surface != surface)
weston_subsurface_parent_commit(sub, 0);
}
+ print_plog(resource, "wcommit", PERF_END);
}
static void
diff --git a/src/input.c b/src/input.c
index c039af0..d317573 100644
--- a/src/input.c
+++ b/src/input.c
@@ -33,6 +33,7 @@
#include "../shared/os-compatibility.h"
#include "compositor.h"
+#include "perf_log_server.h"
static void
empty_region(pixman_region32_t *region)
@@ -244,10 +245,15 @@ default_grab_touch_down(struct weston_touch_grab *grab, uint32_t time,
if (!wl_list_empty(resource_list) && touch->focus) {
serial = wl_display_next_serial(display);
- wl_resource_for_each(resource, resource_list)
- wl_touch_send_down(resource, serial, time,
+ wl_resource_for_each(resource, resource_list) {
+ wl_touch_send_down(resource, serial, time,
touch->focus->surface->resource,
touch_id, sx, sy);
+ print_plog(touch->focus->surface->resource,
+ "touch down", PERF_END);
+ print_plog(touch->focus->surface->resource,
+ "client process", PERF_START);
+ }
}
}
@@ -265,8 +271,13 @@ default_grab_touch_up(struct weston_touch_grab *grab,
if (!wl_list_empty(resource_list)) {
serial = wl_display_next_serial(display);
- wl_resource_for_each(resource, resource_list)
+ wl_resource_for_each(resource, resource_list) {
wl_touch_send_up(resource, serial, time, touch_id);
+ print_plog(touch->focus->surface->resource,
+ "touch up", PERF_END);
+ print_plog(touch->focus->surface->resource,
+ "client process", PERF_START);
+ }
}
}
@@ -283,6 +294,10 @@ default_grab_touch_motion(struct weston_touch_grab *grab, uint32_t time,
wl_resource_for_each(resource, resource_list) {
wl_touch_send_motion(resource, time,
touch_id, sx, sy);
+ print_plog(touch->focus->surface->resource,
+ "touch motion", PERF_END);
+ print_plog(touch->focus->surface->resource,
+ "client process", PERF_START);
}
}
@@ -1474,6 +1489,7 @@ weston_touch_set_focus(struct weston_seat *seat, struct weston_view *view)
return;
}
+ print_plog(view->surface->resource, NULL, PERF_ID);
surface_client = wl_resource_get_client(view->surface->resource);
move_resources_for_client(focus_resource_list,
&seat->touch->resource_list,
@@ -1511,6 +1527,11 @@ notify_touch(struct weston_seat *seat, uint32_t time, int touch_id,
switch (touch_type) {
case WL_TOUCH_DOWN:
+ if (touch->focus) {
+ print_plog(touch->focus->surface->resource,
+ "touch hardware down", PERF_START);
+ } else
+ print_plog(NULL, "touch hardware down", PERF_START);
weston_compositor_idle_inhibit(ec);
touch->num_tp++;
@@ -1536,6 +1557,11 @@ notify_touch(struct weston_seat *seat, uint32_t time, int touch_id,
weston_compositor_run_touch_binding(ec, seat,
time, touch_type);
+ print_plog(touch->focus->surface->resource,
+ "touch hardware down", PERF_END);
+ print_plog(touch->focus->surface->resource,
+ "touch down", PERF_START);
+
grab->interface->down(grab, time, touch_id, sx, sy);
if (touch->num_tp == 1) {
touch->grab_serial =
@@ -1552,10 +1578,21 @@ notify_touch(struct weston_seat *seat, uint32_t time, int touch_id,
if (!ev)
break;
+ print_plog(touch->focus->surface->resource,
+ "touch hardware motion", PERF_START);
+
weston_view_from_global_fixed(ev, x, y, &sx, &sy);
+
+ print_plog(touch->focus->surface->resource,
+ "touch hardware motion", PERF_END);
+ print_plog(touch->focus->surface->resource,
+ "touch motion", PERF_START);
+
grab->interface->motion(grab, time, touch_id, sx, sy);
break;
case WL_TOUCH_UP:
+ print_plog(touch->focus->surface->resource,
+ "touch hardware up", PERF_START);
if (touch->num_tp == 0) {
/* This can happen if we start out with one or
* more fingers on the touch screen, in which
@@ -1567,9 +1604,16 @@ notify_touch(struct weston_seat *seat, uint32_t time, int touch_id,
weston_compositor_idle_release(ec);
touch->num_tp--;
+ print_plog(touch->focus->surface->resource,
+ "touch hardware up", PERF_END);
+ print_plog(touch->focus->surface->resource,
+ "touch up", PERF_START);
+
grab->interface->up(grab, time, touch_id);
- if (touch->num_tp == 0)
+ if (touch->num_tp == 0) {
+ print_plog(NULL, "touch end", PERF_POINT);
weston_touch_set_focus(seat, NULL);
+ }
break;
}
}
diff --git a/src/log.c b/src/log.c
index 99bbe18..117181b 100644
--- a/src/log.c
+++ b/src/log.c
@@ -35,6 +35,8 @@
static FILE *weston_logfile = NULL;
+static int perf_debug = 0;
+
static int cached_tm_mday = -1;
static int weston_log_timestamp(void)
@@ -58,7 +60,7 @@ static int weston_log_timestamp(void)
strftime(string, sizeof string, "%H:%M:%S", brokendown_time);
- return fprintf(weston_logfile, "[%s.%03li] ", string, tv.tv_usec/1000);
+ return fprintf(weston_logfile, "[%s.%06li] ", string, tv.tv_usec);
}
static void
@@ -72,10 +74,15 @@ custom_handler(const char *fmt, va_list arg)
void
weston_log_file_open(const char *filename)
{
+ const char *debug;
+
wl_log_set_handler_server(custom_handler);
if (filename != NULL)
weston_logfile = fopen(filename, "a");
+ debug = getenv("PERF_DEBUG");
+ if (debug && strstr(debug, "1"))
+ perf_debug = 1;
if (weston_logfile == NULL)
weston_logfile = stderr;
@@ -116,6 +123,20 @@ weston_log(const char *fmt, ...)
}
WL_EXPORT int
+weston_plog(const char *fmt, ...)
+{
+ int l;
+ va_list argp;
+ if (perf_debug) {
+ va_start(argp, fmt);
+ l = weston_vlog(fmt, argp);
+ va_end(argp);
+ }
+
+ return l;
+}
+
+WL_EXPORT int
weston_vlog_continue(const char *fmt, va_list argp)
{
return vfprintf(weston_logfile, fmt, argp);
diff --git a/src/perf_log_server.h b/src/perf_log_server.h
new file mode 100644
index 0000000..740c97a
--- /dev/null
+++ b/src/perf_log_server.h
@@ -0,0 +1,38 @@
+#ifndef __PERF_LOG__
+#define __PERF_LOG__
+#include "compositor.h"
+
+static const char *flag_str[4] = {"start", "end", "id", "point"};
+
+enum PERF_FLAG {
+ PERF_START,
+ PERF_END,
+ PERF_ID,
+ PERF_POINT
+};
+
+#define PERF_LOG(msg, flag) \
+ weston_plog("perf_%s:%s\n", flag_str[flag], msg);
+
+static inline void
+print_plog(struct wl_resource *resource, const char *msg, int flag)
+{
+ char str[32] = {};
+ uint32_t id;
+
+ if (resource)
+ id = wl_resource_get_id(resource);
+ else {
+ PERF_LOG(msg, flag);
+ return;
+ }
+
+ if (msg)
+ sprintf(str, "%s_%d", msg, id);
+ else
+ sprintf(str, "%d", id);
+
+ PERF_LOG(str, flag);
+}
+
+#endif
--
1.8.1.2
More information about the wayland-devel
mailing list