Revert "Temporary additional logging to investigate bug"
This reverts commit 32584a7d672864b20ab8b83a3cb23c1858e908b7
Change-Id: I9dc680578b955b1af462eeb7a49d61a0d45eb81b
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 @@
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 @@
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 @@
addedTracks &= ~(1 << i);
const FastTrack* fastTrack = ¤t->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 @@
}
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 = ¤t->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 @@
generations[i] = fastTrack->mGeneration;
}
}
- if (actuallyModifiedTracks) {
- logWriter->logf("act. mod. %#x", actuallyModifiedTracks);
- }
fastTracksGen = current->mFastTracksGen;
@@ -410,7 +377,6 @@
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 @@
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 = ¤t->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 @@
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;