clean up handler methods, common logging

hscontrol/handlers.go

@@ -32,6 +32,12 @@ const (
 	reservedResponseHeaderSize = 4
 )
 
+// httpError logs an error and sends an HTTP error response with the given
+func httpError(w http.ResponseWriter, err error, userError string, code int) {
+	log.Error().Err(err).Msg(userError)
+	http.Error(w, userError, code)
+}
+
 var ErrRegisterMethodCLIDoesNotSupportExpire = errors.New(
 	"machines registered with CLI does not support expire",
 )
@@ -52,7 +58,7 @@ func parseCabailityVersion(req *http.Request) (tailcfg.CapabilityVersion, error)
 	return tailcfg.CapabilityVersion(clientCapabilityVersion), nil
 }
 
-func (h *Headscale) handleVerifyRequest(
+func (h *Headscale) derpRequestIsAllowed(
 	req *http.Request,
 ) (bool, error) {
 	body, err := io.ReadAll(req.Body)
@@ -79,36 +85,22 @@ func (h *Headscale) VerifyHandler(
 	req *http.Request,
 ) {
 	if req.Method != http.MethodPost {
-		http.Error(writer, "Wrong method", http.StatusMethodNotAllowed)
-
+		httpError(writer, nil, "Wrong method", http.StatusMethodNotAllowed)
 		return
 	}
-	log.Debug().
-		Str("handler", "/verify").
-		Msg("verify client")
 
-	allow, err := h.handleVerifyRequest(req)
+	allow, err := h.derpRequestIsAllowed(req)
 	if err != nil {
-		log.Error().
-			Caller().
-			Err(err).
-			Msg("Failed to verify client")
-		http.Error(writer, "Internal error", http.StatusInternalServerError)
+		httpError(writer, err, "Internal error", http.StatusInternalServerError)
+		return
 	}
 
 	resp := tailcfg.DERPAdmitClientResponse{
 		Allow: allow,
 	}
 
 	writer.Header().Set("Content-Type", "application/json")
-	writer.WriteHeader(http.StatusOK)
-	err = json.NewEncoder(writer).Encode(resp)
-	if err != nil {
-		log.Error().
-			Caller().
-			Err(err).
-			Msg("Failed to write response")
-	}
+	json.NewEncoder(writer).Encode(resp)
 }
 
 // KeyHandler provides the Headscale pub key
@@ -120,35 +112,17 @@ func (h *Headscale) KeyHandler(
 	// New Tailscale clients send a 'v' parameter to indicate the CurrentCapabilityVersion
 	capVer, err := parseCabailityVersion(req)
 	if err != nil {
-		log.Error().
-			Caller().
-			Err(err).
-			Msg("could not get capability version")
-		writer.Header().Set("Content-Type", "text/plain; charset=utf-8")
-		writer.WriteHeader(http.StatusInternalServerError)
-
+		httpError(writer, err, "Internal error", http.StatusInternalServerError)
 		return
 	}
 
-	log.Debug().
-		Str("handler", "/key").
-		Int("cap_ver", int(capVer)).
-		Msg("New noise client")
-
 	// TS2021 (Tailscale v2 protocol) requires to have a different key
 	if capVer >= NoiseCapabilityVersion {
 		resp := tailcfg.OverTLSPublicKeyResponse{
 			PublicKey: h.noisePrivateKey.Public(),
 		}
 		writer.Header().Set("Content-Type", "application/json")
-		writer.WriteHeader(http.StatusOK)
-		err = json.NewEncoder(writer).Encode(resp)
-		if err != nil {
-			log.Error().
-				Caller().
-				Err(err).
-				Msg("Failed to write response")
-		}
+		json.NewEncoder(writer).Encode(resp)
 
 		return
 	}
@@ -169,18 +143,10 @@ func (h *Headscale) HealthHandler(
 
 		if err != nil {
 			writer.WriteHeader(http.StatusInternalServerError)
-			log.Error().Caller().Err(err).Msg("health check failed")
 			res.Status = "fail"
 		}
 
-		buf, err := json.Marshal(res)
-		if err != nil {
-			log.Error().Caller().Err(err).Msg("marshal failed")
-		}
-		_, err = writer.Write(buf)
-		if err != nil {
-			log.Error().Caller().Err(err).Msg("write failed")
-		}
+		json.NewEncoder(writer).Encode(res)
 	}
 
 	if err := h.db.PingDB(req.Context()); err != nil {
@@ -233,16 +199,11 @@ func (a *AuthProviderWeb) RegisterHandler(
 	// the template and log an error.
 	registrationId, err := types.RegistrationIDFromString(registrationIdStr)
 	if err != nil {
-		http.Error(writer, "invalid registration ID", http.StatusBadRequest)
+		httpError(writer, err, "invalid registration ID", http.StatusBadRequest)
 		return
 	}
 
 	writer.Header().Set("Content-Type", "text/html; charset=utf-8")
 	writer.WriteHeader(http.StatusOK)
-	if _, err := writer.Write([]byte(templates.RegisterWeb(registrationId).Render())); err != nil {
-		log.Error().
-			Caller().
-			Err(err).
-			Msg("Failed to write response")
-	}
+	writer.Write([]byte(templates.RegisterWeb(registrationId).Render()))
 }

hscontrol/noise.go

@@ -80,9 +80,7 @@ func (h *Headscale) NoiseUpgradeHandler(
 		noiseServer.earlyNoise,
 	)
 	if err != nil {
-		log.Error().Err(err).Msg("noise upgrade failed")
-		http.Error(writer, err.Error(), http.StatusInternalServerError)
-
+		httpError(writer, err, "noise upgrade failed", http.StatusInternalServerError)
 		return
 	}
 
@@ -160,12 +158,7 @@ func isSupportedVersion(version tailcfg.CapabilityVersion) bool {
 func rejectUnsupported(writer http.ResponseWriter, version tailcfg.CapabilityVersion) bool {
 	// Reject unsupported versions
 	if !isSupportedVersion(version) {
-		log.Info().
-			Caller().
-			Int("min_version", int(MinimumCapVersion)).
-			Int("client_version", int(version)).
-			Msg("unsupported client connected")
-		http.Error(writer, "unsupported client version", http.StatusBadRequest)
+		httpError(writer, nil, "unsupported client version", http.StatusBadRequest)
 
 		return true
 	}
@@ -190,23 +183,10 @@ func (ns *noiseServer) NoisePollNetMapHandler(
 
 	var mapRequest tailcfg.MapRequest
 	if err := json.Unmarshal(body, &mapRequest); err != nil {
-		log.Error().
-			Caller().
-			Err(err).
-			Msg("Cannot parse MapRequest")
-		http.Error(writer, "Internal error", http.StatusInternalServerError)
-
+		httpError(writer, err, "Internal error", http.StatusInternalServerError)
 		return
 	}
 
-	log.Trace().
-		Caller().
-		Str("handler", "NoisePollNetMap").
-		Any("headers", req.Header).
-		Str("node", mapRequest.Hostinfo.Hostname).
-		Int("capver", int(mapRequest.Version)).
-		Msg("PollNetMapHandler called")
-
 	// Reject unsupported versions
 	if rejectUnsupported(writer, mapRequest.Version) {
 		return
@@ -220,11 +200,7 @@ func (ns *noiseServer) NoisePollNetMapHandler(
 		key.NodePublic{},
 	)
 	if err != nil {
-		log.Error().
-			Str("handler", "NoisePollNetMap").
-			Msgf("Failed to fetch node from the database with node key: %s", mapRequest.NodeKey.String())
-		http.Error(writer, "Internal error", http.StatusInternalServerError)
-
+		httpError(writer, err, "Internal error", http.StatusInternalServerError)
 		return
 	}
 
@@ -242,26 +218,16 @@ func (ns *noiseServer) NoiseRegistrationHandler(
 	writer http.ResponseWriter,
 	req *http.Request,
 ) {
-	log.Trace().Caller().Msgf("Noise registration handler for client %s", req.RemoteAddr)
 	if req.Method != http.MethodPost {
-		http.Error(writer, "Wrong method", http.StatusMethodNotAllowed)
+		httpError(writer, nil, "Wrong method", http.StatusMethodNotAllowed)
 
 		return
 	}
 
-	log.Trace().
-		Any("headers", req.Header).
-		Caller().
-		Msg("Headers")
-
 	body, _ := io.ReadAll(req.Body)
 	var registerRequest tailcfg.RegisterRequest
 	if err := json.Unmarshal(body, &registerRequest); err != nil {
-		log.Error().
-			Caller().
-			Err(err).
-			Msg("Cannot parse RegisterRequest")
-		http.Error(writer, "Internal error", http.StatusInternalServerError)
+		httpError(writer, err, "Internal error", http.StatusInternalServerError)
 
 		return
 	}

hscontrol/oidc.go

@@ -134,34 +134,28 @@ func (a *AuthProviderOIDC) RegisterHandler(
 	req *http.Request,
 ) {
 	vars := mux.Vars(req)
-	registrationIdStr, ok := vars["registration_id"]
+	registrationIdStr, _ := vars["registration_id"]
 
 	// We need to make sure we dont open for XSS style injections, if the parameter that
 	// is passed as a key is not parsable/validated as a NodePublic key, then fail to render
 	// the template and log an error.
 	registrationId, err := types.RegistrationIDFromString(registrationIdStr)
 	if err != nil {
-		http.Error(writer, "invalid registration ID", http.StatusBadRequest)
+		httpError(writer, err, "invalid registration ID", http.StatusBadRequest)
 		return
 	}
 
-	log.Debug().
-		Caller().
-		Str("registration_id", registrationId.String()).
-		Bool("ok", ok).
-		Msg("Received oidc register call")
-
 	// Set the state and nonce cookies to protect against CSRF attacks
 	state, err := setCSRFCookie(writer, req, "state")
 	if err != nil {
-		http.Error(writer, "Internal server error", http.StatusInternalServerError)
+		httpError(writer, err, "Internal server error", http.StatusInternalServerError)
 		return
 	}
 
 	// Set the state and nonce cookies to protect against CSRF attacks
 	nonce, err := setCSRFCookie(writer, req, "nonce")
 	if err != nil {
-		http.Error(writer, "Internal server error", http.StatusInternalServerError)
+		httpError(writer, err, "Internal server error", http.StatusInternalServerError)
 		return
 	}
 
@@ -225,64 +219,64 @@ func (a *AuthProviderOIDC) OIDCCallbackHandler(
 ) {
 	code, state, err := extractCodeAndStateParamFromRequest(req)
 	if err != nil {
-		http.Error(writer, err.Error(), http.StatusBadRequest)
+		httpError(writer, err, err.Error(), http.StatusBadRequest)
 		return
 	}
 
-	log.Debug().Interface("cookies", req.Cookies()).Msg("Received oidc callback")
 	cookieState, err := req.Cookie("state")
 	if err != nil {
-		http.Error(writer, "state not found", http.StatusBadRequest)
+		httpError(writer, err, "state not found", http.StatusBadRequest)
 		return
 	}
 
 	if state != cookieState.Value {
-		http.Error(writer, "state did not match", http.StatusBadRequest)
+		httpError(writer, err, "state did not match", http.StatusBadRequest)
 		return
 	}
 
 	idToken, err := a.extractIDToken(req.Context(), code, state)
 	if err != nil {
-		http.Error(writer, err.Error(), http.StatusBadRequest)
+		httpError(writer, err, err.Error(), http.StatusBadRequest)
 		return
 	}
 
 	nonce, err := req.Cookie("nonce")
 	if err != nil {
-		http.Error(writer, "nonce not found", http.StatusBadRequest)
+		httpError(writer, err, "nonce not found", http.StatusBadRequest)
 		return
 	}
 	if idToken.Nonce != nonce.Value {
-		http.Error(writer, "nonce did not match", http.StatusBadRequest)
+		httpError(writer, err, "nonce did not match", http.StatusBadRequest)
 		return
 	}
 
 	nodeExpiry := a.determineNodeExpiry(idToken.Expiry)
 
 	var claims types.OIDCClaims
 	if err := idToken.Claims(&claims); err != nil {
-		http.Error(writer, fmt.Errorf("failed to decode ID token claims: %w", err).Error(), http.StatusInternalServerError)
+		err = fmt.Errorf("decoding ID token claims: %w", err)
+		httpError(writer, err, err.Error(), http.StatusInternalServerError)
 		return
 	}
 
 	if err := validateOIDCAllowedDomains(a.cfg.AllowedDomains, &claims); err != nil {
-		http.Error(writer, err.Error(), http.StatusUnauthorized)
+		httpError(writer, err, err.Error(), http.StatusUnauthorized)
 		return
 	}
 
 	if err := validateOIDCAllowedGroups(a.cfg.AllowedGroups, &claims); err != nil {
-		http.Error(writer, err.Error(), http.StatusUnauthorized)
+		httpError(writer, err, err.Error(), http.StatusUnauthorized)
 		return
 	}
 
 	if err := validateOIDCAllowedUsers(a.cfg.AllowedUsers, &claims); err != nil {
-		http.Error(writer, err.Error(), http.StatusUnauthorized)
+		httpError(writer, err, err.Error(), http.StatusUnauthorized)
 		return
 	}
 
 	user, err := a.createOrUpdateUserFromClaim(&claims)
 	if err != nil {
-		http.Error(writer, err.Error(), http.StatusInternalServerError)
+		httpError(writer, err, err.Error(), http.StatusInternalServerError)
 		return
 	}
 
@@ -297,7 +291,7 @@ func (a *AuthProviderOIDC) OIDCCallbackHandler(
 		verb := "Reauthenticated"
 		newNode, err := a.handleRegistrationID(user, *registrationId, nodeExpiry)
 		if err != nil {
-			http.Error(writer, err.Error(), http.StatusInternalServerError)
+			httpError(writer, err, err.Error(), http.StatusInternalServerError)
 			return
 		}
 
@@ -308,7 +302,7 @@ func (a *AuthProviderOIDC) OIDCCallbackHandler(
 		// TODO(kradalby): replace with go-elem
 		content, err := renderOIDCCallbackTemplate(user, verb)
 		if err != nil {
-			http.Error(writer, err.Error(), http.StatusInternalServerError)
+			httpError(writer, err, err.Error(), http.StatusInternalServerError)
 			return
 		}
 
@@ -323,7 +317,7 @@ func (a *AuthProviderOIDC) OIDCCallbackHandler(
 
 	// Neither node nor machine key was found in the state cache meaning
 	// that we could not reauth nor register the node.
-	http.Error(writer, "login session expired, try again", http.StatusInternalServerError)
+	httpError(writer, nil, "login session expired, try again", http.StatusInternalServerError)
 	return
 }
 
@@ -423,7 +417,6 @@ func validateOIDCAllowedUsers(
 ) error {
 	if len(allowedUsers) > 0 &&
 		!slices.Contains(allowedUsers, claims.Email) {
-		log.Trace().Msg("authenticated principal does not match any allowed user")
 		return errOIDCAllowedUsers
 	}