Skip to content

ateapi: intermittent nil-pointer panic in ateredis.(*Persistence).getSortedMasters during background sweep (go-redis ForEachMaster) #982

Description

@wfrank2509

Environment

  • Agent Substrate on a local kind cluster (Apple Silicon / aarch64).
  • ate-api-server runs from a locally loaded image, so I cannot supply an upstream
    version tag; the trace's file/line references and the go-redis version below can
    be matched against source. go-redis: v9.18.0 (from the trace path).
  • State store: a genuine valkey cluster - six pods (valkey-cluster-0..5), one
    ClusterIP service valkey-cluster:6379, completed valkey-cluster-init job -
    addressed via go-redis ClusterClient.

Observation

ate-api-server intermittently dies with exit code 2 on a nil-pointer panic. In my
deployment: 41 restarts over 2d17h, roughly one per 1.6 hours on average, NOT
periodic - one observed container lived 15 minutes, the current one has run over
105 minutes and 21 sweeps without panicking.

Full panic from a previous container (complete goroutine, nothing elided):

panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0x161bf94]

goroutine 5679 [running]:
github.com/agent-substrate/substrate/cmd/ateapi/internal/store/ateredis.(*Persistence).getSortedMasters.func1({0x1aa4400?, 0x53387f288ba0?}, 0x53387f4d5c10?)
	github.com/agent-substrate/substrate/cmd/ateapi/internal/store/ateredis/ateredis.go:721 +0x94
github.com/redis/go-redis/v9.(*ClusterClient).ForEachMaster.func1(0x53387f56ef80?)
	github.com/redis/go-redis/v9@v9.18.0/osscluster.go:1337 +0x60
created by github.com/redis/go-redis/v9.(*ClusterClient).ForEachMaster in goroutine 5678
	github.com/redis/go-redis/v9@v9.18.0/osscluster.go:1335 +0x94

Timing facts

  • The log shows a background sweep logging "worker cache synced" exactly every 5
    minutes. In the observed crash the panic fell immediately after the 4th sweep.
  • It is NOT deterministic on a sweep count: the current container has completed
    21 sweeps without panicking.
  • No ERROR or WARN precedes the panic; the 20 preceding lines are INFO, 19 of
    them the same successful read RPC.

Observable consequence

After a restart, records previously visible through the control API were no
longer present, while pod volumes persisted - state visibility loss at the API
layer. The records were recreatable by re-issuing the create calls.

What I ruled out on my side

  • The valkey cluster itself has been stable for 23 hours (all six pods 1/1
    Running; their 3 restarts each are coincident with a host restart of every pod
    in the namespace), while ate-api-server restarted many times inside that
    window.
  • Connectivity is fine: the same process serves read RPCs successfully seconds
    before each panic.
  • I could not run cluster info from inside (no CLI in the valkey image), so
    cluster-internal health is observed from pod status only, stated as such.

Hypothesis (explicitly a hypothesis)

ForEachMaster fans out one goroutine per master (osscluster.go:1335-1337). The
getSortedMasters callback at ateredis.go:721 appears to dereference a per-shard
entry that can be nil for a moment - for example a client or node entry absent
during a topology refresh. If that is right, a nil-guard (or tolerating a nil
shard in one iteration of the sweep) would turn an intermittent process death
into a skipped sweep iteration.

Same reporter as #973; happy to provide more log context on request.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions