diff --git a/src/transport_layer/auto_socket.c b/src/transport_layer/auto_socket.c index a1530cc1..b92d94e1 100644 --- a/src/transport_layer/auto_socket.c +++ b/src/transport_layer/auto_socket.c @@ -653,8 +653,8 @@ static void reconcile_iface(struct AUTO_SOCKET* as, uint32_t ifindex, const char struct sockaddr_storage old4 = sock->interface_addr; socket_monitor_update_if_addr(sock); if (memcmp(&old4, &sock->interface_addr, sizeof(old4)) != 0) { - DEBUG_INFO(DEBUG_CATEGORY_AS, "[as] v4 UDP interface_addr changed: %s -> %s", - sockaddr_storage_to_str(&old4).str, sockaddr_storage_to_str(&sock->interface_addr).str); + DEBUG_INFO(DEBUG_CATEGORY_AS, "[as] v4 UDP (%s) addr changed: %s → %s", + ifname, sockaddr_storage_to_str(&old4).str, sockaddr_storage_to_str(&sock->interface_addr).str); etcp_socket_cbk_fire(sock, ETCP_SOCKET_EVENT_ADDR_CHANGED); changed = 1; } @@ -692,8 +692,8 @@ static void reconcile_iface(struct AUTO_SOCKET* as, uint32_t ifindex, const char struct sockaddr_storage old6 = sock->interface_addr; socket_monitor_update_if_addr(sock); if (memcmp(&old6, &sock->interface_addr, sizeof(old6)) != 0) { - DEBUG_INFO(DEBUG_CATEGORY_AS, "[as] v6 UDP interface_addr changed: %s -> %s", - sockaddr_storage_to_str(&old6).str, sockaddr_storage_to_str(&sock->interface_addr).str); + DEBUG_INFO(DEBUG_CATEGORY_AS, "[as] v6 UDP (%s) addr changed: %s → %s", + ifname, sockaddr_storage_to_str(&old6).str, sockaddr_storage_to_str(&sock->interface_addr).str); etcp_socket_cbk_fire(sock, ETCP_SOCKET_EVENT_ADDR_CHANGED); changed = 1; } diff --git a/src/transport_layer/etcp_api.c b/src/transport_layer/etcp_api.c index 5e8bfdb1..59bd86b7 100644 --- a/src/transport_layer/etcp_api.c +++ b/src/transport_layer/etcp_api.c @@ -138,7 +138,6 @@ void etcp_socket_cbk_fire(struct ETCP_SOCKET* sock, int event) { static const char* names[] = { "ADDR_CHANGED", "STATUS_CHANGED" }; int idx = 0, e = event; while (e >>= 1) idx++; const char* name = (idx >= 0 && idx < (int)(sizeof(names)/sizeof(names[0]))) ? names[idx] : "?"; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socket %s event: %s", sock->name, name); DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "socket %s event: %s if_addr=%s local=%s nat=%s type=%d netif=%u", sock->name, name, sockaddr_storage_to_str(&sock->interface_addr).str, diff --git a/src/transport_layer/socket_monitor.c b/src/transport_layer/socket_monitor.c index feb0cbfc..b1447ac9 100644 --- a/src/transport_layer/socket_monitor.c +++ b/src/transport_layer/socket_monitor.c @@ -121,8 +121,10 @@ static void socket_monitor_fire_one(struct SOCKET_MONITOR* sm, struct ETCP_SOCKE socket_monitor_update_if_addr(es); if (memcmp(&old_if_addr, &es->interface_addr, sizeof(old_if_addr)) != 0) { sm->socket_updates++; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socket %s interface_addr changed: %s -> %s", - es->name, sockaddr_storage_to_str(&old_if_addr).str, sockaddr_storage_to_str(&es->interface_addr).str); + char ifname[IFNAMSIZ]; if (!if_indextoname(es->netif_index, ifname)) snprintf(ifname, sizeof(ifname), "idx%u", es->netif_index); + DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socket %s (%s idx=%u) addr changed: %s → %s", + es->name, ifname, es->netif_index, + sockaddr_storage_to_str(&old_if_addr).str, sockaddr_storage_to_str(&es->interface_addr).str); etcp_socket_cbk_fire(es, ETCP_SOCKET_EVENT_ADDR_CHANGED); } } @@ -137,8 +139,9 @@ static void socket_monitor_check_and_fire(struct SOCKET_MONITOR* sm, struct ETCP static void socket_monitor_handle_addr(struct SOCKET_MONITOR* sm, struct ifaddrmsg* ifa, int msg_type) { sm->addr_changes++; - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "addr event: type=%s ifindex=%u family=%d", - msg_type == RTM_NEWADDR ? "NEW" : "DEL", ifa->ifa_index, ifa->ifa_family); + char ifname[IFNAMSIZ]; if (!if_indextoname(ifa->ifa_index, ifname)) snprintf(ifname, sizeof(ifname), "idx%u", ifa->ifa_index); + DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "addr %s: %s (idx=%u) family=%d", + msg_type == RTM_NEWADDR ? "NEW" : "DEL", ifname, ifa->ifa_index, ifa->ifa_family); struct ETCP_SOCKET* es = sm->instance->etcp_sockets; while (es) { socket_monitor_check_and_fire(sm, es, ifa->ifa_index); es = es->next; } } @@ -146,11 +149,13 @@ static void socket_monitor_handle_addr(struct SOCKET_MONITOR* sm, struct ifaddrm static void socket_monitor_handle_link(struct SOCKET_MONITOR* sm, struct ifinfomsg* ifi, int msg_type) { sm->link_changes++; int is_up = (ifi->ifi_flags & IFF_UP) != 0; - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "link event: type=%s ifindex=%u flags=0x%x up=%d", - msg_type == RTM_NEWLINK ? "NEW" : "DEL", ifi->ifi_index, ifi->ifi_flags, is_up); + char ifname[IFNAMSIZ]; if (!if_indextoname(ifi->ifi_index, ifname)) snprintf(ifname, sizeof(ifname), "idx%u", ifi->ifi_index); + DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "link %s: %s (idx=%u) flags=0x%x", + is_up ? "UP" : "DOWN", ifname, ifi->ifi_index, ifi->ifi_flags); struct ETCP_SOCKET* es = sm->instance->etcp_sockets; while (es) { if (es->netif_index == ifi->ifi_index) { + DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, " → socket %s firing STATUS_CHANGED", es->name); etcp_socket_cbk_fire(es, ETCP_SOCKET_EVENT_STATUS_CHANGED); if (is_up) socket_monitor_check_and_fire(sm, es, ifi->ifi_index); } @@ -161,8 +166,8 @@ static void socket_monitor_handle_link(struct SOCKET_MONITOR* sm, struct ifinfom static void socket_monitor_handle_route(struct SOCKET_MONITOR* sm, struct rtmsg* rtm, int msg_type) { if (rtm->rtm_dst_len != 0) return; sm->route_changes++; - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "default route event: type=%s family=%d", - msg_type == RTM_NEWROUTE ? "NEW" : "DEL", rtm->rtm_family); + DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "default route %s: family=%d", + msg_type == RTM_NEWROUTE ? "NEW" : "DEL", rtm->rtm_family); struct ETCP_SOCKET* es = sm->instance->etcp_sockets; while (es) { if (es->netif_index != 0 || es->local_addr.ss_family == 0) { es = es->next; continue; } @@ -179,8 +184,10 @@ static void socket_monitor_handle_route(struct SOCKET_MONITOR* sm, struct rtmsg* socket_monitor_update_if_addr(es); if (memcmp(&old_if_addr, &es->interface_addr, sizeof(old_if_addr)) != 0) { sm->socket_updates++; - DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socket %s interface_addr changed via default route: %s -> %s", - es->name, sockaddr_storage_to_str(&old_if_addr).str, sockaddr_storage_to_str(&es->interface_addr).str); + char ifname[IFNAMSIZ]; if (!if_indextoname(es->netif_index, ifname)) snprintf(ifname, sizeof(ifname), "idx%u", es->netif_index); + DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "socket %s (%s idx=%u) addr changed via default route: %s → %s", + es->name, ifname, es->netif_index, + sockaddr_storage_to_str(&old_if_addr).str, sockaddr_storage_to_str(&es->interface_addr).str); etcp_socket_cbk_fire(es, ETCP_SOCKET_EVENT_ADDR_CHANGED); } } @@ -239,10 +246,13 @@ static void socket_monitor_bsd_read_cb(int fd, void* arg) { case RTM_IFINFO: case RTM_IFANNOUNCE: sm->link_changes++; - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "link event: type=%d", rtm->rtm_type); { + const char* nm = rtm->rtm_type == RTM_IFINFO ? "IFINFO" : "IFANNOUNCE"; + DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "link event %s:", nm); struct ETCP_SOCKET* es = sm->instance->etcp_sockets; while (es) { + char ifname[IFNAMSIZ]; if (!if_indextoname(es->netif_index, ifname)) snprintf(ifname, sizeof(ifname), "idx%u", es->netif_index); + DEBUG_INFO(DEBUG_CATEGORY_SOCKET, " → socket %s (%s idx=%u) firing STATUS_CHANGED", es->name, ifname, es->netif_index); etcp_socket_cbk_fire(es, ETCP_SOCKET_EVENT_STATUS_CHANGED); socket_monitor_fire_one(sm, es); es = es->next; @@ -252,7 +262,7 @@ static void socket_monitor_bsd_read_cb(int fd, void* arg) { case RTM_NEWADDR: case RTM_DELADDR: sm->addr_changes++; - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "addr event: type=%s", rtm->rtm_type == RTM_NEWADDR ? "NEW" : "DEL"); + DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "addr %s:", rtm->rtm_type == RTM_NEWADDR ? "NEW" : "DEL"); { struct ETCP_SOCKET* es = sm->instance->etcp_sockets; while (es) { socket_monitor_fire_one(sm, es); es = es->next; } @@ -261,7 +271,7 @@ static void socket_monitor_bsd_read_cb(int fd, void* arg) { case RTM_ADD: case RTM_DELETE: sm->route_changes++; - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "route event: type=%s", rtm->rtm_type == RTM_ADD ? "ADD" : "DELETE"); + DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "route %s:", rtm->rtm_type == RTM_ADD ? "ADD" : "DELETE"); { struct ETCP_SOCKET* es = sm->instance->etcp_sockets; while (es) { @@ -314,7 +324,7 @@ static void WINAPI addr_change_cb(PVOID ctx, PMIB_UNICASTIPADDRESS_ROW row, MIB_ (void)row; (void)type; struct SOCKET_MONITOR* sm = (struct SOCKET_MONITOR*)ctx; sm->addr_changes++; - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "addr event: type=%d", (int)type); + DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "addr event: type=%d", (int)type); uasync_post(sm->instance->ua, process_win_addr_notify, sm); } @@ -322,7 +332,7 @@ static void WINAPI route_change_cb(PVOID ctx, PMIB_IPFORWARD_ROW2 row, MIB_NOTIF (void)row; (void)type; struct SOCKET_MONITOR* sm = (struct SOCKET_MONITOR*)ctx; sm->route_changes++; - DEBUG_DEBUG(DEBUG_CATEGORY_SOCKET, "route event: type=%d", (int)type); + DEBUG_INFO(DEBUG_CATEGORY_SOCKET, "route event: type=%d", (int)type); uasync_post(sm->instance->ua, process_win_route_notify, sm); }