From 3db476930b354672be8efe589ea688dcc08573fd Mon Sep 17 00:00:00 2001 From: Peter Hutterer Date: Tue, 11 Aug 2020 11:28:31 +1000 Subject: [PATCH] Add a bunch of log_debug messages We can remove those when we have a working implementation, for now it's too painful to debug when an exchange doesn't work for some reason. Signed-off-by: Peter Hutterer --- src/libei.c | 20 +++++++++++++++++++- src/libeis-client.c | 12 ++++++++++++ src/libeis.c | 2 ++ test/eierpecken.c | 24 +++++++++++++++++------- 4 files changed, 50 insertions(+), 8 deletions(-) diff --git a/src/libei.c b/src/libei.c index c965263..738edc0 100644 --- a/src/libei.c +++ b/src/libei.c @@ -42,7 +42,7 @@ /* The message type for the wire format */ enum message_type { - MESSAGE_CONNECTED, + MESSAGE_CONNECTED = 1, MESSAGE_DISCONNECTED, MESSAGE_ADDED, MESSAGE_REMOVED, @@ -171,6 +171,8 @@ ei_dispatch(struct ei *ei) static void ei_queue_event(struct ei *ei, struct ei_event *event) { + log_debug(ei, "queuing event type %d\n", event->type); + list_append(&ei->event_queue, &event->link); } @@ -212,6 +214,8 @@ ei_queue_removed_event(struct ei_device *device) { struct ei *ei= ei_device_get_context(device); + log_debug(ei, "queuing removed event\n"); + struct ei_event_client *e = xalloc(sizeof(*e)); ei_event_init_object(&e->base, &ei->object); e->base.type = EI_EVENT_DEVICE_REMOVED; @@ -241,6 +245,8 @@ connection_send_connect(struct ei *ei) ei->state == EI_STATE_DISCONNECTED) return 0; + log_debug(ei, "sending connect\n"); + ClientMessage msg = CLIENT_MESSAGE__INIT; Connect connect = CONNECT__INIT; @@ -257,6 +263,8 @@ connection_send_disconnect(struct ei *ei) ei->state == EI_STATE_DISCONNECTED) return 0; + log_debug(ei, "sending disconnect\n"); + ClientMessage msg = CLIENT_MESSAGE__INIT; Disconnect disconnect = DISCONNECT__INIT; @@ -273,6 +281,8 @@ connection_send_add(struct ei *ei, struct ei_device *device) ei->state == EI_STATE_DISCONNECTED) return 0; + log_debug(ei, "sending add\n"); + ClientMessage msg = CLIENT_MESSAGE__INIT; AddDevice add = ADD_DEVICE__INIT; @@ -292,6 +302,8 @@ connection_send_remove(struct ei *ei, struct ei_device *device) ei->state == EI_STATE_DISCONNECTED) return 0; + log_debug(ei, "sending remove\n"); + ClientMessage msg = CLIENT_MESSAGE__INIT; RemoveDevice remove = REMOVE_DEVICE__INIT; @@ -428,6 +440,8 @@ ei_added(struct ei *ei, uint32_t deviceid, uint32_t capabilities) { struct ei_device *d; + log_debug(ei, "Added device %d with caps %#x\n", deviceid, capabilities); + list_for_each(d, &ei->devices, link) { if (d->id == deviceid) { ei_device_set_capabilities(d, capabilities); @@ -446,6 +460,8 @@ ei_removed(struct ei *ei, uint32_t deviceid) { struct ei_device *d; + log_debug(ei, "Removed device %d\n", deviceid); + list_for_each(d, &ei->devices, link) { if (d->id == deviceid) { ei_queue_removed_event(d); @@ -685,6 +701,8 @@ connection_dispatch(struct source *source, void *userdata) goto error; } + log_debug(ei, "Message type %d\n", msg->type); + idx += len; switch (ei->state) { diff --git a/src/libeis-client.c b/src/libeis-client.c index 382c2ab..23af560 100644 --- a/src/libeis-client.c +++ b/src/libeis-client.c @@ -162,6 +162,9 @@ client_send_disconnect(struct eis_client *client) ServerMessage msg = SERVER_MESSAGE__INIT; Disconnected disconnected = DISCONNECTED__INIT; + log_debug(eis_client_get_context(client), + "sending disconnect\n"); + msg.disconnected = &disconnected; msg.msg_case = SERVER_MESSAGE__MSG_DISCONNECTED; @@ -174,6 +177,9 @@ client_send_connect(struct eis_client *client) ServerMessage msg = SERVER_MESSAGE__INIT; Connected connected = CONNECTED__INIT; + log_debug(eis_client_get_context(client), + "sending connect\n"); + msg.connected = &connected; msg.msg_case = SERVER_MESSAGE__MSG_CONNECTED; @@ -186,6 +192,9 @@ client_send_added(struct eis_client *client, struct eis_device *device) ServerMessage msg = SERVER_MESSAGE__INIT; Added added = ADDED__INIT; + log_debug(eis_client_get_context(client), + "sending added\n"); + added.deviceid = device->id; added.capabilities = device->capabilities; @@ -201,6 +210,9 @@ client_send_removed(struct eis_client *client, struct eis_device *device) ServerMessage msg = SERVER_MESSAGE__INIT; Removed removed = REMOVED__INIT; + log_debug(eis_client_get_context(client), + "sending removed\n"); + removed.deviceid = device->id; msg.removed = &removed; diff --git a/src/libeis.c b/src/libeis.c index 8016495..4785cd4 100644 --- a/src/libeis.c +++ b/src/libeis.c @@ -202,6 +202,8 @@ eis_dispatch(struct eis *eis) static void eis_queue_event(struct eis *eis, struct eis_event *event) { + log_debug(eis, "queuing event type %d\n", event->type); + list_append(&eis->event_queue, &event->link); } diff --git a/test/eierpecken.c b/test/eierpecken.c index c244f90..a0bfc5b 100644 --- a/test/eierpecken.c +++ b/test/eierpecken.c @@ -160,10 +160,10 @@ peck_handle_eis_connect(struct peck *peck, struct eis_event *e) { struct eis_client *client = eis_event_get_client(e); if (flag_is_set(peck->eis_behavior, PECK_EIS_BEHAVIOR_ACCEPT_CLIENT)) { - log_debug(peck, "Accepting client: %s\n", eis_client_get_name(client)); + log_debug(peck, "EIS accepting client: %s\n", eis_client_get_name(client)); eis_client_connect(client); } else { - log_debug(peck, "Disconnecting client: %s\n", eis_client_get_name(client)); + log_debug(peck, "EIS disconnecting client: %s\n", eis_client_get_name(client)); eis_client_disconnect(client); } } @@ -203,6 +203,8 @@ peck_dispatch_eis(struct peck *peck) { struct eis *eis = peck->eis; + log_debug(peck, "EIS Dispatch\n"); + while(true) { eis_dispatch(eis); tristate process_event = tristate_unset; @@ -211,6 +213,8 @@ peck_dispatch_eis(struct peck *peck) if (!e) break; + log_debug(peck, "EIS event %d\n", eis_event_get_type(e)); + switch (eis_event_get_type(e)) { case EIS_EVENT_NONE: abort(); @@ -231,9 +235,12 @@ peck_dispatch_eis(struct peck *peck) break; } - if (!tristate_is_yes(process_event)) + if (!tristate_is_yes(process_event)) { + log_debug(peck, "... punting to caller\n"); break; + } + log_debug(peck, "... processing\n"); /* manual unref, _cleanup_ will take care of the real event */ eis_event_unref(e); e = eis_get_event(eis); @@ -245,21 +252,21 @@ peck_dispatch_eis(struct peck *peck) peck_handle_eis_connect(peck, e); break; case EIS_EVENT_CLIENT_DISCONNECT: - log_debug(peck, "Disconnecting client: %s\n", + log_debug(peck, "EIS disconnecting client: %s\n", eis_client_get_name(eis_event_get_client(e))); eis_client_disconnect(eis_event_get_client(e)); break; case EIS_EVENT_DEVICE_ADDED: if (tristate_is_yes(peck_check_eis_added(peck, e))) { + log_debug(peck, "EIS adding device\n"); eis_device_connect(eis_event_get_device(e)); - log_debug(peck, "Connecting device\n"); } else { - log_debug(peck, "Disconnecting device\n"); + log_debug(peck, "EIS refusing device\n"); eis_device_disconnect(eis_event_get_device(e)); } break; case EIS_EVENT_DEVICE_REMOVED: - log_debug(peck, "Disconnecting device\n"); + log_debug(peck, "EIS removing device\n"); eis_device_disconnect(eis_event_get_device(e)); break; default: @@ -293,6 +300,8 @@ peck_dispatch_ei(struct peck *peck) { struct ei *ei = peck->ei; + log_debug(peck, "ei is dispatching\n"); + while (true) { ei_dispatch(ei); tristate process_event = tristate_no; @@ -326,6 +335,7 @@ peck_dispatch_ei(struct peck *peck) case EI_EVENT_NONE: abort(); case EI_EVENT_CONNECT: + log_debug(peck, "ei is connected\n"); /* Nothing to do here */ break; case EI_EVENT_DEVICE_ADDED: