| 1 | package main |
| 2 | |
| 3 | import ( |
| 4 | "context" |
| 5 | "fmt" |
| 6 | "log/slog" |
| 7 | goruntime "runtime" |
| 8 | "sync/atomic" |
| 9 | "time" |
| 10 | ) |
| 11 | |
| 12 | const ( |
| 13 | mainThreadHeartbeatInterval = time.Second |
| 14 | mainThreadHangThreshold = 12 * time.Second |
| 15 | mainThreadHangCheckInterval = 2 * time.Second |
| 16 | mainThreadSleepSkip = 30 * time.Second |
| 17 | ) |
| 18 | |
| 19 | var ( |
| 20 | mainThreadClockBase = time.Now() |
| 21 | mainThreadLastHeartbeatElapsed atomic.Int64 |
| 22 | mainThreadLastHeartbeatWall atomic.Int64 |
| 23 | mainThreadHangReported atomic.Bool |
| 24 | ) |
| 25 | |
| 26 | func recordMainThreadHeartbeat(t time.Time) { |
| 27 | elapsed := t.Sub(mainThreadClockBase) |
| 28 | if elapsed < 0 { |
| 29 | elapsed = 0 |
| 30 | } |
| 31 | mainThreadLastHeartbeatElapsed.Store(int64(elapsed)) |
| 32 | mainThreadLastHeartbeatWall.Store(t.UnixNano()) |
| 33 | } |
| 34 | |
| 35 | func mainThreadHeartbeatAge(now time.Time) (time.Duration, time.Time, bool) { |
| 36 | lastElapsed := time.Duration(mainThreadLastHeartbeatElapsed.Load()) |
| 37 | lastWall := mainThreadLastHeartbeatWall.Load() |
| 38 | if lastWall <= 0 { |
| 39 | return 0, time.Time{}, false |
| 40 | } |
| 41 | age := now.Sub(mainThreadClockBase) - lastElapsed |
| 42 | if age < 0 { |
| 43 | age = 0 |
| 44 | } |
| 45 | return age, time.Unix(0, lastWall), true |
| 46 | } |
| 47 | |
| 48 | func resetMainThreadHeartbeatAfterSleep(lastCheck, now time.Time) bool { |
| 49 | if now.Sub(lastCheck) <= mainThreadSleepSkip { |
| 50 | return false |
| 51 | } |
| 52 | // The native UI heartbeat and this Go ticker are both suspended while the |
| 53 | // machine sleeps. Treat wake as a fresh observation epoch so the sleep gap |
| 54 | // cannot be reported as a multi-minute UI-thread hang on the next tick. |
| 55 | recordMainThreadHeartbeat(now) |
| 56 | return true |
| 57 | } |
| 58 | |
| 59 | func (a *App) startMainThreadWatchdog() { |
| 60 | if !mainThreadWatchdogSupported() { |
| 61 | return |
| 62 | } |
| 63 | a.hangWatchdogMu.Lock() |
| 64 | if a.hangWatchdogCancel != nil { |
| 65 | a.hangWatchdogMu.Unlock() |
| 66 | return |
| 67 | } |
| 68 | ctx, cancel := context.WithCancel(context.Background()) |
| 69 | a.hangWatchdogCancel = cancel |
| 70 | mainThreadHangReported.Store(false) |
| 71 | recordMainThreadHeartbeat(time.Now()) |
| 72 | startNativeMainThreadHeartbeat(uint64(mainThreadHeartbeatInterval / time.Millisecond)) |
| 73 | a.hangWatchdogMu.Unlock() |
| 74 | |
| 75 | a.goSafe("mainThreadHangWatchdog", func() { |
| 76 | a.watchMainThreadHeartbeat(ctx) |
| 77 | }) |
| 78 | } |
| 79 | |
| 80 | func (a *App) stopMainThreadWatchdog() { |
| 81 | if !mainThreadWatchdogSupported() { |
| 82 | return |
| 83 | } |
| 84 | a.hangWatchdogMu.Lock() |
| 85 | cancel := a.hangWatchdogCancel |
| 86 | a.hangWatchdogCancel = nil |
| 87 | a.hangWatchdogMu.Unlock() |
| 88 | if cancel != nil { |
| 89 | cancel() |
| 90 | } |
| 91 | stopNativeMainThreadHeartbeat() |
| 92 | } |
| 93 | |
| 94 | func (a *App) watchMainThreadHeartbeat(ctx context.Context) { |
| 95 | ticker := time.NewTicker(mainThreadHangCheckInterval) |
| 96 | defer ticker.Stop() |
| 97 | lastCheck := time.Now() |
| 98 | for { |
| 99 | select { |
| 100 | case <-ctx.Done(): |
| 101 | return |
| 102 | case now := <-ticker.C: |
| 103 | if resetMainThreadHeartbeatAfterSleep(lastCheck, now) { |
| 104 | lastCheck = now |
| 105 | continue |
| 106 | } |
| 107 | lastCheck = now |
| 108 | age, last, ok := mainThreadHeartbeatAge(now) |
| 109 | if !ok { |
| 110 | continue |
| 111 | } |
| 112 | if age < mainThreadHangThreshold { |
| 113 | continue |
| 114 | } |
| 115 | if mainThreadHangReported.CompareAndSwap(false, true) { |
| 116 | a.recordMainThreadHang(age, last, now) |
| 117 | } |
| 118 | } |
| 119 | } |
| 120 | } |
| 121 | |
| 122 | func (a *App) recordMainThreadHang(age time.Duration, lastHeartbeat, observedAt time.Time) { |
| 123 | report := mainThreadHangReport(age, lastHeartbeat, observedAt) |
| 124 | wrote := writePendingReport(report, true) |
| 125 | if m := a.metrics.Load(); m != nil { |
| 126 | m.inc("desktop_hang", mainThreadMetricBucket()) |
| 127 | m.inc("desktop_hang_age", hangAgeBucket(age)) |
| 128 | m.persist() |
| 129 | } |
| 130 | slog.Warn("desktop: native UI thread heartbeat stalled", |
| 131 | "age", age.Round(time.Millisecond).String(), |
| 132 | "lastHeartbeat", lastHeartbeat.Format(time.RFC3339), |
| 133 | "pendingReport", wrote, |
| 134 | ) |
| 135 | } |
| 136 | |
| 137 | func mainThreadHangReport(age time.Duration, lastHeartbeat, observedAt time.Time) crashReport { |
| 138 | label, errorType, platformName, topFrame := mainThreadDiagnosticIdentity() |
| 139 | age = age.Round(time.Second) |
| 140 | message := fmt.Sprintf(`[%s] |
| 141 | |
| 142 | Reasonix detected that the %s UI-thread heartbeat stopped for %s. |
| 143 | |
| 144 | --- watchdog context --- |
| 145 | last heartbeat: %s |
| 146 | observed at: %s |
| 147 | threshold: %s |
| 148 | bucket: %s |
| 149 | |
| 150 | --- native runtime context --- |
| 151 | %s`, |
| 152 | label, |
| 153 | platformName, |
| 154 | age, |
| 155 | lastHeartbeat.UTC().Format(time.RFC3339), |
| 156 | observedAt.UTC().Format(time.RFC3339), |
| 157 | mainThreadHangThreshold, |
| 158 | hangAgeBucket(age), |
| 159 | nativeResourceContext(), |
| 160 | ) |
| 161 | report := baseCrashReport("performance") |
| 162 | report.SchemaVersion = 2 |
| 163 | report.Source = "native.watchdog" |
| 164 | report.Label = label |
| 165 | report.ErrorType = errorType |
| 166 | report.ErrorMessage = sanitizeCrashText(platformName+" UI thread heartbeat stopped; the native/Wails message loop may be blocked.", maxCrashFieldBytes) |
| 167 | report.TopFrame = topFrame |
| 168 | report.OccurredAt = observedAt.UTC().Format(time.RFC3339) |
| 169 | report.Message = sanitizeCrashText(message, maxCrashDetailBytes) |
| 170 | return report |
| 171 | } |
| 172 | |
| 173 | func mainThreadDiagnosticIdentity() (label, errorType, platformName, topFrame string) { |
| 174 | if goruntime.GOOS == "windows" { |
| 175 | return "windows.ui_thread.hang", "WindowsUIThreadHang", "Windows", "windows.ui_thread.heartbeat" |
| 176 | } |
| 177 | return "mac.main_thread.hang", "MacMainThreadHang", "macOS", "mac.main_thread.heartbeat" |
| 178 | } |
| 179 | |
| 180 | func mainThreadMetricBucket() string { |
| 181 | if goruntime.GOOS == "windows" { |
| 182 | return "windows_ui_thread" |
| 183 | } |
| 184 | return "main_thread" |
| 185 | } |
| 186 | |
| 187 | func hangAgeBucket(age time.Duration) string { |
| 188 | seconds := age.Seconds() |
| 189 | switch { |
| 190 | case seconds < 15: |
| 191 | return "s_10_15" |
| 192 | case seconds < 30: |
| 193 | return "s_15_30" |
| 194 | case seconds < 60: |
| 195 | return "s_30_60" |
| 196 | case seconds < 300: |
| 197 | return "m_1_5" |
| 198 | default: |
| 199 | return "m_5_plus" |
| 200 | } |
| 201 | } |
| 202 |