More precise and detailed performance measurements

5 files changed, 145 insertions, 51 deletions

diff --git a/encode.c b/encode.c
index 4fe0af0..c3751b1 100644
--- a/encode.c
+++ b/encode.c
@@ -31,6 +31,7 @@
 #include <va/va_drmcommon.h>
 
 #include "gpu.h"
+#include "perf.h"
 #include "util.h"
 
 #define AVBufferRefDestroy av_buffer_unref
@@ -125,9 +126,10 @@ struct EncodeContext* EncodeContextCreate(struct GpuContext* gpu_context,
     return NULL;
   }
 
-  const AVCodec* codec = avcodec_find_encoder_by_name("h264_vaapi");
+  static const char codec_name[] = "h264_vaapi";
+  const AVCodec* codec = avcodec_find_encoder_by_name(codec_name);
   if (!codec) {
-    LOG("Failed to find h264_vaapi encoder");
+    LOG("Failed to find %s encoder", codec_name);
     return NULL;
   }
 
@@ -143,7 +145,7 @@ struct EncodeContext* EncodeContextCreate(struct GpuContext* gpu_context,
   encode_context->codec_context->pix_fmt = AV_PIX_FMT_VAAPI;
   encode_context->codec_context->max_b_frames = 0;
   encode_context->codec_context->refs = 1;
-  encode_context->codec_context->global_quality = 18;
+  encode_context->codec_context->global_quality = 32;
   encode_context->codec_context->colorspace = ConvertColorspace(colrospace);
   encode_context->codec_context->color_range = ConvertRange(range);
 
@@ -250,7 +252,10 @@ static bool DrainPacket(const struct AVPacket* packet, int fd) {
   }
 }
 
