sendnrw/netbird
2
0
Fork 0
mirror of https://github.com/netbirdio/netbird.git synced 2026-04-24 19:26:39 +00:00
Code Issues Packages Projects Releases Wiki Activity

Add detailed timing logs to sync fast path operations

Browse Source
This commit is contained in:
mlsmaycon
2026-04-21 23:02:58 +02:00
parent 3eb1298cb4
commit 46446acd30
1 changed files with 21 additions and 1 deletions
Download Patch File Download Diff File Expand all files Collapse all files

22
management/internals/shared/grpc/sync_fast_path.go
View File

@@ -106,15 +106,18 @@ func buildFastPathResponse(
nbConfig := toNetbirdConfig(cfg, turnToken, relayToken, extraSettings)
var peerGroups []string
start := time.Now()
if fetchGroups != nil {
if ids, err := fetchGroups(ctx, peer.AccountID, peer.ID); err != nil {
log.WithContext(ctx).Debugf("fast path: get peer group ids: %v", err)
} else {
peerGroups = ids
}
log.WithContext(ctx).Debugf("fast path: get peer group took %s", time.Since(start))
}
start = time.Now()
nbConfig = integrationsConfig.ExtendNetBirdConfig(peer.ID, peerGroups, nbConfig, extraSettings)
log.WithContext(ctx).Debugf("fast path: ExtendNetBirdConfig took %s", time.Since(start))
return &proto.SyncResponse{NetbirdConfig: nbConfig}
}
@@ -155,9 +158,12 @@ func (s *Server) tryFastPathSync(
cached, hit := s.peerSerialCache.Get(peerKey.String())
if !shouldSkipNetworkMap(peerMeta.GoOS, hit, cached, network.CurrentSerial(), peerMetaHash) {
log.WithContext(ctx).Tracef("fast path: checking for fast path eligibility for peer took %s", time.Since(reqStart))
return false, nil
}
log.WithContext(ctx).Tracef("fast path: checking for fast path eligibility for peer took %s", time.Since(reqStart))
peer, updates, committed := s.commitFastPath(ctx, accountID, peerKey, realIP, syncStart, network.CurrentSerial())
if !committed {
return false, nil
@@ -180,28 +186,39 @@ func (s *Server) commitFastPath(
syncStart time.Time,
expectedSerial uint64,
) (*nbpeer.Peer, chan *network_map.UpdateMessage, bool) {
defer log.WithContext(ctx).Tracef("fast path: commitFastPath took %s", time.Since(syncStart))
if err := s.accountManager.MarkPeerConnected(ctx, peerKey.String(), true, realIP, accountID, syncStart); err != nil {
log.WithContext(ctx).Warnf("fast path: mark connected for peer %s: %v", peerKey.String(), err)
}
log.WithContext(ctx).Tracef("fast path: mark peer connected took %s", time.Since(syncStart))
peer, err := s.accountManager.GetStore().GetPeerByPeerPubKey(ctx, store.LockingStrengthNone, peerKey.String())
if err != nil {
log.WithContext(ctx).Debugf("fast path: lookup peer %s: %v", peerKey.String(), err)
return nil, nil, false
}
log.WithContext(ctx).Tracef("fast path: get peer took %s", time.Since(syncStart))
updates, err := s.networkMapController.OnPeerConnected(ctx, accountID, peer.ID)
if err != nil {
log.WithContext(ctx).Debugf("fast path: notify peer connected for %s: %v", peerKey.String(), err)
return nil, nil, false
}
log.WithContext(ctx).Tracef("fast path: on peer connected took %s", time.Since(syncStart))
network, err := s.accountManager.GetStore().GetAccountNetwork(ctx, store.LockingStrengthNone, accountID)
if err != nil {
log.WithContext(ctx).Debugf("fast path: re-check account network: %v", err)
s.cancelPeerRoutinesWithoutLock(ctx, accountID, peer, syncStart)
return nil, nil, false
}
log.WithContext(ctx).Tracef("fast path: get network took %s", time.Since(syncStart))
if network.CurrentSerial() != expectedSerial {
log.WithContext(ctx).Debugf("fast path: serial advanced from %d to %d after subscribe, falling back to slow path for peer %s", expectedSerial, network.CurrentSerial(), peerKey.String())
s.cancelPeerRoutinesWithoutLock(ctx, accountID, peer, syncStart)
@@ -234,6 +251,8 @@ func (s *Server) runFastPathSync(
return err
}
log.WithContext(ctx).Tracef("fast path: mark peer connected took %s", time.Since(syncStart))
s.secretsManager.SetupRefresh(ctx, accountID, peer.ID)
if unlock != nil && *unlock != nil {
@@ -244,6 +263,7 @@ func (s *Server) runFastPathSync(
if s.appMetrics != nil {
s.appMetrics.GRPCMetrics().CountSyncRequestDuration(time.Since(reqStart), accountID)
}
log.WithContext(ctx).Tracef("fast path: sync took %s", time.Since(syncStart))
log.WithContext(ctx).Debugf("Sync (fast path) took %s", time.Since(reqStart))
s.syncSem.Add(-1)