Files
zeekayandHanzo Dev af99a001fc zapexporter: a peer that stops answering must not stop the exporter
Measured on the busiest node in the fleet, 135 seconds after a routine
cloud restart: 9,854 log records accepted, 0 sent, 0 failed, sending
queue at 197 MB of its 256 MB ceiling and climbing. The agent had logged
"Connected to peer" 30 minutes earlier and had reported nothing wrong
since. Three agents were in that state at once; one was at 94% of its
ceiling, where it would have begun discarding.

Zero throughput and zero errors at the same time is the one combination
nothing downstream survives. exporterhelper never sees a failure, so it
never retries and never backs off; the persistent queue is not a defence
because nothing is draining it; and every counter an operator would
check reads healthy. The queue was the symptom. This is the cause.

luxfi/zap's TCP path sets no deadline anywhere. ConnectDirectID dials
with a 5s timeout and then does a plain blocking handshake read;
Conn.Send writes with no write deadline; Node.Send takes a context and
consults it only on the QUIC path. So a peer that accepts the socket and
then stops reading — precisely what cloud looks like from a node while it
restarts, since the kernel completes the handshake from the listen
backlog long before the process answers — parks the caller indefinitely.
The exporter's own timeout setting cannot reach any of it.

send() then held one mutex across all of that, so the first call to park
took every other consumer with it.

Three changes, smallest first:

  - The mutex guards the node and peer fields and is never held across
    I/O, so consumers stop sharing one another's fate.
  - Every attempt is bounded by the caller's deadline. The blocked call
    keeps running — there is no way to interrupt a read on a socket
    nobody set a deadline on — but the exporter stops waiting on it and
    returns a retryable error, so the batch stays queued and the retry
    machinery works again.
  - After three consecutive abandoned attempts the ZAP node is rebuilt.
    luxfi/zap has no way to drop a single peer, and ConnectDirect is
    documented idempotent, so redialling a wedged peer returns the same
    wedged Conn; rebuilding is the only way to let go of it. The node
    identity nonce moves from per-process to per-node-instance for this:
    a rebuild reusing the old nonce would be refused as a duplicate with
    EOF, permanently, which is worse than the stall it replaces.

Start's dial is bounded too. It was unbounded, so a deaf peer at boot
blocked startup forever and the collector never became ready or tailed a
file — a pre-existing bug the new test found on its first run.

Tests stand up a peer that accepts and never answers, and hold the
connection open so it cannot reset. Against the old code the first hangs
until the test binary is killed, with the stack parked in readMessageRaw
under ConnectDirectID.

Co-authored-by: Hanzo Dev <[email protected]>
2026-08-13 23:30:54 -07:00

185 lines
7.3 KiB
Go

