TimeCheck: Update code to support a callback
Callback will be used for binder statistics and logging.
Nest TimeCheck into mediautils namespace.
Copy input char * to a persistent string.
Log the thread id which is blocked to the debug message.
Separate code to a const shared ptr handler for easier analysis.
Add timecheck_tests which validate callback.
Test: atest libmediautils_test
Test: atest timecheck_tests
Bug: 219958414
Change-Id: I13c751ed90f39e41d7cfa3b8be51e40403787608
diff --git a/media/utils/TimeCheck.cpp b/media/utils/TimeCheck.cpp
index 2b765cc..5f269af 100644
--- a/media/utils/TimeCheck.cpp
+++ b/media/utils/TimeCheck.cpp
@@ -24,7 +24,7 @@
#include <utils/Log.h>
#include "debuggerd/handler.h"
-namespace android {
+namespace android::mediautils {
namespace {
@@ -48,7 +48,7 @@
void TimeCheck::accessAudioHalPids(std::vector<pid_t>* pids, bool update) {
static constexpr int kNumAudioHalPidsVectors = 3;
static std::vector<pid_t> audioHalPids[kNumAudioHalPidsVectors];
- static std::atomic<int> curAudioHalPids = 0;
+ static std::atomic<unsigned> curAudioHalPids = 0;
if (update) {
audioHalPids[(curAudioHalPids++ + 1) % kNumAudioHalPidsVectors] = *pids;
@@ -70,27 +70,54 @@
}
/* static */
-TimerThread* TimeCheck::getTimeCheckThread() {
- static TimerThread* sTimeCheckThread = new TimerThread();
+TimerThread& TimeCheck::getTimeCheckThread() {
+ static TimerThread sTimeCheckThread{};
return sTimeCheckThread;
}
-TimeCheck::TimeCheck(const char* tag, uint32_t timeoutMs)
- : mTimerHandle(getTimeCheckThread()->scheduleTask(
- [tag, startTime = std::chrono::system_clock::now()] { crash(tag, startTime); },
+TimeCheck::TimeCheck(std::string tag, OnTimerFunc&& onTimer, uint32_t timeoutMs,
+ bool crashOnTimeout)
+ : mTimeCheckHandler(new TimeCheckHandler{
+ std::move(tag), std::move(onTimer), crashOnTimeout,
+ std::chrono::system_clock::now(), gettid()})
+ , mTimerHandle(getTimeCheckThread().scheduleTask(
+ // Pass in all the arguments by value to this task for safety.
+ // The thread could call the callback before the constructor is finished.
+ // The destructor will be blocked on the callback, but that is implementation
+ // dependent.
+ [ timeCheckHandler = mTimeCheckHandler ] {
+ timeCheckHandler->onTimeout();
+ },
std::chrono::milliseconds(timeoutMs))) {}
TimeCheck::~TimeCheck() {
- getTimeCheckThread()->cancelTask(mTimerHandle);
+ mTimeCheckHandler->onCancel(mTimerHandle);
}
-/* static */
-void TimeCheck::crash(const char* tag, std::chrono::system_clock::time_point startTime) {
- std::chrono::system_clock::time_point endTime = std::chrono::system_clock::now();
+void TimeCheck::TimeCheckHandler::onCancel(TimerThread::Handle timerHandle) const
+{
+ if (TimeCheck::getTimeCheckThread().cancelTask(timerHandle) && onTimer) {
+ const std::chrono::system_clock::time_point endTime = std::chrono::system_clock::now();
+ onTimer(false /* timeout */,
+ std::chrono::duration_cast<std::chrono::duration<float, std::milli>>(
+ endTime - startTime).count());
+ }
+}
+
+void TimeCheck::TimeCheckHandler::onTimeout() const
+{
+ const std::chrono::system_clock::time_point endTime = std::chrono::system_clock::now();
+ if (onTimer) {
+ onTimer(true /* timeout */,
+ std::chrono::duration_cast<std::chrono::duration<float, std::milli>>(
+ endTime - startTime).count());
+ }
+
+ if (!crashOnTimeout) return;
// Generate audio HAL processes tombstones and allow time to complete
// before forcing restart
- std::vector<pid_t> pids = getAudioHalPids();
+ std::vector<pid_t> pids = TimeCheck::getAudioHalPids();
if (pids.size() != 0) {
for (const auto& pid : pids) {
ALOGI("requesting tombstone for pid: %d", pid);
@@ -100,9 +127,9 @@
} else {
ALOGI("No HAL process pid available, skipping tombstones");
}
- LOG_EVENT_STRING(LOGTAG_AUDIO_BINDER_TIMEOUT, tag);
- LOG_ALWAYS_FATAL("TimeCheck timeout for %s (start=%s, end=%s)", tag,
- formatTime(startTime).c_str(), formatTime(endTime).c_str());
+ LOG_EVENT_STRING(LOGTAG_AUDIO_BINDER_TIMEOUT, tag.c_str());
+ LOG_ALWAYS_FATAL("TimeCheck timeout for %s on thread %d (start=%s, end=%s)",
+ tag.c_str(), tid, formatTime(startTime).c_str(), formatTime(endTime).c_str());
}
-}; // namespace android
+} // namespace android::mediautils
diff --git a/media/utils/TimerThread.cpp b/media/utils/TimerThread.cpp
index 3c95798..dfc84e1 100644
--- a/media/utils/TimerThread.cpp
+++ b/media/utils/TimerThread.cpp
@@ -50,9 +50,12 @@
return deadline;
}
-void TimerThread::cancelTask(Handle handle) {
+// Returns true if cancelled, false if handle doesn't exist.
+// Beware of lock inversion with cancelTask() as the callback
+// is called while holding mMutex.
+bool TimerThread::cancelTask(Handle handle) {
std::lock_guard _l(mMutex);
- mMonitorRequests.erase(handle);
+ return mMonitorRequests.erase(handle) != 0;
}
void TimerThread::threadFunc() {
diff --git a/media/utils/fuzzers/TimeCheckFuzz.cpp b/media/utils/fuzzers/TimeCheckFuzz.cpp
index eeb6ba6..7966469 100644
--- a/media/utils/fuzzers/TimeCheckFuzz.cpp
+++ b/media/utils/fuzzers/TimeCheckFuzz.cpp
@@ -44,11 +44,11 @@
// 2. We also have setAudioHalPids, which is populated with the pids set
// above.
- android::TimeCheck::setAudioHalPids(pids);
+ android::mediautils::TimeCheck::setAudioHalPids(pids);
std::string name = data_provider.ConsumeRandomLengthString(kMaxStringLen);
// 3. The constructor, which is fuzzed here:
- android::TimeCheck timeCheck(name.c_str(), timeoutMs);
+ android::mediautils::TimeCheck timeCheck(name.c_str(), {} /* onTimer */, timeoutMs);
// We will leave some buffer to avoid sleeping too long
uint8_t sleep_amount_ms = data_provider.ConsumeIntegralInRange<uint8_t>(0, timeoutMs / 2);
diff --git a/media/utils/include/mediautils/TimeCheck.h b/media/utils/include/mediautils/TimeCheck.h
index 0d6e80d..991a921 100644
--- a/media/utils/include/mediautils/TimeCheck.h
+++ b/media/utils/include/mediautils/TimeCheck.h
@@ -20,27 +20,76 @@
#include <mediautils/TimerThread.h>
-namespace android {
+namespace android::mediautils {
// A class monitoring execution time for a code block (scoped variable) and causing an assert
// if it exceeds a certain time
class TimeCheck {
public:
+ using OnTimerFunc = std::function<void(bool /* timeout */, float /* elapsedMs */ )>;
+
// 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 is a RAII object which will notify a callback
+ * on timer expiration or when the object is deallocated.
+ *
+ * TimeCheck is used as a watchdog and aborts by default on timer expiration.
+ * When it aborts, it will also send a debugger signal to pids passed in through
+ * setAudioHalPids().
+ *
+ * If the callback function returns for timeout it will not be called again for
+ * the deallocation.
+ *
+ * \param tag string associated with the TimeCheck object.
+ * \param onTimer callback function with 2 parameters
+ * bool timeout (which is true when the TimeCheck object
+ * times out, false when the TimeCheck object is
+ * destroyed or leaves scope before the timer expires.)
+ * float elapsedMs (the elapsed time to this event).
+ * The callback when timeout is true will be called on a different thread.
+ * Currently this is guaranteed to block the destructor
+ * (potential lock inversion warning here) nevertheless
+ * it would be safer not to depend on stack contents.
+ * \param timeoutMs timeout in milliseconds.
+ * \param crashOnTimeout true if the object issues an abort on timeout.
+ */
+ explicit TimeCheck(std::string tag, OnTimerFunc&& onTimer = {},
+ uint32_t timeoutMs = kDefaultTimeOutMs, bool crashOnTimeout = true);
+ // Remove copy constructors as there should only be one call to the destructor.
+ // Move is kept implicitly disabled, but would be logically consistent if enabled.
+ TimeCheck(const TimeCheck& other) = delete;
+ TimeCheck& operator=(const TimeCheck&) = delete;
+
~TimeCheck();
static void setAudioHalPids(const std::vector<pid_t>& pids);
static std::vector<pid_t> getAudioHalPids();
private:
- static TimerThread* getTimeCheckThread();
+ static TimerThread& getTimeCheckThread();
static void accessAudioHalPids(std::vector<pid_t>* pids, bool update);
- static void crash(const char* tag, std::chrono::system_clock::time_point startTime);
+ // Helper class for handling events.
+ // The usage here is const safe.
+ class TimeCheckHandler {
+ public:
+ const std::string tag;
+ const OnTimerFunc onTimer;
+ const bool crashOnTimeout;
+ const std::chrono::system_clock::time_point startTime;
+ const pid_t tid;
+
+ void onCancel(TimerThread::Handle handle) const;
+ void onTimeout() const;
+ };
+
+ // mTimeCheckHandler is immutable, prefer to be first initialized, last destroyed.
+ // Technically speaking, we do not need a shared_ptr here because TimerThread::cancelTask()
+ // is mutually exclusive of the callback, but the price paid for lifetime safety is minimal.
+ const std::shared_ptr<const TimeCheckHandler> mTimeCheckHandler;
const TimerThread::Handle mTimerHandle;
};
-}; // namespace android
+} // namespace android::mediautils
diff --git a/media/utils/include/mediautils/TimerThread.h b/media/utils/include/mediautils/TimerThread.h
index cf457b8..acf0b16 100644
--- a/media/utils/include/mediautils/TimerThread.h
+++ b/media/utils/include/mediautils/TimerThread.h
@@ -48,9 +48,9 @@
/**
* Cancel a task, previously scheduled with scheduleTask().
- * If the task has already executed, this is a no-op.
+ * If the task has already executed, this is a no-op and returns false.
*/
- void cancelTask(Handle handle);
+ bool cancelTask(Handle handle);
private:
using TimePoint = std::chrono::steady_clock::time_point;
diff --git a/media/utils/tests/Android.bp b/media/utils/tests/Android.bp
index 6593d56..f240dae 100644
--- a/media/utils/tests/Android.bp
+++ b/media/utils/tests/Android.bp
@@ -26,3 +26,30 @@
"media_synchronization_tests.cpp",
],
}
+
+cc_test {
+ name: "timecheck_tests",
+
+ cflags: [
+ "-Wall",
+ "-Werror",
+ "-Wextra",
+ ],
+
+ sanitize:{
+ address: true,
+ cfi: true,
+ integer_overflow: true,
+ memtag_heap: true,
+ },
+
+ shared_libs: [
+ "liblog",
+ "libmediautils",
+ "libutils",
+ ],
+
+ srcs: [
+ "timecheck_tests.cpp",
+ ],
+}
diff --git a/media/utils/tests/timecheck_tests.cpp b/media/utils/tests/timecheck_tests.cpp
new file mode 100644
index 0000000..9833dc9
--- /dev/null
+++ b/media/utils/tests/timecheck_tests.cpp
@@ -0,0 +1,67 @@
+/*
+ * 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 "timecheck_tests"
+
+#include <mediautils/TimeCheck.h>
+
+#include <atomic>
+#include <gtest/gtest.h>
+#include <utils/Log.h>
+
+using namespace android::mediautils;
+
+TEST(timecheck_tests, success) {
+ bool timeoutRegistered = false;
+ float elapsedMsRegistered = 0.f;
+ bool event = false;
+
+ {
+ TimeCheck timeCheck("success",
+ [&event, &timeoutRegistered, &elapsedMsRegistered]
+ (bool timeout, float elapsedMs) {
+ timeoutRegistered = timeout;
+ elapsedMsRegistered = elapsedMs;
+ event = true;
+ }, 1000 /* msec */, false /* crash */);
+ }
+ ASSERT_TRUE(event);
+ ASSERT_FALSE(timeoutRegistered);
+ ASSERT_GT(elapsedMsRegistered, 0.f);
+}
+
+TEST(timecheck_tests, timeout) {
+ bool timeoutRegistered = false;
+ float elapsedMsRegistered = 0.f;
+ std::atomic_bool event = false; // seq-cst implies acquire-release
+
+ {
+ TimeCheck timeCheck("timeout",
+ [&event, &timeoutRegistered, &elapsedMsRegistered]
+ (bool timeout, float elapsedMs) {
+ timeoutRegistered = timeout;
+ elapsedMsRegistered = elapsedMs;
+ event = true; // store-release, must be last.
+ }, 1 /* msec */, false /* crash */);
+ usleep(100 * 1000 /* usec */); // extra time as callback called by different thread.
+ }
+ ASSERT_TRUE(event); // load-acquire, must be first.
+ ASSERT_TRUE(timeoutRegistered); // only called once on failure, not on dealloc.
+ ASSERT_GT(elapsedMsRegistered, 0.f);
+}
+
+// Note: We do not test TimeCheck crash because TimeCheck is multithreaded and the
+// EXPECT_EXIT() signal catching is imperfect due to the gtest fork.