More log for issue 2242381.

Added more log in system dump for AudioFlinger and AudioPolicyService to help debug issue 2242381 and other issues where the audio driver hangs.

1 files changed, 104 insertions, 14 deletions

diff --git a/libs/audioflinger/AudioFlinger.cpp b/libs/audioflinger/AudioFlinger.cpp
index 9c0c850..230e833 100644
--- a/libs/audioflinger/AudioFlinger.cpp
+++ b/libs/audioflinger/AudioFlinger.cpp
@@ -815,6 +815,58 @@ void AudioFlinger::ThreadBase::processConfigEvents()
     mLock.unlock();
 }
 
+status_t AudioFlinger::ThreadBase::dumpBase(int fd, const Vector<String16>& args)
+{
+    const size_t SIZE = 256;
+    char buffer[SIZE];
+    String8 result;
+
+    bool locked = tryLock(mLock);
+    if (!locked) {
+        snprintf(buffer, SIZE, "thread %p maybe dead locked\n", this);
+        write(fd, buffer, strlen(buffer));
+    }
+
+    snprintf(buffer, SIZE, "standby: %d\n", mStandby);
+    result.append(buffer);
+    snprintf(buffer, SIZE, "Sample rate: %d\n", mSampleRate);
+    result.append(buffer);
+    snprintf(buffer, SIZE, "Frame count: %d\n", mFrameCount);
+    result.append(buffer);
+    snprintf(buffer, SIZE, "Channel Count: %d\n", mChannelCount);
+    result.append(buffer);
+    snprintf(buffer, SIZE, "Format: %d\n", mFormat);
+    result.append(buffer);
+    snprintf(buffer, SIZE, "Frame size: %d\n", mFrameSize);
+    result.append(buffer);
+
+    snprintf(buffer, SIZE, "\nPending setParameters commands: \n");
+    result.append(buffer);
+    result.append(" Index Command");
+    for (size_t i = 0; i < mNewParameters.size(); ++i) {
+        snprintf(buffer, SIZE, "\n %02d    ", i);
+        result.append(buffer);
+        result.append(mNewParameters[i]);
+    }
+
+    snprintf(buffer, SIZE, "\n\nPending config events: \n");
+    result.append(buffer);
+    snprintf(buffer, SIZE, " Index event param\n");
+    result.append(buffer);
+    for (size_t i = 0; i < mConfigEvents.size(); i++) {
+        snprintf(buffer, SIZE, " %02d    %02d    %d\n", i, mConfigEvents[i]->mEvent, mConfigEvents[i]->mParam);
+        result.append(buffer);
+    }
+    result.append("\n");
+
+    write(fd, result.string(), result.size());
+
+    if (locked) {
+        mLock.unlock();
+    }
+    return NO_ERROR;
+}
+
 
 // ----------------------------------------------------------------------------
 
