diff --git a/changes/bug40841 b/changes/bug40841 new file mode 100644 index 0000000000..2e67db3261 --- /dev/null +++ b/changes/bug40841 @@ -0,0 +1,5 @@ + o Minor bugfixes (conflux): + - Demote a relay-side warn about too many legs to ProtocolWarn, + as there are conditions that it can briefly happen during set + construction. Also add additional set logging details for + all error cases. Fixes bug 40841; bugfix on 0.4.8.1-alpha. diff --git a/src/core/or/conflux.c b/src/core/or/conflux.c index ab464f3446..0082089504 100644 --- a/src/core/or/conflux.c +++ b/src/core/or/conflux.c @@ -566,9 +566,9 @@ conflux_pick_first_leg(conflux_t *cfx) // Since we have no legs, we have no idea if this is really a client // or server set. Try to find any that match: log_warn(LD_BUG, "Matching client sets:"); - conflux_log_set(cfx, true); + conflux_log_set(LOG_WARN, cfx, true); log_warn(LD_BUG, "Matching server sets:"); - conflux_log_set(cfx, false); + conflux_log_set(LOG_WARN, cfx, false); log_warn(LD_BUG, "End conflux set dump"); return false; } @@ -578,7 +578,7 @@ conflux_pick_first_leg(conflux_t *cfx) if (BUG(min_leg->linked_sent_usec == 0)) { log_warn(LD_BUG, "Conflux has no legs with non-zero RTT. " "Using first leg."); - conflux_log_set(cfx, CIRCUIT_IS_ORIGIN(min_leg->circ)); + conflux_log_set(LOG_WARN, cfx, CIRCUIT_IS_ORIGIN(min_leg->circ)); } } diff --git a/src/core/or/conflux_pool.c b/src/core/or/conflux_pool.c index 79fd6c1648..46d36cf106 100644 --- a/src/core/or/conflux_pool.c +++ b/src/core/or/conflux_pool.c @@ -2071,22 +2071,32 @@ conflux_pool_init(void) * For use in rare bug cases that are hard to diagnose. */ void -conflux_log_set(const conflux_t *cfx, bool is_client) +conflux_log_set(int loglevel, const conflux_t *cfx, bool is_client) { tor_assert(cfx); - log_warn(LD_BUG, "Conflux %s: %d linked, %d launched", + log_fn(loglevel, + LD_BUG, + "Conflux %s: %d linked, %d launched. Delivered: %"PRIu64"; " + "teardown: %d; Current: %p, Previous: %p", fmt_nonce(cfx->nonce), smartlist_len(cfx->legs), - cfx->num_leg_launch); + cfx->num_leg_launch, + cfx->last_seq_delivered, cfx->in_full_teardown, + cfx->curr_leg, cfx->prev_leg); // Log all linked legs int legs = 0; CONFLUX_FOR_EACH_LEG_BEGIN(cfx, leg) { - log_warn(LD_BUG, + const struct congestion_control_t *cc = circuit_ccontrol(leg->circ); + log_fn(loglevel, LD_BUG, " - Linked Leg %d purpose=%d; RTT %"PRIu64", sent: %"PRIu64 - " marked: %d", + "; sent: %"PRIu64", recv: %"PRIu64", infl: %"PRIu64", " + "ptr: %p, idx: %d, marked: %d", legs, leg->circ->purpose, leg->circ_rtts_usec, - leg->linked_sent_usec, leg->circ->marked_for_close); + leg->linked_sent_usec, leg->last_seq_recv, + leg->last_seq_sent, cc->inflight, leg->circ, + leg->circ->global_circuitlist_idx, + leg->circ->marked_for_close); legs++; } CONFLUX_FOR_EACH_LEG_END(leg); @@ -2094,16 +2104,18 @@ conflux_log_set(const conflux_t *cfx, bool is_client) unlinked_circuits_t *unlinked = unlinked_pool_get(cfx->nonce, is_client); if (unlinked) { // Log the number of legs and the is_for_linked_set status - log_warn(LD_BUG, " - Unlinked set: %d legs, for link: %d", + log_fn(loglevel, LD_BUG, " - Unlinked set: %d legs, for link: %d", smartlist_len(unlinked->legs), unlinked->is_for_linked_set); legs = 0; SMARTLIST_FOREACH_BEGIN(unlinked->legs, leg_t *, leg) { - log_warn(LD_BUG, + log_fn(loglevel, LD_BUG, " Unlinked Leg: %d purpose=%d; linked: %d, RTT %"PRIu64", " - "sent: %"PRIu64" link ptr %p, marked: %d", + "sent: %"PRIu64" link ptr %p, circ ptr: %p, idx: %d, marked: %d", legs, leg->circ->purpose, leg->linked, leg->rtt_usec, leg->link_sent_usec, - leg->link, leg->circ->marked_for_close); + leg->link, leg->circ, + leg->circ->global_circuitlist_idx, + leg->circ->marked_for_close); legs++; } SMARTLIST_FOREACH_END(leg); } diff --git a/src/core/or/conflux_pool.h b/src/core/or/conflux_pool.h index 9a9701a484..afa4d9d058 100644 --- a/src/core/or/conflux_pool.h +++ b/src/core/or/conflux_pool.h @@ -37,7 +37,7 @@ void conflux_process_linked(circuit_t *circ, crypt_path_t *layer_hint, void conflux_process_linked_ack(circuit_t *circ); typedef struct conflux_t conflux_t; -void conflux_log_set(const conflux_t *cfx, bool is_client); +void conflux_log_set(int loglevel, const conflux_t *cfx, bool is_client); #ifdef TOR_UNIT_TESTS bool launch_new_set(int num_legs); diff --git a/src/core/or/conflux_util.c b/src/core/or/conflux_util.c index 589db41e83..7e2e938ca4 100644 --- a/src/core/or/conflux_util.c +++ b/src/core/or/conflux_util.c @@ -384,13 +384,13 @@ conflux_validate_legs(const conflux_t *cfx) /* Ensure we have no pending nonce on the circ */ if (BUG(leg->circ->conflux_pending_nonce != NULL)) { - conflux_log_set(cfx, is_client); + conflux_log_set(LOG_WARN, cfx, is_client); continue; } /* Ensure we have a conflux object */ if (BUG(leg->circ->conflux == NULL)) { - conflux_log_set(cfx, is_client); + conflux_log_set(LOG_WARN, cfx, is_client); continue; } @@ -403,9 +403,10 @@ conflux_validate_legs(const conflux_t *cfx) // TODO-329-UDP: Eventually we want to allow three legs for the // exit case, to allow reconnection of legs to hit an RTT target. // For now, this validation helps find bugs. - if (BUG(num_legs > conflux_params_get_num_legs_set())) { - log_warn(LD_BUG, "Number of legs is above maximum of %d allowed: %d\n", + if (num_legs > conflux_params_get_num_legs_set()) { + log_fn(LOG_PROTOCOL_WARN, + LD_BUG, "Number of legs is above maximum of %d allowed: %d\n", conflux_params_get_num_legs_set(), smartlist_len(cfx->legs)); - conflux_log_set(cfx, is_client); + conflux_log_set(LOG_PROTOCOL_WARN, cfx, is_client); } }