Spatializer dumpsys: Add parameters and local logs in dumpsys

Bug: 233092747
Test: m and "adb shell dumpsys media.audio_policy"

Change-Id: Idbcd4686987e48511302cb3afed8e8035b2a502c
Merged-In: Idbcd4686987e48511302cb3afed8e8035b2a502c
(cherry picked from commit afc0c2ec992ed1e301a98643d83326198bff4dc8)
diff --git a/media/libheadtracking/Android.bp b/media/libheadtracking/Android.bp
index 9d63f9b..7e2c762 100644
--- a/media/libheadtracking/Android.bp
+++ b/media/libheadtracking/Android.bp
@@ -22,6 +22,10 @@
       "StillnessDetector.cpp",
       "Twist.cpp",
     ],
+    shared_libs: [
+        "libaudioutils",
+        "libbase",
+    ],
     export_include_dirs: [
         "include",
     ],
@@ -39,6 +43,7 @@
       "SensorPoseProvider.cpp",
     ],
     shared_libs: [
+        "libbase",
         "libheadtracking",
         "liblog",
         "libsensor",
diff --git a/media/libheadtracking/HeadTrackingProcessor.cpp b/media/libheadtracking/HeadTrackingProcessor.cpp
index 71fae8a..fb44567 100644
--- a/media/libheadtracking/HeadTrackingProcessor.cpp
+++ b/media/libheadtracking/HeadTrackingProcessor.cpp
@@ -13,7 +13,10 @@
  * See the License for the specific language governing permissions and
  * limitations under the License.
  */
+#include <inttypes.h>
 
+#include <android-base/stringprintf.h>
+#include <audio_utils/SimpleLog.h>
 #include "media/HeadTrackingProcessor.h"
 
 #include "ModeSelector.h"
@@ -26,6 +29,7 @@
 namespace media {
 namespace {
 
+using android::base::StringAppendF;
 using Eigen::Quaternionf;
 using Eigen::Vector3f;
 
@@ -136,10 +140,12 @@
         if (recenterHead) {
             mHeadPoseBias.recenter();
             mHeadStillnessDetector.reset();
+            mLocalLog.log("recenter Head");
         }
         if (recenterScreen) {
             mScreenPoseBias.recenter();
             mScreenStillnessDetector.reset();
+            mLocalLog.log("recenter Screen");
         }
 
         // If a sensor being recentered is included in the current mode, apply rate limiting to
@@ -152,6 +158,35 @@
         }
     }
 
+    std::string toString_l(unsigned level) const override {
+        std::string prefixSpace(level, ' ');
+        std::string ss = prefixSpace + "HeadTrackingProcessor:\n";
+        StringAppendF(&ss, "%smaxTranslationalVelocity: %f\n", prefixSpace.c_str(),
+                      mOptions.maxTranslationalVelocity);
+        StringAppendF(&ss, "%smaxRotationalVelocity: %f\n", prefixSpace.c_str(),
+                      mOptions.maxRotationalVelocity);
+        StringAppendF(&ss, "%sfreshnessTimeout: %" PRId64 "\n", prefixSpace.c_str(),
+                      mOptions.freshnessTimeout);
+        StringAppendF(&ss, "%spredictionDuration: %f\n", prefixSpace.c_str(),
+                      mOptions.predictionDuration);
+        StringAppendF(&ss, "%sautoRecenterWindowDuration: %" PRId64 "\n", prefixSpace.c_str(),
+                      mOptions.autoRecenterWindowDuration);
+        StringAppendF(&ss, "%sautoRecenterTranslationalThreshold: %f\n", prefixSpace.c_str(),
+                      mOptions.autoRecenterTranslationalThreshold);
+        StringAppendF(&ss, "%sautoRecenterRotationalThreshold: %f\n", prefixSpace.c_str(),
+                      mOptions.autoRecenterRotationalThreshold);
+        StringAppendF(&ss, "%sscreenStillnessWindowDuration: %" PRId64 "\n", prefixSpace.c_str(),
+                      mOptions.screenStillnessWindowDuration);
+        StringAppendF(&ss, "%sscreenStillnessTranslationalThreshold: %f\n", prefixSpace.c_str(),
+                      mOptions.screenStillnessTranslationalThreshold);
+        StringAppendF(&ss, "%sscreenStillnessRotationalThreshold: %f\n", prefixSpace.c_str(),
+                      mOptions.screenStillnessRotationalThreshold);
+        ss.append(prefixSpace + "ReCenterHistory:\n");
+        ss += mLocalLog.dumpToString((prefixSpace + " ").c_str(), mMaxLocalLogLine);
+        // TODO: 233092747 add string from PoseRateLimiter/PoseRateLimiter etc...
+        return ss;
+    }
+
   private:
     const Options mOptions;
     float mPhysicalToLogicalAngle = 0;
@@ -168,6 +203,8 @@
     ScreenHeadFusion mScreenHeadFusion;
     ModeSelector mModeSelector;
     PoseRateLimiter mRateLimiter;
+    static constexpr std::size_t mMaxLocalLogLine = 10;
+    SimpleLog mLocalLog{mMaxLocalLogLine};
 };
 
 }  // namespace
