From 64d000070f8f426ce3003b6a1d36e2aece2689d3 Mon Sep 17 00:00:00 2001 From: Stavros Date: Sat, 15 Nov 2025 11:38:57 +0200 Subject: [PATCH] wip --- Dockerfile.dev | 5 +- air.toml | 4 +- cmd/root.go | 1 + internal/bootstrap/app_bootstrap.go | 15 +++- internal/config/config.go | 1 + internal/controller/oauth_controller.go | 56 ++++++++++-- internal/controller/user_controller.go | 94 ++++++++++++++++++-- internal/controller/user_controller_test.go | 10 ++- internal/service/access_log_service.go | 96 +++++++++++++++++++++ internal/service/auth_service.go | 10 +-- main.go | 2 +- 11 files changed, 265 insertions(+), 29 deletions(-) create mode 100644 internal/service/access_log_service.go diff --git a/Dockerfile.dev b/Dockerfile.dev index d0889c9..a132ded 100644 --- a/Dockerfile.dev +++ b/Dockerfile.dev @@ -7,13 +7,14 @@ COPY go.sum ./ RUN go mod download +RUN go install github.com/air-verse/air@v1.61.7 +RUN go install github.com/go-delve/delve/cmd/dlv@latest + COPY ./cmd ./cmd COPY ./internal ./internal COPY ./main.go ./ COPY ./air.toml ./ -RUN go install github.com/air-verse/air@v1.61.7 - EXPOSE 3000 ENTRYPOINT ["air", "-c", "air.toml"] \ No newline at end of file diff --git a/air.toml b/air.toml index 1772c27..7a2cfc6 100644 --- a/air.toml +++ b/air.toml @@ -2,9 +2,9 @@ root = "/tinyauth" tmp_dir = "tmp" [build] -pre_cmd = ["mkdir -p internal/assets/dist", "mkdir -p /data", "echo 'backend running' > internal/assets/dist/index.html", "go install github.com/go-delve/delve/cmd/dlv@v1.25.0"] +pre_cmd = ["mkdir -p internal/assets/dist", "mkdir -p /data", "echo 'backend running' > internal/assets/dist/index.html", "cp /go/bin/dlv dlv"] cmd = "CGO_ENABLED=0 go build -gcflags=\"all=-N -l\" -o tmp/tinyauth ." -bin = "/go/bin/dlv --listen :4000 --headless=true --api-version=2 --accept-multiclient --log=true exec tmp/tinyauth --continue --check-go-version=false" +bin = "dlv --listen :4000 --headless=true --api-version=2 --accept-multiclient --log=true exec tmp/tinyauth --continue --check-go-version=false" include_ext = ["go"] exclude_dir = ["internal/assets/dist"] exclude_regex = [".*_test\\.go"] diff --git a/cmd/root.go b/cmd/root.go index aa1ce50..3de67bb 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -71,6 +71,7 @@ func (c *rootCmd) Register() { {"disable-analytics", false, "Disable anonymous version collection."}, {"disable-resources", false, "Disable the resources server."}, {"socket-path", "", "Path to the Unix socket to bind the server to."}, + {"access-log-file", "", "Path to the access log file."}, } for _, opt := range configOptions { diff --git a/internal/bootstrap/app_bootstrap.go b/internal/bootstrap/app_bootstrap.go index 7c5ae8c..212c6cb 100644 --- a/internal/bootstrap/app_bootstrap.go +++ b/internal/bootstrap/app_bootstrap.go @@ -48,6 +48,9 @@ func NewBootstrapApp(config config.Config) *BootstrapApp { } func (app *BootstrapApp) Setup() error { + // Log json + shoudLogJson := utils.ShoudLogJSON(os.Environ(), os.Args) + // Parse users users, err := utils.GetUsers(app.config.Users, app.config.UsersFile) @@ -142,6 +145,10 @@ func (app *BootstrapApp) Setup() error { aclsService := service.NewAccessControlsService(dockerService) authService := service.NewAuthService(authConfig, dockerService, ldapService, database) oauthBrokerService := service.NewOAuthBrokerService(oauthProviders) + accessLogService := service.NewAccessLogService(&service.AccessLogServiceConfig{ + LogFile: app.config.AccessLogFile, + LogJson: shoudLogJson, + }) // Initialize services (order matters) services := []Service{ @@ -149,6 +156,7 @@ func (app *BootstrapApp) Setup() error { aclsService, authService, oauthBrokerService, + accessLogService, } for _, svc := range services { @@ -244,7 +252,7 @@ func (app *BootstrapApp) Setup() error { CSRFCookieName: csrfCookieName, RedirectCookieName: redirectCookieName, CookieDomain: cookieDomain, - }, apiRouter, authService, oauthBrokerService) + }, apiRouter, authService, oauthBrokerService, accessLogService) proxyController := controller.NewProxyController(controller.ProxyControllerConfig{ AppURL: app.config.AppURL, @@ -252,7 +260,7 @@ func (app *BootstrapApp) Setup() error { userController := controller.NewUserController(controller.UserControllerConfig{ CookieDomain: cookieDomain, - }, apiRouter, authService) + }, apiRouter, authService, accessLogService) resourcesController := controller.NewResourcesController(controller.ResourcesControllerConfig{ ResourcesDir: app.config.ResourcesDir, @@ -375,7 +383,8 @@ func (app *BootstrapApp) dbCleanup(db *gorm.DB) { for ; true; <-ticker.C { log.Debug().Msg("Cleaning up old database sessions") - _, err := gorm.G[model.Session](db).Where("expiry < ?", time.Now().UnixMilli()).Delete(ctx) + rows, err := gorm.G[model.Session](db).Where("expiry < ?", time.Now().UnixMilli()).Delete(ctx) + log.Debug().Int("rows_affected", rows).Msg("Old sessions cleanup completed") if err != nil { log.Error().Err(err).Msg("Failed to cleanup old sessions") } diff --git a/internal/config/config.go b/internal/config/config.go index 753f971..a2e066a 100644 --- a/internal/config/config.go +++ b/internal/config/config.go @@ -42,6 +42,7 @@ type Config struct { DisableAnalytics bool `mapstructure:"disable-analytics"` DisableResources bool `mapstructure:"disable-resources"` SocketPath string `mapstructure:"socket-path"` + AccessLogFile string `mapstructure:"access-log-file"` } // OAuth/OIDC config diff --git a/internal/controller/oauth_controller.go b/internal/controller/oauth_controller.go index 99e2289..092c956 100644 --- a/internal/controller/oauth_controller.go +++ b/internal/controller/oauth_controller.go @@ -31,14 +31,16 @@ type OAuthController struct { router *gin.RouterGroup auth *service.AuthService broker *service.OAuthBrokerService + als *service.AccessLogService } -func NewOAuthController(config OAuthControllerConfig, router *gin.RouterGroup, auth *service.AuthService, broker *service.OAuthBrokerService) *OAuthController { +func NewOAuthController(config OAuthControllerConfig, router *gin.RouterGroup, auth *service.AuthService, broker *service.OAuthBrokerService, als *service.AccessLogService) *OAuthController { return &OAuthController{ config: config, router: router, auth: auth, broker: broker, + als: als, } } @@ -61,7 +63,7 @@ func (controller *OAuthController) oauthURLHandler(c *gin.Context) { return } - service, exists := controller.broker.GetService(req.Provider) + svc, exists := controller.broker.GetService(req.Provider) if !exists { log.Warn().Msgf("OAuth provider not found: %s", req.Provider) @@ -72,9 +74,9 @@ func (controller *OAuthController) oauthURLHandler(c *gin.Context) { return } - service.GenerateVerifier() - state := service.GenerateState() - authURL := service.GetAuthURL(state) + svc.GenerateVerifier() + state := svc.GenerateState() + authURL := svc.GetAuthURL(state) c.SetCookie(controller.config.CSRFCookieName, state, int(time.Hour.Seconds()), "/", fmt.Sprintf(".%s", controller.config.CookieDomain), controller.config.SecureCookie, true) redirectURI := c.Query("redirect_uri") @@ -106,8 +108,16 @@ func (controller *OAuthController) oauthCallbackHandler(c *gin.Context) { state := c.Query("state") csrfCookie, err := c.Cookie(controller.config.CSRFCookieName) + clientIP := c.ClientIP() if err != nil || state != csrfCookie { + controller.als.Log(service.AccessLog{ + Provider: req.Provider, + Username: "", + ClientIP: clientIP, + Success: false, + Message: "CSRF token mismatch or cookie missing", + }) log.Warn().Err(err).Msg("CSRF token mismatch or cookie missing") c.SetCookie(controller.config.CSRFCookieName, "", -1, "/", fmt.Sprintf(".%s", controller.config.CookieDomain), controller.config.SecureCookie, true) c.Redirect(http.StatusTemporaryRedirect, fmt.Sprintf("%s/error", controller.config.AppURL)) @@ -117,16 +127,30 @@ func (controller *OAuthController) oauthCallbackHandler(c *gin.Context) { c.SetCookie(controller.config.CSRFCookieName, "", -1, "/", fmt.Sprintf(".%s", controller.config.CookieDomain), controller.config.SecureCookie, true) code := c.Query("code") - service, exists := controller.broker.GetService(req.Provider) + svc, exists := controller.broker.GetService(req.Provider) if !exists { + controller.als.Log(service.AccessLog{ + Provider: req.Provider, + Username: "", + ClientIP: clientIP, + Success: false, + Message: "OAuth provider not found", + }) log.Warn().Msgf("OAuth provider not found: %s", req.Provider) c.Redirect(http.StatusTemporaryRedirect, fmt.Sprintf("%s/error", controller.config.AppURL)) return } - err = service.VerifyCode(code) + err = svc.VerifyCode(code) if err != nil { + controller.als.Log(service.AccessLog{ + Provider: req.Provider, + Username: "", + ClientIP: clientIP, + Success: false, + Message: "Failed to verify OAuth code", + }) log.Error().Err(err).Msg("Failed to verify OAuth code") c.Redirect(http.StatusTemporaryRedirect, fmt.Sprintf("%s/error", controller.config.AppURL)) return @@ -147,6 +171,14 @@ func (controller *OAuthController) oauthCallbackHandler(c *gin.Context) { } if !controller.auth.IsEmailWhitelisted(user.Email) { + controller.als.Log(service.AccessLog{ + Provider: req.Provider, + Username: user.Email, + ClientIP: clientIP, + Success: false, + Message: "Email not whitelisted", + }) + log.Warn().Str("email", user.Email).Msg("Email not whitelisted") queries, err := query.Values(config.UnauthorizedQuery{ @@ -189,7 +221,7 @@ func (controller *OAuthController) oauthCallbackHandler(c *gin.Context) { Email: user.Email, Provider: req.Provider, OAuthGroups: utils.CoalesceToString(user.Groups), - OAuthName: service.GetName(), + OAuthName: svc.GetName(), } log.Trace().Interface("session_cookie", sessionCookie).Msg("Creating session cookie") @@ -202,6 +234,14 @@ func (controller *OAuthController) oauthCallbackHandler(c *gin.Context) { return } + controller.als.Log(service.AccessLog{ + Provider: req.Provider, + Username: user.Email, + ClientIP: clientIP, + Success: true, + Message: "OAuth login successful", + }) + redirectURI, err := c.Cookie(controller.config.RedirectCookieName) if err != nil || !utils.IsRedirectSafe(redirectURI, controller.config.CookieDomain) { diff --git a/internal/controller/user_controller.go b/internal/controller/user_controller.go index ff26de1..42bf138 100644 --- a/internal/controller/user_controller.go +++ b/internal/controller/user_controller.go @@ -29,13 +29,15 @@ type UserController struct { config UserControllerConfig router *gin.RouterGroup auth *service.AuthService + als *service.AccessLogService } -func NewUserController(config UserControllerConfig, router *gin.RouterGroup, auth *service.AuthService) *UserController { +func NewUserController(config UserControllerConfig, router *gin.RouterGroup, auth *service.AuthService, als *service.AccessLogService) *UserController { return &UserController{ config: config, router: router, auth: auth, + als: als, } } @@ -72,6 +74,13 @@ func (controller *UserController) loginHandler(c *gin.Context) { isLocked, remainingTime := controller.auth.IsAccountLocked(rateIdentifier) if isLocked { + controller.als.Log(service.AccessLog{ + Provider: "username", + Username: req.Username, + ClientIP: clientIP, + Success: false, + Message: "Account is locked due to too many failed login attempts", + }) log.Warn().Str("username", req.Username).Str("ip", clientIP).Msg("Account is locked due to too many failed login attempts") c.JSON(429, gin.H{ "status": 429, @@ -83,6 +92,13 @@ func (controller *UserController) loginHandler(c *gin.Context) { userSearch := controller.auth.SearchUser(req.Username) if userSearch.Type == "unknown" { + controller.als.Log(service.AccessLog{ + Provider: "username", + Username: req.Username, + ClientIP: clientIP, + Success: false, + Message: "User not found", + }) log.Warn().Str("username", req.Username).Str("ip", clientIP).Msg("User not found") controller.auth.RecordLoginAttempt(rateIdentifier, false) c.JSON(401, gin.H{ @@ -93,6 +109,13 @@ func (controller *UserController) loginHandler(c *gin.Context) { } if !controller.auth.VerifyUser(userSearch, req.Password) { + controller.als.Log(service.AccessLog{ + Provider: "username", + Username: req.Username, + ClientIP: clientIP, + Success: false, + Message: "Invalid password", + }) log.Warn().Str("username", req.Username).Str("ip", clientIP).Msg("Invalid password") controller.auth.RecordLoginAttempt(rateIdentifier, false) c.JSON(401, gin.H{ @@ -102,14 +125,18 @@ func (controller *UserController) loginHandler(c *gin.Context) { return } - log.Info().Str("username", req.Username).Str("ip", clientIP).Msg("Login successful") - - controller.auth.RecordLoginAttempt(rateIdentifier, true) - if userSearch.Type == "local" { user := controller.auth.GetLocalUser(userSearch.Username) if user.TotpSecret != "" { + controller.als.Log(service.AccessLog{ + Provider: "username", + Username: req.Username, + ClientIP: clientIP, + Success: true, + Message: "User has TOTP enabled, requiring TOTP verification", + }) + log.Debug().Str("username", req.Username).Msg("User has TOTP enabled, requiring TOTP verification") err := controller.auth.CreateSessionCookie(c, &config.SessionCookie{ @@ -158,6 +185,18 @@ func (controller *UserController) loginHandler(c *gin.Context) { return } + controller.als.Log(service.AccessLog{ + Provider: "username", + Username: req.Username, + ClientIP: clientIP, + Success: true, + Message: "Login successful", + }) + + log.Info().Str("username", req.Username).Str("ip", clientIP).Msg("Login successful") + + controller.auth.RecordLoginAttempt(rateIdentifier, true) + c.JSON(200, gin.H{ "status": 200, "message": "Login successful", @@ -167,8 +206,28 @@ func (controller *UserController) loginHandler(c *gin.Context) { func (controller *UserController) logoutHandler(c *gin.Context) { log.Debug().Msg("Logout request received") + context, err := utils.GetContext(c) + + if err != nil { + log.Debug().Msg("Not logged in, nothing to do") + c.JSON(200, gin.H{ + "status": 200, + "message": "Not logged in", + }) + return + } + + clientIP := c.ClientIP() controller.auth.DeleteSessionCookie(c) + controller.als.Log(service.AccessLog{ + Provider: "username", + Username: context.Username, + ClientIP: clientIP, + Success: true, + Message: "Logout successful", + }) + c.JSON(200, gin.H{ "status": 200, "message": "Logout successful", @@ -188,6 +247,7 @@ func (controller *UserController) totpHandler(c *gin.Context) { return } + clientIP := c.ClientIP() context, err := utils.GetContext(c) if err != nil { @@ -208,8 +268,6 @@ func (controller *UserController) totpHandler(c *gin.Context) { return } - clientIP := c.ClientIP() - rateIdentifier := context.Username if rateIdentifier == "" { @@ -221,6 +279,13 @@ func (controller *UserController) totpHandler(c *gin.Context) { isLocked, remainingTime := controller.auth.IsAccountLocked(rateIdentifier) if isLocked { + controller.als.Log(service.AccessLog{ + Provider: "username", + Username: context.Username, + ClientIP: clientIP, + Success: false, + Message: "Account is locked due to too many failed TOTP attempts", + }) log.Warn().Str("username", context.Username).Str("ip", clientIP).Msg("Account is locked due to too many failed TOTP attempts") c.JSON(429, gin.H{ "status": 429, @@ -234,6 +299,13 @@ func (controller *UserController) totpHandler(c *gin.Context) { ok := totp.Validate(req.Code, user.TotpSecret) if !ok { + controller.als.Log(service.AccessLog{ + Provider: "username", + Username: context.Username, + ClientIP: clientIP, + Success: false, + Message: "Invalid TOTP code", + }) log.Warn().Str("username", context.Username).Str("ip", clientIP).Msg("Invalid TOTP code") controller.auth.RecordLoginAttempt(rateIdentifier, false) c.JSON(401, gin.H{ @@ -243,6 +315,14 @@ func (controller *UserController) totpHandler(c *gin.Context) { return } + controller.als.Log(service.AccessLog{ + Provider: "username", + Username: context.Username, + ClientIP: clientIP, + Success: true, + Message: "TOTP verification successful", + }) + log.Info().Str("username", context.Username).Str("ip", clientIP).Msg("TOTP verification successful") controller.auth.RecordLoginAttempt(rateIdentifier, true) diff --git a/internal/controller/user_controller_test.go b/internal/controller/user_controller_test.go index 6065521..c707ed1 100644 --- a/internal/controller/user_controller_test.go +++ b/internal/controller/user_controller_test.go @@ -64,10 +64,18 @@ func setupUserController(t *testing.T, middlewares *[]gin.HandlerFunc) (*gin.Eng SessionCookieName: "tinyauth-session", }, nil, nil, database) + // Access log service + als := service.NewAccessLogService(&service.AccessLogServiceConfig{ + LogFile: "", + LogJson: true, + }) + + assert.NilError(t, als.Init()) + // Controller ctrl := controller.NewUserController(controller.UserControllerConfig{ CookieDomain: "localhost", - }, group, authService) + }, group, authService, als) ctrl.SetupRoutes() return router, recorder diff --git a/internal/service/access_log_service.go b/internal/service/access_log_service.go new file mode 100644 index 0000000..d9effa4 --- /dev/null +++ b/internal/service/access_log_service.go @@ -0,0 +1,96 @@ +package service + +import ( + "fmt" + "io" + "os" + "strings" + "time" + + "github.com/rs/zerolog" +) + +type AccessLog struct { + Provider string + Username string + ClientIP string + Success bool + Message string +} + +type AccessLogServiceConfig struct { + LogFile string + LogJson bool +} + +type AccessLogService struct { + config *AccessLogServiceConfig + logger zerolog.Logger +} + +func NewAccessLogService(config *AccessLogServiceConfig) *AccessLogService { + return &AccessLogService{ + config: config, + } +} + +func (als *AccessLogService) Init() error { + writers := make([]io.Writer, 0) + + if als.config.LogFile != "" { + // We are not closing the file here since we will keep writing to it until interrupted + file, err := os.OpenFile(als.config.LogFile, os.O_RDWR|os.O_CREATE|os.O_TRUNC, 0640) + if err != nil { + return err + } + writter := zerolog.ConsoleWriter(zerolog.ConsoleWriter{Out: file, TimeFormat: time.RFC3339, NoColor: true, PartsOrder: []string{ + "time", "level", "caller", "message", + }}) + writter.FormatLevel = func(i any) string { + return strings.ToUpper(fmt.Sprintf("[ %s ]", i)) + } + writter.FormatCaller = func(i any) string { + return fmt.Sprintf("%s:", i) + } + writter.FormatMessage = func(i any) string { + return fmt.Sprintf("%s", i) + } + writter.FormatFieldName = func(i any) string { + return fmt.Sprintf("%s=", i) + } + writter.FormatFieldValue = func(i any) string { + return fmt.Sprintf("%s", i) + } + writers = append(writers, writter) + } + + if !als.config.LogJson { + writter := zerolog.ConsoleWriter(zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.RFC3339}) + writers = append(writers, writter) + } else { + writers = append(writers, os.Stdout) + } + + als.logger = zerolog.New(zerolog.MultiLevelWriter(writers...)).With().Caller().Logger() + + return nil +} + +func (als *AccessLogService) Log(log AccessLog) { + var event *zerolog.Event + + if log.Success { + event = als.logger.Info() + } else { + event = als.logger.Warn() + } + + event = event. + Str("provider", log.Provider). + Str("username", log.Username). + Str("client_ip", log.ClientIP). + Int64("time", time.Now().UnixMilli()). + Bool("success", log.Success) + + event.Msg(log.Message) +} diff --git a/internal/service/auth_service.go b/internal/service/auth_service.go index a75bb04..4de547c 100644 --- a/internal/service/auth_service.go +++ b/internal/service/auth_service.go @@ -213,7 +213,7 @@ func (auth *AuthService) CreateSessionCookie(c *gin.Context, data *config.Sessio Provider: data.Provider, TOTPPending: data.TotpPending, OAuthGroups: data.OAuthGroups, - Expiry: time.Now().Add(time.Duration(expiry) * time.Second).Unix(), + Expiry: time.Now().Add(time.Duration(expiry) * time.Second).UnixMilli(), OAuthName: data.OAuthName, } @@ -263,12 +263,12 @@ func (auth *AuthService) GetSessionCookie(c *gin.Context) (config.SessionCookie, return config.SessionCookie{}, fmt.Errorf("session not found") } - currentTime := time.Now().Unix() + currentTime := time.Now().UnixMilli() if currentTime > session.Expiry { - res := auth.database.Unscoped().Where("uuid = ?", session.UUID).Delete(&model.Session{}) - if res.Error != nil { - log.Error().Err(res.Error).Msg("Failed to delete expired session") + _, err = gorm.G[model.Session](auth.database).Where("uuid = ?", cookie).Delete(auth.ctx) + if err != nil { + log.Error().Err(err).Msg("Failed to delete expired session") } return config.SessionCookie{}, fmt.Errorf("session expired") } diff --git a/main.go b/main.go index 893e62f..94aefe2 100644 --- a/main.go +++ b/main.go @@ -11,7 +11,7 @@ import ( ) func main() { - log.Logger = log.Logger.With().Timestamp().Caller().Logger() + log.Logger = log.Logger.With().Caller().Logger() if !utils.ShoudLogJSON(os.Environ(), os.Args) { log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr, TimeFormat: time.RFC3339}) }