1From 0000000000000000000000000000000000000000 Mon Sep 17 00:00:00 2001 2From: Lloyd Pique <[email protected]> 3Date: Fri, 11 Mar 2022 20:04:55 -0800 4Subject: [PATCH 6/6] client: Log unknown messages through the observer API 5 6Client message observers 6/6 7 8When the client code receives an event message for an unknown (or zombie) 9object, the code was logging a message only to stderr, and only if debug_client 10was set. 11 12Introduce a helper function to create some temporary wl_closure and related 13structures so that the unknown message can be sent out using the new client 14observer API. This allows the client implementation to potentially log it 15somewhere more useful than to just stderr, and it can register an observer at 16any time too. 17 18Note that the message that is logged is now structured slightly differently, 19though it contains the same content. 20 21Signed-off-by: Lloyd Pique <[email protected]> 22 23diff --git a/src/wayland-client-core.h b/src/wayland-client-core.h 24index a57cbe0..af7c184 100644 25--- a/src/wayland-client-core.h 26+++ b/src/wayland-client-core.h 27@@ -311,6 +311,9 @@ enum wl_client_message_discarded_reason { 28 29 /** The target had no listener or dispatcher */ 30 WL_CLIENT_MESSAGE_DISCARD_NO_LISTENER_ON_DISPATCH, 31+ 32+ /** The target was not valid when the event was demarshalled */ 33+ WL_CLIENT_MESSAGE_DISCARD_UNKNOWN_ID_ON_DEMARSHAL, 34 }; 35 36 /** 37diff --git a/src/wayland-client.c b/src/wayland-client.c 38index ab68bdb..d54e715 100644 39--- a/src/wayland-client.c 40+++ b/src/wayland-client.c 41@@ -178,6 +178,8 @@ get_discarded_reason_str( 42 return "dead proxy on dispatch"; 43 case WL_CLIENT_MESSAGE_DISCARD_NO_LISTENER_ON_DISPATCH: 44 return "no listener on dispatch"; 45+ case WL_CLIENT_MESSAGE_DISCARD_UNKNOWN_ID_ON_DEMARSHAL: 46+ return "unknown id on demarshal"; 47 } 48 return NULL; 49 } 50@@ -237,6 +239,53 @@ closure_log(struct wl_closure *closure, struct wl_proxy *proxy, bool send, 51 } 52 } 53 54+/** 55+ * This function helps log unknown messages on the client, when logging is 56+ * enabled. 57+ * 58+ * \param display current display 59+ * \param zombie true if there was a zombie for the message target 60+ * \param id id of the proxy this message was meant for 61+ * \param opcode opcode from the message 62+ * \param num_fds number of fd arguments for this message 63+ * \param num_bytes byte size of this message 64+ */ 65+static void 66+log_unknown_message(struct wl_display *display, bool zombie, uint32_t id, 67+ int opcode, int num_fds, int num_bytes) 68+{ 69+ char event_detail[100]; 70+ struct wl_interface unknown_interface = { 0 }; 71+ struct wl_proxy unknown_proxy = { 0 }; 72+ struct wl_message unknown_message = { 0 }; 73+ struct wl_closure unknown_closure = { 0 }; 74+ 75+ if (!debug_client && wl_list_empty(&display->observers)) 76+ return; 77+ 78+ snprintf(event_detail, sizeof event_detail, 79+ "[event %d, %d fds, %d bytes]", opcode, num_fds, num_bytes); 80+ 81+ unknown_interface.name = zombie ? "[zombie]" : "[unknown]"; 82+ 83+ unknown_proxy.object.interface = &unknown_interface; 84+ unknown_proxy.object.id = id; 85+ unknown_proxy.display = display; 86+ unknown_proxy.refcount = -1; 87+ unknown_proxy.flags = WL_PROXY_FLAG_WRAPPER; 88+ 89+ unknown_message.name = event_detail; 90+ unknown_message.signature = ""; 91+ unknown_message.types = NULL; 92+ 93+ unknown_closure.message = &unknown_message; 94+ unknown_closure.opcode = opcode; 95+ unknown_closure.proxy = &unknown_proxy; 96+ 97+ closure_log(&unknown_closure, &unknown_proxy, false, 98+ WL_CLIENT_MESSAGE_DISCARD_UNKNOWN_ID_ON_DEMARSHAL); 99+} 100+ 101 /** 102 * This helper function wakes up all threads that are 103 * waiting for display->reader_cond (i. e. when reading is done, 104@@ -1626,8 +1675,6 @@ queue_event(struct wl_display *display, int len) 105 struct wl_closure *closure; 106 const struct wl_message *message; 107 struct wl_event_queue *queue; 108- struct timespec tp; 109- unsigned int time; 110 int num_zombie_fds; 111 112 wl_connection_copy(display->connection, p, sizeof p); 113@@ -1645,17 +1692,9 @@ queue_event(struct wl_display *display, int len) 114 num_zombie_fds = (zombie && opcode < zombie->event_count) ? 115 zombie->fd_count[opcode] : 0; 116 117- if (debug_client) { 118- clock_gettime(CLOCK_REALTIME, &tp); 119- time = (tp.tv_sec * 1000000L) + (tp.tv_nsec / 1000); 120+ log_unknown_message(display, !!zombie, id, opcode, 121+ num_zombie_fds, size); 122 123- fprintf(stderr, "[%7u.%03u] discarded [%s]@%d.[event %d]" 124- "(%d fd, %d byte)\n", 125- time / 1000, time % 1000, 126- zombie ? "zombie" : "unknown", 127- id, opcode, 128- num_zombie_fds, size); 129- } 130 if (num_zombie_fds > 0) 131 wl_connection_close_fds_in(display->connection, 132 num_zombie_fds); 133diff --git a/tests/protocol-logger-test.c b/tests/protocol-logger-test.c 134index 9420b5e..94e437d 100644 135--- a/tests/protocol-logger-test.c 136+++ b/tests/protocol-logger-test.c 137@@ -562,3 +562,250 @@ TEST(client_discards_if_no_listener_on_dispatch) 138 139 logger_teardown(&compositor, &client); 140 } 141+ 142+TEST(client_discards_if_invalid_id_on_demarshal) 143+{ 144+ test_set_timeout(1); 145+ 146+ struct expected_client_message client_messages[] = { 147+ { 148+ .type = WL_CLIENT_MESSAGE_REQUEST, 149+ .discarded_reason = WL_CLIENT_MESSAGE_NOT_DISCARDED, 150+ .class = "wl_display", 151+ .opcode = 0, 152+ .message_name = "sync", 153+ .args_count = 1, 154+ }, 155+ { 156+ .type = WL_CLIENT_MESSAGE_EVENT, 157+ .discarded_reason = 158+ WL_CLIENT_MESSAGE_DISCARD_UNKNOWN_ID_ON_DEMARSHAL, 159+ .class = "[unknown]", 160+ .opcode = 0, 161+ .message_name = "[event 0, 0 fds, 12 bytes]", 162+ .args_count = 0, 163+ }, 164+ { 165+ .type = WL_CLIENT_MESSAGE_EVENT, 166+ .discarded_reason = WL_CLIENT_MESSAGE_NOT_DISCARDED, 167+ .class = "wl_display", 168+ .opcode = 1, 169+ .message_name = "delete_id", 170+ .args_count = 1, 171+ }, 172+ }; 173+ struct compositor compositor = { 0 }; 174+ struct client client = { 0 }; 175+ 176+ logger_setup(&compositor, &client); 177+ 178+ compositor.expected_msg_count = 3; 179+ 180+ client.expected_msg = &client_messages[0]; 181+ client.expected_msg_count = ARRAY_LENGTH(client_messages); 182+ 183+ client.cb = wl_display_sync(client.display); 184+ wl_display_flush(client.display); 185+ 186+ while (compositor.actual_msg_count < compositor.expected_msg_count) { 187+ wl_event_loop_dispatch(compositor.loop, -1); 188+ wl_display_flush_clients(compositor.display); 189+ } 190+ 191+ // To get a WL_CLIENT_MESSAGE_DISCARD_UNKNOWN_ID_ON_DEMARSHAL, we 192+ // destroy the callback before reading and dispatching client events. 193+ wl_callback_destroy(client.cb); 194+ 195+ while (client.actual_msg_count < client.expected_msg_count) { 196+ wl_display_dispatch(client.display); 197+ } 198+ 199+ logger_teardown(&compositor, &client); 200+} 201+ 202+static const struct wl_keyboard_interface keyboard_interface = { 0 }; 203+ 204+static void 205+seat_get_pointer(struct wl_client *client, struct wl_resource *resource, 206+ uint32_t id) 207+{ 208+ assert(false && "Not expected to be called by client."); 209+} 210+ 211+static void 212+seat_get_keyboard(struct wl_client *client, struct wl_resource *resource, 213+ uint32_t id) 214+{ 215+ struct wl_resource *keyboard_res; 216+ 217+ keyboard_res = 218+ wl_resource_create(client, &wl_keyboard_interface, 219+ wl_resource_get_version(resource), id); 220+ wl_resource_set_implementation(keyboard_res, &keyboard_interface, NULL, 221+ NULL); 222+ 223+ wl_keyboard_send_key(keyboard_res, 0, 0, 0, 0); 224+} 225+ 226+static void 227+seat_get_touch(struct wl_client *client, struct wl_resource *resource, 228+ uint32_t id) 229+{ 230+ assert(false && "Not expected to be called by client."); 231+} 232+ 233+static void 234+seat_release(struct wl_client *client, struct wl_resource *resource) 235+{ 236+ wl_resource_destroy(resource); 237+} 238+ 239+static const struct wl_seat_interface seat_interface = { 240+ &seat_get_pointer, 241+ &seat_get_keyboard, 242+ &seat_get_touch, 243+ &seat_release, 244+}; 245+ 246+static void 247+bind_seat(struct wl_client *client, void *data, uint32_t vers, uint32_t id) 248+{ 249+ struct wl_resource *seat_res; 250+ 251+ seat_res = wl_resource_create(client, &wl_seat_interface, vers, id); 252+ wl_resource_set_implementation(seat_res, &seat_interface, NULL, NULL); 253+} 254+ 255+static void 256+registry_seat_listener_handle_global(void *data, struct wl_registry *registry, 257+ uint32_t id, const char *intf, 258+ uint32_t ver) 259+{ 260+ uint32_t *seat_id_ptr = data; 261+ 262+ if (strcmp(intf, wl_seat_interface.name) == 0) { 263+ *seat_id_ptr = id; 264+ } 265+} 266+ 267+static const struct wl_registry_listener registry_seat_listener = { 268+ registry_seat_listener_handle_global, NULL 269+}; 270+ 271+TEST(client_discards_if_zombie_on_demarshal) 272+{ 273+ test_set_timeout(1); 274+ 275+ struct expected_client_message client_messages[] = { 276+ { 277+ .type = WL_CLIENT_MESSAGE_REQUEST, 278+ .discarded_reason = WL_CLIENT_MESSAGE_NOT_DISCARDED, 279+ .class = "wl_display", 280+ .opcode = 1, 281+ .message_name = "get_registry", 282+ .args_count = 1, 283+ }, 284+ { 285+ .type = WL_CLIENT_MESSAGE_EVENT, 286+ .discarded_reason = WL_CLIENT_MESSAGE_NOT_DISCARDED, 287+ .class = "wl_registry", 288+ .opcode = 0, 289+ .message_name = "global", 290+ .args_count = 3, 291+ }, 292+ { 293+ .type = WL_CLIENT_MESSAGE_REQUEST, 294+ .discarded_reason = WL_CLIENT_MESSAGE_NOT_DISCARDED, 295+ .class = "wl_registry", 296+ .opcode = 0, 297+ .message_name = "bind", 298+ .args_count = 4, 299+ }, 300+ { 301+ .type = WL_CLIENT_MESSAGE_REQUEST, 302+ .discarded_reason = WL_CLIENT_MESSAGE_NOT_DISCARDED, 303+ .class = "wl_seat", 304+ .opcode = 1, 305+ .message_name = "get_keyboard", 306+ .args_count = 1, 307+ }, 308+ { 309+ .type = WL_CLIENT_MESSAGE_REQUEST, 310+ .discarded_reason = WL_CLIENT_MESSAGE_NOT_DISCARDED, 311+ .class = "wl_keyboard", 312+ .opcode = 0, 313+ .message_name = "release", 314+ .args_count = 0, 315+ }, 316+ { 317+ .type = WL_CLIENT_MESSAGE_REQUEST, 318+ .discarded_reason = WL_CLIENT_MESSAGE_NOT_DISCARDED, 319+ .class = "wl_seat", 320+ .opcode = 3, 321+ .message_name = "release", 322+ .args_count = 0, 323+ }, 324+ { 325+ .type = WL_CLIENT_MESSAGE_EVENT, 326+ .discarded_reason = 327+ WL_CLIENT_MESSAGE_DISCARD_UNKNOWN_ID_ON_DEMARSHAL, 328+ .class = "[zombie]", 329+ .opcode = 3, 330+ .message_name = "[event 3, 0 fds, 24 bytes]", 331+ .args_count = 0, 332+ }, 333+ }; 334+ 335+ struct compositor compositor = { 0 }; 336+ struct client client = { 0 }; 337+ struct wl_global *g_keyboard; 338+ struct wl_registry *registry; 339+ struct wl_seat *seat; 340+ struct wl_keyboard *keyboard; 341+ int32_t seat_id; 342+ 343+ logger_setup(&compositor, &client); 344+ 345+ client.expected_msg = &client_messages[0]; 346+ client.expected_msg_count = ARRAY_LENGTH(client_messages); 347+ 348+ g_keyboard = wl_global_create(compositor.display, &wl_seat_interface, 349+ 5, &compositor.display, bind_seat); 350+ 351+ registry = wl_display_get_registry(client.display); 352+ wl_registry_add_listener(registry, ®istry_seat_listener, &seat_id); 353+ wl_display_flush(client.display); 354+ 355+ compositor.actual_msg_count = 0; 356+ compositor.expected_msg_count = 2; 357+ 358+ while (compositor.actual_msg_count < compositor.expected_msg_count) { 359+ wl_event_loop_dispatch(compositor.loop, -1); 360+ wl_display_flush_clients(compositor.display); 361+ } 362+ 363+ wl_display_dispatch(client.display); 364+ 365+ seat = wl_registry_bind(registry, seat_id, &wl_seat_interface, 5); 366+ keyboard = wl_seat_get_keyboard(seat); 367+ wl_display_flush(client.display); 368+ 369+ compositor.actual_msg_count = 0; 370+ compositor.expected_msg_count = 3; 371+ 372+ while (compositor.actual_msg_count < compositor.expected_msg_count) { 373+ wl_event_loop_dispatch(compositor.loop, -1); 374+ wl_display_flush_clients(compositor.display); 375+ } 376+ 377+ wl_keyboard_release(keyboard); 378+ wl_seat_release(seat); 379+ 380+ wl_display_dispatch(client.display); 381+ 382+ wl_registry_destroy(registry); 383+ 384+ wl_global_destroy(g_keyboard); 385+ 386+ logger_teardown(&compositor, &client); 387+} 388