diff --git a/media/libheadtracking/SensorPoseProvider.cpp b/media/libheadtracking/SensorPoseProvider.cpp
index e5e1521..6c0a96d 100644
--- a/media/libheadtracking/SensorPoseProvider.cpp
+++ b/media/libheadtracking/SensorPoseProvider.cpp
@@ -24,6 +24,7 @@
 #include <map>
 #include <thread>
 
+#include <android-base/stringprintf.h>
 #include <android-base/thread_annotations.h>
 #include <log/log_main.h>
 #include <sensor/SensorEventQueue.h>
@@ -36,6 +37,8 @@
 namespace media {
 namespace {
 
+using android::base::StringAppendF;
+
 // Identifier to use for our event queue on the loop.
 // The number 19 is arbitrary, only useful if using multiple objects on the same looper.
 constexpr int kIdent = 19;
@@ -153,6 +156,38 @@
         mEnabledSensorsExtra.erase(handle);
     }
 
+    std::string toString(unsigned level) override {
+        std::string prefixSpace(level, ' ');
+        std::string ss = prefixSpace + "SensorPoseProvider:\n";
+        bool needUnlock = false;
+
+        prefixSpace += " ";
+        auto now = std::chrono::steady_clock::now();
+        if (!mMutex.try_lock_until(now + media::kSpatializerDumpSysTimeOutInSecond)) {
+            ss.append(prefixSpace).append("try_lock failed, dumpsys below maybe INACCURATE!\n");
+        } else {
+            needUnlock = true;
+        }
+
+        // Enabled sensor information
+        StringAppendF(&ss, "%sSensors total number %zu:\n", prefixSpace.c_str(),
+                      mEnabledSensorsExtra.size());
+        for (auto sensor : mEnabledSensorsExtra) {
+            StringAppendF(&ss, "%s[Handle: 0x%08x, Format %s", prefixSpace.c_str(), sensor.first,
+                          toString(sensor.second.format).c_str());
+            if (sensor.second.discontinuityCount.has_value()) {
+                StringAppendF(&ss, ", DiscontinuityCount: %d",
+                              sensor.second.discontinuityCount.value());
+            }
+            ss += "]\n";
+        }
+
+        if (needUnlock) {
+            mMutex.unlock();
+        }
+        return ss;
+    }
+
   private:
     enum DataFormat {
         kUnknown,
@@ -174,7 +209,7 @@
     sp<Looper> mLooper;
     Listener* const mListener;
     SensorManager* const mSensorManager;
-    std::mutex mMutex;
+    std::timed_mutex mMutex;
     std::map<int32_t, SensorEnableGuard> mEnabledSensors;
     std::map<int32_t, SensorExtra> mEnabledSensorsExtra GUARDED_BY(mMutex);
     sp<SensorEventQueue> mQueue;
@@ -193,7 +228,6 @@
           mSensorManager(&SensorManager::getInstanceForPackage(String16(packageName))) {
         mThread = std::thread([this] { threadFunc(); });
     }
-
     void initFinished(bool success) { mInitPromise.set_value(success); }
 
     bool waitInitFinished() { return mInitPromise.get_future().get(); }
@@ -346,6 +380,19 @@
                 LOG_ALWAYS_FATAL("Unexpected sensor type: %d", static_cast<int>(format));
         }
     }
+
+    const std::string toString(DataFormat format) {
+        switch (format) {
+            case DataFormat::kUnknown:
+                return "kUnknown";
+            case DataFormat::kQuaternion:
+                return "kQuaternion";
+            case DataFormat::kRotationVectorsAndDiscontinuityCount:
+                return "kRotationVectorsAndDiscontinuityCount";
+            default:
+                return "NotImplemented";
+        }
+    }
 };
 
 }  // namespace
