From 273cf8a43286843e28f65dcba5594a0acd3b0446 Mon Sep 17 00:00:00 2001 From: Roman Gilg Date: Fri, 28 Feb 2020 02:41:45 +0100 Subject: [PATCH] feat: log current planes on apply It is helpful for debugging to know in which state the available planes on an output are when a layout is applied that leads to a change. For that log all planes that are compatible with the output. Currently disabled planes have multiple properties logged per line to keep the log short. Example: == Apply request for output 62 == Note: Reused previous plane allocation 5 times. Available planes (on output 62): Plane 55: type: primary FB_ID: 93 IN_FENCE_FD: -1 CRTC_ID: 62 CRTC_X: 39 CRTC_Y: 0 CRTC_W: 3761 CRTC_H: 2160 SRC_X: 0 SRC_Y: 0 SRC_W: 2349 SRC_H: 1349 COLOR_ENCODING: 0 COLOR_RANGE: 0 Plane 61 (inactive): type: cursor FB_ID: 0 IN_FENCE_FD: -1 CRTC_ID: 0 CRTC_X: 0 CRTC_Y: 0 CRTC_W: 0 CRTC_H: 0 SRC_X: 0 SRC_Y: 0 SRC_W: 0 SRC_H: 0 Plane 58 (inactive): type: overlay FB_ID: 0 IN_FENCE_FD: -1 CRTC_ID: 0 CRTC_X: 0 CRTC_Y: 0 CRTC_W: 0 CRTC_H: 0 SRC_X: 0 SRC_Y: 0 SRC_W: 0 SRC_H: 0 alpha: 65535 pixel blend mode: 0 Committed layers: Layer 0x561febd41260: FB_ID = 93 zpos = 0 SRC_X = 0 SRC_Y = 0 SRC_W = 2349 SRC_H = 1349 CRTC_X = 39 CRTC_Y = 0 CRTC_W = 3761 CRTC_H = 2160 Layer 0x561febd3c830: FB_ID = 110 zpos = 2 SRC_X = 0 SRC_Y = 0 SRC_W = 48 SRC_H = 48 CRTC_X = 66 CRTC_Y = 39 CRTC_W = 48 CRTC_H = 48 Reset planes: 55 52 49 46 43 40 71 69 67 65 63 61 58 Performing allocation for plane 55 (1/13) Layer 0x561febd41260 -> plane 55: applying properties... Layer 0x561febd41260 -> plane 55: success Performing allocation for plane 61 (12/13) Layer 0x561febd3c830 -> plane 61: applying properties... Layer 0x561febd3c830 -> plane 61: success Performing allocation for plane 58 (13/13) Found a better allocation with score=2 Layer 0x561febd3c830 -> plane 55: applying properties... Layer 0x561febd3c830 -> plane 55: success Performing allocation for plane 61 (12/13) Layer 0x561febd41260 -> plane 61: applying properties... Layer 0x561febd41260 -> plane 61: success Performing allocation for plane 58 (13/13) Found plane allocation for output 0x561febd3e2a0 with score=2 Final assignment of layers to planes: [1] Layer 0x561febd41260 -> plane 55 (primary) [2] Layer 0x561febd3c830 -> plane 61 (cursor) --- alloc.c | 127 ++++++++++++++++++++++++++++++++++++++++++++++++++++--- output.c | 11 +---- 2 files changed, 121 insertions(+), 17 deletions(-) diff --git a/alloc.c b/alloc.c index e794575..78573a2 100644 --- a/alloc.c +++ b/alloc.c @@ -568,6 +568,19 @@ static void log_reuse(struct liftoff_output *output) output->alloc_reused_counter++; } +static void log_no_reuse(struct liftoff_output *output) +{ + liftoff_log(LIFTOFF_DEBUG, + "\n== Apply request for output %"PRIu32" ==", output->crtc_id); + + if (output->alloc_reused_counter != 0) { + liftoff_log(LIFTOFF_DEBUG, + " Note: Reused previous plane allocation %d times.", + output->alloc_reused_counter); + output->alloc_reused_counter = 0; + } +} + static void log_plane_type_change(uint32_t base, uint32_t cmp) { switch (base) { @@ -589,13 +602,109 @@ static void log_plane_type_change(uint32_t base, uint32_t cmp) } } +static void log_planes(struct liftoff_device *device, + struct liftoff_output *output) +{ + struct liftoff_plane *plane; + drmModeObjectProperties *drm_props; + drmModePropertyRes *drm_prop; + size_t i; + int per_line, max_per_line; + + if (!log_has(LIFTOFF_DEBUG)) { + return; + } + + liftoff_log_cnt(LIFTOFF_DEBUG, "\nAvailable planes"); + if (output) { + liftoff_log(LIFTOFF_DEBUG, " (on output %"PRIu32 "):", output->crtc_id); + } else { + liftoff_log(LIFTOFF_DEBUG, ":"); + } + + liftoff_list_for_each(plane, &device->planes, link) { + bool active = false; + + if (output) { + if ((plane->possible_crtcs & (1 << output->crtc_index)) == 0) { + continue; + } + } + + drm_props = drmModeObjectGetProperties(device->drm_fd, plane->id, + DRM_MODE_OBJECT_PLANE); + if (drm_props == NULL) { + liftoff_log_errno(LIFTOFF_ERROR, "drmModeObjectGetProperties"); + continue; + } + + for (i = 0; i < drm_props->count_props; i++) { + drm_prop = drmModeGetProperty(device->drm_fd, + drm_props->props[i]); + if (drm_prop == NULL) { + liftoff_log_errno(LIFTOFF_ERROR, "drmModeObjectGetProperties"); + continue; + } + + if (strcmp(drm_prop->name, "CRTC_ID") == 0 + && drm_props->prop_values[i] != 0) { + active = true; + break; + } + } + + liftoff_log_cnt(LIFTOFF_DEBUG, " Plane %"PRIu32 "%s", plane->id, + active ? ":" : " (inactive):"); + + max_per_line = active ? 1 : 4; + per_line = max_per_line - 1; + for (i = 0; i < drm_props->count_props; i++) { + uint64_t value = drm_props->prop_values[i]; + char *name; + + if (++per_line == max_per_line) { + liftoff_log_cnt(LIFTOFF_DEBUG, "\n "); + per_line = 0; + } + + drm_prop = drmModeGetProperty(device->drm_fd, + drm_props->props[i]); + if (drm_prop == NULL) { + liftoff_log_cnt(LIFTOFF_DEBUG, "ERR!"); + continue; + } + + name = drm_prop->name; + + if (strcmp(name, "type") == 0) { + liftoff_log_cnt(LIFTOFF_DEBUG, " %s: %s", name, + value == DRM_PLANE_TYPE_PRIMARY ? "primary" : + value == DRM_PLANE_TYPE_CURSOR ? "cursor" : "overlay"); + continue; + } + + if (strcmp(name, "CRTC_X") == 0 || strcmp(name, "CRTC_Y") == 0 + || strcmp(name, "IN_FENCE_FD") == 0) { + liftoff_log_cnt(LIFTOFF_DEBUG, " %s: %"PRIi32, name, (int32_t)value); + continue; + } + + if (strcmp(name, "SRC_W") == 0 || strcmp(name, "SRC_H") == 0) { + value = value >> 16; + } + liftoff_log_cnt(LIFTOFF_DEBUG, " %s: %"PRIu64, name, value); + } + liftoff_log_cnt(LIFTOFF_DEBUG, "\n"); + } +} + static bool reset_planes(struct liftoff_device *device, drmModeAtomicReq *req) { struct liftoff_plane *plane; uint32_t debug_type = DRM_PLANE_TYPE_PRIMARY; bool compatible; - liftoff_log_cnt(LIFTOFF_DEBUG, "Reset planes:"); + liftoff_log_cnt(LIFTOFF_DEBUG, "\nReset planes:"); liftoff_list_for_each(plane, &device->planes, link) { if (plane->layer != NULL) { @@ -616,7 +725,7 @@ static bool reset_planes(struct liftoff_device *device, drmModeAtomicReq *req) assert(compatible); } - liftoff_log_cnt(LIFTOFF_DEBUG, "\n"); + liftoff_log(LIFTOFF_DEBUG, "\n"); return true; } @@ -638,7 +747,11 @@ bool liftoff_output_apply(struct liftoff_output *output, drmModeAtomicReq *req) return true; } - output_log_layers(output); + if (log_has(LIFTOFF_DEBUG)) { + log_no_reuse(output); + log_planes(device, output); + output_log_layers(output); + } /* Unset all existing plane and layer mappings with this output. */ liftoff_list_for_each(plane, &device->planes, link) { @@ -691,7 +804,7 @@ bool liftoff_output_apply(struct liftoff_output *output, drmModeAtomicReq *req) "score=%d:", (void *)output, result.best_score); /* Apply the best allocation */ - liftoff_log(LIFTOFF_DEBUG, "Final assignment of layers to planes:"); + liftoff_log(LIFTOFF_DEBUG, "\nFinal assignment of layers to planes:"); i = j = 0; liftoff_list_for_each(plane, &device->planes, link) { layer = result.best[i]; @@ -702,9 +815,9 @@ bool liftoff_output_apply(struct liftoff_output *output, drmModeAtomicReq *req) j++; liftoff_log(LIFTOFF_DEBUG, " [%zu] Layer %p -> plane %"PRIu32 - " (%s)", j, (void *)layer, plane->id, - plane->type == DRM_PLANE_TYPE_PRIMARY ? "primary" : - DRM_PLANE_TYPE_OVERLAY ? "overlay" : "cursor"); + " (%s)", j, (void *)layer, plane->id, + plane->type == DRM_PLANE_TYPE_PRIMARY ? "primary" : + plane->type == DRM_PLANE_TYPE_OVERLAY ? "overlay" : "cursor"); assert(plane->layer == NULL); assert(layer->plane == NULL); diff --git a/output.c b/output.c index 4730c39..906f0a3 100644 --- a/output.c +++ b/output.c @@ -66,16 +66,7 @@ void output_log_layers(struct liftoff_output *output) { return; } - liftoff_log(LIFTOFF_DEBUG, "\n== Apply request for output %"PRIu32" ==", output->crtc_id); - - if (output->alloc_reused_counter != 0) { - liftoff_log(LIFTOFF_DEBUG, - " Note: Reused previous plane allocation %d times.", - output->alloc_reused_counter); - output->alloc_reused_counter = 0; - } - - liftoff_log(LIFTOFF_DEBUG, "Active layers:"); + liftoff_log(LIFTOFF_DEBUG, "\nCommitted layers:"); liftoff_list_for_each(layer, &output->layers, link) { if (layer->force_composition) {