Spatializer: Add rate based stats
A new class ThreadSnapshot encapsulates
current (and future) thread based statistics.
Test: adb shell dumpsys media.audio_flinger --all
Test: atest media_threadsnapshot_tests
Bug: 228648325
Change-Id: Idbfdee08032c56f2c47e2e48d2ceb0656168c125
diff --git a/media/utils/Android.bp b/media/utils/Android.bp
index d76602b..a38ef57 100644
--- a/media/utils/Android.bp
+++ b/media/utils/Android.bp
@@ -37,6 +37,7 @@
"ProcessInfo.cpp",
"SchedulingPolicyService.cpp",
"ServiceUtilities.cpp",
+ "ThreadSnapshot.cpp",
"TimeCheck.cpp",
"TimerThread.cpp",
],
diff --git a/media/utils/ThreadSnapshot.cpp b/media/utils/ThreadSnapshot.cpp
new file mode 100644
index 0000000..382738e
--- /dev/null
+++ b/media/utils/ThreadSnapshot.cpp
@@ -0,0 +1,145 @@
+/*
+ * Copyright (C) 2022 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#define LOG_TAG "ThreadSnapshot"
+#include <utils/Log.h>
+#include <utils/Timers.h>
+#include <mediautils/ThreadSnapshot.h>
+
+#include <mediautils/Process.h>
+
+namespace android::mediautils {
+
+pid_t ThreadSnapshot::getTid() const {
+ std::lock_guard lg(mLock);
+ return mState.mTid;
+}
+
+void ThreadSnapshot::setTid(pid_t tid) {
+ std::lock_guard lg(mLock);
+ if (mState.mTid == tid) return;
+ mState.reset(tid);
+}
+
+void ThreadSnapshot::reset() {
+ std::lock_guard lg(mLock);
+ mState.reset(mState.mTid);
+}
+
+void ThreadSnapshot::onBegin() {
+ std::string sched = getThreadSchedAsString(getTid()); // tid could race here,
+ // accept as benign.
+ std::lock_guard lg(mLock);
+ mState.onBegin(std::move(sched));
+}
+
+void ThreadSnapshot::onEnd() {
+ std::lock_guard lg(mLock);
+ mState.onEnd();
+}
+
+std::string ThreadSnapshot::toString() const {
+ // Make a local copy of the stats data under lock.
+ State state;
+ {
+ std::lock_guard lg(mLock);
+ state = mState;
+ }
+ return state.toString();
+}
+
+void ThreadSnapshot::State::reset(pid_t tid) {
+ mTid = tid;
+ mBeginTimeNs = -2;
+ mEndTimeNs = -1;
+ mCumulativeTimeNs = 0;
+ mBeginSched.clear();
+}
+
+void ThreadSnapshot::State::onBegin(std::string sched) {
+ if (mBeginTimeNs < mEndTimeNs) {
+ mBeginTimeNs = systemTime();
+ mBeginSched = std::move(sched);
+ }
+}
+
+void ThreadSnapshot::State::onEnd() {
+ if (mEndTimeNs < mBeginTimeNs) {
+ mEndTimeNs = systemTime();
+ mCumulativeTimeNs += mEndTimeNs - mBeginTimeNs;
+ }
+}
+
+std::string ThreadSnapshot::State::toString() const {
+ if (mBeginTimeNs < 0) return {}; // never begun.
+
+ // compute time intervals.
+ const int64_t nowNs = systemTime();
+ int64_t cumulativeTimeNs = mCumulativeTimeNs;
+ int64_t diffNs = mEndTimeNs - mBeginTimeNs; // if onEnd() isn't matched, diffNs < 0.
+ if (diffNs < 0) {
+ diffNs = nowNs - mBeginTimeNs;
+ cumulativeTimeNs += diffNs;
+ }
+ // normalization for rate variables
+ const double lastRunPerSec = 1e9 / diffNs;
+ const double totalPerSec = 1e9 / cumulativeTimeNs;
+
+ // HANDLE THE SCHEDULER STATISTICS HERE
+ // current and differential statistics for the scheduler.
+ std::string schedNow = getThreadSchedAsString(mTid);
+ const auto schedMapThen = parseThreadSchedString(mBeginSched);
+ const auto schedMapNow = parseThreadSchedString(schedNow);
+ static const char * schedDiffKeyList[] = {
+ "se.sum_exec_runtime",
+ "se.nr_migrations",
+ "se.statistics.wait_sum",
+ "se.statistics.wait_count",
+ "se.statistics.iowait_sum",
+ "se.statistics.iowait_count",
+ "se.statistics.nr_forced_migrations",
+ "nr_involuntary_switches",
+ };
+
+ // compute differential rate statistics.
+ std::string diffString;
+ for (const auto diffKey : schedDiffKeyList) {
+ if (auto itThen = schedMapThen.find(diffKey);
+ itThen != schedMapThen.end()) {
+
+ if (auto itNow = schedMapNow.find(diffKey);
+ itNow != schedMapNow.end()) {
+ auto diff = itNow->second - itThen->second;
+ diff *= lastRunPerSec;
+ auto total = itNow->second * totalPerSec;
+ diffString.append(diffKey).append(" last-run:")
+ .append(std::to_string(diff))
+ .append(" cumulative:")
+ .append(std::to_string(total))
+ .append("\n");
+ }
+ }
+ }
+
+ if (!diffString.empty()) {
+ schedNow.append("*** per second stats ***\n").append(diffString);
+ }
+
+ // Return snapshot string.
+ return schedNow;
+}
+
+} // android::mediautils
diff --git a/media/utils/include/mediautils/ThreadSnapshot.h b/media/utils/include/mediautils/ThreadSnapshot.h
new file mode 100644
index 0000000..c470822
--- /dev/null
+++ b/media/utils/include/mediautils/ThreadSnapshot.h
@@ -0,0 +1,83 @@
+/*
+ * Copyright (C) 2022 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#pragma once
+
+#include <mutex>
+#include <string>
+
+#include <android-base/thread_annotations.h>
+
+namespace android::mediautils {
+
+/**
+ * Collect Thread performance statistics.
+ *
+ * An onBegin() and onEnd() signal a continuous "run".
+ * Statistics are returned by toString().
+ */
+class ThreadSnapshot {
+public:
+ explicit ThreadSnapshot(pid_t tid = -1) { mState.reset(tid); };
+
+ // Returns current tid
+ pid_t getTid() const;
+
+ // Sets the tid
+ void setTid(pid_t tid);
+
+ // Reset statistics, keep same tid.
+ void reset();
+
+ // Signal a timing run is beginning
+ void onBegin();
+
+ // Signal a timing run is ending
+ void onEnd();
+
+ // Return the thread snapshot statistics in a string
+ std::string toString() const;
+
+private:
+ mutable std::mutex mLock;
+
+ // State represents our statistics at a given point in time.
+ // It is not thread-safe, so any locking must occur at the caller.
+ struct State {
+ pid_t mTid;
+ int64_t mBeginTimeNs; // when last run began
+ int64_t mEndTimeNs; // when last run ends (if less than begin time, not started)
+ int64_t mCumulativeTimeNs;
+
+ // Sched is the scheduler statistics obtained as a string.
+ // This is parsed only when toString() is called.
+ std::string mBeginSched;
+
+ // Clears existing state.
+ void reset(pid_t tid);
+
+ // onBegin() takes a std::string sched should can be captured outside
+ // of locking.
+ void onBegin(std::string sched);
+ void onEnd();
+ std::string toString() const;
+ };
+
+ // Our current state. We only keep the current running state.
+ State mState GUARDED_BY(mLock);
+};
+
+} // android::mediautils
diff --git a/media/utils/tests/Android.bp b/media/utils/tests/Android.bp
index d9c2b21..a6f408d 100644
--- a/media/utils/tests/Android.bp
+++ b/media/utils/tests/Android.bp
@@ -104,6 +104,26 @@
}
cc_test {
+ name: "media_threadsnapshot_tests",
+
+ cflags: [
+ "-Wall",
+ "-Werror",
+ "-Wextra",
+ ],
+
+ shared_libs: [
+ "liblog",
+ "libmediautils",
+ "libutils",
+ ],
+
+ srcs: [
+ "media_threadsnapshot_tests.cpp",
+ ],
+}
+
+cc_test {
name: "methodstatistics_tests",
cflags: [
diff --git a/media/utils/tests/media_threadsnapshot_tests.cpp b/media/utils/tests/media_threadsnapshot_tests.cpp
new file mode 100644
index 0000000..c7a45e2
--- /dev/null
+++ b/media/utils/tests/media_threadsnapshot_tests.cpp
@@ -0,0 +1,52 @@
+/*
+ * Copyright (C) 2022 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#include <mediautils/ThreadSnapshot.h>
+
+#define LOG_TAG "media_threadsnapshot_tests"
+
+#include <gtest/gtest.h>
+#include <utils/Log.h>
+
+#include <chrono>
+#include <thread>
+
+using namespace android;
+using namespace android::mediautils;
+
+TEST(media_threadsnapshot_tests, basic) {
+ using namespace std::chrono_literals;
+
+ ThreadSnapshot threadSnapshot(gettid());
+
+ threadSnapshot.onBegin();
+
+ std::string snapshot1 = threadSnapshot.toString();
+
+ std::this_thread::sleep_for(100ms);
+
+ threadSnapshot.onEnd();
+
+ std::string snapshot2 = threadSnapshot.toString();
+
+ // Either we can't get a snapshot, or they must be different when taken when thread is running.
+ if (snapshot1.empty()) {
+ ASSERT_TRUE(snapshot2.empty());
+ } else {
+ ASSERT_FALSE(snapshot2.empty());
+ ASSERT_NE(snapshot1, snapshot2);
+ }
+}
diff --git a/services/audioflinger/AudioFlinger.h b/services/audioflinger/AudioFlinger.h
index 59f22eb..8e4383c 100644
--- a/services/audioflinger/AudioFlinger.h
+++ b/services/audioflinger/AudioFlinger.h
@@ -76,6 +76,7 @@
#include <media/VolumeShaper.h>
#include <mediautils/ServiceUtilities.h>
#include <mediautils/Synchronization.h>
+#include <mediautils/ThreadSnapshot.h>
#include <audio_utils/clock.h>
#include <audio_utils/FdToString.h>
diff --git a/services/audioflinger/Threads.cpp b/services/audioflinger/Threads.cpp
index f8c3ae4..9344e20 100644
--- a/services/audioflinger/Threads.cpp
+++ b/services/audioflinger/Threads.cpp
@@ -933,7 +933,7 @@
}
}
if (dumpAll || type() == SPATIALIZER) {
- const std::string sched = mediautils::getThreadSchedAsString(getTid());
+ const std::string sched = mThreadSnapshot.toString();
if (!sched.empty()) {
(void)write(fd, sched.c_str(), sched.size());
}
@@ -2113,6 +2113,7 @@
}
}
run(mThreadName, ANDROID_PRIORITY_URGENT_AUDIO);
+ mThreadSnapshot.setTid(getTid());
}
// ThreadBase virtuals
@@ -3354,6 +3355,7 @@
mInWrite = false;
if (mStandby) {
mThreadMetrics.logBeginInterval();
+ mThreadSnapshot.onBegin();
mStandby = false;
}
return bytesWritten;
@@ -3839,6 +3841,7 @@
if (!mStandby) {
LOG_AUDIO_STATE();
mThreadMetrics.logEndInterval();
+ mThreadSnapshot.onEnd();
mStandby = true;
}
sendStatistics(false /* force */);
@@ -5974,6 +5977,7 @@
mOutput->standby();
if (!mStandby) {
mThreadMetrics.logEndInterval();
+ mThreadSnapshot.onEnd();
mStandby = true;
}
mBytesWritten = 0;
@@ -6495,6 +6499,7 @@
mOutput->standby();
if (!mStandby) {
mThreadMetrics.logEndInterval();
+ mThreadSnapshot.onEnd();
mStandby = true;
}
mBytesWritten = 0;
@@ -7081,6 +7086,7 @@
}
if (mStandby) {
mThreadMetrics.logBeginInterval();
+ mThreadSnapshot.onBegin();
mStandby = false;
}
return (ssize_t)mSinkBufferSize;
@@ -7606,6 +7612,7 @@
doBroadcast = true;
if (mStandby) {
mThreadMetrics.logBeginInterval();
+ mThreadSnapshot.onBegin();
mStandby = false;
}
activeTrack->mState = TrackBase::ACTIVE;
@@ -8087,6 +8094,7 @@
if (!mStandby) {
inputStandBy();
mThreadMetrics.logEndInterval();
+ mThreadSnapshot.onEnd();
mStandby = true;
}
}
@@ -9472,6 +9480,7 @@
}
if (mStandby) {
mThreadMetrics.logBeginInterval();
+ mThreadSnapshot.onBegin();
mStandby = false;
}
return NO_ERROR;
@@ -9668,6 +9677,7 @@
mHalStream->standby();
if (!mStandby) {
mThreadMetrics.logEndInterval();
+ mThreadSnapshot.onEnd();
mStandby = true;
}
releaseWakeLock();
diff --git a/services/audioflinger/Threads.h b/services/audioflinger/Threads.h
index 1fccdc5..b2962ed8 100644
--- a/services/audioflinger/Threads.h
+++ b/services/audioflinger/Threads.h
@@ -687,6 +687,9 @@
int64_t mLastIoBeginNs = -1;
int64_t mLastIoEndNs = -1;
+ // ThreadSnapshot is thread-safe (internally locked)
+ mediautils::ThreadSnapshot mThreadSnapshot;
+
// This should be read under ThreadBase lock (if not on the threadLoop thread).
audio_utils::Statistics<double> mIoJitterMs{0.995 /* alpha */};
audio_utils::Statistics<double> mProcessTimeMs{0.995 /* alpha */};