forked from ppy/osu
-
Notifications
You must be signed in to change notification settings - Fork 0
Add 5s hang watchdog and one-shot Android FrameSync→VSync migration #245
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Merged
Merged
Changes from all commits
Commits
File filter
Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
There are no files selected for viewing
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change | ||||||||||||||||||||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| @@ -0,0 +1,349 @@ | ||||||||||||||||||||||||||||||||||||
| // Copyright (c) ppy Pty Ltd <contact@ppy.sh>. Licensed under the MIT Licence. | ||||||||||||||||||||||||||||||||||||
| // See the LICENCE file in the repository root for full licence text. | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| using System; | ||||||||||||||||||||||||||||||||||||
| using System.Collections.Generic; | ||||||||||||||||||||||||||||||||||||
| using System.IO; | ||||||||||||||||||||||||||||||||||||
| using System.Runtime.InteropServices; | ||||||||||||||||||||||||||||||||||||
| using System.Text; | ||||||||||||||||||||||||||||||||||||
| using System.Threading; | ||||||||||||||||||||||||||||||||||||
| using Debug = System.Diagnostics.Debug; | ||||||||||||||||||||||||||||||||||||
| using osu.Framework.Platform; | ||||||||||||||||||||||||||||||||||||
| using osu.Framework.Threading; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| namespace osu.Android | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| /// <summary> | ||||||||||||||||||||||||||||||||||||
| /// Per-GameThread liveness watchdog that detects multi-second stalls on the | ||||||||||||||||||||||||||||||||||||
| /// Update / Draw / Audio / Input threads and dumps a rich snapshot of every | ||||||||||||||||||||||||||||||||||||
| /// Linux thread in the process (comm, wchan, syscall, status) into the | ||||||||||||||||||||||||||||||||||||
| /// existing <c>native_crash.log</c>. | ||||||||||||||||||||||||||||||||||||
| /// | ||||||||||||||||||||||||||||||||||||
| /// <para> | ||||||||||||||||||||||||||||||||||||
| /// The dump is the actionable signal: <c>/proc/self/task/<tid>/wchan</c> | ||||||||||||||||||||||||||||||||||||
| /// names the kernel function each thread is waiting in, and | ||||||||||||||||||||||||||||||||||||
| /// <c>/proc/self/task/<tid>/syscall</c> gives the active syscall number | ||||||||||||||||||||||||||||||||||||
| /// plus the user-space PC. Together these pinpoint Vulkan present-queue | ||||||||||||||||||||||||||||||||||||
| /// stalls (futex on the GPU driver), Realm fifo waits, AAudio polls, GC | ||||||||||||||||||||||||||||||||||||
| /// pauses, etc., without needing adb access. | ||||||||||||||||||||||||||||||||||||
| /// </para> | ||||||||||||||||||||||||||||||||||||
| /// | ||||||||||||||||||||||||||||||||||||
| /// <para> | ||||||||||||||||||||||||||||||||||||
| /// The hang threshold is intentionally short (5s): the runtime log can grow | ||||||||||||||||||||||||||||||||||||
| /// to ~70MB on the user's device, so we'd rather over-dump than miss a | ||||||||||||||||||||||||||||||||||||
| /// stall, but we still rate-limit re-dumps of the same hang to one every | ||||||||||||||||||||||||||||||||||||
| /// 10s so we don't fill the log in a single second of frozen state. | ||||||||||||||||||||||||||||||||||||
| /// </para> | ||||||||||||||||||||||||||||||||||||
| /// </summary> | ||||||||||||||||||||||||||||||||||||
| internal static class HangWatchdog | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| // Threshold above which a thread is considered hung. Any GameThread that | ||||||||||||||||||||||||||||||||||||
| // fails to drain a queued no-op for this long triggers a snapshot. | ||||||||||||||||||||||||||||||||||||
| private const int hang_threshold_ms = 5_000; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| // Heartbeat scheduling cadence. Each game thread executes a no-op every | ||||||||||||||||||||||||||||||||||||
| // ~1s via Scheduler.AddDelayed(repeat: true) which updates its last-tick | ||||||||||||||||||||||||||||||||||||
| // timestamp; the monitor wakes at the same cadence to evaluate ages. | ||||||||||||||||||||||||||||||||||||
| private const int heartbeat_interval_ms = 1_000; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| // Minimum gap between two consecutive snapshots while still hung. Without | ||||||||||||||||||||||||||||||||||||
| // this, a 60s hang would generate 12 full /proc/self/task dumps and | ||||||||||||||||||||||||||||||||||||
| // potentially blow the log size cap in a few seconds. | ||||||||||||||||||||||||||||||||||||
| private const int redump_cooldown_ms = 10_000; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| // Maximum number of distinct hang dumps written for the lifetime of the | ||||||||||||||||||||||||||||||||||||
| // process. Prevents pathological "permanent hang plus runaway watchdog" | ||||||||||||||||||||||||||||||||||||
| // from filling the log indefinitely if the cooldown logic ever misbehaves. | ||||||||||||||||||||||||||||||||||||
| private const int max_dumps_per_process = 200; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| private static int started; | ||||||||||||||||||||||||||||||||||||
| private static Thread? monitorThread; | ||||||||||||||||||||||||||||||||||||
| private static readonly Heartbeat[] heartbeats = new Heartbeat[4]; | ||||||||||||||||||||||||||||||||||||
| private static int dumpCount; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| // libc.gettid: returns the Linux kernel thread id of the calling thread. | ||||||||||||||||||||||||||||||||||||
| // We need this (not managed Thread.ManagedThreadId) to map heartbeats to | ||||||||||||||||||||||||||||||||||||
| // /proc/self/task/<tid>/* entries. | ||||||||||||||||||||||||||||||||||||
| [DllImport("libc", EntryPoint = "gettid", SetLastError = false)] | ||||||||||||||||||||||||||||||||||||
| private static extern int gettid(); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| /// <summary> | ||||||||||||||||||||||||||||||||||||
| /// Begin watchdog monitoring against the four standard <see cref="GameHost"/> | ||||||||||||||||||||||||||||||||||||
| /// threads. Idempotent: a second call after the monitor is already running | ||||||||||||||||||||||||||||||||||||
| /// is a no-op. Safe to call from any thread; the monitor itself runs on a | ||||||||||||||||||||||||||||||||||||
| /// dedicated background OS thread that never enters managed game code. | ||||||||||||||||||||||||||||||||||||
| /// </summary> | ||||||||||||||||||||||||||||||||||||
| public static void Start(GameHost? host) | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| if (host == null) return; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| if (Interlocked.Exchange(ref started, 1) != 0) | ||||||||||||||||||||||||||||||||||||
| return; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| try | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| heartbeats[0] = new Heartbeat("Update", host.UpdateThread); | ||||||||||||||||||||||||||||||||||||
| heartbeats[1] = new Heartbeat("Draw", host.DrawThread); | ||||||||||||||||||||||||||||||||||||
| heartbeats[2] = new Heartbeat("Audio", host.AudioThread); | ||||||||||||||||||||||||||||||||||||
| heartbeats[3] = new Heartbeat("Input", host.InputThread); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| foreach (var hb in heartbeats) | ||||||||||||||||||||||||||||||||||||
| hb.Arm(); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| monitorThread = new Thread(monitorLoop) | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| Name = "HangWatchdog", | ||||||||||||||||||||||||||||||||||||
| IsBackground = true, | ||||||||||||||||||||||||||||||||||||
| }; | ||||||||||||||||||||||||||||||||||||
| monitorThread.Start(); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| CrashDiagnostics.WriteAliveMarker($"HangWatchdog.Start (threshold={hang_threshold_ms}ms, cooldown={redump_cooldown_ms}ms)"); | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
| catch (Exception e) | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| Debug.WriteLine($"[osu!] HangWatchdog.Start failed: {e.Message}"); | ||||||||||||||||||||||||||||||||||||
| Interlocked.Exchange(ref started, 0); | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| private static void monitorLoop() | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| // Per-thread cooldown so each thread can dump independently without | ||||||||||||||||||||||||||||||||||||
| // starving the others (e.g. Audio hung 30s while Draw hangs at 50s | ||||||||||||||||||||||||||||||||||||
| // should still produce two distinct snapshots). | ||||||||||||||||||||||||||||||||||||
| long[] lastDumpUtcMs = new long[heartbeats.Length]; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| while (true) | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| try | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| Thread.Sleep(heartbeat_interval_ms); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| if (dumpCount >= max_dumps_per_process) | ||||||||||||||||||||||||||||||||||||
| continue; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| long nowMs = nowUtcMs(); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| for (int i = 0; i < heartbeats.Length; i++) | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| var hb = heartbeats[i]; | ||||||||||||||||||||||||||||||||||||
| if (hb == null) continue; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| long lastTickMs = Interlocked.Read(ref hb.LastTickUtcMs); | ||||||||||||||||||||||||||||||||||||
| long armedAtMs = Interlocked.Read(ref hb.ArmedAtUtcMs); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| // A thread that has never ticked yet is treated as hung | ||||||||||||||||||||||||||||||||||||
| // once it has been armed for longer than the threshold — | ||||||||||||||||||||||||||||||||||||
| // this catches startup deadlocks where the GameThread | ||||||||||||||||||||||||||||||||||||
| // never actually starts running its Scheduler. | ||||||||||||||||||||||||||||||||||||
| long referenceMs = lastTickMs > 0 ? lastTickMs : armedAtMs; | ||||||||||||||||||||||||||||||||||||
| if (referenceMs <= 0) continue; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| long ageMs = nowMs - referenceMs; | ||||||||||||||||||||||||||||||||||||
| if (ageMs < hang_threshold_ms) continue; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| if (nowMs - lastDumpUtcMs[i] < redump_cooldown_ms) continue; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| lastDumpUtcMs[i] = nowMs; | ||||||||||||||||||||||||||||||||||||
| dumpHang(hb, ageMs, lastTickMs > 0); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| // Re-arm so that if the thread eventually recovers we | ||||||||||||||||||||||||||||||||||||
| // start counting from the recovery point, not the start | ||||||||||||||||||||||||||||||||||||
| // of the original hang. | ||||||||||||||||||||||||||||||||||||
| hb.Arm(); | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
| catch (Exception e) | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| Debug.WriteLine($"[osu!] HangWatchdog monitor loop iteration failed: {e.Message}"); | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
| // ReSharper disable once FunctionNeverReturns -- by design; monitor lives for the process. | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| private static void dumpHang(Heartbeat hb, long ageMs, bool everTicked) | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| int currentDump = Interlocked.Increment(ref dumpCount); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| try | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| var sb = new StringBuilder(16 * 1024); | ||||||||||||||||||||||||||||||||||||
| sb.Append("\n=========================================================\n"); | ||||||||||||||||||||||||||||||||||||
| sb.Append("=== HANG WATCHDOG TRIGGER ===\n"); | ||||||||||||||||||||||||||||||||||||
| sb.Append($" utc_time = {DateTime.UtcNow:O}\n"); | ||||||||||||||||||||||||||||||||||||
| sb.Append($" thread = {hb.Name} (GameThread)\n"); | ||||||||||||||||||||||||||||||||||||
| sb.Append($" age_ms = {ageMs}\n"); | ||||||||||||||||||||||||||||||||||||
| sb.Append($" ever_ticked = {everTicked}\n"); | ||||||||||||||||||||||||||||||||||||
| sb.Append($" game_tid = {Interlocked.Read(ref hb.LinuxTid)}\n"); | ||||||||||||||||||||||||||||||||||||
| sb.Append($" dump_index = {currentDump}/{max_dumps_per_process}\n"); | ||||||||||||||||||||||||||||||||||||
| sb.Append("\n--- Heartbeats ---\n"); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| long now = nowUtcMs(); | ||||||||||||||||||||||||||||||||||||
| foreach (var other in heartbeats) | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| if (other == null) continue; | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| long t = Interlocked.Read(ref other.LastTickUtcMs); | ||||||||||||||||||||||||||||||||||||
| long a = Interlocked.Read(ref other.ArmedAtUtcMs); | ||||||||||||||||||||||||||||||||||||
| long otherAge = t > 0 ? now - t : (a > 0 ? now - a : -1); | ||||||||||||||||||||||||||||||||||||
| sb.Append($" {other.Name,-7} tid={Interlocked.Read(ref other.LinuxTid),-7} age_ms={otherAge,-7} ticks={Interlocked.Read(ref other.TickCount)}\n"); | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| sb.Append("\n--- /proc/self/task snapshot ---\n"); | ||||||||||||||||||||||||||||||||||||
| appendProcTaskSnapshot(sb); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| sb.Append("=== END OF HANG WATCHDOG TRIGGER ===\n\n"); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| CrashDiagnostics.AppendDiagnosticBlock(sb.ToString()); | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
| catch (Exception e) | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| Debug.WriteLine($"[osu!] HangWatchdog.dumpHang failed: {e.Message}"); | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| private static void appendProcTaskSnapshot(StringBuilder sb) | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| try | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| // /proc/self/task entries are subdirectories, not files, so | ||||||||||||||||||||||||||||||||||||
| // enumerate via Directory.EnumerateDirectories and extract the | ||||||||||||||||||||||||||||||||||||
| // numeric tid from each path leaf. | ||||||||||||||||||||||||||||||||||||
| var collected = new List<string>(64); | ||||||||||||||||||||||||||||||||||||
| try | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| foreach (string dir in Directory.EnumerateDirectories("/proc/self/task")) | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| string leaf = Path.GetFileName(dir); | ||||||||||||||||||||||||||||||||||||
| if (!string.IsNullOrEmpty(leaf)) | ||||||||||||||||||||||||||||||||||||
| collected.Add(leaf); | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
| catch (Exception e) | ||||||||||||||||||||||||||||||||||||
| { | ||||||||||||||||||||||||||||||||||||
| sb.Append($" (failed to enumerate /proc/self/task: {e.Message})\n"); | ||||||||||||||||||||||||||||||||||||
| return; | ||||||||||||||||||||||||||||||||||||
| } | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
| // Sort by tid so consecutive dumps for the same hang produce | ||||||||||||||||||||||||||||||||||||
| // diff-able output — makes it easy to spot which thread changed | ||||||||||||||||||||||||||||||||||||
| // state between two snapshots taken 10s apart during a long hang. | ||||||||||||||||||||||||||||||||||||
| collected.Sort(StringComparer.Ordinal); | ||||||||||||||||||||||||||||||||||||
|
|
||||||||||||||||||||||||||||||||||||
|
Comment on lines
+231
to
+232
|
||||||||||||||||||||||||||||||||||||
| collected.Sort(StringComparer.Ordinal); | |
| collected.Sort((x, y) => | |
| { | |
| bool xParsed = int.TryParse(x, out int xTid); | |
| bool yParsed = int.TryParse(y, out int yTid); | |
| if (xParsed && yParsed) | |
| return xTid.CompareTo(yTid); | |
| if (xParsed) | |
| return -1; | |
| if (yParsed) | |
| return 1; | |
| return StringComparer.Ordinal.Compare(x, y); | |
| }); |
Oops, something went wrong.
Oops, something went wrong.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
hb.Arm()is called after every hang dump, butHeartbeat.Arm()schedules a repeatingScheduler.AddDelayed(..., repeat: true)each time. This will accumulate multiple repeating heartbeats per thread after repeated hangs/re-dumps (extra queued work every second, and potential memory/leakage). Consider scheduling the repeating tick exactly once per thread (store/cancel the scheduled delegate), and on re-arm only reset the timestamps/counters instead of adding another repeating schedule.