We're hiring!
*

Weston debugging and tracing on-the-fly

Marius Vlad avatar

Marius Vlad
April 24, 2019

Share this post:

The recent release of version 6 of the Weston compositor has brought with it the weston-debug protocol, a new feature that allows developers and users alike to display on-the-fly various debugging (logging) information generated by the compositor.

On one side developers can make use of its debugging API as to further enhance their code and debug potential problems without cluttering the log file, or the standard files opened by the server when started manually. On the other side users can use it to debug protocol issues, back-end and compositor issues and to provide to the developers logging information which would've been added when writing their code.

Description

One key element of the weston-debug protocol is the fact it can be used dynamically without the need to restart or recompile the server. But as the protocol might expose sensitive information and potentially could allow denial-of-service attacks, the server will need to be started using --debug command line argument. The server will advertise the available debug scopes which the client can choose to bind to. Binding to a debug scope, chosen by its name, creates a debug stream to the client.

The debug stream is essentially a file descriptor which the server will write data to. More than one debug stream (i.e., multiple clients) can be attached to a debug scope. Some debug scopes will write one-shot data after which the stream will terminate, other scopes keep producing messages until stopped by the client. The server signals terminating streams using the complete event. When the client destroys the debug stream it will also signal the server to end writing to the file descriptor thus closing it if wasn't already. In case of a failure the server will close the file descriptor and will signal the client with a failure event.

Usage

Currently, Weston has the following debug scopes:

  • log - a debug scope for generic logging.
  • proto - debug scope that displays the protocol communication. It is similar to WAYLAND_DEBUG=server environmental variable but has the ability to distinguish multiple clients.
  • scene-graph - an one-shot debug scope which describes the current scene graph comprising of layers (containers of views), views (which represent a window), their surfaces, sub-surfaces, buffer type and format, both in DRM_FOURCC[1] type and human-friendly form.
  • drm-backend - Weston uses DRM (Direct Rendering Manager) as one of its backends and this debug scope display information related to that: details the transitions of a view as it takes before being assigned to a hardware plane or to a renderer, current assignments of views, the compositing mode Weston is using for rendering the scene-graph, describes the current hardware plane properties like CRTC_ID, FB_ID, FORMAT when doing a commit or a page-flip. It incorporates the scene-graph scope as well.
  • xwm-wm-x11 - a scope for the X11 window manager in Weston for supporting Xwayland, printing some X11 protocol actions.

The client uses the same as the protocol name, respectively weston-debug, and can either bind to one, more or all the debug scopes being advertised by the server.

Extras

A scene-graph debug scope snippet:

Weston scene graph at 1778.948165211:

Output 0 (DP-1):
        position: (0, 0) -> (1920, 1080)
        mode: 1920x1080@59.880Hz
        scale: 1
        repaint status: awaiting completion
        Head 0 (DP-1): connected

Layer 0 (pos 0xffffffff):
        [no views]
...
Layer 5 (pos 0x50000000):
        View 0 (role xdg_toplevel, PID 616, surface ID 18, top-level window 'Wayland Terminal', 0x2725580):
                position: (396, 146) -> (1202, 637)
                [opaque: (431, 181) -> (1167, 602)]
                outputs: 0 (DP-1) (primary)
                dmabuf buffer
                        format: 0x34325241 ARGB8888
                        modifier: 0x600000000000002
        View 1 (role xdg_toplevel, PID 604, surface ID 9, top-level window 'simple-egl', 0x272a058):
                position: (715, 266) -> (965, 516)
                [not opaque]
                outputs: 0 (DP-1) (primary)
                dmabuf buffer
                        format: 0x34325241 ARGB8888
                        modifier: 0x600000000000002

Layer 6 (pos 0x2):
        View 0 (role (null), PID 546, surface ID 20, background for output DP-1, 0x2484008):
                position: (0, 0) -> (1920, 1080)
                [fully opaque]
                outputs: 0 (DP-1) (primary)
                dmabuf buffer
                        format: 0x34325241 XRGB8888 (was: ARGB8888)
                        modifier: 0x600000000000002

Some drm-backend scope transition of views between different compositing modes:

[repaint] preparing state for output DP-1 (0)
[repaint] trying planes-only build state
                [view] evaluating view 0x2725580 for output DP-1 (0)
                        [view] not assigning view 0x2725580 to plane (view not fully opaque)
        [view] failing state generation: placing view 0x2725580 to renderer not allowed
[repaint] could not build planes-only state, trying mixed
        [state] using renderer FB ID 61 for mixed mode for output DP-1 (0)
                [view] evaluating view 0x2725580 for output DP-1 (0)
                        [view] not assigning view 0x2725580 to plane (view not fully opaque)
                [view] evaluating view 0x272a058 for output DP-1 (0)
                        [view] not assigning view 0x272a058 to plane (occluded by other overlay planes)
                        [view] not assigning view 0x272a058 to plane (view not fully opaque)
                [view] evaluating view 0x2484008 for output DP-1 (0)
                        [view] not assigning view 0x2484008 to plane (occluded by other overlay planes)

