diff --git a/go.mod b/go.mod index bf7e61b7..20bd86bd 100644 --- a/go.mod +++ b/go.mod @@ -150,7 +150,6 @@ require ( github.com/opencontainers/image-spec v1.1.0-rc6 // indirect github.com/opencontainers/runc v1.1.12 // indirect github.com/pelletier/go-toml/v2 v2.1.1 // indirect - github.com/petermattis/goid v0.0.0-20180202154549-b0b1615b78e5 // indirect github.com/pierrec/lz4/v4 v4.1.21 // indirect github.com/pkg/errors v0.9.1 // indirect github.com/pmezard/go-difflib v1.0.1-0.20181226105442-5d4384ee4fb2 // indirect @@ -162,7 +161,6 @@ require ( github.com/safchain/ethtool v0.3.0 // indirect github.com/sagikazarmark/locafero v0.4.0 // indirect github.com/sagikazarmark/slog-shim v0.1.0 // indirect - github.com/sasha-s/go-deadlock v0.3.1 // indirect github.com/sirupsen/logrus v1.9.3 // indirect github.com/sourcegraph/conc v0.3.0 // indirect github.com/spf13/afero v1.11.0 // indirect diff --git a/go.sum b/go.sum index 703fa08c..63876d19 100644 --- a/go.sum +++ b/go.sum @@ -336,8 +336,6 @@ github.com/patrickmn/go-cache v2.1.0+incompatible h1:HRMgzkcYKYpi3C8ajMPV8OFXaaR github.com/patrickmn/go-cache v2.1.0+incompatible/go.mod h1:3Qf8kWWT7OJRJbdiICTKqZju1ZixQ/KpMGzzAfe6+WQ= github.com/pelletier/go-toml/v2 v2.1.1 h1:LWAJwfNvjQZCFIDKWYQaM62NcYeYViCmWIwmOStowAI= github.com/pelletier/go-toml/v2 v2.1.1/go.mod h1:tJU2Z3ZkXwnxa4DPO899bsyIoywizdUvyaeZurnPPDc= -github.com/petermattis/goid v0.0.0-20180202154549-b0b1615b78e5 h1:q2e307iGHPdTGp0hoxKjt1H5pDo6utceo3dQVK3I5XQ= -github.com/petermattis/goid v0.0.0-20180202154549-b0b1615b78e5/go.mod h1:jvVRKCrJTQWu0XVbaOlby/2lO20uSCHEMzzplHXte1o= github.com/philip-bui/grpc-zerolog v1.0.1 h1:EMacvLRUd2O1K0eWod27ZP5CY1iTNkhBDLSN+Q4JEvA= github.com/philip-bui/grpc-zerolog v1.0.1/go.mod h1:qXbiq/2X4ZUMMshsqlWyTHOcw7ns+GZmlqZZN05ZHcQ= github.com/pierrec/lz4/v4 v4.1.14/go.mod h1:gZWDp/Ze/IJXGXf23ltt2EXimqmTUXEy0GFuRQyBid4= @@ -394,8 +392,6 @@ github.com/sagikazarmark/slog-shim v0.1.0 h1:diDBnUNK9N/354PgrxMywXnAwEr1QZcOr6g github.com/sagikazarmark/slog-shim v0.1.0/go.mod h1:SrcSrq8aKtyuqEI1uvTDTK1arOWRIczQRv+GVI1AkeQ= github.com/samber/lo v1.39.0 h1:4gTz1wUhNYLhFSKl6O+8peW0v2F4BCY034GRpU9WnuA= github.com/samber/lo v1.39.0/go.mod h1:+m/ZKRl6ClXCE2Lgf3MsQlWfh4bn1bz6CXEOxnEXnEA= -github.com/sasha-s/go-deadlock v0.3.1 h1:sqv7fDNShgjcaxkO0JNcOAlr8B9+cV5Ey/OB71efZx0= -github.com/sasha-s/go-deadlock v0.3.1/go.mod h1:F73l+cr82YSh10GxyRI6qZiCgK64VaZjwesgfQ1/iLM= github.com/sergi/go-diff v1.2.0/go.mod h1:STckp+ISIX8hZLjrqAeVduY0gWCT9IjLuqbuNXdaHfM= github.com/sergi/go-diff v1.3.1 h1:xkr+Oxo4BOQKmkn/B9eMK0g5Kg/983T9DqqPHwYqD+8= github.com/sergi/go-diff v1.3.1/go.mod h1:aMJSSKb2lpPvRNec0+w3fl7LP9IOFzdc9Pa4NFbPK1I= diff --git a/hscontrol/app.go b/hscontrol/app.go index 7eb15495..6d727001 100644 --- a/hscontrol/app.go +++ b/hscontrol/app.go @@ -39,7 +39,6 @@ import ( "github.com/prometheus/client_golang/prometheus/promhttp" zl "github.com/rs/zerolog" "github.com/rs/zerolog/log" - "github.com/sasha-s/go-deadlock" "golang.org/x/crypto/acme" "golang.org/x/crypto/acme/autocert" "golang.org/x/oauth2" @@ -79,10 +78,10 @@ const ( registerCacheCleanup = time.Minute * 20 ) -func init() { - deadlock.Opts.DeadlockTimeout = 15 * time.Second - deadlock.Opts.PrintAllCurrentGoroutines = true -} +// func init() { +// deadlock.Opts.DeadlockTimeout = 15 * time.Second +// deadlock.Opts.PrintAllCurrentGoroutines = true +// } // Headscale represents the base app of the service. type Headscale struct { @@ -107,7 +106,7 @@ type Headscale struct { pollNetMapStreamWG sync.WaitGroup mapSessions map[types.NodeID]*mapSession - mapSessionMu deadlock.Mutex + mapSessionMu sync.Mutex } var ( @@ -323,11 +322,6 @@ func (h *Headscale) grpcAuthenticationInterceptor(ctx context.Context, meta, ok := metadata.FromIncomingContext(ctx) if !ok { - log.Error(). - Caller(). - Str("client_address", client.Addr.String()). - Msg("Retrieving metadata is failed") - return ctx, status.Errorf( codes.InvalidArgument, "Retrieving metadata is failed", @@ -336,11 +330,6 @@ func (h *Headscale) grpcAuthenticationInterceptor(ctx context.Context, authHeader, ok := meta["authorization"] if !ok { - log.Error(). - Caller(). - Str("client_address", client.Addr.String()). - Msg("Authorization token is not supplied") - return ctx, status.Errorf( codes.Unauthenticated, "Authorization token is not supplied", @@ -350,11 +339,6 @@ func (h *Headscale) grpcAuthenticationInterceptor(ctx context.Context, token := authHeader[0] if !strings.HasPrefix(token, AuthPrefix) { - log.Error(). - Caller(). - Str("client_address", client.Addr.String()). - Msg(`missing "Bearer " prefix in "Authorization" header`) - return ctx, status.Error( codes.Unauthenticated, `missing "Bearer " prefix in "Authorization" header`, @@ -363,12 +347,6 @@ func (h *Headscale) grpcAuthenticationInterceptor(ctx context.Context, valid, err := h.db.ValidateAPIKey(strings.TrimPrefix(token, AuthPrefix)) if err != nil { - log.Error(). - Caller(). - Err(err). - Str("client_address", client.Addr.String()). - Msg("failed to validate token") - return ctx, status.Error(codes.Internal, "failed to validate token") } diff --git a/hscontrol/db/node.go b/hscontrol/db/node.go index 61c952a0..4f8688c1 100644 --- a/hscontrol/db/node.go +++ b/hscontrol/db/node.go @@ -233,15 +233,7 @@ func RenameNode(tx *gorm.DB, newName, ) if err != nil { - log.Error(). - Caller(). - Str("func", "RenameNode"). - Uint64("nodeID", nodeID). - Str("newName", newName). - Err(err). - Msg("failed to rename node") - - return err + return fmt.Errorf("renaming node: %w", err) } if err := tx.Model(&types.Node{}).Where("id = ?", nodeID).Update("given_name", newName).Error; err != nil { @@ -451,13 +443,7 @@ func GetAdvertisedRoutes(tx *gorm.DB, node *types.Node) ([]netip.Prefix, error) Preload("Node"). Where("node_id = ? AND advertised = ?", node.ID, true).Find(&routes).Error if err != nil && !errors.Is(err, gorm.ErrRecordNotFound) { - log.Error(). - Caller(). - Err(err). - Str("node", node.Hostname). - Msg("Could not get advertised routes for node") - - return nil, err + return nil, fmt.Errorf("getting advertised routes for node(%d): %w", node.ID, err) } prefixes := []netip.Prefix{} @@ -483,13 +469,7 @@ func GetEnabledRoutes(tx *gorm.DB, node *types.Node) ([]netip.Prefix, error) { Where("node_id = ? AND advertised = ? AND enabled = ?", node.ID, true, true). Find(&routes).Error if err != nil && !errors.Is(err, gorm.ErrRecordNotFound) { - log.Error(). - Caller(). - Err(err). - Str("node", node.Hostname). - Msg("Could not get enabled routes for node") - - return nil, err + return nil, fmt.Errorf("getting enabled routes for node(%d): %w", node.ID, err) } prefixes := []netip.Prefix{} @@ -508,8 +488,6 @@ func IsRoutesEnabled(tx *gorm.DB, node *types.Node, routeStr string) bool { enabledRoutes, err := GetEnabledRoutes(tx, node) if err != nil { - log.Error().Err(err).Msg("Could not get enabled routes") - return false } @@ -681,8 +659,6 @@ func DeleteExpiredEphemeralNodes(tx *gorm.DB, ) ([]types.NodeID, []types.NodeID) { users, err := ListUsers(tx) if err != nil { - log.Error().Err(err).Msg("Error listing users") - return nil, nil } @@ -691,11 +667,6 @@ func DeleteExpiredEphemeralNodes(tx *gorm.DB, for _, user := range users { nodes, err := ListNodesByUser(tx, user.Name) if err != nil { - log.Error(). - Err(err). - Str("user", user.Name). - Msg("Error listing nodes in user") - return nil, nil } @@ -740,10 +711,6 @@ func ExpireExpiredNodes(tx *gorm.DB, nodes, err := ListNodes(tx) if err != nil { - log.Error(). - Err(err). - Msg("Error listing nodes to find expired nodes") - return time.Unix(0, 0), types.StateUpdate{}, false } for _, node := range nodes { diff --git a/hscontrol/db/routes.go b/hscontrol/db/routes.go index 9cc78af8..a94e1a88 100644 --- a/hscontrol/db/routes.go +++ b/hscontrol/db/routes.go @@ -417,12 +417,10 @@ func FailoverNodeRoutesIfNeccessary( return nil, nil } - log.Trace().Msgf("NODE ROUTES: %d", len(nodeRoutes)) changedNodes := make(set.Set[types.NodeID]) nodeRouteLoop: for _, nodeRoute := range nodeRoutes { - log.Trace().Msgf("NODE ROUTE: %d", nodeRoute.ID) routes, err := getRoutesByPrefix(tx, netip.Prefix(nodeRoute.Prefix)) if err != nil { return nil, fmt.Errorf("getting routes by prefix: %w", err) diff --git a/hscontrol/db/users.go b/hscontrol/db/users.go index 99e93393..1cf8e92f 100644 --- a/hscontrol/db/users.go +++ b/hscontrol/db/users.go @@ -2,10 +2,10 @@ package db import ( "errors" + "fmt" "github.com/juanfont/headscale/hscontrol/types" "github.com/juanfont/headscale/hscontrol/util" - "github.com/rs/zerolog/log" "gorm.io/gorm" ) @@ -34,12 +34,7 @@ func CreateUser(tx *gorm.DB, name string) (*types.User, error) { } user.Name = name if err := tx.Create(&user).Error; err != nil { - log.Error(). - Str("func", "CreateUser"). - Err(err). - Msg("Could not create row") - - return nil, err + return nil, fmt.Errorf("creating user: %w", err) } return &user, nil diff --git a/hscontrol/mapper/mapper.go b/hscontrol/mapper/mapper.go index 3a92cae6..93ab1f71 100644 --- a/hscontrol/mapper/mapper.go +++ b/hscontrol/mapper/mapper.go @@ -372,10 +372,7 @@ func (m *Mapper) marshalMapResponse( jsonBody, err := json.Marshal(resp) if err != nil { - log.Error(). - Caller(). - Err(err). - Msg("Cannot marshal map response") + return nil, fmt.Errorf("marshalling map response: %w", err) } if debugDumpMapResponsePath != "" { @@ -402,10 +399,7 @@ func (m *Mapper) marshalMapResponse( body, err := json.MarshalIndent(data, "", " ") if err != nil { - log.Error(). - Caller(). - Err(err). - Msg("Cannot marshal map response") + return nil, fmt.Errorf("marshalling map response: %w", err) } perms := fs.FileMode(debugMapResponsePerm) diff --git a/hscontrol/oidc.go b/hscontrol/oidc.go index d669a922..2ac1b56c 100644 --- a/hscontrol/oidc.go +++ b/hscontrol/oidc.go @@ -58,12 +58,7 @@ func (h *Headscale) initOIDC() error { h.oidcProvider, err = oidc.NewProvider(context.Background(), h.cfg.OIDC.Issuer) if err != nil { - log.Error(). - Err(err). - Caller(). - Msgf("Could not retrieve OIDC Config: %s", err.Error()) - - return err + return fmt.Errorf("creating OIDC provider from issuer config: %w", err) } h.oauth2Config = &oauth2.Config{ @@ -514,12 +509,6 @@ func (h *Headscale) validateNodeForOIDCCallback( User: claims.Email, Verb: "Reauthenticated", }); err != nil { - log.Error(). - Str("func", "OIDCCallback"). - Str("type", "reauthenticate"). - Err(err). - Msg("Could not render OIDC callback template") - writer.Header().Set("Content-Type", "text/plain; charset=utf-8") writer.WriteHeader(http.StatusInternalServerError) _, werr := writer.Write([]byte("Could not render OIDC callback template")) @@ -527,7 +516,7 @@ func (h *Headscale) validateNodeForOIDCCallback( util.LogErr(err, "Failed to write response") } - return nil, true, err + return nil, true, fmt.Errorf("rendering OIDC callback template: %w", err) } writer.Header().Set("Content-Type", "text/html; charset=utf-8") @@ -579,10 +568,6 @@ func (h *Headscale) findOrCreateNewUserForOIDCCallback( if errors.Is(err, db.ErrUserNotFound) { user, err = h.db.CreateUser(userName) if err != nil { - log.Error(). - Err(err). - Caller(). - Msgf("could not create new user '%s'", userName) writer.Header().Set("Content-Type", "text/plain; charset=utf-8") writer.WriteHeader(http.StatusInternalServerError) _, werr := writer.Write([]byte("could not create user")) @@ -590,14 +575,9 @@ func (h *Headscale) findOrCreateNewUserForOIDCCallback( util.LogErr(err, "Failed to write response") } - return nil, err + return nil, fmt.Errorf("creating new user: %w", err) } } else if err != nil { - log.Error(). - Caller(). - Err(err). - Str("user", userName). - Msg("could not find or create user") writer.Header().Set("Content-Type", "text/plain; charset=utf-8") writer.WriteHeader(http.StatusInternalServerError) _, werr := writer.Write([]byte("could not find or create user")) @@ -605,7 +585,7 @@ func (h *Headscale) findOrCreateNewUserForOIDCCallback( util.LogErr(err, "Failed to write response") } - return nil, err + return nil, fmt.Errorf("find or create user: %w", err) } return user, nil @@ -661,12 +641,6 @@ func renderOIDCCallbackTemplate( User: claims.Email, Verb: "Authenticated", }); err != nil { - log.Error(). - Str("func", "OIDCCallback"). - Str("type", "authenticate"). - Err(err). - Msg("Could not render OIDC callback template") - writer.Header().Set("Content-Type", "text/plain; charset=utf-8") writer.WriteHeader(http.StatusInternalServerError) _, werr := writer.Write([]byte("Could not render OIDC callback template")) @@ -674,7 +648,7 @@ func renderOIDCCallbackTemplate( util.LogErr(err, "Failed to write response") } - return nil, err + return nil, fmt.Errorf("rendering OIDC callback template: %w", err) } return &content, nil diff --git a/hscontrol/policy/acls.go b/hscontrol/policy/acls.go index b4095781..a4eee01e 100644 --- a/hscontrol/policy/acls.go +++ b/hscontrol/policy/acls.go @@ -159,23 +159,14 @@ func (pol *ACLPolicy) CompileFilterRules( for srcIndex, src := range acl.Sources { srcs, err := pol.expandSource(src, nodes) if err != nil { - log.Error(). - Interface("src", src). - Int("ACL index", index). - Int("Src index", srcIndex). - Msgf("Error parsing ACL") - - return nil, err + return nil, fmt.Errorf("parsing policy, acl index: %d->%d: %w", index, srcIndex, err) } srcIPs = append(srcIPs, srcs...) } protocols, isWildcard, err := parseProtocol(acl.Protocol) if err != nil { - log.Error(). - Msgf("Error parsing ACL %d. protocol unknown %s", index, acl.Protocol) - - return nil, err + return nil, fmt.Errorf("parsing policy, protocol err: %w ", err) } destPorts := []tailcfg.NetPortRange{} @@ -326,16 +317,12 @@ func (pol *ACLPolicy) CompileSSHPolicy( case "check": checkAction, err := sshCheckAction(sshACL.CheckPeriod) if err != nil { - log.Error(). - Msgf("Error parsing SSH %d, check action with unparsable duration '%s'", index, sshACL.CheckPeriod) + return nil, fmt.Errorf("parsing SSH policy, parsing check duration, index: %d: %w", index, err) } else { action = *checkAction } default: - log.Error(). - Msgf("Error parsing SSH %d, unknown action '%s', skipping", index, sshACL.Action) - - continue + return nil, fmt.Errorf("parsing SSH policy, unknown action %q, index: %d: %w", sshACL.Action, index, err) } principals := make([]*tailcfg.SSHPrincipal, 0, len(sshACL.Sources)) @@ -347,10 +334,7 @@ func (pol *ACLPolicy) CompileSSHPolicy( } else if isGroup(rawSrc) { users, err := pol.expandUsersFromGroup(rawSrc) if err != nil { - log.Error(). - Msgf("Error parsing SSH %d, Source %d", index, innerIndex) - - return nil, err + return nil, fmt.Errorf("parsing SSH policy, expanding user from group, index: %d->%d: %w", index, innerIndex, err) } for _, user := range users { @@ -364,10 +348,7 @@ func (pol *ACLPolicy) CompileSSHPolicy( rawSrc, ) if err != nil { - log.Error(). - Msgf("Error parsing SSH %d, Source %d", index, innerIndex) - - return nil, err + return nil, fmt.Errorf("parsing SSH policy, expanding alias, index: %d->%d: %w", index, innerIndex, err) } for _, expandedSrc := range expandedSrcs.Prefixes() { principals = append(principals, &tailcfg.SSHPrincipal{ @@ -499,7 +480,7 @@ func parseProtocol(protocol string) ([]int, bool, error) { default: protocolNumber, err := strconv.Atoi(protocol) if err != nil { - return nil, false, err + return nil, false, fmt.Errorf("parsing protocol number: %w", err) } needsWildcard := protocolNumber != protocolTCP && protocolNumber != protocolUDP && diff --git a/hscontrol/poll.go b/hscontrol/poll.go index 7b554f30..c38c65e2 100644 --- a/hscontrol/poll.go +++ b/hscontrol/poll.go @@ -16,7 +16,6 @@ import ( "github.com/juanfont/headscale/hscontrol/mapper" "github.com/juanfont/headscale/hscontrol/types" "github.com/rs/zerolog/log" - "github.com/sasha-s/go-deadlock" xslices "golang.org/x/exp/slices" "gorm.io/gorm" "tailscale.com/tailcfg" @@ -43,7 +42,7 @@ type mapSession struct { mapper *mapper.Mapper serving bool - servingMu deadlock.Mutex + servingMu sync.Mutex ch chan types.StateUpdate cancelCh chan struct{}