weston/libweston/timeline.c

/*
 * Copyright © 2014 Pekka Paalanen <pq@iki.fi>
 * Copyright © 2014, 2019 Collabora, Ltd.
 *
 * Permission is hereby granted, free of charge, to any person obtaining
 * a copy of this software and associated documentation files (the
 * "Software"), to deal in the Software without restriction, including
 * without limitation the rights to use, copy, modify, merge, publish,
 * distribute, sublicense, and/or sell copies of the Software, and to
 * permit persons to whom the Software is furnished to do so, subject to
 * the following conditions:
 *
 * The above copyright notice and this permission notice (including the
 * next paragraph) shall be included in all copies or substantial
 * portions of the Software.
 *
 * THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
 * EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
 * MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND
 * NONINFRINGEMENT.  IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS
 * BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN
 * ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN
 * CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
 * SOFTWARE.
 */

#include "config.h"

#include <stdio.h>
#include <errno.h>
#include <string.h>
#include <time.h>
#include <assert.h>

#include <libweston/libweston.h>
#include <libweston/weston-log.h>
#include "timeline.h"
#include "weston-log-internal.h"

struct timeline_emit_context {
	FILE *cur;
	struct weston_log_subscription *subscription;
};

/** Create a timeline subscription and hang it off the subscription
 *
 * Called when the subscription is created.
 *
 * @ingroup internal-log
 */
void
weston_timeline_create_subscription(struct weston_log_subscription *sub,
		void *user_data)
{
	struct weston_timeline_subscription *tl_sub = zalloc(sizeof(*tl_sub));
	if (!tl_sub)
		return;

	wl_list_init(&tl_sub->objects);

	/* attach this timeline_subscription to it */
	weston_log_subscription_set_data(sub, tl_sub);
}

static void
weston_timeline_destroy_subscription_object(struct weston_timeline_subscription_object *sub_obj)
{
	/* remove the notify listener */
	wl_list_remove(&sub_obj->destroy_listener.link);
	sub_obj->destroy_listener.notify = NULL;

	wl_list_remove(&sub_obj->subscription_link);
	free(sub_obj);
}

/** Destroy the timeline subscription and all timeline subscription objects
 * associated with it.
 *
 * Called when (before) the subscription is destroyed.
 *
 * @ingroup internal-log
 */
void
weston_timeline_destroy_subscription(struct weston_log_subscription *sub,
				     void *user_data)
{
	struct weston_timeline_subscription *tl_sub =
		weston_log_subscription_get_data(sub);
	struct weston_timeline_subscription_object *sub_obj, *tmp_sub_obj;

	if (!tl_sub)
		return;

	wl_list_for_each_safe(sub_obj, tmp_sub_obj,
			      &tl_sub->objects, subscription_link)
		weston_timeline_destroy_subscription_object(sub_obj);

	free(tl_sub);
}

static bool
weston_timeline_check_object_refresh(struct weston_timeline_subscription_object *obj)
{
	if (obj->force_refresh == true) {
		obj->force_refresh = false;
		return true;
	}
	return false;
}

static struct weston_timeline_subscription_object *
weston_timeline_subscription_search(struct weston_timeline_subscription *tl_sub,
				    void *object)
{
	struct weston_timeline_subscription_object *sub_obj;

	wl_list_for_each(sub_obj, &tl_sub->objects, subscription_link)
		if (sub_obj->object == object)
			return sub_obj;

	return NULL;
}

static struct weston_timeline_subscription_object *
weston_timeline_subscription_object_create(void *object,
					   struct weston_timeline_subscription *tm_sub)
{
	struct weston_timeline_subscription_object *sub_obj;

	sub_obj = zalloc(sizeof(*sub_obj));
	sub_obj->id = ++tm_sub->next_id;
	sub_obj->object = object;

	/* when the object is created so that it has the chance to display the
	 * object ID, we set the refresh status; it will only be re-freshed by
	 * the backend (or part parts) when the underlying objects has suffered
	 * modifications */
	sub_obj->force_refresh = true;

