[x265] [PATCH 11 of 13] stats: report wall time of frame encoder with no active worker threads

[Steve Borho]

# HG changeset patch
# User Steve Borho <steve at borho.org>
# Date 1422474942 21600
#      Wed Jan 28 13:55:42 2015 -0600
# Node ID 9c26ca2c9c0e8786331e40b4ac3bce223e8e59b5
# Parent  766e91256991ae9ab6754da3101838e1c0861a24
stats: report wall time of frame encoder with no active worker threads

But do not start this counter until the first CTU is processed

diff -r 766e91256991 -r 9c26ca2c9c0e source/encoder/encoder.cpp
--- a/source/encoder/encoder.cpp	Wed Jan 28 13:44:58 2015 -0600
+++ b/source/encoder/encoder.cpp	Wed Jan 28 13:55:42 2015 -0600
@@ -215,7 +215,7 @@
                         fprintf(m_csvfpt, "RateFactor, ");
                     fprintf(m_csvfpt, "Y PSNR, U PSNR, V PSNR, YUV PSNR, SSIM, SSIM (dB),  List 0, List 1");
                     /* detailed performance statistics */
-                    fprintf(m_csvfpt, ", Row0Wait ms, Wall time ms, Ref Wait Wall ms, Total CTU time ms, Avg WPP, Row Blocks\n");
+                    fprintf(m_csvfpt, ", Row0Wait ms, Wall time ms, Ref Wait Wall ms, Total CTU time ms, Stall Time ms, Avg WPP, Row Blocks\n");
                 }
                 else
                     fputs(summaryCSVHeader, m_csvfpt);
@@ -1187,11 +1187,12 @@
 #define ELAPSED_MSEC(start, end) (((double)(end) - (start)) / 1000)
 
             // detailed frame statistics
-            fprintf(m_csvfpt, ", %.1lf, %.1lf, %.1lf, %.1lf",
+            fprintf(m_csvfpt, ", %.1lf, %.1lf, %.1lf, %.1lf, %.1lf",
                 ELAPSED_MSEC(curEncoder->m_startCompressTime, curEncoder->m_row0WaitTime),
                 ELAPSED_MSEC(curEncoder->m_row0WaitTime, curEncoder->m_endCompressTime),
                 ELAPSED_MSEC(curEncoder->m_row0WaitTime, curEncoder->m_allRowsAvailableTime),
-                ELAPSED_MSEC(0, curEncoder->m_totalWorkerElapsedTime));
+                ELAPSED_MSEC(0, curEncoder->m_totalWorkerElapsedTime),
+                ELAPSED_MSEC(0, curEncoder->m_totalNoWorkerTime));
             if (curEncoder->m_totalActiveWorkerCount)
                 fprintf(m_csvfpt, ", %.3lf", (double)curEncoder->m_totalActiveWorkerCount / curEncoder->m_activeWorkerCountSamples);
             else
diff -r 766e91256991 -r 9c26ca2c9c0e source/encoder/frameencoder.cpp
--- a/source/encoder/frameencoder.cpp	Wed Jan 28 13:44:58 2015 -0600
+++ b/source/encoder/frameencoder.cpp	Wed Jan 28 13:55:42 2015 -0600
@@ -239,7 +239,10 @@
     m_totalActiveWorkerCount = 0;
     m_activeWorkerCountSamples = 0;
     m_totalWorkerElapsedTime = 0;
+    m_totalNoWorkerTime = 0;
     m_countRowBlocks = 0;
+    m_allRowsAvailableTime = 0;
+    m_stallStartTime = 0;
 
     /* Emit access unit delimiter unless this is the first frame and the user is
      * not repeating headers (since AUD is supposed to be the first NAL in the access
@@ -689,7 +692,8 @@
 void FrameEncoder::processRow(int row, int threadId)
 {
     int64_t startTime = x265_mdate();
-    ATOMIC_INC(&m_activeWorkerCount);
+    if (ATOMIC_INC(&m_activeWorkerCount) == 1 && m_stallStartTime)
+        m_totalNoWorkerTime += x265_mdate() - m_stallStartTime;
 
     const uint32_t realRow = row >> 1;
     const uint32_t typeNum = row & 1;
@@ -709,7 +713,9 @@
             m_completionEvent.trigger();
     }
 
-    ATOMIC_DEC(&m_activeWorkerCount);
+    if (ATOMIC_DEC(&m_activeWorkerCount) == 0)
+        m_stallStartTime = x265_mdate();
+
     m_totalWorkerElapsedTime += x265_mdate() - startTime; // not thread safe, but good enough
 }
 
diff -r 766e91256991 -r 9c26ca2c9c0e source/encoder/frameencoder.h
--- a/source/encoder/frameencoder.h	Wed Jan 28 13:44:58 2015 -0600
+++ b/source/encoder/frameencoder.h	Wed Jan 28 13:55:42 2015 -0600
@@ -172,6 +172,7 @@
     int64_t                  m_allRowsAvailableTime;     // timestamp when all reference dependencies are resolved
     int64_t                  m_endCompressTime;          // timestamp after all CTUs are compressed
     int64_t                  m_endFrameTime;             // timestamp after RCEnd, NR updates, etc
+    int64_t                  m_stallStartTime;           // timestamp when worker count becomes 0
     int64_t                  m_totalWorkerElapsedTime;   // total elapsed time spent by worker threads processing CTUs
     int64_t                  m_totalNoWorkerTime;        // total elapsed time without any active worker threads