From 5b506f21b1bf4e49cbcb341b46881a77e2f98bf7 Mon Sep 17 00:00:00 2001
From: Mikhail Naganov <mnaganov@google.com>
Date: Wed, 19 Jul 2017 17:54:29 -0700
Subject: [PATCH] audio effects: Eliminate the cause warning logs about
 unreleased interface

The cause of frequent "EffectModule 0xxx destructor called with unreleased
interface" messages was due to not releasing the effects when purging
stale effects.

The cause of "Effect handle 0xxx disconnected after thread destruction"
message was due to late binder call for disconnecting already purged
effect handle.

Also improved logging to communicate uuids of the effects causing
these issues.

Bug: 62267926
Test: no aforementioned warnings in the log when opening the Effects
      panel in Play Music

Change-Id: I6ec6f60c46dc704226931fb59a641e4cd74c2fd1
(cherry picked from commit 424c4f5b76a6ed11f2c713b42246a7220cfbb240)
---
 media/libaudioclient/AudioEffect.cpp   |  6 +++++-
 services/audioflinger/AudioFlinger.cpp |  2 +-
 services/audioflinger/Effects.cpp      | 27 ++++++++++++--------------
 3 files changed, 18 insertions(+), 17 deletions(-)

diff --git a/media/libaudioclient/AudioEffect.cpp b/media/libaudioclient/AudioEffect.cpp
index a5f9ab6874..b1cb0e7bdd 100644
--- a/media/libaudioclient/AudioEffect.cpp
+++ b/media/libaudioclient/AudioEffect.cpp
@@ -135,7 +135,11 @@ status_t AudioEffect::set(const effect_uuid_t *type,
             &mStatus, &mId, &enabled);
 
     if (iEffect == 0 || (mStatus != NO_ERROR && mStatus != ALREADY_EXISTS)) {
-        ALOGE("set(): AudioFlinger could not create effect, status: %d", mStatus);
+        char typeBuffer[64], uuidBuffer[64];
+        guidToString(type, typeBuffer, sizeof(typeBuffer));
+        guidToString(uuid, uuidBuffer, sizeof(uuidBuffer));
+        ALOGE("set(): AudioFlinger could not create effect %s / %s, status: %d",
+                typeBuffer, uuidBuffer, mStatus);
         if (iEffect == 0) {
             mStatus = NO_INIT;
         }
diff --git a/services/audioflinger/AudioFlinger.cpp b/services/audioflinger/AudioFlinger.cpp
index a15b256caa..13522f5b71 100644
--- a/services/audioflinger/AudioFlinger.cpp
+++ b/services/audioflinger/AudioFlinger.cpp
@@ -2603,7 +2603,7 @@ void AudioFlinger::purgeStaleEffects_l() {
             while (ec->mEffects.size()) {
                 sp<EffectModule> effect = ec->mEffects[0];
                 effect->unPin();
-                t->removeEffect_l(effect);
+                t->removeEffect_l(effect, /*release*/ true);
                 if (effect->purgeHandles()) {
                     t->checkSuspendOnEffectEnabled_l(effect, false, effect->sessionId());
                 }
diff --git a/services/audioflinger/Effects.cpp b/services/audioflinger/Effects.cpp
index f2c1c4fbce..bd5f146a82 100644
--- a/services/audioflinger/Effects.cpp
+++ b/services/audioflinger/Effects.cpp
@@ -25,6 +25,7 @@
 #include <system/audio_effects/effect_ns.h>
 #include <system/audio_effects/effect_visualizer.h>
 #include <audio_utils/primitives.h>
+#include <media/AudioEffect.h>
 #include <media/audiohal/EffectHalInterface.h>
 #include <media/audiohal/EffectsFactoryHalInterface.h>
 
@@ -109,7 +110,10 @@ AudioFlinger::EffectModule::~EffectModule()
 {
     ALOGV("Destructor %p", this);
     if (mEffectInterface != 0) {
-        ALOGW("EffectModule %p destructor called with unreleased interface", this);
+        char uuidStr[64];
+        AudioEffect::guidToString(&mDescriptor.uuid, uuidStr, sizeof(uuidStr));
+        ALOGW("EffectModule %p destructor called with unreleased interface, effect %s",
+                this, uuidStr);
         release_l();
     }
 
@@ -1081,18 +1085,12 @@ void AudioFlinger::EffectModule::dump(int fd, const Vector<String16>& args __unu
     result.append(buffer);
 
     result.append("\t\tDescriptor:\n");
-    snprintf(buffer, SIZE, "\t\t- UUID: %08X-%04X-%04X-%04X-%02X%02X%02X%02X%02X%02X\n",
-            mDescriptor.uuid.timeLow, mDescriptor.uuid.timeMid, mDescriptor.uuid.timeHiAndVersion,
-            mDescriptor.uuid.clockSeq, mDescriptor.uuid.node[0], mDescriptor.uuid.node[1],
-                    mDescriptor.uuid.node[2],
-            mDescriptor.uuid.node[3],mDescriptor.uuid.node[4],mDescriptor.uuid.node[5]);
+    char uuidStr[64];
+    AudioEffect::guidToString(&mDescriptor.uuid, uuidStr, sizeof(uuidStr));
+    snprintf(buffer, SIZE, "\t\t- UUID: %s\n", uuidStr);
     result.append(buffer);
-    snprintf(buffer, SIZE, "\t\t- TYPE: %08X-%04X-%04X-%04X-%02X%02X%02X%02X%02X%02X\n",
-                mDescriptor.type.timeLow, mDescriptor.type.timeMid,
-                    mDescriptor.type.timeHiAndVersion,
-                mDescriptor.type.clockSeq, mDescriptor.type.node[0], mDescriptor.type.node[1],
-                    mDescriptor.type.node[2],
-                mDescriptor.type.node[3],mDescriptor.type.node[4],mDescriptor.type.node[5]);
+    AudioEffect::guidToString(&mDescriptor.type, uuidStr, sizeof(uuidStr));
+    snprintf(buffer, SIZE, "\t\t- TYPE: %s\n", uuidStr);
     result.append(buffer);
     snprintf(buffer, SIZE, "\t\t- apiVersion: %08X\n\t\t- flags: %08X (%s)\n",
             mDescriptor.apiVersion,
@@ -1306,11 +1304,10 @@ void AudioFlinger::EffectHandle::disconnect(bool unpinIfLast)
     if (thread != 0) {
         thread->disconnectEffectHandle(this, unpinIfLast);
     } else {
-        ALOGW("%s Effect handle %p disconnected after thread destruction", __FUNCTION__, this);
         // try to cleanup as much as we can
         sp<EffectModule> effect = mEffect.promote();
-        if (effect != 0) {
-            effect->disconnectHandle(this, unpinIfLast);
+        if (effect != 0 && effect->disconnectHandle(this, unpinIfLast) > 0) {
+            ALOGW("%s Effect handle %p disconnected after thread destruction", __FUNCTION__, this);
         }
     }