Log invite retry attempts. (#464)

* Log invite retry attempts.

* Account for reinvites.

Author: dennwc

go.mod

@@ -33,6 +33,7 @@ require (
 )
 
 require (
+	github.com/hashicorp/golang-lru/v2 v2.0.7 // indirect
 	github.com/nyaruka/phonenumbers v1.6.5 // indirect
 	go.opentelemetry.io/auto/sdk v1.1.0 // indirect
 	go.opentelemetry.io/otel v1.37.0 // indirect

go.sum

@@ -97,6 +97,8 @@ github.com/gorilla/websocket v1.5.3 h1:saDtZ6Pbx/0u+bgYQ3q96pZgCzfhKXGPqt7kZ72aN
 github.com/gorilla/websocket v1.5.3/go.mod h1:YR8l580nyteQvAITg2hZ9XVh4b55+EU/adAjf1fMHhE=
 github.com/gotranspile/g722 v0.0.0-20240123003956-384a1bb16a19 h1:vqA29ogkaaq2GxFQsMA8TTFUSGc1lGaZtnKbuiP840c=
 github.com/gotranspile/g722 v0.0.0-20240123003956-384a1bb16a19/go.mod h1:AcVi4yM6DRZscpQXsEWBPItD52Saqw0x7md4mmjzUi8=
+github.com/hashicorp/golang-lru/v2 v2.0.7 h1:a+bsQ5rvGLjzHuww6tVxozPZFVghXaHOwFs4luLUK2k=
+github.com/hashicorp/golang-lru/v2 v2.0.7/go.mod h1:QeFd9opnmA6QUJc5vARoKUSoFhyfM2/ZepoAG6RGpeM=
 github.com/icholy/digest v1.1.0 h1:HfGg9Irj7i+IX1o1QAmPfIBNu/Q5A5Tu3n/MED9k9H4=
 github.com/icholy/digest v1.1.0/go.mod h1:QNrsSGQ5v7v9cReDI0+eyjsXGUoRSUZQHeQ5C4XLa0Y=
 github.com/jfreymuth/oggvorbis v1.0.5 h1:u+Ck+R0eLSRhgq8WTmffYnrVtSztJcYrl588DM4e3kQ=

pkg/sip/inbound.go

@@ -76,6 +76,63 @@ func hashPassword(password string) string {
 	return hex.EncodeToString(hash[:8]) // Use first 8 bytes for shorter hash
 }
 
+type inboundCallInfo struct {
+	sync.Mutex
+	cseq        uint32
+	cseqAuth    uint32
+	invites     uint32
+	invitesAuth uint32
+}
+
+func inviteHasAuth(r *sip.Request) bool {
+	return r.GetHeader("Proxy-Authorization") != nil ||
+		r.GetHeader("Authorization") != nil
+}
+
+func (c *inboundCallInfo) countInvite(log logger.Logger, req *sip.Request) {
+	hasAuth := inviteHasAuth(req)
+	cseq := req.CSeq()
+	if cseq == nil {
+		return
+	}
+	c.Lock()
+	defer c.Unlock()
+	cseqPtr := &c.cseq
+	countPtr := &c.invites
+	name := "invite"
+	if hasAuth {
+		cseqPtr = &c.cseqAuth
+		countPtr = &c.invitesAuth
+		name = "invite with auth"
+	}
+	if *cseqPtr == 0 {
+		*cseqPtr = cseq.SeqNo
+	}
+	if cseq.SeqNo > *cseqPtr {
+		return // reinvite
+	}
+	*countPtr++
+	if *countPtr > 1 {
+		log.Warnw("remote appears to be retrying an "+name, nil, "invites", *countPtr, "cseq", *cseqPtr)
+	}
+}
+
+func (s *Server) getCallInfo(id string) *inboundCallInfo {
+	c, _ := s.infos.byCallID.Get(id)
+	if c != nil {
+		return c
+	}
+	s.infos.Lock()
+	defer s.infos.Unlock()
+	c, _ = s.infos.byCallID.Get(id)
+	if c != nil {
+		return c
+	}
+	c = &inboundCallInfo{}
+	s.infos.byCallID.Add(id, c)
+	return c
+}
+
 func (s *Server) getInvite(sipCallID string) *inProgressInvite {
 	s.imu.Lock()
 	defer s.imu.Unlock()
@@ -118,6 +175,8 @@ func (s *Server) handleInviteAuth(log logger.Logger, req *sip.Request, tx sip.Se
 	if h := req.CallID(); h != nil {
 		sipCallID = h.Value()
 	}
+	ci := s.getCallInfo(sipCallID)
+	ci.countInvite(log, req)
 	inviteState := s.getInvite(sipCallID)
 	log = log.WithValues("inviteStateSipCallID", sipCallID)
 

pkg/sip/server.go

@@ -27,6 +27,7 @@ import (
 	"time"
 
 	"github.com/frostbyte73/core"
+	"github.com/hashicorp/golang-lru/v2/expirable"
 	"github.com/icholy/digest"
 	"golang.org/x/exp/maps"
 
@@ -46,6 +47,11 @@ const (
 	digestLimit = 500
 )
 
+const (
+	maxCallCache = 5000        // ~8 B per entry, ~40 KB
+	callCacheTTL = time.Minute // we only need it for detecting retries from providers for now
+)
+
 var (
 	contentTypeHeaderSDP = sip.ContentTypeHeader("application/sdp")
 )
@@ -133,6 +139,11 @@ type Server struct {
 	activeCalls map[RemoteTag]*inboundCall
 	byLocal     map[LocalTag]*inboundCall
 
+	infos struct {
+		sync.Mutex
+		byCallID *expirable.LRU[string, *inboundCallInfo]
+	}
+
 	handler Handler
 	conf    *config.Config
 	sconf   *ServiceConfig
@@ -158,6 +169,7 @@ func NewServer(region string, conf *config.Config, log logger.Logger, mon *stats
 		activeCalls: make(map[RemoteTag]*inboundCall),
 		byLocal:     make(map[LocalTag]*inboundCall),
 	}
+	s.infos.byCallID = expirable.NewLRU[string, *inboundCallInfo](maxCallCache, nil, callCacheTTL)
 	s.initMediaRes()
 	return s
 }