From bf90c1a8285e32663b1e29e3e29c3d619a9a2eed Mon Sep 17 00:00:00 2001 From: Jannis Mattheis Date: Sun, 17 May 2026 11:48:19 +0200 Subject: [PATCH 1/2] fix: use zerolog --- api/oidc.go | 8 +++--- api/stream/client.go | 4 +-- app.go | 10 +++++-- database/database.go | 14 ++++++--- go.mod | 2 ++ go.sum | 4 +++ plugin/manager.go | 13 +++++---- router/router.go | 68 +++++++++++++++++++++++++++++--------------- runner/runner.go | 35 +++++++++++++++++------ 9 files changed, 109 insertions(+), 49 deletions(-) diff --git a/api/oidc.go b/api/oidc.go index 6bec28b4..4ce4e21f 100644 --- a/api/oidc.go +++ b/api/oidc.go @@ -7,7 +7,6 @@ import ( "errors" "fmt" "io" - "log" "net/http" "time" @@ -17,6 +16,7 @@ import ( "github.com/gotify/server/v2/database" "github.com/gotify/server/v2/decaymap" "github.com/gotify/server/v2/model" + "github.com/rs/zerolog/log" "github.com/zitadel/oidc/v3/pkg/client/rp" httphelper "github.com/zitadel/oidc/v3/pkg/http" "github.com/zitadel/oidc/v3/pkg/oidc" @@ -30,7 +30,7 @@ func NewOIDC(conf *config.Configuration, db *database.GormDatabase, userChangeNo cookieKey := make([]byte, 32) if _, err := rand.Read(cookieKey); err != nil { - log.Fatalf("failed to generate OIDC cookie key: %v", err) + log.Fatal().Err(err).Msg("failed to generate OIDC cookie key") } cookieHandlerOpt := []httphelper.CookieHandlerOpt{} if !conf.Server.SecureCookie { @@ -50,7 +50,7 @@ func NewOIDC(conf *config.Configuration, db *database.GormDatabase, userChangeNo opts..., ) if err != nil { - log.Fatalf("failed to initialize OIDC provider: %v", err) + log.Fatal().Err(err).Msg("failed to initialize OIDC provider") } return &OIDCAPI{ @@ -415,7 +415,7 @@ func (a *OIDCAPI) resolveUser(info *oidc.UserInfo) (*model.User, int, error) { return nil, http.StatusInternalServerError, fmt.Errorf("failed to create user: %w", err) } if err := a.UserChangeNotifier.fireUserAdded(user.ID); err != nil { - log.Printf("Could not notify user change: %v\n", err) + log.Error().Err(err).Uint("user_id", user.ID).Msg("Could not notify user change") } } return user, 0, nil diff --git a/api/stream/client.go b/api/stream/client.go index 044f91e3..1d7f4ba0 100644 --- a/api/stream/client.go +++ b/api/stream/client.go @@ -1,11 +1,11 @@ package stream import ( - "fmt" "time" "github.com/gorilla/websocket" "github.com/gotify/server/v2/model" + "github.com/rs/zerolog/log" ) const ( @@ -115,5 +115,5 @@ func printWebSocketError(prefix string, err error) { return } - fmt.Println("WebSocket:", prefix, err) + log.Warn().Err(err).Msgf("WebSocket %s", prefix) } diff --git a/app.go b/app.go index 6d117302..ad208bd5 100644 --- a/app.go +++ b/app.go @@ -1,8 +1,8 @@ package main import ( - "fmt" "os" + "time" "github.com/gotify/server/v2/config" "github.com/gotify/server/v2/database" @@ -10,6 +10,8 @@ import ( "github.com/gotify/server/v2/model" "github.com/gotify/server/v2/router" "github.com/gotify/server/v2/runner" + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" ) var ( @@ -24,10 +26,12 @@ var ( ) func main() { + log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr, TimeFormat: time.RFC3339}) + vInfo := &model.VersionInfo{Version: Version, Commit: Commit, BuildDate: BuildDate} mode.Set(Mode) - fmt.Println("Starting Gotify version", vInfo.Version+"@"+BuildDate) + log.Info().Str("version", vInfo.Version).Str("build_date", BuildDate).Msg("Gotify") conf := config.Get() if conf.PluginsDir != "" { @@ -49,7 +53,7 @@ func main() { defer closeable() if err := runner.Run(engine, conf); err != nil { - fmt.Println("Server error: ", err) + log.Error().Err(err).Msg("Server error") os.Exit(1) } } diff --git a/database/database.go b/database/database.go index 574c13ff..cb9085df 100644 --- a/database/database.go +++ b/database/database.go @@ -3,8 +3,6 @@ package database import ( "database/sql" "errors" - "fmt" - "log" "math" "os" "path/filepath" @@ -14,6 +12,7 @@ import ( "github.com/gotify/server/v2/fracdex" "github.com/gotify/server/v2/model" "github.com/mattn/go-isatty" + "github.com/rs/zerolog/log" "gorm.io/driver/mysql" "gorm.io/driver/postgres" "gorm.io/driver/sqlite" @@ -21,13 +20,20 @@ import ( "gorm.io/gorm/logger" ) +// gormLogWriter routes gorm logger output through zerolog. +type gormLogWriter struct{} + +func (gormLogWriter) Printf(format string, args ...interface{}) { + log.Warn().Str("component", "gorm").Msgf(format, args...) +} + var mkdirAll = os.MkdirAll // New creates a new wrapper for the gorm database framework. func New(dialect, connection, defaultUser, defaultPass string, strength int, createDefaultUserIfNotExist bool) (*GormDatabase, error) { createDirectoryIfSqlite(dialect, connection) - dbLogger := logger.New(log.New(os.Stderr, "\r\n", log.LstdFlags), logger.Config{ + dbLogger := logger.New(gormLogWriter{}, logger.Config{ SlowThreshold: 200 * time.Millisecond, LogLevel: logger.Warn, IgnoreRecordNotFoundError: true, @@ -111,7 +117,7 @@ func fillMissingSortKeys(db *gorm.DB) error { if err := db.Order("user_id, sort_key, id ASC").Find(&apps).Error; err != nil && err != gorm.ErrRecordNotFound { return err } - fmt.Println("Migrating", len(apps), "application sort keys") + log.Info().Int("count", len(apps)).Msg("Migrating application sort keys") sortKey := "" currentUser := uint(math.MaxUint) diff --git a/go.mod b/go.mod index c519e2cc..3e641d3e 100644 --- a/go.mod +++ b/go.mod @@ -13,6 +13,7 @@ require ( github.com/jinzhu/configor v1.2.2 github.com/mattn/go-isatty v0.0.20 github.com/robfig/cron v1.2.0 + github.com/rs/zerolog v1.35.1 github.com/stretchr/testify v1.11.1 github.com/zitadel/oidc/v3 v3.45.5 golang.org/x/crypto v0.48.0 @@ -53,6 +54,7 @@ require ( github.com/json-iterator/go v1.1.12 // indirect github.com/klauspost/cpuid/v2 v2.3.0 // indirect github.com/leodido/go-urn v1.4.0 // indirect + github.com/mattn/go-colorable v0.1.14 // indirect github.com/mattn/go-sqlite3 v1.14.32 // indirect github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect github.com/modern-go/reflect2 v1.0.2 // indirect diff --git a/go.sum b/go.sum index fbb19cba..a6dae214 100644 --- a/go.sum +++ b/go.sum @@ -100,6 +100,8 @@ github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY= github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE= github.com/leodido/go-urn v1.4.0 h1:WT9HwE9SGECu3lg4d/dIA+jxlljEa1/ffXKmRjqdmIQ= github.com/leodido/go-urn v1.4.0/go.mod h1:bvxc+MVxLKB4z00jd1z+Dvzr47oO32F/QSNjSBOlFxI= +github.com/mattn/go-colorable v0.1.14 h1:9A9LHSqF/7dyVVX6g0U9cwm9pG3kP9gSzcuIPHPsaIE= +github.com/mattn/go-colorable v0.1.14/go.mod h1:6LmQG8QLFO4G5z1gPvYEzlUgJ2wF+stgPZH1UqBm1s8= github.com/mattn/go-isatty v0.0.4/go.mod h1:M+lRXTBqGeGNdLjl/ufCoiOlB5xdOkqRJdNxMWT7Zi4= github.com/mattn/go-isatty v0.0.20 h1:xfD0iDuEKnDkl03q4limB+vH+GxLEtL/jb4xVJSWWEY= github.com/mattn/go-isatty v0.0.20/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y= @@ -129,6 +131,8 @@ github.com/rogpeppe/go-internal v1.14.1 h1:UQB4HGPB6osV0SQTLymcB4TgvyWu6ZyliaW0t github.com/rogpeppe/go-internal v1.14.1/go.mod h1:MaRKkUm5W0goXpeCfT7UZI6fk/L7L7so1lCWt35ZSgc= github.com/rs/cors v1.11.1 h1:eU3gRzXLRK57F5rKMGMZURNdIG4EoAmX8k94r9wXWHA= github.com/rs/cors v1.11.1/go.mod h1:XyqrcTp5zjWr1wsJ8PIRZssZ8b/WMcMf71DJnit4EMU= +github.com/rs/zerolog v1.35.1 h1:m7xQeoiLIiV0BCEY4Hs+j2NG4Gp2o2KPKmhnnLiazKI= +github.com/rs/zerolog v1.35.1/go.mod h1:EjML9kdfa/RMA7h/6z6pYmq1ykOuA8/mjWaEvGI+jcw= github.com/sirupsen/logrus v1.9.4 h1:TsZE7l11zFCLZnZ+teH4Umoq5BhEIfIzfRDZ1Uzql2w= github.com/sirupsen/logrus v1.9.4/go.mod h1:ftWc9WdOfJ0a92nsE2jF5u5ZwH8Bv2zdeOC42RjbV2g= github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME= diff --git a/plugin/manager.go b/plugin/manager.go index 2bb4041e..9c9436dc 100644 --- a/plugin/manager.go +++ b/plugin/manager.go @@ -6,7 +6,6 @@ import ( "encoding/json" "errors" "fmt" - "log" "os" "path/filepath" "plugin" @@ -18,6 +17,7 @@ import ( "github.com/gotify/server/v2/auth" "github.com/gotify/server/v2/model" "github.com/gotify/server/v2/plugin/compat" + "github.com/rs/zerolog/log" "gopkg.in/yaml.v3" ) @@ -155,7 +155,7 @@ func (m *Manager) PluginInfo(modulePath string) compat.Info { if p, ok := m.plugins[modulePath]; ok { return p.PluginInfo() } - fmt.Println("Could not get plugin info for", modulePath) + log.Warn().Str("module_path", modulePath).Msg("Could not get plugin info") return compat.Info{ Name: "UNKNOWN", ModulePath: modulePath, @@ -237,7 +237,7 @@ func (m *Manager) loadPlugins(directory string) error { pluginPath := filepath.Join(directory, "./", name) - fmt.Println("Loading plugin", pluginPath) + log.Info().Str("path", pluginPath).Msg("Loading plugin") pRaw, err := plugin.Open(pluginPath) if err != nil { return pluginFileLoadError{name, err} @@ -355,7 +355,7 @@ func (m *Manager) initializeSingleUserPlugin(userCtx compat.UserContext, p compa if err != nil { // Single user plugin cannot be enabled // Don't panic, disable for now and wait for user to update config - log.Printf("Plugin initialize failed for user %s: %s. Disabling now...", userCtx.Name, err.Error()) + log.Warn().Err(err).Str("user", userCtx.Name).Msg("Plugin initialize failed, disabling now") pluginConf.Enabled = false m.db.UpdatePluginConf(pluginConf) } @@ -374,7 +374,10 @@ func (m *Manager) initializeConfigurerForSingleUserPlugin(instance compat.Plugin if yaml.Unmarshal(pluginConf.Config, c) != nil || instance.ValidateAndSetConfig(c) != nil { pluginConf.Enabled = false - log.Printf("Plugin %s for user %d failed to initialize because it rejected the current config. It might be outdated. A default config is used and the user would need to enable it again.", pluginConf.ModulePath, pluginConf.UserID) + log.Warn(). + Str("module_path", pluginConf.ModulePath). + Uint("user_id", pluginConf.UserID). + Msg("Plugin failed to initialize because it rejected the current config. It might be outdated. A default config is used and the user would need to enable it again.") newConf := bytes.NewBufferString("# Plugin initialization failed because it rejected the current config. It might be outdated.\r\n# A default plugin configuration is used:\r\n") d, _ := yaml.Marshal(c) diff --git a/router/router.go b/router/router.go index cb39af00..12236d45 100644 --- a/router/router.go +++ b/router/router.go @@ -21,6 +21,7 @@ import ( "github.com/gotify/server/v2/model" "github.com/gotify/server/v2/plugin" "github.com/gotify/server/v2/ui" + "github.com/rs/zerolog/log" ) // Create creates the gin engine with all routes. @@ -39,7 +40,7 @@ func Create(db *database.GormDatabase, vInfo *model.VersionInfo, conf *config.Co } }) - g.Use(gin.LoggerWithFormatter(logFormatter), gin.Recovery(), gerror.Handler(), location.Default()) + g.Use(accessLogger(), gin.Recovery(), gerror.Handler(), location.Default()) g.NoRoute(gerror.NotFound()) if conf.Server.SSL.Enabled && conf.Server.SSL.RedirectToHTTPS { @@ -239,31 +240,52 @@ func Create(db *database.GormDatabase, vInfo *model.VersionInfo, conf *config.Co var tokenRegexp = regexp.MustCompile("token=[^&]+") -func logFormatter(param gin.LogFormatterParams) string { - if (param.ClientIP == "127.0.0.1" || param.ClientIP == "::1") && param.Path == "/health" { - return "" - } +func accessLogger() gin.HandlerFunc { + return func(c *gin.Context) { + start := time.Now() - var statusColor, methodColor, resetColor string - if param.IsOutputColor() { - statusColor = param.StatusCodeColor() - methodColor = param.MethodColor() - resetColor = param.ResetColor() - } + rawQuery := c.Request.URL.RawQuery + path := c.Request.URL.Path + + c.Next() + + clientIP := c.ClientIP() + if (clientIP == "127.0.0.1" || clientIP == "::1") && path == "/health" { + return + } + + if rawQuery != "" { + path = path + "?" + rawQuery + } + path = tokenRegexp.ReplaceAllString(path, "token=[masked]") + + latency := time.Since(start) + if latency > time.Minute { + latency = latency - latency%time.Second + } + + status := c.Writer.Status() + evt := log.Info() + switch { + case status >= 500: + evt = log.Error() + case status >= 400: + evt = log.Warn() + } + + evt. + Int("status", status). + Str("duration", latency.String()). + Str("ip", clientIP). + Str("method", c.Request.Method). + Str("path", path) + + if errs := c.Errors.ByType(gin.ErrorTypePrivate).String(); errs != "" { + evt.Str("errors", strings.TrimSpace(errs)) + } - if param.Latency > time.Minute { - param.Latency = param.Latency - param.Latency%time.Second + evt.Msg("HTTP") } - path := tokenRegexp.ReplaceAllString(param.Path, "token=[masked]") - return fmt.Sprintf("%v |%s %3d %s| %13v | %15s |%s %-7s %s %#v\n%s", - param.TimeStamp.Format(time.RFC3339), - statusColor, param.StatusCode, resetColor, - param.Latency, - param.ClientIP, - methodColor, param.Method, resetColor, - path, - param.ErrorMessage, - ) } type onlyImageFS struct { diff --git a/runner/runner.go b/runner/runner.go index c1ce239c..bee93dc8 100644 --- a/runner/runner.go +++ b/runner/runner.go @@ -3,7 +3,6 @@ package runner import ( "context" "fmt" - "log" "net" "net/http" "os" @@ -13,6 +12,7 @@ import ( "time" "github.com/gotify/server/v2/config" + "github.com/rs/zerolog/log" "golang.org/x/crypto/acme" "golang.org/x/crypto/acme/autocert" ) @@ -33,7 +33,7 @@ func Run(router http.Handler, conf *config.Configuration) error { if conf.Server.SSL.LetsEncrypt.Enabled { applyLetsEncrypt(s, conf) } else if conf.Server.SSL.CertFile == "" || conf.Server.SSL.CertKey == "" { - log.Fatalln("CertFile and CertKey must be set to use HTTPS when LetsEncrypt is disabled, please set GOTIFY_SERVER_SSL_CERTFILE and GOTIFY_SERVER_SSL_CERTKEY") + log.Fatal().Msg("CertFile and CertKey must be set to use HTTPS when LetsEncrypt is disabled, please set GOTIFY_SERVER_SSL_CERTFILE and GOTIFY_SERVER_SSL_CERTKEY") } httpsListener, err := startListening("TLS connection", conf.Server.SSL.ListenAddr, conf.Server.SSL.Port, conf.Server.KeepAlivePeriodSeconds) @@ -53,7 +53,7 @@ func Run(router http.Handler, conf *config.Configuration) error { }() err = <-shutdown - fmt.Println("Shutting down:", err) + log.Info().Err(err).Msg("Shutting down") ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) defer cancel() @@ -85,7 +85,11 @@ func startListening(connectionType, listenAddr string, port, keepAlive int) (net l, err := lc.Listen(context.Background(), network, addr) if err == nil { - fmt.Println("Started listening for", connectionType, "on", l.Addr().Network(), l.Addr().String()) + log.Info(). + Str("connection_type", connectionType). + Str("network", l.Addr().Network()). + Str("address", l.Addr().String()). + Msg("Listen") } return l, err } @@ -105,11 +109,26 @@ type LoggingRoundTripper struct { func (l *LoggingRoundTripper) RoundTrip(r *http.Request) (resp *http.Response, err error) { resp, err = l.RoundTripper.RoundTrip(r) if resp.StatusCode == 429 { - log.Printf("%s Rate Limited: Retry-After %s on %s %s\n", l.Name, resp.Header.Get("Retry-After"), r.Method, r.URL.String()) + log.Warn(). + Str("client", l.Name). + Str("retry_after", resp.Header.Get("Retry-After")). + Str("method", r.Method). + Str("url", r.URL.String()). + Msg("Rate limited") } else if resp.StatusCode >= 400 { - log.Printf("%s Request Failed: Unexpected status code %d on %s %s\n", l.Name, resp.StatusCode, r.Method, r.URL.String()) + log.Warn(). + Str("client", l.Name). + Int("status_code", resp.StatusCode). + Str("method", r.Method). + Str("url", r.URL.String()). + Msg("Request failed: unexpected status code") } else if err != nil { - log.Printf("%s Request Failed: %s on %s %s\n", l.Name, err.Error(), r.Method, r.URL.String()) + log.Warn(). + Str("client", l.Name). + Err(err). + Str("method", r.Method). + Str("url", r.URL.String()). + Msg("Request failed") } return resp, err } @@ -128,7 +147,7 @@ func applyLetsEncrypt(s *http.Server, conf *config.Configuration) { Client: acmeClient, Prompt: func(tosURL string) bool { if !conf.Server.SSL.LetsEncrypt.AcceptTOS { - log.Fatalf("Let's Encrypt TOS must be accepted to use Let's Encrypt, please acknowledge TOS at %s and set GOTIFY_SERVER_SSL_LETSENCRYPT_ACCEPTTOS=true\n", tosURL) + log.Fatal().Str("tos_url", tosURL).Msg("Let's Encrypt TOS must be accepted to use Let's Encrypt, please acknowledge TOS and set GOTIFY_SERVER_SSL_LETSENCRYPT_ACCEPTTOS=true") } return true }, From 21d42cc1c9ed4bc640dc74cf71d8224e9e3b9e7d Mon Sep 17 00:00:00 2001 From: Jannis Mattheis Date: Mon, 18 May 2026 17:30:42 +0200 Subject: [PATCH 2/2] fixup! fix: use zerolog --- app.go | 13 ++++++++++++- 1 file changed, 12 insertions(+), 1 deletion(-) diff --git a/app.go b/app.go index ad208bd5..641e0f4e 100644 --- a/app.go +++ b/app.go @@ -10,6 +10,7 @@ import ( "github.com/gotify/server/v2/model" "github.com/gotify/server/v2/router" "github.com/gotify/server/v2/runner" + "github.com/mattn/go-isatty" "github.com/rs/zerolog" "github.com/rs/zerolog/log" ) @@ -26,7 +27,7 @@ var ( ) func main() { - log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr, TimeFormat: time.RFC3339}) + log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.RFC3339, NoColor: noColor()}) vInfo := &model.VersionInfo{Version: Version, Commit: Commit, BuildDate: BuildDate} mode.Set(Mode) @@ -57,3 +58,13 @@ func main() { os.Exit(1) } } + +func noColor() bool { + // https://no-color.org/ + if os.Getenv("NO_COLOR") == "1" { + return true + } + + isTTY := isatty.IsTerminal(os.Stdout.Fd()) || isatty.IsCygwinTerminal(os.Stderr.Fd()) + return !isTTY +}