Explain why prometheus-exporter marks an endpoint unavailable

[maoueh]

An alert firing on substreams_healthcheck_status gave no way to tell an unreachable endpoint from an unauthenticated, overloaded or merely late one, and a flapping endpoint could produce no logs at all. This adds a failure taxonomy, separates connection setup from the request, and logs every failed poll.

• Every failure is classified into a reason (invalid_config, connect_failed, connect_timeout, invalid_request, request_timeout, stream_error, stale_block, invalid_response, no_data), exposed on a new substreams_healthcheck_failure_count{reason,grpc_code} counter and carried in the logs. Metrics are declared through dmetrics.

• Connection establishment gets its own --connect-timeout (default 10s), separate from --timeout, which now covers the Blocks request alone. gRPC dials lazily, so DNS/TLS/LB resolution was previously charged to the request budget and a slow connection was reported as an endpoint failure — the source of the waiting for new LB policy update: context deadline exceeded errors. The exporter now waits for the channel to be READY first, and reports substreams_healthcheck_connect_duration_ms and substreams_healthcheck_stream_duration_ms separately; substreams_healthcheck_duration_ms keeps its old meaning of the two combined.

• A dial that fails outright is reported as connect_failed within milliseconds, carrying the real dial error (connection refused, DNS failure), rather than waiting out the connect budget. connect_timeout is reserved for a connection that is merely slow to come up, and its error names the budget that expired instead of saying context deadline exceeded.

• Every failed poll is logged, not just the transition into unavailable, with reason, gRPC code, both durations and the consecutive failure count; recovery logs the downtime and how many polls failed. A block age crossing half of --max-freshness is reported too, so an alert on substreams_healthcheck_block_age_ms is no longer silent — edge-triggered and confirmed over three polls, so a chain whose block interval straddles the threshold stays quiet.

• New substreams_healthcheck_consecutive_failures gauge to alert on instead of status when single-poll hiccups should be ignored, and block_age_ms now resets to NaN when a poll returns no block instead of reporting the age of the last block ever seen.

• The exporter speaks sf.substreams.rpc.v4.Stream/Blocks only. The v3-to-v2 fallback is removed — it closed the connection and then kept reading from it — and --force-protocol-version now accepts only 4 (or unset), the flag being kept for the protocol versions to come. Nothing in production passes it today, so there is no deploy-order step.

• Fixes a panic on inconsistent label cardinality when endpoints are given different sets of query-parameter labels, and guards the block Clock dereference that would otherwise take the whole exporter down.

Verified end-to-end against the live fleet with a real API key: the v4 success path works on mainnet.eth and mainnet.sol, and connect_failed (refused port and NXDOMAIN), connect_timeout, stream_error/Unauthenticated, stale_block, the block-age crossing and the version-flag rejection were each exercised.

[dfuse-bot]

🔍 Vulnerabilities of ghcr.io/streamingfast/substreams:9ee0246

📦 Image Reference ghcr.io/streamingfast/substreams:9ee0246

digest	sha256:a40efb32ca471e83805d1c1ba8e2c9a5de8e9f166ed51957f397d434a5776520
vulnerabilities
platform	linux/amd64
size	124 MB
packages	380

📦 Base Image ubuntu:24.04

also known as	c1ca75be10a22ea09ff0b7bbe8b82ee03553a4f9b795030ee2ec921e42418fc8 noble noble-20260810
digest	sha256:1e0a86e57d247923571b75e0aaf48a1449cf8c543d51fb3e07a4a7d7bfa79316
vulnerabilities

[GabrielCartier]

Solid direction and the failure taxonomy is the right shape — the cardinality fix is genuinely correct, and I verified it at runtime with endpoints carrying different query-param label sets. Two things need to change before this goes in.

The first is a crasher: the metric pointers are now assigned by initHealthcheckMetrics, but the poller goroutines are launched before that call. Any endpoint whose first poll fails synchronously inside NewSubstreamsClientConn (missing :port, or --insecure --plaintext together) reaches markFailure while status is still nil. dmetrics.GaugeVec.SetInt derefs immediately and the pollers have no recover, so it takes the whole exporter down, all endpoints. go build -race flags it too. Reproduced both halves.

