Skip to content

Commit 4826817

Browse files
FZambiaFZambia
committed
logging improvements
1 parent 7722f74 commit 4826817

File tree

10 files changed

+52
-24
lines changed

10 files changed

+52
-24
lines changed

‎go.mod

+1-1
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,7 @@ go 1.23.0
55
require (
66
github.com/FZambia/eagle v0.1.0
77
github.com/FZambia/statik v0.1.2-0.20180217151304-b9f012bb2a1b
8-
github.com/centrifugal/centrifuge v0.33.5-0.20241222164738-7c718f40f348
8+
github.com/centrifugal/centrifuge v0.33.5-0.20241224182106-98fa466b7243
99
github.com/centrifugal/protocol v0.13.5-0.20241111155425-6c360178091e
1010
github.com/cristalhq/jwt/v5 v5.4.0
1111
github.com/go-viper/mapstructure/v2 v2.2.1

‎go.sum

+2-2
Original file line numberDiff line numberDiff line change
@@ -6,8 +6,8 @@ github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM=
66
github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw=
77
github.com/cenkalti/backoff/v4 v4.3.0 h1:MyRJ/UdXutAwSAT+s3wNd7MfTIcy71VQueUuFK343L8=
88
github.com/cenkalti/backoff/v4 v4.3.0/go.mod h1:Y3VNntkOUPxTVeUxJ/G5vcM//AlwfmyYozVcomhLiZE=
9-
github.com/centrifugal/centrifuge v0.33.5-0.20241222164738-7c718f40f348 h1:F2UZujbtzJwNxcXt6BoXfXFe5NIUkVjYjlvPnzLf8pE=
10-
github.com/centrifugal/centrifuge v0.33.5-0.20241222164738-7c718f40f348/go.mod h1:hKy1+IjduZJge3EDS3NSSZdTpWd4qhz+AlANNfyv/jE=
9+
github.com/centrifugal/centrifuge v0.33.5-0.20241224182106-98fa466b7243 h1:mb42mNCu+SOmEDdC1QyAGyoc/ItG/0F6YO2A847LV7c=
10+
github.com/centrifugal/centrifuge v0.33.5-0.20241224182106-98fa466b7243/go.mod h1:hKy1+IjduZJge3EDS3NSSZdTpWd4qhz+AlANNfyv/jE=
1111
github.com/centrifugal/protocol v0.13.5-0.20241111155425-6c360178091e h1:+GbuEwJybDuHz6e8S17t/f0I4aTDnZjk37c0aGNFbwc=
1212
github.com/centrifugal/protocol v0.13.5-0.20241111155425-6c360178091e/go.mod h1:7V5vI30VcoxJe4UD87xi7bOsvI0bmEhvbQuMjrFM2L4=
1313
github.com/cespare/xxhash/v2 v2.3.0 h1:UL815xU9SqsFlibzuggzjXhog7bL6oX9BbNZnL2UFvs=

‎internal/consuming/kafka.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -528,7 +528,7 @@ func (pc *partitionConsumer) processRecords(records []*kgo.Record) {
528528
retries++
529529
backoffDuration = getNextBackoffDuration(backoffDuration, retries)
530530
pc.metrics.errorsTotal.WithLabelValues(pc.name).Inc()
531-
log.Error().Err(err).Str("consumer_name", pc.name).Str("topic", record.Topic).Int32("partition", record.Partition).Dur("next_attempt_in", backoffDuration).Msg("error processing consumed record")
531+
log.Error().Err(err).Str("consumer_name", pc.name).Str("topic", record.Topic).Int32("partition", record.Partition).Str("next_attempt_in", backoffDuration.String()).Msg("error processing consumed record")
532532
select {
533533
case <-time.After(backoffDuration):
534534
case <-pc.partitionCtx.Done():

‎internal/logging/logging.go

+42-14
Original file line numberDiff line numberDiff line change
@@ -1,15 +1,16 @@
11
package logging
22

33
import (
4+
"io"
45
"os"
56
"runtime"
67
"strings"
78

89
"github.com/centrifugal/centrifugo/v5/internal/config"
910
"github.com/centrifugal/centrifugo/v5/internal/logutils"
11+
"github.com/mattn/go-isatty"
1012

1113
"github.com/centrifugal/centrifuge"
12-
"github.com/mattn/go-isatty"
1314
"github.com/rs/zerolog"
1415
"github.com/rs/zerolog/log"
1516
)
@@ -80,8 +81,16 @@ func (h *centrifugeLogHandler) readEntries() {
8081
continue
8182
}
8283
if entry.Fields != nil {
84+
if entry.Error != nil {
85+
l = l.Err(entry.Error)
86+
delete(entry.Fields, "error")
87+
}
8388
l.Fields(entry.Fields).Msg(entry.Message)
8489
} else {
90+
if entry.Error != nil {
91+
l = l.Err(entry.Error)
92+
delete(entry.Fields, "error")
93+
}
8594
l.Msg(entry.Message)
8695
}
8796
}
@@ -95,40 +104,59 @@ func (h *centrifugeLogHandler) Handle(entry centrifuge.LogEntry) {
95104
}
96105
}
97106

98-
func configureConsoleWriter() {
107+
func configureConsoleWriter() *zerolog.ConsoleWriter {
99108
if isTerminalAttached() {
100-
log.Logger = log.Output(zerolog.ConsoleWriter{
109+
return &zerolog.ConsoleWriter{
101110
Out: os.Stdout,
102111
TimeFormat: "2006-01-02 15:04:05",
103112
FormatLevel: logutils.ConsoleFormatLevel(),
104113
FormatErrFieldName: logutils.ConsoleFormatErrFieldName(),
105114
FormatErrFieldValue: logutils.ConsoleFormatErrFieldValue(),
106-
})
115+
}
107116
}
117+
return nil
108118
}
109119

110120
func isTerminalAttached() bool {
111121
return isatty.IsTerminal(os.Stdout.Fd()) && runtime.GOOS != "windows"
112122
}
113123

114124
func Setup(cfg config.Config) (centrifuge.LogHandler, func()) {
115-
configureConsoleWriter()
125+
var writers []io.Writer
126+
127+
var file *os.File
128+
if cfg.LogFile != "" {
129+
var err error
130+
file, err = os.OpenFile(cfg.LogFile, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0644)
131+
if err != nil {
132+
log.Fatal().Err(err).Msg("error opening log file")
133+
}
134+
writers = append(writers, file)
135+
} else {
136+
consoleWriter := configureConsoleWriter()
137+
if consoleWriter != nil {
138+
writers = append(writers, consoleWriter)
139+
} else {
140+
writers = append(writers, os.Stderr)
141+
}
142+
}
143+
116144
logLevel, ok := logLevelMatches[strings.ToUpper(cfg.LogLevel)]
117145
if !ok {
118146
logLevel = zerolog.InfoLevel
119147
}
120148
zerolog.SetGlobalLevel(logLevel)
121-
if cfg.LogFile != "" {
122-
f, err := os.OpenFile(cfg.LogFile, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0644)
123-
if err != nil {
124-
log.Fatal().Err(err).Msg("error opening log file")
125-
}
126-
log.Logger = log.Output(f)
127-
return newCentrifugeLogHandler().Handle, func() {
128-
_ = f.Close()
149+
150+
if len(writers) > 0 {
151+
mw := io.MultiWriter(writers...)
152+
log.Logger = log.Output(mw)
153+
}
154+
155+
return newCentrifugeLogHandler().Handle, func() {
156+
if file != nil {
157+
_ = file.Close()
129158
}
130159
}
131-
return newCentrifugeLogHandler().Handle, nil
132160
}
133161

134162
// Enabled checks if a specific logging level is enabled

‎internal/unigrpc/grpc.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -64,7 +64,7 @@ func (s *Service) Consume(req *unistream.ConnectRequest, stream unistream.Centri
6464
if logging.Enabled(logging.DebugLevel) {
6565
log.Debug().Str("transport", transport.Name()).Str("client", c.ID()).Msg("client connection established")
6666
defer func(started time.Time) {
67-
log.Debug().Str("transport", transport.Name()).Str("client", c.ID()).Dur("duration", time.Since(started)).Msg("client connection completed")
67+
log.Debug().Str("transport", transport.Name()).Str("client", c.ID()).Str("duration", time.Since(started).String()).Msg("client connection completed")
6868
}(time.Now())
6969
}
7070

‎internal/unihttpstream/handler.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -73,7 +73,7 @@ func (h Handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
7373
if logging.Enabled(logging.DebugLevel) {
7474
log.Debug().Str("transport", transportName).Str("client", c.ID()).Msg("client connection established")
7575
defer func(started time.Time) {
76-
log.Debug().Str("transport", transportName).Str("client", c.ID()).Dur("duration", time.Since(started)).Msg("client connection completed")
76+
log.Debug().Str("transport", transportName).Str("client", c.ID()).Str("duration", time.Since(started).String()).Msg("client connection completed")
7777
}(time.Now())
7878
}
7979

‎internal/unisse/handler.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -83,7 +83,7 @@ func (h Handler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
8383
if logging.Enabled(logging.DebugLevel) {
8484
log.Debug().Str("transport", transportName).Str("client", c.ID()).Msg("client connection established")
8585
defer func(started time.Time) {
86-
log.Debug().Str("transport", transportName).Str("client", c.ID()).Dur("duration", time.Since(started)).Msg("client connection completed")
86+
log.Debug().Str("transport", transportName).Str("client", c.ID()).Str("duration", time.Since(started).String()).Msg("client connection completed")
8787
}(time.Now())
8888
}
8989

‎internal/uniws/handler.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -142,7 +142,7 @@ func (s *Handler) ServeHTTP(rw http.ResponseWriter, r *http.Request) {
142142
if logging.Enabled(logging.DebugLevel) {
143143
log.Debug().Str("transport", transportName).Str("client", c.ID()).Msg("client connection established")
144144
defer func(started time.Time) {
145-
log.Debug().Str("transport", transportName).Str("client", c.ID()).Dur("duration", time.Since(started)).Msg("client connection completed")
145+
log.Debug().Str("transport", transportName).Str("client", c.ID()).Str("duration", time.Since(started).String()).Msg("client connection completed")
146146
}(time.Now())
147147
}
148148

‎internal/usage/usage.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -141,7 +141,7 @@ func (s *Sender) isDev() bool {
141141
func (s *Sender) Run(ctx context.Context) error {
142142
firstTimeSend := time.Now().Add(initialDelay)
143143
if s.isDev() {
144-
log.Debug().Dur("delay", initialDelay).Msg("usage stats: schedule next send")
144+
log.Debug().Str("delay", initialDelay.String()).Msg("usage stats: schedule next send")
145145
}
146146

147147
// Wait 1/4 of a delay to randomize hourly ticks on different nodes.

‎internal/wt/handler.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -64,7 +64,7 @@ func (s *Handler) ServeHTTP(rw http.ResponseWriter, r *http.Request) {
6464
if logging.Enabled(logging.DebugLevel) {
6565
log.Debug().Str("transport", transportName).Str("client", c.ID()).Msg("client connection established")
6666
defer func(started time.Time) {
67-
log.Debug().Str("transport", transportName).Str("client", c.ID()).Dur("duration", time.Since(started)).Msg("client connection completed")
67+
log.Debug().Str("transport", transportName).Str("client", c.ID()).Str("duration", time.Since(started).String()).Msg("client connection completed")
6868
}(time.Now())
6969
}
7070

0 commit comments

Comments
 (0)