Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit 99c99d00 authored by Glenn Kasten's avatar Glenn Kasten
Browse files

systrace for audio 

Trace fast track buffer fill status for underruns etc.

Move the definition of macro to Android.mk.

No overhead if disabled.

Change-Id: If0e83e21b61b059ca38f543f8a6ffb58e08c79ee
parent 55247760

services/audioflinger/Android.mk

+3 −0
Original line number Diff line number Diff line
@@ -82,4 +82,7 @@ LOCAL_CFLAGS += -DSTATE_QUEUE_INSTANTIATIONS='"StateQueueInstantiations.cpp"' 


LOCAL_CFLAGS += -DHAVE_REQUEST_PRIORITY -UFAST_TRACKS_AT_NON_NATIVE_SAMPLE_RATE -USOAKER



# uncomment for systrace

# LOCAL_CFLAGS += -DATRACE_TAG=ATRACE_TAG_AUDIO



include $(BUILD_SHARED_LIBRARY)

services/audioflinger/AudioFlinger.cpp

+6 −2
Original line number Diff line number Diff line
@@ -19,8 +19,6 @@ 
#define LOG_TAG "AudioFlinger"

//#define LOG_NDEBUG 0



//#define ATRACE_TAG ATRACE_TAG_AUDIO



#include <math.h>

#include <signal.h>

#include <sys/time.h>
@@ -2557,7 +2555,9 @@ if (mType == MIXER) { 
            if (!mStandby && delta > maxPeriod) {

                mNumDelayedWrites++;

                if ((now - lastWarning) > kWarningThrottleNs) {

#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)

                    ScopedTrace st(ATRACE_TAG, "underrun");

#endif

                    ALOGW("write blocked for %llu msecs, %d delayed writes, thread %p",

                            ns2ms(delta), mNumDelayedWrites, this);

                    lastWarning = now;
@@ -2652,9 +2652,13 @@ void AudioFlinger::PlaybackThread::threadLoop_write() 


#define mBitShift 2 // FIXME

    size_t count = mixBufferSize >> mBitShift;

#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)

    Tracer::traceBegin(ATRACE_TAG, "write");

#endif

    ssize_t framesWritten = mNormalSink->write(mMixBuffer, count);

#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)

    Tracer::traceEnd(ATRACE_TAG);

#endif

    if (framesWritten > 0) {

        size_t bytesWritten = framesWritten << mBitShift;

        mBytesWritten += bytesWritten;

services/audioflinger/FastMixer.cpp

+18 −3
Original line number Diff line number Diff line
@@ -17,8 +17,6 @@ 
#define LOG_TAG "FastMixer"

//#define LOG_NDEBUG 0



//#define ATRACE_TAG ATRACE_TAG_AUDIO



#include <sys/atomics.h>

#include <time.h>

#include <utils/Log.h>
@@ -359,10 +357,17 @@ bool FastMixer::threadLoop() 
                // up to 1 ms.  If enough active tracks all blocked in sequence, this would result

                // in the overall fast mix cycle being delayed.  Should use a non-blocking FIFO.

                size_t framesReady = fastTrack->mBufferProvider->framesReady();

#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)

                // I wish we had formatted trace names

                char traceName[16];

                strcpy(traceName, "framesReady");

                traceName[11] = i + (i < 10 ? '0' : 'A' - 10);

                traceName[12] = '\0';

                ATRACE_INT(traceName, framesReady);

#endif

                FastTrackDump *ftDump = &dumpState->mTracks[i];

                FastTrackUnderruns underruns = ftDump->mUnderruns;

                if (framesReady < frameCount) {

                    ATRACE_INT("underrun", i);

                    if (framesReady == 0) {

                        underruns.mBitFields.mEmpty++;

                        underruns.mBitFields.mMostRecent = UNDERRUN_EMPTY;
@@ -396,9 +401,13 @@ bool FastMixer::threadLoop() 
            // FIXME write() is non-blocking and lock-free for a properly implemented NBAIO sink,

            //       but this code should be modified to handle both non-blocking and blocking sinks

            dumpState->mWriteSequence++;

#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)

            Tracer::traceBegin(ATRACE_TAG, "write");

#endif

            ssize_t framesWritten = outputSink->write(mixBuffer, frameCount);

#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)

            Tracer::traceEnd(ATRACE_TAG);

#endif

            dumpState->mWriteSequence++;

            if (framesWritten >= 0) {

                ALOG_ASSERT(framesWritten <= frameCount);
@@ -448,7 +457,9 @@ bool FastMixer::threadLoop() 
                    }

                }

                if (sec > 0 || nsec > underrunNs) {

#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)

                    ScopedTrace st(ATRACE_TAG, "underrun");

#endif

                    // FIXME only log occasionally

                    ALOGV("underrun: time since last cycle %d.%03ld sec",

                            (int) sec, nsec / 1000000L);
@@ -518,6 +529,10 @@ bool FastMixer::threadLoop() 
                // this store #4 is not atomic with respect to stores #1, #2, #3 above, but

                // the newest open and oldest closed halves are atomic with respect to each other

                dumpState->mBounds = bounds;

#if defined(ATRACE_TAG) && (ATRACE_TAG != ATRACE_TAG_NEVER)

                ATRACE_INT("cycle_ms", monotonicNs / 1000000);

                ATRACE_INT("load_us", loadNs / 1000);

#endif

#endif

            } else {

                // first time through the loop