The second is that the change loses the "why" for the most common failure. waitForConnReady treats TRANSIENT_FAILURE as retryable, so connection-refused and NXDOMAIN both burn the full --connect-timeout and come out as byte-identical connect_timeout lines with the real dial error discarded. Before this, both surfaced as gRPC Unavailable carrying dial tcp ...: connection refused / no such host. Endpoint-down is the case an operator hits most, and it's the one that got harder to diagnose.

Rest is smaller — details inline. Worth calling the --force-protocol-version rejection out in the PR body with a deploy-order note: anything currently pinning 2 or 3 crash-loops on the new image, which silences that fleet's healthcheck metrics at exactly the wrong moment.

[GabrielCartier]

Second pass. Six of the seven are properly resolved and I verified each rather than taking the replies at face value — init ordering exercised under -race with both trigger cases, context.Cause confirmed end-to-end (dgrpc.AsGRPCError unwraps, so the grpc_code label survives the %w), the freshness streak traced through sustained drift / straddling / recovery / nil maxFreshness, and the nil-Clock branch confirmed reachable against a fake server. All nine taxonomy reasons are reachable, none dead. CI green including -race.

The waitForConnReady fix is the problem. Failing fast on the first TRANSIENT_FAILURE fixed the diagnostic but broke recovery: gRPC enters that state on any failed dial and re-dials on its own backoff, so it is not terminal. An endpoint that refuses one dial and accepts the next — a rolling restart, a brief DNS blip, a load balancer moment with no healthy backend — is now reported unavailable on the first refused SYN, and --connect-timeout no longer covers the case it exists for. That is a behaviour change to the availability signal itself, not to its explanation, which makes it worse than the bug it replaced.

I wrote two regression tests rather than just asserting this. Both fail on 06d6569b:

--- FAIL: TestWaitForConnReady_RecoversWithinConnectBudget (0.50s)
    endpoint came up after 500ms, well inside the 5s connect budget,
    but the poll gave up after 593.833µs
--- FAIL: TestWaitForConnReady_GivesUpAfterConnectBudget (0.00s)
    gave up after 529.125µs without spending the 500ms connect budget

Both pass with the fix suggested inline, and the full tools suite stays green under -race. Test file and the one-function change are in the inline comments — take them or replace them, but waitForConnReady should not stay uncovered either way: it is the site of both this fix and the previous one, and neither had a test that could fail.

The rest is small: the changelog claims the DNS failure is carried in the error and it isn't, and a few nits.

One aside — 44c481de's message body ends with the git merge comment template committed verbatim (# Conflicts: / # docs/release-notes/change-log.md). Worth a reword on the next force-push.

[GabrielCartier]

Blocking — this fixes the diagnostic but regresses the availability signal.

TRANSIENT_FAILURE is not terminal. gRPC enters it on any failed dial attempt and re-dials on its own backoff, so returning here gives up on connections that were about to succeed. I ran the develop loop and this one against a real grpc.Server that starts listening at t=2s, with a 10s budget:

OLD (server up at t=2s, budget 10s)  elapsed=2.86s  err=<nil>              <- poll SUCCEEDS
NEW (server up at t=2s, budget 10s)  elapsed=0.00s  err=connection failed to establish

So any rolling restart of a Substreams backend, any DNS blip, any LB moment with zero healthy backends now flips substreams_healthcheck_status to 0 and increments failure_count{reason="connect_failed"} on the first refused SYN. --connect-timeout has become dead budget for the entire class it was introduced to cover, and the flag's own help text at line 60 still promises the opposite — "endpoints will be considered 'failing' ... if the gRPC connection does not become ready in that duration".

What I think you want is to keep waiting through TRANSIENT_FAILURE — that is what the budget is for — while remembering that a dial actually failed, so the caller still issues the request and gets the real error instead of a bare connect_timeout:

