diff --git a/management/server/account.go b/management/server/account.go index aac136657..e00a31b73 100644 --- a/management/server/account.go +++ b/management/server/account.go @@ -386,6 +386,12 @@ func (a *Account) GetGroup(groupID string) *nbgroup.Group { // GetPeerNetworkMap returns a group by ID if exists, nil otherwise func (a *Account) GetPeerNetworkMap(peerID, dnsDomain string, validatedPeersMap map[string]struct{}) *NetworkMap { + startTime := time.Now() + defer func() { + duration := time.Since(startTime) + log.Debugf("GetPeerNetworkMap took %s", duration) + }() + peer := a.Peers[peerID] if peer == nil { return &NetworkMap{ diff --git a/management/server/grpcserver.go b/management/server/grpcserver.go index 4df24711e..84c6d561d 100644 --- a/management/server/grpcserver.go +++ b/management/server/grpcserver.go @@ -121,6 +121,12 @@ func getRealIP(ctx context.Context) net.IP { // Sync validates the existence of a connecting peer, sends an initial state (all available for the connecting peers) and // notifies the connected peer of any updates (e.g. new peers under the same account) func (s *GRPCServer) Sync(req *proto.EncryptedMessage, srv proto.ManagementService_SyncServer) error { + startTime := time.Now() + defer func() { + duration := time.Since(startTime) + log.Debugf("Sync took %s", duration) + }() + reqStart := time.Now() if s.appMetrics != nil { s.appMetrics.GRPCMetrics().CountSyncRequest() @@ -523,6 +529,12 @@ func (s *GRPCServer) IsHealthy(ctx context.Context, req *proto.Empty) (*proto.Em // sendInitialSync sends initial proto.SyncResponse to the peer requesting synchronization func (s *GRPCServer) sendInitialSync(peerKey wgtypes.Key, peer *nbpeer.Peer, networkMap *NetworkMap, srv proto.ManagementService_SyncServer) error { + startTime := time.Now() + defer func() { + duration := time.Since(startTime) + log.Debugf("sendInitialSync took %s", duration) + }() + // make secret time based TURN credentials optional var turnCredentials *TURNCredentials if s.config.TURNConfig.TimeBasedCredentials { diff --git a/management/server/integrated_validator.go b/management/server/integrated_validator.go index cd770a801..a47dc5bf3 100644 --- a/management/server/integrated_validator.go +++ b/management/server/integrated_validator.go @@ -2,6 +2,7 @@ package server import ( "errors" + "time" "github.com/google/martian/v3/log" @@ -76,5 +77,11 @@ func (am *DefaultAccountManager) GroupValidation(accountId string, groups []stri } func (am *DefaultAccountManager) GetValidatedPeers(account *Account) (map[string]struct{}, error) { + startTime := time.Now() + defer func() { + duration := time.Since(startTime) + log.Debugf("GetValidatedPeers took %s", duration) + }() + return am.integratedPeerValidator.GetValidatedPeers(account.Id, account.Groups, account.Peers, account.Settings.Extra) } diff --git a/management/server/peer.go b/management/server/peer.go index 1a8b183ed..9712bd1f6 100644 --- a/management/server/peer.go +++ b/management/server/peer.go @@ -89,6 +89,12 @@ func (am *DefaultAccountManager) GetPeers(accountID, userID string) ([]*nbpeer.P // MarkPeerConnected marks peer as connected (true) or disconnected (false) func (am *DefaultAccountManager) MarkPeerConnected(peerPubKey string, connected bool, realIP net.IP) error { + startTime := time.Now() + defer func() { + duration := time.Since(startTime) + log.Debugf("MarkPeerConnected took %s", duration) + }() + account, err := am.Store.GetAccountByPeerPubKey(peerPubKey) if err != nil { return err @@ -519,6 +525,12 @@ func (am *DefaultAccountManager) AddPeer(setupKey, userID string, peer *nbpeer.P // SyncPeer checks whether peer is eligible for receiving NetworkMap (authenticated) and returns its NetworkMap if eligible func (am *DefaultAccountManager) SyncPeer(sync PeerSync) (*nbpeer.Peer, *NetworkMap, error) { + startTime := time.Now() + defer func() { + duration := time.Since(startTime) + log.Debugf("SyncPeer took %s", duration) + }() + account, err := am.Store.GetAccountByPeerPubKey(sync.WireGuardPubKey) if err != nil { if errStatus, ok := status.FromError(err); ok && errStatus.Type() == status.NotFound { @@ -684,6 +696,12 @@ func (am *DefaultAccountManager) LoginPeer(login PeerLogin) (*nbpeer.Peer, *Netw } func checkIfPeerOwnerIsBlocked(peer *nbpeer.Peer, account *Account) error { + startTime := time.Now() + defer func() { + duration := time.Since(startTime) + log.Debugf("checkIfPeerOwnerIsBlocked took %s", duration) + }() + if peer.AddedWithSSOLogin() { user, err := account.FindUser(peer.UserID) if err != nil { @@ -857,6 +875,12 @@ func updatePeerMeta(peer *nbpeer.Peer, meta nbpeer.PeerSystemMeta, account *Acco // updateAccountPeers updates all peers that belong to an account. // Should be called when changes have to be synced to peers. func (am *DefaultAccountManager) updateAccountPeers(account *Account) { + startTime := time.Now() + defer func() { + duration := time.Since(startTime) + log.Debugf("updateAccountPeers took %s", duration) + }() + peers := account.GetPeers() approvedPeersMap, err := am.GetValidatedPeers(account) diff --git a/management/server/peer/peer.go b/management/server/peer/peer.go index e62843180..42efe40aa 100644 --- a/management/server/peer/peer.go +++ b/management/server/peer/peer.go @@ -5,6 +5,8 @@ import ( "net" "net/netip" "time" + + log "github.com/sirupsen/logrus" ) // Peer represents a machine connected to the network. @@ -173,6 +175,8 @@ func (p *Peer) UpdateMetaIfNew(meta PeerSystemMeta) bool { meta.UIVersion = p.Meta.UIVersion } + log.Infof("Check if meta is equal: %v", p.Meta.isEqual(meta)) + if p.Meta.isEqual(meta) { return false } diff --git a/management/server/sqlite_store.go b/management/server/sqlite_store.go index bfde82a6d..3c77cea10 100644 --- a/management/server/sqlite_store.go +++ b/management/server/sqlite_store.go @@ -263,36 +263,27 @@ func (s *SqliteStore) GetInstallationID() string { } func (s *SqliteStore) SavePeerStatus(accountID, peerID string, peerStatus nbpeer.PeerStatus) error { - var peer nbpeer.Peer + startTime := time.Now() + defer func() { + duration := time.Since(startTime) + log.Debugf("SavePeerStatus took %s", duration) + }() - result := s.db.First(&peer, "account_id = ? and id = ?", accountID, peerID) - if result.Error != nil { - if errors.Is(result.Error, gorm.ErrRecordNotFound) { - return status.Errorf(status.NotFound, "peer %s not found", peerID) - } - log.Errorf("error when getting peer from the store: %s", result.Error) - return status.Errorf(status.Internal, "issue getting peer from store") - } - - peer.Status = &peerStatus - - return s.db.Save(peer).Error + log.Infof("saving peer status") + s.db.Where("account_id = ? and id = ?", accountID, peerID).Update("status", peerStatus) + return nil } func (s *SqliteStore) SavePeerLocation(accountID string, peerWithLocation *nbpeer.Peer) error { - var peer nbpeer.Peer - result := s.db.First(&peer, "account_id = ? and id = ?", accountID, peerWithLocation.ID) - if result.Error != nil { - if errors.Is(result.Error, gorm.ErrRecordNotFound) { - return status.Errorf(status.NotFound, "peer %s not found", peer.ID) - } - log.Errorf("error when getting peer from the store: %s", result.Error) - return status.Errorf(status.Internal, "issue getting peer from store") - } + startTime := time.Now() + defer func() { + duration := time.Since(startTime) + log.Debugf("SavePeerLocation took %s", duration) + }() - peer.Location = peerWithLocation.Location - - return s.db.Save(peer).Error + log.Info("saving peer location") + s.db.Where("account_id = ? and id = ?", accountID, peerWithLocation.ID).Update("location", peerWithLocation.Location) + return nil } // DeleteHashedPAT2TokenIDIndex is noop in Sqlite @@ -400,6 +391,12 @@ func (s *SqliteStore) GetAllAccounts() (all []*Account) { } func (s *SqliteStore) GetAccount(accountID string) (*Account, error) { + startTime := time.Now() + defer func() { + duration := time.Since(startTime) + log.Debugf("GetAccount took %s", duration) + }() + var account Account result := s.db.Model(&account). Preload("UsersG.PATsG"). // have to be specifies as this is nester reference