Initial check-in for collecting stats from authoring engine at runtime

Change-Id: I93a9d8bd260efc5e7fc135b726e3f1307c6df794

5 files changed, 145 insertions, 6 deletions

diff --git a/include/media/stagefright/AudioSource.h b/include/media/stagefright/AudioSource.h
index 251937993f1d..860384e2ddf1 100644
--- a/include/media/stagefright/AudioSource.h
+++ b/include/media/stagefright/AudioSource.h
@@ -51,6 +51,12 @@ private:
     AudioRecord *mRecord;
     status_t mInitCheck;
     bool mStarted;
+
+    bool mCollectStats;
+    int64_t mTotalReadTimeUs;
+    int64_t mTotalReadBytes;
+    int64_t mTotalReads;
+
     MediaBufferGroup *mGroup;
 
     AudioSource(const AudioSource &);
diff --git a/include/media/stagefright/CameraSource.h b/include/media/stagefright/CameraSource.h
index 0a7023ad8749..b2134b4bbed7 100644
--- a/include/media/stagefright/CameraSource.h
+++ b/include/media/stagefright/CameraSource.h
@@ -65,6 +65,7 @@ private:
     int32_t mNumFramesReceived;
     int32_t mNumFramesEncoded;
     int32_t mNumFramesDropped;
+    bool mCollectStats;
     bool mStarted;
 
     CameraSource(const sp<Camera> &camera);
diff --git a/media/libstagefright/AudioSource.cpp b/media/libstagefright/AudioSource.cpp
index abd8abc16bb0..326e8dc701e0 100644
--- a/media/libstagefright/AudioSource.cpp
+++ b/media/libstagefright/AudioSource.cpp
@@ -25,6 +25,9 @@
 #include <media/stagefright/MediaDebug.h>
 #include <media/stagefright/MediaDefs.h>
 #include <media/stagefright/MetaData.h>
+#include <cutils/properties.h>
+#include <sys/time.h>
+#include <time.h>
 
 namespace android {
 
@@ -34,6 +37,10 @@ AudioSource::AudioSource(
                 inputSource, sampleRate, AudioSystem::PCM_16_BIT, channels)),
       mInitCheck(mRecord->initCheck()),
       mStarted(false),
+      mCollectStats(false),
+      mTotalReadTimeUs(0),
+      mTotalReadBytes(0),
+      mTotalReads(0),
       mGroup(NULL) {
 }
 
@@ -55,6 +62,11 @@ status_t AudioSource::start(MetaData *params) {
         return UNKNOWN_ERROR;
     }
 
