From 08d382c981947723ffbc3d03e7f7ebd764e771bd Mon Sep 17 00:00:00 2001 From: Stavros Date: Sun, 26 Jan 2025 20:23:09 +0200 Subject: [PATCH] feat: add debug log level --- cmd/root.go | 9 +++++++ internal/api/api.go | 46 ++++++++++++++++++++++++++++++++- internal/auth/auth.go | 9 +++++++ internal/hooks/hooks.go | 8 ++++++ internal/providers/generic.go | 8 ++++++ internal/providers/github.go | 8 ++++++ internal/providers/google.go | 8 ++++++ internal/providers/providers.go | 9 +++++++ internal/types/types.go | 1 + internal/utils/utils.go | 14 ++++++++++ 10 files changed, 119 insertions(+), 1 deletion(-) diff --git a/cmd/root.go b/cmd/root.go index eb40c4b..e08ecb8 100644 --- a/cmd/root.go +++ b/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()) } diff --git a/internal/api/api.go b/internal/api/api.go index 2016732..a7b94c2 100644 --- a/internal/api/api.go +++ b/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 } diff --git a/internal/auth/auth.go b/internal/auth/auth.go index 60085a2..b466296 100644 --- a/internal/auth/auth.go +++ b/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 diff --git a/internal/hooks/hooks.go b/internal/hooks/hooks.go index 3d1ce4c..b252a40 100644 --- a/internal/hooks/hooks.go +++ b/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, diff --git a/internal/providers/generic.go b/internal/providers/generic.go index 22b538c..4654bb7 100644 --- a/internal/providers/generic.go +++ b/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 } diff --git a/internal/providers/github.go b/internal/providers/github.go index 687be6b..356fe14 100644 --- a/internal/providers/github.go +++ b/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 diff --git a/internal/providers/google.go b/internal/providers/google.go index 49eaf6d..15cfed6 100644 --- a/internal/providers/google.go +++ b/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 } diff --git a/internal/providers/providers.go b/internal/providers/providers.go index 0b8db1d..d13f95f 100644 --- a/internal/providers/providers.go +++ b/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 diff --git a/internal/types/types.go b/internal/types/types.go index 5056dbc..1d209e0 100644 --- a/internal/types/types.go +++ b/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 { diff --git a/internal/utils/utils.go b/internal/utils/utils.go index b6ecafc..e951107 100644 --- a/internal/utils/utils.go +++ b/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) }