bug: launchd service cannot reach Tart VM bridge, leaving macOS runners stuck preparing

[STRRL]

Summary

The macOS Tart runner can get stuck cycling runners because waitForSSH reports SSH not reachable for every VM, even though the VM receives an IP and can be reached manually from the host in some attempts.

This currently blocks the Integration Test (Tart) job on PR #71:

• PR: [codex] fix dashboard metadata and Tart readiness #71
• Run: https://github.com/boring-design/elastic-fruit-runner/actions/runs/24902274163
• Queued job: https://github.com/boring-design/elastic-fruit-runner/actions/runs/24902274163/job/72960888759

Observed behavior

On eiu-the-runner, elastic-fruit-runner repeatedly prepares a Tart VM, gets 192.168.64.3, waits for SSH for two minutes, then deletes the VM and retries.

Representative log lines:

preparing runner runnerSet=fruit-runner-macos-arm64 runner=fruit-runner-macos-arm64-d9024
VM image not found locally, pulling image=ghcr.io/cirruslabs/macos-tahoe-xcode:latest
cloning VM image=ghcr.io/cirruslabs/macos-tahoe-xcode:latest name=fruit-runner-macos-arm64-d9024
starting VM name=fruit-runner-macos-arm64-d9024
waiting for VM IP name=fruit-runner-macos-arm64-d9024
waiting for SSH name=fruit-runner-macos-arm64-d9024 ip=192.168.64.3 retry_in=1s
...
start runner failed runnerSet=fruit-runner-macos-arm64 runner=fruit-runner-macos-arm64-d9024 err="start runner in VM fruit-runner-macos-arm64-d9024: SSH not reachable on fruit-runner-macos-arm64-d9024 (192.168.64.3:22) after 2m0s"
stopping VM name=fruit-runner-macos-arm64-d9024
deleting VM name=fruit-runner-macos-arm64-d9024

This repeats across multiple runner names, so it does not look like a single corrupt VM instance.

Profiling / debugging notes

Sampling the live daemon did not show CPU pressure or an internal hot loop. Most threads were parked in Go runtime waits, kevent, or read, which matches the process waiting on external VM/network readiness.

The installed Homebrew binary is stripped, so sample and go tool addr2line could not map addresses back to Go symbols. This makes live production profiling harder than necessary.

Manual checks from the same host during the failure window showed that the Tart VM and credentials can be valid:

sshpass -p admin ssh -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o ConnectTimeout=5 admin@192.168.64.3 "echo ok && sw_vers -productVersion"
ok
26.3

A tcpdump captured a SYN toward the VM SSH port with the physical LAN source address instead of the Tart bridge source address:

IP 192.168.1.87.<ephemeral> > 192.168.64.3.22: Flags [S]

The expected host-side Tart bridge address is 192.168.64.1 on bridge101; route -n get 192.168.64.3 also reported bridge101.

Suspected root cause

internal/tart/manager.go currently treats SSH readiness as a raw TCP probe:

dialer := net.Dialer{Timeout: 2 * time.Second}
conn, err := dialer.DialContext(ctx, "tcp", ip+":22")
if err == nil {
    conn.Close()
    return nil
}

That probe can falsely fail in this macOS/Tart bridge networking setup. Because the retry log only records name, ip, and retry_in, we lose the actual dial error, local address, and interface information needed to distinguish slow boot, route selection, firewall/refused, and timeout cases.

There is also a behavioral mismatch: after waitForSSH succeeds, the next step uses sshpass ssh. In the observed environment, manual sshpass ssh can succeed while the daemon continues to fail the raw TCP readiness gate.

Proposed fix

1. Log the actual DialContext error on every readiness retry, or at least on timeout.
2. On successful TCP probe, log conn.LocalAddr() and conn.RemoteAddr() at debug/info level.
3. Prefer making readiness use the same transport as the real operation, for example sshpass ssh -o ConnectTimeout=... admin@<ip> true, instead of a bare TCP port check.
4. If keeping TCP probing, consider explicitly selecting/binding the Tart bridge local address/interface for VM IPs.
5. Add an ops/debug mode to preserve failed Tart VMs instead of deleting them immediately after readiness timeout.
6. Publish or retain symbolized debug builds for the runner binary used on self-hosted machines so production samples can be mapped back to Go code.

Increasing the two-minute timeout may help slow boots, but it does not address the false-negative readiness signal seen here.

Acceptance criteria

• A Tart VM that is reachable by sshpass ssh admin@<ip> true is accepted as ready by the runner manager.
• Readiness timeout logs include the underlying connection error and enough local/remote address data to diagnose routing/interface issues.
• The Integration Test (Tart) job no longer remains queued because the runner repeatedly fails during VM SSH readiness.

[STRRL]

Additional root-cause evidence from eiu-the-runner:

This is not a Tart VM boot failure and not a general Go net.Dialer failure. It is specific to processes started by launchd/Homebrew service context.

During the same active VM window (fruit-runner-macos-arm64-22d33, 192.168.64.3):

# Same probe binary, run from an SSH shell:
2026-04-24T18:09:26.426832-07:00 dial ok addr=192.168.64.3:22 local=192.168.64.1:52753 remote=192.168.64.3:22
2026-04-24T18:09:28.428097-07:00 dial ok addr=192.168.64.3:22 local=192.168.64.1:52755 remote=192.168.64.3:22
2026-04-24T18:09:30.429427-07:00 dial ok addr=192.168.64.3:22 local=192.168.64.1:52757 remote=192.168.64.3:22

nc: Connection to 192.168.64.3 port 22 [tcp/ssh] succeeded
sshpass ssh: ssh-ok

At the same time, the same CGO-disabled Go probe, started as a LaunchAgent, failed with no route:

2026-04-24T18:09:26.060945-07:00 dial err addr=192.168.64.3:22 err=dial tcp 192.168.64.3:22: connect: no route to host
2026-04-24T18:09:28.067850-07:00 dial err addr=192.168.64.3:22 err=dial tcp 192.168.64.3:22: connect: no route to host
2026-04-24T18:09:30.069726-07:00 dial err addr=192.168.64.3:22 err=dial tcp 192.168.64.3:22: connect: no route to host

The production runner is also a LaunchAgent:

gui/501/homebrew.mxcl.elastic-fruit-runner
program = /opt/homebrew/opt/elastic-fruit-runner/bin/elastic-fruit-runner
spawn type = daemon (3)

While those shell probes were succeeding, the production daemon kept logging waiting for SSH and eventually failed the same VM:

2026-04-24T18:09:26-07:00 waiting for SSH name=fruit-runner-macos-arm64-22d33 ip=192.168.64.3 retry_in=16s
2026-04-24T18:11:02-07:00 start runner failed ... SSH not reachable on fruit-runner-macos-arm64-22d33 (192.168.64.3:22) after 2m0s

So the root cause is: launchd-started jobs on this host cannot route/connect to the Tart bridge address (192.168.64.3 via bridge101), while interactive SSH-shell processes can. The runner then misreports this as a generic SSH readiness timeout because waitForSSH drops the underlying dial error.

Likely fix areas:

• macOS service install/runtime docs need a launch mode that has local-network access to the Tart bridge, or a documented Local Network/TCC/network-policy grant if macOS requires one.
• The Homebrew service plist may not be a safe default for Tart-backed runners on this macOS version.
• Code should still log the underlying dial error; otherwise connect: no route to host gets hidden behind SSH not reachable after 2m0s.

[STRRL]

Follow-up verification:

• Running the daemon in a foreground SSH session allowed the Tart VM readiness check to pass.
• The macOS runner started, accepted the GitHub Actions job, executed it, reported completion, and cleaned up the VM.
• PR [codex] fix dashboard metadata and Tart readiness #71's latest pull_request checks are now green after commit 6e187c0, which also avoids the separate macOS codecov-action@v5 failure caused by missing gpg on the Tart image.

This confirms the stuck CI root cause is the Homebrew/launchd service runtime context, not the Tart VM image or the runner setup code itself.

The permanent fix is still needed: running under brew services / launchd can still lose access to the Tart bridge and reproduce the original SSH not reachable loop.

[STRRL]

Permanent fix implemented in PR #71, commit b7c008e (fix(tart): use ssh for readiness checks).

Root cause refinement:

• The Homebrew/launchd service could start Tart VMs and obtain the VM bridge IP.
• Under that service context, the old Go raw TCP readiness probe could report route-level failures against the Tart bridge address.
• The actual transport used later by the controller is sshpass ssh, and a direct launchd probe showed that SSH can succeed even when the Go raw dial path is unreliable.

Fix:

• internal/tart.Manager.waitForSSH now probes readiness with the same SSH transport used by Exec: sshpass ssh ... true.
• The SSH command uses bounded attempts (ConnectTimeout=5, ConnectionAttempts=1) and keeps the existing exponential backoff around readiness.
• Timeout errors now include the last SSH failure output, so future Tart startup failures are diagnosable from logs.
• Added unit coverage for using SSH transport and reporting the last readiness error.

Validation:

• Local: go test -count=1 ./internal/tart ./internal/backend ./internal/controller
• PR [codex] fix dashboard metadata and Tart readiness #71 checks on b7c008e are green.
• Most importantly, Integration Test (Tart) passed under the Homebrew/launchd service: https://github.com/boring-design/elastic-fruit-runner/actions/runs/24924469701/job/72991940273

The service log showed the new probe retry through early VM boot errors (Operation timed out, No route to host, Host is down), then successfully run the VM bootstrap and start the runner before the GitHub Actions job completed.