Skip to content

connection: print debug time mod 10000 seconds, not mod 2^32 µs

M. Stoeckl requested to merge mstoeckl/wayland:debug-retime into main

This patch has been useful for me so far, although I'm unsure whether it's worth the cost of changing the debug format.

When looking at WAYLAND_DEBUG output, it's often helpful to match it with program logs, or other timestamped output; but these can sometimes be buffered or otherwise delayed. Printing the debug timestamp as "Unix time in milliseconds % 10000 seconds" makes it easier to align with other program's logs, because the fractional parts of seconds are more likely to match. For example, interleaving debug output with Weston compositor logs produces:

[21:08:22.103] Output repaint window is 7 ms maximum.
[21:08:22.103] Loading module '/home/user/local/lib/libweston-14/wayland-backend.so'
[2902115.326] {Default Queue}  -> wl_display#1.get_registry(new id wl_registry#2)
[2902115.364] {Default Queue}  -> wl_display#1.sync(new id wl_callback#3)

where one can see the wl_display#1.get_registry(new id wl_registry#2) request was logged about 115 - 103 = 12 milliseconds after the module load. Comparing the timestamps this way is impractical with the current % 2^32 µs printing, as the microsecond part of the WAYLAND_DEBUG timestamp is effectively randomly offset from UTC microseconds.

Getting "Unix time in seconds % 10000 seconds" on a terminal can be done using date +%s.%N | cut -b 7-17.

For a related issue requesting a human readable date mode, see: #403

Edited by M. Stoeckl

Merge request reports

Loading