[weston,v5,14/14] compositor-drm: Add drm-backend log debug scope

Submitted by Daniel Stone on July 20, 2018, 7:03 p.m.

Details

Message ID 20180720190335.23880-15-daniels@collabora.com
State Superseded
Headers show
Series "weston-debug API and tool" ( rev: 2 1 ) in Wayland

Not browsing as part of any series.

Commit Message

Daniel Stone July 20, 2018, 7:03 p.m.
Add a 'drm-debug' scope which prints verbose information about the DRM
backend's repaint cycle, including the decision tree on how views are
assigned (or not) to planes.

Signed-off-by: Daniel Stone <daniels@collabora.com>
---
 libweston/compositor-drm.c | 233 ++++++++++++++++++++++++++++++++-----
 1 file changed, 206 insertions(+), 27 deletions(-)

Patch hide | download patch | download mbox

diff --git a/libweston/compositor-drm.c b/libweston/compositor-drm.c
index 653d13e0c..2cadf036c 100644
--- a/libweston/compositor-drm.c
+++ b/libweston/compositor-drm.c
@@ -51,6 +51,7 @@ 
 
 #include "compositor.h"
 #include "compositor-drm.h"
+#include "weston-debug.h"
 #include "shared/helpers.h"
 #include "shared/timespec-util.h"
 #include "gl-renderer.h"
@@ -73,6 +74,9 @@ 
 #define GBM_BO_USE_CURSOR GBM_BO_USE_CURSOR_64X64
 #endif
 
+#define drm_debug(b, ...) \
+	weston_debug_scope_printf((b)->debug, __VA_ARGS__)
+
 #define MAX_CLONED_CONNECTORS 4
 
 /**
@@ -302,6 +306,8 @@  struct drm_backend {
 	bool shutting_down;
 
 	bool aspect_ratio_supported;
+
+	struct weston_debug_scope *debug;
 };
 
 struct drm_mode {
@@ -2358,6 +2364,9 @@  crtc_add_prop(drmModeAtomicReq *req, struct drm_output *output,
 
 	ret = drmModeAtomicAddProperty(req, output->crtc_id, info->prop_id,
 				       val);
+	drm_debug(output->backend, "\t\t\t[CRTC:%d] %d (%s) -> %lld (0x%llx)\n",
+		  output->crtc_id, info->prop_id, info->name,
+		  (unsigned long long) val, (unsigned long long) val);
 	return (ret <= 0) ? -1 : 0;
 }
 
@@ -2373,6 +2382,9 @@  connector_add_prop(drmModeAtomicReq *req, struct drm_head *head,
 
 	ret = drmModeAtomicAddProperty(req, head->connector_id,
 				       info->prop_id, val);
+	drm_debug(head->backend, "\t\t\t[CONN:%d] %d (%s) -> %lld (0x%llx)\n",
+		  head->connector_id, info->prop_id, info->name,
+		  (unsigned long long) val, (unsigned long long) val);
 	return (ret <= 0) ? -1 : 0;
 }
 
@@ -2388,6 +2400,9 @@  plane_add_prop(drmModeAtomicReq *req, struct drm_plane *plane,
 
 	ret = drmModeAtomicAddProperty(req, plane->plane_id, info->prop_id,
 				       val);
+	drm_debug(plane->backend, "\t\t\t[PLANE:%d] %d (%s) -> %lld (0x%llx)\n",
+		  plane->plane_id, info->prop_id, info->name,
+		  (unsigned long long) val, (unsigned long long) val);
 	return (ret <= 0) ? -1 : 0;
 }
 
@@ -2406,6 +2421,9 @@  drm_mode_ensure_blob(struct drm_backend *backend, struct drm_mode *mode)
 	if (ret != 0)
 		weston_log("failed to create mode property blob: %m\n");
 
+	drm_debug(backend, "\t\t\t[atomic] created new mode blob %ld for %s",
+		  (unsigned long) mode->blob_id, mode->mode_info.name);
+
 	return ret;
 }
 
@@ -2415,17 +2433,23 @@  drm_output_apply_state_atomic(struct drm_output_state *state,
 			      uint32_t *flags)
 {
 	struct drm_output *output = state->output;
-	struct drm_backend *backend = to_drm_backend(output->base.compositor);
+	struct drm_backend *b = to_drm_backend(output->base.compositor);
 	struct drm_plane_state *plane_state;
 	struct drm_mode *current_mode = to_drm_mode(output->base.current_mode);
 	struct drm_head *head;
 	int ret = 0;
 
-	if (state->dpms != output->state_cur->dpms)
+	drm_debug(b, "\t\t[atomic] %s output %d (%s) state\n",
+		  (*flags & DRM_MODE_ATOMIC_TEST_ONLY) ? "testing" : "applying",
+		  output->base.id, output->base.name);
+
+	if (state->dpms != output->state_cur->dpms) {
+		drm_debug(b, "\t\t\t[atomic] DPMS state differs, modeset OK\n");
 		*flags |= DRM_MODE_ATOMIC_ALLOW_MODESET;
+	}
 
 	if (state->dpms == WESTON_DPMS_ON) {
-		ret = drm_mode_ensure_blob(backend, current_mode);
+		ret = drm_mode_ensure_blob(b, current_mode);
 		if (ret != 0)
 			return ret;
 
@@ -2523,6 +2547,9 @@  drm_pending_state_apply_atomic(struct drm_pending_state *pending_state,
 		uint32_t *unused;
 		int err;
 
+		drm_debug(b, "\t\t[atomic] previous state invalid; "
+			     "starting with fresh state\n");
+
 		/* If we need to reset all our state (e.g. because we've
 		 * just started, or just been VT-switched in), explicitly
 		 * disable all the CRTCs and connectors we aren't using. */
