diff --git a/src/etcp_connections.c b/src/etcp_connections.c index e490c0d1..4078c622 100644 --- a/src/etcp_connections.c +++ b/src/etcp_connections.c @@ -1245,6 +1245,8 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) { sc_context_t resp_sc; sc_init_ctx(&resp_sc, &e_sock->instance->my_keys); if (sc_set_peer_public_key(&resp_sc, decrypted_pubkey, SC_PEER_PUBKEY_BIN) == SC_OK) { + DEBUG_INFO(DEBUG_CATEGORY_BGP, "PONG send nonce=%016llx to=%s fd=%d", + (unsigned long long)nonce, sockaddr_storage_to_str(&addr).str, e_sock->fd); etcp_send_ping_raw(resp, e_sock->fd, &resp_sc, &addr, 0); } u_free(resp); @@ -1262,10 +1264,15 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) { udata = pkt->data + 19; } } + DEBUG_INFO(DEBUG_CATEGORY_BGP, "PONG recv nonce=%016llx data_len=%u from=%s socket=%s", + (unsigned long long)nonce, (unsigned)pkt->data_len, + sockaddr_storage_to_str(&addr).str, e_sock->name); struct PING_CONTEXT* ctx = e_sock->instance->pending_pings; struct PING_CONTEXT* prev = NULL; + int found = 0; while (ctx) { if (ctx->nonce == nonce) { + found = 1; if (prev) prev->next = ctx->next; else e_sock->instance->pending_pings = ctx->next; if (ctx->timeout_timer) { @@ -1274,6 +1281,8 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) { } uint64_t now = get_time_tb(); uint16_t rtt = (now >= ctx->send_time) ? (uint16_t)(now - ctx->send_time) : 0; + DEBUG_INFO(DEBUG_CATEGORY_BGP, "PONG matched nonce=%016llx rtt=%u", + (unsigned long long)nonce, (unsigned)rtt); ctx->cb(1, rtt, ctx->arg, nonce, udata, ulen); if (ctx->user_data) u_free(ctx->user_data); u_free(ctx); @@ -1282,6 +1291,10 @@ void etcp_connections_read_callback_socket(socket_t sock, void* arg) { prev = ctx; ctx = ctx->next; } + if (!found) { + DEBUG_WARN(DEBUG_CATEGORY_BGP, "PONG nonce=%016llx NOT FOUND in pending (timeout?)", + (unsigned long long)nonce); + } memory_pool_free(e_sock->instance->pkt_pool, pkt); return; } diff --git a/src/route_ping.c b/src/route_ping.c index 6abb6b63..e92ab904 100644 --- a/src/route_ping.c +++ b/src/route_ping.c @@ -275,7 +275,9 @@ static void route_ping_single_cb(int success, ctx->sum_rtt += rtt; } - DEBUG_INFO(DEBUG_CATEGORY_BGP, "ping response nonce=%016llx", (unsigned long long)nonce); + DEBUG_INFO(DEBUG_CATEGORY_BGP, "ping callback nonce=%016llx success=%d rtt=%u sent=%u ok=%u", + (unsigned long long)nonce, success, (unsigned)rtt, + (unsigned)ctx->count_sent, (unsigned)ctx->count_ok); /* Если ещё не все пакеты отправлены — сразу шлём следующий */ if (ctx->count_sent < ctx->count_total) {