Timestamp: Collect and dump statistics (2e2c0bbe) · Commits · e / os / android_frameworks_av

services/audioflinger/AudioFlinger.h

+1 −0

Original line number	Diff line number	Diff line
		@@ -63,6 +63,7 @@
		#include <media/VolumeShaper.h>

		#include <audio_utils/SimpleLog.h>
		#include <audio_utils/TimestampVerifier.h>

		#include "FastCapture.h"
		#include "FastMixer.h"

services/audioflinger/FastMixer.cpp

+42 −32

Original line number	Diff line number	Diff line
		@@ -336,13 +336,15 @@ void FastMixer::onWork()
		{
		// TODO: pass an ID parameter to indicate which time series we want to write to in NBLog.cpp
		// Or: pass both of these into a single call with a boolean
		const FastMixerState * const current = (const FastMixerState *) mCurrent;
		FastMixerDumpState * const dumpState = (FastMixerDumpState *) mDumpState;

		if (mIsWarm) {
		LOG_HIST_TS();
		} else {
		dumpState->mTimestampVerifier.discontinuity();
		LOG_AUDIO_STATE();
		}
		const FastMixerState * const current = (const FastMixerState *) mCurrent;
		FastMixerDumpState * const dumpState = (FastMixerDumpState *) mDumpState;
		const FastMixerState::Command command = mCommand;
		const size_t frameCount = current->mFrameCount;

		@@ -477,9 +479,14 @@ void FastMixer::onWork()
		mAttemptedWrite = true;
		// FIXME count # of writes blocked excessively, CPU usage, etc. for dump

		if (mIsWarm) {
		ExtendedTimestamp timestamp; // local
		status_t status = mOutputSink->getTimestamp(timestamp);
		if (status == NO_ERROR) {
		dumpState->mTimestampVerifier.add(
		timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL],
		timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL],
		mSampleRate);
		const int64_t totalNativeFramesPresented =
		timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL];
		if (totalNativeFramesPresented <= mTotalNativeFramesWritten) {
		@@ -498,6 +505,8 @@ void FastMixer::onWork()
		mNativeFramesWrittenButNotPresented = 0;
		status = INVALID_OPERATION;
		}
		} else {
		dumpState->mTimestampVerifier.error();
		}
		if (status == NO_ERROR) {
		mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_SERVER] =
		@@ -513,5 +522,6 @@ void FastMixer::onWork()
		}
		}
		}
		}

		} // namespace android

services/audioflinger/FastMixerDumpState.cpp

+1 −0

Original line number	Diff line number	Diff line
		@@ -73,6 +73,7 @@ void FastMixerDumpState::dump(int fd) const
		mNumTracks, mWriteErrors, mUnderruns, mOverruns,
		mSampleRate, mFrameCount, measuredWarmupMs, mWarmupCycles,
		mixPeriodSec * 1e3, mLatencyMs);
		dprintf(fd, " FastMixer Timestamp stats: %s\n", mTimestampVerifier.toString().c_str());
		#ifdef FAST_THREAD_STATISTICS
		// find the interval of valid samples
		uint32_t bounds = mBounds;

services/audioflinger/FastMixerDumpState.h

+4 −0

Original line number	Diff line number	Diff line
		@@ -18,6 +18,7 @@
		#define ANDROID_AUDIO_FAST_MIXER_DUMP_STATE_H

		#include <stdint.h>
		#include <audio_utils/TimestampVerifier.h>
		#include "Configuration.h"
		#include "FastThreadDumpState.h"
		#include "FastMixerState.h"
		@@ -75,6 +76,9 @@ struct FastMixerDumpState : FastThreadDumpState {
		size_t mFrameCount;
		uint32_t mTrackMask; // mask of active tracks
		FastTrackDump mTracks[FastMixerState::kMaxFastTracks];

		// For timestamp statistics.
		TimestampVerifier<int64_t /* frame count /, int64_t / time ns */> mTimestampVerifier;
		};

		} // android

services/audioflinger/Threads.cpp

+31 −3

Original line number	Diff line number	Diff line
		@@ -853,6 +853,14 @@ void AudioFlinger::ThreadBase::dumpBase(int fd, const Vector<String16>& args __u
		dprintf(fd, " Input device: %#x (%s)\n", mInDevice, devicesToString(mInDevice).c_str());
		dprintf(fd, " Audio source: %d (%s)\n", mAudioSource, sourceToString(mAudioSource));

		// Dump timestamp statistics for the Thread types that support it.
		if (mType == RECORD
		\|\| mType == MIXER
		\|\| mType == DUPLICATING
		\|\| (mType == DIRECT && audio_is_linear_pcm(mHALFormat))) {
		dprintf(fd, " Timestamp stats: %s\n", mTimestampVerifier.toString().c_str());
		}

		if (locked) {
		mLock.unlock();
		}
		@@ -3205,12 +3213,21 @@ bool AudioFlinger::PlaybackThread::threadLoop()
		logString = NULL;
		}

		// Collect timestamp statistics for the Playback Thread types that support it.
		if (mType == MIXER
		\|\| mType == DUPLICATING
		\|\| (mType == DIRECT && audio_is_linear_pcm(mHALFormat))) { // 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 (threadloop_getHalTimestamp_l(&timestamp) == OK) {
		if (mStandby) {
		mTimestampVerifier.discontinuity();
		} else if (threadloop_getHalTimestamp_l(&timestamp) == OK) {
		mTimestampVerifier.add(timestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL],
		timestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL],
		mSampleRate);
		// We always fetch the timestamp here because often the downstream
		// sink will block while writing.

		@@ -3241,7 +3258,10 @@ bool AudioFlinger::PlaybackThread::threadLoop()
		+ 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.
		@@ -3274,6 +3294,7 @@ bool AudioFlinger::PlaybackThread::threadLoop()
		}
		}
		}
		} // if (mType ... ) { // no indentation
		#if 0
		// logFormat example
		if (z % 100 == 0) {
		@@ -6730,8 +6751,9 @@ reacquire_wakelock:
		// Update server timestamp with kernel stats
		if (mPipeSource.get() == nullptr /* don't obtain for FastCapture, could block */) {
		int64_t position, time;
		int ret = mInput->stream->getCapturePosition(&position, &time);
		if (ret == NO_ERROR) {
		if (mStandby) {
		mTimestampVerifier.discontinuity();
		} else if (mInput->stream->getCapturePosition(&position, &time) == NO_ERROR) {
		mTimestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL] = position;
		mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL] = time;
		// Note: In general record buffers should tend to be empty in
		@@ -6739,6 +6761,12 @@ reacquire_wakelock:
		//
		// Also, it is not advantageous to call get_presentation_position during the read
		// as the read obtains a lock, preventing the timestamp call from executing.

		mTimestampVerifier.add(mTimestamp.mPosition[ExtendedTimestamp::LOCATION_KERNEL],
		mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_KERNEL],
		mSampleRate);
		} else {
		mTimestampVerifier.error();
		}
		}
		// Use this to track timestamp information