X-Git-Url: https://git.sesse.net/?a=blobdiff_plain;f=print_latency.cpp;fp=print_latency.cpp;h=a80ac4f3242a2e7e1b44b5bb3215b8986fe1f728;hb=1df7849fad1d0647a02951abaa60f9e4f40ce360;hp=ee9470cc2187a2f39c325ac29def78f7b5b0efac;hpb=c574aef4437253dcf0e6c1fed4c9cab1033b33f9;p=nageru diff --git a/print_latency.cpp b/print_latency.cpp index ee9470c..a80ac4f 100644 --- a/print_latency.cpp +++ b/print_latency.cpp @@ -1,6 +1,7 @@ #include "print_latency.h" #include "flags.h" +#include "metrics.h" #include #include @@ -22,18 +23,48 @@ ReceivedTimestamps find_received_timestamp(const vector &input_ return { min_ts, max_ts }; } -void print_latency(const string &header, const ReceivedTimestamps &received_ts, bool is_b_frame, int *frameno) +void LatencyHistogram::init(const string &measuring_point) +{ + histogram_lowest_latency_input.init_geometric(0.001, 10.0, 30); + histogram_highest_latency_input.init_geometric(0.001, 10.0, 30); + histogram_lowest_latency_input_bframe.init_geometric(0.001, 10.0, 30); + histogram_highest_latency_input_bframe.init_geometric(0.001, 10.0, 30); + + global_metrics.add("latency_seconds", + {{ "measuring_point", measuring_point }, { "input", "lowest_latency" }, { "frame_type", "i/p" }}, + &histogram_lowest_latency_input); + global_metrics.add("latency_seconds", + {{ "measuring_point", measuring_point }, { "input", "highest_latency" }, { "frame_type", "i/p" }}, + &histogram_highest_latency_input); + global_metrics.add("latency_seconds", + {{ "measuring_point", measuring_point }, { "input", "lowest_latency" }, { "frame_type", "b" }}, + &histogram_lowest_latency_input_bframe); + global_metrics.add("latency_seconds", + {{ "measuring_point", measuring_point }, { "input", "highest_latency" }, { "frame_type", "b" }}, + &histogram_highest_latency_input_bframe); +} + +void print_latency(const string &header, const ReceivedTimestamps &received_ts, bool is_b_frame, int *frameno, LatencyHistogram *histogram) { if (received_ts.max_ts == steady_clock::time_point::min()) return; + const steady_clock::time_point now = steady_clock::now(); + duration lowest_latency = now - received_ts.max_ts; + duration highest_latency = now - received_ts.min_ts; + + if (is_b_frame) { + histogram->histogram_lowest_latency_input_bframe.count_event(lowest_latency.count()); + histogram->histogram_highest_latency_input_bframe.count_event(highest_latency.count()); + } else { + histogram->histogram_lowest_latency_input.count_event(lowest_latency.count()); + histogram->histogram_highest_latency_input.count_event(highest_latency.count()); + } + // 101 is chosen so that it's prime, which is unlikely to get the same frame type every time. if (global_flags.print_video_latency && (++*frameno % 101) == 0) { - const steady_clock::time_point now = steady_clock::now(); printf("%-60s %4.0f ms (lowest-latency input), %4.0f ms (highest-latency input)", - header.c_str(), - 1e3 * std::chrono::duration(now - received_ts.max_ts).count(), - 1e3 * std::chrono::duration(now - received_ts.min_ts).count()); + header.c_str(), 1e3 * lowest_latency.count(), 1e3 * highest_latency.count()); if (is_b_frame) { printf(" [on B-frame; potential extra latency]\n");