feat: add debug log level

cmd/root.go

@@ -11,6 +11,7 @@ import (
 	"tinyauth/internal/utils"
 
 	"github.com/go-playground/validator/v10"
+	"github.com/rs/zerolog"
 	"github.com/rs/zerolog/log"
 	"github.com/spf13/cobra"
 	"github.com/spf13/viper"
@@ -33,6 +34,10 @@ var rootCmd = &cobra.Command{
 		validateErr := validator.Struct(config)
 		HandleError(validateErr, "Invalid config")
 
+		// Set log level
+		log.Info().Int8("log_level", config.LogLevel).Msg("Setting log level")
+		log.Logger = log.Logger.Level(zerolog.Level(config.LogLevel))
+
 		// Users
 		log.Info().Msg("Parsing users")
 		users, usersErr := utils.GetUsers(config.Users, config.UsersFile)
@@ -47,6 +52,7 @@ var rootCmd = &cobra.Command{
 
 		// Create oauth whitelist
 		oauthWhitelist := strings.Split(config.OAuthWhitelist, ",")
+		log.Debug().Strs("oauth_whitelist", oauthWhitelist).Msg("Parsed OAuth whitelist")
 
 		// Create OAuth config
 		oauthConfig := types.OAuthConfig{
@@ -62,6 +68,7 @@ var rootCmd = &cobra.Command{
 			GenericUserURL:      config.GenericUserURL,
 			AppURL:              config.AppURL,
 		}
+		log.Debug().Interface("oauth_config", oauthConfig).Msg("Parsed OAuth config")
 
 		// Create auth service
 		auth := auth.NewAuth(users, oauthWhitelist)
@@ -134,6 +141,7 @@ func init() {
 	rootCmd.Flags().Bool("disable-continue", false, "Disable continue screen and redirect to app directly.")
 	rootCmd.Flags().String("oauth-whitelist", "", "Comma separated list of email addresses to whitelist when using OAuth.")
 	rootCmd.Flags().Int("cookie-expiry", 86400, "Cookie expiration time in seconds.")
+	rootCmd.Flags().Int("log-level", 1, "Log level.")
 	viper.BindEnv("port", "PORT")
 	viper.BindEnv("address", "ADDRESS")
 	viper.BindEnv("secret", "SECRET")
@@ -157,5 +165,6 @@ func init() {
 	viper.BindEnv("disable-continue", "DISABLE_CONTINUE")
 	viper.BindEnv("oauth-whitelist", "OAUTH_WHITELIST")
 	viper.BindEnv("cookie-expiry", "COOKIE_EXPIRY")
+	viper.BindEnv("log-level", "LOG_LEVEL")
 	viper.BindPFlags(rootCmd.Flags())
 }

internal/api/api.go

@@ -42,17 +42,22 @@ type API struct {
 func (api *API) Init() {
 	gin.SetMode(gin.ReleaseMode)
 
+	log.Debug().Msg("Setting up router")
 	router := gin.New()
 	router.Use(zerolog())
+	log.Debug().Msg("Setting up assets")
 	dist, distErr := fs.Sub(assets.Assets, "dist")
 
 	if distErr != nil {
 		log.Fatal().Err(distErr).Msg("Failed to get UI assets")
 	}
 
+	log.Debug().Msg("Setting up file server")
 	fileServer := http.FileServer(http.FS(dist))
+	log.Debug().Msg("Setting up cookie store")
 	store := cookie.NewStore([]byte(api.Config.Secret))
 
+	log.Debug().Msg("Getting domain")
 	domain, domainErr := utils.GetRootURL(api.Config.AppURL)
 
 	if domainErr != nil {
@@ -90,9 +95,11 @@ func (api *API) Init() {
 
 func (api *API) SetupRoutes() {
 	api.Router.GET("/api/auth", func(c *gin.Context) {
+		log.Debug().Msg("Checking auth")
 		userContext := api.Hooks.UseUserContext(c)
 
 		if userContext.IsLoggedIn {
+			log.Debug().Msg("Authenticated")
 			c.JSON(200, gin.H{
 				"status":  200,
 				"message": "Authenticated",
@@ -107,6 +114,8 @@ func (api *API) SetupRoutes() {
 			RedirectURI: fmt.Sprintf("%s://%s%s", proto, host, uri),
 		})
 
+		log.Debug().Interface("queries", queries).Msg("Redirecting to login")
+
 		if queryErr != nil {
 			log.Error().Err(queryErr).Msg("Failed to build query")
 			c.JSON(501, gin.H{
@@ -133,9 +142,12 @@ func (api *API) SetupRoutes() {
 			return
 		}
 
+		log.Debug().Interface("login", login).Msg("Got login request")
+
 		user := api.Auth.GetUser(login.Username)
 
 		if user == nil {
+			log.Debug().Str("username", login.Username).Msg("User not found")
 			c.JSON(401, gin.H{
 				"status":  401,
 				"message": "Unauthorized",
@@ -144,6 +156,7 @@ func (api *API) SetupRoutes() {
 		}
 
 		if !api.Auth.CheckPassword(*user, login.Password) {
+			log.Debug().Str("username", login.Username).Msg("Password incorrect")
 			c.JSON(401, gin.H{
 				"status":  401,
 				"message": "Unauthorized",
@@ -151,6 +164,8 @@ func (api *API) SetupRoutes() {
 			return
 		}
 
+		log.Debug().Msg("Password correct, logging in")
+
 		api.Auth.CreateSessionCookie(c, &types.SessionCookie{
 			Username: login.Username,
 			Provider: "username",
@@ -165,6 +180,8 @@ func (api *API) SetupRoutes() {
 	api.Router.POST("/api/logout", func(c *gin.Context) {
 		api.Auth.DeleteSessionCookie(c)
 
+		log.Debug().Msg("Cleaning up redirect cookie")
+
 		c.SetCookie("tinyauth_redirect_uri", "", -1, "/", api.Domain, api.Config.CookieSecure, true)
 
 		c.JSON(200, gin.H{
@@ -174,9 +191,11 @@ func (api *API) SetupRoutes() {
 	})
 
 	api.Router.GET("/api/status", func(c *gin.Context) {
+		log.Debug().Msg("Checking status")
 		userContext := api.Hooks.UseUserContext(c)
 
 		if !userContext.IsLoggedIn {
+			log.Debug().Msg("Unauthenticated")
 			c.JSON(200, gin.H{
 				"status":              200,
 				"message":             "Unauthenticated",
@@ -190,6 +209,8 @@ func (api *API) SetupRoutes() {
 			return
 		}
 
+		log.Debug().Interface("userContext", userContext).Strs("configuredProviders", api.Providers.GetConfiguredProviders()).Bool("disableContinue", api.Config.DisableContinue).Msg("Authenticated")
+
 		c.JSON(200, gin.H{
 			"status":              200,
 			"message":             "Authenticated",
@@ -223,6 +244,8 @@ func (api *API) SetupRoutes() {
 			return
 		}
 
+		log.Debug().Interface("request", request).Msg("Got OAuth request")
+
 		provider := api.Providers.GetProvider(request.Provider)
 
 		if provider == nil {
@@ -233,11 +256,16 @@ func (api *API) SetupRoutes() {
 			return
 		}
 
+		log.Debug().Str("provider", request.Provider).Msg("Got provider")
+
 		authURL := provider.GetAuthURL()
 
+		log.Debug().Str("authURL", authURL).Msg("Got auth URL")
+
 		redirectURI := c.Query("redirect_uri")
 
 		if redirectURI != "" {
+			log.Debug().Str("redirectURI", redirectURI).Msg("Setting redirect cookie")
 			c.SetCookie("tinyauth_redirect_uri", redirectURI, 3600, "/", api.Domain, api.Config.CookieSecure, true)
 		}
 
@@ -257,6 +285,8 @@ func (api *API) SetupRoutes() {
 			return
 		}
 
+		log.Debug().Interface("providerName", providerName).Msg("Got provider name")
+
 		code := c.Query("code")
 
 		if code == "" {
@@ -265,14 +295,20 @@ func (api *API) SetupRoutes() {
 			return
 		}
 
+		log.Debug().Str("code", code).Msg("Got code")
+
 		provider := api.Providers.GetProvider(providerName.Provider)
 
+		log.Debug().Str("provider", providerName.Provider).Msg("Got provider")
+
 		if provider == nil {
 			c.Redirect(http.StatusPermanentRedirect, "/not-found")
 			return
 		}
 
-		_, tokenErr := provider.ExchangeToken(code)
+		token, tokenErr := provider.ExchangeToken(code)
+
+		log.Debug().Str("token", token).Msg("Got token")
 
 		if handleApiError(c, "Failed to exchange token", tokenErr) {
 			return
@@ -280,6 +316,8 @@ func (api *API) SetupRoutes() {
 
 		email, emailErr := api.Providers.GetUser(providerName.Provider)
 
+		log.Debug().Str("email", email).Msg("Got email")
+
 		if handleApiError(c, "Failed to get user", emailErr) {
 			return
 		}
@@ -295,6 +333,8 @@ func (api *API) SetupRoutes() {
 			c.Redirect(http.StatusPermanentRedirect, fmt.Sprintf("%s/unauthorized?%s", api.Config.AppURL, unauthorizedQuery.Encode()))
 		}
 
+		log.Debug().Msg("Email whitelisted")
+
 		api.Auth.CreateSessionCookie(c, &types.SessionCookie{
 			Username: email,
 			Provider: providerName.Provider,
@@ -309,12 +349,16 @@ func (api *API) SetupRoutes() {
 			})
 		}
 
+		log.Debug().Str("redirectURI", redirectURI).Msg("Got redirect URI")
+
 		c.SetCookie("tinyauth_redirect_uri", "", -1, "/", api.Domain, api.Config.CookieSecure, true)
 
 		redirectQuery, redirectQueryErr := query.Values(types.LoginQuery{
 			RedirectURI: redirectURI,
 		})
 
+		log.Debug().Interface("redirectQuery", redirectQuery).Msg("Got redirect query")
+
 		if handleApiError(c, "Failed to build query", redirectQueryErr) {
 			return
 		}

internal/auth/auth.go

@@ -48,27 +48,36 @@ func (auth *Auth) EmailWhitelisted(emailSrc string) bool {
 }
 
 func (auth *Auth) CreateSessionCookie(c *gin.Context, data *types.SessionCookie) {
+	log.Debug().Msg("Creating session cookie")
 	sessions := sessions.Default(c)
+	log.Debug().Interface("data", data).Msg("Setting session cookie")
 	sessions.Set("username", data.Username)
 	sessions.Set("provider", data.Provider)
 	sessions.Save()
 }
 
 func (auth *Auth) DeleteSessionCookie(c *gin.Context) {
+	log.Debug().Msg("Deleting session cookie")
 	sessions := sessions.Default(c)
 	sessions.Clear()
 	sessions.Save()
 }
 
 func (auth *Auth) GetSessionCookie(c *gin.Context) (types.SessionCookie, error) {
+	log.Debug().Msg("Getting session cookie")
 	sessions := sessions.Default(c)
 
 	cookieUsername := sessions.Get("username")
 	cookieProvider := sessions.Get("provider")
 
+	log.Debug().Interface("cookieUsername", cookieUsername).Msg("Got username")
+	log.Debug().Interface("cookieProvider", cookieProvider).Msg("Got provider")
+
 	username, usernameOk := cookieUsername.(string)
 	provider, providerOk := cookieProvider.(string)
 
+	log.Debug().Str("username", username).Bool("usernameOk", usernameOk).Str("provider", provider).Bool("providerOk", providerOk).Msg("Parsed cookie")
+
 	if !usernameOk || !providerOk {
 		log.Warn().Msg("Session cookie invalid")
 		return types.SessionCookie{}, nil

internal/hooks/hooks.go

@@ -34,8 +34,12 @@ func (hooks *Hooks) UseUserContext(c *gin.Context) types.UserContext {
 		}
 	}
 
+	log.Debug().Interface("cookie", cookie).Msg("Got session cookie")
+
 	if cookie.Provider == "username" {
+		log.Debug().Msg("Provider is username")
 		if hooks.Auth.GetUser(cookie.Username) != nil {
+			log.Debug().Msg("User exists")
 			return types.UserContext{
 				Username:   cookie.Username,
 				IsLoggedIn: true,
@@ -45,9 +49,11 @@ func (hooks *Hooks) UseUserContext(c *gin.Context) types.UserContext {
 		}
 	}
 
+	log.Debug().Msg("Provider is not username")
 	provider := hooks.Providers.GetProvider(cookie.Provider)
 
 	if provider != nil {
+		log.Debug().Msg("Provider exists")
 		if !hooks.Auth.EmailWhitelisted(cookie.Username) {
 			log.Error().Msgf("Email %s not whitelisted", cookie.Username)
 			hooks.Auth.DeleteSessionCookie(c)
@@ -58,6 +64,7 @@ func (hooks *Hooks) UseUserContext(c *gin.Context) types.UserContext {
 				Provider:   "",
 			}
 		}
+		log.Debug().Msg("Email is whitelisted")
 		return types.UserContext{
 			Username:   cookie.Username,
 			IsLoggedIn: true,
@@ -66,6 +73,7 @@ func (hooks *Hooks) UseUserContext(c *gin.Context) types.UserContext {
 		}
 	}
 
+	log.Error().Msg("Provider does not exist")
 	return types.UserContext{
 		Username:   "",
 		IsLoggedIn: false,

internal/providers/generic.go

@@ -4,6 +4,8 @@ import (
 	"encoding/json"
 	"io"
 	"net/http"
+
+	"github.com/rs/zerolog/log"
 )
 
 type GenericUserInfoResponse struct {
@@ -17,12 +19,16 @@ func GetGenericEmail(client *http.Client, url string) (string, error) {
 		return "", resErr
 	}
 
+	log.Debug().Msg("Got response from generic provider")
+
 	body, bodyErr := io.ReadAll(res.Body)
 
 	if bodyErr != nil {
 		return "", bodyErr
 	}
 
+	log.Debug().Msg("Read body from generic provider")
+
 	var user GenericUserInfoResponse
 
 	jsonErr := json.Unmarshal(body, &user)
@@ -31,5 +37,7 @@ func GetGenericEmail(client *http.Client, url string) (string, error) {
 		return "", jsonErr
 	}
 
+	log.Debug().Interface("user", user).Msg("Parsed user from generic provider")
+
 	return user.Email, nil
 }

internal/providers/github.go

@@ -5,6 +5,8 @@ import (
 	"errors"
 	"io"
 	"net/http"
+
+	"github.com/rs/zerolog/log"
 )
 
 type GithubUserInfoResponse []struct {
@@ -23,12 +25,16 @@ func GetGithubEmail(client *http.Client) (string, error) {
 		return "", resErr
 	}
 
+	log.Debug().Msg("Got response from github")
+
 	body, bodyErr := io.ReadAll(res.Body)
 
 	if bodyErr != nil {
 		return "", bodyErr
 	}
 
+	log.Debug().Msg("Read body from github")
+
 	var emails GithubUserInfoResponse
 
 	jsonErr := json.Unmarshal(body, &emails)
@@ -37,6 +43,8 @@ func GetGithubEmail(client *http.Client) (string, error) {
 		return "", jsonErr
 	}
 
+	log.Debug().Interface("emails", emails).Msg("Parsed emails from github")
+
 	for _, email := range emails {
 		if email.Primary {
 			return email.Email, nil

internal/providers/google.go

@@ -4,6 +4,8 @@ import (
 	"encoding/json"
 	"io"
 	"net/http"
+
+	"github.com/rs/zerolog/log"
 )
 
 type GoogleUserInfoResponse struct {
@@ -21,12 +23,16 @@ func GetGoogleEmail(client *http.Client) (string, error) {
 		return "", resErr
 	}
 
+	log.Debug().Msg("Got response from google")
+
 	body, bodyErr := io.ReadAll(res.Body)
 
 	if bodyErr != nil {
 		return "", bodyErr
 	}
 
+	log.Debug().Msg("Read body from google")
+
 	var user GoogleUserInfoResponse
 
 	jsonErr := json.Unmarshal(body, &user)
@@ -35,5 +41,7 @@ func GetGoogleEmail(client *http.Client) (string, error) {
 		return "", jsonErr
 	}
 
+	log.Debug().Interface("user", user).Msg("Parsed user from google")
+
 	return user.Email, nil
 }

internal/providers/providers.go

@@ -79,33 +79,42 @@ func (providers *Providers) GetUser(provider string) (string, error) {
 	switch provider {
 	case "github":
 		if providers.Github == nil {
+			log.Debug().Msg("Github provider not configured")
 			return "", nil
 		}
 		client := providers.Github.GetClient()
+		log.Debug().Msg("Got client from github")
 		email, emailErr := GetGithubEmail(client)
 		if emailErr != nil {
 			return "", emailErr
 		}
+		log.Debug().Msg("Got email from github")
 		return email, nil
 	case "google":
 		if providers.Google == nil {
+			log.Debug().Msg("Google provider not configured")
 			return "", nil
 		}
 		client := providers.Google.GetClient()
+		log.Debug().Msg("Got client from google")
 		email, emailErr := GetGoogleEmail(client)
 		if emailErr != nil {
 			return "", emailErr
 		}
+		log.Debug().Msg("Got email from google")
 		return email, nil
 	case "generic":
 		if providers.Generic == nil {
+			log.Debug().Msg("Generic provider not configured")
 			return "", nil
 		}
 		client := providers.Generic.GetClient()
+		log.Debug().Msg("Got client from generic")
 		email, emailErr := GetGenericEmail(client, providers.Config.GenericUserURL)
 		if emailErr != nil {
 			return "", emailErr
 		}
+		log.Debug().Msg("Got email from generic")
 		return email, nil
 	default:
 		return "", nil

internal/types/types.go

@@ -42,6 +42,7 @@ type Config struct {
 	DisableContinue         bool   `mapstructure:"disable-continue"`
 	OAuthWhitelist          string `mapstructure:"oauth-whitelist"`
 	CookieExpiry            int    `mapstructure:"cookie-expiry"`
+	LogLevel                int8   `mapstructure:"log-level"`
 }
 
 type UserContext struct {

internal/utils/utils.go

@@ -6,18 +6,24 @@ import (
 	"os"
 	"strings"
 	"tinyauth/internal/types"
+
+	"github.com/rs/zerolog/log"
 )
 
 func ParseUsers(users string) (types.Users, error) {
+	log.Debug().Msg("Parsing users")
 	var usersParsed types.Users
 	userList := strings.Split(users, ",")
 
+	log.Debug().Strs("users", userList).Msg("Splitted users")
+
 	if len(userList) == 0 {
 		return types.Users{}, errors.New("invalid user format")
 	}
 
 	for _, user := range userList {
 		userSplit := strings.Split(user, ":")
+		log.Debug().Strs("user", userSplit).Msg("Splitting user")
 		if len(userSplit) != 2 {
 			return types.Users{}, errors.New("invalid user format")
 		}
@@ -27,6 +33,8 @@ func ParseUsers(users string) (types.Users, error) {
 		})
 	}
 
+	log.Debug().Interface("users", usersParsed).Msg("Parsed users")
+
 	return usersParsed, nil
 }
 
@@ -77,10 +85,12 @@ func ParseFileToLine(content string) string {
 
 func GetSecret(env string, file string) string {
 	if env == "" && file == "" {
+		log.Debug().Msg("No secret provided")
 		return ""
 	}
 
 	if env != "" {
+		log.Debug().Str("secret", env).Msg("Using secret from env")
 		return env
 	}
 
@@ -90,6 +100,8 @@ func GetSecret(env string, file string) string {
 		return ""
 	}
 
+	log.Debug().Str("secret", contents).Msg("Using secret from file")
+
 	return contents
 }
 
@@ -101,6 +113,7 @@ func GetUsers(env string, file string) (types.Users, error) {
 	}
 
 	if env != "" {
+		log.Debug().Str("users", env).Msg("Using users from env")
 		users += env
 	}
 
@@ -108,6 +121,7 @@ func GetUsers(env string, file string) (types.Users, error) {
 		fileContents, fileErr := ReadFile(file)
 
 		if fileErr == nil {
+			log.Debug().Str("users", ParseFileToLine(fileContents)).Msg("Using users from file")
 			users += ","
 			users += ParseFileToLine(fileContents)
 		}