Browse Source

logging: explain BGP readiness, route selection and peer removal

master
evgeny 5 days ago
parent
commit
15d460ee7c
  1. 47
      src/routing_layer/topo_group.c
  2. 2
      src/transport_layer/reality.c

47
src/routing_layer/topo_group.c

@ -100,9 +100,13 @@ int topo_group_peer_ready(const struct TOPO_GROUP* group, uint64_t peer_id) {
static void topo_group_notify_ready(struct TOPO_GROUP_CONN_ITEM* peer, int ready) { static void topo_group_notify_ready(struct TOPO_GROUP_CONN_ITEM* peer, int ready) {
if (peer->ready_notified == ready) return; if (peer->ready_notified == ready) return;
peer->ready_notified = ready; peer->ready_notified = ready;
DEBUG_INFO(DEBUG_CATEGORY_BGP, "group peer readiness: group=%016llx peer=%016llx ready=%d epoch=%016llx", DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP peer %s: group=%016llx peer=%016llx local_epoch=%016llx remote_epoch=%016llx "
"links_up=%u transport_down=%u accepted=%u table_sent=%u table_received=%u send_failed=%u",
ready ? "READY (group exchange complete)" : "NOT READY (group session unavailable)",
(unsigned long long)peer->group->group_id, (unsigned long long)peer->node_id, (unsigned long long)peer->group->group_id, (unsigned long long)peer->node_id,
ready, (unsigned long long)peer->local_epoch); (unsigned long long)peer->local_epoch, (unsigned long long)peer->remote_epoch,
peer->conn ? peer->conn->links_up : 0, peer->transport_down, peer->accepted,
peer->table_sent, peer->table_received, peer->tx_failed);
for (struct topo_peer_ready_cbk* cb = peer->group->peer_ready_cbks; cb; cb = cb->next) for (struct topo_peer_ready_cbk* cb = peer->group->peer_ready_cbks; cb; cb = cb->next)
cb->fn(peer->group, peer->node_id, ready, cb->arg); cb->fn(peer->group, peer->node_id, ready, cb->arg);
} }
@ -1007,10 +1011,18 @@ int topo_group_new_conn(struct TOPO_GROUP* group, struct ETCP_CONN* conn) {
void topo_group_remove_conn(struct TOPO_GROUP* group, struct ETCP_CONN* conn, enum topo_group_remove_reason reason) { void topo_group_remove_conn(struct TOPO_GROUP* group, struct ETCP_CONN* conn, enum topo_group_remove_reason reason) {
if (!group || !conn) { DEBUG_ERROR(DEBUG_CATEGORY_BGP, "invalid args"); return; } if (!group || !conn) { DEBUG_ERROR(DEBUG_CATEGORY_BGP, "invalid args"); return; }
if (!conn->instance) { DEBUG_ERROR(DEBUG_CATEGORY_BGP, "invalid instance"); return; } if (!conn->instance) { DEBUG_ERROR(DEBUG_CATEGORY_BGP, "invalid instance"); return; }
const char* reason_text = "unknown";
switch (reason) {
case TOPO_REMOVE_TRANSPORT_DOWN: reason_text = "transport-down"; break;
case TOPO_REMOVE_LOCAL_LEAVE: reason_text = "local-left-group"; break;
case TOPO_REMOVE_REMOTE_LEAVE: reason_text = "peer-left-group"; break;
case TOPO_REMOVE_MEMBER_INVALID: reason_text = "membership-invalid"; break;
case TOPO_REMOVE_REJECTED: reason_text = "group-join-rejected"; break;
}
struct TOPO_GROUP_CONN_ITEM* pending = topo_group_peer(group, conn->peer_node_id); struct TOPO_GROUP_CONN_ITEM* pending = topo_group_peer(group, conn->peer_node_id);
if (pending && !pending->conn && node_conn_direct_get_conn(pending->handle) == conn) { if (pending && !pending->conn && node_conn_direct_get_conn(pending->handle) == conn) {
DEBUG_INFO(DEBUG_CATEGORY_BGP, "group pending peer removed: peer=%016llx group=%016llx reason=%d", DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP pending connection lost: peer=%016llx group=%016llx reason=%s",
(unsigned long long)pending->node_id, (unsigned long long)group->group_id, reason); (unsigned long long)pending->node_id, (unsigned long long)group->group_id, reason_text);
if (reason == TOPO_REMOVE_TRANSPORT_DOWN && pending->requests) { if (reason == TOPO_REMOVE_TRANSPORT_DOWN && pending->requests) {
pending->transport_down = 1; pending->retained = 0; pending->transport_down = 1; pending->retained = 0;
topo_recovery_changed(group); topo_group_connect_changed(group); topo_recovery_changed(group); topo_group_connect_changed(group);
@ -1023,9 +1035,10 @@ void topo_group_remove_conn(struct TOPO_GROUP* group, struct ETCP_CONN* conn, en
while (e) { struct TOPO_GROUP_CONN_ITEM* item = (struct TOPO_GROUP_CONN_ITEM*)e->data; if (item->conn == conn) { found_in_list = true; break; } e = e->next; } while (e) { struct TOPO_GROUP_CONN_ITEM* item = (struct TOPO_GROUP_CONN_ITEM*)e->data; if (item->conn == conn) { found_in_list = true; break; } e = e->next; }
if (!found_in_list) { DEBUG_WARN(DEBUG_CATEGORY_BGP, "topo_group_remove_conn: conn=%p peer=%016llx state=%d NOT in senders_list (already removed?), skip grp=%016llx ch=%s", (void*)conn, (unsigned long long)conn->peer_node_id, conn->state, (unsigned long long)group->group_id, group->channel_id); return; } if (!found_in_list) { DEBUG_WARN(DEBUG_CATEGORY_BGP, "topo_group_remove_conn: conn=%p peer=%016llx state=%d NOT in senders_list (already removed?), skip grp=%016llx ch=%s", (void*)conn, (unsigned long long)conn->peer_node_id, conn->state, (unsigned long long)group->group_id, group->channel_id); return; }
DEBUG_INFO(DEBUG_CATEGORY_BGP, "topo_group_remove_conn: conn=%p peer=%016llx state=%d name='%s' grp=%016llx ch=%s", DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP peer session lost; removing its routes: peer=%016llx group=%016llx channel=%s "
(void*)conn, (unsigned long long)conn->peer_node_id, conn->state, conn->log_name, "reason=%s links_up=%u close_requested=%u reinit_pending=%u",
(unsigned long long)group->group_id, group->channel_id); (unsigned long long)conn->peer_node_id, (unsigned long long)group->group_id, group->channel_id,
reason_text, conn->links_up, conn->close_requested, conn->reinit_pending);
/* Больше не публикуем в закрываемую сессию, даже если общий транспорт ещё UP. */ /* Больше не публикуем в закрываемую сессию, даже если общий транспорт ещё UP. */
pending->transport_down = 1; pending->transport_down = 1;
@ -1061,8 +1074,10 @@ void topo_group_remove_conn(struct TOPO_GROUP* group, struct ETCP_CONN* conn, en
topo_recovery_add_node(group, key, next_hop, lost_rtt); cascaded++; topo_recovery_add_node(group, key, next_hop, lost_rtt); cascaded++;
} }
nodes_removed++; nodes_removed++;
DEBUG_INFO(DEBUG_CATEGORY_BGP, "node removed from group: node=%016llx grp=%016llx type=%u ch=%s (link_down)", DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP destination unreachable; no alternative path: node=%016llx group=%016llx "
(unsigned long long)key, (unsigned long long)group->group_id, group->group_type, group->channel_id); "lost_peer=%016llx reason=%s",
(unsigned long long)key, (unsigned long long)group->group_id,
(unsigned long long)conn->peer_node_id, reason_text);
// REINIT временно убирает путь, но end-to-end данные роутера остаются неподтверждёнными. // REINIT временно убирает путь, но end-to-end данные роутера остаются неподтверждёнными.
if (!conn->reinit_pending) etcp_router_conn_close_all_for_node(group->instance, group->group_id, key); if (!conn->reinit_pending) etcp_router_conn_close_all_for_node(group->instance, group->group_id, key);
} }
@ -1097,8 +1112,9 @@ void topo_group_remove_conn(struct TOPO_GROUP* group, struct ETCP_CONN* conn, en
topo_group_connect_on_down(group, conn); topo_group_connect_on_down(group, conn);
DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP peer removed: %s nodes=%d grp=%016llx reason=%d recovery=%d", DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP peer removal complete: peer=%016llx group=%016llx reason=%s "
conn->log_name, nodes_removed, (unsigned long long)group->group_id, reason, cascaded); "destinations_without_paths=%d recovery_targets=%d",
(unsigned long long)conn->peer_node_id, (unsigned long long)group->group_id, reason_text, nodes_removed, cascaded);
} }
@ -1163,8 +1179,10 @@ static void topo_group_routes_changed(struct TOPO_GROUP* group, struct TOPO_GROU
node->conn_presence |= NCONN_DIRECT; node->conn_presence |= NCONN_DIRECT;
if (p->conn->links_up && !p->conn->close_requested) node->conn_up |= NCONN_DIRECT; if (p->conn->links_up && !p->conn->close_requested) node->conn_up |= NCONN_DIRECT;
} }
DEBUG_INFO(DEBUG_CATEGORY_BGP, "route changed: group=%016llx node=%016llx paths=%d via=%016llx hops=%u", DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP route recomputed: group=%016llx node=%016llx result=%s stored_paths=%d via=%016llx hops=%u",
(unsigned long long)group->group_id, (unsigned long long)id, node->paths ? queue_entry_count(node->paths) : 0, (unsigned long long)group->group_id, (unsigned long long)id,
best ? (best->conn->peer_node_id == id ? "direct" : "via-intermediary") : "unreachable-no-live-path",
node->paths ? queue_entry_count(node->paths) : 0,
(unsigned long long)(best ? best->conn->peer_node_id : 0), best ? best->hop_count : 0); (unsigned long long)(best ? best->conn->peer_node_id : 0), best ? best->hop_count : 0);
if (group->group_type != TOPO_GROUP_TYPE_CHAT && group->instance->rt) { if (group->group_type != TOPO_GROUP_TYPE_CHAT && group->instance->rt) {
if (best && node->subnets) route_insert(group->instance->rt, node); if (best && node->subnets) route_insert(group->instance->rt, node);
@ -1427,7 +1445,8 @@ int topo_group_process_withdraw(struct TOPO_GROUP* group, struct ETCP_CONN* send
if (!nq) { DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "WITHDRAW unknown node=%016llx", (unsigned long long)node_id); return 0; } if (!nq) { DEBUG_DEBUG(DEBUG_CATEGORY_BGP, "WITHDRAW unknown node=%016llx", (unsigned long long)node_id); return 0; }
int removed = topo_group_remove_path(nq, sender); int removed = topo_group_remove_path(nq, sender);
int remaining = nq->paths ? queue_entry_count(nq->paths) : 0; int remaining = nq->paths ? queue_entry_count(nq->paths) : 0;
DEBUG_INFO(DEBUG_CATEGORY_BGP, "WITHDRAW group=%016llx node=%016llx source=%016llx removed=%d remaining=%d", DEBUG_INFO(DEBUG_CATEGORY_BGP, "BGP WITHDRAW received (sender withdrew its route): group=%016llx node=%016llx "
"source=%016llx removed=%d remaining_stored_paths=%d",
(unsigned long long)group->group_id, (unsigned long long)node_id, (unsigned long long)group->group_id, (unsigned long long)node_id,
(unsigned long long)sender->peer_node_id, removed, remaining); (unsigned long long)sender->peer_node_id, removed, remaining);
if (removed) topo_group_routes_changed(group, nq, TOPO_NODE_EVENT_UPDATE); if (removed) topo_group_routes_changed(group, nq, TOPO_NODE_EVENT_UPDATE);

2
src/transport_layer/reality.c

@ -401,7 +401,7 @@ static int client_hello_build(struct reality_session *session, const struct real
memcpy(session->session_id, seal_out, 32); memcpy(session->session_id, seal_out, 32);
if (reality_transcript_add(session, hs, hs_len)) { rc = REALITY_ERR_CRYPTO; goto out; } if (reality_transcript_add(session, hs, hs_len)) { rc = REALITY_ERR_CRYPTO; goto out; }
} }
DEBUG_INFO(DEBUG_CATEGORY_REALITY, "client hello built: total=%zu sni=%s version=%u.%u.%u", total, DEBUG_TRACE(DEBUG_CATEGORY_REALITY, "client hello built: total=%zu sni=%s version=%u.%u.%u", total,
cfg->server_name, cfg->version[0], cfg->version[1], cfg->version[2]); cfg->server_name, cfg->version[0], cfg->version[1], cfg->version[2]);
rc = REALITY_OK; rc = REALITY_OK;
out: out:

Loading…
Cancel
Save