[PATCH wayland] Add API to install protocol loggers on the server wl_display
Bryce Harrington
bryce at osg.samsung.com
Wed Mar 30 18:26:14 UTC 2016
On Wed, Mar 30, 2016 at 09:05:07AM +0300, Giulio Camuffo wrote:
> 2016-03-30 2:10 GMT+03:00 Bryce Harrington <bryce at osg.samsung.com>:
> > On Wed, Mar 23, 2016 at 04:31:16PM +0200, Giulio Camuffo wrote:
> >> The new wl_display_add_protocol_logger allows to set a function as
> >> a logger, which will get called when a new request is received or an
> >> event is sent.
> >> This is akin to setting WAYLAND_DEBUG=1, but more powerful because it
> >> can be enabled at run time and allows to show the log e.g. in a UI view.
> >>
> >> Signed-off-by: Giulio Camuffo <giulio.camuffo at kdab.com>
> >
> > Hi Giulio,
> >
> > This looks pretty interesting but I have a few questions.
> >
> > This patch allows adding an arbitrary number of watchers to tap the
> > client/server communication stream at the wayland display layer. The
> > data is rendered down into strings formatted in the same style as
> > wayland's current logging output.
> >
> > You mention a use case of a UI view, so first question is what is the
> > use case for allowing multiple loggers? Obviously the implementation
> > would be simpler if you just have a single logger (plus stderr).
>
> I think this would be fragile. Say a compositor has a dropdown log
> console, it would install the log handler itself and an external tool
> would not work, or it would replace the handler and break the
> compositor's internal view.
[Note that my pushing back here is not saying that it *should* be a
single logger, but that the use case for multiple loggers is not well
defined.]
If this is a functionality that is used internally by the compositor,
then there seems little point in more than one logger; the compositor
can simply pass or copy the data as it sees fit.
If we bring external tools into the mix, then multiple loggers does
appear to be of value, but now we have to think about security issues.
We would want the compositor to ensure this access is controlled in some
fashion, e.g. a dbus connection or a direct socket connection or
whatnot. But if the compositor is going to wrapper the API, then why
not have this wrapper code be the logger, and multiplex the data to both
internal and authorized external users.
Again, I'm not opposed to the idea of multiple loggers, but that if we
think in that direction there's a lot more I think has to be considered.
And it seems not necessarily the only way to solve the functional need
here. So I would like to better understand your vision of how this
would be used in practice, in more detail.
So like, one use case I can think of where you would indeed want
multiple loggers is if loggers could be set to return different kinds of
data depending on how they're configured. E.g. applying filters on what
is returned, or changing the level of detail returned. If all the
loggers got the same data, and they're all getting them through the
compositor, then it seems like wayland could have a single logger and
let the compositor pass the data around as needed; but if loggers can
vary in the data they get, then something like your proposal seems like
it might be a stronger design.
Now, if external users is a principle use case, then maybe instead of an
internal API to the compositor, we should be thinking about making it an
actual wayland protocol thing with privileged client access or some sort
of strong control so that the API is only usable in testing conditions.
> > It seems to me that for a UI log browser you're going to want
> > functionality to filter or reformat the raw data, so my second question
> > is why the API renders all the data down to a string, rather than just
> > copy the data into a structure and pass that? A UI log browser could
> > then format the data as it wished after applying its own filters. This
> > would also obviate the need for wl_closure_format() so wl_closure_print
> > could stay as it is.
>
> I have wondered about that, but the problem is that some of the API,
> such as wl_closure is private. So we'd need to make that public, or to
> add new API to use in place of that.
Right, but my suggestion here is to create a new struct, and just copy
in the raw bits from wl_closure or other places that we would normally
be printing in the string. So nothing would need to be made public, and
we wouldn't be exposing anything that isn't already exposed via the
logging functionality.
> > Although, I wonder (third question) if this logging system is in place,
> > could wl_closure_print() be redone to be a logger function? This would
> > simplify the code somewhat, and also make it possible to turn stderr
> > logging on/off at runtime, which I suppose could be handy when
> > debugging in certain circumstances.
>
> This sounds interesting, and another reason why having only one
> handler would be limiting.
Well in fact that's what raised the question for me. I had assumed the
reason for the multiple loggers is so it could handle stderr as well as
a secondary stream for the compositor.
Bryce
> Thanks,
> Giulio
>
> >
> > Bryce
> >
> >
> >> ---
> >> src/connection.c | 117 ++++++++++++++++++++++++++++++++++------------
> >> src/wayland-private.h | 4 ++
> >> src/wayland-server-core.h | 13 ++++++
> >> src/wayland-server.c | 94 ++++++++++++++++++++++++++++++++++---
> >> 4 files changed, 192 insertions(+), 36 deletions(-)
> >>
> >> diff --git a/src/connection.c b/src/connection.c
> >> index c0e322f..f6447c0 100644
> >> --- a/src/connection.c
> >> +++ b/src/connection.c
> >> @@ -1181,71 +1181,128 @@ wl_closure_queue(struct wl_closure *closure, struct wl_connection *connection)
> >> return result;
> >> }
> >>
> >> -void
> >> -wl_closure_print(struct wl_closure *closure, struct wl_object *target, int send)
> >> +static inline int
> >> +min(int a, int b)
> >> +{
> >> + return a < b ? a : b;
> >> +}
> >> +
> >> +/** Formats the closure and returns a static const char * with the value,
> >> + * in the 'interface at id.message_name(args)' format.
> >> + * DO NOT free or mess with the returned pointer.
> >> + */
> >> +const char *
> >> +wl_closure_format(struct wl_closure *closure, struct wl_object *target)
> >> {
> >> + static char *buffer = NULL;
> >> + static size_t buf_size;
> >> int i;
> >> struct argument_details arg;
> >> const char *signature = closure->message->signature;
> >> - struct timespec tp;
> >> - unsigned int time;
> >> + size_t size = 0;
> >>
> >> - clock_gettime(CLOCK_REALTIME, &tp);
> >> - time = (tp.tv_sec * 1000000L) + (tp.tv_nsec / 1000);
> >> + if (!buffer) {
> >> + buf_size = 128;
> >> + buffer = malloc(buf_size);
> >> + }
> >>
> >> - fprintf(stderr, "[%10.3f] %s%s@%u.%s(",
> >> - time / 1000.0,
> >> - send ? " -> " : "",
> >> - target->interface->name, target->id,
> >> - closure->message->name);
> >> + size = snprintf(buffer, buf_size, "%s@%u.%s(",
> >> + target->interface->name, target->id,
> >> + closure->message->name);
> >>
> >> for (i = 0; i < closure->count; i++) {
> >> signature = get_next_argument(signature, &arg);
> >> if (i > 0)
> >> - fprintf(stderr, ", ");
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size),
> >> + ", ");
> >>
> >> switch (arg.type) {
> >> case 'u':
> >> - fprintf(stderr, "%u", closure->args[i].u);
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size),
> >> + "%u", closure->args[i].u);
> >> break;
> >> case 'i':
> >> - fprintf(stderr, "%d", closure->args[i].i);
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size),
> >> + "%d", closure->args[i].i);
> >> break;
> >> case 'f':
> >> - fprintf(stderr, "%f",
> >> - wl_fixed_to_double(closure->args[i].f));
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size), "%f",
> >> + wl_fixed_to_double(closure->args[i].f));
> >> break;
> >> case 's':
> >> - fprintf(stderr, "\"%s\"", closure->args[i].s);
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size),
> >> + "\"%s\"", closure->args[i].s);
> >> break;
> >> case 'o':
> >> if (closure->args[i].o)
> >> - fprintf(stderr, "%s@%u",
> >> - closure->args[i].o->interface->name,
> >> - closure->args[i].o->id);
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size), "%s@%u",
> >> + closure->args[i].o->interface->name,
> >> + closure->args[i].o->id);
> >> else
> >> - fprintf(stderr, "nil");
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size),
> >> + "nil");
> >> break;
> >> case 'n':
> >> - fprintf(stderr, "new id %s@",
> >> - (closure->message->types[i]) ?
> >> - closure->message->types[i]->name :
> >> - "[unknown]");
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size),
> >> + "new id %s@",
> >> + (closure->message->types[i]) ?
> >> + closure->message->types[i]->name :
> >> + "[unknown]");
> >> if (closure->args[i].n != 0)
> >> - fprintf(stderr, "%u", closure->args[i].n);
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size),
> >> + "%u", closure->args[i].n);
> >> else
> >> - fprintf(stderr, "nil");
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size),
> >> + "nil");
> >> break;
> >> case 'a':
> >> - fprintf(stderr, "array");
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size),
> >> + "array");
> >> break;
> >> case 'h':
> >> - fprintf(stderr, "fd %d", closure->args[i].h);
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size),
> >> + "fd %d", closure->args[i].h);
> >> break;
> >> }
> >> }
> >>
> >> - fprintf(stderr, ")\n");
> >> + size += snprintf(buffer + size,
> >> + buf_size - min(size, buf_size), ")");
> >> +
> >> + if (size >= buf_size) {
> >> + buf_size = size + 1;
> >> + buffer = realloc(buffer, buf_size);
> >> + return wl_closure_format(closure, target);
> >> + }
> >> +
> >> + return buffer;
> >> +}
> >> +
> >> +void
> >> +wl_closure_print(struct wl_closure *closure, struct wl_object *target, int send)
> >> +{
> >> + struct timespec tp;
> >> + unsigned int time;
> >> +
> >> + clock_gettime(CLOCK_REALTIME, &tp);
> >> + time = (tp.tv_sec * 1000000L) + (tp.tv_nsec / 1000);
> >> +
> >> + fprintf(stderr, "[%10.3f] %s%s\n",
> >> + time / 1000.0,
> >> + send ? "-> " : "",
> >> + wl_closure_format(closure, target));
> >> }
> >>
> >> void
> >> diff --git a/src/wayland-private.h b/src/wayland-private.h
> >> index 994bc45..6689195 100644
> >> --- a/src/wayland-private.h
> >> +++ b/src/wayland-private.h
> >> @@ -210,6 +210,10 @@ void
> >> wl_closure_print(struct wl_closure *closure,
> >> struct wl_object *target, int send);
> >>
> >> +const char *
> >> +wl_closure_format(struct wl_closure *closure,
> >> + struct wl_object *target);
> >> +
> >> void
> >> wl_closure_destroy(struct wl_closure *closure);
> >>
> >> diff --git a/src/wayland-server-core.h b/src/wayland-server-core.h
> >> index 9980c29..ea9201d 100644
> >> --- a/src/wayland-server-core.h
> >> +++ b/src/wayland-server-core.h
> >> @@ -514,6 +514,19 @@ wl_shm_buffer_create(struct wl_client *client,
> >>
> >> void wl_log_set_handler_server(wl_log_func_t handler);
> >>
> >> +enum wl_protocol_logger_direction {
> >> + WL_PROTOCOL_LOGGER_INCOMING,
> >> + WL_PROTOCOL_LOGGER_OUTGOING,
> >> +};
> >> +
> >> +typedef void (*wl_protocol_logger_func_t)(void *, struct wl_resource *,
> >> + enum wl_protocol_logger_direction, const char *);
> >> +void wl_add_protocol_logger(struct wl_display *display,
> >> + wl_protocol_logger_func_t, void *user_data);
> >> +
> >> +void wl_remove_protocol_logger(struct wl_display *display,
> >> + wl_protocol_logger_func_t, void *user_data);
> >> +
> >> #ifdef __cplusplus
> >> }
> >> #endif
> >> diff --git a/src/wayland-server.c b/src/wayland-server.c
> >> index e47ccec..6118f60 100644
> >> --- a/src/wayland-server.c
> >> +++ b/src/wayland-server.c
> >> @@ -95,6 +95,7 @@ struct wl_display {
> >> struct wl_list global_list;
> >> struct wl_list socket_list;
> >> struct wl_list client_list;
> >> + struct wl_list protocol_loggers;
> >>
> >> struct wl_signal destroy_signal;
> >> struct wl_signal create_client_signal;
> >> @@ -121,10 +122,39 @@ struct wl_resource {
> >> void *data;
> >> int version;
> >> wl_dispatcher_func_t dispatcher;
> >> + struct wl_resource *parent;
> >> +};
> >> +
> >> +struct wl_protocol_logger {
> >> + struct wl_list link;
> >> + wl_protocol_logger_func_t func;
> >> + void *user_data;
> >> };
> >>
> >> static int debug_server = 0;
> >>
> >> +static void
> >> +closure_print(struct wl_resource *resource, struct wl_closure *closure, int send)
> >> +{
> >> + struct wl_object *object = &resource->object;
> >> + struct wl_display *display = resource->client->display;
> >> + struct wl_protocol_logger *protocol_logger;
> >> + const char *message;
> >> +
> >> + if (debug_server)
> >> + wl_closure_print(closure, object, send);
> >> +
> >> + if (!wl_list_empty(&display->protocol_loggers)) {
> >> + message = wl_closure_format(closure, object);
> >> + wl_list_for_each(protocol_logger, &display->protocol_loggers, link) {
> >> + protocol_logger->func(protocol_logger->user_data,
> >> + resource,
> >> + send ? WL_PROTOCOL_LOGGER_OUTGOING :
> >> + WL_PROTOCOL_LOGGER_INCOMING, message);
> >> + }
> >> + }
> >> +}
> >> +
> >> WL_EXPORT void
> >> wl_resource_post_event_array(struct wl_resource *resource, uint32_t opcode,
> >> union wl_argument *args)
> >> @@ -143,8 +173,7 @@ wl_resource_post_event_array(struct wl_resource *resource, uint32_t opcode,
> >> if (wl_closure_send(closure, resource->client->connection))
> >> resource->client->error = 1;
> >>
> >> - if (debug_server)
> >> - wl_closure_print(closure, object, true);
> >> + closure_print(resource, closure, true);
> >>
> >> wl_closure_destroy(closure);
> >> }
> >> @@ -183,8 +212,7 @@ wl_resource_queue_event_array(struct wl_resource *resource, uint32_t opcode,
> >> if (wl_closure_queue(closure, resource->client->connection))
> >> resource->client->error = 1;
> >>
> >> - if (debug_server)
> >> - wl_closure_print(closure, object, true);
> >> + closure_print(resource, closure, true);
> >>
> >> wl_closure_destroy(closure);
> >> }
> >> @@ -331,8 +359,7 @@ wl_client_connection_data(int fd, uint32_t mask, void *data)
> >> break;
> >> }
> >>
> >> - if (debug_server)
> >> - wl_closure_print(closure, object, false);
> >> + closure_print(resource, closure, false);
> >>
> >> if ((resource_flags & WL_MAP_ENTRY_LEGACY) ||
> >> resource->dispatcher == NULL) {
> >> @@ -879,6 +906,7 @@ wl_display_create(void)
> >> wl_list_init(&display->socket_list);
> >> wl_list_init(&display->client_list);
> >> wl_list_init(&display->registry_resource_list);
> >> + wl_list_init(&display->protocol_loggers);
> >>
> >> wl_signal_init(&display->destroy_signal);
> >> wl_signal_init(&display->create_client_signal);
> >> @@ -1463,6 +1491,60 @@ wl_log_set_handler_server(wl_log_func_t handler)
> >> wl_log_handler = handler;
> >> }
> >>
> >> +/** Adds a new protocol logger.
> >> + *
> >> + * When a new protocol message arrives or is sent from the server
> >> + * all the protocol logger functions will be called, carrying the
> >> + * \a user_data pointer, the relevant \a wl_resource, the direction
> >> + * of the message (incoming or outgoing) and the actual message.
> >> + *
> >> + * \param func The function to call to log a new protocol message
> >> + * \param user_data The user data pointer to pass to \a func
> >> + *
> >> + * \sa wl_remove_protocol_logger
> >> + *
> >> + * \memberof wl_display
> >> + */
> >> +WL_EXPORT void
> >> +wl_add_protocol_logger(struct wl_display *display,
> >> + wl_protocol_logger_func_t func, void *user_data)
> >> +{
> >> + struct wl_protocol_logger *logger;
> >> +
> >> + logger = malloc(sizeof *logger);
> >> + if (!logger)
> >> + return;
> >> +
> >> + logger->func = func;
> >> + logger->user_data = user_data;
> >> + wl_list_init(&logger->link);
> >> + wl_list_insert(&display->protocol_loggers, &logger->link);
> >> +}
> >> +
> >> +/** Removes a protocol logger.
> >> + *
> >> + * If a protocol logger was previously added with the same \a func and
> >> + * \a user_data, it will be removed from the display's list so that it
> >> + * will not be invoked anymore.
> >> + *
> >> + * \sa wl_add_protocol_logger
> >> + *
> >> + * \memberof wl_display
> >> + */
> >> +WL_EXPORT void
> >> +wl_remove_protocol_logger(struct wl_display *display,
> >> + wl_protocol_logger_func_t func, void *user_data)
> >> +{
> >> + struct wl_protocol_logger *logger;
> >> + wl_list_for_each(logger, &display->protocol_loggers, link) {
> >> + if (logger->func == func && logger->user_data == user_data) {
> >> + wl_list_remove(&logger->link);
> >> + free(logger);
> >> + return;
> >> + }
> >> + }
> >> +}
> >> +
> >> /** Add support for a wl_shm pixel format
> >> *
> >> * \param display The display object
> >> --
> >> 2.7.4
> >>
> >> _______________________________________________
> >> wayland-devel mailing list
> >> wayland-devel at lists.freedesktop.org
> >> https://lists.freedesktop.org/mailman/listinfo/wayland-devel
More information about the wayland-devel
mailing list