From 5169129029f891e2f5c97c1006fbb6e630e6dc0c Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Zolt=C3=A1n=20Papp?= Date: Wed, 28 Jan 2026 15:51:51 +0100 Subject: [PATCH] Add signaling metrics tracking for initial and reconnection attempts --- client/internal/peer/conn.go | 2 +- client/internal/peer/handshaker.go | 28 ++++++++++++++++++++------- client/internal/peer/metrics_saver.go | 26 +++++++++++++++++++++++-- 3 files changed, 46 insertions(+), 10 deletions(-) diff --git a/client/internal/peer/conn.go b/client/internal/peer/conn.go index c23d356e0..c0a2c2862 100644 --- a/client/internal/peer/conn.go +++ b/client/internal/peer/conn.go @@ -213,7 +213,7 @@ func (conn *Conn) Open(engineCtx context.Context) error { } conn.workerICE = workerICE - conn.handshaker = NewHandshaker(conn.Log, conn.config, conn.signaler, conn.workerICE, conn.workerRelay) + conn.handshaker = NewHandshaker(conn.Log, conn.config, conn.signaler, conn.workerICE, conn.workerRelay, &conn.metricsStages) conn.handshaker.AddRelayListener(conn.workerRelay.OnNewOffer) if !isForceRelayed() { diff --git a/client/internal/peer/handshaker.go b/client/internal/peer/handshaker.go index aff26f847..9b50cecd1 100644 --- a/client/internal/peer/handshaker.go +++ b/client/internal/peer/handshaker.go @@ -44,12 +44,13 @@ type OfferAnswer struct { } type Handshaker struct { - mu sync.Mutex - log *log.Entry - config ConnConfig - signaler *Signaler - ice *WorkerICE - relay *WorkerRelay + mu sync.Mutex + log *log.Entry + config ConnConfig + signaler *Signaler + ice *WorkerICE + relay *WorkerRelay + metricsStages *MetricsStages // relayListener is not blocking because the listener is using a goroutine to process the messages // and it will only keep the latest message if multiple offers are received in a short time // this is to avoid blocking the handshaker if the listener is doing some heavy processing @@ -64,13 +65,14 @@ type Handshaker struct { remoteAnswerCh chan OfferAnswer } -func NewHandshaker(log *log.Entry, config ConnConfig, signaler *Signaler, ice *WorkerICE, relay *WorkerRelay) *Handshaker { +func NewHandshaker(log *log.Entry, config ConnConfig, signaler *Signaler, ice *WorkerICE, relay *WorkerRelay, metricsStages *MetricsStages) *Handshaker { return &Handshaker{ log: log, config: config, signaler: signaler, ice: ice, relay: relay, + metricsStages: metricsStages, remoteOffersCh: make(chan OfferAnswer), remoteAnswerCh: make(chan OfferAnswer), } @@ -89,6 +91,12 @@ func (h *Handshaker) Listen(ctx context.Context) { select { case remoteOfferAnswer := <-h.remoteOffersCh: h.log.Infof("received offer, running version %s, remote WireGuard listen port %d, session id: %s", remoteOfferAnswer.Version, remoteOfferAnswer.WgListenPort, remoteOfferAnswer.SessionIDString()) + + // Record signaling received for reconnection attempts + if h.metricsStages != nil { + h.metricsStages.RecordSignalingReceived() + } + if h.relayListener != nil { h.relayListener.Notify(&remoteOfferAnswer) } @@ -103,6 +111,12 @@ func (h *Handshaker) Listen(ctx context.Context) { } case remoteOfferAnswer := <-h.remoteAnswerCh: h.log.Infof("received answer, running version %s, remote WireGuard listen port %d, session id: %s", remoteOfferAnswer.Version, remoteOfferAnswer.WgListenPort, remoteOfferAnswer.SessionIDString()) + + // Record signaling received for reconnection attempts + if h.metricsStages != nil { + h.metricsStages.RecordSignalingReceived() + } + if h.relayListener != nil { h.relayListener.Notify(&remoteOfferAnswer) } diff --git a/client/internal/peer/metrics_saver.go b/client/internal/peer/metrics_saver.go index 6cf00d4ff..2e78ec58d 100644 --- a/client/internal/peer/metrics_saver.go +++ b/client/internal/peer/metrics_saver.go @@ -29,13 +29,35 @@ func (s *MetricsStages) RecordSemaphoreAcquired() { s.stageTimestamps.SemaphoreAcquired = time.Now() } +// RecordSignaling records the signaling timestamp when sending offers +// For initial connections: records when we start sending +// For reconnections: does nothing (we wait for RecordSignalingReceived) func (s *MetricsStages) RecordSignaling() { s.mu.Lock() defer s.mu.Unlock() - log.Infof("--- RecordSignaling") + log.Infof("--- RecordSignaling (send)") + + if s.isReconnectionAttempt { + return + } if s.stageTimestamps.Signaling.IsZero() { - log.Infof("--- Recorded Signaling") + log.Infof("--- Recorded Signaling (initial connection, sending)") + s.stageTimestamps.Signaling = time.Now() + } +} + +// RecordSignalingReceived records the signaling timestamp when receiving offers/answers +// For reconnections: records when we receive the first signal +// For initial connections: does nothing (already recorded in RecordSignaling) +func (s *MetricsStages) RecordSignalingReceived() { + s.mu.Lock() + defer s.mu.Unlock() + log.Infof("--- RecordSignalingReceived (receive)") + + // Only record for reconnections when we receive a signal + if s.isReconnectionAttempt && s.stageTimestamps.Signaling.IsZero() { + log.Infof("--- Recorded Signaling (reconnection, receiving)") s.stageTimestamps.Signaling = time.Now() } }