@@ -2535,9 +2562,14 @@  drm_pending_state_apply_atomic(struct drm_pending_state *pending_state,
 
 			head = to_drm_head(head_base);
 
+			drm_debug(b, "\t\t[atomic] disabling inactive head %s\n",
+				  head_base->name);
+
 			info = &head->props_conn[WDRM_CONNECTOR_CRTC_ID];
 			err = drmModeAtomicAddProperty(req, head->connector_id,
 						       info->prop_id, 0);
+			drm_debug(b, "\t\t\t[CONN:%d] %d (%s) -> 0\n",
+				  head->connector_id, info->prop_id, info->name);
 			if (err <= 0)
 				ret = -1;
 		}
@@ -2574,12 +2606,19 @@  drm_pending_state_apply_atomic(struct drm_pending_state *pending_state,
 				continue;
 			}
 
+			drm_debug(b, "\t\t[atomic] disabling unused CRTC %d\n",
+				  *unused);
+
+			drm_debug(b, "\t\t\t[CRTC:%d] %d (%s) -> 0\n",
+				  *unused, info->prop_id, info->name);
 			err = drmModeAtomicAddProperty(req, *unused,
 						       info->prop_id, 0);
 			if (err <= 0)
 				ret = -1;
 
 			info = &infos[WDRM_CRTC_MODE_ID];
+			drm_debug(b, "\t\t\t[CRTC:%d] %d (%s) -> 0\n",
+				  *unused, info->prop_id, info->name);
 			err = drmModeAtomicAddProperty(req, *unused,
 						       info->prop_id, 0);
 			if (err <= 0)
@@ -2591,6 +2630,8 @@  drm_pending_state_apply_atomic(struct drm_pending_state *pending_state,
 		/* Disable all the planes; planes which are being used will
 		 * override this state in the output-state application. */
 		wl_list_for_each(plane, &b->plane_list, link) {
+			drm_debug(b, "\t\t[atomic] starting with plane %d disabled\n",
+				  plane->plane_id);
 			plane_add_prop(req, plane, WDRM_PLANE_CRTC_ID, 0);
 			plane_add_prop(req, plane, WDRM_PLANE_FB_ID, 0);
 		}
@@ -2969,10 +3010,15 @@  drm_repaint_begin(struct weston_compositor *compositor)
 {
 	struct drm_backend *b = to_drm_backend(compositor);
 	struct drm_pending_state *ret;
+	char *scene_graph = weston_compositor_print_scene_graph(compositor);
 
 	ret = drm_pending_state_alloc(b);
 	b->repaint_data = ret;
 
+	drm_debug(b, "[repaint] Beignning repaint; pending_state %p\n", ret);
+	drm_debug(b, "%s", scene_graph);
+	free(scene_graph);
+
 	return ret;
 }
 
@@ -2992,6 +3038,7 @@  drm_repaint_flush(struct weston_compositor *compositor, void *repaint_data)
 	struct drm_pending_state *pending_state = repaint_data;
 
 	drm_pending_state_apply(pending_state);
+	drm_debug(b, "[repaint] flushed pending_state %p\n", pending_state);
 	b->repaint_data = NULL;
 }
 
