From b73a9db061e2825ec8776c114107451f97d084cc Mon Sep 17 00:00:00 2001 From: Stavros Date: Fri, 8 May 2026 17:43:20 +0300 Subject: [PATCH] fix: improve logging in routines --- internal/bootstrap/app_bootstrap.go | 4 +++- internal/bootstrap/router_bootstrap.go | 9 ++------- internal/service/auth_service.go | 6 ++++++ internal/service/ldap_service.go | 2 ++ internal/service/oauth_broker_service.go | 1 + internal/service/oidc_service.go | 4 ++-- internal/utils/logger/logger.go | 7 ++++--- internal/utils/logger/logger_test.go | 2 +- 8 files changed, 21 insertions(+), 14 deletions(-) diff --git a/internal/bootstrap/app_bootstrap.go b/internal/bootstrap/app_bootstrap.go index 92a89b39..bd052c6b 100644 --- a/internal/bootstrap/app_bootstrap.go +++ b/internal/bootstrap/app_bootstrap.go @@ -252,7 +252,7 @@ func (app *BootstrapApp) Setup() error { for { select { case <-app.ctx.Done(): - app.log.App.Debug().Msg("Oh, seems like I got to shutdown, bye!") + app.log.App.Info().Msg("Oh, seems like I got to shutdown, bye!") app.db.Close() return nil case err := <-errChan: @@ -410,6 +410,8 @@ func (app *BootstrapApp) dbCleanupRoutine() { if err != nil { app.log.App.Error().Err(err).Msg("Failed to delete expired sessions") } + + app.log.App.Debug().Msg("Database cleanup completed") case <-app.ctx.Done(): app.log.App.Debug().Msg("Stopping database cleanup routine") ticker.Stop() diff --git a/internal/bootstrap/router_bootstrap.go b/internal/bootstrap/router_bootstrap.go index 47d3461e..ce739fc9 100644 --- a/internal/bootstrap/router_bootstrap.go +++ b/internal/bootstrap/router_bootstrap.go @@ -2,21 +2,16 @@ package bootstrap import ( "fmt" - "slices" "github.com/tinyauthapp/tinyauth/internal/controller" "github.com/tinyauthapp/tinyauth/internal/middleware" - "github.com/tinyauthapp/tinyauth/internal/model" "github.com/gin-gonic/gin" ) -var DEV_MODES = []string{"main", "test", "development"} - func (app *BootstrapApp) setupRouter() error { - if !slices.Contains(DEV_MODES, model.Version) { - gin.SetMode(gin.ReleaseMode) - } + // we don't want gin debug mode + gin.SetMode(gin.ReleaseMode) engine := gin.New() engine.Use(gin.Recovery()) diff --git a/internal/service/auth_service.go b/internal/service/auth_service.go index 8b891c34..60a205db 100644 --- a/internal/service/auth_service.go +++ b/internal/service/auth_service.go @@ -724,12 +724,16 @@ func (auth *AuthService) EndOAuthSession(sessionId string) { } func (auth *AuthService) CleanupOAuthSessionsRoutine() { + auth.log.App.Debug().Msg("Starting OAuth session cleanup routine") + ticker := time.NewTicker(30 * time.Minute) defer ticker.Stop() for { select { case <-ticker.C: + auth.log.App.Debug().Msg("Running OAuth session cleanup") + auth.oauthMutex.Lock() now := time.Now() @@ -741,7 +745,9 @@ func (auth *AuthService) CleanupOAuthSessionsRoutine() { } auth.oauthMutex.Unlock() + auth.log.App.Debug().Msg("OAuth session cleanup completed") case <-auth.context.Done(): + auth.log.App.Debug().Msg("Stopping OAuth session cleanup routine") return } } diff --git a/internal/service/ldap_service.go b/internal/service/ldap_service.go index d356cc75..c1a5d187 100644 --- a/internal/service/ldap_service.go +++ b/internal/service/ldap_service.go @@ -89,6 +89,8 @@ func (ldap *LdapService) Init() error { } go func() { + ldap.log.App.Debug().Msg("Starting LDAP connection heartbeat routine") + ticker := time.NewTicker(5 * time.Minute) defer ticker.Stop() diff --git a/internal/service/oauth_broker_service.go b/internal/service/oauth_broker_service.go index c3bfec9c..8d693ad9 100644 --- a/internal/service/oauth_broker_service.go +++ b/internal/service/oauth_broker_service.go @@ -35,6 +35,7 @@ func NewOAuthBrokerService( configs map[string]model.OAuthServiceConfig, ) *OAuthBrokerService { return &OAuthBrokerService{ + log: log, services: make(map[string]OAuthServiceImpl), configs: configs, } diff --git a/internal/service/oidc_service.go b/internal/service/oidc_service.go index da69eb96..38101fa7 100644 --- a/internal/service/oidc_service.go +++ b/internal/service/oidc_service.go @@ -756,14 +756,14 @@ func (service *OIDCService) DeleteOldSession(ctx context.Context, sub string) er // Cleanup routine - Resource heavy due to the linked tables func (service *OIDCService) cleanupRoutine() { - + service.log.App.Debug().Msg("Starting OIDC cleanup routine") ticker := time.NewTicker(time.Duration(30) * time.Minute) defer ticker.Stop() for { select { case <-ticker.C: - service.log.App.Debug().Msg("Starting OIDC cleanup routine") + service.log.App.Debug().Msg("Performing OIDC cleanup routine") currentTime := time.Now().Unix() diff --git a/internal/utils/logger/logger.go b/internal/utils/logger/logger.go index d85af79e..24d93145 100644 --- a/internal/utils/logger/logger.go +++ b/internal/utils/logger/logger.go @@ -87,6 +87,10 @@ func (l *Logger) Init() { }) } + if base.GetLevel() == zerolog.TraceLevel || base.GetLevel() == zerolog.DebugLevel { + base = base.With().Caller().Logger() + } + l.base = base l.audit = l.createLogger("audit", l.config.Streams.Audit) l.HTTP = l.createLogger("http", l.config.Streams.HTTP) @@ -113,9 +117,6 @@ func (l *Logger) createLogger(component string, cfg model.LogStreamConfig) zerol if cfg.Level != "" { sub = sub.Level(l.parseLogLevel(cfg.Level)) } - if sub.GetLevel() == zerolog.DebugLevel { - sub = sub.With().Caller().Logger() - } return sub } diff --git a/internal/utils/logger/logger_test.go b/internal/utils/logger/logger_test.go index 66387a5f..395d348f 100644 --- a/internal/utils/logger/logger_test.go +++ b/internal/utils/logger/logger_test.go @@ -162,7 +162,7 @@ func TestLogger(t *testing.T) { l.AuditLoginFailure("test", "test", "test", "test") assert.NotEmpty(t, buf.String()) - assert.Equal(t, 119, buf.Len()) // it's the length of the test log entry + assert.Equal(t, 81, buf.Len()) // it's the length of the test log entry }, }, }