[PATCH wayland] Add API to install protocol loggers on the server wl_display
Giulio Camuffo
giuliocamuffo at gmail.com
Wed Mar 30 18:56:08 UTC 2016
2016-03-30 21:26 GMT+03:00 Bryce Harrington <bryce at osg.samsung.com>:
> 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.
This would mean that the tool would only work with certain
compositors, but my idea was to have the API compositor agnostic.
Moreover, this requires to add a proxy in the compositors, adding
complexity, where it can be done more simply in libwayland.
>
> 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.
I hadn't thought about security issues. It doesn't appear to me this
is sensitive data, and anyway the API as it is in this patch doesn't
directly expose anything to any process. The way i'm using it in the
tool i'm working on is by attaching to the compositor process with
ptrace or the like, and at that point there is no point in trying to
put some security mechanism.
>
> 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.
Honestly, i only need one logger. My tool attaches to the compositor,
installs the logger and receives the data. But i don't see how having
multiple loggers is or could be a problem, on the other hand i see
how, for my use case, having a single one could be a problem, if the
compositor also adds a logger.
I think that tools inspecting the state of any process should not
change anything, unless they actually mean to. Having a single logger
is a problem, when the compositor installs one too. You may say that
compositors likely won't do that but there isn't any guarantee about
that and a solution that only likely works is no good.
>
> 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.
Making a protocol is an interesting idea, but while i am indeed an
external user, in a sense, a protocol would not be useful for me
because i'd attach to the process anyway for other reasons.
>
>> > 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.
That may be doable, i'll have a look.
Thanks,
Giulio
>
>> > 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