@@ -3008,6 +3055,7 @@  drm_repaint_cancel(struct weston_compositor *compositor, void *repaint_data)
 	struct drm_pending_state *pending_state = repaint_data;
 
 	drm_pending_state_free(pending_state);
+	drm_debug(b, "[repaint] cancel pending_state %p\n", pending_state);
 	b->repaint_data = NULL;
 }
 
@@ -3051,12 +3099,21 @@  drm_output_prepare_overlay_view(struct drm_output_state *output_state,
 	struct drm_fb *fb;
 	unsigned int i;
 	int ret;
+	enum {
+		NO_PLANES,
+		NO_PLANES_WITH_FORMAT,
+		NO_PLANES_ACCEPTED,
+		PLACED_ON_PLANE,
+	} availability = NO_PLANES;
 
 	assert(!b->sprites_are_broken);
 
 	fb = drm_fb_get_from_view(output_state, ev);
-	if (!fb)
+	if (!fb) {
+		drm_debug(b, "\t\t\t\t[overlay] not placing view %p on overlay: "
+		 	     " couldn't get fb\n", ev);
 		return NULL;
+	}
 
 	wl_list_for_each(p, &b->plane_list, link) {
 		if (p->type != WDRM_PLANE_TYPE_OVERLAY)
@@ -3065,6 +3122,15 @@  drm_output_prepare_overlay_view(struct drm_output_state *output_state,
 		if (!drm_plane_is_available(p, output))
 			continue;
 
+		state = drm_output_state_get_plane(output_state, p);
+		if (state->fb) {
+			state = NULL;
+			continue;
+		}
+
+		if (availability == NO_PLANES)
+			availability = NO_PLANES_WITH_FORMAT;
+
 		/* Check whether the format is supported */
 		for (i = 0; i < p->count_formats; i++) {
 			unsigned int j;
@@ -3085,15 +3151,14 @@  drm_output_prepare_overlay_view(struct drm_output_state *output_state,
 		if (i == p->count_formats)
 			continue;
 
-		state = drm_output_state_get_plane(output_state, p);
-		if (state->fb) {
-			state = NULL;
-			continue;
-		}
+		if (availability == NO_PLANES_WITH_FORMAT)
+			availability = NO_PLANES_ACCEPTED;
 
 		state->ev = ev;
 		state->output = output;
 		if (!drm_plane_state_coords_for_view(state, ev)) {
+			drm_debug(b, "\t\t\t\t[overlay] not placing view %p on overlay: "
+			 	     "unsuitable transform\n", ev);
 			drm_plane_state_put_back(state);
 			state = NULL;
 			continue;
@@ -3101,6 +3166,8 @@  drm_output_prepare_overlay_view(struct drm_output_state *output_state,
 		if (!b->atomic_modeset &&
 		    (state->src_w != state->dest_w << 16 ||
 		     state->src_h != state->dest_h << 16)) {
+			drm_debug(b, "\t\t\t\t[overlay] not placing view %p on overlay: "
+			 	     "no scaling without atomic\n", ev);
 			drm_plane_state_put_back(state);
 			state = NULL;
 			continue;
@@ -3114,17 +3181,48 @@  drm_output_prepare_overlay_view(struct drm_output_state *output_state,
 
 		/* In planes-only mode, we don't have an incremental state to
 		 * test against, so we just hope it'll work. */
-		if (mode == DRM_OUTPUT_PROPOSE_STATE_PLANES_ONLY)
+		if (mode == DRM_OUTPUT_PROPOSE_STATE_PLANES_ONLY) {
+			drm_debug(b, "\t\t\t\t[overlay] provisionally placing "
+				     "view %p on overlay %d in planes-only mode\n",
+			  	  ev, p->plane_id);
+			availability = PLACED_ON_PLANE;
 			goto out;
+		}
 
 		ret = drm_pending_state_test(output_state->pending_state);
-		if (ret == 0)
+		if (ret == 0) {
+			drm_debug(b, "\t\t\t\t[overlay] provisionally placing "
+				     "view %p on overlay %d in mixed mode\n",
+			  	  ev, p->plane_id);
+			availability = PLACED_ON_PLANE;
 			goto out;
+		}
+
+		drm_debug(b, "\t\t\t\t[overlay] not placing view %p on overlay %d "
+			     "in mixed mode: kernel test failed\n",
+			  ev, p->plane_id);
 
 		drm_plane_state_put_back(state);
 		state = NULL;
 	}
 
+	switch (availability) {
+	case NO_PLANES:
+		drm_debug(b, "\t\t\t\t[overlay] not placing view %p on overlay: "
+			     "no free overlay planes\n", ev);
+		break;
+	case NO_PLANES_WITH_FORMAT:
+		drm_debug(b, "\t\t\t\t[overlay] not placing view %p on overlay: "
+			     "no free overlay planes matching format 0x%lx, "
+			     "modifier 0x%llx\n",
+			  ev, (unsigned long) fb->format,
+		  	  (unsigned long long) fb->modifier);
+		break;
+	case NO_PLANES_ACCEPTED:
+	case PLACED_ON_PLANE:
+		break;
+	}
+
 out:
 	drm_fb_unref(fb);
 	return state;
@@ -3193,13 +3291,23 @@  drm_output_prepare_cursor_view(struct drm_output_state *output_state,
 	if (b->gbm == NULL)
 		return NULL;
 
-	if (ev->surface->buffer_ref.buffer == NULL)
+	if (ev->surface->buffer_ref.buffer == NULL) {
+		drm_debug(b, "\t\t\t\t[cursor] not assigning view %p to cursor plane "
+			     "(no buffer available)\n", ev);
 		return NULL;
+	}
 	shmbuf = wl_shm_buffer_get(ev->surface->buffer_ref.buffer->resource);
-	if (!shmbuf)
+	if (!shmbuf) {
+		drm_debug(b, "\t\t\t\t[cursor] not assigning view %p to cursor plane "
+			     "(buffer isn't SHM)\n", ev);
 		return NULL;
-	if (wl_shm_buffer_get_format(shmbuf) != WL_SHM_FORMAT_ARGB8888)
+	}
+	if (wl_shm_buffer_get_format(shmbuf) != WL_SHM_FORMAT_ARGB8888) {
+		drm_debug(b, "\t\t\t\t[cursor] not assigning view %p to cursor plane "
+			     "(format 0x%lx unsuitable)\n",
+			  ev, (unsigned long) wl_shm_buffer_get_format(shmbuf));
 		return NULL;
+	}
 
 	plane_state =
 		drm_output_state_get_plane(output_state, output->cursor_plane);
@@ -3217,8 +3325,11 @@  drm_output_prepare_cursor_view(struct drm_output_state *output_state,
 	    plane_state->src_w > (unsigned) b->cursor_width << 16 ||
 	    plane_state->src_h > (unsigned) b->cursor_height << 16 ||
 	    plane_state->src_w != plane_state->dest_w << 16 ||
-	    plane_state->src_h != plane_state->dest_h << 16)
+	    plane_state->src_h != plane_state->dest_h << 16) {
+		drm_debug(b, "\t\t\t\t[cursor] not assigning view %p to cursor plane "
+			     "(positioning requires cropping or scaling)\n", ev);
 		goto err;
+	}
 
 	/* Since we're setting plane state up front, we need to work out
 	 * whether or not we need to upload a new cursor. We can't use the
@@ -3241,8 +3352,10 @@  drm_output_prepare_cursor_view(struct drm_output_state *output_state,
 	plane_state->fb =
 		drm_fb_ref(output->gbm_cursor_fb[output->current_cursor]);
 
-	if (needs_update)
+	if (needs_update) {
+		drm_debug(b, "\t\t\t\t[cursor] copying new content to cursor BO\n");
 		cursor_bo_update(plane_state, ev);
+	}
 
 	/* The cursor API is somewhat special: in cursor_bo_update(), we upload
 	 * a buffer which is always cursor_width x cursor_height, even if the
@@ -3253,6 +3366,9 @@  drm_output_prepare_cursor_view(struct drm_output_state *output_state,
 	plane_state->dest_w = b->cursor_width;
 	plane_state->dest_h = b->cursor_height;
 
+	drm_debug(b, "\t\t\t\t[cursor] provisionally assigned view %p to cursor\n",
+		  ev);
+
 	return plane_state;
 
 err:
@@ -3348,18 +3464,29 @@  drm_output_propose_state(struct weston_output *output_base,
 		if (!scanout_fb ||
 		    (scanout_fb->type != BUFFER_GBM_SURFACE &&
 		     scanout_fb->type != BUFFER_PIXMAN_DUMB)) {
+			drm_debug(b, "\t\t[state] cannot propose mixed mode: "
+			             "for output %s (%d): no previous renderer "
+			             "fb\n",
+				  output->base.name, output->base.id);
 			drm_output_state_free(state);
 			return NULL;
 		}
 
 		if (scanout_fb->width != output_base->current_mode->width ||
 		    scanout_fb->height != output_base->current_mode->height) {
+			drm_debug(b, "\t\t[state] cannot propose mixed mode "
+			             "for output %s (%d): previous fb has "
+				     "different size\n",
+				  output->base.name, output->base.id);
 			drm_output_state_free(state);
 			return NULL;
 		}
 
 		scanout_state = drm_plane_state_duplicate(state,
 							  plane->state_cur);
+		drm_debug(b, "\t\t[state] using renderer FB ID %d for mixed "
+			     "mode for output %s (%d)\n",
+			  scanout_fb->fb_id, output->base.name, output->base.id);
 	}
 
 	/*
@@ -3385,18 +3512,31 @@  drm_output_propose_state(struct weston_output *output_base,
 		bool totally_occluded = false;
 		bool overlay_occluded = false;
 
+		drm_debug(b, "\t\t\t[view] evaluating view %p for "
+		             "output %s (%d)\n",
+		          ev, output->base.name, output->base.id);
+
 		/* If this view doesn't touch our output at all, there's no
 		 * reason to do anything with it. */
-		if (!(ev->output_mask & (1u << output->base.id)))
+		if (!(ev->output_mask & (1u << output->base.id))) {
+			drm_debug(b, "\t\t\t\t[view] ignoring view %p "
+			             "(not on our output)\n", ev);
 			continue;
+		}
 
 		/* We only assign planes to views which are exclusively present
 		 * on our output. */
-		if (ev->output_mask != (1u << output->base.id))
+		if (ev->output_mask != (1u << output->base.id)) {
+			drm_debug(b, "\t\t\t\t[view] not assigning view %p to plane "
+			             "(on multiple outputs)\n", ev);
 			force_renderer = true;
+		}
 
-		if (!ev->surface->buffer_ref.buffer)
+		if (!ev->surface->buffer_ref.buffer) {
+			drm_debug(b, "\t\t\t\t[view] not assigning view %p to plane "
+			             "(no buffer available)\n", ev);
 			force_renderer = true;
+		}
 
 		/* Ignore views we know to be totally occluded. */
 		pixman_region32_init(&clipped_view);
@@ -3409,6 +3549,8 @@  drm_output_propose_state(struct weston_output *output_base,
 					 &occluded_region);
 		totally_occluded = !pixman_region32_not_empty(&surface_overlap);
 		if (totally_occluded) {
+			drm_debug(b, "\t\t\t\t[view] ignoring view %p "
+			             "(occluded on our output)\n", ev);
 			pixman_region32_fini(&surface_overlap);
 			pixman_region32_fini(&clipped_view);
 			continue;
@@ -3419,8 +3561,11 @@  drm_output_propose_state(struct weston_output *output_base,
 		 * be part of, or occluded by, it, and cannot go on a plane. */
 		pixman_region32_intersect(&surface_overlap, &renderer_region,
 					  &clipped_view);
-		if (pixman_region32_not_empty(&surface_overlap))
+		if (pixman_region32_not_empty(&surface_overlap)) {
+			drm_debug(b, "\t\t\t\t[view] not assigning view %p to plane "
+			             "(occluded by renderer views)\n", ev);
 			force_renderer = true;
+		}
 
 		/* We do not control the stacking order of overlay planes;
 		 * the scanout plane is strictly stacked bottom and the cursor
@@ -3429,8 +3574,11 @@  drm_output_propose_state(struct weston_output *output_base,
 		 * planes overlapping each other. */
 		pixman_region32_intersect(&surface_overlap, &occluded_region,
 					  &clipped_view);
-		if (pixman_region32_not_empty(&surface_overlap))
+		if (pixman_region32_not_empty(&surface_overlap)) {
+			drm_debug(b, "\t\t\t\t[view] not assigning view %p to plane "
+			             "(occluded by other overlay planes)\n", ev);
 			overlay_occluded = true;
+		}
 		pixman_region32_fini(&surface_overlap);
 
 		/* The cursor plane is 'special' in the sense that we can still
@@ -3442,10 +3590,16 @@  drm_output_propose_state(struct weston_output *output_base,
 		/* If sprites are disabled or the view is not fully opaque, we
 		 * must put the view into the renderer - unless it has already
 		 * been placed in the cursor plane, which can handle alpha. */
-		if (!ps && !planes_ok)
+		if (!ps && !planes_ok) {
+			drm_debug(b, "\t\t\t\t[view] not assigning view %p to plane "
+			             "(precluded by mode)\n", ev);
 			force_renderer = true;
-		if (!ps && !drm_view_is_opaque(ev))
+		}
+		if (!ps && !drm_view_is_opaque(ev)) {
+			drm_debug(b, "\t\t\t\t[view] not assigning view %p to plane "
+			             "(view not fully opaque)\n", ev);
 			force_renderer = true;
+		}
 
 		/* Only try to place scanout surfaces in planes-only mode; in
 		 * mixed mode, we have already failed to place a view on the
@@ -3478,6 +3632,9 @@  drm_output_propose_state(struct weston_output *output_base,
 		 * check if this is OK, and add ourselves to the renderer
 		 * region if so. */
 		if (!renderer_ok) {
+			drm_debug(b, "\t\t[view] failing state generation: "
+				      "placing view %p to renderer not allowed\n",
+				  ev);
 			pixman_region32_fini(&clipped_view);
 			goto err_region;
 		}
@@ -3497,8 +3654,11 @@  drm_output_propose_state(struct weston_output *output_base,
 
 	/* Check to see if this state will actually work. */
 	ret = drm_pending_state_test(state->pending_state);
-	if (ret != 0)
+	if (ret != 0) {
+		drm_debug(b, "\t\t[view] failing state generation: "
+			     "atomic test not OK\n");
 		goto err;
+	}
 
 	/* Counterpart to duplicating scanout state at the top of this
 	 * function: if we have taken a renderer framebuffer and placed it in
@@ -3531,12 +3691,20 @@  drm_assign_planes(struct weston_output *output_base, void *repaint_data)
 	struct weston_view *ev;
 	struct weston_plane *primary = &output_base->compositor->primary_plane;
 
+	drm_debug(b, "\t[repaint] preparing state for output %s (%d)\n",
+		  output_base->name, output_base->id);
+
 	if (!b->sprites_are_broken) {
 		state = drm_output_propose_state(output_base, pending_state,
 						 DRM_OUTPUT_PROPOSE_STATE_PLANES_ONLY);
-		if (!state)
+		if (!state) {
+			drm_debug(b, "\t[repaint] could not build planes-only "
+				     "state, trying mixed\n");
 			state = drm_output_propose_state(output_base, pending_state,
 							 DRM_OUTPUT_PROPOSE_STATE_MIXED);
+		}
+	} else {
+		drm_debug(b, "\t[state] no overlay plane support\n");
 	}
 
 	if (!state)
@@ -3583,10 +3751,16 @@  drm_assign_planes(struct weston_output *output_base, void *repaint_data)
 			}
 		}
 
-		if (target_plane)
+		if (target_plane) {
+			drm_debug(b, "\t[repaint] view %p on %s plane %d\n",
+				  ev, plane_type_enums[target_plane->type].name,
+				  target_plane->plane_id);
 			weston_view_move_to_plane(ev, &target_plane->base);
-		else
+		} else {
+			drm_debug(b, "\t[repaint] view %p using renderer "
+				     "composition\n", ev);
 			weston_view_move_to_plane(ev, primary);
+		}
 
 		if (!target_plane ||
 		    target_plane->type == WDRM_PLANE_TYPE_CURSOR) {
@@ -6262,6 +6436,7 @@  drm_destroy(struct weston_compositor *ec)
 
 	destroy_sprites(b);
 
+	weston_debug_scope_destroy(b->debug);
 	weston_compositor_shutdown(ec);
 
 	wl_list_for_each_safe(base, next, &ec->head_list, compositor_link)
@@ -6723,6 +6898,10 @@  drm_backend_create(struct weston_compositor *compositor,
 	b->pageflip_timeout = config->pageflip_timeout;
 	b->use_pixman_shadow = config->use_pixman_shadow;
 
+	b->debug = weston_compositor_add_debug_scope(compositor, "drm-backend",
+						     "Debug messages from DRM/KMS backend\n",
+					     	     NULL, NULL);
+
 	compositor->backend = &b->base;
 
 	if (parse_gbm_format(config->gbm_format, GBM_FORMAT_XRGB8888, &b->gbm_format) < 0)

Comments

On Fri, 20 Jul 2018 20:03:35 +0100
Daniel Stone <daniels@collabora.com> wrote:

> Add a 'drm-debug' scope which prints verbose information about the DRM
> backend's repaint cycle, including the decision tree on how views are
> assigned (or not) to planes.
> 
> Signed-off-by: Daniel Stone <daniels@collabora.com>
> ---
>  libweston/compositor-drm.c | 233 ++++++++++++++++++++++++++++++++-----
>  1 file changed, 206 insertions(+), 27 deletions(-)
> 

Hi,

lots of output from this one, nice!


> diff --git a/libweston/compositor-drm.c b/libweston/compositor-drm.c
> index 653d13e0c..2cadf036c 100644
> --- a/libweston/compositor-drm.c
> +++ b/libweston/compositor-drm.c
> @@ -51,6 +51,7 @@
>  
>  #include "compositor.h"
>  #include "compositor-drm.h"
> +#include "weston-debug.h"
>  #include "shared/helpers.h"
>  #include "shared/timespec-util.h"
>  #include "gl-renderer.h"
> @@ -73,6 +74,9 @@
>  #define GBM_BO_USE_CURSOR GBM_BO_USE_CURSOR_64X64
>  #endif
>  
> +#define drm_debug(b, ...) \
> +	weston_debug_scope_printf((b)->debug, __VA_ARGS__)
> +
>  #define MAX_CLONED_CONNECTORS 4
>  
>  /**
> @@ -302,6 +306,8 @@ struct drm_backend {
>  	bool shutting_down;
>  
>  	bool aspect_ratio_supported;
> +
> +	struct weston_debug_scope *debug;
>  };
>  
>  struct drm_mode {
> @@ -2358,6 +2364,9 @@ crtc_add_prop(drmModeAtomicReq *req, struct drm_output *output,
>  
>  	ret = drmModeAtomicAddProperty(req, output->crtc_id, info->prop_id,
>  				       val);
> +	drm_debug(output->backend, "\t\t\t[CRTC:%d] %d (%s) -> %lld (0x%llx)\n",
> +		  output->crtc_id, info->prop_id, info->name,
> +		  (unsigned long long) val, (unsigned long long) val);

This is using %lld to print (unsigned long long), should it not be %llu
instead?

All the property ids are unsigned as well, so %d -> %u?

>  	return (ret <= 0) ? -1 : 0;
>  }
>  
> @@ -2373,6 +2382,9 @@ connector_add_prop(drmModeAtomicReq *req, struct drm_head *head,
>  
>  	ret = drmModeAtomicAddProperty(req, head->connector_id,
>  				       info->prop_id, val);
> +	drm_debug(head->backend, "\t\t\t[CONN:%d] %d (%s) -> %lld (0x%llx)\n",
> +		  head->connector_id, info->prop_id, info->name,
> +		  (unsigned long long) val, (unsigned long long) val);

%d -> %u
%lld -> %llu

>  	return (ret <= 0) ? -1 : 0;
>  }
>  
> @@ -2388,6 +2400,9 @@ plane_add_prop(drmModeAtomicReq *req, struct drm_plane *plane,
>  
>  	ret = drmModeAtomicAddProperty(req, plane->plane_id, info->prop_id,
>  				       val);
> +	drm_debug(plane->backend, "\t\t\t[PLANE:%d] %d (%s) -> %lld (0x%llx)\n",
> +		  plane->plane_id, info->prop_id, info->name,
> +		  (unsigned long long) val, (unsigned long long) val);

%d -> %u
%lld -> %llu

>  	return (ret <= 0) ? -1 : 0;
>  }
>  
> @@ -2406,6 +2421,9 @@ drm_mode_ensure_blob(struct drm_backend *backend, struct drm_mode *mode)
>  	if (ret != 0)
>  		weston_log("failed to create mode property blob: %m\n");
>  
> +	drm_debug(backend, "\t\t\t[atomic] created new mode blob %ld for %s",
> +		  (unsigned long) mode->blob_id, mode->mode_info.name);

%ld -> %u without the cast?

There are more of these kinds below, should I point them out?


> +
>  	return ret;
>  }

...

> @@ -2969,10 +3010,15 @@ drm_repaint_begin(struct weston_compositor *compositor)
>  {
>  	struct drm_backend *b = to_drm_backend(compositor);
>  	struct drm_pending_state *ret;
> +	char *scene_graph = weston_compositor_print_scene_graph(compositor);

Maybe you'd want to make the call to
weston_compositor_print_scene_graph() conditional on the debug scope
being enabled? To not incur the work while not being debugged.

>  
>  	ret = drm_pending_state_alloc(b);
>  	b->repaint_data = ret;
>  
> +	drm_debug(b, "[repaint] Beignning repaint; pending_state %p\n", ret);

Typoed "Beginning".


> +	drm_debug(b, "%s", scene_graph);
> +	free(scene_graph);
> +
>  	return ret;
>  }
>  

...

> @@ -3531,12 +3691,20 @@ drm_assign_planes(struct weston_output *output_base, void *repaint_data)
>  	struct weston_view *ev;
>  	struct weston_plane *primary = &output_base->compositor->primary_plane;
>  
> +	drm_debug(b, "\t[repaint] preparing state for output %s (%d)\n",
> +		  output_base->name, output_base->id);
> +
>  	if (!b->sprites_are_broken) {
>  		state = drm_output_propose_state(output_base, pending_state,
>  						 DRM_OUTPUT_PROPOSE_STATE_PLANES_ONLY);
> -		if (!state)
> +		if (!state) {
> +			drm_debug(b, "\t[repaint] could not build planes-only "
> +				     "state, trying mixed\n");
>  			state = drm_output_propose_state(output_base, pending_state,
>  							 DRM_OUTPUT_PROPOSE_STATE_MIXED);

Should there be a note if mixed mode failed?

> +		}
> +	} else {
> +		drm_debug(b, "\t[state] no overlay plane support\n");
>  	}
>  
>  	if (!state)

Looks good aside from the minor details.


Thanks,
pq