From b7441514fe3395f7b582d17d31186056d78b852b Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Jonas=20=C3=85dahl?= Date: Fri, 2 Oct 2020 18:37:18 +0200 Subject: [PATCH] kms: Add some basic debug logging Enabled using MUTTER_DEBUG=kms or via Meta.add_verbose_topic(Meta.DebugTopic.KMS) in looking glass. Part-of: --- src/backends/native/meta-kms-device.c | 3 + .../native/meta-kms-impl-device-simple.c | 124 ++++++++++++++++++ src/backends/native/meta-kms-update-private.h | 2 + src/backends/native/meta-kms-update.c | 9 ++ src/backends/native/meta-renderer-native.c | 14 ++ src/core/main.c | 1 + src/core/util.c | 2 + src/meta/util.h | 2 + 8 files changed, 157 insertions(+) diff --git a/src/backends/native/meta-kms-device.c b/src/backends/native/meta-kms-device.c index e774476bc..f1fe833df 100644 --- a/src/backends/native/meta-kms-device.c +++ b/src/backends/native/meta-kms-device.c @@ -285,6 +285,9 @@ meta_create_kms_impl_device (MetaKmsDevice *device, driver_description = g_strdup ("Unknown"); } + g_message ("Adding device '%s' (%s) using non-atomic mode setting.", + path, driver_name); + return g_initable_new (META_TYPE_KMS_IMPL_DEVICE_SIMPLE, NULL, error, "device", device, "impl", impl, diff --git a/src/backends/native/meta-kms-impl-device-simple.c b/src/backends/native/meta-kms-impl-device-simple.c index 17f5fdc16..c9824539a 100644 --- a/src/backends/native/meta-kms-impl-device-simple.c +++ b/src/backends/native/meta-kms-impl-device-simple.c @@ -118,6 +118,13 @@ process_connector_update (MetaKmsImplDevice *impl_device, if (connector_update->dpms.has_update) { + meta_topic (META_DEBUG_KMS, + "[simple] Setting DPMS on connector %u (%s) to %" + G_GUINT64_FORMAT, + meta_kms_connector_get_id (connector), + meta_kms_impl_device_get_path (impl_device), + connector_update->dpms.state); + if (!set_connector_property (impl_device, connector, META_KMS_CONNECTOR_PROP_DPMS, @@ -129,6 +136,14 @@ process_connector_update (MetaKmsImplDevice *impl_device, if (connector_update->underscanning.has_update && connector_update->underscanning.is_active) { + meta_topic (META_DEBUG_KMS, + "[simple] Setting underscanning on connector %u (%s) to " + "%" G_GUINT64_FORMAT "x%" G_GUINT64_FORMAT, + meta_kms_connector_get_id (connector), + meta_kms_impl_device_get_path (impl_device), + connector_update->underscanning.hborder, + connector_update->underscanning.vborder); + if (!set_connector_property (impl_device, connector, META_KMS_CONNECTOR_PROP_UNDERSCAN, @@ -150,6 +165,11 @@ process_connector_update (MetaKmsImplDevice *impl_device, } else if (connector_update->underscanning.has_update) { + meta_topic (META_DEBUG_KMS, + "[simple] Unsetting underscanning on connector %u (%s)", + meta_kms_connector_get_id (connector), + meta_kms_impl_device_get_path (impl_device)); + if (!set_connector_property (impl_device, connector, META_KMS_CONNECTOR_PROP_UNDERSCAN, @@ -217,6 +237,13 @@ set_plane_rotation (MetaKmsImplDevice *impl_device, rotation_prop_id = meta_kms_plane_get_prop_id (plane, META_KMS_PLANE_PROP_ROTATION); + + meta_topic (META_DEBUG_KMS, + "[simple] Setting plane %u (%s) rotation to %" G_GUINT64_FORMAT, + meta_kms_plane_get_id (plane), + meta_kms_impl_device_get_path (impl_device), + rotation); + ret = drmModeObjectSetProperty (fd, meta_kms_plane_get_id (plane), DRM_MODE_OBJECT_PLANE, @@ -293,6 +320,12 @@ process_mode_set (MetaKmsImplDevice *impl_device, buffer = plane_assignment->buffer; fb_id = meta_drm_buffer_get_fb_id (buffer); + + meta_topic (META_DEBUG_KMS, + "[simple] Setting mode of CRTC %u (%s) to %s", + meta_kms_crtc_get_id (crtc), + meta_kms_impl_device_get_path (impl_device), + drm_mode->name); } else { @@ -301,6 +334,11 @@ process_mode_set (MetaKmsImplDevice *impl_device, n_connectors = 0; connectors = NULL; fb_id = 0; + + meta_topic (META_DEBUG_KMS, + "[simple] Unsetting mode of CRTC %u (%s)", + meta_kms_crtc_get_id (crtc), + meta_kms_impl_device_get_path (impl_device)); } fd = meta_kms_impl_device_get_fd (impl_device); @@ -346,6 +384,12 @@ process_crtc_gamma (MetaKmsImplDevice *impl_device, int fd; int ret; + meta_topic (META_DEBUG_KMS, + "[simple] Setting CRTC %u (%s) gamma, size: %d", + meta_kms_crtc_get_id (crtc), + meta_kms_impl_device_get_path (impl_device), + gamma->size); + fd = meta_kms_impl_device_get_fd (impl_device); ret = drmModeCrtcSetGamma (fd, meta_kms_crtc_get_id (crtc), gamma->size, @@ -447,11 +491,21 @@ retry_page_flips (gpointer user_data) custom_page_flip_func = retry_page_flip_data->custom_page_flip_func; if (custom_page_flip_func) { + meta_topic (META_DEBUG_KMS, + "[simple] Retrying custom page flip on CRTC %u (%s)", + meta_kms_crtc_get_id (crtc), + meta_kms_impl_device_get_path (impl_device)); ret = custom_page_flip_func (retry_page_flip_data->custom_page_flip_user_data, retry_page_flip_data->page_flip_data); } else { + meta_topic (META_DEBUG_KMS, + "[simple] Retrying page flip on CRTC %u (%s) with %u", + meta_kms_crtc_get_id (crtc), + meta_kms_impl_device_get_path (impl_device), + retry_page_flip_data->fb_id); + fd = meta_kms_impl_device_get_fd (impl_device); ret = drmModePageFlip (fd, meta_kms_crtc_get_id (crtc), @@ -464,6 +518,11 @@ retry_page_flips (gpointer user_data) { float refresh_rate; + meta_topic (META_DEBUG_KMS, + "[simple] Rescheduling page flip retry on CRTC %u (%s)", + meta_kms_crtc_get_id (crtc), + meta_kms_impl_device_get_path (impl_device)); + refresh_rate = get_cached_crtc_refresh_rate (impl_device_simple, crtc); retry_page_flip_data->retry_time_us += @@ -727,6 +786,10 @@ dispatch_page_flip (MetaKmsImplDevice *impl_device, &custom_page_flip_user_data); if (custom_page_flip_func) { + meta_topic (META_DEBUG_KMS, + "[simple] Invoking custom page flip on CRTC %u (%s)", + meta_kms_crtc_get_id (crtc), + meta_kms_impl_device_get_path (impl_device)); ret = custom_page_flip_func (custom_page_flip_user_data, meta_kms_page_flip_data_ref (page_flip_data)); } @@ -735,6 +798,14 @@ dispatch_page_flip (MetaKmsImplDevice *impl_device, uint32_t fb_id; fb_id = meta_drm_buffer_get_fb_id (plane_assignment->buffer); + + meta_topic (META_DEBUG_KMS, + "[simple] Page flipping CRTC %u (%s) with %u, data: %p", + meta_kms_crtc_get_id (crtc), + meta_kms_impl_device_get_path (impl_device), + fb_id, + page_flip_data); + ret = drmModePageFlip (fd, meta_kms_crtc_get_id (crtc), fb_id, @@ -749,6 +820,11 @@ dispatch_page_flip (MetaKmsImplDevice *impl_device, { CachedModeSet *cached_mode_set; + meta_topic (META_DEBUG_KMS, + "[simple] Scheduling page flip retry on CRTC %u (%s)", + meta_kms_crtc_get_id (crtc), + meta_kms_impl_device_get_path (impl_device)); + cached_mode_set = get_cached_mode_set (impl_device_simple, crtc); if (cached_mode_set) { @@ -781,6 +857,11 @@ dispatch_page_flip (MetaKmsImplDevice *impl_device, } else if (ret == -EINVAL) { + meta_topic (META_DEBUG_KMS, + "[simple] Falling back to mode set on CRTC %u (%s)", + meta_kms_crtc_get_id (crtc), + meta_kms_impl_device_get_path (impl_device)); + if (!mode_set_fallback (impl_device_simple, update, plane_assignment, @@ -952,6 +1033,16 @@ process_cursor_plane_assignment (MetaKmsImplDevice *impl_device, handle_u32 = 0; } + meta_topic (META_DEBUG_KMS, + "[simple] Setting HW cursor of CRTC %u (%s) to %u " + "(size: %dx%d, hot: (%d, %d))", + crtc_id, + meta_kms_impl_device_get_path (impl_device), + handle_u32, + width, height, + plane_assignment->cursor_hotspot.x, + plane_assignment->cursor_hotspot.y); + if (plane_assignment->cursor_hotspot.is_valid) { ret = drmModeSetCursor2 (fd, @@ -977,6 +1068,13 @@ process_cursor_plane_assignment (MetaKmsImplDevice *impl_device, } } + meta_topic (META_DEBUG_KMS, + "[simple] Moving HW cursor of CRTC %u (%s) to (%d, %d)", + crtc_id, + meta_kms_impl_device_get_path (impl_device), + plane_assignment->dst_rect.x, + plane_assignment->dst_rect.y); + drmModeMoveCursor (fd, crtc_id, plane_assignment->dst_rect.x, @@ -1081,11 +1179,20 @@ page_flip_handler (int fd, { MetaKmsPageFlipData *page_flip_data = user_data; MetaKmsImplDevice *impl_device; + MetaKmsCrtc *crtc; meta_kms_page_flip_data_set_timings_in_impl (page_flip_data, sequence, tv_sec, tv_usec); impl_device = meta_kms_page_flip_data_get_impl_device (page_flip_data); + crtc = meta_kms_page_flip_data_get_crtc (page_flip_data); + + meta_topic (META_DEBUG_KMS, + "[simple] Handling page flip callback from %s, data: %p, CRTC: %u", + meta_kms_impl_device_get_path (impl_device), + page_flip_data, + meta_kms_crtc_get_id (crtc)); + meta_kms_impl_device_handle_page_flip_callback (impl_device, page_flip_data); } @@ -1104,6 +1211,10 @@ meta_kms_impl_device_simple_process_update (MetaKmsImplDevice *impl_device, GError *error = NULL; GList *failed_planes = NULL; + meta_topic (META_DEBUG_KMS, + "[simple] Processing update %" G_GUINT64_FORMAT, + meta_kms_update_get_sequence_number (update)); + if (!process_entries (impl_device, update, meta_kms_update_get_connector_updates (update), @@ -1186,6 +1297,14 @@ meta_kms_impl_device_simple_discard_pending_page_flips (MetaKmsImplDevice *impl_ MetaKmsPageFlipData *page_flip_data; page_flip_data = g_steal_pointer (&retry_page_flip_data->page_flip_data); + + meta_topic (META_DEBUG_KMS, + "[simple] Discarding page flip retry for CRTC %u (%s)", + meta_kms_crtc_get_id ( + meta_kms_page_flip_data_get_crtc (page_flip_data)), + meta_kms_impl_device_get_path ( + meta_kms_page_flip_data_get_impl_device (page_flip_data))); + meta_kms_page_flip_data_discard_in_impl (page_flip_data, NULL); retry_page_flip_data_free (retry_page_flip_data); } @@ -1244,6 +1363,11 @@ meta_kms_impl_device_simple_initable_init (GInitable *initable, if (plane) continue; + meta_topic (META_DEBUG_KMS, + "[simple] Adding fake cursor plane for CRTC %u (%s)", + meta_kms_crtc_get_id (crtc), + meta_kms_impl_device_get_path (impl_device)); + meta_kms_device_add_fake_plane_in_impl (device, META_KMS_PLANE_TYPE_CURSOR, crtc); diff --git a/src/backends/native/meta-kms-update-private.h b/src/backends/native/meta-kms-update-private.h index 2a1675836..f5be87b97 100644 --- a/src/backends/native/meta-kms-update-private.h +++ b/src/backends/native/meta-kms-update-private.h @@ -116,6 +116,8 @@ void meta_kms_update_unlock (MetaKmsUpdate *update); gboolean meta_kms_update_is_locked (MetaKmsUpdate *update); +uint64_t meta_kms_update_get_sequence_number (MetaKmsUpdate *update); + MetaKmsDevice * meta_kms_update_get_device (MetaKmsUpdate *update); void meta_kms_plane_assignment_set_rotation (MetaKmsPlaneAssignment *plane_assignment, diff --git a/src/backends/native/meta-kms-update.c b/src/backends/native/meta-kms-update.c index e03d03533..95f480bcc 100644 --- a/src/backends/native/meta-kms-update.c +++ b/src/backends/native/meta-kms-update.c @@ -33,6 +33,7 @@ struct _MetaKmsUpdate MetaKmsDevice *device; gboolean is_locked; + uint64_t sequence_number; MetaPowerSave power_save; GList *mode_sets; @@ -535,13 +536,21 @@ meta_kms_update_get_custom_page_flip_func (MetaKmsUpdate *update, *custom_page_flip_user_data = update->custom_page_flip_user_data; } +uint64_t +meta_kms_update_get_sequence_number (MetaKmsUpdate *update) +{ + return update->sequence_number; +} + MetaKmsUpdate * meta_kms_update_new (MetaKmsDevice *device) { MetaKmsUpdate *update; + static uint64_t sequence_number = 0; update = g_new0 (MetaKmsUpdate, 1); update->device = device; + update->sequence_number = sequence_number++; return update; } diff --git a/src/backends/native/meta-renderer-native.c b/src/backends/native/meta-renderer-native.c index c2b98920b..00e5f445f 100644 --- a/src/backends/native/meta-renderer-native.c +++ b/src/backends/native/meta-renderer-native.c @@ -1870,6 +1870,8 @@ unset_disabled_crtcs (MetaBackend *backend, { GList *l; + meta_topic (META_DEBUG_KMS, "Disabling all disabled CRTCs"); + for (l = meta_backend_get_gpus (backend); l; l = l->next) { MetaGpu *gpu = l->data; @@ -2012,6 +2014,11 @@ meta_onscreen_native_swap_buffers_with_damage (CoglOnscreen *onscreen, kms_crtc = meta_crtc_kms_get_kms_crtc (META_CRTC_KMS (onscreen_native->crtc)); kms_device = meta_kms_crtc_get_device (kms_crtc); + meta_topic (META_DEBUG_KMS, + "Posting primary plane composite update for CRTC %u (%s)", + meta_kms_crtc_get_id (kms_crtc), + meta_kms_device_get_path (kms_device)); + flags = META_KMS_UPDATE_FLAG_NONE; kms_feedback = meta_kms_post_pending_update_sync (kms, kms_device, flags); if (meta_kms_feedback_get_result (kms_feedback) != META_KMS_FEEDBACK_PASSED) @@ -2208,6 +2215,11 @@ meta_onscreen_native_direct_scanout (CoglOnscreen *onscreen, kms_crtc = meta_crtc_kms_get_kms_crtc (META_CRTC_KMS (onscreen_native->crtc)); kms_device = meta_kms_crtc_get_device (kms_crtc); + meta_topic (META_DEBUG_KMS, + "Posting direct scanout update for CRTC %u (%s)", + meta_kms_crtc_get_id (kms_crtc), + meta_kms_device_get_path (kms_device)); + flags = META_KMS_UPDATE_FLAG_PRESERVE_ON_ERROR; kms_feedback = meta_kms_post_pending_update_sync (kms, kms_device, flags); if (meta_kms_feedback_get_result (kms_feedback) != META_KMS_FEEDBACK_PASSED) @@ -2685,6 +2697,8 @@ meta_renderer_native_queue_modes_reset (MetaRendererNative *renderer_native) onscreen_native->pending_set_crtc = TRUE; } + meta_topic (META_DEBUG_KMS, "Queue mode set"); + renderer_native->pending_unset_disabled_crtcs = TRUE; } diff --git a/src/core/main.c b/src/core/main.c index d0b2a48d9..f4ead0645 100644 --- a/src/core/main.c +++ b/src/core/main.c @@ -120,6 +120,7 @@ static const GDebugKey meta_debug_keys[] = { { "dbus", META_DEBUG_DBUS }, { "input", META_DEBUG_INPUT }, { "wayland", META_DEBUG_WAYLAND }, + { "kms", META_DEBUG_KMS }, }; /* diff --git a/src/core/util.c b/src/core/util.c index 1a77927d1..b10f54f47 100644 --- a/src/core/util.c +++ b/src/core/util.c @@ -276,6 +276,8 @@ topic_name (MetaDebugTopic topic) return "DBUS"; case META_DEBUG_INPUT: return "INPUT"; + case META_DEBUG_KMS: + return "KMS"; case META_DEBUG_VERBOSE: return "VERBOSE"; case META_DEBUG_WAYLAND: diff --git a/src/meta/util.h b/src/meta/util.h index 1bf80d868..814d14479 100644 --- a/src/meta/util.h +++ b/src/meta/util.h @@ -76,6 +76,7 @@ void meta_fatal (const char *format, * @META_DEBUG_SHAPES: shapes * @META_DEBUG_EDGE_RESISTANCE: edge resistance * @META_DEBUG_WAYLAND: Wayland + * @META_DEBUG_KMS: kernel mode setting */ typedef enum { @@ -101,6 +102,7 @@ typedef enum META_DEBUG_DBUS = 1 << 18, META_DEBUG_INPUT = 1 << 19, META_DEBUG_WAYLAND = 1 << 20, + META_DEBUG_KMS = 1 << 21, } MetaDebugTopic; /**