audioserver: log system event for binder timeouts
Add event logging in case of audioserver watchdog to help
collect statistics.
Test: make. Simulate watchdog and check events in logcat.
Change-Id: I4716852c77d56703ad5f3dfc2500f598a2b80a12
diff --git a/media/utils/Android.bp b/media/utils/Android.bp
index de8e46a..13b66ed 100644
--- a/media/utils/Android.bp
+++ b/media/utils/Android.bp
@@ -22,6 +22,7 @@
"ProcessInfo.cpp",
"SchedulingPolicyService.cpp",
"ServiceUtilities.cpp",
+ "TimeCheck.cpp",
],
shared_libs: [
"libbinder",
@@ -31,6 +32,8 @@
"libmemunreachable",
],
+ logtags: ["EventLogTags.logtags"],
+
cflags: [
"-Wall",
"-Wextra",
diff --git a/media/utils/EventLogTags.logtags b/media/utils/EventLogTags.logtags
new file mode 100644
index 0000000..67f0ea8
--- /dev/null
+++ b/media/utils/EventLogTags.logtags
@@ -0,0 +1,41 @@
+# The entries in this file map a sparse set of log tag numbers to tag names.
+# This is installed on the device, in /system/etc, and parsed by logcat.
+#
+# Tag numbers are decimal integers, from 0 to 2^31. (Let's leave the
+# negative values alone for now.)
+#
+# Tag names are one or more ASCII letters and numbers or underscores, i.e.
+# "[A-Z][a-z][0-9]_". Do not include spaces or punctuation (the former
+# impacts log readability, the latter makes regex searches more annoying).
+#
+# Tag numbers and names are separated by whitespace. Blank lines and lines
+# starting with '#' are ignored.
+#
+# Optionally, after the tag names can be put a description for the value(s)
+# of the tag. Description are in the format
+# (<name>|data type[|data unit])
+# Multiple values are separated by commas.
+#
+# The data type is a number from the following values:
+# 1: int
+# 2: long
+# 3: string
+# 4: list
+#
+# The data unit is a number taken from the following list:
+# 1: Number of objects
+# 2: Number of bytes
+# 3: Number of milliseconds
+# 4: Number of allocations
+# 5: Id
+# 6: Percent
+# Default value for data of type int/long is 2 (bytes).
+#
+# See system/core/logcat/event.logtags for the master copy of the tags.
+
+# 61000 - 61199 reserved for audioserver
+
+61000 audioserver_binder_timeout (command|3)
+
+# NOTE - the range 1000000-2000000 is reserved for partners and others who
+# want to define their own log tags without conflicting with the core platform.
diff --git a/media/utils/TimeCheck.cpp b/media/utils/TimeCheck.cpp
new file mode 100644
index 0000000..59cf4ef
--- /dev/null
+++ b/media/utils/TimeCheck.cpp
@@ -0,0 +1,93 @@
+/*
+ * Copyright (C) 2018 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 <utils/Log.h>
+#include <media/TimeCheck.h>
+#include <media/EventLog.h>
+
+namespace android {
+
+/* static */
+sp<TimeCheck::TimeCheckThread> TimeCheck::getTimeCheckThread()
+{
+ static sp<TimeCheck::TimeCheckThread> sTimeCheckThread = new TimeCheck::TimeCheckThread();
+ return sTimeCheckThread;
+}
+
+TimeCheck::TimeCheck(const char *tag, uint32_t timeoutMs)
+ : mEndTimeNs(getTimeCheckThread()->startMonitoring(tag, timeoutMs))
+{
+}
+
+TimeCheck::~TimeCheck() {
+ getTimeCheckThread()->stopMonitoring(mEndTimeNs);
+}
+
+TimeCheck::TimeCheckThread::~TimeCheckThread()
+{
+ AutoMutex _l(mMutex);
+ requestExit();
+ mMonitorRequests.clear();
+ mCond.signal();
+}
+
+nsecs_t TimeCheck::TimeCheckThread::startMonitoring(const char *tag, uint32_t timeoutMs) {
+ Mutex::Autolock _l(mMutex);
+ nsecs_t endTimeNs = systemTime() + milliseconds(timeoutMs);
+ for (; mMonitorRequests.indexOfKey(endTimeNs) >= 0; ++endTimeNs);
+ mMonitorRequests.add(endTimeNs, tag);
+ mCond.signal();
+ return endTimeNs;
+}
+
+void TimeCheck::TimeCheckThread::stopMonitoring(nsecs_t endTimeNs) {
+ Mutex::Autolock _l(mMutex);
+ mMonitorRequests.removeItem(endTimeNs);
+ mCond.signal();
+}
+
+bool TimeCheck::TimeCheckThread::threadLoop()
+{
+ status_t status = TIMED_OUT;
+ const char *tag;
+ {
+ AutoMutex _l(mMutex);
+
+ if (exitPending()) {
+ return false;
+ }
+
+ nsecs_t endTimeNs = INT64_MAX;
+ // KeyedVector mMonitorRequests is ordered so take first entry as next timeout
+ if (mMonitorRequests.size() != 0) {
+ endTimeNs = mMonitorRequests.keyAt(0);
+ tag = mMonitorRequests.valueAt(0);
+ }
+
+ const nsecs_t waitTimeNs = endTimeNs - systemTime();
+ if (waitTimeNs > 0) {
+ status = mCond.waitRelative(mMutex, waitTimeNs);
+ }
+ }
+ if (status != NO_ERROR) {
+ LOG_EVENT_STRING(LOGTAG_AUDIO_BINDER_TIMEOUT, tag);
+ LOG_ALWAYS_FATAL("TimeCheck timeout for %s", tag);
+ }
+ return true;
+}
+
+}; // namespace android
diff --git a/media/utils/include/mediautils/EventLog.h b/media/utils/include/mediautils/EventLog.h
new file mode 100644
index 0000000..553d3bd
--- /dev/null
+++ b/media/utils/include/mediautils/EventLog.h
@@ -0,0 +1,28 @@
+/*
+ * Copyright (C) 2018 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.
+ */
+#ifndef ANDROID_AUDIO_EVENT_LOG_H_
+#define ANDROID_AUDIO_EVENT_LOG_H_
+
+namespace android {
+
+// keep values in sync with frameworks/av/media/utils/EventLogTags.logtags
+enum {
+ LOGTAG_AUDIO_BINDER_TIMEOUT = 61000,
+};
+
+} // namespace android
+
+#endif // ANDROID_AUDIO_EVENT_LOG_H_
diff --git a/media/utils/include/mediautils/TimeCheck.h b/media/utils/include/mediautils/TimeCheck.h
new file mode 100644
index 0000000..6c5f656
--- /dev/null
+++ b/media/utils/include/mediautils/TimeCheck.h
@@ -0,0 +1,72 @@
+/*
+ * Copyright (C) 2018 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.
+ */
+
+
+#ifndef ANDROID_TIME_CHECK_H
+#define ANDROID_TIME_CHECK_H
+
+#include <utils/KeyedVector.h>
+#include <utils/Thread.h>
+
+
+namespace android {
+
+// A class monitoring execution time for a code block (scoped variable) and causing an assert
+// if it exceeds a certain time
+
+class TimeCheck {
+public:
+
+ // The default timeout is chosen to be less than system server watchdog timeout
+ static constexpr uint32_t kDefaultTimeOutMs = 5000;
+
+ TimeCheck(const char *tag, uint32_t timeoutMs = kDefaultTimeOutMs);
+ ~TimeCheck();
+
+private:
+
+ class TimeCheckThread : public Thread {
+ public:
+
+ TimeCheckThread() {}
+ virtual ~TimeCheckThread() override;
+
+ nsecs_t startMonitoring(const char *tag, uint32_t timeoutMs);
+ void stopMonitoring(nsecs_t endTimeNs);
+
+ private:
+
+ // RefBase
+ virtual void onFirstRef() override { run("TimeCheckThread", PRIORITY_URGENT_AUDIO); }
+
+ // Thread
+ virtual bool threadLoop() override;
+
+ Condition mCond;
+ Mutex mMutex;
+ // using the end time in ns as key is OK given the risk is low that two entries
+ // are added in such a way that <add time> + <timeout> are the same for both.
+ KeyedVector< nsecs_t, const char*> mMonitorRequests;
+ };
+
+ static sp<TimeCheckThread> getTimeCheckThread();
+
+ const nsecs_t mEndTimeNs;
+};
+
+}; // namespace android
+
+#endif // ANDROID_TIME_CHECK_H