Browse Source

fix(docker): correct build alive-detection and harden build flow

The build loop slept 30s before its first poll and then misclassified a
still-running tmux session as dead:  exits 0 and prints
nothing when the session is alive, but the code treated an empty result
as dead. A running build was therefore reported "failed after 0m" at the
first poll, orphaning the tmux session (which kept building in the
background) and never stamping the checksum label. Subsequent runs then
collided with the orphaned session ("duplicate session") or rebuilt
from a cached-but-unlabeled image until they happened to finish within a
poll window.

- Treat empty alive output as ALIVE; only the "DEAD" marker is dead.
- Kill any stale session before starting a new one to avoid duplicate-
  session collisions after an interrupted or falsely reported-dead run.
- Detect the success marker over the full log with grep instead of a
  tail -5 window (the marker could fall outside the window on trailing
  output); widen the error tail to 20 lines.
- Format elapsed duration as "30s" / "1m 30s" instead of truncating to
  whole minutes (30s -> "0m"); add a unit test.
Alexander Korolev 3 tháng trước cách đây
mục cha
commit
d102308e93
1 tập tin đã thay đổi với 73 bổ sung và 10 xóa
  1. 73 10
      src/docker/build.rs

+ 73 - 10
src/docker/build.rs

@@ -61,6 +61,19 @@ pub async fn build_image_on_node(
     );
     crate::ssh::upload_dir(config, node, local_dir, &remote_dir, false).await?;
 
+    // Kill any stale session from a previous (interrupted or falsely reported
+    // dead) run so `tmux new-session` does not collide with "duplicate session".
+    run_ssh(
+        config,
+        node,
+        format!(
+            "tmux kill-session -t '{}' 2>/dev/null || true",
+            session_name
+        ),
+        false,
+    )
+    .await?;
+
     let tmux_cmd = format!(
         "tmux new-session -d -s '{}' -c {} \"TAG={} bash build.sh 2>&1 | tee {}\"",
         session_name, remote_dir, image_tag, logfile
@@ -72,6 +85,12 @@ pub async fn build_image_on_node(
         tokio::time::sleep(std::time::Duration::from_secs(30)).await;
         let elapsed = start.elapsed();
 
+        // `tmux has-session` exits 0 and prints nothing when the session is
+        // alive; the `|| echo DEAD` makes it print DEAD when the session is
+        // gone (still exit 0, so run_ssh stays Ok). An empty `alive` therefore
+        // means ALIVE — it must NOT be treated as dead (that was the original
+        // bug: a still-running build was reported "failed after 0m" at the
+        // first 30s poll, orphaning the tmux session).
         let alive = run_ssh(
             config,
             node,
@@ -79,6 +98,7 @@ pub async fn build_image_on_node(
             false,
         )
         .await?;
+        let dead = alive.trim().contains("DEAD");
 
         if let Ok(logs) = run_ssh(
             config,
@@ -93,28 +113,43 @@ pub async fn build_image_on_node(
             }
         }
 
-        if alive.trim().contains("DEAD") || alive.trim().is_empty() {
-            let exit_log = run_ssh(config, node, format!("tail -5 {}", logfile), false)
-                .await
-                .unwrap_or_default();
-            if exit_log.contains(&format!("Done: {}", image_tag)) {
+        if dead {
+            // Detect the success marker anywhere in the full log (a `tail -5`
+            // window can miss it if trailing output pushes it past the end).
+            let marker = format!("Done: {}", image_tag);
+            let ok = run_ssh(
+                config,
+                node,
+                format!(
+                    "grep -F -- '{}' {} >/dev/null 2>&1 && echo OK || echo NO",
+                    marker, logfile
+                ),
+                false,
+            )
+            .await
+            .map(|s| s.trim() == "OK")
+            .unwrap_or(false);
+            if ok {
                 info!(
-                    "Image '{}' built on '{}' ({}m)",
+                    "Image '{}' built on '{}' ({})",
                     image_tag,
                     node.name,
-                    elapsed.as_secs() / 60
+                    format_elapsed(elapsed)
                 );
             } else {
+                let exit_log = run_ssh(config, node, format!("tail -20 {}", logfile), false)
+                    .await
+                    .unwrap_or_default();
                 anyhow::bail!(
-                    "Build on '{}' failed after {}m.\n{}",
+                    "Build on '{}' failed after {}.\n{}",
                     node.name,
-                    elapsed.as_secs() / 60,
+                    format_elapsed(elapsed),
                     exit_log
                 );
             }
             break;
         }
-        info!("  Build running for {}m...", elapsed.as_secs() / 60);
+        info!("  Build running for {}...", format_elapsed(elapsed));
     }
 
     // Stamp checksum label on the built image.
@@ -220,3 +255,31 @@ pub async fn handle_build(
     }
     Ok(())
 }
+
+/// Format a `Duration` as a compact human string: `45s`, `1m 30s`, `12m 04s`.
+fn format_elapsed(d: std::time::Duration) -> String {
+    let total_secs = d.as_secs();
+    let mins = total_secs / 60;
+    let secs = total_secs % 60;
+    if mins == 0 {
+        format!("{}s", secs)
+    } else {
+        format!("{}m {:02}s", mins, secs)
+    }
+}
+
+#[cfg(test)]
+mod tests {
+    use super::format_elapsed;
+    use std::time::Duration;
+
+    #[test]
+    fn format_elapsed_seconds_and_minutes() {
+        assert_eq!(format_elapsed(Duration::from_secs(0)), "0s");
+        assert_eq!(format_elapsed(Duration::from_secs(30)), "30s");
+        assert_eq!(format_elapsed(Duration::from_secs(59)), "59s");
+        assert_eq!(format_elapsed(Duration::from_secs(60)), "1m 00s");
+        assert_eq!(format_elapsed(Duration::from_secs(90)), "1m 30s");
+        assert_eq!(format_elapsed(Duration::from_secs(125)), "2m 05s");
+    }
+}