func waitForConnReady(ctx context.Context, conn *grpc.ClientConn) error {
	conn.Connect()

	dialFailed := false
	for {
		state := conn.GetState()
		switch state {
		case connectivity.Ready:
			return nil
		case connectivity.TransientFailure:
			// gRPC re-dials on its own backoff, so this is not terminal: an endpoint restarting
			// behind a load balancer refuses the first dial and accepts the next one. Waiting is
			// what the connect budget is for, but the dial error is worth keeping.
			dialFailed = true
		case connectivity.Shutdown:
			return fmt.Errorf("connection shut down before becoming ready")
		}

		if !conn.WaitForStateChange(ctx, state) {
			if dialFailed {
				return errConnFailedFast
			}
			return fmt.Errorf("connection stuck in state %q: %w", state, context.Cause(ctx))
		}
	}
}

You keep connect_failed with the real dial error, and connect_timeout now means what it says: never failed, just never got there. Both regression tests pass with this, and the full tools suite stays green under -race.

The trade-off is explicit and yours to make: a permanently dead endpoint costs the full --connect-timeout again rather than 2ms. For a healthcheck polling every 20s I would take that over false unavailability during restarts, but if the 2ms matters, a bounded grace (wait through the first N failures, or a fraction of the budget) gets most of both. What should not stand is the current behaviour, where the budget is never spent at all.

[GabrielCartier]

One open question here, now that the DNS claim is corrected (1118bbbb).

"connect_timeout is reserved for a connection that is merely slow to come up" reads as a naming refinement, but as currently implemented it is a behaviour change: connect_timeout is nearly unreachable, because anything that fails a dial short-circuits before the budget is ever spent. Same for the next bullet's "The exporter now waits for the channel to be READY before issuing the request" — it doesn't, when the dial fails.

If you take the waitForConnReady change, both sentences become true as written and nothing more is needed. If you keep fail-fast, the availability-semantics change wants its own bullet — it is the part an operator would want to read before upgrading.

[GabrielCartier]

connectFailedFast short-circuits before the error is looked at, so the reason and the code can disagree.

Once it is set at prometheus-exporter.go:519, gRPC keeps re-dialing on its backoff. If the channel reaches READY before the RPC is issued and the stream then fails for an unrelated reason — ResourceExhausted, Unauthenticated, a request deadline — this still returns reasonConnectFailed while grpcCodeOf reports the true code. failure_count{reason="connect_failed",grpc_code="Unauthenticated"} is a series that describes nothing real.

Low probability today (gRPC's base backoff is ~1s against microseconds to issue the RPC), and it shrinks further if you take the wait-through-TRANSIENT_FAILURE version, since the flag would then only be set at budget expiry. Left unpatched for that reason — worth settling waitForConnReady first, then gating this on the error rather than the flag alone.

[GabrielCartier]

subReq.Validate() runs inside the poll loop, after a full dial, on every poll of every endpoint.

A bad module name is a startup config error. Hoisting the validation next to the other startup checks in runPrometheus would fail the command immediately, instead of reporting every endpoint as invalid_request forever, once per interval, each time paying a TCP+TLS connection first.

Left this one to you — it changes when the command fails, which is more than a nit.

[GabrielCartier]

Pushed four commits rather than leaving the code in comments:

• 769d70a0 — test(tools): the two waitForConnReady regression tests. These fail on the current head, so CI is red until the connect-budget behaviour changes. That is deliberate: the red is the finding.
• 6686ef61 — fix(tools): reset the block-age streak on polls carrying no age, so a streak cannot span an outage.
• dae4ae6c — refactor(tools): drop the now-unreachable ParseProtocolVersion error branch.
• 1118bbbb — docs(tools): correct the changelog's DNS claim and the garbled streamFailure doc comment.

Each is one logical change; go build, go vet and gofmt are clean, and the only failing tests are the two new ones.

What I did not push, on purpose: the waitForConnReady fix itself, the connectFailedFast classification gate, and hoisting subReq.Validate() out of the poll loop. The first is a genuine trade-off (a dead endpoint costs the full connect budget again instead of 2ms) and the other two hang off however you resolve it. Suggested implementation is in the thread if you want it as-is — it turns both tests green with the suite passing under -race.

I've cleared out the review comments that the pushes resolved, so what's left inline is only what's still open. I also withdrew an earlier nit about the test-go/testify → stretchr/testify swap: extract-proto_test.go and metrics_test.go already use stretchr, so the change makes the file match its package. That one was my mistake.

Happy to take the waitForConnReady change too if you'd rather I just applied it — say which shape you want.