Ride out a stalled read instead of abandoning the download

b36ef03 · Gabriel Morell · 2026-09-16 20:33

3 files +98 -10
Message
{commit_body(@commit)}

Files changed

modified CLAUDE.md
+26 −0
@@ -557,6 +557,32 @@ startup, logging `indicator: cycle counter calibrated at N cycles/us`. If that
557 557 line is missing or `new()` errors, the counter is not running and the timing
558 558 would be garbage — the driver refuses rather than emitting nonsense.
559 559
560 +### A stalled read is not a failed download
561 +
562 +Seen on hardware mid-OTA:
563 +
564 +```
565 +E (1977785) transport_base: esp_tls_conn_read error, errno=No more processes
566 +```
567 +
568 +"No more processes" is newlib's name for **EAGAIN**, which reads far more
569 +alarmingly than it deserves: the HTTP read hit its 30s timeout with nothing
570 +ready, `esp_http_client_read` returned `-ESP_ERR_HTTP_EAGAIN`, and esp-idf-svc
571 +handed that back as an error. `apply()` treated it as fatal and threw away the
572 +whole 1.5MB downloaded so far — on a marginal link, every time the air went
573 +briefly quiet.
574 +
575 +It now rides out `READ_STALLS` (6) consecutive timeouts, which is minutes of
576 +patience, and only then gives up. A radio competing with two UDP strands is
577 +expected to stall; restarting a 1.5MB download is expensive and a retry is
578 +free.
579 +
580 +Separately, a failed check or download now retries after `RETRY_AFTER`
581 +(5 minutes) rather than at the next interval — six hours of a fleet sitting on
582 +firmware somebody already replaced, because one read timed out, is not a
583 +trade worth making. A device configured *not* to poll still does not: `0`
584 +means "only when asked", including after a failure.
585 +
560 586 ### A locally flashed board does not poll
561 587
562 588 `ota_interval_mins` defaults to **0 for a build CI did not stamp**, and to 360
modified src/ota.rs
+72 −10
@@ -55,7 +55,7 @@ use esp_idf_svc::hal::reset;
55 55 use esp_idf_svc::http::client::{Configuration as HttpConfiguration, EspHttpConnection};
56 56 use esp_idf_svc::http::Method;
57 57 use esp_idf_svc::ota::{EspOta, SlotState};
58 −use esp_idf_svc::sys::{esp_crt_bundle_attach, mbedtls_sha256_context};
58 +use esp_idf_svc::sys::{esp_crt_bundle_attach, mbedtls_sha256_context, EspError, ESP_ERR_HTTP_EAGAIN};
59 59 use serde::Deserialize;
60 60
61 61 /// Where to look for updates when nothing is configured.
@@ -102,6 +102,22 @@ const CHUNK: usize = 4096;
102 102 /// `recv_timeout` rather than needing a second code path for `recv`.
103 103 const NEVER: Duration = Duration::from_secs(365 * 24 * 60 * 60);
104 104
105 +/// Consecutive read timeouts to ride out before abandoning a download.
106 +///
107 +/// Each one is a full `timeout` of silence (30s below), so this is minutes of
108 +/// patience — deliberately. A download that stalls mid-image is the normal
109 +/// condition on a marginal link, not an error: the radio is competing with
110 +/// two UDP strands and whatever else is on the channel, and starting over
111 +/// costs the whole 1.5MB.
112 +const READ_STALLS: u32 = 6;
113 +
114 +/// How soon to try again after a failed check or download, when polling is on.
115 +///
116 +/// Without this a transient failure costs a whole interval — six hours of a
117 +/// fleet sitting on firmware somebody has already replaced, because one read
118 +/// timed out.
119 +const RETRY_AFTER: Duration = Duration::from_secs(300);
120 +
105 121 /// Refuse a manifest that is obviously not one. Ours is a few hundred bytes
106 122 /// per version; 64KB is a fleet's worth of history and still nothing.
107 123 const MAX_MANIFEST: usize = 64 * 1024;
@@ -289,10 +305,13 @@ impl Updater {
289 305 let mut written: u64 = 0;
290 306 let mut buf = [0u8; CHUNK];
291 307
308 + let mut stalls = 0u32;
309 +
292 310 let outcome = loop {
293 311 match connection.read(&mut buf) {
294 312 Ok(0) => break Ok(()),
295 313 Ok(read) => {
314 + stalls = 0;
296 315 let chunk = &buf[..read];
297 316 digest.update(chunk);
298 317 written += read as u64;
@@ -307,6 +326,25 @@ impl Updater {
307 326 log::info!("ota: {written} bytes");
308 327 }
309 328 }
329 + // A read that times out with nothing ready is not a failed
330 + // download, it is a quiet link — `esp_http_client_read`
331 + // returns EAGAIN and the transport logs
332 + // `esp_tls_conn_read error, errno=No more processes`, which
333 + // is EAGAIN's name in newlib's table and reads far more
334 + // alarmingly than it deserves. Treating it as fatal threw
335 + // away the 1.5MB downloaded so far every time the air went
336 + // briefly quiet.
337 + Err(err) if is_stall(&err) && stalls < READ_STALLS => {
338 + stalls += 1;
339 + log::warn!(
340 + "ota: read stalled at {written} bytes ({stalls}/{READ_STALLS}), retrying"
341 + );
342 + }
343 + Err(err) if is_stall(&err) => {
344 + break Err(anyhow!(
345 + "the download stalled at {written} bytes and did not resume"
346 + ));
347 + }
310 348 Err(err) => break Err(anyhow!("reading the image: {err}")),
311 349 }
312 350 };
@@ -372,6 +410,15 @@ impl Updater {
372 410 }
373 411 }
374 412
413 +/// Is this the read timing out with nothing ready, rather than a real failure?
414 +///
415 +/// `esp_http_client_read` returns `-ESP_ERR_HTTP_EAGAIN` when its timeout
416 +/// expires before any byte arrives, and esp-idf-svc hands that back verbatim
417 +/// as the error code (negated, hence the sign here).
418 +fn is_stall(err: &EspError) -> bool {
419 + err.code() == -(ESP_ERR_HTTP_EAGAIN as i32)
420 +}
421 +
375 422 /// An HTTPS connection that trusts the ESP-IDF certificate bundle.
376 423 ///
377 424 /// `crt_bundle_attach` is what makes this verify anything at all — without it
@@ -449,9 +496,17 @@ pub fn spawn(manifest_url: String, interval: Duration) -> Result<Handle> {
449 496 Err(RecvTimeoutError::Disconnected) => break,
450 497 }
451 498
452 − run_once(&updater, &thread_report);
453 −
454 − wait = if interval.is_zero() { NEVER } else { interval };
499 + let failed = run_once(&updater, &thread_report);
500 +
501 + wait = if interval.is_zero() {
502 + // Manual-only stays manual-only, even after a failure:
503 + // "never poll" is an instruction, not a preference.
504 + NEVER
505 + } else if failed {
506 + RETRY_AFTER.min(interval)
507 + } else {
508 + interval
509 + };
455 510 }
456 511 })
457 512 .context("spawning the OTA thread")?;
@@ -461,7 +516,10 @@ pub fn spawn(manifest_url: String, interval: Duration) -> Result<Handle> {
461 516
462 517 /// One check, and the install if there is one. Never panics: a failed update
463 518 /// must leave the device doing its actual job.
464 −fn run_once(updater: &Updater, report: &Arc<Mutex<Report>>) {
519 +///
520 +/// Returns whether it failed, so the caller can come back sooner than the
521 +/// configured interval.
522 +fn run_once(updater: &Updater, report: &Arc<Mutex<Report>>) -> bool {
465 523 let outcome = updater.check().and_then(|available| match available {
466 524 None => Ok(None),
467 525 Some(available) => {
@@ -476,11 +534,14 @@ fn run_once(updater: &Updater, report: &Arc<Mutex<Report>>) {
476 534 // The new image is the boot slot; nothing else here runs on it.
477 535 reset::restart();
478 536 }
479 − Ok(None) => set(report, |r| {
480 − r.available = None;
481 − r.last_error = None;
482 − r.checked = true;
483 − }),
537 + Ok(None) => {
538 + set(report, |r| {
539 + r.available = None;
540 + r.last_error = None;
541 + r.checked = true;
542 + });
543 + false
544 + }
484 545 Err(err) => {
485 546 // `{:#}` so the context chain ("fetching …: HTTP 503") survives.
486 547 log::warn!("ota: {err:#}");
@@ -488,6 +549,7 @@ fn run_once(updater: &Updater, report: &Arc<Mutex<Report>>) {
488 549 r.last_error = Some(format!("{err:#}"));
489 550 r.checked = true;
490 551 });
552 + true
491 553 }
492 554 }
493 555 }

Parents: 5717abc