commit a269bd174b423720b74dfa7caa354cc0996b9635
author Gopalakrishnan Nallasamy <gokrishnan@google.com> Tue Jun 30 16:53:55 2020 -0700
committer Gopalakrishnan Nallasamy <gokrishnan@google.com> Thu Jul 02 05:59:21 2020 +0000
tree fd1ce10ee25202b489b2ea082483928cb2e8f3c1
parent 54cc1e3c434ab84d623d558db19679f37bb60142

MPEG4Writer:Print longest 5 write durations

Using priority queue, maintain longest 5 write durations and print them
as debug logs during stop.

Bug: 159254170

Test: atest android.media.cts.MediaMuxerTest \
        android.mediav2.cts.MuxerTest \
        android.mediav2.cts.MuxerUnitTest \
        android.media.cts.MediaRecorderTest
Change-Id: I86fcbde66ec387d1aafb2bdbd6f9b2a72a17f977
Merged-In: I86fcbde66ec387d1aafb2bdbd6f9b2a72a17f977

media/libstagefright/MPEG4Writer.cpp

diff --git a/media/libstagefright/MPEG4Writer.cpp b/media/libstagefright/MPEG4Writer.cpp
index 39423c7..ca92198 100644
--- a/media/libstagefright/MPEG4Writer.cpp
+++ b/media/libstagefright/MPEG4Writer.cpp
@@ -1110,6 +1110,21 @@
     writeInt32(0x40000000);  // w
 }
 
+void MPEG4Writer::printWriteDurations() {
+    if (mWriteDurationPQ.empty()) {
+        return;
+    }
+    std::string writeDurationsString =
+            "Top " + std::to_string(mWriteDurationPQ.size()) + " write durations(microseconds):";
+    uint8_t i = 0;
+    while (!mWriteDurationPQ.empty()) {
+        writeDurationsString +=
+                " #" + std::to_string(++i) + ":" + std::to_string(mWriteDurationPQ.top().count());
+        mWriteDurationPQ.pop();
+    }
+    ALOGD("%s", writeDurationsString.c_str());
+}
+
 status_t MPEG4Writer::release() {
     ALOGD("release()");
     status_t err = OK;
@@ -1138,6 +1153,9 @@
     mStarted = false;
     free(mInMemoryCache);
     mInMemoryCache = NULL;
+
+    printWriteDurations();
+
     return err;
 }
 
@@ -1594,7 +1612,17 @@
 void MPEG4Writer::writeOrPostError(int fd, const void* buf, size_t count) {
     if (mWriteSeekErr == true)
         return;
+
+    auto beforeTP = std::chrono::high_resolution_clock::now();
     ssize_t bytesWritten = ::write(fd, buf, count);
+    auto afterTP = std::chrono::high_resolution_clock::now();
+    auto writeDuration =
+            std::chrono::duration_cast<std::chrono::microseconds>(afterTP - beforeTP).count();
+    mWriteDurationPQ.emplace(writeDuration);
+    if (mWriteDurationPQ.size() > kWriteDurationsCount) {
+        mWriteDurationPQ.pop();
+    }
+
     /* Write as much as possible during stop() execution when there was an error
      * (mWriteSeekErr == true) in the previous call to write() or lseek64().
      */

media/libstagefright/include/media/stagefright/MPEG4Writer.h

diff --git a/media/libstagefright/include/media/stagefright/MPEG4Writer.h b/media/libstagefright/include/media/stagefright/MPEG4Writer.h
index a1fe57c..501cf2c 100644
--- a/media/libstagefright/include/media/stagefright/MPEG4Writer.h
+++ b/media/libstagefright/include/media/stagefright/MPEG4Writer.h
@@ -27,6 +27,7 @@
 #include <media/stagefright/foundation/AHandlerReflector.h>
 #include <media/stagefright/foundation/ALooper.h>
 #include <mutex>
+#include <queue>
 
 namespace android {
 
@@ -125,6 +126,10 @@
     bool mWriteSeekErr;
     bool mFallocateErr;
     bool mPreAllocationEnabled;
+    // Queue to hold top long write durations
+    std::priority_queue<std::chrono::microseconds, std::vector<std::chrono::microseconds>,
+                        std::greater<std::chrono::microseconds>> mWriteDurationPQ;
+    const uint8_t kWriteDurationsCount = 5;
 
     sp<ALooper> mLooper;
     sp<AHandlerReflector<MPEG4Writer> > mReflector;
@@ -149,6 +154,7 @@
     int64_t estimateMoovBoxSize(int32_t bitRate);
     int64_t estimateFileLevelMetaSize(MetaData *params);
     void writeCachedBoxToFile(const char *type);
+    void printWriteDurations();
 
     struct Chunk {
         Track               *mTrack;        // Owner