connection: Simplify wl_closure_print

Client message observers 1/6

Cleans up wl_closure_print(), and adds a client-private closure_log()
intermediate function.

This patch simplifies wl_closure_print() slightly by moving some client-only
details to a new closure_log() intermediate function. This new function will
also handle delivering messages to the new listener callback in a subsequent
patch.

closure_log() internally handles the check for logging being enabled,
simplifying its callers, and returns early if logging is not enabled. This check
becomes a bit more complex when there can be listeners.

closure_log() also handles the work same transformation performed by
id_from_object(), by making a copy of the args, and applying the transform to
the copy before passing the arguments to wl_closure_print(). Doing it this way
means the same arguments can also be passed to the eventual listeners.

The boolean "discarded" argument for wl_closure_print() has been replaced by a
"discarded_reason" string argument, allowing an arbitrary reason string to be
passed in. For now only "discarded[]" is printed as an empty reason string is
passed if the message was discarded, but that will also change.

Signed-off-by: Lloyd Pique <lpique@google.com>

src/connection.c

@@ -1480,8 +1480,7 @@ wl_closure_queue(struct wl_closure *closure, struct wl_connection *connection)
 
 void
 wl_closure_print(struct wl_closure *closure, struct wl_object *target,
-		 int send, int discarded, uint32_t (*n_parse)(union wl_argument *arg),
-		 const char *queue_name)
+		 bool send, const char* discarded_reason, const char *queue_name)
 {
 	int i;
 	struct argument_details arg;
@@ -1500,13 +1499,14 @@ wl_closure_print(struct wl_closure *closure, struct wl_object *target,
 	clock_gettime(CLOCK_REALTIME, &tp);
 	time = (tp.tv_sec * 1000000L) + (tp.tv_nsec / 1000);
 
-	fprintf(f, "[%7u.%03u] ", time / 1000, time % 1000);
-
-	if (queue_name)
-		fprintf(f, "{%s} ", queue_name);
-
-	fprintf(f, "%s%s%s#%u.%s(",
-		discarded ? "discarded " : "",
+	fprintf(f, "[%7u.%03u] %s%s%s%s%s%s%s%s#%u.%s(",
+		time / 1000, time % 1000,
+		(queue_name != NULL) ? "{" : "",
+		(queue_name != NULL) ? queue_name : "",
+		(queue_name != NULL) ? "} " : "",
+		(discarded_reason != NULL) ? "discarded[" : "",
+		(discarded_reason != NULL) ? discarded_reason : "",
+		(discarded_reason != NULL) ? "] " : "",
 		send ? " -> " : "",
 		target->interface->name, target->id,
 		closure->message->name);
@@ -1551,10 +1551,7 @@ wl_closure_print(struct wl_closure *closure, struct wl_object *target,
 				fprintf(f, "nil");
 			break;
 		case WL_ARG_NEW_ID:
-			if (n_parse)
-				nval = n_parse(&closure->args[i]);
-			else
-				nval = closure->args[i].n;
+			nval = closure->args[i].n;
 
 			fprintf(f, "new id %s#",
 				(closure->message->types[i]) ?

src/wayland-client.c

@@ -115,6 +115,73 @@ struct wl_display {
 
 static int debug_client = 0;
 
+/**
+ * This helper function adjusts the closure arguments before they are logged.
+ * On the client, after the call to create_proxies(), NEW_ID arguments will
+ * point to a wl_proxy accessible via arg.o instead of being an int32
+ * accessible by arg.n, which is what wl_closure_print() attempts to print.
+ * This helper transforms the argument back into an id, so wl_closure_print()
+ * doesn't need to handle that as a special case.
+ *
+ * \param closure  closure to adjust
+ * \param send     if this is closure is for a request
+ *
+ */
+static void
+adjust_closure_args_for_logging(struct wl_closure *closure, bool send)
+{
+	int i;
+	struct argument_details arg;
+	const struct wl_proxy *proxy;
+	const char *signature = closure->message->signature;
+
+	// No adjustment needed for a send.
+	if (send)
+		return;
+
+	for (i = 0; i < closure->count; i++) {
+		signature = get_next_argument(signature, &arg);
+
+		switch (arg.type) {
+		case WL_ARG_NEW_ID:
+			proxy = (struct wl_proxy *)closure->args[i].o;
+			closure->args[i].n = proxy ? proxy->object.id : 0;
+			break;
+		default:
+			break;
+		}
+	}
+}
+
+/**
+ * This function helps log closures from the client, assuming logging is
+ * enabled.
+ *
+ * \param closure    closure for the message
+ * \param proxy      proxy for the message
+ * \param send       true if this is closure is for a request
+ * \param discarded  true if this is message is being discarded
+ * \param queue_name name for the queue for the message
+ *
+ */
+static void
+closure_log(struct wl_closure *closure, struct wl_proxy *proxy, bool send,
+	    bool discarded, const char *queue_name)
+{
+	struct wl_closure adjusted_closure = { 0 };
+
+	// Note: The real closure has extra data (referenced by its args
+	// immediately following the structure in memory, but we don't
+	// need to duplicate that.
+	memcpy(&adjusted_closure, closure, sizeof(struct wl_closure));
+
+	// Adjust the closure arguments.
+	adjust_closure_args_for_logging(&adjusted_closure, send);
+
+	wl_closure_print(&adjusted_closure, &proxy->object, send,
+			 discarded ? "" : NULL, queue_name);
+}
+
 /**
  * This helper function wakes up all threads that are
  * waiting for display->reader_cond (i. e. when reading is done,
@@ -931,8 +998,9 @@ wl_proxy_marshal_array_flags(struct wl_proxy *proxy, uint32_t opcode,
 		if (queue)
 			queue_name = wl_event_queue_get_name(queue);
 
-		wl_closure_print(closure, &proxy->object, true, false, NULL,
-				 queue_name);
+		closure_log(closure, proxy, true, false,
+			    queue_name);
+
 	}
 
 	if (wl_closure_send(closure, proxy->display->connection)) {
@@ -1628,19 +1696,6 @@ queue_event(struct wl_display *display, int len)
 	return size;
 }
 
-static uint32_t
-id_from_object(union wl_argument *arg)
-{
-	struct wl_proxy *proxy;
-
-	if (arg->o) {
-		proxy = (struct wl_proxy *)arg->o;
-		return proxy->object.id;
-	}
-
-	return 0;
-}
-
 static void
 dispatch_event(struct wl_display *display, struct wl_event_queue *queue)
 {
@@ -1663,8 +1718,7 @@ dispatch_event(struct wl_display *display, struct wl_event_queue *queue)
 		bool discarded = proxy_destroyed ||
 				 !(proxy->dispatcher || proxy->object.implementation);
 
-		wl_closure_print(closure, &proxy->object, false, discarded,
-				 id_from_object, queue->name);
+		closure_log(closure, proxy, false, discarded, queue->name);
 	}
 
 	if (proxy_destroyed) {

src/wayland-private.h

@@ -228,8 +228,9 @@ wl_closure_queue(struct wl_closure *closure, struct wl_connection *connection);
 
 void
 wl_closure_print(struct wl_closure *closure,
-		 struct wl_object *target, int send, int discarded,
-		 uint32_t (*n_parse)(union wl_argument *arg),
+		 struct wl_object *target,
+		 bool send,
+		 const char *discarded_reason,
 		 const char *queue_name);
 
 void

src/wayland-server.c

@@ -160,7 +160,7 @@ log_closure(struct wl_resource *resource,
 	struct wl_protocol_logger_message message;
 
 	if (debug_server)
-		wl_closure_print(closure, object, send, false, NULL, NULL);
+		wl_closure_print(closure, object, send, NULL, NULL);
 
 	if (!wl_list_empty(&display->protocol_loggers)) {
 		message.resource = resource;