	wl_list_insert(&tm_sub->objects, &sub_obj->subscription_link);

	return sub_obj;
}

static void
weston_timeline_destroy_subscription_object_notify(struct wl_listener *listener, void *data)
{
	struct weston_timeline_subscription_object *sub_obj;

	sub_obj = wl_container_of(listener, sub_obj, destroy_listener);
	weston_timeline_destroy_subscription_object(sub_obj);
}

static struct weston_timeline_subscription_object *
weston_timeline_subscription_output_ensure(struct weston_timeline_subscription *tl_sub,
		struct weston_output *output)
{
	struct weston_timeline_subscription_object *sub_obj;

	sub_obj = weston_timeline_subscription_search(tl_sub, output);
	if (!sub_obj) {
		sub_obj = weston_timeline_subscription_object_create(output, tl_sub);

		sub_obj->destroy_listener.notify =
			weston_timeline_destroy_subscription_object_notify;
		wl_signal_add(&output->destroy_signal,
			      &sub_obj->destroy_listener);
	}
	return sub_obj;
}

static struct weston_timeline_subscription_object *
weston_timeline_subscription_surface_ensure(struct weston_timeline_subscription *tl_sub,
		struct weston_surface *surface)
{
	struct weston_timeline_subscription_object *sub_obj;

	sub_obj = weston_timeline_subscription_search(tl_sub, surface);
	if (!sub_obj) {
		sub_obj = weston_timeline_subscription_object_create(surface, tl_sub);

		sub_obj->destroy_listener.notify =
			weston_timeline_destroy_subscription_object_notify;
		wl_signal_add(&surface->destroy_signal,
			      &sub_obj->destroy_listener);
	}

	return sub_obj;
}

static void
fprint_quoted_string(struct weston_log_subscription *sub, const char *str)
{
	if (!str) {
		weston_log_subscription_printf(sub, "null");
		return;
	}

	weston_log_subscription_printf(sub, "\"%s\"", str);
}

static void
emit_weston_output_print_id(struct weston_log_subscription *sub,
			    struct weston_timeline_subscription_object *sub_obj,
			    const char *name)
{
	if (!weston_timeline_check_object_refresh(sub_obj))
		return;

	weston_log_subscription_printf(sub, "{ \"id\":%u, "
			"\"type\":\"weston_output\", \"name\":", sub_obj->id);
	fprint_quoted_string(sub, name);
	weston_log_subscription_printf(sub, " }\n");
}

static int
emit_weston_output(struct timeline_emit_context *ctx, void *obj)
{
	struct weston_log_subscription *sub = ctx->subscription;
	struct weston_output *output = obj;
	struct weston_timeline_subscription_object *sub_obj;
	struct weston_timeline_subscription *tl_sub;

	tl_sub = weston_log_subscription_get_data(sub);
	sub_obj = weston_timeline_subscription_output_ensure(tl_sub, output);
	emit_weston_output_print_id(sub, sub_obj, output->name);

	assert(sub_obj->id != 0);
	fprintf(ctx->cur, "\"wo\":%u", sub_obj->id);

	return 1;
}


static void
check_weston_surface_description(struct weston_log_subscription *sub,
				 struct weston_surface *s,
				 struct weston_timeline_subscription *tm_sub,
				 struct weston_timeline_subscription_object *sub_obj)
{
	struct weston_surface *mains;
	char d[512];
	char mainstr[32];

	if (!weston_timeline_check_object_refresh(sub_obj))
		return;

	mains = weston_surface_get_main_surface(s);
	if (mains != s) {
		struct weston_timeline_subscription_object *new_sub_obj;

		new_sub_obj = weston_timeline_subscription_surface_ensure(tm_sub, mains);
		check_weston_surface_description(sub, mains, tm_sub, new_sub_obj);
		if (snprintf(mainstr, sizeof(mainstr), ", \"main_surface\":%u",
			     new_sub_obj->id) < 0)
			mainstr[0] = '\0';
	} else {
		mainstr[0] = '\0';
	}