@@ -856,7 +908,7 @@ status_t AudioFlinger::PlaybackThread::dumpTracks(int fd, const Vector<String16>
 
     snprintf(buffer, SIZE, "Output thread %p tracks\n", this);
     result.append(buffer);
-    result.append("   Name Clien Typ Fmt Chn Buf S M F SRate LeftV RighV Serv User\n");
+    result.append("   Name Clien Typ Fmt Chn Buf  S M F SRate  LeftV RighV Serv     User\n");
     for (size_t i = 0; i < mTracks.size(); ++i) {
         sp<Track> track = mTracks[i];
         if (track != 0) {
@@ -867,7 +919,7 @@ status_t AudioFlinger::PlaybackThread::dumpTracks(int fd, const Vector<String16>
 
     snprintf(buffer, SIZE, "Output thread %p active tracks\n", this);
     result.append(buffer);
-    result.append("   Name Clien Typ Fmt Chn Buf S M F SRate LeftV RighV Serv User\n");
+    result.append("   Name Clien Typ Fmt Chn Buf  S M F SRate  LeftV RighV Serv     User\n");
     for (size_t i = 0; i < mActiveTracks.size(); ++i) {
         wp<Track> wTrack = mActiveTracks[i];
         if (wTrack != 0) {
@@ -888,7 +940,7 @@ status_t AudioFlinger::PlaybackThread::dumpInternals(int fd, const Vector<String
     char buffer[SIZE];
     String8 result;
 
-    snprintf(buffer, SIZE, "Output thread %p internals\n", this);
+    snprintf(buffer, SIZE, "\nOutput thread %p internals\n", this);
     result.append(buffer);
     snprintf(buffer, SIZE, "last write occurred (msecs): %llu\n", ns2ms(systemTime() - mLastWriteTime));
     result.append(buffer);
@@ -898,9 +950,10 @@ status_t AudioFlinger::PlaybackThread::dumpInternals(int fd, const Vector<String
     result.append(buffer);
     snprintf(buffer, SIZE, "blocked in write: %d\n", mInWrite);
     result.append(buffer);
-    snprintf(buffer, SIZE, "standby: %d\n", mStandby);
-    result.append(buffer);
     write(fd, result.string(), result.size());
+
+    dumpBase(fd, args);
+
     return NO_ERROR;
 }
 
@@ -1493,8 +1546,6 @@ bool AudioFlinger::MixerThread::checkForNewParameters_l()
         AudioParameter param = AudioParameter(keyValuePair);
         int value;
 
-        mNewParameters.removeAt(0);
-
         if (param.getInt(String8(AudioParameter::keySamplingRate), value) == NO_ERROR) {
             reconfig = true;
         }
@@ -1546,6 +1597,9 @@ bool AudioFlinger::MixerThread::checkForNewParameters_l()
                 sendConfigEvent_l(AudioSystem::OUTPUT_CONFIG_CHANGED);
             }
         }
+
+        mNewParameters.removeAt(0);
+
         mParamStatus = status;
         mParamCond.signal();
         mWaitWorkCV.wait(mLock);
@@ -1818,8 +1872,6 @@ bool AudioFlinger::DirectOutputThread::checkForNewParameters_l()
         AudioParameter param = AudioParameter(keyValuePair);
         int value;
 
-        mNewParameters.removeAt(0);
-
         if (param.getInt(String8(AudioParameter::keyFrameCount), value) == NO_ERROR) {
             // do not accept frame count changes if tracks are open as the track buffer
             // size depends on frame count and correct behavior would not be garantied
@@ -1843,6 +1895,9 @@ bool AudioFlinger::DirectOutputThread::checkForNewParameters_l()
                 sendConfigEvent_l(AudioSystem::OUTPUT_CONFIG_CHANGED);
             }
         }
+
+        mNewParameters.removeAt(0);
+
         mParamStatus = status;
         mParamCond.signal();
         mWaitWorkCV.wait(mLock);
@@ -2253,7 +2308,7 @@ void AudioFlinger::PlaybackThread::Track::destroy()
 
 void AudioFlinger::PlaybackThread::Track::dump(char* buffer, size_t size)
 {
-    snprintf(buffer, size, "  %5d %5d %3u %3u %3u %3u %1d %1d %1d %5u %5u %5u %04x %04x\n",
+    snprintf(buffer, size, "  %5d %5d %3u %3u %3u %04u %1d %1d %1d %5u %5u %5u  %08x %08x\n",
             mName - AudioMixer::TRACK0,
             (mClient == NULL) ? getpid() : mClient->pid(),
             mStreamType,
@@ -2509,6 +2564,19 @@ void AudioFlinger::RecordThread::RecordTrack::stop()
     }
 }
 
+void AudioFlinger::RecordThread::RecordTrack::dump(char* buffer, size_t size)
+{
+    snprintf(buffer, size, "   %05d %03u %03u %04u %01d %05u  %08x %08x\n",
+            (mClient == NULL) ? getpid() : mClient->pid(),
+            mFormat,
+            mCblk->channels,
+            mFrameCount,
+            mState,
+            mCblk->sampleRate,
+            mCblk->server,
+            mCblk->user);
+}
+
 
 // ----------------------------------------------------------------------------
 
@@ -3136,13 +3204,34 @@ status_t AudioFlinger::RecordThread::dump(int fd, const Vector<String16>& args)
     String8 result;
     pid_t pid = 0;
 
-    if (mActiveTrack != 0 && mActiveTrack->mClient != 0) {
-        snprintf(buffer, SIZE, "Record client pid: %d\n", mActiveTrack->mClient->pid());
+    snprintf(buffer, SIZE, "\nInput thread %p internals\n", this);
+    result.append(buffer);
+
+    if (mActiveTrack != 0) {
+        result.append("Active Track:\n");
+        result.append("   Clien Fmt Chn Buf  S SRate  Serv     User\n");
+        mActiveTrack->dump(buffer, SIZE);
+        result.append(buffer);
+
+        snprintf(buffer, SIZE, "In index: %d\n", mRsmpInIndex);
+        result.append(buffer);
+        snprintf(buffer, SIZE, "In size: %d\n", mInputBytes);
+        result.append(buffer);
+        snprintf(buffer, SIZE, "Resampling: %d\n", (mResampler != 0));
+        result.append(buffer);
+        snprintf(buffer, SIZE, "Out channel count: %d\n", mReqChannelCount);
+        result.append(buffer);
+        snprintf(buffer, SIZE, "Out sample rate: %d\n", mReqSampleRate);
         result.append(buffer);
+
+
     } else {
         result.append("No record client\n");
     }
     write(fd, result.string(), result.size());
+
+    dumpBase(fd, args);
+
     return NO_ERROR;
 }
 
@@ -3198,8 +3287,6 @@ bool AudioFlinger::RecordThread::checkForNewParameters_l()
         int reqSamplingRate = mReqSampleRate;
         int reqChannelCount = mReqChannelCount;
 
-        mNewParameters.removeAt(0);
-
         if (param.getInt(String8(AudioParameter::keySamplingRate), value) == NO_ERROR) {
             reqSamplingRate = value;
             reconfig = true;
@@ -3241,6 +3328,9 @@ bool AudioFlinger::RecordThread::checkForNewParameters_l()
                 }
             }
         }
+
+        mNewParameters.removeAt(0);
+
         mParamStatus = status;
         mParamCond.signal();
         mWaitWorkCV.wait(mLock);