Make separate latencies per card, instead of just min and max.

diff --git a/metrics.cpp b/metrics.cpp
index fafc38915a9601732d27df973daf903f82412214..5079acb2064e5515a1a549af00c35924edcc57dd 100644 (file)
--- a/metrics.cpp
+++ b/metrics.cpp
@@ -63,10 +63,11 @@ void Metrics::add(const string &name, const vector<pair<string, string>> &labels
        types[name] = type;
 }
 
-void Metrics::add(const string &name, const vector<pair<string, string>> &labels, Histogram *location)
+void Metrics::add(const string &name, const vector<pair<string, string>> &labels, Histogram *location, Laziness laziness)
 {
        Metric metric;
        metric.data_type = DATA_TYPE_HISTOGRAM;
+       metric.laziness = laziness;
        metric.location_histogram = location;
 
        lock_guard<mutex> lock(mu);
@@ -126,7 +127,7 @@ string Metrics::serialize() const
                                ss << name << " " << val << "\n";
                        }
                } else {
-                       ss << metric.location_histogram->serialize(key_and_metric.first.name, key_and_metric.first.labels);
+                       ss << metric.location_histogram->serialize(metric.laziness, key_and_metric.first.name, key_and_metric.first.labels);
                }
        }
 
@@ -175,8 +176,22 @@ void Histogram::count_event(double val)
        sum = sum + val;
 }
 
-string Histogram::serialize(const string &name, const vector<pair<string, string>> &labels) const
+string Histogram::serialize(Metrics::Laziness laziness, const string &name, const vector<pair<string, string>> &labels) const
 {
+       // Check if the histogram is empty and should not be serialized.
+       if (laziness == Metrics::PRINT_WHEN_NONEMPTY && count_after_last_bucket.load() == 0) {
+               bool empty = true;
+               for (size_t bucket_idx = 0; bucket_idx < num_buckets; ++bucket_idx) {
+                       if (buckets[bucket_idx].count.load() != 0) {
+                               empty = false;
+                               break;
+                       }
+               }
+               if (empty) {
+                       return "";
+               }
+       }
+
        stringstream ss;
        ss.imbue(locale("C"));
        ss.precision(20);

diff --git a/metrics.h b/metrics.h
index 603abb09630623c163d155952346d0fdb6a6865f..d515720ade805b8c4d43eeea23fe23955e7aa819 100644 (file)
--- a/metrics.h
+++ b/metrics.h
@@ -28,6 +28,10 @@ public:
                TYPE_GAUGE,
                TYPE_HISTOGRAM,  // Internal use only.
        };
+       enum Laziness {
+               PRINT_ALWAYS,
+               PRINT_WHEN_NONEMPTY,
+       };
 
        void add(const std::string &name, std::atomic<int64_t> *location, Type type = TYPE_COUNTER)
        {
@@ -46,7 +50,7 @@ public:
 
        void add(const std::string &name, const std::vector<std::pair<std::string, std::string>> &labels, std::atomic<int64_t> *location, Type type = TYPE_COUNTER);
        void add(const std::string &name, const std::vector<std::pair<std::string, std::string>> &labels, std::atomic<double> *location, Type type = TYPE_COUNTER);
-       void add(const std::string &name, const std::vector<std::pair<std::string, std::string>> &labels, Histogram *location);
+       void add(const std::string &name, const std::vector<std::pair<std::string, std::string>> &labels, Histogram *location, Laziness laziness = PRINT_ALWAYS);
 
        void remove(const std::string &name)
        {
@@ -85,6 +89,7 @@ private:
        };
        struct Metric {
                DataType data_type;
+               Laziness laziness;  // Only for TYPE_HISTOGRAM.
                union {
                        std::atomic<int64_t> *location_int64;
                        std::atomic<double> *location_double;
@@ -106,7 +111,7 @@ public:
        void init_uniform(size_t num_buckets);  // Sets up buckets 0..(N-1).
        void init_geometric(double min, double max, size_t num_buckets);
        void count_event(double val);
-       std::string serialize(const std::string &name, const std::vector<std::pair<std::string, std::string>> &labels) const;
+       std::string serialize(Metrics::Laziness laziness, const std::string &name, const std::vector<std::pair<std::string, std::string>> &labels) const;
 
 private:
        // Bucket <i> counts number of events where val[i - 1] < x <= val[i].

diff --git a/print_latency.cpp b/print_latency.cpp
index a80ac4f3242a2e7e1b44b5bb3215b8986fe1f728..7101f39671101738b3c5388c55cdc1f68e021b2c 100644 (file)
--- a/print_latency.cpp
+++ b/print_latency.cpp
@@ -2,8 +2,10 @@
 
 #include "flags.h"
 #include "metrics.h"
+#include "mixer.h"
 
 #include <stdio.h>
+#include <algorithm>
 #include <chrono>
 #include <string>
 
@@ -12,53 +14,77 @@ using namespace std::chrono;
 
 ReceivedTimestamps find_received_timestamp(const vector<RefCountedFrame> &input_frames)
 {
-       // Find min and max timestamp of all input frames that have a timestamp.
-       steady_clock::time_point min_ts = steady_clock::time_point::max(), max_ts = steady_clock::time_point::min();
-       for (const RefCountedFrame &input_frame : input_frames) {
-               if (input_frame && input_frame->received_timestamp > steady_clock::time_point::min()) {
-                       min_ts = min(min_ts, input_frame->received_timestamp);
-                       max_ts = max(max_ts, input_frame->received_timestamp);
+       unsigned num_cards = global_mixer->get_num_cards();
+       assert(input_frames.size() == num_cards * FRAME_HISTORY_LENGTH);
+
+       ReceivedTimestamps ts;
+       for (unsigned card_index = 0; card_index < num_cards; ++card_index) {
+               for (unsigned frame_index = 0; frame_index < FRAME_HISTORY_LENGTH; ++frame_index) {
+                       const RefCountedFrame &input_frame = input_frames[card_index * FRAME_HISTORY_LENGTH + frame_index];
+                       if (input_frame == nullptr ||
+                           (frame_index > 0 && input_frame.get() == input_frames[card_index * FRAME_HISTORY_LENGTH + frame_index - 1].get())) {
+                               ts.ts.push_back(steady_clock::time_point::min());
+                       } else {
+                               ts.ts.push_back(input_frame->received_timestamp);
+                       }
                }
        }
-       return { min_ts, max_ts };
+       return ts;
 }
 
 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);
+       unsigned num_cards = global_flags.num_cards;  // The mixer might not be ready yet.
+       histograms.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);
+               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);
 
-       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);
+                       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);
+                       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],
+                               (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],
+                               Metrics::PRINT_WHEN_NONEMPTY);
+               }
+       }
 }
 
 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())