And further on displaying composition mode if the views uses the renderer or the HW-planes. Finally plane properties are displayed:

        [repaint] Using mixed state composition
        [repaint] view 0x2730680 using renderer composition
        [repaint] view 0x2484008 using renderer composition
                [atomic] applying output 0 (DP-1) state
                        [CRTC:33] 22 (MODE_ID) -> 66 (0x42)
                        [CRTC:33] 21 (ACTIVE) -> 1 (0x1)
                        [CONN:53] 19 (CRTC_ID) -> 33 (0x21)
                        [PLANE:30] 16 (FB_ID) -> 61 (0x3d)
                        [PLANE:30] 19 (CRTC_ID) -> 33 (0x21)
                        [PLANE:30] 8 (SRC_X) -> 0 (0x0)
                        [PLANE:30] 9 (SRC_Y) -> 0 (0x0)
                        [PLANE:30] 10 (SRC_W) -> 125829120 (0x7800000)
                        [PLANE:30] 11 (SRC_H) -> 70778880 (0x4380000)
                        [PLANE:30] 12 (CRTC_X) -> 0 (0x0)
                        [PLANE:30] 13 (CRTC_Y) -> 0 (0x0)
                        [PLANE:30] 14 (CRTC_W) -> 1920 (0x780)
                        [PLANE:30] 15 (CRTC_H) -> 1080 (0x438)
                        [PLANE:30] FORMAT: XRGB8888
[repaint] flushed pending_state 0x271cb88

And proto debug scope:

