carlos / platform Public

deploy: timeout report carries the wake reason and names carlos logs (#131)

The old hint could not help: the reason was journal-only and the command
it named was the box-local instances form. watchVersion now takes optional
diagnostics — runDeploy wires the platform log stream (one host, errors
only, last 15m) so the report says WHY, and points at the timeline verb.

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>

Paul Campbell 2 months ago 6d40b10dd388713552b15cdc6abb79819ce56669 parent 00c3344

2 files changed, +92 −10

deploy.go +41 −3
deploy_test.go +51 −7

diff --git a/deploy.go b/deploy.go

index a74fc7264..209930a4c 100644

--- a/deploy.go

+++ b/deploy.go

@@ -14,6 +14,7 @@ import (

"io"

"log"

"net/http"

+ "net/url"

"os/exec"

"sort"

"strings"

@@ -108,7 +109,23 @@ func runDeploy(args []string) {

for _, h := range hosts {

targets = append(targets, watchTarget{Host: h, Origin: watchOrigin(h)})

}

- if err := watchVersion(stdout, targets, *ver, *timeout, 2*time.Second); err != nil {

+ diag := &watchDiagnostics{

+ // A timed-out host's wake reason, from the platform log stream —

+ // scoped tight (one host, errors only, the watch's own recent past)

+ // so a diagnosis this may print was caused by THIS deploy, not an

+ // incident from earlier in the day.

+ wakeReason: func(host string) string {

+ q := url.Values{"stream": {"platform"}, "level": {"error"},

+ "host": {host}, "since": {"15m"}, "limit": {"1"}}

+ res, err := sess.logsGet(ctx, acct, *app, q)

+ if err != nil || len(res.Records) == 0 {

+ return ""

+ }

+ return res.Records[len(res.Records)-1].Msg

+ },

+ logsHint: fmt.Sprintf("carlos logs -app %s -account %s -stream platform", *app, acct.Seg),

+ }

+ if err := watchVersion(stdout, targets, *ver, *timeout, 2*time.Second, diag); err != nil {

log.Fatalf("deploy: %v", err)

}

@@ -387,7 +404,17 @@ var watchOrigin = func(host string) string { return "https://" + host }

// poll one stale cached hit for the whole timeout and report a healthy

// deploy as failed. The attempt counter is sufficient (no randomness

// needed): each request just needs to differ from the ones before it.

-func watchVersion(w io.Writer, targets []watchTarget, ver string, timeout, interval time.Duration) error {

+// watchDiagnostics enriches watchVersion's timeout report (issue #131's

+// tail): wakeReason answers "why is this host down" from the platform log

+// stream — the fact that used to be journal-only — and logsHint names the

+// command that shows the member the whole timeline. Nil (store-mode deploys,

+// tests that aren't about the report) changes nothing.

+type watchDiagnostics struct {

+ wakeReason func(host string) string // last platform-stream error for host; "" = none found

+ logsHint string // the follow-up command, in the member's own flags

+func watchVersion(w io.Writer, targets []watchTarget, ver string, timeout, interval time.Duration, diag *watchDiagnostics) error {

// pending is a slice, not a map, so target order stays stable across

// sweeps — the goroutines below write into an indexed result slice keyed

// off this same order, and the "live" lines print in that order once the

@@ -485,9 +512,20 @@ func watchVersion(w io.Writer, targets []watchTarget, ver string, timeout, inter

}

sort.Strings(hosts)

var b strings.Builder

- fmt.Fprintf(&b, "timed out waiting for %s to serve %s (route not minted yet or a wake failing? try `carlos instances -app <a>`):", strings.Join(hosts, ", "), ver)

+ fmt.Fprintf(&b, "timed out waiting for %s to serve %s:", strings.Join(hosts, ", "), ver)

for _, h := range hosts {

fmt.Fprintf(&b, "\n %s: %s", h, last[h])

+ // The reason a wake failed used to be journal-only (#131);

+ // now the platform log stream carries it member-safe, so a

+ // timeout report can SAY it instead of guessing at causes.

+ if diag != nil && diag.wakeReason != nil {

+ if r := diag.wakeReason(h); r != "" {

+ fmt.Fprintf(&b, "\n %s", r)

+ }

+ if diag != nil && diag.logsHint != "" {

+ fmt.Fprintf(&b, "\nfull timeline: %s", diag.logsHint)

}

return errors.New(b.String())

}

diff --git a/deploy_test.go b/deploy_test.go

index 1de0d74de..6ea48fdab 100644

--- a/deploy_test.go

+++ b/deploy_test.go

@@ -221,7 +221,7 @@ func TestWatchVersionSucceedsWhenHeaderMatches(t *testing.T) {

go func() { time.Sleep(30 * time.Millisecond); mu.Lock(); ver = "new5678"; mu.Unlock() }()

var out bytes.Buffer

err := watchVersion(&out, []watchTarget{{Host: "x.test", Origin: srv.URL}}, "new5678",

- 2*time.Second, 10*time.Millisecond)

+ 2*time.Second, 10*time.Millisecond, nil)

if err != nil {

t.Fatal(err)

}

@@ -237,7 +237,7 @@ func TestWatchVersionTimeoutDiagnostics(t *testing.T) {

defer srv.Close()

var out bytes.Buffer

err := watchVersion(&out, []watchTarget{{Host: "x.test", Origin: srv.URL}}, "new5678",

- 50*time.Millisecond, 10*time.Millisecond)

+ 50*time.Millisecond, 10*time.Millisecond, nil)

if err == nil {

t.Fatal("must time out")

}

@@ -259,7 +259,7 @@ func TestWatchVersionMatchingHeaderNon2xxNotLive(t *testing.T) {

defer srv.Close()

var out bytes.Buffer

err := watchVersion(&out, []watchTarget{{Host: "x.test", Origin: srv.URL}}, "new5678",

- 50*time.Millisecond, 10*time.Millisecond)

+ 50*time.Millisecond, 10*time.Millisecond, nil)

if err == nil {

t.Fatal("a 502 carrying the new version header must NOT be reported live")

}

@@ -279,7 +279,7 @@ func TestWatchVersionNoHeaderDiagnostic(t *testing.T) {

defer srv.Close()

var out bytes.Buffer

err := watchVersion(&out, []watchTarget{{Host: "x.test", Origin: srv.URL}}, "new5678",

- 50*time.Millisecond, 10*time.Millisecond)

+ 50*time.Millisecond, 10*time.Millisecond, nil)

if err == nil || !strings.Contains(err.Error(), "no X-Carlos-Version") {

t.Fatalf("old-edge diagnostic: %v", err)

}

@@ -298,7 +298,7 @@ func TestWatchVersionNonOKNoHeaderDiagnostic(t *testing.T) {

}))

var out bytes.Buffer

err := watchVersion(&out, []watchTarget{{Host: "x.test", Origin: srv.URL}}, "new5678",

- 50*time.Millisecond, 10*time.Millisecond)

+ 50*time.Millisecond, 10*time.Millisecond, nil)

srv.Close()

if err == nil {

t.Fatalf("HTTP %d: must time out", code)

@@ -350,7 +350,7 @@ func TestWatchVersionSweepsTargetsConcurrently(t *testing.T) {

targets[i] = watchTarget{Host: fmt.Sprintf("h%d.test", i), Origin: s.URL}

}

var out bytes.Buffer

- err := watchVersion(&out, targets, "new5678", 5*time.Second, 10*time.Millisecond)

+ err := watchVersion(&out, targets, "new5678", 5*time.Second, 10*time.Millisecond, nil)

if err != nil {

t.Fatal(err)

}

@@ -382,7 +382,7 @@ func TestWatchVersionCacheBustsEveryPoll(t *testing.T) {

defer srv.Close()

var out bytes.Buffer

_ = watchVersion(&out, []watchTarget{{Host: "x.test", Origin: srv.URL}}, "new5678",

- 35*time.Millisecond, 10*time.Millisecond)

+ 35*time.Millisecond, 10*time.Millisecond, nil)

mu.Lock()

defer mu.Unlock()

@@ -423,3 +423,47 @@ func TestDeployingLine(t *testing.T) {

}

+// TestWatchVersionTimeoutCarriesWakeReasonAndLogsHint (issue #131's tail):

+// the timeout report used to end with a hint that could not help — the wake

+// reason was journal-only and the suggested command was the box-local form.

+// With diagnostics wired, the report carries the host's last platform-stream

+// error and names the command that shows the whole timeline.

+func TestWatchVersionTimeoutCarriesWakeReasonAndLogsHint(t *testing.T) {

+ srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {

+ w.WriteHeader(http.StatusServiceUnavailable)

+ }))

+ defer srv.Close()

+ var out bytes.Buffer

+ var asked []string

+ diag := &watchDiagnostics{

+ wakeReason: func(host string) string {

+ asked = append(asked, host)

+ return "wake failed: nothing is promoted for this instance's channel"

+ },

+ logsHint: "carlos logs -app lpay -account bde -stream platform",

+ }

+ err := watchVersion(&out, []watchTarget{{Host: "x.test", Origin: srv.URL}}, "new5678",

+ 50*time.Millisecond, 10*time.Millisecond, diag)

+ if err == nil {

+ t.Fatal("watch should have timed out")

+ }

+ for _, want := range []string{

+ "wake failed: nothing is promoted",

+ "full timeline: carlos logs -app lpay -account bde -stream platform",

+ } {

+ if !strings.Contains(err.Error(), want) {

+ t.Fatalf("timeout report missing %q:\n%v", want, err)

+ }

+ if len(asked) != 1 || asked[0] != "x.test" {

+ t.Fatalf("wakeReason asked for %v, want the one pending host", asked)

+ }

+ // A reason lookup that finds nothing adds nothing — no empty line.

+ diag.wakeReason = func(string) string { return "" }

+ err = watchVersion(&out, []watchTarget{{Host: "x.test", Origin: srv.URL}}, "new5678",

+ 50*time.Millisecond, 10*time.Millisecond, diag)

+ if err == nil || strings.Contains(err.Error(), "\n \n") {

+ t.Fatalf("empty reason printed a blank line: %v", err)

+ }