From 6a92eec98382a2a1e898e524e60c56894798168d Mon Sep 17 00:00:00 2001 From: evgeny Date: Tue, 13 Oct 2026 00:56:18 +0200 Subject: [PATCH] Log stream probe backoff and pending bootstrap state --- src/stream/stream_optimizer.c | 25 ++++++++++++++++++++++++- 1 file changed, 24 insertions(+), 1 deletion(-) diff --git a/src/stream/stream_optimizer.c b/src/stream/stream_optimizer.c index c6ecd865..b54e51bc 100644 --- a/src/stream/stream_optimizer.c +++ b/src/stream/stream_optimizer.c @@ -40,7 +40,7 @@ struct stream_optimizer { struct stream_selection_settings settings; struct stream_selection_info info; struct stream_probe_schedule schedule; - uint64_t roster_ms, progress_ms, next_seq; + uint64_t roster_ms, progress_ms, next_seq, diagnostic_ms; int progress_valid, draining; }; @@ -113,6 +113,11 @@ static void probes_poll(struct stream_optimizer *o, struct STREAM_HANDLE *h, uin s->offers[s->probe_sub].info.info_ms = 0; if (info.reason == STREAM_REASON_TRANSPORT || info.reason == STREAM_REASON_MEMBER || info.reason == STREAM_REASON_PROTOCOL) { s->failures++; s->retry_ms = now + backoff(s->failures); + DEBUG_WARN(DEBUG_CATEGORY_STREAM, "stream optimizer probe closed source=%llx peer=%llx sub=%u reason=%d" + " info_ready=%d local_epoch=%llx peer_epoch=%llx failures=%u retry_in_ms=%llu cycle=%llu", + (unsigned long long)o->descriptor.source_node_id, (unsigned long long)s->node, s->probe_sub, info.reason, + info.info_ready, (unsigned long long)info.local_epoch, (unsigned long long)info.peer_epoch, s->failures, + (unsigned long long)(s->retry_ms - now), (unsigned long long)s->cycle); stream_receive_close(s->probe); s->probe = NULL; continue; } } else { @@ -421,4 +426,22 @@ void stream_optimizer_tick(struct stream_optimizer *o, struct STREAM_HANDLE *h, if (o->selected[sub].replacement) o->info.overlaps++; } if (o->info.subflows != o->descriptor.n) o->info.protected_by_fec = 0; + /* Пока нет первого блока, раз в секунду показываем причину ожидания каждого поставщика. */ + if (!local.anchored && now >= o->diagnostic_ms) { + o->diagnostic_ms = now + STREAM_PROBE_PERIOD_MS; + DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "stream bootstrap waits group=%llx source=%llx epoch=%llx candidates=%u probes=%u" + " subflows=%u cycle=%llu cycle_age_ms=%llu", + (unsigned long long)o->descriptor.group_id, (unsigned long long)o->descriptor.source_node_id, + (unsigned long long)o->descriptor.source_epoch, o->info.candidates, o->info.probes_active, o->info.subflows, + (unsigned long long)o->schedule.cycle, (unsigned long long)(now - o->schedule.started_ms)); + for (struct stream_supplier *s = o->suppliers; s; s = s->next) { + struct stream_receive_info probe = {0}; + if (s->probe) stream_receive_get_info(s->probe, &probe); + DEBUG_DEBUG(DEBUG_CATEGORY_DEBUG, "stream bootstrap supplier source=%llx peer=%llx online=%d compatible=%d source_peer=%d" + " cycle=%llu failures=%u retry_in_ms=%llu probe=%d sub=%u state=%d info_ready=%d reason=%d", + (unsigned long long)o->descriptor.source_node_id, (unsigned long long)s->node, s->online, s->compatible, s->source, + (unsigned long long)s->cycle, s->failures, (unsigned long long)(s->retry_ms > now ? s->retry_ms - now : 0), + s->probe != NULL, s->probe_sub, probe.state, probe.info_ready, probe.reason); + } + } }