[2018-07-01 02:40:55.912][proto] client 0x271e8a0 rq wl_display@1.get_registry(new id wl_registry@2)
[2018-07-01 02:40:55.912][proto] client 0x271e8a0 ev wl_registry@2.global(1, "wl_compositor", 4)
[2018-07-01 02:40:55.912][proto] client 0x271e8a0 ev wl_registry@2.global(2, "wl_subcompositor", 1)
[2018-07-01 02:40:55.912][proto] client 0x271e8a0 ev wl_registry@2.global(3, "wp_viewporter", 1)
[2018-07-01 02:40:55.912][proto] client 0x271e8a0 ev wl_registry@2.global(4, "wp_presentation", 1)
[2018-07-01 02:40:55.912][proto] client 0x271e8a0 ev wl_registry@2.global(5, "zwp_relative_pointer_manager_v1", 1)
[2018-07-01 02:40:55.912][proto] client 0x271e8a0 ev wl_registry@2.global(6, "zwp_pointer_constraints_v1", 1)
[2018-07-01 02:40:55.913][proto] client 0x271e8a0 ev wl_registry@2.global(7, "zwp_input_timestamps_manager_v1", 1)
[2018-07-01 02:40:55.913][proto] client 0x271e8a0 ev wl_registry@2.global(8, "wl_data_device_manager", 3)
[2018-07-01 02:40:55.913][proto] client 0x271e8a0 ev wl_registry@2.global(9, "wl_shm", 1)
[2018-07-01 02:40:55.913][proto] client 0x271e8a0 ev wl_registry@2.global(10, "weston_debug_v1", 1)
[2018-07-01 02:40:55.913][proto] client 0x271e8a0 ev wl_registry@2.global(11, "wl_drm", 2)
[2018-07-01 02:40:55.913][proto] client 0x271e8a0 ev wl_registry@2.global(12, "wl_seat", 5)
[2018-07-01 02:40:55.913][proto] client 0x271e8a0 ev wl_registry@2.global(13, "zwp_linux_dmabuf_v1", 3)
[2018-07-01 02:40:55.913][proto] client 0x271e8a0 ev wl_registry@2.global(14, "wl_output", 3)
[2018-07-01 02:40:55.913][proto] client 0x271e8a0 ev wl_registry@2.global(15, "zwp_input_panel_v1", 1)
[2018-07-01 02:40:55.913][proto] client 0x271e8a0 ev wl_registry@2.global(16, "zwp_input_method_v1", 1)
[2018-07-01 02:40:55.913][proto] client 0x271e8a0 ev wl_registry@2.global(17, "zwp_text_input_manager_v1", 1)
[2018-07-01 02:40:55.914][proto] client 0x271e8a0 ev wl_registry@2.global(18, "zxdg_shell_v6", 1)
[2018-07-01 02:40:55.914][proto] client 0x271e8a0 ev wl_registry@2.global(19, "wl_shell", 1)
[2018-07-01 02:40:55.914][proto] client 0x271e8a0 ev wl_registry@2.global(20, "weston_desktop_shell", 1)
[2018-07-01 02:40:55.914][proto] client 0x271e8a0 ev wl_registry@2.global(21, "zodiac_foreign_position", 1)
[2018-07-01 02:40:55.914][proto] client 0x271e8a0 ev wl_registry@2.global(22, "weston_screenshooter", 1)
[2018-07-01 02:40:55.914][proto] client 0x271e8a0 rq wl_display@1.sync(new id wl_callback@3)
[2018-07-01 02:40:55.914][proto] client 0x271e8a0 ev wl_callback@3.done(56)
[2018-07-01 02:40:55.914][proto] client 0x271e8a0 ev wl_display@1.delete_id(3)
[2018-07-01 02:40:55.915][proto] client 0x271e8a0 rq wl_registry@2.bind(1, "wl_compositor", 3, new id

weston-screenshooter

Under the same --debug feature, weston-screenshooter has been allowed to take screenshots of the screen without the need to hook-up a keyboard. This allows connecting remotely and running weston-screenshooter binary.

Conclusion, further work and other directions

Following the addition of the weston-debug protocol a few ideas of improving other aspects of weston have been exposed.

Post-mortem and better debug information from assertion failures

One further improvement of the debug stream is the ability to display fatal errors. If the server is in the process of terminating, or it is being terminated just as it started because it has encountered a fatal error weston-debug client won't be of use. Some current ideas around this is to save debug scope data into a rather large ring-buffer which in case of a failure, can be displayed by the server right before terminating.

On the same page, Weston makes use of assert() to signal fatal flaws as to avoid continuing having core constrains being violated. One particular example is the DRM back-end, which makes use of them especially in the repaint machinery. Exiting with a rather specific (and sometimes cryptic message) is not really useful to properly diagnose what the culprit was. Even when they are, the internal memory state leading to the assert() won't be kept so we need a way to store in some sort of a flight-recorder all the internal state of the compositor as to determine what lead to that assert(). We observe that the same approach of using an internal ring-buffer comes to mind as a way to implement this.

Timeline output through debug protocol

Another improvement direction is the ability to convert the existing timeline debug [2] feature in Weston, to a debug scope. The timeline debug feature was created by Pekka Paalanen to help him diagnose latency and repaint issues with the older repaint scheduling algorithm. This feature is (upon invoking a debug key-binding) recording into a JSON-type of file various parts of the repaint loop, and with the help of a parser, will convert that file to a SVG file which can be visualized, allowing investigation of latency issues in the repaint loop.

Convert renderer debug bindings into debug scopes

As it stands now, in Weston there are a few debug key-bindings (for instance GL renderer part, or enabling the timeline feature). Under the same debug umbrella like the weston-debug protocol, we are seeing the need to have something equivalent either for manipulating and replacing those debug key-bindings (as to remove the need for a keyboard) or to modify the compositor internal state, for instance like enforcing on the fly which compositing mode to be used by Weston and ignore all others.

Add debug scope groups

With the addition of other debug scopes, in the future, there could be a problem when selecting which debug scope to bind the client to. The idea here is to create groups of debug scopes, which brings together multiple debug scopes under a single entry.

Per-client authentication/authorize mechanisms

Rather than specifying --debug as a command line option for the server, we identify the need to have a better way to authenticate and possibly authorize clients. A wider scope is not something that we seek at the moment but at least a way to do it for the Weston compositor. There's a need for considering on how to approach this with multiple OS in mind, as on *BSD variants some of the options that we find on Linux are not available.

Acknowledgement

The weston-debug protocol developed as a collaboration between Pekka Paalanen and Daniel Stone.


[1] Optimizing graphics memory bandwidth with compression and tiling: Notes on DRM format modifiers.

[2] Weston repaint scheduling.

Comments (0)


Add a Comment






Allowed tags: <b><i><br>Add a new comment:


Search the newsroom

Latest Blog Posts

GStreamer in Oslo

18/07/2019

A little over a month and a half ago, Collaborans including Aaron Boxer, George Kiagiadakis, Guillaume Desmottes, Stéphane Cerveau and myself…

GNOME meets Panfrost

26/06/2019

In my last Panfrost blog post, I announced my internship goal: improve Panfrost to run GNOME3. GNOME is a popular Linux desktop making heavy…

Using dummy-hcd to play with USB gadgets

24/06/2019

Dummy_hcd which consists of a software-emulated host controller and a UDC chip. In other words, this means you can play with USB gadgets…

Building Debian images for Le Potato and OrangePi with debos

18/06/2019

Both the Le Potato and OrangePi Zero Plus2 boards are already supported by Armbian. But how do you get a minimal Debian upstream image with…

Joining Collabora for a summer of Panfrost

05/06/2019

Years ago, I joined the open-source community with a passion and a mission: to enable equal access to high-quality computing via open-source…

Testing Video4Linux2 drivers like a boss

23/05/2019

With virtme, you can run a custom built kernel on top of our running root filesystem. In this post, we explore another example of virtme…

Open Since 2005 logo

We use cookies on this website to ensure that you get the best experience. By continuing to use this website you are consenting to the use of these cookies. To find out more please follow this link.

Collabora Ltd © 2005-2019. All rights reserved. Website sitemap.