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

Commit 12473e91 authored by Dean Wheatley's avatar Dean Wheatley Committed by Andy Hung
Browse files

Return direct/offload corrected timestamps 

Previously, for direct/offload outputs with timestamp correction
enabled, getTimestamp would not return corrected timestamps, but
only raw HAL timestamps with downstream latency compensation.
To resolve this, run timestamp correction routine in getTimestamp
and return latest kernel timestamps, as threadLoop() timestamps
may be stale for (large buffer) direct/offload outputs.

Also, use timestamp verifier discontinuity new API to fix corrected
timestamps after pause/standby. Direct non-pcm and offload threads
should register timestamp verifier zero discontinuties on standby, but
other threads should register continuous discontinuities. On pause, all
threads should register continuous discontinuity. Update to use new
timestamp verifier API to set the discontinuity type on each
discontinuity event.

Test: Offloaded (eac3) into MSD HAL AudioTrack (corrected) timestamps
      Jitter standard deviation reduced.
Change-Id: I28a95c3922165689dfcbd13ab83b35dab8ec6adb
parent 7a9d8d60

services/audioflinger/FastMixer.cpp

+2 −1
Original line number Diff line number Diff line
@@ -353,7 +353,8 @@ void FastMixer::onWork() 
#endif

        //ALOGD("Eric FastMixer::onWork() mIsWarm");

    } else {

        dumpState->mTimestampVerifier.discontinuity();

        dumpState->mTimestampVerifier.discontinuity(

            dumpState->mTimestampVerifier.DISCONTINUITY_MODE_CONTINUOUS);

        // See comment in if block.

#ifdef FASTMIXER_LOG_HIST_TS

        LOG_AUDIO_STATE();

services/audioflinger/Threads.cpp

+161 −157
Original line number Diff line number Diff line
@@ -622,7 +622,7 @@ void AudioFlinger::ThreadBase::sendIoConfigEvent_l(audio_io_config_event event, 
    mIoJitterMs.reset();

    mLatencyMs.reset();

    mProcessTimeMs.reset();

    mTimestampVerifier.discontinuity();

    mTimestampVerifier.discontinuity(mTimestampVerifier.DISCONTINUITY_MODE_CONTINUOUS);



    sp<ConfigEvent> configEvent = (ConfigEvent *)new IoConfigEvent(event, pid, portId);

    sendConfigEvent_l(configEvent);
@@ -2719,7 +2719,7 @@ void AudioFlinger::PlaybackThread::resetDraining(uint32_t sequence) 
        // the timestamp frame position to reset to 0 for direct and offload threads.

        // (Out of sequence requests are ignored, since the discontinuity would be handled

        // elsewhere, e.g. in flush).

        mTimestampVerifier.discontinuity();

        mTimestampVerifier.discontinuity(mTimestampVerifier.DISCONTINUITY_MODE_ZERO);

        mDrainSequence &= ~1;

        mWaitWorkCV.signal();

    }
@@ -3408,7 +3408,6 @@ bool AudioFlinger::PlaybackThread::threadLoop() 


    mStandbyTimeNs = systemTime();

    int64_t lastLoopCountWritten = -2; // never matches "previous" loop, when loopCount = 0.

    int64_t lastFramesWritten = -1;    // track changes in timestamp server frames written



    // MIXER

    nsecs_t lastWarning = 0;
@@ -3444,14 +3443,6 @@ bool AudioFlinger::PlaybackThread::threadLoop() 


    checkSilentMode_l();



    // DIRECT and OFFLOAD threads should reset frame count to zero on stop/flush

    // TODO: add confirmation checks:

    // 1) DIRECT threads and linear PCM format really resets to 0?

    // 2) Is frame count really valid if not linear pcm?

    // 3) Are all 64 bits of position returned, not just lowest 32 bits?

    if (mType == OFFLOAD || mType == DIRECT) {

        mTimestampVerifier.setDiscontinuityMode(mTimestampVerifier.DISCONTINUITY_MODE_ZERO);

    }

    audio_patch_handle_t lastDownstreamPatchHandle = AUDIO_PATCH_HANDLE_NONE;



    // loopCount is used for statistics and diagnostics.
@@ -3523,135 +3514,8 @@ bool AudioFlinger::PlaybackThread::threadLoop() 
                logString = NULL;

            }



            // Collect timestamp statistics for the Playback Thread types that support it.

            if (mType == MIXER

                    || mType == DUPLICATING

                    || mType == DIRECT

                    || mType == OFFLOAD) { // no indentation

            // Gather the framesReleased counters for all active tracks,

            // and associate with the sink frames written out.  We need

            // this to convert the sink timestamp to the track timestamp.

            bool kernelLocationUpdate = false;

            ExtendedTimestamp timestamp; // use private copy to fetch

            if (mStandby) {

                mTimestampVerifier.discontinuity();

            } else if (threadloop_getHalTimestamp_l(&timestamp) == OK) {

                mTimestampVerifier.add(timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL],

                        timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL],

                        mSampleRate);



                if (isTimestampCorrectionEnabled()) {

                    ALOGVV("TS_BEFORE: %d %lld %lld", id(),

                            (long long)timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL],

                            (long long)timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL]);

                    auto correctedTimestamp = mTimestampVerifier.getLastCorrectedTimestamp();

                    timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL]

                            = correctedTimestamp.mFrames;

                    timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL]

                            = correctedTimestamp.mTimeNs;

                    ALOGVV("TS_AFTER: %d %lld %lld", id(),

                            (long long)timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL],

                            (long long)timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL]);



                    // Note: Downstream latency only added if timestamp correction enabled.

                    if (mDownstreamLatencyStatMs.getN() > 0) { // we have latency info.

                        const int64_t newPosition =

                                timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL]

                                - int64_t(mDownstreamLatencyStatMs.getMean() * mSampleRate * 1e-3);

                        // prevent retrograde

                        timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL] = max(

                                newPosition,

                                (mTimestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL]

                                        - mSuspendedFrames));

                    }

                }



                // We always fetch the timestamp here because often the downstream

                // sink will block while writing.



                // We keep track of the last valid kernel position in case we are in underrun

                // and the normal mixer period is the same as the fast mixer period, or there

                // is some error from the HAL.

                if (mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL] >= 0) {

                    mTimestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL_LASTKERNELOK] =

                            mTimestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL];

                    mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL_LASTKERNELOK] =

                            mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL];



                    mTimestamp.mPosition[ExtendedTimestamp::LOCATION_SERVER_LASTKERNELOK] =

                            mTimestamp.mPosition[ExtendedTimestamp::LOCATION_SERVER];

                    mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_SERVER_LASTKERNELOK] =

                            mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_SERVER];

                }



                if (timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL] >= 0) {

                    kernelLocationUpdate = true;

                } else {

                    ALOGVV("getTimestamp error - no valid kernel position");

                }



                // copy over kernel info

                mTimestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL] =

                        timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL]

                        + mSuspendedFrames; // add frames discarded when suspended

                mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL] =

                        timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL];

            } else {

                mTimestampVerifier.error();

            }



            // mFramesWritten for non-offloaded tracks are contiguous

            // even after standby() is called. This is useful for the track frame

            // to sink frame mapping.

            bool serverLocationUpdate = false;

            if (mFramesWritten != lastFramesWritten) {

                serverLocationUpdate = true;

                lastFramesWritten = mFramesWritten;

            }

            // Only update timestamps if there is a meaningful change.

            // Either the kernel timestamp must be valid or we have written something.

            if (kernelLocationUpdate || serverLocationUpdate) {

                if (serverLocationUpdate) {

                    // use the time before we called the HAL write - it is a bit more accurate

                    // to when the server last read data than the current time here.

                    //

                    // If we haven't written anything, mLastIoBeginNs will be -1

                    // and we use systemTime().

                    mTimestamp.mPosition[ExtendedTimestamp::LOCATION_SERVER] = mFramesWritten;

                    mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_SERVER] = mLastIoBeginNs == -1

                            ? systemTime() : mLastIoBeginNs;

                }



                for (const sp<Track> &t : mActiveTracks) {

                    if (!t->isFastTrack()) {

                        t->updateTrackFrameInfo(

                                t->mAudioTrackServerProxy->framesReleased(),

                                mFramesWritten,

                                mSampleRate,

                                mTimestamp);

                    }

                }

            }

            collectTimestamps_l();



            if (audio_has_proportional_frames(mFormat)) {

                const double latencyMs = mTimestamp.getOutputServerLatencyMs(mSampleRate);

                if (latencyMs != 0.) { // note 0. means timestamp is empty.

                    mLatencyMs.add(latencyMs);

                }

            }



            } // if (mType ... ) { // no indentation

