Reduce log messages on AudioFlinger throttle

Bug: 21858740
Change-Id: I8f291b64c1033867bb57ffceaa3b7d94aa998715
diff --git a/services/audioflinger/Threads.cpp b/services/audioflinger/Threads.cpp
index 489f2d4..410fff5 100644
--- a/services/audioflinger/Threads.cpp
+++ b/services/audioflinger/Threads.cpp
@@ -2194,6 +2194,8 @@
 
     // Check if we want to throttle the processing to no more than 2x normal rate
     mThreadThrottle = property_get_bool("af.thread.throttle", true /* default_value */);
+    mThreadThrottleTimeMs = 0;
+    mThreadThrottleEndMs = 0;
     mHalfBufferMs = mNormalFrameCount * 1000 / (2 * mSampleRate);
 
     // mSinkBuffer is the sink buffer.  Size is always multiple-of-16 frames.
@@ -2960,8 +2962,19 @@
                         const int32_t throttleMs = mHalfBufferMs - deltaMs;
                         if ((signed)mHalfBufferMs >= throttleMs && throttleMs > 0) {
                             usleep(throttleMs * 1000);
-                            ALOGD("mixer(%p) throttle: ret(%zd) deltaMs(%d) requires sleep %d ms",
+                            // notify of throttle start on verbose log
+                            ALOGV_IF(mThreadThrottleEndMs == mThreadThrottleTimeMs,
+                                    "mixer(%p) throttle begin:"
+                                    " ret(%zd) deltaMs(%d) requires sleep %d ms",
                                     this, ret, deltaMs, throttleMs);
+                            mThreadThrottleTimeMs += throttleMs;
+                        } else {
+                            uint32_t diff = mThreadThrottleTimeMs - mThreadThrottleEndMs;
+                            if (diff > 0) {
+                                // notify of throttle end on debug log
+                                ALOGD("mixer(%p) throttle end: throttle time(%u)", this, diff);
+                                mThreadThrottleEndMs = mThreadThrottleTimeMs;
+                            }
                         }
                     }
                 }
@@ -4340,7 +4353,7 @@
     String8 result;
 
     PlaybackThread::dumpInternals(fd, args);
-
+    dprintf(fd, "  Thread throttle time (msecs): %u\n", mThreadThrottleTimeMs);
     dprintf(fd, "  AudioMixer tracks: 0x%08x\n", mAudioMixer->trackNames());
 
     // Make a non-atomic copy of fast mixer dump state so it won't change underneath us
diff --git a/services/audioflinger/Threads.h b/services/audioflinger/Threads.h
index 4ebe615..b12b091 100644
--- a/services/audioflinger/Threads.h
+++ b/services/audioflinger/Threads.h
@@ -614,6 +614,8 @@
     size_t                          mNormalFrameCount;  // normal mixer and effects
 
     bool                            mThreadThrottle;     // throttle the thread processing
+    uint32_t                        mThreadThrottleTimeMs; // throttle time for MIXER threads
+    uint32_t                        mThreadThrottleEndMs;  // notify once per throttling
     uint32_t                        mHalfBufferMs;       // half the buffer size in milliseconds
 
     void*                           mSinkBuffer;         // frame size aligned sink buffer