AudioTrack: Fix timestamp startup condition

Suppress timestamps without valid kernel information or
a server update.

Update timing of server timestamp location to better indicate
when the server pull occurs.

Update write timing logic to suppress unneeded time calls
and to ensure proper throttling.

Bug: 28771691
Change-Id: I2cd25dad638ca1d0b1355d87d175d908f3bddb26
diff --git a/media/libmedia/AudioTrack.cpp b/media/libmedia/AudioTrack.cpp
index f206f5c..1963da3 100644
--- a/media/libmedia/AudioTrack.cpp
+++ b/media/libmedia/AudioTrack.cpp
@@ -2390,6 +2390,9 @@
                     } else {
                         timestamp.mPosition = (uint32_t)(ets.mPosition[location] - frames);
                     }
+                } else if (location == ExtendedTimestamp::LOCATION_KERNEL) {
+                    ALOGV_IF(mPreviousLocation == ExtendedTimestamp::LOCATION_SERVER,
+                            "getTimestamp() location moved from server to kernel");
                 }
                 mPreviousLocation = location;
             } else {
diff --git a/services/audioflinger/Threads.cpp b/services/audioflinger/Threads.cpp
index 9fe61702..3759424 100644
--- a/services/audioflinger/Threads.cpp
+++ b/services/audioflinger/Threads.cpp
@@ -1576,7 +1576,7 @@
         mActiveTracksGeneration(0),
         // mStreamTypes[] initialized in constructor body
         mOutput(output),
-        mLastWriteTime(0), mNumWrites(0), mNumDelayedWrites(0), mInWrite(false),
+        mLastWriteTime(-1), mNumWrites(0), mNumDelayedWrites(0), mInWrite(false),
         mMixerStatus(MIXER_IDLE),
         mMixerStatusIgnoringFastTracks(MIXER_IDLE),
         mStandbyDelayNs(AudioFlinger::mStandbyTimeInNsecs),
@@ -2537,8 +2537,6 @@
 // shared by MIXER and DIRECT, overridden by DUPLICATING
 ssize_t AudioFlinger::PlaybackThread::threadLoop_write()
 {
-    // FIXME rewrite to reduce number of system calls
-    mLastWriteTime = systemTime();
     mInWrite = true;
     ssize_t bytesWritten;
     const size_t offset = mCurrentWriteLength - mBytesRemaining;
@@ -2834,6 +2832,8 @@
     Vector< sp<Track> > tracksToRemove;
 
     mStandbyTimeNs = systemTime();
+    nsecs_t lastWriteFinished = -1; // time last server write completed
+    int64_t lastFramesWritten = -1; // track changes in timestamp server frames written
 
     // MIXER
     nsecs_t lastWarning = 0;
@@ -2884,10 +2884,11 @@
             // 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;
             if (mNormalSink != 0) {
                 // Note: The DuplicatingThread may not have a mNormalSink.
                 // We always fetch the timestamp here because often the downstream
-                // sink will block whie writing.
+                // sink will block while writing.
                 ExtendedTimestamp timestamp; // use private copy to fetch
                 (void) mNormalSink->getTimestamp(timestamp);
 
@@ -2904,6 +2905,10 @@
                             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 {
                     ALOGV("getTimestamp error - no valid kernel position");
                 }
@@ -2917,16 +2922,33 @@
             // mFramesWritten for non-offloaded tracks are contiguous
             // even after standby() is called. This is useful for the track frame
             // to sink frame mapping.
-            mTimestamp.mPosition[ExtendedTimestamp::LOCATION_SERVER] = mFramesWritten;
-            mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_SERVER] = systemTime();
-            const size_t size = mActiveTracks.size();
-            for (size_t i = 0; i < size; ++i) {
-                sp<Track> t = mActiveTracks[i].promote();
-                if (t != 0 && !t->isFastTrack()) {
-                    t->updateTrackFrameInfo(
-                            t->mAudioTrackServerProxy->framesReleased(),
-                            mFramesWritten,
-                            mTimestamp);
+            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, mLastWriteTime will be -1
+                    // and we use systemTime().
+                    mTimestamp.mPosition[ExtendedTimestamp::LOCATION_SERVER] = mFramesWritten;
+                    mTimestamp.mTimeNs[ExtendedTimestamp::LOCATION_SERVER] = mLastWriteTime == -1
+                            ? systemTime() : mLastWriteTime;
+                }
+                const size_t size = mActiveTracks.size();
+                for (size_t i = 0; i < size; ++i) {
+                    sp<Track> t = mActiveTracks[i].promote();
+                    if (t != 0 && !t->isFastTrack()) {
+                        t->updateTrackFrameInfo(
+                                t->mAudioTrackServerProxy->framesReleased(),
+                                mFramesWritten,
+                                mTimestamp);
+                    }
                 }
             }
 
@@ -3104,8 +3126,17 @@
             // mSleepTimeUs == 0 means we must write to audio hardware
             if (mSleepTimeUs == 0) {
                 ssize_t ret = 0;
+                // We save lastWriteFinished here, as previousLastWriteFinished,
+                // for throttling. On thread start, previousLastWriteFinished will be
+                // set to -1, which properly results in no throttling after the first write.
+                nsecs_t previousLastWriteFinished = lastWriteFinished;
+                nsecs_t delta = 0;
                 if (mBytesRemaining) {
+                    // FIXME rewrite to reduce number of system calls
+                    mLastWriteTime = systemTime();  // also used for dumpsys
                     ret = threadLoop_write();
+                    lastWriteFinished = systemTime();
+                    delta = lastWriteFinished - mLastWriteTime;
                     if (ret < 0) {
                         mBytesRemaining = 0;
                     } else {
@@ -3119,15 +3150,13 @@
                 }
                 if (mType == MIXER && !mStandby) {
                     // write blocked detection
-                    nsecs_t now = systemTime();
-                    nsecs_t delta = now - mLastWriteTime;
                     if (delta > maxPeriod) {
                         mNumDelayedWrites++;
-                        if ((now - lastWarning) > kWarningThrottleNs) {
+                        if ((lastWriteFinished - lastWarning) > kWarningThrottleNs) {
                             ATRACE_NAME("underrun");
                             ALOGW("write blocked for %llu msecs, %d delayed writes, thread %p",
                                     (unsigned long long) ns2ms(delta), mNumDelayedWrites, this);
-                            lastWarning = now;
+                            lastWarning = lastWriteFinished;
                         }
                     }
 
@@ -3147,7 +3176,9 @@
                         // (2) minimum buffer sized tracks (even if the track is full,
                         //     the app won't fill fast enough to handle the sudden draw).
 
-                        const int32_t deltaMs = delta / 1000000;
+                        // it's OK if deltaMs is an overestimate.
+                        const int32_t deltaMs =
+                                (lastWriteFinished - previousLastWriteFinished) / 1000000;
                         const int32_t throttleMs = mHalfBufferMs - deltaMs;
                         if ((signed)mHalfBufferMs >= throttleMs && throttleMs > 0) {
                             usleep(throttleMs * 1000);