+    char value[PROPERTY_VALUE_MAX];
+    if (property_get("media.stagefright.record-stats", value, NULL)
+        && (!strcmp(value, "1") || !strcasecmp(value, "true"))) {
+        mCollectStats = true;
+    }
     status_t err = mRecord->start();
 
     if (err == OK) {
@@ -79,6 +91,13 @@ status_t AudioSource::stop() {
 
     mStarted = false;
 
+    if (mCollectStats) {
+        LOGI("%lld reads: %.2f bps in %lld us",
+                mTotalReads,
+                (mTotalReadBytes * 8000000.0) / mTotalReadTimeUs,
+                mTotalReadTimeUs);
+    }
+
     return OK;
 }
 
@@ -95,6 +114,7 @@ sp<MetaData> AudioSource::getFormat() {
 status_t AudioSource::read(
         MediaBuffer **out, const ReadOptions *options) {
     *out = NULL;
+    ++mTotalReads;
 
     MediaBuffer *buffer;
     CHECK_EQ(mGroup->acquire_buffer(&buffer), OK);
@@ -107,7 +127,20 @@ status_t AudioSource::read(
             (1000000ll * numFramesRecorded) / mRecord->getSampleRate()
             - mRecord->latency() * 1000);
 
-    ssize_t n = mRecord->read(buffer->data(), buffer->size());
+    ssize_t n = 0;
+    if (mCollectStats) {
+        struct timeval tv_start, tv_end;
+        gettimeofday(&tv_start, NULL);
+        n = mRecord->read(buffer->data(), buffer->size());
+        gettimeofday(&tv_end, NULL);
+        mTotalReadTimeUs += ((1000000LL * (tv_end.tv_sec - tv_start.tv_sec))
+                + (tv_end.tv_usec - tv_start.tv_usec));
+        if (n >= 0) {
+            mTotalReadBytes += n;
+        }
+    } else {
+        n = mRecord->read(buffer->data(), buffer->size());
+    }
 
     if (n < 0) {
         buffer->release();
diff --git a/media/libstagefright/CameraSource.cpp b/media/libstagefright/CameraSource.cpp
index 264ac5f3e93c..416b75ca2e14 100644
--- a/media/libstagefright/CameraSource.cpp
+++ b/media/libstagefright/CameraSource.cpp
@@ -28,6 +28,7 @@
 #include <camera/Camera.h>
 #include <camera/CameraParameters.h>
 #include <utils/String8.h>
+#include <cutils/properties.h>
 
 namespace android {
 
@@ -122,6 +123,7 @@ CameraSource::CameraSource(const sp<Camera> &camera)
       mNumFramesReceived(0),
       mNumFramesEncoded(0),
       mNumFramesDropped(0),
+      mCollectStats(false),
       mStarted(false) {
     String8 s = mCamera->getParameters();
     printf("params: \"%s\"\n", s.string());
@@ -151,6 +153,11 @@ status_t CameraSource::start(MetaData *) {
     LOGV("start");
     CHECK(!mStarted);
 
+    char value[PROPERTY_VALUE_MAX];
+    if (property_get("media.stagefright.record-stats", value, NULL)
+        && (!strcmp(value, "1") || !strcasecmp(value, "true"))) {
+        mCollectStats = true;
+    }
     mCamera->setListener(new CameraSourceListener(this));
     CHECK_EQ(OK, mCamera->startRecording());
 
@@ -163,19 +170,23 @@ status_t CameraSource::stop() {
     Mutex::Autolock autoLock(mLock);
     mStarted = false;
     mFrameAvailableCondition.signal();
+
     mCamera->setListener(NULL);
     mCamera->stopRecording();
 
     releaseQueuedFrames();
 
     while (!mFramesBeingEncoded.empty()) {
-        LOGI("Number of outstanding frames is being encoded: %d", mFramesBeingEncoded.size());
+        LOGI("Waiting for outstanding frames being encoded: %d",
+                mFramesBeingEncoded.size());
         mFrameCompleteCondition.wait(mLock);
     }
 
-    LOGI("Frames received/encoded/dropped: %d/%d/%d, timestamp (us) last/first: %lld/%lld",
-            mNumFramesReceived, mNumFramesEncoded, mNumFramesDropped,
-            mLastFrameTimestampUs, mFirstFrameTimeUs);
+    if (mCollectStats) {
+        LOGI("Frames received/encoded/dropped: %d/%d/%d in %lld us",
+                mNumFramesReceived, mNumFramesEncoded, mNumFramesDropped,
+                mLastFrameTimestampUs - mFirstFrameTimeUs);
+    }
 
     CHECK_EQ(mNumFramesReceived, mNumFramesEncoded + mNumFramesDropped);
     return OK;
@@ -252,7 +263,6 @@ status_t CameraSource::read(
 void CameraSource::dataCallbackTimestamp(int64_t timestampUs,
         int32_t msgType, const sp<IMemory> &data) {
     LOGV("dataCallbackTimestamp: timestamp %lld us", timestampUs);
-    mLastFrameTimestampUs = timestampUs;
     Mutex::Autolock autoLock(mLock);
     if (!mStarted) {
         mCamera->releaseRecordingFrame(data);
@@ -261,6 +271,7 @@ void CameraSource::dataCallbackTimestamp(int64_t timestampUs,
         return;
     }
 
+    mLastFrameTimestampUs = timestampUs;
     if (mNumFramesReceived == 0) {
         mFirstFrameTimeUs = timestampUs;
     }
diff --git a/media/libstagefright/MPEG4Writer.cpp b/media/libstagefright/MPEG4Writer.cpp
index 6fa11e062c11..db600786bbca 100644
--- a/media/libstagefright/MPEG4Writer.cpp
+++ b/media/libstagefright/MPEG4Writer.cpp
@@ -32,6 +32,7 @@
 #include <media/stagefright/MediaSource.h>
 #include <media/stagefright/Utils.h>
 #include <media/mediarecorder.h>
+#include <cutils/properties.h>
 
 namespace android {
 
@@ -82,6 +83,7 @@ private:
     List<StscTableEntry> mStscTableEntries;
 
     List<int32_t> mStssTableEntries;
+    List<int64_t> mChunkDurations;
 
     struct SttsTableEntry {
 
@@ -106,6 +108,9 @@ private:
     status_t makeAVCCodecSpecificData(
             const uint8_t *data, size_t size);
     void writeOneChunk(bool isAvc);
+    void logStatisticalData(bool isAudio);
+    void findMinMaxFrameRates(float *minFps, float *maxFps);
+    void findMinMaxChunkDurations(int64_t *min, int64_t *max);
 
     Track(const Track &);
     Track &operator=(const Track &);
@@ -912,6 +917,7 @@ void MPEG4Writer::Track::threadEntry() {
             } else {
                 if (timestampUs - chunkTimestampUs > interleaveDurationUs) {
                     ++nChunks;
+                    mChunkDurations.push_back(timestampUs - chunkTimestampUs);
                     if (nChunks == 1 ||  // First chunk
                         (--(mStscTableEntries.end()))->samplesPerChunk !=
                          mChunkSamples.size()) {
@@ -952,6 +958,88 @@ void MPEG4Writer::Track::threadEntry() {
     mReachedEOS = true;
     LOGI("Received total/0-length (%d/%d) buffers and encoded %d frames - %s",
             count, nZeroLengthFrames, mSampleInfos.size(), is_audio? "audio": "video");
+
+    logStatisticalData(is_audio);
+}
+
+void MPEG4Writer::Track::findMinMaxFrameRates(float *minFps, float *maxFps) {
+    int32_t minSampleDuration = 0x7FFFFFFF;
+    int32_t maxSampleDuration = 0;
+    for (List<SttsTableEntry>::iterator it = mSttsTableEntries.begin();
+        it != mSttsTableEntries.end(); ++it) {
+        int32_t sampleDuration = static_cast<int32_t>(it->sampleDuration);
+        if (sampleDuration > maxSampleDuration) {
+            maxSampleDuration = sampleDuration;
+        } else if (sampleDuration < minSampleDuration) {
+            minSampleDuration = sampleDuration;
+        }
+    }
+    CHECK(minSampleDuration != 0 && maxSampleDuration != 0);
+    *minFps = 1000.0 / maxSampleDuration;
+    *maxFps = 1000.0 / minSampleDuration;
+}
+
+// Don't count the last duration
+void MPEG4Writer::Track::findMinMaxChunkDurations(int64_t *min, int64_t *max) {
+    int64_t duration = mOwner->interleaveDuration();
+    int64_t minChunkDuration = duration;
+    int64_t maxChunkDuration = duration;
+    if (mChunkDurations.size() > 1) {
+        for (List<int64_t>::iterator it = mChunkDurations.begin();
+            it != --mChunkDurations.end(); ++it) {
+            if (minChunkDuration > (*it)) {
+                minChunkDuration = (*it);
+            } else if (maxChunkDuration < (*it)) {
+                maxChunkDuration = (*it);
+            }
+        }
+    }
+    *min = minChunkDuration;
+    *max = maxChunkDuration;
+}
+
+void MPEG4Writer::Track::logStatisticalData(bool isAudio) {
+    if (mMaxTimeStampUs <= 0 || mSampleInfos.empty()) {
+        LOGI("nothing is recorded");
+        return;
+    }
+
+    bool collectStats = false;
+    char value[PROPERTY_VALUE_MAX];
+    if (property_get("media.stagefright.record-stats", value, NULL)
+        && (!strcmp(value, "1") || !strcasecmp(value, "true"))) {
+        collectStats = true;
+    }
+
+    if (collectStats) {
+        if (isAudio) {
+            LOGI("audio track - duration %lld us", mMaxTimeStampUs);
+        } else {
+            float fps = (mSampleInfos.size() * 1000000.0) / mMaxTimeStampUs;
+            float minFps;
+            float maxFps;
+            findMinMaxFrameRates(&minFps, &maxFps);
+            LOGI("video track - duration %lld us", mMaxTimeStampUs);
+            LOGI("min/avg/max frame rate (fps): %.2f/%.2f/%.2f",
+                minFps, fps, maxFps);
+        }
+
+        int64_t totalBytes = 0;
+        for (List<SampleInfo>::iterator it = mSampleInfos.begin();
+            it != mSampleInfos.end(); ++it) {
+            totalBytes += it->size;
+        }
+        float bitRate = (totalBytes * 8000000.0) / mMaxTimeStampUs;
+        LOGI("avg bit rate (bps): %.2f", bitRate);
+
+        int64_t duration = mOwner->interleaveDuration();
+        if (duration != 0) {  // If interleaving is enabled
+            int64_t minChunk, maxChunk;
+            findMinMaxChunkDurations(&minChunk, &maxChunk);
+            LOGI("min/avg/max chunk duration (ms): %lld/%lld/%lld",
+                minChunk, duration, maxChunk);
+        }
+    }
 }
 
 void MPEG4Writer::Track::writeOneChunk(bool isAvc) {