more log.Error -> fmt.Errorf cleanup

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

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=

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() {
+// func init() {
-	deadlock.Opts.DeadlockTimeout = 15 * time.Second
+// 	deadlock.Opts.DeadlockTimeout = 15 * time.Second
-	deadlock.Opts.PrintAllCurrentGoroutines = true
+// 	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")
 	}
 

hscontrol/db/node.go

@@ -233,15 +233,7 @@ func RenameNode(tx *gorm.DB,
 		newName,
 	)
 	if err != nil {
-		log.Error().
+		return fmt.Errorf("renaming node: %w", err)
-			Caller().
-			Str("func", "RenameNode").
-			Uint64("nodeID", nodeID).
-			Str("newName", newName).
-			Err(err).
-			Msg("failed to rename node")
-
-		return 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().
+		return nil, fmt.Errorf("getting advertised routes for node(%d): %w", node.ID, err)
-			Caller().
-			Err(err).
-			Str("node", node.Hostname).
-			Msg("Could not get advertised routes for node")
-
-		return nil, 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().
+		return nil, fmt.Errorf("getting enabled routes for node(%d): %w", node.ID, err)
-			Caller().
-			Err(err).
-			Str("node", node.Hostname).
-			Msg("Could not get enabled routes for node")
-
-		return nil, 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 {

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)

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().
+		return nil, fmt.Errorf("creating user: %w", err)
-			Str("func", "CreateUser").
-			Err(err).
-			Msg("Could not create row")
-
-		return nil, err
 	}
 
 	return &user, nil

hscontrol/mapper/mapper.go

@@ -372,10 +372,7 @@ func (m *Mapper) marshalMapResponse(
 
 	jsonBody, err := json.Marshal(resp)
 	if err != nil {
-		log.Error().
+		return nil, fmt.Errorf("marshalling map response: %w", err)
-			Caller().
-			Err(err).
-			Msg("Cannot marshal map response")
 	}
 
 	if debugDumpMapResponsePath != "" {
@@ -402,10 +399,7 @@ func (m *Mapper) marshalMapResponse(
 
 		body, err := json.MarshalIndent(data, "", "  ")
 		if err != nil {
-			log.Error().
+			return nil, fmt.Errorf("marshalling map response: %w", err)
-				Caller().
-				Err(err).
-				Msg("Cannot marshal map response")
 		}
 
 		perms := fs.FileMode(debugMapResponsePerm)

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().
+			return fmt.Errorf("creating OIDC provider from issuer config: %w", err)
-				Err(err).
-				Caller().
-				Msgf("Could not retrieve OIDC Config: %s", err.Error())
-
-			return 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

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().
+				return nil, fmt.Errorf("parsing policy, acl index: %d->%d: %w", index, srcIndex, err)
-					Interface("src", src).
-					Int("ACL index", index).
-					Int("Src index", srcIndex).
-					Msgf("Error parsing ACL")
-
-				return nil, err
 			}
 			srcIPs = append(srcIPs, srcs...)
 		}
 
 		protocols, isWildcard, err := parseProtocol(acl.Protocol)
 		if err != nil {
-			log.Error().
+			return nil, fmt.Errorf("parsing policy, protocol err: %w ", err)
-				Msgf("Error parsing ACL %d. protocol unknown %s", index, acl.Protocol)
-
-			return nil, err
 		}
 
 		destPorts := []tailcfg.NetPortRange{}
@@ -326,16 +317,12 @@ func (pol *ACLPolicy) CompileSSHPolicy(
 		case "check":
 			checkAction, err := sshCheckAction(sshACL.CheckPeriod)
 			if err != nil {
-				log.Error().
+				return nil, fmt.Errorf("parsing SSH policy, parsing check duration, index: %d: %w", index, err)
-					Msgf("Error parsing SSH %d, check action with unparsable duration '%s'", index, sshACL.CheckPeriod)
 			} else {
 				action = *checkAction
 			}
 		default:
-			log.Error().
+			return nil, fmt.Errorf("parsing SSH policy, unknown action %q, index: %d: %w", sshACL.Action, index, err)
-				Msgf("Error parsing SSH %d, unknown action '%s', skipping", index, sshACL.Action)
-
-			continue
 		}
 
 		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().
+					return nil, fmt.Errorf("parsing SSH policy, expanding user from group, index: %d->%d: %w", index, innerIndex, err)
-						Msgf("Error parsing SSH %d, Source %d", index, innerIndex)
-
-					return nil, err
 				}
 
 				for _, user := range users {
@@ -364,10 +348,7 @@ func (pol *ACLPolicy) CompileSSHPolicy(
 					rawSrc,
 				)
 				if err != nil {
-					log.Error().
+					return nil, fmt.Errorf("parsing SSH policy, expanding alias, index: %d->%d: %w", index, innerIndex, err)
-						Msgf("Error parsing SSH %d, Source %d", index, innerIndex)
-
-					return nil, 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 &&

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{}