X-Git-Url: https://git.sesse.net/?a=blobdiff_plain;f=print_latency.cpp;h=72440ae0fe41a3ec13df76c595450ca409090aec;hb=e284d1c7a2e18ee7e4aea082c4a57a3504a0f5e8;hp=9b5be9ea0be3f0457f430e16118ea90f1bd51241;hpb=a52521ba8935fcf02e37d01767c3013c39e8dce2;p=nageru diff --git a/print_latency.cpp b/print_latency.cpp index 9b5be9e..72440ae 100644 --- a/print_latency.cpp +++ b/print_latency.cpp @@ -35,53 +35,74 @@ ReceivedTimestamps find_received_timestamp(const vector &input_ void LatencyHistogram::init(const string &measuring_point) { unsigned num_cards = global_flags.num_cards; // The mixer might not be ready yet. - histograms.resize(num_cards * FRAME_HISTORY_LENGTH * 2); + summaries.resize(num_cards * FRAME_HISTORY_LENGTH * 2); for (unsigned card_index = 0; card_index < num_cards; ++card_index) { char card_index_str[64]; snprintf(card_index_str, sizeof(card_index_str), "%u", card_index); - histograms[card_index].resize(FRAME_HISTORY_LENGTH); + summaries[card_index].resize(FRAME_HISTORY_LENGTH); for (unsigned frame_index = 0; frame_index < FRAME_HISTORY_LENGTH; ++frame_index) { char frame_index_str[64]; snprintf(frame_index_str, sizeof(frame_index_str), "%u", frame_index); - histograms[card_index][frame_index].reset(new Histogram[2]); - histograms[card_index][frame_index][0].init_geometric(0.001, 10.0, 30); - histograms[card_index][frame_index][1].init_geometric(0.001, 10.0, 30); + vector quantiles{0.01, 0.1, 0.25, 0.5, 0.75, 0.9, 0.99}; + summaries[card_index][frame_index].reset(new Summary[3]); + summaries[card_index][frame_index][0].init(quantiles, 60.0); + summaries[card_index][frame_index][1].init(quantiles, 60.0); + summaries[card_index][frame_index][2].init(quantiles, 60.0); global_metrics.add("latency_seconds", {{ "measuring_point", measuring_point }, { "card", card_index_str }, { "frame_age", frame_index_str }, { "frame_type", "i/p" }}, - &histograms[card_index][frame_index][0], + &summaries[card_index][frame_index][0], (frame_index == 0) ? Metrics::PRINT_ALWAYS : Metrics::PRINT_WHEN_NONEMPTY); global_metrics.add("latency_seconds", {{ "measuring_point", measuring_point }, { "card", card_index_str }, { "frame_age", frame_index_str }, { "frame_type", "b" }}, - &histograms[card_index][frame_index][1], + &summaries[card_index][frame_index][1], Metrics::PRINT_WHEN_NONEMPTY); + global_metrics.add("latency_seconds", + {{ "measuring_point", measuring_point }, + { "card", card_index_str }, + { "frame_age", frame_index_str }, + { "frame_type", "total" }}, + &summaries[card_index][frame_index][2], + (frame_index == 0) ? Metrics::PRINT_ALWAYS : Metrics::PRINT_WHEN_NONEMPTY); } } } -void print_latency(const string &header, const ReceivedTimestamps &received_ts, bool is_b_frame, int *frameno, LatencyHistogram *histogram) +void print_latency(const char *header, const ReceivedTimestamps &received_ts, bool is_b_frame, int *frameno, LatencyHistogram *histogram) { if (received_ts.ts.empty()) return; const steady_clock::time_point now = steady_clock::now(); - unsigned num_cards = global_mixer->get_num_cards(); - assert(received_ts.ts.size() == num_cards * FRAME_HISTORY_LENGTH); - for (unsigned card_index = 0; card_index < num_cards; ++card_index) { - for (unsigned frame_index = 0; frame_index < FRAME_HISTORY_LENGTH; ++frame_index) { - steady_clock::time_point ts = received_ts.ts[card_index * FRAME_HISTORY_LENGTH + frame_index]; - if (ts == steady_clock::time_point::min()) { - continue; - } + if (global_mixer == nullptr) { + // Kaeru. + assert(received_ts.ts.size() == 1); + steady_clock::time_point ts = received_ts.ts[0]; + if (ts != steady_clock::time_point::min()) { duration latency = now - ts; - histogram->histograms[card_index][frame_index][is_b_frame].count_event(latency.count()); + histogram->summaries[0][0][is_b_frame].count_event(latency.count()); + histogram->summaries[0][0][2].count_event(latency.count()); + } + } else { + unsigned num_cards = global_mixer->get_num_cards(); + assert(received_ts.ts.size() == num_cards * FRAME_HISTORY_LENGTH); + for (unsigned card_index = 0; card_index < num_cards; ++card_index) { + for (unsigned frame_index = 0; frame_index < FRAME_HISTORY_LENGTH; ++frame_index) { + steady_clock::time_point ts = received_ts.ts[card_index * FRAME_HISTORY_LENGTH + frame_index]; + if (ts == steady_clock::time_point::min()) { + continue; + } + duration latency = now - ts; + histogram->summaries[card_index][frame_index][is_b_frame].count_event(latency.count()); + histogram->summaries[card_index][frame_index][2].count_event(latency.count()); + } } } @@ -99,7 +120,7 @@ void print_latency(const string &header, const ReceivedTimestamps &received_ts, duration highest_latency = now - min_ts; printf("%-60s %4.0f ms (lowest-latency input), %4.0f ms (highest-latency input)", - header.c_str(), 1e3 * lowest_latency.count(), 1e3 * highest_latency.count()); + header, 1e3 * lowest_latency.count(), 1e3 * highest_latency.count()); if (is_b_frame) { printf(" [on B-frame; potential extra latency]\n");