Jetstream consumer createOrUpdate context deadline exceeded
Observed behavior
I've found unstable behaviour on createOrUpdateConsumer using NATS Jetstream. Sometimes client can waiting for 5 seconds and after it client produces error "context deadline exceeded". It can be reproduced only on cluster mode (or stream replica count > 1, my setup is 3 replicas), not on local host (I can't catch it on some local setups using docker compose). I've tested it on three different clusters, including external platforms. I cannot find some network issues in any of cases.
Expected behavior
CreateOrUpdateConsumer worked correctly without context deadline error (excluding network infrastracture issues)
Server and client version
Client: github.com/nats-io/nats.go v1.48.0 Server: docker containers on different servers with tag 2.11.4-alpine / 2.14.2-alpine3.22 or systemd service. Cluster setup with 3 replicas
Host environment
1st cluster: 3 replicas (8 cores, 16 GiB and two machines with 4 cores with 6 GiB). With docker compose setup (image 2.14.1-linux) Config:
server_name=nats-1
host: 0.0.0.0
port: 4224
http_port: 8224
#debug: true
#trace: true
logfile_size_limit: 1GB
logfile_max_num: 5
max_connections: 65536
ping_interval: "2m"
write_deadline: "5s"
max_pending: 67108864
jetstream {
store_dir: "/var/lib/nats/jetstream"
max_memory_store: 5147483648 #2GB
max_file_store: 53687091200 #50GB
max_outstanding_catchup: 64MB
sync: "2s"
}
cluster {
name: "XXX"
port: 6224
routes: [
"nats://XXX",
"nats://YYY"
]
}2nd cluster: 3 replicas with 2 cores 4 GiB memory for each machine. Using docker compose:
services:
nats:
image: nats:2.14.2-alpine3.22
container_name: nats-1
command: >
--server_name nats-1
--cluster_name js-cluster
--jetstream
--store_dir /data/jetstream
--cluster nats://0.0.0.0:6222
--routes nats://XXX:6222,nats://YYY:6222,nats://ZZZ:6222
--http_port 8222
ports:
- "4222:4222"
- "6222:6222"
- "8222:8222"
volumes:
- nats-data:/data
network_mode: host
volumes:
nats-data:3rd setup: systemd service, 8 cores with 16 GiB for each server. Nats config:
server_name=nats-1
host: 0.0.0.0
port: 4222
http_port: 8222
#debug: true
#trace: true
logfile_size_limit: 1GB
logfile_max_num: 30
max_connections: 65536
ping_interval: "2m"
write_deadline: "5s"
max_pending: 67108864
jetstream {
store_dir: "/var/lib/nats/jetstream"
max_memory_store: 5147483648 #2GB
max_file_store: 53687091200 #50GB
}
cluster {
name: "XXX"
port: 6222
routes: [
"nats://XXX:6222",
"nats://YYY:6222"
]
}sysctl.conf:
net.ipv4.tcp_max_syn_backlog = 65535
net.ipv4.tcp_max_tw_buckets = 1048576
net.ipv4.ip_local_port_range = 1024 65535
net.core.rmem_max = 33554432
net.core.wmem_max = 33554432
net.ipv4.tcp_rmem = 4096 87380 33554432
net.ipv4.tcp_wmem = 4096 65536 33554432
net.core.somaxconn = 249535
net.ipv4.tcp_max_syn_backlog = 65535
net.ipv4.ip_local_port_range = 1024 65535
net.ipv4.tcp_max_tw_buckets = 1048576
net.ipv4.tcp_tw_reuse = 1
vm.swappiness = 0
vm.overcommit_memory = 1Steps to reproduce
I wrote tool that can reproduce it:
package main
import (
"context"
"fmt"
"strings"
"time"
"github.com/google/uuid"
"github.com/nats-io/nats.go"
"github.com/nats-io/nats.go/jetstream"
)
var (
localURLs = []string{"localhost:4222", "localhost:6222", "localhost:8222"}
)
const (
n = 5000
replicaCount = 3
)
var urls = localURLs
func main() {
natsConn, err := nats.Connect(strings.Join(urls, ","))
if err != nil {
panic(err)
}
js, err := jetstream.New(natsConn)
if err != nil {
panic(err)
}
ctx := context.Background()
go func() {
ticker := time.NewTicker(5 * time.Second)
for {
select {
case <-ctx.Done():
return
case <-ticker.C:
fmt.Println("5 second loop")
}
}
}()
for i := range n {
go func(deviceID uuid.UUID) {
fmt.Println("new device! ", i)
var stream jetstream.Stream
stream, err := js.CreateOrUpdateStream(ctx, jetstream.StreamConfig{
Name: "device_stream_" + deviceID.String(),
Subjects: []string{fmt.Sprintf("device_subject_%s.%s.%s", deviceID.String(), "*", "*")},
Retention: jetstream.WorkQueuePolicy,
MaxAge: 24 * time.Hour,
Replicas: replicaCount,
AllowMsgTTL: true,
})
if err != nil {
stream, err = js.Stream(ctx, "device_stream_"+deviceID.String())
if err != nil {
panic(err)
}
}
consumer, err := stream.CreateOrUpdateConsumer(ctx, jetstream.ConsumerConfig{
Name: "device_consumer_" + deviceID.String(),
AckWait: 5 * time.Second,
MaxDeliver: 3,
MaxAckPending: 5,
Replicas: replicaCount,
})
if err != nil {
panic(err)
}
consumerFunc := func(_ jetstream.Msg) {
fmt.Println("new message!")
}
ch, err := consumer.Consume(consumerFunc)
if err != nil {
panic(err)
}
ch.Stop()
}(uuid.Nil)
}
<-ctx.Done()
}It can be reproduced not on 100% cases but 70% I think. And only on cluster setup + not on local host.
For tests I used this docker compose:
services:
nats:
image: nats:2.14.2-alpine3.22
container_name: nats-1
command: >
--server_name nats-1
--cluster_name js-cluster
--jetstream
--store_dir /data/jetstream
--cluster nats://0.0.0.0:6222
--routes nats://XXX:6222,nats://YYY:6222,nats://ZZZ:6222
--http_port 8222
ports:
- "4222:4222"
- "6222:6222"
- "8222:8222"
volumes:
- nats-data:/data
network_mode: host
volumes:
nats-data:Source: nats-io/nats-server