diff --git a/internal/link/hearing_nats.go b/internal/link/hearing_nats.go index b2c4885..cbc57e2 100644 --- a/internal/link/hearing_nats.go +++ b/internal/link/hearing_nats.go @@ -224,17 +224,22 @@ func (l *natsLink) Health(ctx context.Context, node string, body []byte) error { // node-engine holds is this one, not OverNATS: without it here the queue's ToolBus assertion failed on // every live link and each tool check read "no link to the bus is open" while the link was up. func (l *natsLink) Ask(ctx context.Context, subject string, body []byte) ([]byte, error) { + before := l.conn.LastError() reply, err := OverNATS{Conn: l.conn, JS: l.js}.Ask(ctx, subject, body) switch { + case err == nil: + return reply, nil case errors.Is(err, nats.ErrNoResponders): return nil, fmt.Errorf("nothing on this machine answers %s", subject) - case err != nil: - if refused := l.refusal(subject); refused != "" { - return nil, fmt.Errorf("asking %s: %v%s", subject, err, refused) - } - return nil, fmt.Errorf("asking %s: %w", subject, err) } - return reply, nil + if refused := l.refusal(subject, before); refused != "" { + return nil, fmt.Errorf("%s: %v%s", subject, err, refused) + } + if errors.Is(err, context.DeadlineExceeded) || errors.Is(err, nats.ErrTimeout) { + // Said as the deadline, which the caller words with the time it gave the question. + return nil, fmt.Errorf("no answer from %s: %w", subject, context.DeadlineExceeded) + } + return nil, fmt.Errorf("%s: %w", subject, err) } // What the queue asks of a live link beside Bus, each by a type assertion that fails quietly: said here diff --git a/internal/link/witnessing.go b/internal/link/witnessing.go index 6b8c2e1..340eaec 100644 --- a/internal/link/witnessing.go +++ b/internal/link/witnessing.go @@ -60,12 +60,13 @@ func (q *Queue) Asker() Asker { func (l *natsLink) ReadKey(ctx context.Context, bucket, key string) ([]byte, bool, error) { subject := DirectGetSubject(bucket, key) + before := l.conn.LastError() msg, err := l.conn.RequestWithContext(ctx, subject, nil) switch { case errors.Is(err, nats.ErrNoResponders): return nil, false, fmt.Errorf("%w: the bus has no bucket %s that answers a direct get", ErrCannotAsk, bucket) case err != nil: - return nil, false, fmt.Errorf("%w: reading %s from %s: %v%s", ErrCannotAsk, key, bucket, err, l.refusal(subject)) + return nil, false, fmt.Errorf("%w: reading %s from %s: %v%s", ErrCannotAsk, key, bucket, err, l.refusal(subject, before)) } if msg.Header != nil { switch status := msg.Header.Get("Status"); status { @@ -89,13 +90,14 @@ func (l *natsLink) ReadKey(ctx context.Context, bucket, key string) ([]byte, boo func (l *natsLink) Ping(ctx context.Context, service, id string) error { subject := PingSubject(service, id) + before := l.conn.LastError() msg, err := l.conn.RequestWithContext(ctx, subject, nil) switch { case errors.Is(err, nats.ErrNoResponders): // The bus delivered the question and nothing subscribes to it: the runtime is not on the bus. return fmt.Errorf("%w: no %s on this machine is on the bus", ErrNoAnswer, service) case err != nil: - if refused := l.refusal(subject); refused != "" { + if refused := l.refusal(subject, before); refused != "" { return fmt.Errorf("%w: asking %s: %v%s", ErrCannotAsk, subject, err, refused) } return fmt.Errorf("%w: %s did not answer: %v", ErrNoAnswer, subject, err) @@ -110,11 +112,13 @@ func (l *natsLink) Ping(ctx context.Context, service, id string) error { return nil } -// refusal is the bus's last word on this connection when it refused a publish to subject, said as -// the end of an error; empty when it did not. -func (l *natsLink) refusal(subject string) string { +// refusal is the bus's word on this connection when it refused a publish to subject while this question +// was asked, said as the end of an error; empty when it did not. before is the connection's last error +// as it stood before asking: the client keeps its last error for the life of the connection, so a +// refusal from an earlier question — under a grant since widened — is not said again as this one's. +func (l *natsLink) refusal(subject string, before error) string { last := l.conn.LastError() - if last == nil { + if last == nil || last == before { return "" } words := strings.ToLower(last.Error()) diff --git a/internal/liveness/readiness.go b/internal/liveness/readiness.go index 585c08e..a5e1c08 100644 --- a/internal/liveness/readiness.go +++ b/internal/liveness/readiness.go @@ -254,8 +254,10 @@ func (p *Probes) Look(ctx context.Context, module string, c *declaration.Health) } healthy, why, err := p.AskTool(ctx, module, c.Tool) switch { + case errors.Is(err, context.DeadlineExceeded): + return false, fmt.Sprintf("no answer within %s", timeout) case err != nil: - return false, "asking it: " + firstLine(err.Error()) + return false, firstLine(err.Error()) case !healthy: return false, orSaid(why, "it answered not healthy, and not why") } diff --git a/internal/liveness/readiness_test.go b/internal/liveness/readiness_test.go index 9203844..0c39419 100644 --- a/internal/liveness/readiness_test.go +++ b/internal/liveness/readiness_test.go @@ -2,6 +2,8 @@ package liveness import ( "context" + "errors" + "fmt" "net" "net/http" "net/http/httptest" @@ -191,6 +193,25 @@ func TestAToolCheckIsAskedOfTheNodeTools(t *testing.T) { } } +// A tool that does not answer in time is said as the time it was given, once, and an error from the link is +// said as it is, without a second "asking" in front of what the link already says. +func TestAToolCheckThatGetsNoAnswerSaysHowLongItWaited(t *testing.T) { + check := &declaration.Health{Kind: declaration.HealthTool, Tool: "sensors_health", + Interval: "30s", Timeout: "5s", Looks: 2, Grace: "0s"} + p := &Probes{AskTool: func(context.Context, string, string) (bool, string, error) { + return false, "", fmt.Errorf("no answer from mesh.mod.sensors.tool.sensors_health.anchor: %w", context.DeadlineExceeded) + }} + if ok, why := p.Look(t.Context(), "sensors", check); ok || why != "no answer within 5s" { + t.Fatalf("%v %q", ok, why) + } + p.AskTool = func(context.Context, string, string) (bool, string, error) { + return false, "", errors.New("no link to the bus is open") + } + if ok, why := p.Look(t.Context(), "sensors", check); ok || why != "no link to the bus is open" { + t.Fatalf("%v %q", ok, why) + } +} + // The runtime's state of a container's own check is read out of its whole state: a container that carries // none has no Health in it, and that is not an error (a template naming it would refuse every container). func TestTheRuntimesCheckIsReadOutOfTheContainersState(t *testing.T) { diff --git a/merge-check.sh b/merge-check.sh index 4fc67c7..dabdee8 100755 --- a/merge-check.sh +++ b/merge-check.sh @@ -21,6 +21,36 @@ if [ -n "$unformatted" ]; then fi CGO_ENABLED=0 go vet ./... +# **The tests that need a real bus** (MESH_TEST_NATS) run against a throwaway nats-server with JetStream when +# the toolchain holds one, so the link the node-engine dials is tested as it is used (hq issue 331: every +# unit test used fake links, and the real one could not ask a tool). Said when it cannot: a skipped test +# is not a passed one. A caller that sets MESH_TEST_NATS keeps its own bus. +if [ -z "${MESH_TEST_NATS:-}" ]; then + if command -v nats-server >/dev/null 2>&1; then + bus_dir=$(mktemp -d) + bus_port=$((20000 + $$ % 20000)) + nats-server -js -a 127.0.0.1 -p "$bus_port" -sd "$bus_dir" >"$bus_dir/log" 2>&1 & + bus_pid=$! + trap 'kill "$bus_pid" 2>/dev/null || true; rm -rf "$bus_dir"' EXIT + up=0 + for _ in 1 2 3 4 5 6 7 8 9 10; do + if grep -q "Server is ready" "$bus_dir/log"; then + up=1 + break + fi + sleep 0.5 + done + if [ "$up" -ne 1 ]; then + echo "the throwaway nats-server did not start:" + cat "$bus_dir/log" + exit 1 + fi + export MESH_TEST_NATS="nats://127.0.0.1:$bus_port" + else + echo "NOT RUN AGAINST A BUS: the toolchain holds no nats-server; the tests that need one are skipped" + fi +fi + if command -v gcc >/dev/null 2>&1; then CGO_ENABLED=1 go test -race -count=1 ./... else