Attempt to catch linux hang

Author: alan-george-lk

.github/scripts/run_tests_with_backtrace.sh

@@ -2,6 +2,10 @@
 # Run a test binary under debug CI. On fatal signals, print post-mortem
 # backtraces from core dumps when available. Linux also runs under catchsegv
 # so a partial backtrace appears in the log even without a core file.
+#
+# When LIVEKIT_TEST_STALL_SECONDS is set to a positive integer, a watchdog
+# monitors test output and dumps live thread backtraces if the log goes silent
+# for that many seconds (integration-test hang diagnostics on linux-x64).
 set -uo pipefail
 
 usage() {
@@ -57,6 +61,36 @@ dump_macos_crash_reports() {
   fi
 }
 
+dump_live_backtraces() {
+  local test_pid=$1
+  local reason=$2
+
+  echo "=== live backtrace diagnostics (${reason}, pid ${test_pid}) ==="
+
+  if [[ "$(uname -s)" == "Linux" ]]; then
+    if command -v gdb >/dev/null 2>&1; then
+      gdb -batch \
+        -ex 'set pagination off' \
+        -ex 'thread apply all bt full' \
+        -p "${test_pid}" || true
+    else
+      echo "gdb not available; install gdb for live backtraces"
+    fi
+    return 0
+  fi
+
+  if [[ "$(uname -s)" == "Darwin" ]]; then
+    if command -v sample >/dev/null 2>&1; then
+      sample "${test_pid}" 5 -mayDie 2>&1 || true
+    fi
+    if command -v lldb >/dev/null 2>&1; then
+      lldb -p "${test_pid}" --batch -o 'thread backtrace all' -o 'detach' -o 'quit' 2>&1 || true
+    else
+      echo "lldb not available"
+    fi
+  fi
+}
+
 dump_backtraces() {
   local test_pid=$1
   local status=$2
@@ -122,11 +156,57 @@ run_test() {
   fi
 }
 
+start_stall_watchdog() {
+  local test_pid=$1
+  local log_file=$2
+  local stall_limit=$3
+
+  (
+    local last_size=-1
+    local stall=0
+    while kill -0 "${test_pid}" 2>/dev/null; do
+      local size
+      size=$(wc -c <"${log_file}" 2>/dev/null || echo 0)
+      if [[ "${size}" == "${last_size}" ]]; then
+        stall=$((stall + 5))
+      else
+        stall=0
+        last_size=${size}
+      fi
+      if ((stall >= stall_limit)); then
+        echo "=== TEST HANG DETECTED: no output for ${stall}s (pid ${test_pid}) ==="
+        echo "--- last log lines ---"
+        tail -n 40 "${log_file}" || true
+        dump_live_backtraces "${test_pid}" "stall ${stall}s"
+        kill -ABRT "${test_pid}" 2>/dev/null || kill -TERM "${test_pid}" 2>/dev/null || true
+        break
+      fi
+      sleep 5
+    done
+  ) &
+  echo $!
+}
+
+stall_limit=${LIVEKIT_TEST_STALL_SECONDS:-0}
+log_file="${RUNNER_TEMP:-/tmp}/livekit-test-output.log"
+
 set +e
-run_test "$@" &
-test_pid=$!
-wait "${test_pid}"
-status=$?
+if ((stall_limit > 0)); then
+  : >"${log_file}"
+  run_test "$@" >"${log_file}" 2>&1 &
+  test_pid=$!
+  watchdog_pid=$(start_stall_watchdog "${test_pid}" "${log_file}" "${stall_limit}")
+  wait "${test_pid}"
+  status=$?
+  kill "${watchdog_pid}" 2>/dev/null || true
+  wait "${watchdog_pid}" 2>/dev/null || true
+  cat "${log_file}"
+else
+  run_test "$@" &
+  test_pid=$!
+  wait "${test_pid}"
+  status=$?
+fi
 set -e
 
 if ((status > 128)); then

.github/workflows/tests.yml

@@ -191,6 +191,8 @@ jobs:
           - os: ubuntu-latest
             name: linux-x64
             e2e-testing: true
+            # Extra FFI logging on linux-x64 to diagnose timing-sensitive integration hangs.
+            integration_rust_log: info,livekit_ffi::server=debug
           - os: ubuntu-24.04-arm
             name: linux-arm64
             e2e-testing: true
@@ -508,8 +510,11 @@ jobs:
         timeout-minutes: ${{ inputs.integration_timeout_minutes }}
         shell: bash
         env:
-          RUST_LOG: ${{ inputs.integration_rust_log }}
+          RUST_LOG: ${{ matrix.integration_rust_log || inputs.integration_rust_log }}
           RUST_BACKTRACE: full
+          # linux-x64: verbose C++ logs + stall watchdog (see run_tests_with_backtrace.sh).
+          LIVEKIT_TEST_LOG_LEVEL: ${{ matrix.name == 'linux-x64' && 'debug' || '' }}
+          LIVEKIT_TEST_STALL_SECONDS: ${{ matrix.name == 'linux-x64' && '90' || '0' }}
         run: |
           set -euo pipefail
           source .token_helpers/set_data_track_test_tokens.bash

src/tests/common/test_common.h

@@ -144,6 +144,37 @@ inline bool waitForParticipant(Room* room, const std::string& identity, std::chr
 /// once the room is torn down (or before connect). Dereferencing the result of
 /// lock() blindly is undefined behavior, so tests must go through this helper,
 /// which throws instead of crashing when the handle is expired.
+/// Resolve integration-test log verbosity from LIVEKIT_TEST_LOG_LEVEL (trace/debug/info/...).
+inline livekit::LogLevel testLogLevelFromEnv() {
+  const char* level = std::getenv("LIVEKIT_TEST_LOG_LEVEL");
+  if (level == nullptr || std::string(level).empty()) {
+    return livekit::LogLevel::Info;
+  }
+  const std::string value(level);
+  if (value == "trace") {
+    return livekit::LogLevel::Trace;
+  }
+  if (value == "debug") {
+    return livekit::LogLevel::Debug;
+  }
+  if (value == "info") {
+    return livekit::LogLevel::Info;
+  }
+  if (value == "warn") {
+    return livekit::LogLevel::Warn;
+  }
+  if (value == "error") {
+    return livekit::LogLevel::Error;
+  }
+  if (value == "critical") {
+    return livekit::LogLevel::Critical;
+  }
+  if (value == "off") {
+    return livekit::LogLevel::Off;
+  }
+  return livekit::LogLevel::Info;
+}
+
 inline std::shared_ptr<LocalParticipant> lockLocalParticipant(const Room& room) {
   if (auto participant = room.localParticipant().lock()) {
     return participant;
@@ -497,7 +528,7 @@ class StressTestStats {
 class LiveKitTestBase : public ::testing::Test {
 protected:
   void SetUp() override {
-    livekit::initialize(livekit::LogLevel::Info);
+    livekit::initialize(testLogLevelFromEnv());
     config_ = TestConfig::fromEnv();
 
     // Tracing is controlled by compile-time macro LIVEKIT_TEST_ENABLE_TRACING