Fix network idle detection for cached pages by observing 500ms idle period (#847)

The `wait --load networkidle` command was incorrectly returning immediately when pages were served from cache, causing subsequent commands to fail. This happened because the network idle logic would return instantly when no network requests were pending, without observing any idle period.

## Changes Made

- Extract network idle polling logic into a separate `poll_network_idle` function for better testability
- Fix the timeout handling to start a 500ms idle timer when no requests are pending, instead of returning immediately
- Add comprehensive unit tests covering the regression case and normal network request flows
- Ensure the function always observes at least 500ms of network inactivity before resolving, even for cached pages

## Key Fix

The critical change is in the timeout branch: when no CDP events arrive within 600ms, we now start the idle timer if no requests are pending, rather than returning `Ok(())` immediately. This prevents false-positive idle detection for pages that load entirely from cache.

Fixes #846
This commit is contained in:
Chris Tate
2026-03-15 23:11:41 -05:00
committed by GitHub
parent ebfabe0e62
commit d866ee2022
+235 -62
View File
@@ -503,69 +503,8 @@ impl BrowserManager {
session_id: &str,
rx: &mut broadcast::Receiver<CdpEvent>,
) -> Result<(), String> {
let pending = Arc::new(Mutex::new(HashSet::<String>::new()));
let timeout = tokio::time::Duration::from_millis(self.default_timeout_ms);
tokio::time::timeout(timeout, async {
let mut idle_start: Option<tokio::time::Instant> = None;
loop {
let recv_result =
tokio::time::timeout(tokio::time::Duration::from_millis(600), rx.recv()).await;
match recv_result {
Ok(Ok(event)) if event.session_id.as_deref() == Some(session_id) => {
let mut p = pending.lock().await;
match event.method.as_str() {
"Network.requestWillBeSent" => {
if let Some(id) =
event.params.get("requestId").and_then(|v| v.as_str())
{
p.insert(id.to_string());
idle_start = None;
}
}
"Network.loadingFinished" | "Network.loadingFailed" => {
if let Some(id) =
event.params.get("requestId").and_then(|v| v.as_str())
{
p.remove(id);
if p.is_empty() {
idle_start = Some(tokio::time::Instant::now());
}
}
}
"Page.loadEventFired" => {
if p.is_empty() {
idle_start = Some(tokio::time::Instant::now());
}
}
_ => {}
}
}
Ok(Ok(_)) => {}
Ok(Err(tokio::sync::broadcast::error::RecvError::Lagged(_))) => continue,
Ok(Err(_)) => break,
Err(_) => {
// Timeout on recv -- check if idle long enough
let p = pending.lock().await;
if p.is_empty() {
return Ok(());
}
}
}
if let Some(start) = idle_start {
if start.elapsed() >= tokio::time::Duration::from_millis(500) {
return Ok(());
}
}
}
Ok(())
})
.await
.map_err(|_| "Timeout waiting for networkidle".to_string())?
poll_network_idle(session_id, rx, timeout).await
}
pub async fn get_url(&self) -> Result<String, String> {
@@ -1150,6 +1089,82 @@ impl BrowserManager {
}
}
/// Core network-idle polling loop, extracted so it can be unit-tested without a
/// full `BrowserManager` / CDP connection.
///
/// Returns `Ok(())` once no network requests have been in-flight for at least
/// 500 ms, or `Err` if `overall_timeout` elapses first.
async fn poll_network_idle(
session_id: &str,
rx: &mut broadcast::Receiver<CdpEvent>,
overall_timeout: tokio::time::Duration,
) -> Result<(), String> {
let pending = Arc::new(Mutex::new(HashSet::<String>::new()));
tokio::time::timeout(overall_timeout, async {
let mut idle_start: Option<tokio::time::Instant> = None;
loop {
let recv_result =
tokio::time::timeout(tokio::time::Duration::from_millis(600), rx.recv()).await;
match recv_result {
Ok(Ok(event)) if event.session_id.as_deref() == Some(session_id) => {
let mut p = pending.lock().await;
match event.method.as_str() {
"Network.requestWillBeSent" => {
if let Some(id) = event.params.get("requestId").and_then(|v| v.as_str())
{
p.insert(id.to_string());
idle_start = None;
}
}
"Network.loadingFinished" | "Network.loadingFailed" => {
if let Some(id) = event.params.get("requestId").and_then(|v| v.as_str())
{
p.remove(id);
if p.is_empty() {
idle_start = Some(tokio::time::Instant::now());
}
}
}
"Page.loadEventFired" => {
if p.is_empty() {
idle_start = Some(tokio::time::Instant::now());
}
}
_ => {}
}
}
Ok(Ok(_)) => {}
Ok(Err(tokio::sync::broadcast::error::RecvError::Lagged(_))) => continue,
Ok(Err(_)) => break,
Err(_) => {
// Timeout on recv -- if no pending requests, start (or
// continue) the idle timer instead of returning
// immediately. This prevents false-positive idle
// detection when the subscription starts after the page
// has already loaded (e.g. cached pages).
let p = pending.lock().await;
if p.is_empty() && idle_start.is_none() {
idle_start = Some(tokio::time::Instant::now());
}
}
}
if let Some(start) = idle_start {
if start.elapsed() >= tokio::time::Duration::from_millis(500) {
return Ok(());
}
}
}
Ok(())
})
.await
.map_err(|_| "Timeout waiting for networkidle".to_string())?
}
async fn connect_cdp_with_retry(
ws_url: &str,
total_timeout: Duration,
@@ -1469,4 +1484,162 @@ mod tests {
assert!(!is_internal_chrome_target("http://localhost:3000"));
assert!(!is_internal_chrome_target("about:blank"));
}
// -----------------------------------------------------------------------
// poll_network_idle tests
// -----------------------------------------------------------------------
fn cdp_event(method: &str, session_id: &str, params: Value) -> CdpEvent {
CdpEvent {
method: method.to_string(),
params,
session_id: Some(session_id.to_string()),
}
}
/// Regression test for #846: when no network events arrive at all (e.g.
/// page fully served from cache), poll_network_idle must NOT return
/// instantly. It should observe at least 500 ms of idle before resolving.
#[tokio::test]
async fn test_network_idle_no_events_does_not_return_instantly() {
let (tx, mut rx) = broadcast::channel::<CdpEvent>(16);
let session = "s1";
let start = tokio::time::Instant::now();
let result = tokio::time::timeout(
Duration::from_secs(5),
poll_network_idle(session, &mut rx, Duration::from_secs(5)),
)
.await
.expect("outer timeout should not fire");
assert!(result.is_ok());
let elapsed = start.elapsed();
assert!(
elapsed >= Duration::from_millis(500),
"network idle returned in {:?}, expected >= 500ms",
elapsed
);
drop(tx);
}
/// Normal flow: requests start and finish, idle is detected after the last
/// request completes and 500 ms of silence passes.
#[tokio::test]
async fn test_network_idle_after_requests_complete() {
let (tx, mut rx) = broadcast::channel::<CdpEvent>(16);
let session = "s1";
let _keep_alive = tx.clone();
tokio::spawn(async move {
sleep(Duration::from_millis(50)).await;
let _ = tx.send(cdp_event(
"Network.requestWillBeSent",
session,
json!({ "requestId": "r1" }),
));
sleep(Duration::from_millis(100)).await;
let _ = tx.send(cdp_event(
"Network.loadingFinished",
session,
json!({ "requestId": "r1" }),
));
});
let start = tokio::time::Instant::now();
let result = tokio::time::timeout(
Duration::from_secs(5),
poll_network_idle(session, &mut rx, Duration::from_secs(5)),
)
.await
.expect("outer timeout should not fire");
assert!(result.is_ok());
let elapsed = start.elapsed();
assert!(
elapsed >= Duration::from_millis(500),
"should wait >= 500ms after last request finishes, got {:?}",
elapsed
);
}
/// A new request arriving during the idle window resets the timer.
#[tokio::test]
async fn test_network_idle_resets_on_new_request() {
let (tx, mut rx) = broadcast::channel::<CdpEvent>(16);
let session = "s1";
let _keep_alive = tx.clone();
tokio::spawn(async move {
sleep(Duration::from_millis(50)).await;
let _ = tx.send(cdp_event(
"Network.requestWillBeSent",
session,
json!({ "requestId": "r1" }),
));
sleep(Duration::from_millis(50)).await;
let _ = tx.send(cdp_event(
"Network.loadingFinished",
session,
json!({ "requestId": "r1" }),
));
// Wait 200ms (< 500ms idle window), then fire another request
sleep(Duration::from_millis(200)).await;
let _ = tx.send(cdp_event(
"Network.requestWillBeSent",
session,
json!({ "requestId": "r2" }),
));
sleep(Duration::from_millis(100)).await;
let _ = tx.send(cdp_event(
"Network.loadingFinished",
session,
json!({ "requestId": "r2" }),
));
});
let start = tokio::time::Instant::now();
let result = tokio::time::timeout(
Duration::from_secs(5),
poll_network_idle(session, &mut rx, Duration::from_secs(5)),
)
.await
.expect("outer timeout should not fire");
assert!(result.is_ok());
let elapsed = start.elapsed();
// r2 finishes at ~400ms; idle should be detected at ~900ms
assert!(
elapsed >= Duration::from_millis(800),
"should wait for idle after second request, got {:?}",
elapsed
);
}
/// When the overall timeout expires before idle is reached, the function
/// returns an error.
#[tokio::test]
async fn test_network_idle_overall_timeout() {
let (tx, mut rx) = broadcast::channel::<CdpEvent>(16);
let session = "s1";
// Keep sending requests so idle is never reached
tokio::spawn(async move {
for i in 0u64.. {
let _ = tx.send(cdp_event(
"Network.requestWillBeSent",
session,
json!({ "requestId": format!("r{}", i) }),
));
sleep(Duration::from_millis(100)).await;
}
});
let result = poll_network_idle(session, &mut rx, Duration::from_millis(800)).await;
assert!(result.is_err());
assert!(result
.unwrap_err()
.contains("Timeout waiting for networkidle"));
}
}