State queue dump

Bug: 6591648
Change-Id: Iac75e5ea64e86640b3d890c46a636641b9733c6d

5 files changed, 121 insertions, 0 deletions

diff --git a/services/audioflinger/Android.mk b/services/audioflinger/Android.mk
index 4f59a8a..14b7fc1 100644
--- a/services/audioflinger/Android.mk
+++ b/services/audioflinger/Android.mk
@@ -47,6 +47,9 @@ LOCAL_SRC_FILES:=               \
 
 LOCAL_SRC_FILES += StateQueue.cpp
 
+# uncomment for debugging timing problems related to StateQueue::push()
+LOCAL_CFLAGS += -DSTATE_QUEUE_DUMP
+
 LOCAL_C_INCLUDES := \
     $(call include-path-for, audio-effects) \
     $(call include-path-for, audio-utils)
diff --git a/services/audioflinger/AudioFlinger.cpp b/services/audioflinger/AudioFlinger.cpp
index a61b8ea..bf40886 100644
--- a/services/audioflinger/AudioFlinger.cpp
+++ b/services/audioflinger/AudioFlinger.cpp
@@ -2255,6 +2255,10 @@ AudioFlinger::MixerThread::MixerThread(const sp<AudioFlinger>& audioFlinger, Aud
         // create fast mixer and configure it initially with just one fast track for our submix
         mFastMixer = new FastMixer();
         FastMixerStateQueue *sq = mFastMixer->sq();
+#ifdef STATE_QUEUE_DUMP
+        sq->setObserverDump(&mStateQueueObserverDump);
+        sq->setMutatorDump(&mStateQueueMutatorDump);
+#endif
         FastMixerState *state = sq->begin();
         FastTrack *fastTrack = &state->mFastTracks[0];
         // wrap the source side of the MonoPipe to make it an AudioBufferProvider
@@ -3480,6 +3484,14 @@ status_t AudioFlinger::MixerThread::dumpInternals(int fd, const Vector<String16>
     FastMixerDumpState copy = mFastMixerDumpState;
     copy.dump(fd);
 
+#ifdef STATE_QUEUE_DUMP
+    // Similar for state queue
+    StateQueueObserverDump observerCopy = mStateQueueObserverDump;
+    observerCopy.dump(fd);
+    StateQueueMutatorDump mutatorCopy = mStateQueueMutatorDump;
+    mutatorCopy.dump(fd);
+#endif
+
     // Write the tee output to a .wav file
     NBAIO_Source *teeSource = mTeeSource.get();
     if (teeSource != NULL) {
diff --git a/services/audioflinger/AudioFlinger.h b/services/audioflinger/AudioFlinger.h
index 160e4cd..6da5802 100644
--- a/services/audioflinger/AudioFlinger.h
+++ b/services/audioflinger/AudioFlinger.h
@@ -1169,6 +1169,10 @@ public:
 
                     // contents are not guaranteed to be consistent, no locks required
                     FastMixerDumpState mFastMixerDumpState;
+#ifdef STATE_QUEUE_DUMP
+                    StateQueueObserverDump mStateQueueObserverDump;
+                    StateQueueMutatorDump  mStateQueueMutatorDump;
+#endif
 
                     // accessible only within the threadLoop(), no locks required
                     //          mFastMixer->sq()    // for mutating and pushing state
diff --git a/services/audioflinger/StateQueue.cpp b/services/audioflinger/StateQueue.cpp
index ae263f5..3e891a5 100644
--- a/services/audioflinger/StateQueue.cpp
+++ b/services/audioflinger/StateQueue.cpp
@@ -24,12 +24,28 @@
 
 namespace android {
 
+#ifdef STATE_QUEUE_DUMP
+void StateQueueObserverDump::dump(int fd)
+{
+    fdprintf(fd, "State queue observer: stateChanges=%u\n", mStateChanges);
+}
+
+void StateQueueMutatorDump::dump(int fd)
+{
+    fdprintf(fd, "State queue mutator: pushDirty=%u pushAck=%u blockedSequence=%u\n",
+            mPushDirty, mPushAck, mBlockedSequence);
+}
+#endif
+
 // Constructor and destructor
 
 template<typename T> StateQueue<T>::StateQueue() :
     mNext(NULL), mAck(NULL), mCurrent(NULL),
     mMutating(&mStates[0]), mExpecting(NULL),
     mInMutation(false), mIsDirty(false), mIsInitialized(false)
+#ifdef STATE_QUEUE_DUMP
+    , mObserverDump(&mObserverDummyDump), mMutatorDump(&mMutatorDummyDump)
+#endif
 {
 }
 
@@ -45,6 +61,9 @@ template<typename T> const T* StateQueue<T>::poll()
     if (next != mCurrent) {
         mAck = next;    // no additional barrier needed
         mCurrent = next;
+#ifdef STATE_QUEUE_DUMP
+        mObserverDump->mStateChanges++;
+#endif
     }
     return next;
 }
@@ -77,10 +96,23 @@ template<typename T> bool StateQueue<T>::push(StateQueue<T>::block_t block)
 
     ALOG_ASSERT(!mInMutation, "push() called when in a mutation");
 
+#ifdef STATE_QUEUE_DUMP
+    if (block == BLOCK_UNTIL_ACKED) {
+        mMutatorDump->mPushAck++;
+    }
+#endif
+
     if (mIsDirty) {
 
+#ifdef STATE_QUEUE_DUMP
+        mMutatorDump->mPushDirty++;
+#endif
+
         // wait for prior push to be acknowledged
         if (mExpecting != NULL) {
+#ifdef STATE_QUEUE_DUMP
+            unsigned count = 0;
+#endif
             for (;;) {
                 const T *ack = (const T *) mAck;    // no additional barrier needed
                 if (ack == mExpecting) {
@@ -91,8 +123,19 @@ template<typename T> bool StateQueue<T>::push(StateQueue<T>::block_t block)
                 if (block == BLOCK_NEVER) {
                     return false;
                 }
+#ifdef STATE_QUEUE_DUMP
+                if (count == 1) {
+                    mMutatorDump->mBlockedSequence++;
+                }
+                ++count;
+#endif
                 nanosleep(&req, NULL);
             }
+#ifdef STATE_QUEUE_DUMP
+            if (count > 1) {
+                mMutatorDump->mBlockedSequence++;
+            }
+#endif
         }
 
         // publish
@@ -111,14 +154,28 @@ template<typename T> bool StateQueue<T>::push(StateQueue<T>::block_t block)
     // optionally wait for this push or a prior push to be acknowledged
     if (block == BLOCK_UNTIL_ACKED) {
         if (mExpecting != NULL) {
+#ifdef STATE_QUEUE_DUMP
+            unsigned count = 0;
+#endif
             for (;;) {
                 const T *ack = (const T *) mAck;    // no additional barrier needed
                 if (ack == mExpecting) {
                     mExpecting = NULL;
                     break;
                 }
+#ifdef STATE_QUEUE_DUMP
+                if (count == 1) {
+                    mMutatorDump->mBlockedSequence++;
+                }
+                ++count;
+#endif
                 nanosleep(&req, NULL);
             }
+#ifdef STATE_QUEUE_DUMP
+            if (count > 1) {
+                mMutatorDump->mBlockedSequence++;
+            }
+#endif
         }
     }
 
diff --git a/services/audioflinger/StateQueue.h b/services/audioflinger/StateQueue.h
index fe72ddc..eba190c 100644
--- a/services/audioflinger/StateQueue.h
+++ b/services/audioflinger/StateQueue.h
@@ -19,6 +19,34 @@
 
 namespace android {
 
+#ifdef STATE_QUEUE_DUMP
+// The StateQueueObserverDump and StateQueueMutatorDump keep
+// a cache of StateQueue statistics that can be logged by dumpsys.
+// Each individual native word-sized field is accessed atomically.  But the
+// overall structure is non-atomic, that is there may be an inconsistency between fields.
+// No barriers or locks are used for either writing or reading.
+// Only POD types are permitted, and the contents shouldn't be trusted (i.e. do range checks).
+// It has a different lifetime than the StateQueue, and so it can't be a member of StateQueue.
+
+struct StateQueueObserverDump {
+    StateQueueObserverDump() : mStateChanges(0) { }
+    /*virtual*/ ~StateQueueObserverDump() { }
+    unsigned    mStateChanges;    // incremented each time poll() detects a state change
+    void        dump(int fd);
+};
+
+struct StateQueueMutatorDump {
+    StateQueueMutatorDump() : mPushDirty(0), mPushAck(0), mBlockedSequence(0) { }
+    /*virtual*/ ~StateQueueMutatorDump() { }
+    unsigned    mPushDirty;       // incremented each time push() is called with a dirty state
+    unsigned    mPushAck;         // incremented each time push(BLOCK_UNTIL_ACKED) is called
+    unsigned    mBlockedSequence; // incremented before and after each time that push()
+                                  // blocks for more than one PUSH_BLOCK_ACK_NS;
+                                  // if odd, then mutator is currently blocked inside push()
+    void        dump(int fd);
+};
+#endif
+
 // manages a FIFO queue of states
 template<typename T> class StateQueue {
 
@@ -69,6 +97,16 @@ public:
     // Return whether the current state is dirty (modified and not pushed).
     bool    isDirty() const { return mIsDirty; }
 
+#ifdef STATE_QUEUE_DUMP
+    // Register location of observer dump area
+    void    setObserverDump(StateQueueObserverDump *dump)
+            { mObserverDump = dump != NULL ? dump : &mObserverDummyDump; }
+
+    // Register location of mutator dump area
+    void    setMutatorDump(StateQueueMutatorDump *dump)
+            { mMutatorDump = dump != NULL ? dump : &mMutatorDummyDump; }
+#endif
+
 private:
     static const unsigned kN = 4;       // values != 4 are not supported by this code
     T                 mStates[kN];      // written by mutator, read by observer
@@ -87,6 +125,13 @@ private:
     bool              mIsDirty;         // whether mutating state has been modified since last push
     bool              mIsInitialized;   // whether mutating state has been initialized yet
 
+#ifdef STATE_QUEUE_DUMP
+    StateQueueObserverDump  mObserverDummyDump; // default area for observer dump if not set
+    StateQueueObserverDump* mObserverDump;      // pointer to active observer dump, always non-NULL
+    StateQueueMutatorDump   mMutatorDummyDump;  // default area for mutator dump if not set
+    StateQueueMutatorDump*  mMutatorDump;       // pointer to active mutator dump, always non-NULL
+#endif
+
 };  // class StateQueue
 
 }   // namespace android