commit fefe316501e06c96ce0d905c793b4d872d60e976
author Eric Tan <taneric@google.com> Fri Sep 07 10:09:11 2018 -0700
committer Eric Tan <taneric@google.com> Mon Sep 10 19:05:08 2018 -0700
tree cd6bb858c1de4d0bba5d7a321a5db065247fc3fc
parent bc2a77308b7c197a30a3289e5b75d0f089e65982

NBLog: log and store warmup times, underruns, overruns, and thread info

Test: dumpsys media.log
Bug: 68148948

Change-Id: Ib6ea96760f7886cba47c8e2f0334114237a2434b

services/audioflinger/FastThread.cpp

diff --git a/services/audioflinger/FastThread.cpp b/services/audioflinger/FastThread.cpp
index 6f223df..09101d9 100644
--- a/services/audioflinger/FastThread.cpp
+++ b/services/audioflinger/FastThread.cpp
@@ -22,6 +22,7 @@
 #include "Configuration.h"
 #include <linux/futex.h>
 #include <sys/syscall.h>
+#include <audio_utils/clock.h>
 #include <cutils/atomic.h>
 #include <utils/Log.h>
 #include <utils/Trace.h>
@@ -260,6 +261,9 @@
                         mIsWarm = true;
                         mDumpState->mMeasuredWarmupTs = mMeasuredWarmupTs;
                         mDumpState->mWarmupCycles = mWarmupCycles;
+                        const double measuredWarmupMs = (mMeasuredWarmupTs.tv_sec * 1e3) +
+                                (mMeasuredWarmupTs.tv_nsec * 1e-6);
+                        LOG_WARMUP_TIME(measuredWarmupMs);
                     }
                 }
                 mSleepNs = -1;
@@ -270,6 +274,7 @@
                         ALOGV("underrun: time since last cycle %d.%03ld sec",
                                 (int) sec, nsec / 1000000L);
                         mDumpState->mUnderruns++;
+                        LOG_UNDERRUN(audio_utils_ns_from_timespec(&newTs));
                         mIgnoreNextOverrun = true;
                     } else if (nsec < mOverrunNs) {
                         if (mIgnoreNextOverrun) {
@@ -279,6 +284,7 @@
                             ALOGV("overrun: time since last cycle %d.%03ld sec",
                                     (int) sec, nsec / 1000000L);
                             mDumpState->mOverruns++;
+                            LOG_OVERRUN(audio_utils_ns_from_timespec(&newTs));
                         }
                         // This forces a minimum cycle time. It:
                         //  - compensates for an audio HAL with jitter due to sample rate conversion