Remove timing jitter during startup of audio

This fixes a regression introduced recently, that increased timing jitter
during the startup of the FastMixer and AudioTrack callback threads.

The regression was to make requestPriority() asynchronous as a way to
avoid an apparent priority inversion in system_server.  This means that
the target thread could run briefly with the initial priority, before
the new priority takes effect.

This change removes the startup jitter for FastMixer, by making the
requestPriority() synchronous again for that case.  It doesn't matter
that this restores the priority inversion involving normal mixer thread,
because it happens during startup of both threads.

The change also removes the startup jitter for the AudioTrack callback
thread, by having the target thread check whether the requestPriority()
has completed yet.  If not, the target thread blocks with a timeout
until the priority boost finishes.

Finally, we now log an error message if the expected priority boost
doesn't happen.

Bug: 8698989
Change-Id: Id590e9a274b70ec1ba85b44a585ee37a22e41cbc

6 files changed, 17 insertions, 7 deletions

diff --git a/services/audioflinger/FastMixer.cpp b/services/audioflinger/FastMixer.cpp
index 24a6dfe..21df1d7 100644
--- a/services/audioflinger/FastMixer.cpp
+++ b/services/audioflinger/FastMixer.cpp
@@ -170,6 +170,10 @@ bool FastMixer::threadLoop()
                 if (old <= 0) {
                     __futex_syscall4(coldFutexAddr, FUTEX_WAIT_PRIVATE, old - 1, NULL);
                 }
+                int policy = sched_getscheduler(0);
+                if (!(policy == SCHED_FIFO || policy == SCHED_RR)) {
+                    ALOGE("did not receive expected priority boost");
+                }
                 // This may be overly conservative; there could be times that the normal mixer
                 // requests such a brief cold idle that it doesn't require resetting this flag.
                 isWarm = false;
diff --git a/services/audioflinger/ISchedulingPolicyService.cpp b/services/audioflinger/ISchedulingPolicyService.cpp
index 218aa6b..0079968 100644
--- a/services/audioflinger/ISchedulingPolicyService.cpp
+++ b/services/audioflinger/ISchedulingPolicyService.cpp
@@ -37,14 +37,15 @@ public:
     {
     }
 
-    virtual int requestPriority(int32_t pid, int32_t tid, int32_t prio)
+    virtual int requestPriority(int32_t pid, int32_t tid, int32_t prio, bool asynchronous)
     {
         Parcel data, reply;
         data.writeInterfaceToken(ISchedulingPolicyService::getInterfaceDescriptor());
         data.writeInt32(pid);
         data.writeInt32(tid);
         data.writeInt32(prio);
-        remote()->transact(REQUEST_PRIORITY_TRANSACTION, data, &reply, IBinder::FLAG_ONEWAY);
+        uint32_t flags = asynchronous ? IBinder::FLAG_ONEWAY : 0;
+        remote()->transact(REQUEST_PRIORITY_TRANSACTION, data, &reply, flags);
         // fail on exception
         if (reply.readExceptionCode() != 0) return -1;
         return reply.readInt32();
diff --git a/services/audioflinger/ISchedulingPolicyService.h b/services/audioflinger/ISchedulingPolicyService.h
index a38e67e..b94b191 100644
--- a/services/audioflinger/ISchedulingPolicyService.h
+++ b/services/audioflinger/ISchedulingPolicyService.h
@@ -27,7 +27,7 @@ public:
     DECLARE_META_INTERFACE(SchedulingPolicyService);
 
     virtual int         requestPriority(/*pid_t*/int32_t pid, /*pid_t*/int32_t tid,
-                                                int32_t prio) = 0;
+                                                int32_t prio, bool asynchronous) = 0;
 
 };
 
diff --git a/services/audioflinger/SchedulingPolicyService.cpp b/services/audioflinger/SchedulingPolicyService.cpp
index 59cc99a..36e62e9 100644
--- a/services/audioflinger/SchedulingPolicyService.cpp
+++ b/services/audioflinger/SchedulingPolicyService.cpp
@@ -25,7 +25,7 @@ static sp<ISchedulingPolicyService> sSchedulingPolicyService;
 static const String16 _scheduling_policy("scheduling_policy");
 static Mutex sMutex;
 
-int requestPriority(pid_t pid, pid_t tid, int32_t prio)
+int requestPriority(pid_t pid, pid_t tid, int32_t prio, bool asynchronous)
 {
     // FIXME merge duplicated code related to service lookup, caching, and error recovery
     sp<ISchedulingPolicyService> sps;
@@ -46,7 +46,7 @@ int requestPriority(pid_t pid, pid_t tid, int32_t prio)
         }
         sleep(1);
     }
-    return sps->requestPriority(pid, tid, prio);
+    return sps->requestPriority(pid, tid, prio, asynchronous);
 }
 
 }   // namespace android
diff --git a/services/audioflinger/SchedulingPolicyService.h b/services/audioflinger/SchedulingPolicyService.h
index 7ac8454..a9870d4 100644
--- a/services/audioflinger/SchedulingPolicyService.h
+++ b/services/audioflinger/SchedulingPolicyService.h
@@ -21,7 +21,10 @@ namespace android {
 
 // Request elevated priority for thread tid, whose thread group leader must be pid.
 // The priority parameter is currently restricted to either 1 or 2.
-int requestPriority(pid_t pid, pid_t tid, int32_t prio);
+// The asynchronous parameter should be 'true' to return immediately,
+// after the request is enqueued but not necessarily executed.
+// The default value 'false' means to return after request has been enqueued and executed.
+int requestPriority(pid_t pid, pid_t tid, int32_t prio, bool asynchronous = false);
 
 }   // namespace android
 
diff --git a/services/audioflinger/Threads.cpp b/services/audioflinger/Threads.cpp
index 47ca100..539bb4f 100644
--- a/services/audioflinger/Threads.cpp
+++ b/services/audioflinger/Threads.cpp
@@ -373,7 +373,9 @@ void AudioFlinger::ThreadBase::processConfigEvents()
         switch(event->type()) {
             case CFG_EVENT_PRIO: {
                 PrioConfigEvent *prioEvent = static_cast<PrioConfigEvent *>(event);
-                int err = requestPriority(prioEvent->pid(), prioEvent->tid(), prioEvent->prio());
+                // FIXME Need to understand why this has be done asynchronously
+                int err = requestPriority(prioEvent->pid(), prioEvent->tid(), prioEvent->prio(),
+                        true /*asynchronous*/);
                 if (err != 0) {
                     ALOGW("Policy SCHED_FIFO priority %d is unavailable for pid %d tid %d; "
                           "error %d",