Reconnect when RIS Live ends or stalls the stream (closes #53)
check / check (push) Waiting to run
check / check (push) Waiting to run
Only Stop now ends the reconnect loop. A stream that ends any other way, with or without an error, marks the feed disconnected and reconnects with the existing backoff. Before, a response RIS Live ended normally stopped the loop for good while the health check kept reporting ok. The streamer also drops the connection when no line arrives for 60 seconds; each line starts that limit over, and it also bounds the wait for RIS Live to answer. The idle limit and the first backoff delay are fields so the tests, against a local server, run in well under a second. The README's Reconnection note describes this behaviour. Model: opus-5-5
This commit is contained in:
@@ -141,7 +141,10 @@ routewatch/
|
|||||||
- **Batched Writes**: All database operations are batched for performance
|
- **Batched Writes**: All database operations are batched for performance
|
||||||
- **Backpressure**: Probabilistic message dropping when queues exceed 50% capacity
|
- **Backpressure**: Probabilistic message dropping when queues exceed 50% capacity
|
||||||
- **Graceful Shutdown**: 60-second timeout, flushes all pending batches
|
- **Graceful Shutdown**: 60-second timeout, flushes all pending batches
|
||||||
- **Reconnection**: Exponential backoff (5s-320s) with reset after 30s of stable connection
|
- **Reconnection**: Any end of the stream other than shutdown, including RIS Live
|
||||||
|
ending the response normally, marks the feed disconnected and reconnects with
|
||||||
|
exponential backoff (5s-320s). The backoff resets after a stream that lasted
|
||||||
|
more than 30s. A stream with no line for 60s is dropped and reconnected.
|
||||||
- **IP Lookup**: the most specific live route is found by looking up the
|
- **IP Lookup**: the most specific live route is found by looking up the
|
||||||
address's prefix at each mask length, longest first, in the prefix index
|
address's prefix at each mask length, longest first, in the prefix index
|
||||||
(at most 33 lookups for IPv4, 129 for IPv6); prefixes are stored in the
|
(at most 33 lookups for IPv4, 129 for IPv6); prefixes are stored in the
|
||||||
|
|||||||
@@ -7,6 +7,7 @@ import (
|
|||||||
"compress/gzip"
|
"compress/gzip"
|
||||||
"context"
|
"context"
|
||||||
"encoding/json"
|
"encoding/json"
|
||||||
|
"errors"
|
||||||
"fmt"
|
"fmt"
|
||||||
"io"
|
"io"
|
||||||
"math"
|
"math"
|
||||||
@@ -48,6 +49,7 @@ const (
|
|||||||
metricsUpdateRate = time.Second
|
metricsUpdateRate = time.Second
|
||||||
minBackoffDelay = 5 * time.Second
|
minBackoffDelay = 5 * time.Second
|
||||||
maxBackoffDelay = 320 * time.Second
|
maxBackoffDelay = 320 * time.Second
|
||||||
|
streamIdleTimeout = 60 * time.Second // Reconnect when no line arrives for this long
|
||||||
metricsLogInterval = 10 * time.Second
|
metricsLogInterval = 10 * time.Second
|
||||||
bytesPerKB = 1024
|
bytesPerKB = 1024
|
||||||
bytesPerMB = 1024 * 1024
|
bytesPerMB = 1024 * 1024
|
||||||
@@ -58,6 +60,9 @@ const (
|
|||||||
backpressureSlope = 2.0 // Slope for linear drop probability increase
|
backpressureSlope = 2.0 // Slope for linear drop probability increase
|
||||||
)
|
)
|
||||||
|
|
||||||
|
// errStreamEnded is returned by stream when RIS Live ends the response.
|
||||||
|
var errStreamEnded = errors.New("RIS Live ended the stream")
|
||||||
|
|
||||||
// MessageHandler defines the interface for processing RIS messages.
|
// MessageHandler defines the interface for processing RIS messages.
|
||||||
// Implementations must specify which message types they want to receive,
|
// Implementations must specify which message types they want to receive,
|
||||||
// how to process messages, and their desired queue capacity.
|
// how to process messages, and their desired queue capacity.
|
||||||
@@ -107,6 +112,8 @@ type Streamer struct {
|
|||||||
logger *logger.Logger
|
logger *logger.Logger
|
||||||
client *http.Client
|
client *http.Client
|
||||||
url string
|
url string
|
||||||
|
idleTimeout time.Duration // Drop the connection when no line arrives for this long
|
||||||
|
minBackoff time.Duration // First wait before reconnecting; doubles up to maxBackoffDelay
|
||||||
handlers []*handlerInfo
|
handlers []*handlerInfo
|
||||||
rawHandler RawMessageHandler
|
rawHandler RawMessageHandler
|
||||||
mu sync.RWMutex
|
mu sync.RWMutex
|
||||||
@@ -126,6 +133,8 @@ func New(logger *logger.Logger, metrics *metrics.Tracker) *Streamer {
|
|||||||
return &Streamer{
|
return &Streamer{
|
||||||
logger: logger,
|
logger: logger,
|
||||||
url: risLiveURL,
|
url: risLiveURL,
|
||||||
|
idleTimeout: streamIdleTimeout,
|
||||||
|
minBackoff: minBackoffDelay,
|
||||||
client: &http.Client{
|
client: &http.Client{
|
||||||
Timeout: 0, // No timeout for streaming
|
Timeout: 0, // No timeout for streaming
|
||||||
Transport: &http.Transport{
|
Transport: &http.Transport{
|
||||||
@@ -405,7 +414,7 @@ func (s *Streamer) updateMetrics(messageBytes int) {
|
|||||||
|
|
||||||
// streamWithReconnect handles streaming with automatic reconnection and exponential backoff
|
// streamWithReconnect handles streaming with automatic reconnection and exponential backoff
|
||||||
func (s *Streamer) streamWithReconnect(ctx context.Context) {
|
func (s *Streamer) streamWithReconnect(ctx context.Context) {
|
||||||
backoffDelay := minBackoffDelay
|
backoffDelay := s.minBackoff
|
||||||
consecutiveFailures := 0
|
consecutiveFailures := 0
|
||||||
|
|
||||||
for {
|
for {
|
||||||
@@ -422,8 +431,9 @@ func (s *Streamer) streamWithReconnect(ctx context.Context) {
|
|||||||
err := s.stream(ctx)
|
err := s.stream(ctx)
|
||||||
streamDuration := time.Since(startTime)
|
streamDuration := time.Since(startTime)
|
||||||
|
|
||||||
if err == nil {
|
// Only Stop ends the streamer. A stream that ends any other way,
|
||||||
// Clean exit (context cancelled)
|
// with or without an error, is a disconnect and is reconnected.
|
||||||
|
if ctx.Err() != nil {
|
||||||
return
|
return
|
||||||
}
|
}
|
||||||
|
|
||||||
@@ -434,17 +444,13 @@ func (s *Streamer) streamWithReconnect(ctx context.Context) {
|
|||||||
"stream_duration", streamDuration)
|
"stream_duration", streamDuration)
|
||||||
s.metrics.SetConnected(false)
|
s.metrics.SetConnected(false)
|
||||||
|
|
||||||
// Check if context is cancelled
|
// A stream that lasted more than 30 seconds resets the backoff. That
|
||||||
if ctx.Err() != nil {
|
// includes a stream dropped after streamIdleTimeout with no line, so
|
||||||
return
|
// a silent feed is retried after the first backoff delay every time.
|
||||||
}
|
|
||||||
|
|
||||||
// If we streamed for more than 30 seconds, reset the backoff
|
|
||||||
// This indicates we had a successful connection that received data
|
|
||||||
if streamDuration > 30*time.Second {
|
if streamDuration > 30*time.Second {
|
||||||
s.logger.Info("Resetting backoff delay due to successful connection",
|
s.logger.Info("Resetting backoff delay due to successful connection",
|
||||||
"stream_duration", streamDuration)
|
"stream_duration", streamDuration)
|
||||||
backoffDelay = minBackoffDelay
|
backoffDelay = s.minBackoff
|
||||||
consecutiveFailures = 0
|
consecutiveFailures = 0
|
||||||
} else {
|
} else {
|
||||||
// Increment consecutive failures
|
// Increment consecutive failures
|
||||||
@@ -477,7 +483,13 @@ func (s *Streamer) stream(ctx context.Context) error {
|
|||||||
connCtx, connCancel := context.WithCancel(ctx)
|
connCtx, connCancel := context.WithCancel(ctx)
|
||||||
defer connCancel()
|
defer connCancel()
|
||||||
|
|
||||||
req, err := http.NewRequestWithContext(ctx, "GET", s.url, nil)
|
// The idle timer drops the connection, by cancelling connCtx, when no
|
||||||
|
// line arrives for s.idleTimeout. Each line read starts it over. It
|
||||||
|
// also covers the wait for the server to answer.
|
||||||
|
idleTimer := time.AfterFunc(s.idleTimeout, connCancel)
|
||||||
|
defer idleTimer.Stop()
|
||||||
|
|
||||||
|
req, err := http.NewRequestWithContext(connCtx, "GET", s.url, nil)
|
||||||
if err != nil {
|
if err != nil {
|
||||||
return fmt.Errorf("failed to create request: %w", err)
|
return fmt.Errorf("failed to create request: %w", err)
|
||||||
}
|
}
|
||||||
@@ -559,6 +571,8 @@ func (s *Streamer) stream(ctx context.Context) error {
|
|||||||
scanner := bufio.NewScanner(reader)
|
scanner := bufio.NewScanner(reader)
|
||||||
|
|
||||||
for scanner.Scan() {
|
for scanner.Scan() {
|
||||||
|
idleTimer.Reset(s.idleTimeout)
|
||||||
|
|
||||||
select {
|
select {
|
||||||
case <-ctx.Done():
|
case <-ctx.Done():
|
||||||
s.logger.Info("Stream stopped by context")
|
s.logger.Info("Stream stopped by context")
|
||||||
@@ -707,11 +721,19 @@ func (s *Streamer) stream(ctx context.Context) error {
|
|||||||
s.mu.RUnlock()
|
s.mu.RUnlock()
|
||||||
}
|
}
|
||||||
|
|
||||||
|
if ctx.Err() != nil {
|
||||||
|
return ctx.Err()
|
||||||
|
}
|
||||||
|
|
||||||
|
if connCtx.Err() != nil {
|
||||||
|
return fmt.Errorf("no line received for %s", s.idleTimeout)
|
||||||
|
}
|
||||||
|
|
||||||
if err := scanner.Err(); err != nil {
|
if err := scanner.Err(); err != nil {
|
||||||
return fmt.Errorf("scanner error: %w", err)
|
return fmt.Errorf("scanner error: %w", err)
|
||||||
}
|
}
|
||||||
|
|
||||||
return nil
|
return errStreamEnded
|
||||||
}
|
}
|
||||||
|
|
||||||
// shouldDropForBackpressure determines if a message should be dropped based on queue utilization
|
// shouldDropForBackpressure determines if a message should be dropped based on queue utilization
|
||||||
|
|||||||
@@ -7,6 +7,7 @@ import (
|
|||||||
"net/http"
|
"net/http"
|
||||||
"net/http/httptest"
|
"net/http/httptest"
|
||||||
"runtime"
|
"runtime"
|
||||||
|
"sync/atomic"
|
||||||
"testing"
|
"testing"
|
||||||
"time"
|
"time"
|
||||||
|
|
||||||
@@ -57,8 +58,8 @@ func TestStreamDoesNotLeakTickersAcrossReconnects(t *testing.T) {
|
|||||||
|
|
||||||
// One warm-up connection so any persistent HTTP transport goroutine exists
|
// One warm-up connection so any persistent HTTP transport goroutine exists
|
||||||
// before we take the baseline.
|
// before we take the baseline.
|
||||||
if err := s.stream(context.Background()); err != nil {
|
if err := s.stream(context.Background()); !errors.Is(err, errStreamEnded) {
|
||||||
t.Fatalf("warm-up stream returned error: %v", err)
|
t.Fatalf("warm-up stream returned %v, want %v", err, errStreamEnded)
|
||||||
}
|
}
|
||||||
s.client.CloseIdleConnections()
|
s.client.CloseIdleConnections()
|
||||||
|
|
||||||
@@ -66,8 +67,8 @@ func TestStreamDoesNotLeakTickersAcrossReconnects(t *testing.T) {
|
|||||||
|
|
||||||
const reconnects = 20
|
const reconnects = 20
|
||||||
for range reconnects {
|
for range reconnects {
|
||||||
if err := s.stream(context.Background()); err != nil {
|
if err := s.stream(context.Background()); !errors.Is(err, errStreamEnded) {
|
||||||
t.Fatalf("stream returned error: %v", err)
|
t.Fatalf("stream returned %v, want %v", err, errStreamEnded)
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
s.client.CloseIdleConnections()
|
s.client.CloseIdleConnections()
|
||||||
@@ -78,23 +79,35 @@ func TestStreamDoesNotLeakTickersAcrossReconnects(t *testing.T) {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
// updateHandler wants UPDATE messages and does nothing with them.
|
// updateLine is one UPDATE message as RIS Live sends it.
|
||||||
type updateHandler struct{}
|
const updateLine = `{"type":"ris_message","data":{"type":"UPDATE","peer":"192.0.2.1",` +
|
||||||
|
`"peer_asn":"64496","timestamp":1700000000}}` + "\n"
|
||||||
|
|
||||||
|
// updateHandler wants UPDATE messages. For each one it handles it sends on
|
||||||
|
// handled if there is room, and otherwise does nothing; a nil handled is
|
||||||
|
// never sent on.
|
||||||
|
type updateHandler struct {
|
||||||
|
handled chan struct{}
|
||||||
|
}
|
||||||
|
|
||||||
func (updateHandler) WantsMessage(messageType string) bool { return messageType == "UPDATE" }
|
func (updateHandler) WantsMessage(messageType string) bool { return messageType == "UPDATE" }
|
||||||
func (updateHandler) HandleMessage(*ristypes.RISMessage) {}
|
|
||||||
func (updateHandler) QueueCapacity() int { return 10 }
|
func (updateHandler) QueueCapacity() int { return 10 }
|
||||||
|
|
||||||
|
func (h updateHandler) HandleMessage(*ristypes.RISMessage) {
|
||||||
|
select {
|
||||||
|
case h.handled <- struct{}{}:
|
||||||
|
default:
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
// TestStopBeforeMessageReachesQueues stops the streamer after the read loop
|
// TestStopBeforeMessageReachesQueues stops the streamer after the read loop
|
||||||
// has checked for cancellation but before it hands the message to the handler
|
// has checked for cancellation but before it hands the message to the handler
|
||||||
// queues. That is the gap a stop from another goroutine can land in, and it
|
// queues. That is the gap a stop from another goroutine can land in, and it
|
||||||
// used to end in "send on closed channel". The raw handler runs in that gap on
|
// used to end in "send on closed channel". The raw handler runs in that gap on
|
||||||
// the read loop itself, so calling Stop from it hits the gap every time.
|
// the read loop itself, so calling Stop from it hits the gap every time.
|
||||||
func TestStopBeforeMessageReachesQueues(t *testing.T) {
|
func TestStopBeforeMessageReachesQueues(t *testing.T) {
|
||||||
const line = `{"type":"ris_message","data":{"type":"UPDATE","peer":"192.0.2.1",` +
|
|
||||||
`"peer_asn":"64496","timestamp":1700000000}}` + "\n"
|
|
||||||
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
|
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
|
||||||
_, _ = io.WriteString(w, line)
|
_, _ = io.WriteString(w, updateLine)
|
||||||
}))
|
}))
|
||||||
defer srv.Close()
|
defer srv.Close()
|
||||||
|
|
||||||
@@ -117,6 +130,106 @@ func TestStopBeforeMessageReachesQueues(t *testing.T) {
|
|||||||
s.Stop()
|
s.Stop()
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// TestReconnectWhenStreamEnds has the server end the first response
|
||||||
|
// normally, as when RIS Live restarts. The streamer must treat that as a
|
||||||
|
// disconnect and connect again.
|
||||||
|
func TestReconnectWhenStreamEnds(t *testing.T) {
|
||||||
|
endResponse := func(http.ResponseWriter, *http.Request) {}
|
||||||
|
checkReconnect(t, endResponse, streamIdleTimeout)
|
||||||
|
}
|
||||||
|
|
||||||
|
// TestReconnectWhenStreamGoesIdle has the server hold the first response
|
||||||
|
// open without sending anything. The streamer must drop it once the idle
|
||||||
|
// timeout passes and connect again.
|
||||||
|
func TestReconnectWhenStreamGoesIdle(t *testing.T) {
|
||||||
|
const idleTimeout = 50 * time.Millisecond
|
||||||
|
holdResponse := func(w http.ResponseWriter, r *http.Request) {
|
||||||
|
w.(http.Flusher).Flush()
|
||||||
|
<-r.Context().Done()
|
||||||
|
}
|
||||||
|
checkReconnect(t, holdResponse, idleTimeout)
|
||||||
|
}
|
||||||
|
|
||||||
|
// TestStreamNotDroppedWhileLinesArrive has the server send lines well within
|
||||||
|
// the idle timeout for several times the timeout, then end the response. Each
|
||||||
|
// line must start the idle timeout over, so the stream lasts until the server
|
||||||
|
// ends it instead of being dropped as idle.
|
||||||
|
func TestStreamNotDroppedWhileLinesArrive(t *testing.T) {
|
||||||
|
const (
|
||||||
|
idleTimeout = 100 * time.Millisecond
|
||||||
|
lineInterval = idleTimeout / 10
|
||||||
|
sendFor = 5 * idleTimeout
|
||||||
|
)
|
||||||
|
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
|
||||||
|
deadline := time.Now().Add(sendFor)
|
||||||
|
for time.Now().Before(deadline) {
|
||||||
|
_, _ = io.WriteString(w, updateLine)
|
||||||
|
w.(http.Flusher).Flush()
|
||||||
|
time.Sleep(lineInterval)
|
||||||
|
}
|
||||||
|
}))
|
||||||
|
defer srv.Close()
|
||||||
|
|
||||||
|
s := New(logger.New(), metrics.New())
|
||||||
|
s.url = srv.URL
|
||||||
|
s.idleTimeout = idleTimeout
|
||||||
|
|
||||||
|
if err := s.stream(context.Background()); !errors.Is(err, errStreamEnded) {
|
||||||
|
t.Fatalf("stream returned %v, want %v", err, errStreamEnded)
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
|
// checkReconnect runs a streamer against a fake RIS Live server. The first
|
||||||
|
// response is served by firstResponse; every later one carries one UPDATE
|
||||||
|
// line and then stays open. The streamer must come back for a second
|
||||||
|
// response, must not be marked connected when it does, and must handle the
|
||||||
|
// UPDATE in it.
|
||||||
|
func checkReconnect(t *testing.T, firstResponse http.HandlerFunc, idleTimeout time.Duration) {
|
||||||
|
t.Helper()
|
||||||
|
|
||||||
|
const maxWait = 5 * time.Second
|
||||||
|
|
||||||
|
tracker := metrics.New()
|
||||||
|
connectedAtReconnect := make(chan bool, 1)
|
||||||
|
var requests atomic.Int32
|
||||||
|
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
|
||||||
|
if requests.Add(1) == 1 {
|
||||||
|
firstResponse(w, r)
|
||||||
|
|
||||||
|
return
|
||||||
|
}
|
||||||
|
select {
|
||||||
|
case connectedAtReconnect <- tracker.IsConnected():
|
||||||
|
default:
|
||||||
|
}
|
||||||
|
_, _ = io.WriteString(w, updateLine)
|
||||||
|
w.(http.Flusher).Flush()
|
||||||
|
<-r.Context().Done()
|
||||||
|
}))
|
||||||
|
defer srv.Close()
|
||||||
|
|
||||||
|
s := New(logger.New(), tracker)
|
||||||
|
s.url = srv.URL
|
||||||
|
s.idleTimeout = idleTimeout
|
||||||
|
s.minBackoff = time.Millisecond
|
||||||
|
handler := updateHandler{handled: make(chan struct{}, 1)}
|
||||||
|
s.RegisterHandler(handler)
|
||||||
|
if err := s.Start(); err != nil {
|
||||||
|
t.Fatalf("Start returned error: %v", err)
|
||||||
|
}
|
||||||
|
defer s.Stop()
|
||||||
|
|
||||||
|
select {
|
||||||
|
case <-handler.handled:
|
||||||
|
case <-time.After(maxWait):
|
||||||
|
t.Fatalf("no message from a second response handled within %s", maxWait)
|
||||||
|
}
|
||||||
|
|
||||||
|
if <-connectedAtReconnect {
|
||||||
|
t.Error("streamer was still marked connected when it came back for a second response")
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
// settledGoroutineCount lets transient goroutines finish, then reports the
|
// settledGoroutineCount lets transient goroutines finish, then reports the
|
||||||
// current count.
|
// current count.
|
||||||
func settledGoroutineCount() int {
|
func settledGoroutineCount() int {
|
||||||
|
|||||||
Reference in New Issue
Block a user