aaudio: fix timestamps and underruns
Start the client after we get valid timing data from the server.
That can take a while because of the long cold start times.
The client is synced with the current position of the service.
Now the client can start clean with no underruns.
Bug: 63918065
Test: test_timestamps.cpp
Change-Id: I5d01eb844e4b14cd5477d56ea1dd9e309abc1c52
diff --git a/media/libaaudio/src/client/AudioStreamInternal.cpp b/media/libaaudio/src/client/AudioStreamInternal.cpp
index 7f2e495..bbbd439 100644
--- a/media/libaaudio/src/client/AudioStreamInternal.cpp
+++ b/media/libaaudio/src/client/AudioStreamInternal.cpp
@@ -55,7 +55,7 @@
// Wait at least this many times longer than the operation should take.
#define MIN_TIMEOUT_OPERATIONS 4
-#define LOG_TIMESTAMPS 0
+#define LOG_TIMESTAMPS 0
AudioStreamInternal::AudioStreamInternal(AAudioServiceInterface &serviceInterface, bool inService)
: AudioStream()
@@ -66,9 +66,9 @@
, mStreamVolume(1.0f)
, mInService(inService)
, mServiceInterface(serviceInterface)
+ , mAtomicTimestamp()
, mWakeupDelayNanos(AAudioProperty_getWakeupDelayMicros() * AAUDIO_NANOS_PER_MICROSECOND)
, mMinimumSleepNanos(AAudioProperty_getMinimumSleepMicros() * AAUDIO_NANOS_PER_MICROSECOND)
- , mAtomicTimestamp()
{
ALOGD("AudioStreamInternal(): mWakeupDelayNanos = %d, mMinimumSleepNanos = %d",
mWakeupDelayNanos, mMinimumSleepNanos);
@@ -250,25 +250,45 @@
}
}
+/*
+ * It normally takes about 20-30 msec to start a stream on the server.
+ * But the first time can take as much as 200-300 msec. The HW
+ * starts right away so by the time the client gets a chance to write into
+ * the buffer, it is already in a deep underflow state. That can cause the
+ * XRunCount to be non-zero, which could lead an app to tune its latency higher.
+ * To avoid this problem, we set a request for the processing code to start the
+ * client stream at the same position as the server stream.
+ * The processing code will then save the current offset
+ * between client and server and apply that to any position given to the app.
+ */
aaudio_result_t AudioStreamInternal::requestStart()
{
int64_t startTime;
- ALOGD("AudioStreamInternal()::requestStart()");
if (mServiceStreamHandle == AAUDIO_HANDLE_INVALID) {
- ALOGE("AudioStreamInternal::requestStart() mServiceStreamHandle invalid");
+ ALOGE("requestStart() mServiceStreamHandle invalid");
return AAUDIO_ERROR_INVALID_STATE;
}
if (isActive()) {
- ALOGE("AudioStreamInternal::requestStart() already active");
+ ALOGE("requestStart() already active");
return AAUDIO_ERROR_INVALID_STATE;
}
- aaudio_stream_state_t originalState = getState();
+ aaudio_stream_state_t originalState = getState();
+ if (originalState == AAUDIO_STREAM_STATE_DISCONNECTED) {
+ ALOGE("requestStart() but DISCONNECTED");
+ return AAUDIO_ERROR_DISCONNECTED;
+ }
setState(AAUDIO_STREAM_STATE_STARTING);
- aaudio_result_t result = AAudioConvert_androidToAAudioResult(startWithStatus());
+
+ // Clear any stale timestamps from the previous run.
+ drainTimestampsFromService();
+
+ status_t status = startWithStatus(); // Call PlayerBase, which will start the device stream.
+ aaudio_result_t result = AAudioConvert_androidToAAudioResult(status);
startTime = AudioClock::getNanoseconds();
mClockModel.start(startTime);
+ mNeedCatchUp.request(); // Ask data processing code to catch up when first timestamp received.
if (result == AAUDIO_OK && getDataCallbackProc() != nullptr) {
// Launch the callback loop thread.
@@ -314,13 +334,14 @@
aaudio_result_t AudioStreamInternal::requestStopInternal()
{
if (mServiceStreamHandle == AAUDIO_HANDLE_INVALID) {
- ALOGE("AudioStreamInternal::requestStopInternal() mServiceStreamHandle invalid = 0x%08X",
+ ALOGE("requestStopInternal() mServiceStreamHandle invalid = 0x%08X",
mServiceStreamHandle);
return AAUDIO_ERROR_INVALID_STATE;
}
mClockModel.stop(AudioClock::getNanoseconds());
setState(AAUDIO_STREAM_STATE_STOPPING);
+ mAtomicTimestamp.clear();
return AAudioConvert_androidToAAudioResult(stopWithStatus());
}
@@ -336,7 +357,7 @@
aaudio_result_t AudioStreamInternal::registerThread() {
if (mServiceStreamHandle == AAUDIO_HANDLE_INVALID) {
- ALOGE("AudioStreamInternal::registerThread() mServiceStreamHandle invalid");
+ ALOGE("registerThread() mServiceStreamHandle invalid");
return AAUDIO_ERROR_INVALID_STATE;
}
return mServiceInterface.registerAudioThread(mServiceStreamHandle,
@@ -346,7 +367,7 @@
aaudio_result_t AudioStreamInternal::unregisterThread() {
if (mServiceStreamHandle == AAUDIO_HANDLE_INVALID) {
- ALOGE("AudioStreamInternal::unregisterThread() mServiceStreamHandle invalid");
+ ALOGE("unregisterThread() mServiceStreamHandle invalid");
return AAUDIO_ERROR_INVALID_STATE;
}
return mServiceInterface.unregisterAudioThread(mServiceStreamHandle, gettid());
@@ -374,12 +395,14 @@
// Generated in server and passed to client. Return latest.
if (mAtomicTimestamp.isValid()) {
Timestamp timestamp = mAtomicTimestamp.read();
- *framePosition = timestamp.getPosition();
- *timeNanoseconds = timestamp.getNanoseconds();
- return AAUDIO_OK;
- } else {
- return AAUDIO_ERROR_UNAVAILABLE;
+ int64_t position = timestamp.getPosition() + mFramesOffsetFromService;
+ if (position >= 0) {
+ *framePosition = position;
+ *timeNanoseconds = timestamp.getNanoseconds();
+ return AAUDIO_OK;
+ }
}
+ return AAUDIO_ERROR_UNAVAILABLE;
}
aaudio_result_t AudioStreamInternal::updateStateMachine() {
@@ -394,14 +417,14 @@
static int64_t oldTime = 0;
int64_t framePosition = command.timestamp.position;
int64_t nanoTime = command.timestamp.timestamp;
- ALOGD("AudioStreamInternal: timestamp says framePosition = %08lld at nanoTime %lld",
+ ALOGD("logTimestamp: timestamp says framePosition = %8lld at nanoTime %lld",
(long long) framePosition,
(long long) nanoTime);
int64_t nanosDelta = nanoTime - oldTime;
if (nanosDelta > 0 && oldTime > 0) {
int64_t framesDelta = framePosition - oldPosition;
int64_t rate = (framesDelta * AAUDIO_NANOS_PER_SECOND) / nanosDelta;
- ALOGD("AudioStreamInternal: framesDelta = %08lld, nanosDelta = %08lld, rate = %lld",
+ ALOGD("logTimestamp: framesDelta = %8lld, nanosDelta = %8lld, rate = %lld",
(long long) framesDelta, (long long) nanosDelta, (long long) rate);
}
oldPosition = framePosition;
@@ -478,6 +501,34 @@
return result;
}
+aaudio_result_t AudioStreamInternal::drainTimestampsFromService() {
+ aaudio_result_t result = AAUDIO_OK;
+
+ while (result == AAUDIO_OK) {
+ AAudioServiceMessage message;
+ if (mAudioEndpoint.readUpCommand(&message) != 1) {
+ break; // no command this time, no problem
+ }
+ switch (message.what) {
+ // ignore most messages
+ case AAudioServiceMessage::code::TIMESTAMP_SERVICE:
+ case AAudioServiceMessage::code::TIMESTAMP_HARDWARE:
+ break;
+
+ case AAudioServiceMessage::code::EVENT:
+ result = onEventFromServer(&message);
+ break;
+
+ default:
+ ALOGE("WARNING - drainTimestampsFromService() Unrecognized what = %d",
+ (int) message.what);
+ result = AAUDIO_ERROR_INTERNAL;
+ break;
+ }
+ }
+ return result;
+}
+
// Process all the commands coming from the server.
aaudio_result_t AudioStreamInternal::processCommands() {
aaudio_result_t result = AAUDIO_OK;
@@ -502,7 +553,7 @@
break;
default:
- ALOGE("WARNING - AudioStreamInternal::processCommands() Unrecognized what = %d",
+ ALOGE("WARNING - processCommands() Unrecognized what = %d",
(int) message.what);
result = AAUDIO_ERROR_INTERNAL;
break;
@@ -613,7 +664,7 @@
}
aaudio_result_t result = mAudioEndpoint.setBufferSizeInFrames(requestedFrames, &actualFrames);
- ALOGD("AudioStreamInternal::setBufferSize() req = %d => %d", requestedFrames, actualFrames);
+ ALOGD("setBufferSize() req = %d => %d", requestedFrames, actualFrames);
if (result < 0) {
return result;
} else {