Spatializer: Log latency requests to/from output sink

Test: verify latency commands sent
Bug: 259477444
Change-Id: Iaa45dab95add534fc668d6b8c45492f82fa9bfc6
diff --git a/services/audioflinger/Threads.cpp b/services/audioflinger/Threads.cpp
index 211bf71..df05a18 100644
--- a/services/audioflinger/Threads.cpp
+++ b/services/audioflinger/Threads.cpp
@@ -269,6 +269,23 @@
     return ss.str();
 }
 
+static std::string toString(audio_latency_mode_t mode) {
+    // We convert to the AIDL type to print (eventually the legacy type will be removed).
+    const auto result = legacy2aidl_audio_latency_mode_t_LatencyMode(mode);
+    return result.has_value() ? media::toString(*result) : "UNKNOWN";
+}
+
+// Could be made a template, but other toString overloads for std::vector are confused.
+static std::string toString(const std::vector<audio_latency_mode_t>& elements) {
+    std::string s("{ ");
+    for (const auto& e : elements) {
+        s.append(toString(e));
+        s.append(" ");
+    }
+    s.append("}");
+    return s;
+}
+
 static pthread_once_t sFastTrackMultiplierOnce = PTHREAD_ONCE_INIT;
 
 static void sFastTrackMultiplierInit()
@@ -7347,10 +7364,13 @@
 
 void AudioFlinger::SpatializerThread::updateHalSupportedLatencyModes_l() {
     std::vector<audio_latency_mode_t> latencyModes;
-    if (mOutput->stream->getRecommendedLatencyModes(&latencyModes) != NO_ERROR) {
+    const status_t status = mOutput->stream->getRecommendedLatencyModes(&latencyModes);
+    if (status != NO_ERROR) {
         latencyModes.clear();
     }
     if (latencyModes != mSupportedLatencyModes) {
+        ALOGD("%s: thread(%d) status %d supported latency modes: %s",
+            __func__, mId, status, toString(latencyModes).c_str());
         mSupportedLatencyModes.swap(latencyModes);
         sendHalLatencyModesChangedEvent_l();
     }
@@ -7390,6 +7410,8 @@
 
     if (latencyMode != mSetLatencyMode) {
         status_t status = mOutput->stream->setLatencyMode(latencyMode);
+        ALOGD("%s: thread(%d) setLatencyMode(%s) returned %d",
+                __func__, mId, toString(latencyMode).c_str(), status);
         if (status == NO_ERROR) {
             mSetLatencyMode = latencyMode;
         }
diff --git a/services/audiopolicy/service/Spatializer.cpp b/services/audiopolicy/service/Spatializer.cpp
index 38ad494..ad76202 100644
--- a/services/audiopolicy/service/Spatializer.cpp
+++ b/services/audiopolicy/service/Spatializer.cpp
@@ -963,7 +963,10 @@
         }
     }
     if (mOutput != AUDIO_IO_HANDLE_NONE && supportsSetLatencyMode) {
-        AudioSystem::setRequestedLatencyMode(mOutput, requestedLatencyMode);
+        const status_t status =
+                AudioSystem::setRequestedLatencyMode(mOutput, requestedLatencyMode);
+        ALOGD("%s: setRequestedLatencyMode for output thread(%d) to %s returned %d",
+                __func__, mOutput, toString(requestedLatencyMode).c_str(), status);
     }
 }
 
diff --git a/services/audiopolicy/service/Spatializer.h b/services/audiopolicy/service/Spatializer.h
index bcbd92b..7415b1e 100644
--- a/services/audiopolicy/service/Spatializer.h
+++ b/services/audiopolicy/service/Spatializer.h
@@ -165,14 +165,10 @@
     std::string toString(unsigned level) const NO_THREAD_SAFETY_ANALYSIS;
 
     static std::string toString(audio_latency_mode_t mode) {
-        switch (mode) {
-            case AUDIO_LATENCY_MODE_FREE:
-                return "LATENCY_MODE_FREE";
-            case AUDIO_LATENCY_MODE_LOW:
-                return "LATENCY_MODE_LOW";
-        }
-        return "EnumNotImplemented";
-    };
+        // We convert to the AIDL type to print (eventually the legacy type will be removed).
+        const auto result = legacy2aidl_audio_latency_mode_t_LatencyMode(mode);
+        return result.has_value() ? media::toString(*result) : "unknown_latency_mode";
+    }
 
     /**
      * Format head to stage vector to a string, [0.00, 0.00, 0.00, -1.29, -0.50, 15.27].