Revert "Temporary additional logging to investigate bug"

This reverts commit 32584a7d672864b20ab8b83a3cb23c1858e908b7

Change-Id: I9dc680578b955b1af462eeb7a49d61a0d45eb81b

1 files changed, 4 insertions, 89 deletions

diff --git a/services/audioflinger/FastMixer.cpp b/services/audioflinger/FastMixer.cpp
index 75c3c41..80e37ca 100644
--- a/services/audioflinger/FastMixer.cpp
+++ b/services/audioflinger/FastMixer.cpp
@@ -21,15 +21,13 @@
 // </IMPORTANT_WARNING>
 
 #define LOG_TAG "FastMixer"
-#define LOG_NDEBUG 0
+//#define LOG_NDEBUG 0
 
 #define ATRACE_TAG ATRACE_TAG_AUDIO
 
 #include <sys/atomics.h>
 #include <time.h>
 #include <utils/Log.h>
-#undef ALOGV
-#define ALOGV(a...) do { } while (0)
 #include <utils/Trace.h>
 #include <system/audio.h>
 #ifdef FAST_MIXER_STATISTICS
@@ -95,8 +93,6 @@ bool FastMixer::threadLoop()
     uint32_t warmupCycles = 0;  // counter of number of loop cycles required to warmup
     NBAIO_Sink* teeSink = NULL; // if non-NULL, then duplicate write() to this non-blocking sink
     NBLog::Writer dummyLogWriter, *logWriter = &dummyLogWriter;
-    bool myEnabled[FastMixerState::kMaxFastTracks];
-    memset(myEnabled, 0, sizeof(myEnabled));
 
     for (;;) {
 
@@ -124,16 +120,12 @@ bool FastMixer::threadLoop()
         FastMixerState::Command command = next->mCommand;
         if (next != current) {
 
-            logWriter->logTimestamp();
             logWriter->log("next != current");
 
             // As soon as possible of learning of a new dump area, start using it
             dumpState = next->mDumpState != NULL ? next->mDumpState : &dummyDumpState;
             teeSink = next->mTeeSink;
             logWriter = next->mNBLogWriter != NULL ? next->mNBLogWriter : &dummyLogWriter;
-            if (mixer != NULL) {
-                mixer->setLog(logWriter);
-            }
 
             // We want to always have a valid reference to the previous (non-idle) state.
             // However, the state queue only guarantees access to current and previous states.
@@ -308,21 +300,13 @@ bool FastMixer::threadLoop()
                     addedTracks &= ~(1 << i);
                     const FastTrack* fastTrack = &current->mFastTracks[i];
                     AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
-                    logWriter->logf("bp %d i=%d %p", __LINE__, i, bufferProvider);
                     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)
                         name = mixer->getTrackName(AUDIO_CHANNEL_OUT_STEREO, -555);
                         ALOG_ASSERT(name >= 0);
                         fastTrackNames[i] = name;
-                        mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::FAST_INDEX,
-                                (void *) i);
                         mixer->setBufferProvider(name, bufferProvider);
                         mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::MAIN_BUFFER,
                                 (void *) mixBuffer);
@@ -333,41 +317,27 @@ bool FastMixer::threadLoop()
                         }
                         mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::CHANNEL_MASK,
                                 (void *) fastTrack->mChannelMask);
-                        if (!mixer->enabled(name)) {
-                            logWriter->logf("enable %d i=%d name=%d", __LINE__, i, name);
-                        }
                         mixer->enable(name);
-                        myEnabled[i] = true;
                     }
                     generations[i] = fastTrack->mGeneration;
                 }
 
-                // finally process (potentially) modified tracks; these use the same slot
+                // finally process modified tracks; these use the same slot
                 // but may have a different buffer provider or volume provider
                 unsigned modifiedTracks = currentTrackMask & previousTrackMask;
                 if (modifiedTracks) {
-                    logWriter->logf("pot. mod. %#x", modifiedTracks);
+                    logWriter->logf("modified %#x", modifiedTracks);
                 }
