yenru0/zed
1
0 Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

gpui: Make ForegroundJournal aware of sleep and window visibility (#64269)

Browse Source 
## Summary

Keep foreground-work measurements and per-window presentation
expectations valid across observed sleep/wake and visibility changes.
Simplified after review to about 530 changed lines including tests and
configuration.

## Scope

- Keep all measurement state in the foreground-local journal writer. Use
`PowerState` and `PowerTransition`; no new locks, counters, or changes
to the ring protocol.
- Work that started at or before the last power transition (or while
suspended) is dropped when it completes: task polls before small-poll
folding, and actions, inputs, draws, and presents through the same
`power_interrupted_since(start)` check. No per-activity state is added;
every measurement already carries its start time.
- Track visibility and pending frames together per window. Hiding or
sleeping clears the presentation expectation; on recovery
`Window::refresh_visibility` re-records it from the window's actual
dirty state, so the journal never guesses. Old latency associations
remain invalid.
- Repeated notifications for the same power state are ignored, so a
duplicate wake does not invalidate in-flight work.
- The journal subscribes to GPUI's existing power notifications and
rechecks native window visibility after wake. App only registers these
subscriptions (two initialization lines).
- Keep the existing one-second pending-frame deadline and
foreground-turn sealing behavior. No watchdog, recurring timer, test-app
exceptions, unfinished-hang detection, start/end ring notices, or
reader-side deduplication.
- Remove lifecycle counters. Keep measurement version 2 on reports and a
valid dirty-to-present sample count for weighting averages.

## Telemetry

- `Hang Incidents` gains `report_window_seconds` and stall percentiles
over every incident in the window (`stall_p50_ms`, `stall_p95_ms`,
`stall_max_ms`, from an `hdrhistogram`), so stall distributions no
longer depend on the censored `incidents[]` list. Reports are now sent
even when no incident occurred, so summing `report_window_seconds` gives
observed running time for incident rates.
- `Frame Duration Report` gains dirty-to-present percentiles
(`dirty_to_present_p50_ms`, `dirty_to_present_p95_ms`,
`dirty_to_present_max_ms`) alongside the existing average, and
`average_present_interval_ms` (mean frame-to-frame interval while
animating, a proxy for the display's refresh interval when normalizing
dirty-to-present).

Detection remains completion-based. This does not solve hangs that never
return or force an interval to seal when no further foreground events
arrive. Existing legacy hang logs/trace triggers are unchanged. Late or
coalesced platform notifications remain a coverage limitation.

## Validation

- `corgi test -p gpui --features profiler --lib`: **392 tests passed**.
- Focused lifecycle/wake tests also passed a 20-seed run.
- The extension-suggestion regression that failed on all three CI
platforms now passes locally after removal of the
watchdog/test-construction changes.
- `corgi check -p gpui` and `corgi check -p zed -p input_latency_ui`
passed.
- Formatting and `git diff --check` passed.
- Corgi configuration includes only the three existing GPUI image/font
fixtures needed to run its tests.

Native platform sleep/wake testing and review remain outstanding. The
README review marker remains for the human author to remove manually
after review.

Release Notes:

- Improved the accuracy of hang and frame-latency telemetry around
sleep, wake, and hidden windows.
- [GPUI] Added a `PowerTransition` interval boundary and
`measurement_version` to profiler hang reports.
This commit is contained in:
Anthony Eid authored and GitHub committed 2026-09-16 16:00:19 +00:00
1 parent 2b4169b5db
commit 04d586b80e
10 files changed
+408 -62
Download Patch File Download Diff File Expand all files Collapse all files

No files matched your search

Cargo.lock
Generated
+1
View File
@@ -22938,6 +22938,7 @@ dependencies = [
"gpui",
"gpui_platform",
"gpui_tokio",
"hdrhistogram",
"http_client",
"image",
"image_viewer",
corgi.toml
+6 -1
View File
@@ -64,7 +64,12 @@ profiles = ["release"]
proto = ["proto/**"]
livekit_api = ["vendored/protocol/**"]
media = ["src/bindings.h"]
gpui = ["README.md"]
gpui = [
"README.md",
"examples/image/exif-orientation-rotate-180.jpg",
"../../assets/fonts/ibm-plex-sans/IBMPlexSans-Regular.ttf",
"../../assets/fonts/lilex/Lilex-Regular.ttf",
]
git = ["src/checkpoint.gitignore"]
git_ui = ["src/commit_message_prompt.txt"]
editor = ["../grammars/src/**"]
crates/gpui/src/app.rs
+2
View File
@@ -942,6 +942,8 @@ impl App {
init_app_menus(platform.as_ref(), &app.borrow());
SystemWindowTabController::init(&mut app.borrow_mut());
#[cfg(feature = "profiler")]
crate::profiler::journal::observe_power(&app.borrow());
platform.on_keyboard_layout_change(Box::new({
let app = Rc::downgrade(&app);
crates/gpui/src/profiler.rs
+84 -22
View File
@@ -961,17 +961,26 @@ impl WindowProfiler {
return;
};
journal::record_input(journal::InputTiming {
kind,
start: started_at,
end: Instant::now(),
caused_invalidation,
});
if !journal::power_interrupted_since(started_at) {
journal::record_input(journal::InputTiming {
kind,
start: started_at,
end: Instant::now(),
caused_invalidation,
});
}
journal::end_foreground_turn();
if !caused_invalidation {
if !caused_invalidation || !journal::frame_sample_is_valid(self.window_id, started_at) {
return;
}
if self
.first_input_at
.is_some_and(|at| !journal::frame_sample_is_valid(self.window_id, at))
{
self.first_input_at = None;
self.pending_input_count = 0;
}
let arrived_during_draw = self
.active_activities
@@ -1003,11 +1012,13 @@ impl WindowProfiler {
journal::end_foreground_turn();
return;
};
journal::record_action(ActionTiming {
name,
start,
end: Instant::now(),
});
if !journal::power_interrupted_since(start) {
journal::record_action(ActionTiming {
name,
start,
end: Instant::now(),
});
}
journal::end_foreground_turn();
}
@@ -1034,13 +1045,15 @@ impl WindowProfiler {
let draw_end = Instant::now();
let frame_timing = FrameTiming {
window_id: self.window_id,
dirty_at,
dirty_at: dirty_at.filter(|at| journal::frame_sample_is_valid(self.window_id, *at)),
invalidations,
draw_start,
draw_end,
};
let draw_duration = frame_timing.draw_duration();
self.record_draw_timing(frame_timing);
if !journal::power_interrupted_since(draw_start) {
self.record_draw_timing(frame_timing);
}
journal::end_foreground_turn();
draw_duration
}
@@ -1089,21 +1102,33 @@ impl WindowProfiler {
window_active: bool,
next_frame_scheduled: bool,
) {
if let Some(first_input_at) = self.first_input_at.take() {
if let Some(first_input_at) = self.first_input_at.take()
&& journal::frame_sample_is_valid(self.window_id, first_input_at)
{
let latency_nanos = present_end.duration_since(first_input_at).as_nanos() as u64;
self.input_latency_histogram.record(latency_nanos).ok();
if self.pending_input_count > 0 {
self.events_per_frame_histogram
.record(self.pending_input_count)
.ok();
}
}
if self.pending_input_count > 0 {
self.events_per_frame_histogram
.record(self.pending_input_count)
.ok();
self.pending_input_count = 0;
}
self.pending_input_count = 0;
let frame = self.pending_frame.take();
let frame = self
.pending_frame
.take()
.filter(|frame| journal::frame_sample_is_valid(self.window_id, frame.draw_start))
.map(|mut frame| {
frame.dirty_at = frame
.dirty_at
.filter(|at| journal::frame_sample_is_valid(self.window_id, *at));
frame
});
let animation_interval =
if frame.is_some() && self.animating_at_last_present && window_active {
self.last_present_at
.filter(|at| journal::frame_sample_is_valid(self.window_id, *at))
.map(|last_present_at| present_end.duration_since(last_present_at))
} else {
None
@@ -1241,6 +1266,43 @@ mod tests {
use super::*;
use std::sync::{Mutex, MutexGuard};
#[test]
fn interruptions_drop_latency_samples_but_hiding_keeps_draw_work() {
for sleep in [false, true] {
let (_journal, _guard) = journal::install_test_foreground_journal(64, 4);
let id = WindowId::from(1);
let mut profiler = WindowProfiler::new(id).expect("valid histograms");
let old = Instant::now() - Duration::from_secs(1);
record_test_draw(&mut profiler, old);
profiler.record_present_at(old, old, true, true);
profiler.first_input_at = Some(old);
profiler.pending_input_count = 1;
profiler.begin_draw();
if sleep {
journal::record_power_transition(journal::PowerState::Suspended);
journal::record_power_transition(journal::PowerState::Awake);
} else {
journal::record_window_visibility(id, crate::WindowVisibility::Hidden);
journal::record_window_visibility(id, crate::WindowVisibility::Visible);
}
profiler.end_draw(Some(old), 1);
let now = Instant::now();
profiler.record_present_at(now, now, true, true);
assert_eq!(
profiler.draw_duration_histogram.len(),
if sleep { 1 } else { 2 }
);
assert_eq!(profiler.input_latency_histogram.len(), 0);
assert_eq!(profiler.dirty_to_present_histogram.len(), 1);
assert_eq!(profiler.present_interval_histogram.len(), 0);
profiler.begin_draw();
profiler.end_draw(Some(Instant::now()), 1);
let now = Instant::now();
profiler.record_present_at(now, now, true, true);
assert_eq!(profiler.dirty_to_present_histogram.len(), 2);
}
}
#[test]
fn records_draw_events_only_while_tracing() {
let _trace_test_guard = TraceTestGuard::new();
crates/gpui/src/profiler/hang.rs
+9 -2
View File
@@ -15,6 +15,9 @@ use std::time::Duration;
use scheduler::Instant;
use serde::Serialize;
/// Version of the power/visibility-aware measurement rules.
pub const MEASUREMENT_VERSION: u32 = 2;
use super::SerializedLocation;
use super::journal::{
ForegroundEvent, ForegroundJournal, ForegroundJournalCollector, ForegroundJournalEntry,
@@ -111,6 +114,8 @@ impl HangDetector {
/// locations as plain data, contributor count capped by the converter.
#[derive(Debug, Clone, Serialize)]
pub struct SerializedHangIncident {
/// Identifies the rules used to exclude interrupted measurements.
pub measurement_version: u32,
/// `"startup"` when the active window began before the first observed
/// newly drawn frame finished platform submission (see
/// [`HangDetector::first_present_at`]), otherwise `"steady"`.
@@ -133,7 +138,7 @@ pub struct SerializedHangIncident {
/// For presentation-sealed incidents, how long the submitted frame had
/// been dirty, in milliseconds.
pub dirty_to_present_ms: Option<f64>,
/// What closed the incident: `"present"` or `"idle"`. This labels the
/// What closed the incident: `"present"`, `"idle"`, or `"power_transition"`. This labels the
/// boundary, not the hang's cause — the cause is the first contributor.
pub sealed_by: &'static str,
/// Fraction of the active window the foreground spent working,
@@ -269,6 +274,7 @@ impl SerializedHangIncident {
Some(first_present_at) if active_start >= first_present_at => "steady",
_ => "startup",
},
measurement_version: MEASUREMENT_VERSION,
trigger: incident.trigger,
start_ms: since_startup(active_start),
active_ms: as_millis(active),
@@ -281,11 +287,12 @@ impl SerializedHangIncident {
IntervalBoundary::Presented(presented) => {
presented.dirty_to_present_duration().map(as_millis)
}
IntervalBoundary::Idle { .. } => None,
IntervalBoundary::Idle { .. } | IntervalBoundary::PowerTransition { .. } => None,
},
sealed_by: match snapshot.boundary {
IntervalBoundary::Presented(_) => "present",
IntervalBoundary::Idle { .. } => "idle",
IntervalBoundary::PowerTransition { .. } => "power_transition",
},
busy_fraction: (busy_fraction * 1000.0).round() / 1000.0,
event_count: snapshot.events.len(),
crates/gpui/src/profiler/journal.rs
+258 -23
View File
@@ -21,10 +21,17 @@ use std::sync::{
};
use std::time::Duration;
use gpui_util::ResultExt;
use scheduler::Instant;
use super::{ActionTiming, FrameTiming, PresentTiming, TaskTiming};
use crate::WindowId;
use crate::{App, WindowId, WindowVisibility};
#[derive(Clone, Copy, Debug, PartialEq, Eq)]
pub(crate) enum PowerState {
Awake,
Suspended,
}
/// Task polls shorter than this are folded into a [`PollSummary`] instead of
/// being recorded individually. This keeps the stream bounded by the number
@@ -182,6 +189,11 @@ pub enum IntervalBoundary {
/// When the foreground went idle.
ended_at: Instant,
},
/// A power notification interrupted the measurement interval.
PowerTransition {
/// When the foreground received the notification.
ended_at: Instant,
},
}
impl IntervalBoundary {
@@ -189,7 +201,7 @@ impl IntervalBoundary {
pub fn end_time(&self) -> Instant {
match self {
Self::Presented(presented) => presented.presentation.present_end,
Self::Idle { ended_at } => *ended_at,
Self::Idle { ended_at } | Self::PowerTransition { ended_at } => *ended_at,
}
}
@@ -197,7 +209,7 @@ impl IntervalBoundary {
pub fn dirty_at(&self) -> Option<Instant> {
match self {
Self::Presented(presented) => presented.frame.dirty_at,
Self::Idle { .. } => None,
Self::Idle { .. } | Self::PowerTransition { .. } => None,
}
}
}
@@ -379,11 +391,31 @@ impl ForegroundRunnableCounter {
}
}
// Visibility and power changes clear `dirty_at`; `Window::refresh_visibility`
// re-records the frame from the window's actual dirty state afterwards.
struct WindowFrameState {
visibility: WindowVisibility,
dirty_at: Option<Instant>,
visibility_changed_at: Option<Instant>,
}
impl WindowFrameState {
fn new(visibility: WindowVisibility) -> Self {
Self {
visibility,
dirty_at: None,
visibility_changed_at: None,
}
}
}
struct ForegroundJournalWriter {
foreground_runnables: ForegroundRunnableCounter,
publisher: JournalPublisher,
turn_depth: usize,
pending_frames: HashMap<WindowId, Instant>,
windows: HashMap<WindowId, WindowFrameState>,
power: PowerState,
power_changed_at: Option<Instant>,
retained_since_boundary: bool,
small_polls: Option<SmallPollFlush>,
}
@@ -394,7 +426,9 @@ impl ForegroundJournalWriter {
foreground_runnables,
publisher,
turn_depth: 0,
pending_frames: HashMap::new(),
windows: HashMap::new(),
power: PowerState::Awake,
power_changed_at: None,
retained_since_boundary: false,
small_polls: None,
}
@@ -434,12 +468,51 @@ impl ForegroundJournalWriter {
}
fn has_unexpired_pending_frame(&mut self, now: Instant) -> bool {
if self.pending_frames.is_empty() {
return false;
for window in self.windows.values_mut() {
if window
.dirty_at
.is_some_and(|at| now.saturating_duration_since(at) >= FRAME_DEADLINE)
{
window.dirty_at = None;
}
}
self.power == PowerState::Awake
&& self
.windows
.values()
.any(|window| window.dirty_at.is_some())
}
fn power_transition(&mut self, power: PowerState, at: Instant) {
if self.power == power {
return;
}
self.record_entry(ForegroundJournalEntry::Boundary(
IntervalBoundary::PowerTransition { ended_at: at },
));
self.power = power;
self.power_changed_at = Some(at);
for window in self.windows.values_mut() {
window.dirty_at = None;
}
}
/// Whether work that started at `start` spans a sleep or a wake, and so
/// must not be measured as uninterrupted foreground work.
fn power_interrupted_since(&self, start: Instant) -> bool {
self.power == PowerState::Suspended || self.power_changed_at.is_some_and(|at| start <= at)
}
fn set_visibility(&mut self, id: WindowId, visibility: WindowVisibility, at: Instant) {
let window = self
.windows
.entry(id)
.or_insert_with(|| WindowFrameState::new(visibility));
if window.visibility != visibility {
window.visibility = visibility;
window.visibility_changed_at = Some(at);
window.dirty_at = None;
}
self.pending_frames
.retain(|_, dirty_at| now.saturating_duration_since(*dirty_at) < FRAME_DEADLINE);
!self.pending_frames.is_empty()
}
fn fold_small_poll(&mut self, timing: TaskTiming) {
@@ -480,17 +553,20 @@ impl ForegroundJournalWriter {
}
fn record_frame_pending(&mut self, window_id: WindowId, dirty_at: Instant) {
let should_record = match self.pending_frames.get(&window_id) {
Some(previous_dirty_at) => {
dirty_at.saturating_duration_since(*previous_dirty_at) >= FRAME_DEADLINE
}
None => true,
};
if !should_record {
let window = self
.windows
.entry(window_id)
.or_insert_with(|| WindowFrameState::new(WindowVisibility::Visible));
if self.power == PowerState::Suspended
|| !window.visibility.is_visible()
|| window
.dirty_at
.is_some_and(|at| dirty_at.saturating_duration_since(at) < FRAME_DEADLINE)
{
return;
}
self.pending_frames.insert(window_id, dirty_at);
window.dirty_at = Some(dirty_at);
self.record_frame_state(FrameStateChange::Pending {
window_id,
dirty_at,
@@ -498,14 +574,19 @@ impl ForegroundJournalWriter {
}
fn record_window_closed(&mut self, window_id: WindowId, at: Instant) {
self.pending_frames.remove(&window_id);
self.windows.remove(&window_id);
self.record_frame_state(FrameStateChange::Closed { window_id, at });
}
fn record_present(&mut self, timing: PresentTiming, frame: Option<FrameTiming>) {
if let Some(window) = self.windows.get_mut(&timing.window_id) {
window.dirty_at = None;
}
if self.power_interrupted_since(timing.present_start) {
return;
}
match frame {
Some(frame) => {
self.pending_frames.remove(&frame.window_id);
self.record_entry(ForegroundJournalEntry::Boundary(
IntervalBoundary::Presented(PresentedFrame {
frame,
@@ -514,7 +595,6 @@ impl ForegroundJournalWriter {
));
}
None => {
self.pending_frames.remove(&timing.window_id);
self.record_event(ForegroundEvent::Present(timing));
}
}
@@ -605,6 +685,58 @@ fn with_journal(f: impl FnOnce(&mut ForegroundJournalWriter)) {
});
}
pub(crate) fn observe_power(cx: &App) {
cx.on_system_sleep(|_| {
record_power_transition(PowerState::Suspended);
})
.detach();
// Visibility notifications delivered during sleep may have been missed.
cx.on_system_wake(|cx| {
record_power_transition(PowerState::Awake);
cx.spawn(async |cx| {
cx.update(|cx| {
for handle in cx.windows() {
handle
.update(cx, |_, window, cx| window.refresh_visibility(cx))
.log_err();
}
});
})
.detach();
})
.detach();
}
pub(crate) fn record_power_transition(state: PowerState) {
with_journal(|journal| journal.power_transition(state, Instant::now()));
}
/// Whether work that started at `start` spans a sleep or a wake. Such work
/// is dropped rather than measured.
pub(crate) fn power_interrupted_since(start: Instant) -> bool {
let mut interrupted = false;
with_journal(|journal| interrupted = journal.power_interrupted_since(start));
interrupted
}
pub(crate) fn record_window_visibility(id: WindowId, visibility: WindowVisibility) {
with_journal(|journal| journal.set_visibility(id, visibility, Instant::now()));
}
/// Whether a frame sample that started at `start` was measured while the
/// window stayed visible and the system stayed awake.
pub(crate) fn frame_sample_is_valid(id: WindowId, start: Instant) -> bool {
let mut valid = true;
with_journal(|journal| {
valid = !journal.power_interrupted_since(start)
&& journal.windows.get(&id).is_none_or(|window| {
window.visibility.is_visible()
&& window.visibility_changed_at.is_none_or(|at| start > at)
});
});
valid
}
// TODO(gpui-profiler): the turn brackets in the dispatchers and
// WindowProfiler are bare begin/end call pairs rather than uses of this
// guard. A caught unwind between a pair leaves `turn_depth` (and potentially
@@ -636,6 +768,10 @@ pub(crate) fn end_foreground_turn() {
pub(crate) fn record_task_poll(timing: TaskTiming) {
FOREGROUND_RUNNABLES.with(ForegroundRunnableCounter::finished);
with_journal(|journal| {
if journal.power_interrupted_since(timing.start) {
journal.end_turn(timing.end.0);
return;
}
if timing.poll_duration() >= TASK_POLL_FLOOR {
journal.record_event(ForegroundEvent::TaskPoll(timing));
} else {
@@ -1100,6 +1236,96 @@ mod tests {
use super::*;
use crate::{WindowId, profiler::YieldTime};
#[gpui::test]
fn wake_rechecks_native_visibility(cx: &mut crate::TestAppContext) {
use crate::PlatformWindow as _;
let handle = cx.add_window(|_, _| crate::Empty);
let platform = cx.test_window(handle.into());
platform.on_visibility_change(Box::new(|_| {}));
platform.simulate_visibility_change(WindowVisibility::Hidden);
handle
.update(cx, |_, window, _| assert!(window.is_visible()))
.expect("window");
cx.update(|cx| {
cx.system_wake_observers
.clone()
.retain(&(), |callback| callback(cx))
});
cx.run_until_parked();
handle
.update(cx, |_, window, _| assert!(!window.is_visible()))
.expect("window");
}
#[test]
fn power_interruption_drops_the_poll_before_small_poll_folding() {
let (journal, _guard) = install_test_foreground_journal(32, 4);
let mut collector = journal.collector();
let start = Instant::now();
begin_foreground_turn();
record_power_transition(PowerState::Suspended);
record_power_transition(PowerState::Awake);
assert!(power_interrupted_since(start));
record_task_poll(task_timing(start, start + Duration::from_micros(10)));
assert!(
collector
.collect_unseen()
.entries
.iter()
.all(|entry| matches!(
entry,
ForegroundJournalEntry::Boundary(IntervalBoundary::PowerTransition { .. })
))
);
with_journal(|writer| assert!(writer.small_polls.is_none()));
begin_foreground_turn();
let start = Instant::now();
assert!(!power_interrupted_since(start));
record_task_poll(task_timing(start, start + TASK_POLL_FLOOR));
assert!(
collector
.collect_unseen()
.entries
.iter()
.any(|entry| matches!(
entry,
ForegroundJournalEntry::Event(ForegroundEvent::TaskPoll(_))
))
);
}
#[test]
fn visibility_and_power_changes_clear_pending_frames() {
let (mut writer, _) = test_journal(ForegroundRunnableCounter::new());
let start = Instant::now();
let first = WindowId::from(1);
let second = WindowId::from(2);
writer.set_visibility(first, WindowVisibility::Hidden, start);
writer.record_frame_pending(first, start);
assert!(!writer.has_unexpired_pending_frame(start));
writer.record_frame_pending(second, start);
assert!(writer.has_unexpired_pending_frame(start));
writer.set_visibility(second, WindowVisibility::Hidden, start);
assert!(!writer.has_unexpired_pending_frame(start));
writer.set_visibility(first, WindowVisibility::Visible, start);
writer.record_frame_pending(first, start);
assert!(writer.has_unexpired_pending_frame(start));
writer.power_transition(PowerState::Suspended, start);
assert_eq!(writer.windows[&first].dirty_at, None);
writer.record_frame_pending(first, start);
assert!(!writer.has_unexpired_pending_frame(start));
// A repeated notification is not a transition.
writer.power_transition(PowerState::Suspended, start + FRAME_DEADLINE);
assert_eq!(writer.power_changed_at, Some(start));
writer.power_transition(PowerState::Awake, start);
writer.record_frame_pending(first, start);
assert!(writer.has_unexpired_pending_frame(start));
writer.record_present(presentation_timing(first, start + FRAME_DEADLINE), None);
assert_eq!(writer.windows[&first].dirty_at, None);
writer.record_window_closed(first, start);
assert!(!writer.windows.contains_key(&first));
}
#[test]
fn draw_waits_for_its_presentation_boundary() {
let start = Instant::now();
@@ -1152,7 +1378,7 @@ mod tests {
IntervalBoundary::Presented(presented) => {
presented.dirty_to_present_duration()
}
IntervalBoundary::Idle { .. } => None,
IntervalBoundary::Idle { .. } | IntervalBoundary::PowerTransition { .. } => None,
},
Some(Duration::from_millis(5))
);
@@ -1978,6 +2204,7 @@ mod tests {
boundary_kind: match snapshot.boundary {
IntervalBoundary::Idle { .. } => 0,
IntervalBoundary::Presented(_) => 1,
IntervalBoundary::PowerTransition { .. } => 2,
},
interval_end: snapshot.interval_end().duration_since(origin).as_micros() as u64,
events: snapshot
@@ -2076,6 +2303,7 @@ mod tests {
boundary_kind: match boundary {
IntervalBoundary::Idle { .. } => 0,
IntervalBoundary::Presented(_) => 1,
IntervalBoundary::PowerTransition { .. } => 2,
},
interval_end,
events: std::mem::take(&mut events),
@@ -2687,7 +2915,14 @@ mod tests {
);
prop_assert_eq!(writer.turn_depth, model.turn_depth);
prop_assert_eq!(writer.retained_since_boundary, model.retained_since_boundary);
prop_assert_eq!(writer.pending_frames.len(), model.pending_frames.len());
prop_assert_eq!(
writer
.windows
.values()
.filter(|window| window.dirty_at.is_some())
.count(),
model.pending_frames.len()
);
}
}
}
crates/gpui/src/window.rs
+20 -9
View File
@@ -1572,6 +1572,8 @@ impl Window {
let invalidator = WindowInvalidator::new(handle.window_id());
let active = Rc::new(Cell::new(platform_window.is_active()));
let visibility = platform_window.visibility();
#[cfg(feature = "profiler")]
profiler::journal::record_window_visibility(handle.window_id(), visibility);
let hovered = Rc::new(Cell::new(platform_window.is_hovered()));
let needs_present = Rc::new(Cell::new(false));
let next_frame_callbacks: Rc<RefCell<Vec<FrameCallback>>> = Default::default();
@@ -1901,17 +1903,10 @@ impl Window {
}));
platform_window.on_visibility_change(Box::new({
let mut cx = cx.to_async();
move |visibility| {
move |_| {
handle
.update(&mut cx, |_, window, cx| {
if window.visibility == visibility {
return;
}
window.visibility = visibility;
window
.visibility_observers
.clone()
.retain(&(), |callback| callback(visibility, window, cx));
window.refresh_visibility(cx);
})
.log_err();
}
@@ -2151,6 +2146,22 @@ impl Window {
}
}
pub(crate) fn refresh_visibility(&mut self, cx: &mut App) {
let visibility = self.platform_window.visibility();
if self.visibility != visibility {
self.visibility = visibility;
#[cfg(feature = "profiler")]
profiler::journal::record_window_visibility(self.handle.window_id(), visibility);
self.visibility_observers
.clone()
.retain(&(), |callback| callback(visibility, self, cx));
}
#[cfg(feature = "profiler")]
if self.invalidator.is_dirty() || self.needs_present.get() {
profiler::journal::record_frame_pending(self.handle.window_id(), Instant::now());
}
}
/// Whether the platform is presenting this window's frames (see
/// [`WindowVisibility`]).
pub fn visibility(&self) -> WindowVisibility {
crates/input_latency_ui/src/input_latency_ui.rs
+10
View File
@@ -164,6 +164,7 @@ pub fn report_input_latency_telemetry(window: &Window, cx: &mut App) {
frames_with_2_events = frames_with_2_events,
frames_with_3_events = frames_with_3_events,
report_window_seconds = report_window_seconds,
measurement_version = gpui::profiler::hang::MEASUREMENT_VERSION,
);
}
@@ -264,6 +265,7 @@ pub fn report_frame_duration_telemetry(window: &Window, cx: &mut App) {
let intervals_18to36 = count_frames_in_range(&delta_intervals, MS18_NS, MS36_NS);
let intervals_36to100 = count_frames_in_range(&delta_intervals, MS36_NS, MS100_NS);
// intervals > 100ms are implicitly total_intervals - (the buckets above)
let average_present_interval_ms = delta_intervals.mean() / 1_000_000.0;
let average_dirty_to_present_ms = delta_dirty_to_present.mean() / 1_000_000.0;
telemetry::event!(
@@ -278,9 +280,17 @@ pub fn report_frame_duration_telemetry(window: &Window, cx: &mut App) {
intervals_18to36 = intervals_18to36,
intervals_36to100 = intervals_36to100,
total_intervals = total_intervals,
average_present_interval_ms = average_present_interval_ms,
average_dirty_to_present_ms = average_dirty_to_present_ms,
dirty_to_present_samples = delta_dirty_to_present.len(),
dirty_to_present_p50_ms =
delta_dirty_to_present.value_at_quantile(0.5) as f64 / 1_000_000.0,
dirty_to_present_p95_ms =
delta_dirty_to_present.value_at_quantile(0.95) as f64 / 1_000_000.0,
dirty_to_present_max_ms = delta_dirty_to_present.max() as f64 / 1_000_000.0,
root_entity_type_name = window_handle.root_entity_type_name(),
report_window_seconds = report_window_seconds,
measurement_version = gpui::profiler::hang::MEASUREMENT_VERSION,
);
}
crates/zed/Cargo.toml
+1
View File
@@ -128,6 +128,7 @@ gpui_platform = { workspace = true, features = [
"x11",
] }
gpui_tokio.workspace = true
hdrhistogram.workspace = true
image = { workspace = true, optional = true }
spin = "0.10.0"
itertools.workspace = true
crates/zed/src/reliability/hang_detection/telemetry.rs
+17 -5
View File
@@ -1,6 +1,7 @@
use std::time::{Duration, Instant};
use gpui::profiler::hang::{HangTrigger, SerializedHangIncident};
use hdrhistogram::Histogram;
/// Cap on incidents per telemetry event. When more accrue between sends, the
/// ones with the largest stalls are kept and the incident counts still cover
@@ -16,6 +17,8 @@ pub struct Reporter {
pending: Vec<SerializedHangIncident>,
threshold_incidents: u64,
budget_incidents: u64,
// Every incident's stall, in milliseconds; `pending` keeps only the largest.
stalls: Histogram<u64>,
}
impl Reporter {
@@ -25,6 +28,7 @@ impl Reporter {
pending: Vec::new(),
threshold_incidents: 0,
budget_incidents: 0,
stalls: Histogram::new(3).expect("3 significant figures is a valid histogram"),
}
}
@@ -33,6 +37,7 @@ impl Reporter {
HangTrigger::Threshold => self.threshold_incidents += 1,
HangTrigger::Budget => self.budget_incidents += 1,
}
self.stalls.record(incident.stall_ms as u64).ok();
self.pending.push(incident);
if self.pending.len() > MAX_REPORTED_INCIDENTS {
self.pending
@@ -47,11 +52,12 @@ impl Reporter {
}
}
// Sends even without incidents so summing `report_window_seconds` gives the
// observed time when computing incident rates.
pub fn send(&mut self) {
self.last_send = Instant::now();
if self.pending.is_empty() {
return;
}
let now = Instant::now();
let report_window_seconds = now.duration_since(self.last_send).as_secs();
self.last_send = now;
let mut incidents = std::mem::take(&mut self.pending);
incidents.sort_by(|a, b| b.stall_ms.total_cmp(&a.stall_ms));
let threshold_incidents = std::mem::take(&mut self.threshold_incidents);
@@ -64,7 +70,13 @@ impl Reporter {
incidents,
total_incidents,
threshold_incidents,
budget_incidents
budget_incidents,
stall_p50_ms = self.stalls.value_at_quantile(0.5),
stall_p95_ms = self.stalls.value_at_quantile(0.95),
stall_max_ms = self.stalls.max(),
report_window_seconds,
measurement_version = gpui::profiler::hang::MEASUREMENT_VERSION
);
self.stalls.reset();
}
}