diff --git a/media/libheadtracking/include/media/HeadTrackingProcessor.h b/media/libheadtracking/include/media/HeadTrackingProcessor.h
index 1744be3..8ef8ab0 100644
--- a/media/libheadtracking/include/media/HeadTrackingProcessor.h
+++ b/media/libheadtracking/include/media/HeadTrackingProcessor.h
@@ -96,8 +96,12 @@
      * This causes the current poses for both the head and/or screen to be considered "center".
      */
     virtual void recenter(bool recenterHead = true, bool recenterScreen = true) = 0;
-};
 
+    /**
+     * Dump HeadTrackingProcessor parameters under caller lock.
+     */
+    virtual std::string toString_l(unsigned level) const = 0;
+};
 /**
  * Creates an instance featuring a default implementation of the HeadTrackingProcessor interface.
  */
diff --git a/media/libheadtracking/include/media/SensorPoseProvider.h b/media/libheadtracking/include/media/SensorPoseProvider.h
index 0f42074..4609e0c 100644
--- a/media/libheadtracking/include/media/SensorPoseProvider.h
+++ b/media/libheadtracking/include/media/SensorPoseProvider.h
@@ -28,6 +28,9 @@
 namespace android {
 namespace media {
 
+// Timeout for Spatializer dumpsys trylock, don't block for more than 3 seconds.
+constexpr auto kSpatializerDumpSysTimeOutInSecond = std::chrono::seconds(3);
+
 /**
  * A utility providing streaming of pose data from motion sensors provided by the Sensor Framework.
  *
@@ -100,6 +103,11 @@
      * discover properties of the sensor.
      */
     virtual std::optional<const Sensor> getSensorByHandle(int32_t handle) = 0;
+
+    /**
+     * Dump SensorPoseProvider parameters and history data.
+     */
+    virtual std::string toString(unsigned level) = 0;
 };
 
 }  // namespace media
diff --git a/services/audiopolicy/service/AudioPolicyService.cpp b/services/audiopolicy/service/AudioPolicyService.cpp
index ce07dcd..550a7c0 100644
--- a/services/audiopolicy/service/AudioPolicyService.cpp
+++ b/services/audiopolicy/service/AudioPolicyService.cpp
@@ -1215,6 +1215,14 @@
 
         dumpReleaseLock(mLock, locked);
 
+        if (mSpatializer != nullptr) {
+            std::string dumpString = mSpatializer->toString(1 /* level */);
+            write(fd, dumpString.c_str(), dumpString.size());
+        } else {
+            String8 spatializerPtr = String8::format("Spatializer no supportted on this device\n");
+            write(fd, spatializerPtr.c_str(), spatializerPtr.size());
+        }
+
         {
             std::string timeCheckStats = getIAudioPolicyServiceStatistics().dump();
             dprintf(fd, "\nIAudioPolicyService binder call profile\n");
diff --git a/services/audiopolicy/service/Spatializer.cpp b/services/audiopolicy/service/Spatializer.cpp
index c199a76..0c61074 100644
--- a/services/audiopolicy/service/Spatializer.cpp
+++ b/services/audiopolicy/service/Spatializer.cpp
@@ -15,11 +15,12 @@
 ** limitations under the License.
 */
 
-
+#include <string>
 #define LOG_TAG "Spatializer"
 //#define LOG_NDEBUG 0
 #include <utils/Log.h>
 
+#include <inttypes.h>
 #include <limits.h>
 #include <stdint.h>
 #include <sys/types.h>
@@ -157,6 +158,41 @@
 };
 
 // ---------------------------------------------------------------------------