package zapexporter
import (
"context"
"strings"
"testing"
"go.opentelemetry.io/collector/component"
"go.opentelemetry.io/collector/component/componenttest"
"go.opentelemetry.io/collector/exporter"
"go.opentelemetry.io/collector/exporter/exportertest"
"go.opentelemetry.io/collector/pdata/plog"
"go.opentelemetry.io/collector/pdata/ptrace"
)
// fleetSettings reproduces the production situation these tests exist for: N
// collectors running ONE ConfigMap, so every one of them names its exporter
// `zap` and carries the IDENTICAL component ID.
//
// exportertest.NewNopSettings must not be used here — it stamps a fresh UUID as
// the component name, so two exporters built from it differ even under the
// pre-fix code. A test built on it passes against the bug, which is the exact
// failure mode this package's own test file warns about: "a green test against a
// server nobody runs is worse than no test".
func fleetSettings() exporter.Settings {
set := exportertest.NewNopSettings(typeStr)
set.ID = component.NewID(typeStr)
return set
}
// startOn brings up a logs exporter as if it were running on host `host`,
// pointed at addr. The hostname stub is only in effect across Start, which is
// where the ZAP node (and therefore its identity) is created.
func startOn(t *testing.T, host, addr string) exporter.Logs {
t.Helper()
orig := hostname
hostname = func() (string, error) { return host, nil }
defer func() { hostname = orig }()
cfg := NewFactory().CreateDefaultConfig().(*Config)
cfg.Endpoint = addr
exp, err := NewFactory().CreateLogs(context.Background(), fleetSettings(), cfg)
if err != nil {
t.Fatalf("create (%s): %v", host, err)
}
if err := exp.Start(context.Background(), componenttest.NewNopHost()); err != nil {
t.Fatalf("start (%s): %v", host, err)
}
t.Cleanup(func() { _ = exp.Shutdown(context.Background()) })
return exp
}
func oneLog(service, body string) plog.Logs {
ld := plog.NewLogs()
rl := ld.ResourceLogs().AppendEmpty()
rl.Resource().Attributes().PutStr("service.name", service)
rl.ScopeLogs().AppendEmpty().LogRecords().AppendEmpty().Body().SetStr(body)
return ld
}
// TestTwoAgentsOneReceiver is the regression test for the fleet-wide telemetry
// loss measured 2026-08-01.
//
// luxfi/zap admits ONE connection per peer NodeID and refuses duplicates by
// closing without a handshake reply, so the loser reads EOF. When the NodeID was
// derived from the component ID alone, all 25 otel-agent pods claimed
// "otel-agent-zap": one was connected and 24 were refused forever, dropping ~88%
// of the fleet's logs while reporting a network error.
//
// Two senders that differ ONLY by host, one receiver, both batches must land.
// Against the pre-fix exporter the second sender fails Start's dial and its
// export returns `connect ...: EOF`, so this test fails — which is the bug.
func TestTwoAgentsOneReceiver(t *testing.T) {
addr, got := receiver(t)
a := startOn(t, "otel-agent-node-a", addr)
b := startOn(t, "otel-agent-node-b", addr)
if err := a.ConsumeLogs(context.Background(), oneLog("cart", "from node-a")); err != nil {
t.Fatalf("node-a export: %v", err)
}
if err := b.ConsumeLogs(context.Background(), oneLog("cart", "from node-b")); err != nil {
// This is the exact production failure: the second agent is refused.
t.Fatalf("node-b export: %v (a second agent could not deliver — NodeID collision)", err)
}
eventually(t, func() bool { n, _, _ := got.counts(); return n == 2 },
"receiver did not get BOTH agents' batches — one sender was locked out by a duplicate NodeID")
got.mu.Lock()
defer got.mu.Unlock()
bodies := map[string]bool{}
for _, batch := range got.logs {
for _, r := range batch.Records {
bodies[r.Body] = true
}
}
if !bodies["from node-a"] || !bodies["from node-b"] {
t.Fatalf("both agents must be represented, got %v", bodies)
}
}
// TestNodeIDIsUniquePerHostAndComponent states the two axes the identity must
// separate: the same config on different hosts, and two exporters inside one
// collector. Both collided before the fix.
func TestNodeIDIsUniquePerHostAndComponent(t *testing.T) {
orig := hostname
defer func() { hostname = orig }()
idOn := func(host string) string {
hostname = func() (string, error) { return host, nil }
e := newExporter(fleetSettings(), &Config{})
return e.nodeID(newIncarnation())
}
if a, b := idOn("node-a"), idOn("node-b"); a == b {
t.Fatalf("same identity on two hosts: %q — every agent would be refused but one", a)
}
// Host and component must both stay legible; the trailing boot nonce is the
// third axis (TestNodeIDChangesAcrossProcesses) and is not pinned to a value.
if id := idOn("node-a"); !strings.HasPrefix(id, "otel-agent-node-a-zap-") {
t.Fatalf("identity should name the host and the component, got %q", id)
}
// A blank hostname must not fall back to a shared constant.
hostname = func() (string, error) { return "", nil }
e := newExporter(fleetSettings(), &Config{})
if x, y := e.nodeID(newIncarnation()), e.nodeID(newIncarnation()); x == y {
t.Fatalf("blank hostname produced a reusable identity %q — collisions return", x)
}
}
// TestNodeIDChangesAcrossProcesses is the RESTART axis, and it is the one that
// cost four incidents in a single day.
//
// Hostname is unique per pod but STABLE across a container restart inside that
// pod, so without a per-process nonce a restarted collector reclaims an identity
// the receiver may still hold — and the duplicate rule refuses the new process
// with EOF. The refusal never clears, so the pod crash-loops until it is deleted.
// Measured 2026-08-08: otel-gateway logged `connect 10.124.0.71:4319: EOF` 56
// times over 10 restarts and delivered nothing until a manual delete.
func TestNodeIDChangesAcrossProcesses(t *testing.T) {
origHost := hostname
defer func() { hostname = origHost }()
hostname = func() (string, error) { return "same-pod", nil }
e := newExporter(fleetSettings(), &Config{})
first := e.nodeID(newIncarnation())
// The NEXT process in the same pod: same hostname, same component, new
// incarnation. The incarnation is also what a post-stall node rebuild mints,
// so this axis now covers both a restart and an in-place rebuild.
second := e.nodeID(newIncarnation())
if first == second {
t.Fatalf("a restart reused the identity %q — the receiver refuses the duplicate with EOF and the pod crash-loops", first)
}
if !strings.HasPrefix(second, "otel-agent-same-pod-") {
t.Fatalf("the nonce must be a suffix, not a replacement for host+component; got %q", second)
}
}
// TestSpanKindIsTheReceiversVocabulary pins the wire's span-kind casing.
//
// pdata renders SpanKind title-cased; the o11y receiver matches lowercase (or
// the SPAN_KIND_* form) and silently defaults anything else to "internal". Sent
// title-cased, EVERY span — server, client, producer, consumer — stored as
// internal, with no error anywhere to say so.
func TestSpanKindIsTheReceiversVocabulary(t *testing.T) {
for kind, want := range map[ptrace.SpanKind]string{
ptrace.SpanKindServer: "server",
ptrace.SpanKindClient: "client",
ptrace.SpanKindProducer: "producer",
ptrace.SpanKindConsumer: "consumer",
ptrace.SpanKindInternal: "internal",
} {
s := ptrace.NewSpan()
s.SetKind(kind)
if got := translateSpan(s).Kind; got != want {
t.Errorf("kind %v went on the wire as %q, receiver expects %q "+
"(anything else silently becomes internal)", kind, got, want)
}
}
}