Skip to content

Commit b767b74

Browse files
jmattheisjmattheis
committed
fix: use zerolog
1 parent 5f167eb commit b767b74

9 files changed

Lines changed: 119 additions & 49 deletions

File tree

‎api/oidc.go‎

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,6 @@ import (
77
"errors"
88
"fmt"
99
"io"
10-
"log"
1110
"net/http"
1211
"time"
1312

@@ -17,6 +16,7 @@ import (
1716
"github.com/gotify/server/v2/database"
1817
"github.com/gotify/server/v2/decaymap"
1918
"github.com/gotify/server/v2/model"
19+
"github.com/rs/zerolog/log"
2020
"github.com/zitadel/oidc/v3/pkg/client/rp"
2121
httphelper "github.com/zitadel/oidc/v3/pkg/http"
2222
"github.com/zitadel/oidc/v3/pkg/oidc"
@@ -30,7 +30,7 @@ func NewOIDC(conf *config.Configuration, db *database.GormDatabase, userChangeNo
3030

3131
cookieKey := make([]byte, 32)
3232
if _, err := rand.Read(cookieKey); err != nil {
33-
log.Fatalf("failed to generate OIDC cookie key: %v", err)
33+
log.Fatal().Err(err).Msg("failed to generate OIDC cookie key")
3434
}
3535
cookieHandlerOpt := []httphelper.CookieHandlerOpt{}
3636
if !conf.Server.SecureCookie {
@@ -50,7 +50,7 @@ func NewOIDC(conf *config.Configuration, db *database.GormDatabase, userChangeNo
5050
opts...,
5151
)
5252
if err != nil {
53-
log.Fatalf("failed to initialize OIDC provider: %v", err)
53+
log.Fatal().Err(err).Msg("failed to initialize OIDC provider")
5454
}
5555

5656
return &OIDCAPI{
@@ -415,7 +415,7 @@ func (a *OIDCAPI) resolveUser(info *oidc.UserInfo) (*model.User, int, error) {
415415
return nil, http.StatusInternalServerError, fmt.Errorf("failed to create user: %w", err)
416416
}
417417
if err := a.UserChangeNotifier.fireUserAdded(user.ID); err != nil {
418-
log.Printf("Could not notify user change: %v\n", err)
418+
log.Error().Err(err).Uint("user_id", user.ID).Msg("Could not notify user change")
419419
}
420420
}
421421
return user, 0, nil

‎api/stream/client.go‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,11 +1,11 @@
11
package stream
22

33
import (
4-
"fmt"
54
"time"
65

76
"github.com/gorilla/websocket"
87
"github.com/gotify/server/v2/model"
8+
"github.com/rs/zerolog/log"
99
)
1010

1111
const (
@@ -115,5 +115,5 @@ func printWebSocketError(prefix string, err error) {
115115
return
116116
}
117117

118-
fmt.Println("WebSocket:", prefix, err)
118+
log.Warn().Err(err).Msgf("WebSocket %s", prefix)
119119
}

‎app.go‎

Lines changed: 17 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -1,7 +1,6 @@
11
package main
22

33
import (
4-
"fmt"
54
"os"
65
"time"
76

@@ -11,6 +10,9 @@ import (
1110
"github.com/gotify/server/v2/model"
1211
"github.com/gotify/server/v2/router"
1312
"github.com/gotify/server/v2/runner"
13+
"github.com/mattn/go-isatty"
14+
"github.com/rs/zerolog"
15+
"github.com/rs/zerolog/log"
1416
)
1517

1618
var (
@@ -25,10 +27,12 @@ var (
2527
)
2628

2729
func main() {
30+
log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stdout, TimeFormat: time.RFC3339, NoColor: noColor()})
31+
2832
vInfo := &model.VersionInfo{Version: Version, Commit: Commit, BuildDate: BuildDate}
2933
mode.Set(Mode)
3034

31-
fmt.Println("Starting Gotify version", vInfo.Version+"@"+BuildDate)
35+
log.Info().Str("version", vInfo.Version).Str("build_date", BuildDate).Msg("Gotify")
3236
conf := config.Get()
3337

3438
if conf.PluginsDir != "" {
@@ -50,7 +54,17 @@ func main() {
5054
defer closeable()
5155

5256
if err := runner.Run(engine, conf); err != nil {
53-
fmt.Println("Server error: ", err)
57+
log.Error().Err(err).Msg("Server error")
5458
os.Exit(1)
5559
}
5660
}
61+
62+
func noColor() bool {
63+
// https://no-color.org/
64+
if os.Getenv("NO_COLOR") == "1" {
65+
return true
66+
}
67+
68+
isTTY := isatty.IsTerminal(os.Stdout.Fd()) || isatty.IsCygwinTerminal(os.Stderr.Fd())
69+
return !isTTY
70+
}

‎database/database.go‎

Lines changed: 10 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -3,8 +3,6 @@ package database
33
import (
44
"database/sql"
55
"errors"
6-
"fmt"
7-
"log"
86
"math"
97
"os"
108
"path/filepath"
@@ -14,20 +12,28 @@ import (
1412
"github.com/gotify/server/v2/fracdex"
1513
"github.com/gotify/server/v2/model"
1614
"github.com/mattn/go-isatty"
15+
"github.com/rs/zerolog/log"
1716
"gorm.io/driver/mysql"
1817
"gorm.io/driver/postgres"
1918
"gorm.io/driver/sqlite"
2019
"gorm.io/gorm"
2120
"gorm.io/gorm/logger"
2221
)
2322

23+
// gormLogWriter routes gorm logger output through zerolog.
24+
type gormLogWriter struct{}
25+
26+
func (gormLogWriter) Printf(format string, args ...interface{}) {
27+
log.Warn().Str("component", "gorm").Msgf(format, args...)
28+
}
29+
2430
var mkdirAll = os.MkdirAll
2531

2632
// New creates a new wrapper for the gorm database framework.
2733
func New(dialect, connection, defaultUser, defaultPass string, strength int, createDefaultUserIfNotExist bool, now func() time.Time) (*GormDatabase, error) {
2834
createDirectoryIfSqlite(dialect, connection)
2935

30-
dbLogger := logger.New(log.New(os.Stderr, "\r\n", log.LstdFlags), logger.Config{
36+
dbLogger := logger.New(gormLogWriter{}, logger.Config{
3137
SlowThreshold: 200 * time.Millisecond,
3238
LogLevel: logger.Warn,
3339
IgnoreRecordNotFoundError: true,
@@ -131,7 +137,7 @@ func fillMissingSortKeys(db *gorm.DB) error {
131137
if err := db.Order("user_id, sort_key, id ASC").Find(&apps).Error; err != nil && err != gorm.ErrRecordNotFound {
132138
return err
133139
}
134-
fmt.Println("Migrating", len(apps), "application sort keys")
140+
log.Info().Int("count", len(apps)).Msg("Migrating application sort keys")
135141

136142
sortKey := ""
137143
currentUser := uint(math.MaxUint)

‎go.mod‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ require (
1313
github.com/jinzhu/configor v1.2.2
1414
github.com/mattn/go-isatty v0.0.20
1515
github.com/robfig/cron v1.2.0
16+
github.com/rs/zerolog v1.35.1
1617
github.com/stretchr/testify v1.11.1
1718
github.com/zitadel/oidc/v3 v3.45.5
1819
golang.org/x/crypto v0.48.0
@@ -53,6 +54,7 @@ require (
5354
github.com/json-iterator/go v1.1.12 // indirect
5455
github.com/klauspost/cpuid/v2 v2.3.0 // indirect
5556
github.com/leodido/go-urn v1.4.0 // indirect
57+
github.com/mattn/go-colorable v0.1.14 // indirect
5658
github.com/mattn/go-sqlite3 v1.14.32 // indirect
5759
github.com/modern-go/concurrent v0.0.0-20180306012644-bacd9c7ef1dd // indirect
5860
github.com/modern-go/reflect2 v1.0.2 // indirect

‎go.sum‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -100,6 +100,8 @@ github.com/kr/text v0.2.0 h1:5Nx0Ya0ZqY2ygV366QzturHI13Jq95ApcVaJBhpS+AY=
100100
github.com/kr/text v0.2.0/go.mod h1:eLer722TekiGuMkidMxC/pM04lWEeraHUUmBw8l2grE=
101101
github.com/leodido/go-urn v1.4.0 h1:WT9HwE9SGECu3lg4d/dIA+jxlljEa1/ffXKmRjqdmIQ=
102102
github.com/leodido/go-urn v1.4.0/go.mod h1:bvxc+MVxLKB4z00jd1z+Dvzr47oO32F/QSNjSBOlFxI=
103+
github.com/mattn/go-colorable v0.1.14 h1:9A9LHSqF/7dyVVX6g0U9cwm9pG3kP9gSzcuIPHPsaIE=
104+
github.com/mattn/go-colorable v0.1.14/go.mod h1:6LmQG8QLFO4G5z1gPvYEzlUgJ2wF+stgPZH1UqBm1s8=
103105
github.com/mattn/go-isatty v0.0.4/go.mod h1:M+lRXTBqGeGNdLjl/ufCoiOlB5xdOkqRJdNxMWT7Zi4=
104106
github.com/mattn/go-isatty v0.0.20 h1:xfD0iDuEKnDkl03q4limB+vH+GxLEtL/jb4xVJSWWEY=
105107
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
129131
github.com/rogpeppe/go-internal v1.14.1/go.mod h1:MaRKkUm5W0goXpeCfT7UZI6fk/L7L7so1lCWt35ZSgc=
130132
github.com/rs/cors v1.11.1 h1:eU3gRzXLRK57F5rKMGMZURNdIG4EoAmX8k94r9wXWHA=
131133
github.com/rs/cors v1.11.1/go.mod h1:XyqrcTp5zjWr1wsJ8PIRZssZ8b/WMcMf71DJnit4EMU=
134+
github.com/rs/zerolog v1.35.1 h1:m7xQeoiLIiV0BCEY4Hs+j2NG4Gp2o2KPKmhnnLiazKI=
135+
github.com/rs/zerolog v1.35.1/go.mod h1:EjML9kdfa/RMA7h/6z6pYmq1ykOuA8/mjWaEvGI+jcw=
132136
github.com/sirupsen/logrus v1.9.4 h1:TsZE7l11zFCLZnZ+teH4Umoq5BhEIfIzfRDZ1Uzql2w=
133137
github.com/sirupsen/logrus v1.9.4/go.mod h1:ftWc9WdOfJ0a92nsE2jF5u5ZwH8Bv2zdeOC42RjbV2g=
134138
github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=

‎plugin/manager.go‎

Lines changed: 8 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,6 @@ import (
66
"encoding/json"
77
"errors"
88
"fmt"
9-
"log"
109
"os"
1110
"path/filepath"
1211
"plugin"
@@ -18,6 +17,7 @@ import (
1817
"github.com/gotify/server/v2/auth"
1918
"github.com/gotify/server/v2/model"
2019
"github.com/gotify/server/v2/plugin/compat"
20+
"github.com/rs/zerolog/log"
2121
"gopkg.in/yaml.v3"
2222
)
2323

@@ -155,7 +155,7 @@ func (m *Manager) PluginInfo(modulePath string) compat.Info {
155155
if p, ok := m.plugins[modulePath]; ok {
156156
return p.PluginInfo()
157157
}
158-
fmt.Println("Could not get plugin info for", modulePath)
158+
log.Warn().Str("module_path", modulePath).Msg("Could not get plugin info")
159159
return compat.Info{
160160
Name: "UNKNOWN",
161161
ModulePath: modulePath,
@@ -237,7 +237,7 @@ func (m *Manager) loadPlugins(directory string) error {
237237

238238
pluginPath := filepath.Join(directory, "./", name)
239239

240-
fmt.Println("Loading plugin", pluginPath)
240+
log.Info().Str("path", pluginPath).Msg("Loading plugin")
241241
pRaw, err := plugin.Open(pluginPath)
242242
if err != nil {
243243
return pluginFileLoadError{name, err}
@@ -355,7 +355,7 @@ func (m *Manager) initializeSingleUserPlugin(userCtx compat.UserContext, p compa
355355
if err != nil {
356356
// Single user plugin cannot be enabled
357357
// Don't panic, disable for now and wait for user to update config
358-
log.Printf("Plugin initialize failed for user %s: %s. Disabling now...", userCtx.Name, err.Error())
358+
log.Warn().Err(err).Str("user", userCtx.Name).Msg("Plugin initialize failed, disabling now")
359359
pluginConf.Enabled = false
360360
m.db.UpdatePluginConf(pluginConf)
361361
}
@@ -374,7 +374,10 @@ func (m *Manager) initializeConfigurerForSingleUserPlugin(instance compat.Plugin
374374
if yaml.Unmarshal(pluginConf.Config, c) != nil || instance.ValidateAndSetConfig(c) != nil {
375375
pluginConf.Enabled = false
376376

377-
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)
377+
log.Warn().
378+
Str("module_path", pluginConf.ModulePath).
379+
Uint("user_id", pluginConf.UserID).
380+
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.")
378381
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")
379382

380383
d, _ := yaml.Marshal(c)

‎router/router.go‎

Lines changed: 45 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,7 @@ import (
2222
"github.com/gotify/server/v2/model"
2323
"github.com/gotify/server/v2/plugin"
2424
"github.com/gotify/server/v2/ui"
25+
"github.com/rs/zerolog/log"
2526
)
2627

2728
// Create creates the gin engine with all routes.
@@ -40,7 +41,7 @@ func Create(db *database.GormDatabase, vInfo *model.VersionInfo, conf *config.Co
4041
}
4142
})
4243

43-
g.Use(gin.LoggerWithFormatter(logFormatter), gin.Recovery(), gerror.Handler(), location.Default())
44+
g.Use(accessLogger(), gin.Recovery(), gerror.Handler(), location.Default())
4445
g.NoRoute(gerror.NotFound())
4546

4647
if conf.Server.SSL.Enabled && conf.Server.SSL.RedirectToHTTPS {
@@ -249,31 +250,52 @@ func Create(db *database.GormDatabase, vInfo *model.VersionInfo, conf *config.Co
249250

250251
var tokenRegexp = regexp.MustCompile("token=[^&]+")
251252

252-
func logFormatter(param gin.LogFormatterParams) string {
253-
if (param.ClientIP == "127.0.0.1" || param.ClientIP == "::1") && param.Path == "/health" {
254-
return ""
255-
}
253+
func accessLogger() gin.HandlerFunc {
254+
return func(c *gin.Context) {
255+
start := time.Now()
256256

257-
var statusColor, methodColor, resetColor string
258-
if param.IsOutputColor() {
259-
statusColor = param.StatusCodeColor()
260-
methodColor = param.MethodColor()
261-
resetColor = param.ResetColor()
262-
}
257+
rawQuery := c.Request.URL.RawQuery
258+
path := c.Request.URL.Path
259+
260+
c.Next()
261+
262+
clientIP := c.ClientIP()
263+
if (clientIP == "127.0.0.1" || clientIP == "::1") && path == "/health" {
264+
return
265+
}
266+
267+
if rawQuery != "" {
268+
path = path + "?" + rawQuery
269+
}
270+
path = tokenRegexp.ReplaceAllString(path, "token=[masked]")
271+
272+
latency := time.Since(start)
273+
if latency > time.Minute {
274+
latency = latency - latency%time.Second
275+
}
276+
277+
status := c.Writer.Status()
278+
evt := log.Info()
279+
switch {
280+
case status >= 500:
281+
evt = log.Error()
282+
case status >= 400:
283+
evt = log.Warn()
284+
}
285+
286+
evt.
287+
Int("status", status).
288+
Str("duration", latency.String()).
289+
Str("ip", clientIP).
290+
Str("method", c.Request.Method).
291+
Str("path", path)
292+
293+
if errs := c.Errors.ByType(gin.ErrorTypePrivate).String(); errs != "" {
294+
evt.Str("errors", strings.TrimSpace(errs))
295+
}
263296

264-
if param.Latency > time.Minute {
265-
param.Latency = param.Latency - param.Latency%time.Second
297+
evt.Msg("HTTP")
266298
}
267-
path := tokenRegexp.ReplaceAllString(param.Path, "token=[masked]")
268-
return fmt.Sprintf("%v |%s %3d %s| %13v | %15s |%s %-7s %s %#v\n%s",
269-
param.TimeStamp.Format(time.RFC3339),
270-
statusColor, param.StatusCode, resetColor,
271-
param.Latency,
272-
param.ClientIP,
273-
methodColor, param.Method, resetColor,
274-
path,
275-
param.ErrorMessage,
276-
)
277299
}
278300

279301
type onlyImageFS struct {

0 commit comments

Comments
 (0)