-bool EncodeContextEncodeFrame(struct EncodeContext* encode_context, int fd) {
+bool EncodeContextEncodeFrame(struct EncodeContext* encode_context, int fd,
+                              struct TimingStats* encode,
+                              struct TimingStats* drain) {
+  unsigned long long before_send = MicrosNow();
   GpuFrameDestroy(&encode_context->gpu_frame);
   AUTO(AVFrame)* hw_frame = RELEASE(encode_context->hw_frame);
   AUTO(AVPacket)* packet = av_packet_alloc();
@@ -265,13 +270,20 @@ bool EncodeContextEncodeFrame(struct EncodeContext* encode_context, int fd) {
     return false;
   }
 
+  unsigned long long total_send = MicrosNow() - before_send;
+  unsigned long long total_receive = 0;
+  unsigned long long total_drain = 0;
   for (;;) {
+    unsigned long long before_receive = MicrosNow();
     err = avcodec_receive_packet(encode_context->codec_context, packet);
     switch (err) {
       case 0:
         break;
       case AVERROR(EAGAIN):
       case AVERROR_EOF:
+        total_receive += MicrosNow() - before_receive;
+        if (encode) TimingStatsRecord(encode, total_send + total_receive);
+        if (drain) TimingStatsRecord(drain, total_drain);
         return true;
       default:
         LOG("Failed to receive packet (%s)", av_err2str(err));
@@ -279,12 +291,16 @@ bool EncodeContextEncodeFrame(struct EncodeContext* encode_context, int fd) {
     }
 
     packet->stream_index = 0;
+    unsigned long long before_drain = MicrosNow();
     bool result = DrainPacket(packet, fd);
     av_packet_unref(packet);
     if (!result) {
       LOG("Failed to write full packet (%s)", strerror(errno));
       return false;
     }
+
+    total_receive += before_drain - before_receive;
+    total_drain += MicrosNow() - before_drain;
   }
 }
 
diff --git a/encode.h b/encode.h
index 085b0df..318ab02 100644
--- a/encode.h
+++ b/encode.h
@@ -26,6 +26,7 @@
 struct EncodeContext;
 struct GpuContext;
 struct GpuFrame;
+struct TimingStats;
 
 struct EncodeContext* EncodeContextCreate(struct GpuContext* gpu_context,
                                           uint32_t width, uint32_t height,
@@ -33,7 +34,9 @@ struct EncodeContext* EncodeContextCreate(struct GpuContext* gpu_context,
                                           enum YuvRange range);
 const struct GpuFrame* EncodeContextGetFrame(
     struct EncodeContext* encode_context);
-bool EncodeContextEncodeFrame(struct EncodeContext* encode_context, int fd);
+bool EncodeContextEncodeFrame(struct EncodeContext* encode_context, int fd,
+                              struct TimingStats* encode,
+                              struct TimingStats* drain);
 void EncodeContextDestroy(struct EncodeContext** encode_context);
 
 #endif  // STREAMER_ENCODE_H_
diff --git a/main.c b/main.c
index 8d7a42c..1d30c25 100644
--- a/main.c
+++ b/main.c
@@ -16,18 +16,17 @@
  */
 
 #include <errno.h>
-#include <limits.h>
 #include <signal.h>
 #include <stdio.h>
 #include <stdlib.h>
 #include <string.h>
-#include <time.h>
 #include <unistd.h>
 
 #include "capture.h"
 #include "colorspace.h"
 #include "encode.h"
 #include "gpu.h"
+#include "perf.h"
 #include "util.h"
 
 // TODO(mburakov): Currently zwp_linux_dmabuf_v1 has no way to provide
@@ -40,32 +39,6 @@ static const enum YuvRange range = kNarrowRange;
 static volatile sig_atomic_t g_signal;
 static void OnSignal(int status) { g_signal = status; }
 
-struct TimingStats {
-  unsigned long long min;
-  unsigned long long max;
-  unsigned long long sum;
-};
-
-static void TimingStatsRecord(struct TimingStats* timing_stats,
-                              unsigned long long value) {
-  timing_stats->min = MIN(timing_stats->min, value);
-  timing_stats->max = MAX(timing_stats->max, value);
-  timing_stats->sum += value;
-}
-
-static void TimingStatsLog(const struct TimingStats* timing_stats,
-                           const char* name, unsigned long long counter) {
-  LOG("%s min/avg/max: %llu/%llu/%llu", name, timing_stats->min,
-      timing_stats->sum / counter, timing_stats->max);
-}
-
-static unsigned long long MicrosNow(void) {
-  struct timespec ts = {.tv_sec = 0, .tv_nsec = 0};
-  clock_gettime(CLOCK_MONOTONIC, &ts);
-  return (unsigned long long)ts.tv_sec * 1000000ull +
-         (unsigned long long)ts.tv_nsec / 1000ull;
-}
-
 int main(int argc, char* argv[]) {
   (void)argc;
   (void)argv;
@@ -92,12 +65,19 @@ int main(int argc, char* argv[]) {
 
   struct AUTO(EncodeContext)* encode_context = NULL;
 
-  struct TimingStats capture = {.min = ULLONG_MAX};
-  struct TimingStats convert = {.min = ULLONG_MAX};
-  struct TimingStats encode = {.min = ULLONG_MAX};
-  struct TimingStats total = {.min = ULLONG_MAX};
+  struct TimingStats capture;
+  struct TimingStats convert;
+  struct TimingStats encode;
+  struct TimingStats drain;
+  struct TimingStats total;
+  TimingStatsReset(&capture);
+  TimingStatsReset(&convert);
+  TimingStatsReset(&encode);
+  TimingStatsReset(&drain);
+  TimingStatsReset(&total);
   unsigned long long num_frames = 0;
 
+  unsigned long long recording_started = MicrosNow();
   static const unsigned long long delta = 1000000ull / 60ull;
   for (unsigned long long next = MicrosNow() + delta; !g_signal;
        next += delta) {
@@ -135,32 +115,44 @@ int main(int argc, char* argv[]) {
 
     GpuContextSync(gpu_context);
     unsigned long long before_encode = MicrosNow();
-    if (!EncodeContextEncodeFrame(encode_context, STDOUT_FILENO)) {
+    if (!EncodeContextEncodeFrame(encode_context, STDOUT_FILENO, &encode,
+                                  &drain)) {
       LOG("Failed to encode frame");
       return EXIT_FAILURE;
     }
 
     unsigned long long now = MicrosNow();
-    if (num_frames++) {
-      // mburakov: Do not record stats for first (lazy) frame.
-      TimingStatsRecord(&capture, before_convert - before_capture);
-      TimingStatsRecord(&convert, before_encode - before_convert);
-      TimingStatsRecord(&encode, now - before_encode);
-      TimingStatsRecord(&total, now - before_capture);
+    TimingStatsRecord(&capture, before_convert - before_capture);
+    TimingStatsRecord(&convert, before_encode - before_convert);
+    TimingStatsRecord(&total, now - before_capture);
+
+    unsigned long long period = now - recording_started;
+    static const unsigned long long second = 1000000;
+    if (period > 10 * second) {
+      LOG("---->8-------->8-------->8----");
+      TimingStatsLog(&capture, "Capture", num_frames);
+      TimingStatsLog(&convert, "Convert", num_frames);
+      TimingStatsLog(&encode, "Encode", num_frames);
+      TimingStatsLog(&drain, "Drain", num_frames);
+      TimingStatsLog(&total, "Total", num_frames);
+      TimingStatsReset(&capture);
+      TimingStatsReset(&convert);
+      TimingStatsReset(&encode);
+      TimingStatsReset(&drain);
+      TimingStatsReset(&total);
+      recording_started = now;
+      num_frames = 0;
     }
+
+    now = MicrosNow();
     unsigned long long micros = now < next ? next - now : 0;
     if (micros) usleep((unsigned)micros);
+    num_frames++;
   }
 
-  if (!EncodeContextEncodeFrame(encode_context, STDOUT_FILENO)) {
+  if (!EncodeContextEncodeFrame(encode_context, STDOUT_FILENO, NULL, NULL)) {
     LOG("Failed to drain encoder");
     return EXIT_FAILURE;
   }
-
-  num_frames--;
-  TimingStatsLog(&capture, "Capture", num_frames);
-  TimingStatsLog(&convert, "Convert", num_frames);
-  TimingStatsLog(&encode, "Encode", num_frames);
-  TimingStatsLog(&total, "Total", num_frames);
   return EXIT_SUCCESS;
 }
diff --git a/perf.c b/perf.c
new file mode 100644
index 0000000..8ed1d42
--- /dev/null
+++ b/perf.c
@@ -0,0 +1,48 @@
+/*
+ * Copyright (C) 2023 Mikhail Burakov. This file is part of streamer.
+ *
+ * streamer is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * streamer is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with streamer.  If not, see <https://www.gnu.org/licenses/>.
+ */
+
+#include "perf.h"
+
+#include <limits.h>
+#include <stdio.h>
+#include <time.h>
+
+#include "util.h"
+
+unsigned long long MicrosNow(void) {
+  struct timespec ts = {.tv_sec = 0, .tv_nsec = 0};
+  clock_gettime(CLOCK_MONOTONIC, &ts);
+  return (unsigned long long)ts.tv_sec * 1000000ull +
+         (unsigned long long)ts.tv_nsec / 1000ull;
+}
+
+void TimingStatsReset(struct TimingStats* timing_stats) {
+  *timing_stats = (struct TimingStats){.min = ULLONG_MAX};
+}
+
+void TimingStatsRecord(struct TimingStats* timing_stats,
+                       unsigned long long value) {
+  timing_stats->min = MIN(timing_stats->min, value);
+  timing_stats->max = MAX(timing_stats->max, value);
+  timing_stats->sum += value;
+}
+
+void TimingStatsLog(const struct TimingStats* timing_stats, const char* name,
+                    unsigned long long counter) {
+  LOG("%s min/avg/max: %llu/%llu/%llu", name, timing_stats->min,
+      timing_stats->sum / counter, timing_stats->max);
+}
diff --git a/perf.h b/perf.h
new file mode 100644
index 0000000..24c50c7
--- /dev/null
+++ b/perf.h
@@ -0,0 +1,35 @@
+/*
+ * Copyright (C) 2023 Mikhail Burakov. This file is part of streamer.
+ *
+ * streamer is free software: you can redistribute it and/or modify
+ * it under the terms of the GNU General Public License as published by
+ * the Free Software Foundation, either version 3 of the License, or
+ * (at your option) any later version.
+ *
+ * streamer is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+ * GNU General Public License for more details.
+ *
+ * You should have received a copy of the GNU General Public License
+ * along with streamer.  If not, see <https://www.gnu.org/licenses/>.
+ */
+
+#ifndef STREAMER_PERF_H_
+#define STREAMER_PERF_H_
+
+struct TimingStats {
+  unsigned long long min;
+  unsigned long long max;
+  unsigned long long sum;
+};
+
+unsigned long long MicrosNow(void);
+
+void TimingStatsReset(struct TimingStats* timing_stats);
+void TimingStatsRecord(struct TimingStats* timing_stats,
+                       unsigned long long value);
+void TimingStatsLog(const struct TimingStats* timing_stats, const char* name,
+                    unsigned long long counter);
+
+#endif  // STREAMER_PERF_H_