Buffer retry choice diagnostics until measurement completes

tests/test_etcp_multipath.c

@@ -34,6 +34,10 @@ struct recovery_stats {
     uint64_t rto_count, retry_count, rto_late_us, ready_wait_us, transit_extra_us;
     uint32_t late_seq, ready_seq, transit_seq;
 };
+struct retry_choice {
+    uint64_t elapsed_us;
+    uint32_t seq, attempt, previous, selected, healthy, initialized, up, pacing, full, inflight, cwnd, total_attempts;
+};
 struct endpoint {
     struct UTUN_INSTANCE* inst;
     struct NODE_CONN_DIRECT* owner;
@@ -61,6 +65,8 @@ static struct recovery_stats recovery;
 static uint32_t fault_rto_us[PATHS]; // максимум RTO каждого пути с начала отказа, независимо от измеренной паузы
 static uint32_t rx_trigger[2]; // DATA, разбор которого сейчас разблокировал выдачу сообщения
 static unsigned fault_paths;
+static struct retry_choice retry_choices[4096]; // выводим после замера, чтобы I/O лога не менял выбор pacer
+static unsigned retry_choice_count, retry_choice_dropped;
 static FILE* csv;
 static const char* case_name;
 static const char* pubkeys[2] = {
@@ -202,11 +208,11 @@ struct ETCP_LINK* __wrap_etcp_loadbalancer_select_link(struct ETCP_CONN* conn, u
     for (struct ETCP_LINK* healthy = conn->links; healthy; healthy = healthy->next) for (unsigned p = 0; p < path_count; p++) {
         if ((fault_paths & (1u << p)) || ss_get_port(&healthy->remote_addr) != dummynet_get_listen_port(channels[p])) continue;
         int full = bytes > healthy->inflight_lim_bytes || healthy->inflight_bytes > healthy->inflight_lim_bytes - bytes;
-        DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "FAULT retry-choice %s seq=%u attempt=%u previous=%d selected=%d elapsed_us=%llu "
-            "healthy=%u initialized=%u UP=%u pacing_blocked=%d window_full=%d inflight=%u cwnd=%u total_attempts=%u", case_name,
-            retry->seq, retry->attempt_count, previous, chosen, (unsigned long long)(get_time_us() - fault_start),
-            p, healthy->initialized, healthy->link_status, healthy->shaper_timer != NULL, full,
-            healthy->inflight_bytes, healthy->inflight_lim_bytes, conn->active_attempts);
+        if (retry_choice_count == sizeof(retry_choices) / sizeof(retry_choices[0])) { retry_choice_dropped++; continue; }
+        retry_choices[retry_choice_count++] = (struct retry_choice){.elapsed_us=get_time_us() - fault_start,
+            .seq=retry->seq, .attempt=retry->attempt_count, .previous=previous, .selected=chosen, .healthy=p,
+            .initialized=healthy->initialized, .up=healthy->link_status, .pacing=healthy->shaper_timer != NULL, .full=full,
+            .inflight=healthy->inflight_bytes, .cwnd=healthy->inflight_lim_bytes, .total_attempts=conn->active_attempts};
     }
     return selected;
 }
@@ -264,6 +270,7 @@ static void setup(const struct profile* settings, unsigned count, unsigned mask)
     memset(&recovery, 0, sizeof(recovery)); memset(fault_rto_us, 0, sizeof(fault_rto_us));
     memset(rx_trigger, 0, sizeof(rx_trigger));
     fault_paths = 0;
+    retry_choice_count = retry_choice_dropped = 0;
     path_count = count; enabled_mask = mask; measuring = 0; fault_start = 0; fault_trace_count = 0;
     memcpy(profiles, settings, count * sizeof(*settings));
     ua = uasync_create(); CHECK(ua);
@@ -530,6 +537,14 @@ static void stalled(const struct profile* settings, unsigned count, unsigned bro
     else if (duration_ms > 1000) expect(rate >= capacity * 85 / 100,
         "fault steady goodput >=85% healthy capacity", rate, capacity * 85 / 100);
     for (int i = 0; i < 2; i++) CHECK(ep[i].conn->reinit_count == epochs[i] && ep[i].conn->links_up);
+    expect(!retry_choice_dropped, "retry choice trace has no dropped events", retry_choice_dropped, 0);
+    for (unsigned n = 0; n < retry_choice_count; n++) {
+        const struct retry_choice* c = &retry_choices[n];
+        DEBUG_INFO(DEBUG_CATEGORY_DEBUG, "FAULT retry-choice %s seq=%u attempt=%u previous=%u selected=%u elapsed_us=%llu "
+            "healthy=%u initialized=%u UP=%u pacing_blocked=%u window_full=%u inflight=%u cwnd=%u total_attempts=%u", case_name,
+            c->seq, c->attempt, c->previous, c->selected, (unsigned long long)c->elapsed_us,
+            c->healthy, c->initialized, c->up, c->pacing, c->full, c->inflight, c->cwnd, c->total_attempts);
+    }
     measuring = duration_ms <= 100;
     for (unsigned p = 0; p < count; p++) if (broken & (1u << p))
         for (unsigned dir = 0; dir < 2; dir++) CHECK(dummynet_set_mode(channels[p], dir, DUMMYNET_RUN) == 0);