fix(node): the log tail gave up before the turn wrote its first byte
First live test of the streaming path: mission passed 6/6, `checkpoint.log` was 0 bytes, and the node logged nothing at all. `stream_vm_log` treated "no progress" as "the turn finished writing". But the guest's `tail` reports EOF after every idle window, and the FIRST idle window is always the one before any output exists — the VM is still booting and the CLI still starting. So the tail returned `at == 0`, the node concluded the turn was done, and it stopped seconds into a run that then went on for minutes. The abort is the terminator, not idleness: the caller already aborts this task when the exec returns, so waiting cannot outlive the turn. No-progress now sleeps and retries instead of returning. Also logs when a tail STARTS. The bug was invisible in exactly the way this session keeps finding: silence on the success path, silence on the give-up path, and an empty Live tab that looked identical to a feature nobody had wired. Method note, since it cost time: I tried to confirm the deployed binary by grepping it for `vm_out` and found zero — then found zero for `pty_out` and `vm_exec` too, in a binary whose PTY streaming demonstrably works. Binary-grep is not a reliable presence test for these literals; `stream_vm_log` and `tail of` being present is what actually showed the code had shipped.
This commit is contained in:
@@ -909,6 +909,10 @@ async fn stream_vm_log(
|
||||
log_path: String,
|
||||
out: tokio::sync::mpsc::UnboundedSender<String>,
|
||||
) {
|
||||
// Said out loud at the start, because the failure this replaced was
|
||||
// invisible: the tail gave up during VM boot and logged nothing, so an empty
|
||||
// Live tab looked identical to a feature that was never wired.
|
||||
eprintln!("clawmates-node: following {log_path} in {vm_id} for run {run_id}");
|
||||
let mut at: u64 = 0;
|
||||
let mut failures = 0;
|
||||
while failures < 3 {
|
||||
@@ -922,13 +926,19 @@ async fn stream_vm_log(
|
||||
.await
|
||||
{
|
||||
Ok(reached) => {
|
||||
// No progress and no error means the guest reported EOF: the log
|
||||
// stopped growing, so the turn is done writing.
|
||||
if reached == at {
|
||||
return;
|
||||
}
|
||||
// NO PROGRESS IS NOT THE END. The guest reports EOF whenever the
|
||||
// file has been idle, and the first idle window is always the one
|
||||
// before the turn writes anything — the VM is still booting and
|
||||
// the CLI still starting. Returning here meant the tail gave up
|
||||
// seconds into every run, before a single byte existed. Measured:
|
||||
// a turn that streamed nothing at all.
|
||||
//
|
||||
// The caller aborts this task when the exec returns, so "keep
|
||||
// waiting" cannot outlive the turn; the abort is the terminator,
|
||||
// not a guess about idleness.
|
||||
at = reached;
|
||||
failures = 0;
|
||||
tokio::time::sleep(std::time::Duration::from_millis(500)).await;
|
||||
}
|
||||
Err(e) => {
|
||||
failures += 1;
|
||||
|
||||
Reference in New Issue
Block a user