diff --git a/src/stream/stream_optimizer.c b/src/stream/stream_optimizer.c index 91e8a76b..4065817c 100644 --- a/src/stream/stream_optimizer.c +++ b/src/stream/stream_optimizer.c @@ -114,7 +114,15 @@ static void probes_poll(struct stream_optimizer *o, struct STREAM_HANDLE *h, uin s->failures++; s->retry_ms = now + backoff(s->failures); stream_receive_close(s->probe); s->probe = NULL; continue; } - } else { s->offers[s->probe_sub].info = info; s->failures = 0; s->retry_ms = 0; } + } else { + s->offers[s->probe_sub].info = info; s->failures = 0; s->retry_ms = 0; + DEBUG_DEBUG(DEBUG_CATEGORY_STREAM, "stream optimizer offer peer=%llx sub=%u range=%llu..%llu hops=%u rtt=%u/%d chain=%u/%d slots=%u accepting=%d lag=%llu stopped=%d age=%llu/%d queue=%llu", + (unsigned long long)s->node, s->probe_sub, (unsigned long long)info.first_available, + (unsigned long long)info.last_available, info.path.count, info.rtt_ms, info.rtt_valid, + info.path_rtt_ms, info.path_rtt_valid, info.free_slots, info.accepting, + (unsigned long long)info.supplier_metrics.lag_ms, info.supplier_metrics.stopped, + (unsigned long long)info.progress_age_ms, info.progress_valid, (unsigned long long)info.supplier_queue_bytes); + } unsigned next = s->probe_sub + 1; if (next == o->descriptor.n) { stream_receive_close(s->probe); s->probe = NULL; continue; } if (info.state == STREAM_RECEIVE_CLOSED) { @@ -359,6 +367,11 @@ void stream_optimizer_tick(struct stream_optimizer *o, struct STREAM_HANDLE *h, } if (pick->better_node != s->node) { pick->better_node = s->node; pick->better_ms = now; } if (now - pick->better_ms < o->settings.migration_confirm_ms) continue; + DEBUG_DEBUG(DEBUG_CATEGORY_STREAM, "stream optimizer improvement sub=%u old=%llx new=%llx old_problems=%.3f new_problems=%.3f old_rtt=%llu new_rtt=%llu old_usage=%u new_usage=%u confirmed_ms=%llu", + sub, (unsigned long long)info.peer, (unsigned long long)s->node, problems(&info.metrics, info.metrics_valid), + problems(&s->offers[sub].info.supplier_metrics, s->offers[sub].info.supplier_metrics_valid), + (unsigned long long)total_rtt(&info), (unsigned long long)total_rtt(&s->offers[sub].info), + usage(o, info.peer, sub), usage(o, s->node, sub), (unsigned long long)(now - pick->better_ms)); if (stream_receive_open(h, s->node, (uint8_t)sub, seq, &pick->replacement) == STREAM_OK) { pick->replacement_ms = now; migrating = 1; DEBUG_INFO(DEBUG_CATEGORY_STREAM, "stream optimizer overlap sub=%u old=%llx new=%llx index=%llu",