+
+// Convert recorded sensor data to string with level indentation.
+std::string Spatializer::HeadToStagePoseRecorder::toString_l(unsigned level) const {
+    std::string prefixSpace(level, ' ');
+    return mPoseRecordLog.dumpToString((prefixSpace + " ").c_str(), Spatializer::mMaxLocalLogLine);
+}
+
+// Compute sensor data, record into local log when it is time.
+void Spatializer::HeadToStagePoseRecorder::record_l(const std::vector<float>& headToStage) {
+    if (headToStage.size() != mPoseVectorSize) return;
+
+    if (mNumOfSampleSinceLastRecord++ == 0) {
+        mFirstSampleTimestamp = std::chrono::steady_clock::now();
+    }
+    // if it's time, do record and reset.
+    if (shouldRecordLog()) {
+        poseSumToAverage();
+        mPoseRecordLog.log(
+                "mean: %s, min: %s, max %s, calculated %d samples",
+                Spatializer::toString<double>(mPoseRadianSum, true /* radianToDegree */).c_str(),
+                Spatializer::toString<float>(mMinPoseAngle, true /* radianToDegree */).c_str(),
+                Spatializer::toString<float>(mMaxPoseAngle, true /* radianToDegree */).c_str(),
+                mNumOfSampleSinceLastRecord);
+        resetRecord(headToStage);
+    }
+    // update stream average.
+    for (int i = 0; i < mPoseVectorSize; i++) {
+        mPoseRadianSum[i] += headToStage[i];
+        mMaxPoseAngle[i] = std::max(mMaxPoseAngle[i], headToStage[i]);
+        mMinPoseAngle[i] = std::min(mMinPoseAngle[i], headToStage[i]);
+    }
+    return;
+}
+
+// ---------------------------------------------------------------------------
 sp<Spatializer> Spatializer::create(SpatializerPolicyCallback *callback) {
     sp<Spatializer> spatializer;
 
@@ -176,18 +212,20 @@
     ALOG_ASSERT(!descriptors.empty(),
             "%s getDescriptors() returned no error but empty list", __func__);
 
-    //TODO: get supported spatialization modes from FX engine or descriptor
-
+    // TODO: get supported spatialization modes from FX engine or descriptor
     sp<EffectHalInterface> effect;
     status = effectsFactoryHal->createEffect(&descriptors[0].uuid, AUDIO_SESSION_OUTPUT_STAGE,
             AUDIO_IO_HANDLE_NONE, AUDIO_PORT_HANDLE_NONE, &effect);
-    ALOGI("%s FX create status %d effect %p", __func__, status, effect.get());
+    ALOGI("%s FX create status %d effect ID %" PRId64, __func__, status,
+          effect ? effect->effectId() : 0);
 
     if (status == NO_ERROR && effect != nullptr) {
         spatializer = new Spatializer(descriptors[0], callback);
         if (spatializer->loadEngineConfiguration(effect) != NO_ERROR) {
             spatializer.clear();
         }
+        spatializer->mLocalLog.log("%s with effect Id %" PRId64, __func__,
+                                   effect ? effect->effectId() : 0);
     }
 
     return spatializer;
@@ -268,6 +306,7 @@
         ALOGW("%s: cannot get SPATIALIZER_PARAM_SUPPORTED_SPATIALIZATION_MODES", __func__);
         return status;
     }
+
     for (const auto spatializationMode : spatializationModes) {
         if (!aidl_utils::isValidEnum(spatializationMode)) {
             ALOGW("%s: ignoring spatializationMode:%d", __func__, (int)spatializationMode);
@@ -366,7 +405,8 @@
 }
 
 Status Spatializer::setLevel(SpatializationLevel level) {
-    ALOGV("%s level %d", __func__, (int)level);
+    ALOGV("%s level %s", __func__, media::toString(level).c_str());
+    mLocalLog.log("%s with %s", __func__, media::toString(level).c_str());
     if (level != SpatializationLevel::NONE
             && std::find(mLevels.begin(), mLevels.end(), level) == mLevels.end()) {
         return binderStatusFromStatusT(BAD_VALUE);
@@ -426,11 +466,12 @@
 }
 
 Status Spatializer::setDesiredHeadTrackingMode(SpatializerHeadTrackingMode mode) {
-    ALOGV("%s mode %d", __func__, (int)mode);
+    ALOGV("%s mode %s", __func__, media::toString(mode).c_str());
 
     if (!mSupportsHeadTracking) {
         return binderStatusFromStatusT(INVALID_OPERATION);
     }
+    mLocalLog.log("%s with %s", __func__, media::toString(mode).c_str());
     std::lock_guard lock(mLock);
     switch (mode) {
         case SpatializerHeadTrackingMode::OTHER:
@@ -485,6 +526,7 @@
     }
     std::lock_guard lock(mLock);
     if (mPoseController != nullptr) {
+        mLocalLog.log("%s with %s", __func__, toString<float>(screenToStage).c_str());
         mPoseController->setScreenToStagePose(maybePose.value());
     }
     return Status::ok();
@@ -520,6 +562,7 @@
     }
     std::lock_guard lock(mLock);
     if (mHeadSensor != sensorHandle) {
+        mLocalLog.log("%s with 0x%08x", __func__, sensorHandle);
         mHeadSensor = sensorHandle;
         checkPoseController_l();
         checkSensorsState_l();
@@ -534,6 +577,7 @@
     }
     std::lock_guard lock(mLock);
     if (mScreenSensor != sensorHandle) {
+        mLocalLog.log("%s with 0x%08x", __func__, sensorHandle);
         mScreenSensor = sensorHandle;
         // TODO: consider a new method setHeadAndScreenSensor()
         // because we generally set both at the same time.
@@ -550,6 +594,7 @@
     }
     std::lock_guard lock(mLock);
     mDisplayOrientation = physicalToLogicalAngle;
+    mLocalLog.log("%s with %f", __func__, physicalToLogicalAngle);
     if (mPoseController != nullptr) {
         mPoseController->setDisplayOrientation(mDisplayOrientation);
     }
@@ -564,6 +609,7 @@
     std::lock_guard lock(mLock);
     ALOGV("%s hingeAngle %f", __func__, hingeAngle);
     if (mEngine != nullptr) {
+        mLocalLog.log("%s with %f", __func__, hingeAngle);
         setEffectParameter_l(SPATIALIZER_PARAM_HINGE_ANGLE, std::vector<float>{hingeAngle});
     }
     return Status::ok();
@@ -650,6 +696,7 @@
         callback = mHeadTrackingCallback;
         if (mEngine != nullptr) {
             setEffectParameter_l(SPATIALIZER_PARAM_HEAD_TO_STAGE, headToStage);
+            mPoseRecorder.record_l(headToStage);
         }
     }
 
@@ -659,7 +706,9 @@
 }
 
 void Spatializer::onActualModeChange(HeadTrackingMode mode) {
-    ALOGV("%s(%d)", __func__, (int)mode);
+    std::string modeStr = SpatializerPoseController::toString(mode);
+    ALOGV("%s(%s)", __func__, modeStr.c_str());
+    mLocalLog.log("%s with %s", __func__, modeStr.c_str());
     sp<AMessage> msg =
             new AMessage(EngineCallbackHandler::kWhatOnActualModeChange, mHandler);
     msg->setInt32(EngineCallbackHandler::kModeKey, static_cast<int>(mode));
@@ -695,6 +744,9 @@
                                  std::vector<SpatializerHeadTrackingMode>{spatializerMode});
         }
         callback = mHeadTrackingCallback;