#if 0

            // logFormat example

            if (z % 100 == 0) {

                timespec ts;

                clock_gettime(CLOCK_MONOTONIC, &ts);

                LOGT("This is an integer %d, this is a float %f, this is my "

                    "pid %p %% %s %t", 42, 3.14, "and this is a timestamp", ts);

                LOGT("A deceptive null-terminated string %\0");

            }

            ++z;

#endif

            saveOutputTracks();

            if (mSignalPending) {

                // A signal was raised while we were unlocked
@@ -4091,6 +3955,148 @@ bool AudioFlinger::PlaybackThread::threadLoop() 
    return false;

}



void AudioFlinger::PlaybackThread::collectTimestamps_l()

{

    // Collect timestamp statistics for the Playback Thread types that support it.

    if (mType != MIXER

            && mType != DUPLICATING

            && mType != DIRECT

            && mType != OFFLOAD) {

        return;

    }

    if (mStandby) {

        mTimestampVerifier.discontinuity(discontinuityForStandbyOrFlush());

        return;

    } else if (mHwPaused) {

        mTimestampVerifier.discontinuity(mTimestampVerifier.DISCONTINUITY_MODE_CONTINUOUS);

        return;

    }



    // Gather the framesReleased counters for all active tracks,

    // and associate with the sink frames written out.  We need

    // this to convert the sink timestamp to the track timestamp.

    bool kernelLocationUpdate = false;

    ExtendedTimestamp timestamp; // use private copy to fetch



    // Always query HAL timestamp and update timestamp verifier. In standby or pause,

    // HAL may be draining some small duration buffered data for fade out.

    if (threadloop_getHalTimestamp_l(&timestamp) == OK) {

        mTimestampVerifier.add(timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL],

                timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL],

                mSampleRate);



        if (isTimestampCorrectionEnabled()) {

            ALOGVV("TS_BEFORE: %d %lld %lld", id(),

                    (long long)timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL],

                    (long long)timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL]);

            auto correctedTimestamp = mTimestampVerifier.getLastCorrectedTimestamp();

            timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL]

                    = correctedTimestamp.mFrames;

            timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL]

                    = correctedTimestamp.mTimeNs;

            ALOGVV("TS_AFTER: %d %lld %lld", id(),

                    (long long)timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL],

                    (long long)timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL]);



            // Note: Downstream latency only added if timestamp correction enabled.

            if (mDownstreamLatencyStatMs.getN() > 0) { // we have latency info.

                const int64_t newPosition =

                        timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL]

                        - int64_t(mDownstreamLatencyStatMs.getMean() * mSampleRate * 1e-3);

                // prevent retrograde

                timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL] = max(

                        newPosition,

                        (mTimestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL]

                                - mSuspendedFrames));

            }

        }



        // We always fetch the timestamp here because often the downstream

        // sink will block while writing.



        // We keep track of the last valid kernel position in case we are in underrun

        // and the normal mixer period is the same as the fast mixer period, or there

        // is some error from the HAL.

        if (mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL] >= 0) {

            mTimestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL_LASTKERNELOK] =

                    mTimestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL];

            mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL_LASTKERNELOK] =

                    mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL];



            mTimestamp.mPosition[ExtendedTimestamp::LOCATION_SERVER_LASTKERNELOK] =

                    mTimestamp.mPosition[ExtendedTimestamp::LOCATION_SERVER];

            mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_SERVER_LASTKERNELOK] =

                    mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_SERVER];

        }



        if (timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL] >= 0) {

            kernelLocationUpdate = true;

        } else {

            ALOGVV("getTimestamp error - no valid kernel position");

        }



        // copy over kernel info

        mTimestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL] =

                timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL]

                + mSuspendedFrames; // add frames discarded when suspended

        mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL] =

                timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL];

    } else {

        mTimestampVerifier.error();

    }



    // mFramesWritten for non-offloaded tracks are contiguous

    // even after standby() is called. This is useful for the track frame

    // to sink frame mapping.

    bool serverLocationUpdate = false;

    if (mFramesWritten != mLastFramesWritten) {

        serverLocationUpdate = true;

        mLastFramesWritten = mFramesWritten;

    }

    // Only update timestamps if there is a meaningful change.

    // Either the kernel timestamp must be valid or we have written something.

    if (kernelLocationUpdate || serverLocationUpdate) {

        if (serverLocationUpdate) {

            // use the time before we called the HAL write - it is a bit more accurate

            // to when the server last read data than the current time here.

            //

            // If we haven't written anything, mLastIoBeginNs will be -1

            // and we use systemTime().

            mTimestamp.mPosition[ExtendedTimestamp::LOCATION_SERVER] = mFramesWritten;

            mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_SERVER] = mLastIoBeginNs == -1

                    ? systemTime() : mLastIoBeginNs;

        }



        for (const sp<Track> &t : mActiveTracks) {

            if (!t->isFastTrack()) {

                t->updateTrackFrameInfo(

                        t->mAudioTrackServerProxy->framesReleased(),

                        mFramesWritten,

                        mSampleRate,

                        mTimestamp);

            }

        }

    }



    if (audio_has_proportional_frames(mFormat)) {

        const double latencyMs = mTimestamp.getOutputServerLatencyMs(mSampleRate);

        if (latencyMs != 0.) { // note 0. means timestamp is empty.

            mLatencyMs.add(latencyMs);

        }

    }

