TimeCheck: Dump stack of blocked tids

Test: dedicated "crasher" test, check logcat
Test: adb shell dumpsys media.audio_flinger
Bug: 219958414
Change-Id: I6ec2b2aff2bda2b03c426ce79ffe9ce69c4134d2
diff --git a/media/utils/Android.bp b/media/utils/Android.bp
index c333fa6..1756e47 100644
--- a/media/utils/Android.bp
+++ b/media/utils/Android.bp
@@ -49,6 +49,7 @@
         "libcutils",
         "liblog",
         "libutils",
+        "libutilscallstack",
         "libhidlbase",
         "libpermission",
         "android.hardware.graphics.bufferqueue@1.0",
diff --git a/media/utils/TimeCheck.cpp b/media/utils/TimeCheck.cpp
index 3e35970..75a1b22 100644
--- a/media/utils/TimeCheck.cpp
+++ b/media/utils/TimeCheck.cpp
@@ -18,6 +18,7 @@
 
 #include <optional>
 
+#include <android-base/logging.h>
 #include <audio_utils/clock.h>
 #include <mediautils/EventLog.h>
 #include <mediautils/MethodStatistics.h>
@@ -199,8 +200,23 @@
     }
 
     LOG_EVENT_STRING(LOGTAG_AUDIO_BINDER_TIMEOUT, tag.c_str());
-    LOG_ALWAYS_FATAL("TimeCheck timeout for %s scheduled %s on thread %d\n%s",
-            tag.c_str(), formatTime(startTime).c_str(), tid, summary.c_str());
+
+    // Create abort message string - caution: this can be very large.
+    const std::string abortMessage = std::string("TimeCheck timeout for ")
+            .append(tag)
+            .append(" scheduled ").append(formatTime(startTime))
+            .append(" on thread ").append(std::to_string(tid)).append("\n")
+            .append(summary);
+
+    // Note: LOG_ALWAYS_FATAL limits the size of the string - per log/log.h:
+    // Log message text may be truncated to less than an
+    // implementation-specific limit (1023 bytes).
+    //
+    // Here, we send the string through android-base/logging.h LOG()
+    // to avoid the size limitation. LOG(FATAL) does an abort whereas
+    // LOG(FATAL_WITHOUT_ABORT) does not abort.
+
+    LOG(FATAL) << abortMessage;
 }
 
 // Automatically create a TimeCheck class for a class and method.
diff --git a/media/utils/TimerThread.cpp b/media/utils/TimerThread.cpp
index b82816f..3556d7d 100644
--- a/media/utils/TimerThread.cpp
+++ b/media/utils/TimerThread.cpp
@@ -22,6 +22,7 @@
 #include <vector>
 
 #include <mediautils/TimerThread.h>
+#include <utils/CallStack.h>
 #include <utils/ThreadDefs.h>
 
 namespace android::mediautils {
@@ -68,6 +69,19 @@
     if (!analysis.summary.empty()) {
         analysisSummary = std::string("\nanalysis [ ").append(analysis.summary).append(" ]");
     }
+    std::string timeoutStack;
+    if (analysis.timeoutTid != -1) {
+        timeoutStack = std::string("\ntimeout(")
+                .append(std::to_string(analysis.timeoutTid)).append(") callstack [\n")
+                .append(tidCallStackString(analysis.timeoutTid)).append("]");
+    }
+    std::string blockedStack;
+    if (analysis.HALBlockedTid != -1) {
+        blockedStack = std::string("\nblocked(")
+                .append(std::to_string(analysis.HALBlockedTid)).append(")  callstack [\n")
+                .append(tidCallStackString(analysis.HALBlockedTid)).append("]");
+    }
+
     return std::string("now ")
             .append(formatTime(std::chrono::system_clock::now()))
             .append(analysisSummary)
@@ -77,7 +91,9 @@
             .append(requestsToString(pendingRequests))
             .append(" ]\nretired [ ")
             .append(requestsToString(retiredRequests))
-            .append(" ]");
+            .append(" ]")
+            .append(timeoutStack)
+            .append(blockedStack);
 }
 
 // A HAL method is where the substring "Hidl" is in the class name.
@@ -197,6 +213,13 @@
     return requestsToString(timeoutRequests);
 }
 
+/* static */
+std::string TimerThread::tidCallStackString(pid_t tid) {
+    CallStack cs{};
+    cs.update(0 /* ignoreDepth */, tid);
+    return cs.toString().c_str();
+}
+
 std::string TimerThread::Request::toString() const {
     const auto scheduledString = formatTime(scheduled);
     const auto deadlineString = formatTime(deadline);
diff --git a/media/utils/include/mediautils/TimerThread.h b/media/utils/include/mediautils/TimerThread.h
index ffee602..b69e02c 100644
--- a/media/utils/include/mediautils/TimerThread.h
+++ b/media/utils/include/mediautils/TimerThread.h
@@ -125,6 +125,11 @@
         return s;
     }
 
+    /**
+     * Returns callstack of tid as a string.
+     */
+    static std::string tidCallStackString(pid_t tid);
+
   private:
     // To minimize movement of data, we pass around shared_ptrs to Requests.
     // These are allocated and deallocated outside of the lock.