aaudio: reduce glitching by improving sleep timing

ALways sleep a minimum time to avoid busy wait in real-time thread.
Account for wakeup jitter in threads on the other side of a FIFO.
Avoid race condition that caused a longer sleep than necessary.
Fix calculation of mFreeRunning for capture mode.

Also added systrace logging, which was used to debug this.

Bug: 63814792
Test: Run GStomper on Walleye with MMAP on, see bug
Change-Id: I7b20098580ff454365425bd21e43c17ade532a0a
diff --git a/media/libaaudio/src/client/AudioStreamInternalPlay.cpp b/media/libaaudio/src/client/AudioStreamInternalPlay.cpp
index 1b18577..31e0a40 100644
--- a/media/libaaudio/src/client/AudioStreamInternalPlay.cpp
+++ b/media/libaaudio/src/client/AudioStreamInternalPlay.cpp
@@ -18,6 +18,10 @@
 //#define LOG_NDEBUG 0
 #include <utils/Log.h>
 
+#define ATRACE_TAG ATRACE_TAG_AUDIO
+
+#include <utils/Trace.h>
+
 #include "client/AudioStreamInternalPlay.h"
 #include "utility/AudioClock.h"
 
@@ -99,6 +103,10 @@
         return result;
     }
 
+    const char *traceName = "aaWrNow";
+    ATRACE_BEGIN(traceName);
+
+    // If a DMA channel or DSP is reading the other end then we have to update the readCounter.
     if (mAudioEndpoint.isFreeRunning()) {
         // Update data queue based on the timing model.
         int64_t estimatedReadCounter = mClockModel.convertTimeToPosition(currentNanoTime);
@@ -108,10 +116,10 @@
 
     // If the read index passed the write index then consider it an underrun.
     if (mAudioEndpoint.getFullFramesAvailable() < 0) {
-        ALOGV("AudioStreamInternal::processDataNow() - XRun! write = %d, read = %d",
-              (int)mAudioEndpoint.getDataWriteCounter(),
-              (int)mAudioEndpoint.getDataReadCounter());
         mXRunCount++;
+        if (ATRACE_ENABLED()) {
+            ATRACE_INT("aaUnderRuns", mXRunCount);
+        }
     }
 
     // Write some data to the buffer.
@@ -119,6 +127,9 @@
     int32_t framesWritten = writeNowWithConversion(buffer, numFrames);
     //ALOGD("AudioStreamInternal::processDataNow() - tried to write %d frames, wrote %d",
     //    numFrames, framesWritten);
+    if (ATRACE_ENABLED()) {
+        ATRACE_INT("aaWrote", framesWritten);
+    }
 
     // Calculate an ideal time to wake up.
     if (wakeTimePtr != nullptr && framesWritten >= 0) {
@@ -135,14 +146,15 @@
                     wakeTime = currentNanoTime;
                 }
                 break;
-            case AAUDIO_STREAM_STATE_STARTED:   // When do we expect the next read burst to occur?
+            case AAUDIO_STREAM_STATE_STARTED:
             {
-                uint32_t burstSize = mFramesPerBurst;
-                if (burstSize < 32) {
-                    burstSize = 32; // TODO review
-                }
+                // When do we expect the next read burst to occur?
 
-                uint64_t nextReadPosition = mAudioEndpoint.getDataReadCounter() + burstSize;
+                // Calculate frame position based off of the writeCounter because
+                // the readCounter might have just advanced in the background,
+                // causing us to sleep until a later burst.
+                int64_t nextReadPosition = mAudioEndpoint.getDataWriteCounter() + mFramesPerBurst
+                        - mAudioEndpoint.getBufferSizeInFrames();
                 wakeTime = mClockModel.convertPositionToTime(nextReadPosition);
             }
                 break;
@@ -152,10 +164,8 @@
         *wakeTimePtr = wakeTime;
 
     }
-//    ALOGD("AudioStreamInternal::processDataNow finished: now = %llu, read# = %llu, wrote# = %llu",
-//         (unsigned long long)currentNanoTime,
-//         (unsigned long long)mAudioEndpoint.getDataReadCounter(),
-//         (unsigned long long)mAudioEndpoint.getDownDataWriteCounter());
+
+    ATRACE_END();
     return framesWritten;
 }
 
@@ -170,7 +180,7 @@
 
     mAudioEndpoint.getEmptyFramesAvailable(&wrappingBuffer);
 
-    // Read data in one or two parts.
+    // Write data in one or two parts.
     int partIndex = 0;
     while (framesLeft > 0 && partIndex < WrappingBuffer::SIZE) {
         int32_t framesToWrite = framesLeft;
@@ -291,6 +301,7 @@
     aaudio_data_callback_result_t callbackResult = AAUDIO_CALLBACK_RESULT_CONTINUE;
     AAudioStream_dataCallback appCallback = getDataCallbackProc();
     if (appCallback == nullptr) return NULL;
+    int64_t timeoutNanos = calculateReasonableTimeout(mCallbackFrames);
 
     // result might be a frame count
     while (mCallbackEnabled.load() && isActive() && (result >= 0)) {
@@ -302,10 +313,7 @@
                 mCallbackFrames);
 
         if (callbackResult == AAUDIO_CALLBACK_RESULT_CONTINUE) {
-            // Write audio data to stream.
-            int64_t timeoutNanos = calculateReasonableTimeout(mCallbackFrames);
-
-            // This is a BLOCKING WRITE!
+            // Write audio data to stream. This is a BLOCKING WRITE!
             result = write(mCallbackBuffer, mCallbackFrames, timeoutNanos);
             if ((result != mCallbackFrames)) {
                 ALOGE("AudioStreamInternalPlay(): callbackLoop: write() returned %d", result);