+        mLocalLog.log("%s: %s, spatializerMode %s", __func__,
+                      SpatializerPoseController::toString(mode).c_str(),
+                      media::toString(spatializerMode).c_str());
     }
     if (callback != nullptr) {
         callback->onHeadTrackingModeChanged(spatializerMode);
@@ -708,6 +760,8 @@
     {
         std::lock_guard lock(mLock);
         ALOGV("%s output %d mOutput %d", __func__, (int)output, (int)mOutput);
+        mLocalLog.log("%s with output %d tracks %zu (mOutput %d)", __func__, (int)output,
+                      numActiveTracks, (int)mOutput);
         if (mOutput != AUDIO_IO_HANDLE_NONE) {
             LOG_ALWAYS_FATAL_IF(mEngine == nullptr, "%s output set without FX engine", __func__);
             // remove FX instance
@@ -752,6 +806,7 @@
 
     {
         std::lock_guard lock(mLock);
+        mLocalLog.log("%s with output %d tracks %zu", __func__, (int)mOutput, mNumActiveTracks);
         ALOGV("%s mOutput %d", __func__, (int)mOutput);
         if (mOutput == AUDIO_IO_HANDLE_NONE) {
             return output;
@@ -774,6 +829,7 @@
 void Spatializer::updateActiveTracks(size_t numActiveTracks) {
     std::lock_guard lock(mLock);
     if (mNumActiveTracks != numActiveTracks) {
+        mLocalLog.log("%s from %zu to %zu", __func__, mNumActiveTracks, numActiveTracks);
         mNumActiveTracks = numActiveTracks;
         checkEngineState_l();
         checkSensorsState_l();
@@ -861,4 +917,75 @@
     msg->post();
 }
 
+std::string Spatializer::toString(unsigned level) const {
+    std::string prefixSpace;
+    prefixSpace.append(level, ' ');
+    std::string ss = prefixSpace + "Spatializer:\n";
+    bool needUnlock = false;
+
+    prefixSpace += ' ';
+    if (!mLock.try_lock()) {
+        // dumpsys even try_lock failed, information dump can be useful although may not accurate
+        ss.append(prefixSpace).append("try_lock failed, dumpsys below maybe INACCURATE!\n");
+    } else {
+        needUnlock = true;
+    }
+
+    // Spatializer class information.
+    // 1. Capabilities (mLevels, mHeadTrackingModes, mSpatializationModes, mChannelMasks, etc)
+    ss.append(prefixSpace).append("Supported levels: [");
+    for (auto& level : mLevels) {
+        base::StringAppendF(&ss, " %s", media::toString(level).c_str());
+    }
+    base::StringAppendF(&ss, "], mLevel: %s", media::toString(mLevel).c_str());
+
+    base::StringAppendF(&ss, "\n%smHeadTrackingModes: [", prefixSpace.c_str());
+    for (auto& mode : mHeadTrackingModes) {
+        base::StringAppendF(&ss, " %s", media::toString(mode).c_str());
+    }
+    base::StringAppendF(&ss, "], Desired: %s, Actual %s\n",
+                        SpatializerPoseController::toString(mDesiredHeadTrackingMode).c_str(),
+                        media::toString(mActualHeadTrackingMode).c_str());
+
+    base::StringAppendF(&ss, "%smSpatializationModes: [", prefixSpace.c_str());
+    for (auto& mode : mSpatializationModes) {
+        base::StringAppendF(&ss, " %s", media::toString(mode).c_str());
+    }
+    ss += "]\n";
+
+    base::StringAppendF(&ss, "%smChannelMasks: ", prefixSpace.c_str());
+    for (auto& mask : mChannelMasks) {
+        base::StringAppendF(&ss, "%s", audio_channel_out_mask_to_string(mask));
+    }
+    base::StringAppendF(&ss, "\n%smSupportsHeadTracking: %s\n", prefixSpace.c_str(),
+                        mSupportsHeadTracking ? "true" : "false");
+    // 2. Settings (Output, tracks)
+    base::StringAppendF(&ss, "%smNumActiveTracks: %zu\n", prefixSpace.c_str(), mNumActiveTracks);
+    base::StringAppendF(&ss, "%sOutputStreamHandle: %d\n", prefixSpace.c_str(), (int)mOutput);
+
+    // 3. Sensors, Effect information.
+    base::StringAppendF(&ss, "%sHeadSensorHandle: 0x%08x\n", prefixSpace.c_str(), mHeadSensor);
+    base::StringAppendF(&ss, "%sScreenSensorHandle: 0x%08x\n", prefixSpace.c_str(), mScreenSensor);
+    base::StringAppendF(&ss, "%sEffectHandle: %p\n", prefixSpace.c_str(), mEngine.get());
+    base::StringAppendF(&ss, "%sDisplayOrientation: %f\n", prefixSpace.c_str(),
+                        mDisplayOrientation);
+
+    ss.append(prefixSpace + "CommandLog:\n");
+    ss += mLocalLog.dumpToString((prefixSpace + " ").c_str(), mMaxLocalLogLine);
+    ss.append(prefixSpace + "SensorLog:\n");
+    ss += mPoseRecorder.toString_l(level + 1);
+
+    // PostController dump.
+    if (mPoseController != nullptr) {
+        ss += mPoseController->toString(level + 1);
+    } else {
+        ss.append(prefixSpace).append("SpatializerPoseController not exist\n");
+    }
+
+    if (needUnlock) {
+        mLock.unlock();
+    }
+    return ss;
+}
+
 } // namespace android
diff --git a/services/audiopolicy/service/Spatializer.h b/services/audiopolicy/service/Spatializer.h
index 29f4b08..7093957 100644
--- a/services/audiopolicy/service/Spatializer.h
+++ b/services/audiopolicy/service/Spatializer.h
@@ -17,15 +17,19 @@
 #ifndef ANDROID_MEDIA_SPATIALIZER_H
 #define ANDROID_MEDIA_SPATIALIZER_H
 
+#include <android-base/stringprintf.h>
 #include <android/media/BnEffect.h>
 #include <android/media/BnSpatializer.h>
 #include <android/media/SpatializationLevel.h>
 #include <android/media/SpatializationMode.h>
 #include <android/media/SpatializerHeadTrackingMode.h>
+#include <audio_utils/SimpleLog.h>
+#include <math.h>
+#include <media/AudioEffect.h>
 #include <media/audiohal/EffectHalInterface.h>
 #include <media/stagefright/foundation/ALooper.h>
-#include <media/AudioEffect.h>
 #include <system/audio_effects/effect_spatializer.h>
+#include <string>
 
 #include "SpatializerPoseController.h"
 
@@ -150,6 +154,43 @@
 
     void calculateHeadPose();
 
+    /** Convert fields in Spatializer and sub-modules to a string. Disable thread-safety-analysis
+     * here because we want to dump mutex guarded members even try_lock failed to provide as much
+     * information as possible for debugging purpose. */
+    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";
+    };
+
+    /**
+     * Format head to stage vector to a string, [0.00, 0.00, 0.00, -1.29, -0.50, 15.27].
+     */
+    template <typename T>
+    static std::string toString(const std::vector<T>& vec, bool radianToDegree = false) {
+        if (vec.size() == 0) {
+            return "[]";
+        }
+
+        std::string ss = "[";
+        for (const auto& f : vec) {
+            if (radianToDegree) {
+                base::StringAppendF(&ss, "%0.2f, ",
+                                    HeadToStagePoseRecorder::getDegreeWithRadian(f));
+            } else {
+                base::StringAppendF(&ss, "%f, ", f);
+            }
+        }
+        ss.replace(ss.end() - 2, ss.end(), "]");
+        return ss;
+    };
+
 private:
     Spatializer(effect_descriptor_t engineDescriptor,
                      SpatializerPolicyCallback *callback);
@@ -355,9 +396,94 @@
 
     size_t mNumActiveTracks GUARDED_BY(mLock) = 0;
 
-    static const std::vector<const char *> sHeadPoseKeys;
-};
+    static const std::vector<const char*> sHeadPoseKeys;
 
+    // Local log for command messages.
+    static constexpr int mMaxLocalLogLine = 10;
+    SimpleLog mLocalLog{mMaxLocalLogLine};
+
+    /**
+     * @brief Calculate and record sensor data.
+     * Dump to local log with max/average pose angle every mPoseRecordThreshold.
+     * TODO: log azimuth/elevation angles obtained for debugging actual orientation.
+     */
+    class HeadToStagePoseRecorder {
+      public:
+        /** Convert recorded sensor data to string with level indentation */
+        std::string toString_l(unsigned level) const;
+        /**
+         * @brief Calculate sensor data, record into local log when it is time.
+         *
+         * @param headToStage The vector from Pose3f::toVector().
+         */
+        void record_l(const std::vector<float>& headToStage);
+
+        static constexpr float getDegreeWithRadian(const float radian) {
+            float radianToDegreeRatio = (180 / PI);
+            return (radian * radianToDegreeRatio);
+        }
+
+      private:
+        static constexpr float PI = M_PI;
+        /**
+         * Pose recorder time threshold to record sensor data in local log.
+         * Sensor data will be recorded at least every mPoseRecordThreshold.
+         */
+        // TODO: add another history log to record longer period of sensor data.
+        static constexpr std::chrono::duration<double> mPoseRecordThreshold =
+                std::chrono::seconds(1);
+        /**
+         * According to frameworks/av/media/libheadtracking/include/media/Pose.h
+         * "The vector will have exactly 6 elements, where the first three are a translation vector
+         * and the last three are a rotation vector."
+         */
+        static constexpr size_t mPoseVectorSize = 6;
+        /**
+         * Timestamp of last sensor data record in local log.
+         */
+        std::chrono::time_point<std::chrono::steady_clock> mFirstSampleTimestamp;
+        // Last pose recorded, vector obtained from Pose3f::toVector().
+        std::vector<float> mLastPoseRecorded{mPoseVectorSize};
+        /**
+         * Number of sensor samples received since last record, sample rate is ~100Hz which produce
+         * ~6k samples/minute.
+         */
+        uint32_t mNumOfSampleSinceLastRecord = 0;
+        /* The sum of pose angle represented by radian since last dump, div
+         * mNumOfSampleSinceLastRecord to get arithmetic mean. Largest possible value: 2PI * 100Hz *
+         * mPoseRecordThreshold.
+         */
+        std::vector<double> mPoseRadianSum{mPoseVectorSize};
+        std::vector<float> mMaxPoseAngle{mPoseVectorSize};
+        std::vector<float> mMinPoseAngle{mPoseVectorSize};
+        // Local log for history sensor data.
+        SimpleLog mPoseRecordLog{mMaxLocalLogLine};
+
+        bool shouldRecordLog() const {
+            return std::chrono::duration_cast<std::chrono::seconds>(
+                           std::chrono::steady_clock::now() - mFirstSampleTimestamp) >=
+                   mPoseRecordThreshold;
+        }
+
+        void resetRecord(const std::vector<float>& headToStage) {
+            mPoseRadianSum.assign(mPoseVectorSize, 0);
+            mMaxPoseAngle.assign(mPoseVectorSize, 0);
+            mMinPoseAngle.assign(mPoseVectorSize, 0);
+            mNumOfSampleSinceLastRecord = 0;
+            mLastPoseRecorded = headToStage;
+        }
+
+        // Add each sample to sum and only calculate when record.
+        void poseSumToAverage() {
+            if (mNumOfSampleSinceLastRecord == 0) return;
+            for (auto& p : mPoseRadianSum) {
+                const float reciprocal = 1.f / mNumOfSampleSinceLastRecord;
+                p *= reciprocal;
+            }
+        }
+    };  // HeadToStagePoseRecorder
+    HeadToStagePoseRecorder mPoseRecorder;
+};  // Spatializer
 
 }; // namespace android
 
diff --git a/services/audiopolicy/service/SpatializerPoseController.cpp b/services/audiopolicy/service/SpatializerPoseController.cpp
index 23bcd77..e012a0b 100644
--- a/services/audiopolicy/service/SpatializerPoseController.cpp
+++ b/services/audiopolicy/service/SpatializerPoseController.cpp
@@ -14,6 +14,10 @@
  * limitations under the License.
  */
 #include "SpatializerPoseController.h"
+#include <android-base/stringprintf.h>
+#include <chrono>
+#include <cstdint>
+#include <string>
 
 #define LOG_TAG "SpatializerPoseController"
 //#define LOG_NDEBUG 0
@@ -291,4 +295,58 @@
     }
 }
 
