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 <[email protected]> Signed-Off-By Xiaoyanx Zhang <[email protected]> --- 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 _______________________________________________ wayland-devel mailing list [email protected] http://lists.freedesktop.org/mailman/listinfo/wayland-devel
