feat: configurable component-level logging (#575)

* Refactor logging to use centralized logger utility

- Removed direct usage of zerolog in multiple files and replaced it with a centralized logging utility in the `utils` package.
- Introduced `Loggers` struct to manage different loggers (Audit, HTTP, App) with configurable levels and outputs.
- Updated all relevant files to utilize the new logging structure, ensuring consistent logging practices across the application.
- Enhanced error handling and logging messages for better traceability and debugging.

* refactor: update logging implementation to use new logger structure

* Refactor logging to use tlog package

- Replaced instances of utils logging with tlog in various controllers, services, and middleware.
- Introduced audit logging for login success, login failure, and logout events.
- Created tlog package with structured logging capabilities using zerolog.
- Added tests for the new tlog logger functionality.

* refactor: update logging configuration in environment files

* fix: adding coderabbit suggestions

* fix: ensure correct audit caller

* fix: include reason in audit login failure logs
This commit is contained in:
Pushpinder Singh
2026-01-15 08:57:19 -05:00
committed by GitHub
parent ba2d732415
commit 53bd413046
28 changed files with 486 additions and 214 deletions

View File

@@ -8,10 +8,10 @@ import (
"github.com/steveiliop56/tinyauth/internal/config"
"github.com/steveiliop56/tinyauth/internal/service"
"github.com/steveiliop56/tinyauth/internal/utils"
"github.com/steveiliop56/tinyauth/internal/utils/tlog"
"github.com/gin-gonic/gin"
"github.com/pquerna/otp/totp"
"github.com/rs/zerolog/log"
)
type LoginRequest struct {
@@ -53,7 +53,7 @@ func (controller *UserController) loginHandler(c *gin.Context) {
err := c.ShouldBindJSON(&req)
if err != nil {
log.Error().Err(err).Msg("Failed to bind JSON")
tlog.App.Error().Err(err).Msg("Failed to bind JSON")
c.JSON(400, gin.H{
"status": 400,
"message": "Bad Request",
@@ -61,12 +61,13 @@ func (controller *UserController) loginHandler(c *gin.Context) {
return
}
log.Debug().Str("username", req.Username).Msg("Login attempt")
tlog.App.Debug().Str("username", req.Username).Msg("Login attempt")
isLocked, remaining := controller.auth.IsAccountLocked(req.Username)
if isLocked {
log.Warn().Str("username", req.Username).Msg("Account is locked due to too many failed login attempts")
tlog.App.Warn().Str("username", req.Username).Msg("Account is locked due to too many failed login attempts")
tlog.AuditLoginFailure(c, req.Username, "username", "account locked")
c.Writer.Header().Add("x-tinyauth-lock-locked", "true")
c.Writer.Header().Add("x-tinyauth-lock-reset", time.Now().Add(time.Duration(remaining)*time.Second).Format(time.RFC3339))
c.JSON(429, gin.H{
@@ -79,8 +80,9 @@ func (controller *UserController) loginHandler(c *gin.Context) {
userSearch := controller.auth.SearchUser(req.Username)
if userSearch.Type == "unknown" {
log.Warn().Str("username", req.Username).Msg("User not found")
tlog.App.Warn().Str("username", req.Username).Msg("User not found")
controller.auth.RecordLoginAttempt(req.Username, false)
tlog.AuditLoginFailure(c, req.Username, "username", "user not found")
c.JSON(401, gin.H{
"status": 401,
"message": "Unauthorized",
@@ -89,8 +91,9 @@ func (controller *UserController) loginHandler(c *gin.Context) {
}
if !controller.auth.VerifyUser(userSearch, req.Password) {
log.Warn().Str("username", req.Username).Msg("Invalid password")
tlog.App.Warn().Str("username", req.Username).Msg("Invalid password")
controller.auth.RecordLoginAttempt(req.Username, false)
tlog.AuditLoginFailure(c, req.Username, "username", "invalid password")
c.JSON(401, gin.H{
"status": 401,
"message": "Unauthorized",
@@ -98,7 +101,8 @@ func (controller *UserController) loginHandler(c *gin.Context) {
return
}
log.Info().Str("username", req.Username).Msg("Login successful")
tlog.App.Info().Str("username", req.Username).Msg("Login successful")
tlog.AuditLoginSuccess(c, req.Username, "username")
controller.auth.RecordLoginAttempt(req.Username, true)
@@ -106,7 +110,7 @@ func (controller *UserController) loginHandler(c *gin.Context) {
user := controller.auth.GetLocalUser(userSearch.Username)
if user.TotpSecret != "" {
log.Debug().Str("username", req.Username).Msg("User has TOTP enabled, requiring TOTP verification")
tlog.App.Debug().Str("username", req.Username).Msg("User has TOTP enabled, requiring TOTP verification")
err := controller.auth.CreateSessionCookie(c, &config.SessionCookie{
Username: user.Username,
@@ -117,7 +121,7 @@ func (controller *UserController) loginHandler(c *gin.Context) {
})
if err != nil {
log.Error().Err(err).Msg("Failed to create session cookie")
tlog.App.Error().Err(err).Msg("Failed to create session cookie")
c.JSON(500, gin.H{
"status": 500,
"message": "Internal Server Error",
@@ -141,12 +145,12 @@ func (controller *UserController) loginHandler(c *gin.Context) {
Provider: "username",
}
log.Trace().Interface("session_cookie", sessionCookie).Msg("Creating session cookie")
tlog.App.Trace().Interface("session_cookie", sessionCookie).Msg("Creating session cookie")
err = controller.auth.CreateSessionCookie(c, &sessionCookie)
if err != nil {
log.Error().Err(err).Msg("Failed to create session cookie")
tlog.App.Error().Err(err).Msg("Failed to create session cookie")
c.JSON(500, gin.H{
"status": 500,
"message": "Internal Server Error",
@@ -161,10 +165,15 @@ func (controller *UserController) loginHandler(c *gin.Context) {
}
func (controller *UserController) logoutHandler(c *gin.Context) {
log.Debug().Msg("Logout request received")
tlog.App.Debug().Msg("Logout request received")
controller.auth.DeleteSessionCookie(c)
context, err := utils.GetContext(c)
if err == nil && context.IsLoggedIn {
tlog.AuditLogout(c, context.Username, context.Provider)
}
c.JSON(200, gin.H{
"status": 200,
"message": "Logout successful",
@@ -176,7 +185,7 @@ func (controller *UserController) totpHandler(c *gin.Context) {
err := c.ShouldBindJSON(&req)
if err != nil {
log.Error().Err(err).Msg("Failed to bind JSON")
tlog.App.Error().Err(err).Msg("Failed to bind JSON")
c.JSON(400, gin.H{
"status": 400,
"message": "Bad Request",
@@ -187,7 +196,7 @@ func (controller *UserController) totpHandler(c *gin.Context) {
context, err := utils.GetContext(c)
if err != nil {
log.Error().Err(err).Msg("Failed to get user context")
tlog.App.Error().Err(err).Msg("Failed to get user context")
c.JSON(500, gin.H{
"status": 500,
"message": "Internal Server Error",
@@ -196,7 +205,7 @@ func (controller *UserController) totpHandler(c *gin.Context) {
}
if !context.TotpPending {
log.Warn().Msg("TOTP attempt without a pending TOTP session")
tlog.App.Warn().Msg("TOTP attempt without a pending TOTP session")
c.JSON(401, gin.H{
"status": 401,
"message": "Unauthorized",
@@ -204,12 +213,12 @@ func (controller *UserController) totpHandler(c *gin.Context) {
return
}
log.Debug().Str("username", context.Username).Msg("TOTP verification attempt")
tlog.App.Debug().Str("username", context.Username).Msg("TOTP verification attempt")
isLocked, remaining := controller.auth.IsAccountLocked(context.Username)
if isLocked {
log.Warn().Str("username", context.Username).Msg("Account is locked due to too many failed TOTP attempts")
tlog.App.Warn().Str("username", context.Username).Msg("Account is locked due to too many failed TOTP attempts")
c.Writer.Header().Add("x-tinyauth-lock-locked", "true")
c.Writer.Header().Add("x-tinyauth-lock-reset", time.Now().Add(time.Duration(remaining)*time.Second).Format(time.RFC3339))
c.JSON(429, gin.H{
@@ -224,8 +233,9 @@ func (controller *UserController) totpHandler(c *gin.Context) {
ok := totp.Validate(req.Code, user.TotpSecret)
if !ok {
log.Warn().Str("username", context.Username).Msg("Invalid TOTP code")
tlog.App.Warn().Str("username", context.Username).Msg("Invalid TOTP code")
controller.auth.RecordLoginAttempt(context.Username, false)
tlog.AuditLoginFailure(c, context.Username, "totp", "invalid totp code")
c.JSON(401, gin.H{
"status": 401,
"message": "Unauthorized",
@@ -233,7 +243,8 @@ func (controller *UserController) totpHandler(c *gin.Context) {
return
}
log.Info().Str("username", context.Username).Msg("TOTP verification successful")
tlog.App.Info().Str("username", context.Username).Msg("TOTP verification successful")
tlog.AuditLoginSuccess(c, context.Username, "totp")
controller.auth.RecordLoginAttempt(context.Username, true)
@@ -244,12 +255,12 @@ func (controller *UserController) totpHandler(c *gin.Context) {
Provider: "username",
}
log.Trace().Interface("session_cookie", sessionCookie).Msg("Creating session cookie")
tlog.App.Trace().Interface("session_cookie", sessionCookie).Msg("Creating session cookie")
err = controller.auth.CreateSessionCookie(c, &sessionCookie)
if err != nil {
log.Error().Err(err).Msg("Failed to create session cookie")
tlog.App.Error().Err(err).Msg("Failed to create session cookie")
c.JSON(500, gin.H{
"status": 500,
"message": "Internal Server Error",