Temporary additional logging to investigate bug

The bug appears related to continuing to use an invalid buffer provider
in fast mixer after track destruction, so focus the added logs in that area.

Also includes a bug fix: was calling log in an unsafe place
near Threads.cpp AudioFlinger::PlaybackThread::createTrack_l line 1250.

Details:
 - include caller pid or client pid where appropriate
 - increase log buffer size

Bug: 6490974
Change-Id: I4c030f171343fe4b483eae0ddea4427118d8d4b1

1 files changed, 16 insertions, 0 deletions

diff --git a/services/audioflinger/FastMixer.cpp b/services/audioflinger/FastMixer.cpp
index 80e37ca..467da39 100644
--- a/services/audioflinger/FastMixer.cpp
+++ b/services/audioflinger/FastMixer.cpp
@@ -301,6 +301,11 @@ bool FastMixer::threadLoop()
                     const FastTrack* fastTrack = &current->mFastTracks[i];
                     AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
                     ALOG_ASSERT(bufferProvider != NULL && fastTrackNames[i] == -1);
+                    if (bufferProvider == NULL ||
+                            bufferProvider->getValid() != AudioBufferProvider::kValid) {
+                        logWriter->logTimestamp();
+                        logWriter->logf("added invalid %#x", i);
+                    }
                     if (mixer != NULL) {
                         // calling getTrackName with default channel mask and a random invalid
                         //   sessionId (no effects here)
@@ -335,6 +340,11 @@ bool FastMixer::threadLoop()
                     if (fastTrack->mGeneration != generations[i]) {
                         AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
                         ALOG_ASSERT(bufferProvider != NULL);
+                        if (bufferProvider == NULL ||
+                                bufferProvider->getValid() != AudioBufferProvider::kValid) {
+                            logWriter->logTimestamp();
+                            logWriter->logf("modified invalid %#x", i);
+                        }
                         if (mixer != NULL) {
                             name = fastTrackNames[i];
                             ALOG_ASSERT(name >= 0);
@@ -423,6 +433,12 @@ bool FastMixer::threadLoop()
                 }
                 ftDump->mUnderruns = underruns;
                 ftDump->mFramesReady = framesReady;
+                AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
+                if (bufferProvider == NULL ||
+                        bufferProvider->getValid() != AudioBufferProvider::kValid) {
+                    logWriter->logTimestamp();
+                    logWriter->logf("mixing invalid %#x", i);
+                }
             }
 
             int64_t pts;