#if 0

    // logFormat example

    if (z % 100 == 0) {

        timespec ts;

        clock_gettime(CLOCK_MONOTONIC, &ts);

        LOGT("This is an integer %d, this is a float %f, this is my "

            "pid %p %% %s %t", 42, 3.14, "and this is a timestamp", ts);

        LOGT("A deceptive null-terminated string %\0");

    }

    ++z;

#endif

}



// removeTracks_l() must be called with ThreadBase::mLock held

void AudioFlinger::PlaybackThread::removeTracks_l(const Vector< sp<Track> >& tracksToRemove)

{
@@ -4137,21 +4143,16 @@ status_t AudioFlinger::PlaybackThread::getTimestamp_l(AudioTimestamp& timestamp) 
        return status;

    }

    if ((mType == OFFLOAD || mType == DIRECT) && mOutput != NULL) {

        uint64_t position64;

        if (mOutput->getPresentationPosition(&position64, &timestamp.mTime) == OK) {

            timestamp.mPosition = (uint32_t)position64;

            if (mDownstreamLatencyStatMs.getN() > 0) {

                const uint32_t positionOffset =

                    (uint32_t)(mDownstreamLatencyStatMs.getMean() * mSampleRate * 1e-3);

                if (positionOffset > timestamp.mPosition) {

                    timestamp.mPosition = 0;

                } else {

                    timestamp.mPosition -= positionOffset;

                }

        collectTimestamps_l();

        if (mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL] <= 0) {

            return INVALID_OPERATION;

        }

        timestamp.mPosition = mTimestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL];

        const int64_t timeNs = mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL];

        timestamp.mTime.tv_sec = timeNs / NANOS_PER_SECOND;

        timestamp.mTime.tv_nsec = timeNs - (timestamp.mTime.tv_sec * NANOS_PER_SECOND);

        return NO_ERROR;

    }

    }

    return INVALID_OPERATION;

}
@@ -6178,7 +6179,7 @@ void AudioFlinger::DirectOutputThread::flushHw_l() 
    mOutput->flush();

    mHwPaused = false;

    mFlushPending = false;

    mTimestampVerifier.discontinuity(); // DIRECT and OFFLOADED flush resets frame count.

    mTimestampVerifier.discontinuity(discontinuityForStandbyOrFlush());

    mTimestamp.clear();

}
@@ -6514,13 +6515,14 @@ AudioFlinger::PlaybackThread::mixer_state AudioFlinger::OffloadThread::prepareTr 
                    track->presentationComplete(framesWritten, audioHALFrames);

                    track->reset();

                    tracksToRemove->add(track);

                    // DIRECT and OFFLOADED stop resets frame counts.

                    // OFFLOADED stop resets frame counts.

                    if (!mUseAsyncWrite) {

                        // If we don't get explicit drain notification we must

                        // register discontinuity regardless of whether this is

                        // the previous (!last) or the upcoming (last) track

                        // to avoid skipping the discontinuity.

                        mTimestampVerifier.discontinuity();

                        mTimestampVerifier.discontinuity(

                                mTimestampVerifier.DISCONTINUITY_MODE_ZERO);

                    }

                }

            } else {
@@ -7378,7 +7380,9 @@ reacquire_wakelock: 
        if (mPipeSource.get() == nullptr /* don't obtain for FastCapture, could block */) {

            int64_t position, time;

            if (mStandby) {

                mTimestampVerifier.discontinuity();

                mTimestampVerifier.discontinuity(audio_is_linear_pcm(mFormat) ?

                    mTimestampVerifier.DISCONTINUITY_MODE_CONTINUOUS :

                    mTimestampVerifier.DISCONTINUITY_MODE_ZERO);

            } else if (mSource->getCapturePosition(&position, &time) == NO_ERROR

                    && time > mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL]) {

services/audioflinger/Threads.h

+17 −0
Original line number Diff line number Diff line
@@ -590,6 +590,11 @@ protected: 
                ExtendedTimestamp       mTimestamp;

                TimestampVerifier< // For timestamp statistics.

                        int64_t /* frame count */, int64_t /* time ns */> mTimestampVerifier;

                // DIRECT and OFFLOAD threads should reset frame count to zero on stop/flush

                // TODO: add confirmation checks:

                // 1) DIRECT threads and linear PCM format really resets to 0?

                // 2) Is frame count really valid if not linear pcm?

                // 3) Are all 64 bits of position returned, not just lowest 32 bits?

                // Timestamp corrected device should be a single device.

                audio_devices_t         mTimestampCorrectedDevice = AUDIO_DEVICE_NONE;
@@ -1023,6 +1028,8 @@ protected: 


    int64_t                         mBytesWritten;

    int64_t                         mFramesWritten; // not reset on standby

    int64_t                         mLastFramesWritten = -1; // track changes in timestamp

                                                             // server frames written.

    int64_t                         mSuspendedFrames; // not reset on standby



    // mHapticChannelMask and mHapticChannelCount will only be valid when the thread support
@@ -1035,6 +1042,14 @@ private: 
    // copy rather than the one in AudioFlinger.  This optimization saves a lock.

    bool                            mMasterMute;

                void        setMasterMute_l(bool muted) { mMasterMute = muted; }



                auto discontinuityForStandbyOrFlush() const { // call on threadLoop or with lock.

                    return ((mType == DIRECT && !audio_is_linear_pcm(mFormat))

                                    || mType == OFFLOAD)

                            ? mTimestampVerifier.DISCONTINUITY_MODE_ZERO

                            : mTimestampVerifier.DISCONTINUITY_MODE_CONTINUOUS;

                }



protected:

    ActiveTracks<Track>     mActiveTracks;
@@ -1081,6 +1096,8 @@ private: 
    void        updateMetadata_l() final;

    virtual void sendMetadataToBackend_l(const StreamOutHalInterface::SourceMetadata& metadata);



    void        collectTimestamps_l();



    // The Tracks class manages tracks added and removed from the Thread.

    template <typename T>

    class Tracks {