diff options
-rw-r--r-- | services/audioflinger/AudioFlinger.h | 2 | ||||
-rw-r--r-- | services/audioflinger/FastMixer.cpp | 16 | ||||
-rw-r--r-- | services/audioflinger/Threads.cpp | 18 | ||||
-rw-r--r-- | services/audioflinger/Threads.h | 2 | ||||
-rw-r--r-- | services/audioflinger/Tracks.cpp | 14 |
5 files changed, 41 insertions, 11 deletions
diff --git a/services/audioflinger/AudioFlinger.h b/services/audioflinger/AudioFlinger.h index c3f08f6..593f131 100644 --- a/services/audioflinger/AudioFlinger.h +++ b/services/audioflinger/AudioFlinger.h @@ -227,7 +227,7 @@ public: sp<NBLog::Writer> newWriter_l(size_t size, const char *name); void unregisterWriter(const sp<NBLog::Writer>& writer); private: - static const size_t kLogMemorySize = 10 * 1024; + static const size_t kLogMemorySize = 20 * 1024; sp<MemoryDealer> mLogMemoryDealer; // == 0 when NBLog is disabled public: 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 = ¤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) @@ -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; diff --git a/services/audioflinger/Threads.cpp b/services/audioflinger/Threads.cpp index ba848d7..8cc5f6c 100644 --- a/services/audioflinger/Threads.cpp +++ b/services/audioflinger/Threads.cpp @@ -1196,6 +1196,8 @@ sp<AudioFlinger::PlaybackThread::Track> 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 @@ -1249,7 +1251,6 @@ Exit: if (status) { *status = lStatus; } - mNBLogWriter->logf("createTrack_l"); return track; } @@ -1317,7 +1318,8 @@ 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>& track) { - mNBLogWriter->logf("addTrack_l mName=%d", track->mName); + mNBLogWriter->logf("addTrack_l mName=%d mFastIndex=%d caller=%d", track->mName, + track->mFastIndex, IPCThreadState::self()->getCallingPid()); status_t status = ALREADY_EXISTS; // set retry count for buffer fill @@ -1351,7 +1353,9 @@ status_t AudioFlinger::PlaybackThread::addTrack_l(const sp<Track>& track) // destroyTrack_l() must be called with ThreadBase::mLock held void AudioFlinger::PlaybackThread::destroyTrack_l(const sp<Track>& track) { - mNBLogWriter->logf("destroyTrack_l mName=%d", track->mName); + mNBLogWriter->logTimestamp(); + mNBLogWriter->logf("destroyTrack_l mName=%d mFastIndex=%d mClientPid=%d", track->mName, + track->mFastIndex, track->mClient != 0 ? track->mClient->pid() : -1); track->mState = TrackBase::TERMINATED; // active tracks are removed by threadLoop() if (mActiveTracks.indexOf(track) < 0) { @@ -1361,7 +1365,9 @@ void AudioFlinger::PlaybackThread::destroyTrack_l(const sp<Track>& track) void AudioFlinger::PlaybackThread::removeTrack_l(const sp<Track>& track) { - mNBLogWriter->logf("removeTrack_l mName=%d", track->mName); + mNBLogWriter->logTimestamp(); + mNBLogWriter->logf("removeTrack_l mName=%d mFastIndex=%d clientPid=%d", track->mName, + track->mFastIndex, track->mClient != 0 ? track->mClient->pid() : -1); track->triggerEvents(AudioSystem::SYNC_EVENT_PRESENTATION_COMPLETE); mTracks.remove(track); deleteTrackName_l(track->name()); @@ -2870,7 +2876,9 @@ track_is_ready: ; if (CC_UNLIKELY(count)) { for (size_t i=0 ; i<count ; i++) { const sp<Track>& track = tracksToRemove->itemAt(i); - mNBLogWriter->logf("prepareTracks_l remove name=%u", track->name()); + mNBLogWriter->logTimestamp(); + mNBLogWriter->logf("prepareTracks_l remove name=%u mFastIndex=%d", track->name(), + track->mFastIndex); 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 fa1e336..8497788 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<SuspendedSessionDesc> > > mSuspendedSessions; - static const size_t kLogSize = 512; + static const size_t kLogSize = 4096; sp<NBLog::Writer> mNBLogWriter; }; diff --git a/services/audioflinger/Tracks.cpp b/services/audioflinger/Tracks.cpp index 315cbbc..f679751 100644 --- a/services/audioflinger/Tracks.cpp +++ b/services/audioflinger/Tracks.cpp @@ -351,6 +351,7 @@ 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, @@ -360,6 +361,7 @@ 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() @@ -569,7 +571,8 @@ status_t AudioFlinger::PlaybackThread::Track::start(AudioSystem::sync_event_t ev sp<ThreadBase> thread = mThread.promote(); if (thread != 0) { Mutex::Autolock _l(thread->mLock); - thread->mNBLogWriter->logf("start mName=%d", mName); + thread->mNBLogWriter->logf("start mName=%d mFastIndex=%d caller=%d", mName, mFastIndex, + IPCThreadState::self()->getCallingPid()); track_state state = mState; // here the track could be either new, or restarted // in both cases "unstop" the track @@ -612,7 +615,8 @@ void AudioFlinger::PlaybackThread::Track::stop() sp<ThreadBase> thread = mThread.promote(); if (thread != 0) { Mutex::Autolock _l(thread->mLock); - thread->mNBLogWriter->logf("stop mName=%d", mName); + thread->mNBLogWriter->logf("stop mName=%d mFastIndex=%d caller=%d", mName, mFastIndex, + IPCThreadState::self()->getCallingPid()); 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 @@ -649,7 +653,8 @@ void AudioFlinger::PlaybackThread::Track::pause() sp<ThreadBase> thread = mThread.promote(); if (thread != 0) { Mutex::Autolock _l(thread->mLock); - thread->mNBLogWriter->logf("pause mName=%d", mName); + thread->mNBLogWriter->logf("pause mName=%d mFastIndex=%d caller=%d", mName, mFastIndex, + IPCThreadState::self()->getCallingPid()); if (mState == ACTIVE || mState == RESUMING) { mState = PAUSING; ALOGV("ACTIVE/RESUMING => PAUSING (%d) on thread %p", mName, thread.get()); @@ -673,7 +678,8 @@ void AudioFlinger::PlaybackThread::Track::flush() sp<ThreadBase> thread = mThread.promote(); if (thread != 0) { Mutex::Autolock _l(thread->mLock); - thread->mNBLogWriter->logf("flush mName=%d", mName); + thread->mNBLogWriter->logf("flush mName=%d mFastIndex=%d caller=%d", mName, mFastIndex, + IPCThreadState::self()->getCallingPid()); if (mState != STOPPING_1 && mState != STOPPING_2 && mState != STOPPED && mState != PAUSED && mState != PAUSING && mState != IDLE && mState != FLUSHED) { return; |