From 7f2f8042cf335ab1323dec3edbe9143a06109f4e Mon Sep 17 00:00:00 2001 From: Glenn Kasten Date: Thu, 14 Feb 2013 00:02:36 +0000 Subject: Revert "Temporary additional logging to investigate bug" This reverts commit 0ddd56316262ac74a95e9edb595697c163136d6d Change-Id: I180a928af6f5a38d15a5efe44cd1fe927b5d961c --- services/audioflinger/AudioFlinger.h | 2 +- services/audioflinger/AudioMixer.cpp | 8 ++------ services/audioflinger/AudioMixer.h | 4 +--- services/audioflinger/FastMixer.cpp | 30 ++---------------------------- services/audioflinger/Threads.cpp | 28 ++++++---------------------- services/audioflinger/Threads.h | 2 +- services/audioflinger/Tracks.cpp | 14 ++++---------- 7 files changed, 17 insertions(+), 71 deletions(-) (limited to 'services') diff --git a/services/audioflinger/AudioFlinger.h b/services/audioflinger/AudioFlinger.h index 593f131..c3f08f6 100644 --- a/services/audioflinger/AudioFlinger.h +++ b/services/audioflinger/AudioFlinger.h @@ -227,7 +227,7 @@ public: sp newWriter_l(size_t size, const char *name); void unregisterWriter(const sp& writer); private: - static const size_t kLogMemorySize = 20 * 1024; + static const size_t kLogMemorySize = 10 * 1024; sp mLogMemoryDealer; // == 0 when NBLog is disabled public: diff --git a/services/audioflinger/AudioMixer.cpp b/services/audioflinger/AudioMixer.cpp index 30d645c..08325ad 100644 --- a/services/audioflinger/AudioMixer.cpp +++ b/services/audioflinger/AudioMixer.cpp @@ -209,7 +209,6 @@ int AudioMixer::getTrackName(audio_channel_mask_t channelMask, int sessionId) t->mainBuffer = NULL; t->auxBuffer = NULL; t->downmixerBufferProvider = NULL; - t->fastIndex = -1; status_t status = initTrackDownmix(&mState.tracks[n], n, channelMask); if (status == OK) { @@ -456,9 +455,6 @@ void AudioMixer::setParameter(int name, int target, int param, void *value) // for a specific track? or per mixer? /* case DOWNMIX_TYPE: break */ - case FAST_INDEX: - track.fastIndex = valueInt; - break; default: LOG_FATAL("bad param"); } @@ -1115,8 +1111,8 @@ void AudioMixer::process__genericNoResampling(state_t* state, int64_t pts) t.buffer.frameCount = state->frameCount; int valid = t.bufferProvider->getValid(); if (valid != AudioBufferProvider::kValid) { - ALOGE("invalid bufferProvider=%p name=%d fastIndex=%d frameCount=%d valid=%#x enabledTracks=%#x", - t.bufferProvider, i, t.fastIndex, t.buffer.frameCount, valid, enabledTracks); + ALOGE("invalid bufferProvider=%p name=%d frameCount=%d valid=%#x enabledTracks=%#x", + t.bufferProvider, i, t.buffer.frameCount, valid, enabledTracks); // expect to crash } t.bufferProvider->getNextBuffer(&t.buffer, pts); diff --git a/services/audioflinger/AudioMixer.h b/services/audioflinger/AudioMixer.h index f757351..fd21fda 100644 --- a/services/audioflinger/AudioMixer.h +++ b/services/audioflinger/AudioMixer.h @@ -76,7 +76,6 @@ public: MAIN_BUFFER = 0x4002, AUX_BUFFER = 0x4003, DOWNMIX_TYPE = 0X4004, - FAST_INDEX = 0x4005, // for debugging only // for target RESAMPLE SAMPLE_RATE = 0x4100, // Configure sample rate conversion on this track name; // parameter 'value' is the new sample rate in Hz. @@ -201,8 +200,7 @@ private: int32_t sessionId; - int32_t fastIndex; - int32_t padding[1]; + int32_t padding[2]; // 16-byte boundary diff --git a/services/audioflinger/FastMixer.cpp b/services/audioflinger/FastMixer.cpp index b64c8fb..80e37ca 100644 --- a/services/audioflinger/FastMixer.cpp +++ b/services/audioflinger/FastMixer.cpp @@ -120,7 +120,6 @@ 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 @@ -302,19 +301,12 @@ bool FastMixer::threadLoop() const FastTrack* fastTrack = ¤t->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) 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); @@ -330,31 +322,22 @@ bool FastMixer::threadLoop() 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; 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, @@ -377,9 +360,6 @@ bool FastMixer::threadLoop() generations[i] = fastTrack->mGeneration; } } - if (actuallyModifiedTracks) { - logWriter->logf("act. mod. %#x", actuallyModifiedTracks); - } fastTracksGen = current->mFastTracksGen; @@ -443,12 +423,6 @@ 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; diff --git a/services/audioflinger/Threads.cpp b/services/audioflinger/Threads.cpp index 554532d..ba848d7 100644 --- a/services/audioflinger/Threads.cpp +++ b/services/audioflinger/Threads.cpp @@ -1196,8 +1196,6 @@ sp AudioFlinger::PlaybackThread::createTrac { // scope for mLock Mutex::Autolock _l(mLock); - mNBLogWriter->logf("createTrack_l isFast=%d caller=%d", - (*flags & IAudioFlinger::TRACK_FAST) != 0, IPCThreadState::self()->getCallingPid()); // all tracks in same audio session must share the same routing strategy otherwise // conflicts will happen when tracks are moved from one output to another by audio policy @@ -1251,6 +1249,7 @@ Exit: if (status) { *status = lStatus; } + mNBLogWriter->logf("createTrack_l"); return track; } @@ -1318,8 +1317,7 @@ float AudioFlinger::PlaybackThread::streamVolume(audio_stream_type_t stream) con // addTrack_l() must be called with ThreadBase::mLock held status_t AudioFlinger::PlaybackThread::addTrack_l(const sp& track) { - mNBLogWriter->logf("addTrack_l mName=%d mFastIndex=%d caller=%d", track->mName, - track->mFastIndex, IPCThreadState::self()->getCallingPid()); + mNBLogWriter->logf("addTrack_l mName=%d", track->mName); status_t status = ALREADY_EXISTS; // set retry count for buffer fill @@ -1353,9 +1351,7 @@ status_t AudioFlinger::PlaybackThread::addTrack_l(const sp& track) // destroyTrack_l() must be called with ThreadBase::mLock held void AudioFlinger::PlaybackThread::destroyTrack_l(const sp& track) { - mNBLogWriter->logTimestamp(); - mNBLogWriter->logf("destroyTrack_l mName=%d mFastIndex=%d mClientPid=%d", track->mName, - track->mFastIndex, track->mClient != 0 ? track->mClient->pid() : -1); + mNBLogWriter->logf("destroyTrack_l mName=%d", track->mName); track->mState = TrackBase::TERMINATED; // active tracks are removed by threadLoop() if (mActiveTracks.indexOf(track) < 0) { @@ -1365,9 +1361,7 @@ void AudioFlinger::PlaybackThread::destroyTrack_l(const sp& track) void AudioFlinger::PlaybackThread::removeTrack_l(const sp& track) { - mNBLogWriter->logTimestamp(); - mNBLogWriter->logf("removeTrack_l mName=%d mFastIndex=%d clientPid=%d", track->mName, - track->mFastIndex, track->mClient != 0 ? track->mClient->pid() : -1); + mNBLogWriter->logf("removeTrack_l mName=%d", track->mName); track->triggerEvents(AudioSystem::SYNC_EVENT_PRESENTATION_COMPLETE); mTracks.remove(track); deleteTrackName_l(track->name()); @@ -2845,19 +2839,11 @@ track_is_ready: ; block = FastMixerStateQueue::BLOCK_UNTIL_ACKED; pauseAudioWatchdog = true; } + sq->end(); } if (sq != NULL) { - unsigned trackMask = state->mTrackMask; sq->end(didModify); - if (didModify) { - mNBLogWriter->logTimestamp(); - mNBLogWriter->logf("push trackMask=%#x block=%d", trackMask, block); - } sq->push(block); - if (didModify) { - mNBLogWriter->logTimestamp(); - mNBLogWriter->log("pushed"); - } } #ifdef AUDIO_WATCHDOG if (pauseAudioWatchdog && mAudioWatchdog != 0) { @@ -2884,9 +2870,7 @@ track_is_ready: ; if (CC_UNLIKELY(count)) { for (size_t i=0 ; i& track = tracksToRemove->itemAt(i); - mNBLogWriter->logTimestamp(); - mNBLogWriter->logf("prepareTracks_l remove name=%u mFastIndex=%d", track->name(), - track->mFastIndex); + mNBLogWriter->logf("prepareTracks_l remove name=%u", track->name()); mActiveTracks.remove(track); if (track->mainBuffer() != mMixBuffer) { chain = getEffectChain_l(track->sessionId()); diff --git a/services/audioflinger/Threads.h b/services/audioflinger/Threads.h index 8497788..fa1e336 100644 --- a/services/audioflinger/Threads.h +++ b/services/audioflinger/Threads.h @@ -315,7 +315,7 @@ protected: // keyed by session ID, the second by type UUID timeLow field KeyedVector< int, KeyedVector< int, sp > > mSuspendedSessions; - static const size_t kLogSize = 4096; + static const size_t kLogSize = 512; sp mNBLogWriter; }; diff --git a/services/audioflinger/Tracks.cpp b/services/audioflinger/Tracks.cpp index f679751..315cbbc 100644 --- a/services/audioflinger/Tracks.cpp +++ b/services/audioflinger/Tracks.cpp @@ -351,7 +351,6 @@ AudioFlinger::PlaybackThread::Track::Track( // Read the initial underruns because this field is never cleared by the fast mixer mObservedUnderruns = thread->getFastTrackUnderruns(i); thread->mFastTrackAvailMask &= ~(1 << i); - thread->mNBLogWriter->logf("new Track mName=%d mFastIndex=%d", mName, mFastIndex); } } ALOGV("Track constructor name %d, calling pid %d", mName, @@ -361,7 +360,6 @@ AudioFlinger::PlaybackThread::Track::Track( AudioFlinger::PlaybackThread::Track::~Track() { ALOGV("PlaybackThread::Track destructor"); - // FIXME not sure if safe to log here, would need a lock on thread to do it } void AudioFlinger::PlaybackThread::Track::destroy() @@ -571,8 +569,7 @@ status_t AudioFlinger::PlaybackThread::Track::start(AudioSystem::sync_event_t ev sp thread = mThread.promote(); if (thread != 0) { Mutex::Autolock _l(thread->mLock); - thread->mNBLogWriter->logf("start mName=%d mFastIndex=%d caller=%d", mName, mFastIndex, - IPCThreadState::self()->getCallingPid()); + thread->mNBLogWriter->logf("start mName=%d", mName); track_state state = mState; // here the track could be either new, or restarted // in both cases "unstop" the track @@ -615,8 +612,7 @@ void AudioFlinger::PlaybackThread::Track::stop() sp thread = mThread.promote(); if (thread != 0) { Mutex::Autolock _l(thread->mLock); - thread->mNBLogWriter->logf("stop mName=%d mFastIndex=%d caller=%d", mName, mFastIndex, - IPCThreadState::self()->getCallingPid()); + thread->mNBLogWriter->logf("stop mName=%d", mName); track_state state = mState; if (state == RESUMING || state == ACTIVE || state == PAUSING || state == PAUSED) { // If the track is not active (PAUSED and buffers full), flush buffers @@ -653,8 +649,7 @@ void AudioFlinger::PlaybackThread::Track::pause() sp thread = mThread.promote(); if (thread != 0) { Mutex::Autolock _l(thread->mLock); - thread->mNBLogWriter->logf("pause mName=%d mFastIndex=%d caller=%d", mName, mFastIndex, - IPCThreadState::self()->getCallingPid()); + thread->mNBLogWriter->logf("pause mName=%d", mName); if (mState == ACTIVE || mState == RESUMING) { mState = PAUSING; ALOGV("ACTIVE/RESUMING => PAUSING (%d) on thread %p", mName, thread.get()); @@ -678,8 +673,7 @@ void AudioFlinger::PlaybackThread::Track::flush() sp thread = mThread.promote(); if (thread != 0) { Mutex::Autolock _l(thread->mLock); - thread->mNBLogWriter->logf("flush mName=%d mFastIndex=%d caller=%d", mName, mFastIndex, - IPCThreadState::self()->getCallingPid()); + thread->mNBLogWriter->logf("flush mName=%d", mName); if (mState != STOPPING_1 && mState != STOPPING_2 && mState != STOPPED && mState != PAUSED && mState != PAUSING && mState != IDLE && mState != FLUSHED) { return; -- cgit v1.1