	if (!s->get_label || s->get_label(s, d, sizeof(d)) < 0)
		d[0] = '\0';

	weston_log_subscription_printf(sub, "{ \"id\":%u, "
				       "\"type\":\"weston_surface\", \"desc\":",
				       sub_obj->id);
	fprint_quoted_string(sub, d[0] ? d : NULL);
	weston_log_subscription_printf(sub, "%s }\n", mainstr);
}

static int
emit_weston_surface(struct timeline_emit_context *ctx, void *obj)
{
	struct weston_log_subscription *sub = ctx->subscription;
	struct weston_surface *surface = obj;
	struct weston_timeline_subscription_object *sub_obj;
	struct weston_timeline_subscription *tl_sub;

	tl_sub = weston_log_subscription_get_data(sub);
	sub_obj = weston_timeline_subscription_surface_ensure(tl_sub, surface);
	check_weston_surface_description(sub, surface, tl_sub, sub_obj);

	assert(sub_obj->id != 0);
	fprintf(ctx->cur, "\"ws\":%u", sub_obj->id);

	return 1;
}

static int
emit_vblank_timestamp(struct timeline_emit_context *ctx, void *obj)
{
	struct timespec *ts = obj;

	fprintf(ctx->cur, "\"vblank\":[%" PRId64 ", %ld]",
		(int64_t)ts->tv_sec, ts->tv_nsec);

	return 1;
}

static int
emit_gpu_timestamp(struct timeline_emit_context *ctx, void *obj)
{
	struct timespec *ts = obj;

	fprintf(ctx->cur, "\"gpu\":[%" PRId64 ", %ld]",
		(int64_t)ts->tv_sec, ts->tv_nsec);

	return 1;
}

typedef int (*type_func)(struct timeline_emit_context *ctx, void *obj);

static const type_func type_dispatch[] = {
	[TLT_OUTPUT] = emit_weston_output,
	[TLT_SURFACE] = emit_weston_surface,
	[TLT_VBLANK] = emit_vblank_timestamp,
	[TLT_GPU] = emit_gpu_timestamp,
};

WL_EXPORT void
weston_timeline_point(struct weston_log_scope *timeline_scope,
		      const char *name, ...)
{
	struct timespec ts;
	enum timeline_type otype;
	void *obj;
	char buf[512];
	struct weston_log_subscription *sub = NULL;

	if (!weston_log_scope_is_enabled(timeline_scope))
		return;

	clock_gettime(CLOCK_MONOTONIC, &ts);

	while ((sub = weston_log_subscription_iterate(timeline_scope, sub))) {
		va_list argp;
		struct timeline_emit_context ctx = {};

		memset(buf, 0, sizeof(buf));
		ctx.cur = fmemopen(buf, sizeof(buf), "w");
		ctx.subscription = sub;

		if (!ctx.cur) {
			weston_log("Timeline error in fmemopen, closing.\n");
			return;
		}

		fprintf(ctx.cur, "{ \"T\":[%" PRId64 ", %ld], \"N\":\"%s\"",
				(int64_t)ts.tv_sec, ts.tv_nsec, name);

		va_start(argp, name);
		while (1) {
			otype = va_arg(argp, enum timeline_type);
			if (otype == TLT_END)
				break;

			obj = va_arg(argp, void *);
			if (type_dispatch[otype]) {
				fprintf(ctx.cur, ", ");
				type_dispatch[otype](&ctx, obj);
			}
		}
		va_end(argp);

		fprintf(ctx.cur, " }\n");
		fflush(ctx.cur);
		if (ferror(ctx.cur)) {
			weston_log("Timeline error in constructing entry, closing.\n");
		} else {
			weston_log_subscription_printf(ctx.subscription, "%s", buf);
		}

		fclose(ctx.cur);

	}
}