Merge branch 'debug-slow-conn' into merged-fixes

client/iface/configurer/usp.go

@@ -394,6 +394,13 @@ func toLastHandshake(stringVar string) (time.Time, error) {
 	if err != nil {
 		return time.Time{}, fmt.Errorf("parse handshake sec: %w", err)
 	}
+
+	// If sec is 0 (Unix epoch), return zero time instead
+	// This indicates no handshake has occurred
+	if sec == 0 {
+		return time.Time{}, nil
+	}
+
 	return time.Unix(sec, 0), nil
 }
 

client/internal/engine.go

@@ -949,7 +949,6 @@ func (e *Engine) receiveManagementEvents() {
 			e.config.LazyConnectionEnabled,
 		)
 
-		// err = e.mgmClient.Sync(info, e.handleSync)
 		err = e.mgmClient.Sync(e.ctx, info, e.handleSync)
 		if err != nil {
 			// happens if management is unavailable for a long time.
@@ -960,7 +959,7 @@ func (e *Engine) receiveManagementEvents() {
 		}
 		log.Debugf("stopped receiving updates from Management Service")
 	}()
-	log.Debugf("connecting to Management Service updates stream")
+	log.Infof("connecting to Management Service updates stream")
 }
 
 func (e *Engine) updateSTUNs(stuns []*mgmProto.HostConfig) error {

client/internal/peer/wg_watcher.go

@@ -33,6 +33,7 @@ type WGWatcher struct {
 	ctx       context.Context
 	ctxCancel context.CancelFunc
 	ctxLock   sync.Mutex
+	enabled   time.Time
 }
 
 func NewWGWatcher(log *log.Entry, wgIfaceStater WGInterfaceStater, peerKey string, stateDump *stateDump) *WGWatcher {
@@ -48,6 +49,7 @@ func NewWGWatcher(log *log.Entry, wgIfaceStater WGInterfaceStater, peerKey strin
 func (w *WGWatcher) EnableWgWatcher(parentCtx context.Context, onDisconnectedFn func()) {
 	w.log.Debugf("enable WireGuard watcher")
 	w.ctxLock.Lock()
+	w.enabled = time.Now()
 
 	if w.ctx != nil && w.ctx.Err() == nil {
 		w.log.Errorf("WireGuard watcher already enabled")
@@ -87,6 +89,8 @@ func (w *WGWatcher) DisableWgWatcher() {
 func (w *WGWatcher) periodicHandshakeCheck(ctx context.Context, ctxCancel context.CancelFunc, onDisconnectedFn func(), initialHandshake time.Time) {
 	w.log.Infof("WireGuard watcher started")
 
+	debugTicker := time.NewTicker(time.Second)
+
 	timer := time.NewTimer(wgHandshakeOvertime)
 	defer timer.Stop()
 	defer ctxCancel()
@@ -95,12 +99,29 @@ func (w *WGWatcher) periodicHandshakeCheck(ctx context.Context, ctxCancel contex
 
 	for {
 		select {
+		case <-debugTicker.C:
+			handshake, err := w.wgState()
+			if err != nil {
+				w.log.Errorf("failed to read wg stats: %v", err)
+				continue
+			}
+			if !handshake.IsZero() {
+				w.log.Infof("first wg handshake detected at: %s, %s", handshake, time.Since(w.enabled))
+				debugTicker.Stop()
+			}
 		case <-timer.C:
 			handshake, ok := w.handshakeCheck(lastHandshake)
 			if !ok {
 				onDisconnectedFn()
 				return
 			}
+			/*
+				// todo: put it back if remove debug ticker
+				if lastHandshake.IsZero() {
+					w.log.Infof("first wg handshake detected at: %s", handshake)
+				}
+			*/
+
 			lastHandshake = *handshake
 
 			resetTime := time.Until(handshake.Add(checkPeriod))

client/system/info.go

@@ -6,6 +6,7 @@ import (
 	"net/netip"
 	"strings"
 
+	log "github.com/sirupsen/logrus"
 	"google.golang.org/grpc/metadata"
 
 	"github.com/netbirdio/netbird/shared/management/proto"
@@ -180,6 +181,7 @@ func isDuplicated(addresses []NetworkAddress, addr NetworkAddress) bool {
 
 // GetInfoWithChecks retrieves and parses the system information with applied checks.
 func GetInfoWithChecks(ctx context.Context, checks []*proto.Checks) (*Info, error) {
+	log.Debugf("gathering system information with checks: %d", len(checks))
 	processCheckPaths := make([]string, 0)
 	for _, check := range checks {
 		processCheckPaths = append(processCheckPaths, check.GetFiles()...)
@@ -189,10 +191,12 @@ func GetInfoWithChecks(ctx context.Context, checks []*proto.Checks) (*Info, erro
 	if err != nil {
 		return nil, err
 	}
+	log.Debugf("gathering process check information completed")
 
 	info := GetInfo(ctx)
 	info.Files = files
 
+	log.Debugf("all system information gathered successfully")
 	return info, nil
 }
 

client/system/info_windows.go

@@ -33,14 +33,18 @@ type Win32_BIOS struct {
 
 // GetInfo retrieves and parses the system information
 func GetInfo(ctx context.Context) *Info {
+	log.Debugf("gathering OS name and version")
 	osName, osVersion := getOSNameAndVersion()
+	log.Debugf("gathering build version")
 	buildVersion := getBuildVersion()
 
+	log.Debugf("gathering networkAddresses")
 	addrs, err := networkAddresses()
 	if err != nil {
 		log.Warnf("failed to discover network addresses: %s", err)
 	}
 
+	log.Debugf("gathering static info")
 	start := time.Now()
 	si := updateStaticInfo()
 	if time.Since(start) > 1*time.Second {
@@ -62,11 +66,15 @@ func GetInfo(ctx context.Context) *Info {
 		Environment:        si.Environment,
 	}
 
+	log.Debugf("gathering Hostname")
 	systemHostname, _ := os.Hostname()
-	gio.Hostname = extractDeviceName(ctx, systemHostname)
-	gio.NetbirdVersion = version.NetbirdVersion()
-	gio.UIVersion = extractUserAgent(ctx)
 
+	log.Debugf("gathering extractDeviceName")
+	gio.Hostname = extractDeviceName(ctx, systemHostname)
+	log.Debugf("gathering NetbirdVersion")
+	gio.NetbirdVersion = version.NetbirdVersion()
+	log.Debugf("gathering extractUserAgent")
+	gio.UIVersion = extractUserAgent(ctx)
 	return gio
 }