+std::string SpatializerPoseController::toString(unsigned level) const {
+    std::string prefixSpace;
+    prefixSpace.append(level, ' ');
+    std::string ss = prefixSpace + "SpatializerPoseController:\n";
+    bool needUnlock = false;
+
+    prefixSpace += ' ';
+    auto now = std::chrono::steady_clock::now();
+    if (!mMutex.try_lock_until(now + media::kSpatializerDumpSysTimeOutInSecond)) {
+        ss.append(prefixSpace).append("try_lock failed, dumpsys maybe INACCURATE!\n");
+    } else {
+        needUnlock = true;
+    }
+
+    ss += prefixSpace;
+    if (mHeadSensor == media::SensorPoseProvider::INVALID_HANDLE) {
+        ss.append("HeadSensor: INVALID\n");
+    } else {
+        base::StringAppendF(&ss, "HeadSensor: 0x%08x\n", mHeadSensor);
+    }
+
+    ss += prefixSpace;
+    if (mScreenSensor == media::SensorPoseProvider::INVALID_HANDLE) {
+        ss += "ScreenSensor: INVALID\n";
+    } else {
+        base::StringAppendF(&ss, "ScreenSensor: 0x%08x\n", mScreenSensor);
+    }
+
+    ss += prefixSpace;
+    if (mActualMode.has_value()) {
+        base::StringAppendF(&ss, "ActualMode: %s", toString(mActualMode.value()).c_str());
+    } else {
+        ss += "ActualMode NOTEXIST\n";
+    }
+
+    if (mProcessor) {
+        ss += mProcessor->toString_l(level + 1);
+    } else {
+        ss.append(prefixSpace.c_str()).append("HeadTrackingProcessor not exist\n");
+    }
+
+    if (mPoseProvider) {
+        ss += mPoseProvider->toString(level + 1);
+    } else {
+        ss.append(prefixSpace.c_str()).append("SensorPoseProvider not exist\n");
+    }
+
+    if (needUnlock) {
+        mMutex.unlock();
+    }
+    // TODO: 233092747 add history sensor info with SimpleLog.
+    return ss;
+}
+
 }  // namespace android