-                unsigned actuallyModifiedTracks = 0;
                 while (modifiedTracks != 0) {
                     i = __builtin_ctz(modifiedTracks);
                     modifiedTracks &= ~(1 << i);
                     const FastTrack* fastTrack = &current->mFastTracks[i];
                     if (fastTrack->mGeneration != generations[i]) {
-                        actuallyModifiedTracks |= 1 << i;
                         AudioBufferProvider *bufferProvider = fastTrack->mBufferProvider;
-                        logWriter->logf("bp %d i=%d %p", __LINE__, i, bufferProvider);
                         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);
-                            mixer->setParameter(name, AudioMixer::TRACK, AudioMixer::FAST_INDEX,
-                                    (void *) i);
                             mixer->setBufferProvider(name, bufferProvider);
                             if (fastTrack->mVolumeProvider == NULL) {
                                 mixer->setParameter(name, AudioMixer::VOLUME, AudioMixer::VOLUME0,
@@ -390,9 +360,6 @@ bool FastMixer::threadLoop()
                         generations[i] = fastTrack->mGeneration;
                     }
                 }
-                if (actuallyModifiedTracks) {
-                    logWriter->logf("act. mod. %#x", actuallyModifiedTracks);
-                }
 
                 fastTracksGen = current->mFastTracksGen;
 
@@ -410,7 +377,6 @@ bool FastMixer::threadLoop()
             ALOG_ASSERT(mixBuffer != NULL);
             // for each track, update volume and check for underrun
             unsigned currentTrackMask = current->mTrackMask;
-            logWriter->logf("ctm %#x", currentTrackMask);
             while (currentTrackMask != 0) {
                 i = __builtin_ctz(currentTrackMask);
                 currentTrackMask &= ~(1 << i);
@@ -444,76 +410,25 @@ bool FastMixer::threadLoop()
                         underruns.mBitFields.mEmpty++;
                         underruns.mBitFields.mMostRecent = UNDERRUN_EMPTY;
                         mixer->disable(name);
-                        myEnabled[i] = false;
                     } else {
                         // allow mixing partial buffer
                         underruns.mBitFields.mPartial++;
                         underruns.mBitFields.mMostRecent = UNDERRUN_PARTIAL;
-                        if (!mixer->enabled(name)) {
-                            logWriter->logf("enable %d i=%d name=%d", __LINE__, i, name);
-                        }
                         mixer->enable(name);
-                        myEnabled[i] = true;
                     }
                 } else {
                     underruns.mBitFields.mFull++;
                     underruns.mBitFields.mMostRecent = UNDERRUN_FULL;
-                    if (!mixer->enabled(name)) {
-                        logWriter->logf("enable %d i=%d name=%d", __LINE__, i, name);
-                    }
                     mixer->enable(name);
-                    myEnabled[i] = true;
                 }
                 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;
             if (outputSink == NULL || (OK != outputSink->getNextWriteTimestamp(&pts)))
                 pts = AudioBufferProvider::kInvalidPTS;
 
-            // validate that mixer state is correct
-            currentTrackMask = current->mTrackMask;
-            unsigned expectedMixerEnabled = 0;
-            while (currentTrackMask != 0) {
-                i = __builtin_ctz(currentTrackMask);
-                currentTrackMask &= ~(1 << i);
-                const FastTrack* fastTrack = &current->mFastTracks[i];
-                int name = fastTrackNames[i];
-                ALOG_ASSERT(name >= 0);
-                bool isEnabled = mixer->enabled(name);
-                if (isEnabled != myEnabled[i]) {
-                    logWriter->logTimestamp();
-                    logWriter->logf("? i=%d name=%d mixena=%d ftena=%d", i, name, isEnabled,
-                            myEnabled[i]);
-                }
-                if (myEnabled[i]) {
-                    expectedMixerEnabled |= 1 << name;
-                }
-                AudioBufferProvider *abp = mixer->getBufferProvider(name);
-                if (abp != fastTrack->mBufferProvider) {
-                    logWriter->logTimestamp();
-                    logWriter->logf("? i=%d name=%d mixbp=%p ftbp=%p", i, name, abp,
-                            fastTrack->mBufferProvider);
-                }
-                int fastIndex = mixer->getFastIndex(name);
-                if (fastIndex != (int) i) {
-                    logWriter->logTimestamp();
-                    logWriter->logf("? i=%d name=%d fastIndex=%d", i, name, fastIndex);
-                }
-            }
-            unsigned mixerEnabled = mixer->enabledTrackNames();
-            if (mixerEnabled != expectedMixerEnabled) {
-                logWriter->logTimestamp();
-                logWriter->logf("? mixena=%#x expected=%#x", mixerEnabled, expectedMixerEnabled);
-            }
-
             // process() is CPU-bound
             mixer->process(pts);
             mixBufferState = MIXED;
@@ -538,7 +453,7 @@ bool FastMixer::threadLoop()
             ATRACE_END();
             dumpState->mWriteSequence++;
             if (framesWritten >= 0) {
-                ALOG_ASSERT((size_t) framesWritten <= frameCount);
+                ALOG_ASSERT(framesWritten <= frameCount);
                 dumpState->mFramesWritten += framesWritten;
                 //if ((size_t) framesWritten == frameCount) {
                 //    didFullWrite = true;