From ddffa0a8c6259776331dbc7b67501b86fae48e91 Mon Sep 17 00:00:00 2001 From: Pascal Fischer Date: Fri, 7 Feb 2025 11:32:07 +0100 Subject: [PATCH 1/3] add trace logs on grpc api --- management/server/grpcserver.go | 18 ++++++++++++++++++ 1 file changed, 18 insertions(+) diff --git a/management/server/grpcserver.go b/management/server/grpcserver.go index eec109ee970..6b5aa322a60 100644 --- a/management/server/grpcserver.go +++ b/management/server/grpcserver.go @@ -114,6 +114,12 @@ func NewServer( } func (s *GRPCServer) GetServerKey(ctx context.Context, req *proto.Empty) (*proto.ServerKeyResponse, error) { + log.WithContext(ctx).Tracef("GetServerKey request") + start := time.Now() + defer func() { + log.WithContext(ctx).Tracef("GetServerKey took %v", time.Since(start)) + }() + // todo introduce something more meaningful with the key expiration/rotation if s.appMetrics != nil { s.appMetrics.GRPCMetrics().CountGetKeyRequest() @@ -717,6 +723,12 @@ func (s *GRPCServer) sendInitialSync(ctx context.Context, peerKey wgtypes.Key, p // This is used for initiating an Oauth 2 device authorization grant flow // which will be used by our clients to Login func (s *GRPCServer) GetDeviceAuthorizationFlow(ctx context.Context, req *proto.EncryptedMessage) (*proto.EncryptedMessage, error) { + log.WithContext(ctx).Tracef("GetDeviceAuthorizationFlow request") + start := time.Now() + defer func() { + log.WithContext(ctx).Tracef("GetDeviceAuthorizationFlow took %v", time.Since(start)) + }() + peerKey, err := wgtypes.ParseKey(req.GetWgPubKey()) if err != nil { errMSG := fmt.Sprintf("error while parsing peer's Wireguard public key %s on GetDeviceAuthorizationFlow request.", req.WgPubKey) @@ -769,6 +781,12 @@ func (s *GRPCServer) GetDeviceAuthorizationFlow(ctx context.Context, req *proto. // This is used for initiating an Oauth 2 pkce authorization grant flow // which will be used by our clients to Login func (s *GRPCServer) GetPKCEAuthorizationFlow(ctx context.Context, req *proto.EncryptedMessage) (*proto.EncryptedMessage, error) { + log.WithContext(ctx).Tracef("GetPKCEAuthorizationFlow request") + start := time.Now() + defer func() { + log.WithContext(ctx).Tracef("GetPKCEAuthorizationFlow took %v", time.Since(start)) + }() + peerKey, err := wgtypes.ParseKey(req.GetWgPubKey()) if err != nil { errMSG := fmt.Sprintf("error while parsing peer's Wireguard public key %s on GetPKCEAuthorizationFlow request.", req.WgPubKey) From 7e03c853652c9364dab2cc7ac3e24771b5d2bd8a Mon Sep 17 00:00:00 2001 From: Pascal Fischer Date: Fri, 7 Feb 2025 11:37:00 +0100 Subject: [PATCH 2/3] add pubKey to logs --- management/server/grpcserver.go | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/management/server/grpcserver.go b/management/server/grpcserver.go index 6b5aa322a60..2fa6fd7f805 100644 --- a/management/server/grpcserver.go +++ b/management/server/grpcserver.go @@ -723,10 +723,10 @@ func (s *GRPCServer) sendInitialSync(ctx context.Context, peerKey wgtypes.Key, p // This is used for initiating an Oauth 2 device authorization grant flow // which will be used by our clients to Login func (s *GRPCServer) GetDeviceAuthorizationFlow(ctx context.Context, req *proto.EncryptedMessage) (*proto.EncryptedMessage, error) { - log.WithContext(ctx).Tracef("GetDeviceAuthorizationFlow request") + log.WithContext(ctx).Tracef("GetDeviceAuthorizationFlow request for pubKey: %s", req.WgPubKey) start := time.Now() defer func() { - log.WithContext(ctx).Tracef("GetDeviceAuthorizationFlow took %v", time.Since(start)) + log.WithContext(ctx).Tracef("GetDeviceAuthorizationFlow for pubKey: %s took %v", req.WgPubKey, time.Since(start)) }() peerKey, err := wgtypes.ParseKey(req.GetWgPubKey()) @@ -781,10 +781,10 @@ func (s *GRPCServer) GetDeviceAuthorizationFlow(ctx context.Context, req *proto. // This is used for initiating an Oauth 2 pkce authorization grant flow // which will be used by our clients to Login func (s *GRPCServer) GetPKCEAuthorizationFlow(ctx context.Context, req *proto.EncryptedMessage) (*proto.EncryptedMessage, error) { - log.WithContext(ctx).Tracef("GetPKCEAuthorizationFlow request") + log.WithContext(ctx).Tracef("GetPKCEAuthorizationFlow request for pubKey: %s", req.WgPubKey) start := time.Now() defer func() { - log.WithContext(ctx).Tracef("GetPKCEAuthorizationFlow took %v", time.Since(start)) + log.WithContext(ctx).Tracef("GetPKCEAuthorizationFlow for pubKey %s took %v", req.WgPubKey, time.Since(start)) }() peerKey, err := wgtypes.ParseKey(req.GetWgPubKey()) From 7a633d6d61aa2ff003fe7e91d35f650082925bb8 Mon Sep 17 00:00:00 2001 From: Pascal Fischer Date: Fri, 7 Feb 2025 12:23:46 +0100 Subject: [PATCH 3/3] use IP for GetServerKey --- management/server/grpcserver.go | 11 +++++++++-- 1 file changed, 9 insertions(+), 2 deletions(-) diff --git a/management/server/grpcserver.go b/management/server/grpcserver.go index 2fa6fd7f805..e8e0c422ed6 100644 --- a/management/server/grpcserver.go +++ b/management/server/grpcserver.go @@ -15,6 +15,7 @@ import ( log "github.com/sirupsen/logrus" "golang.zx2c4.com/wireguard/wgctrl/wgtypes" "google.golang.org/grpc/codes" + "google.golang.org/grpc/peer" "google.golang.org/grpc/status" "github.com/netbirdio/netbird/encryption" @@ -114,10 +115,16 @@ func NewServer( } func (s *GRPCServer) GetServerKey(ctx context.Context, req *proto.Empty) (*proto.ServerKeyResponse, error) { - log.WithContext(ctx).Tracef("GetServerKey request") + ip := "" + p, ok := peer.FromContext(ctx) + if ok { + ip = p.Addr.String() + } + + log.WithContext(ctx).Tracef("GetServerKey request from %s", ip) start := time.Now() defer func() { - log.WithContext(ctx).Tracef("GetServerKey took %v", time.Since(start)) + log.WithContext(ctx).Tracef("GetServerKey from %s took %v", ip, time.Since(start)) }() // todo introduce something more meaningful with the key expiration/rotation