diff --git a/services/audiopolicy/service/SpatializerPoseController.h b/services/audiopolicy/service/SpatializerPoseController.h
index f199ecb..546eba0 100644
--- a/services/audiopolicy/service/SpatializerPoseController.h
+++ b/services/audiopolicy/service/SpatializerPoseController.h
@@ -113,8 +113,23 @@
      */
     void waitUntilCalculated();
 
+    // convert fields to a printable string
+    std::string toString(unsigned level) const;
+
+    static std::string toString(media::HeadTrackingMode mode) {
+        switch (mode) {
+            case media::HeadTrackingMode::STATIC:
+                return "STATIC";
+            case media::HeadTrackingMode::WORLD_RELATIVE:
+                return "WORLD_RELATIVE";
+            case media::HeadTrackingMode::SCREEN_RELATIVE:
+                return "SCREEN_RELATIVE";
+        }
+        return "EnumNotImplemented";
+    };
+
   private:
-    mutable std::mutex mMutex;
+    mutable std::timed_mutex mMutex;
     Listener* const mListener;
     const std::chrono::microseconds mSensorPeriod;
     // Order matters for the following two members to ensure correct destruction.
@@ -123,7 +138,7 @@
     int32_t mHeadSensor = media::SensorPoseProvider::INVALID_HANDLE;
     int32_t mScreenSensor = media::SensorPoseProvider::INVALID_HANDLE;
     std::optional<media::HeadTrackingMode> mActualMode;
-    std::condition_variable mCondVar;
+    std::condition_variable_any mCondVar;
     bool mShouldCalculate = true;
     bool mShouldExit = false;
     bool mCalculated = false;