+       if (received_ts.ts.empty())
                return;
 
        const steady_clock::time_point now = steady_clock::now();
-       duration<double> lowest_latency = now - received_ts.max_ts;
-       duration<double> highest_latency = now - received_ts.min_ts;
+       duration<double> lowest_latency = now - *max_element(received_ts.ts.begin(), received_ts.ts.end());
+       duration<double> highest_latency = now - *min_element(received_ts.ts.begin(), received_ts.ts.end());
 
-       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());
+       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<double> latency = now - ts;
+                       histogram->histograms[card_index][frame_index][is_b_frame].count_event(latency.count());
+               }
        }
 
        // 101 is chosen so that it's prime, which is unlikely to get the same frame type every time.

diff --git a/print_latency.h b/print_latency.h
index 1c937c58856a7cb2a511e7856ebbf1c51fc87c24..3b0adb1e77244e0b422e93118e6c36c1e92295d4 100644 (file)
--- a/print_latency.h
+++ b/print_latency.h
@@ -13,17 +13,16 @@
 #include "metrics.h"
 
 // Since every output frame is based on multiple input frames, we need
-// more than one start timestamp. For now, we keep just the smallest
-// and largest timestamp, so that we can print out a range.
-// For both of these, steady_clock::time_point::min() is used for “not set”.
+// more than one start timestamp; one for each input.
+// For all of these, steady_clock::time_point::min() is used for “not set”.
 struct ReceivedTimestamps {
-       std::chrono::steady_clock::time_point min_ts, max_ts;
+       std::vector<std::chrono::steady_clock::time_point> ts;
 };
 struct LatencyHistogram {
        void init(const std::string &measuring_point);  // Initializes histograms and registers them in global_metrics.
 
-       Histogram histogram_lowest_latency_input, histogram_highest_latency_input;
-       Histogram histogram_lowest_latency_input_bframe, histogram_highest_latency_input_bframe;
+       // Indices: card number, frame history number, b-frame or not (1/0).
+       std::vector<std::vector<std::unique_ptr<Histogram[]>>> histograms;
 };
 
 ReceivedTimestamps find_received_timestamp(const std::vector<RefCountedFrame> &input_frames);

diff --git a/theme.h b/theme.h
index 71e44bd42cac49b4b9691f358c8f85f545f7addf..9e9672e0fa5b98d23b8edd897a587a84cc9360ca 100644 (file)
--- a/theme.h
+++ b/theme.h
@@ -34,7 +34,8 @@ public:
                movit::EffectChain *chain;
                std::function<void()> setup_chain;
 
-               // May have duplicates.
+               // FRAME_HISTORY frames for each input, in order. Will contain duplicates
+               // for non-interlaced inputs.
                std::vector<RefCountedFrame> input_frames;
        };