More improvements to logging

Signed-off-by: Steffen Vogel <post@steffenvogel.de>
This commit is contained in:
Steffen Vogel
2023-06-23 21:22:09 +02:00
parent 241f1d0ef1
commit ff9a261619
21 changed files with 321 additions and 286 deletions

View File

@@ -87,7 +87,7 @@ func daemonRun(_ *cobra.Command, args []string, cfg *config.Config) {
if logger.Core().Enabled(zap.DebugLevel) {
logger = logger.Named("config")
logger.Debug("Loaded configuration:")
logger.DebugV(1, "Loaded configuration:")
wr := tty.NewIndenter(&zapio.Writer{
Log: logger.Logger,
Level: zap.DebugLevel - 1,

3
go.mod
View File

@@ -24,9 +24,9 @@ require (
github.com/miekg/dns v1.1.54
github.com/mitchellh/mapstructure v1.5.0
github.com/pion/ice/v2 v2.3.8
github.com/pion/logging v0.2.2
github.com/pion/randutil v0.1.0
github.com/pion/stun v0.6.0
github.com/pion/zapion v0.0.0-20230529023309-3bb052e9490b
github.com/spf13/cobra v1.7.0
github.com/spf13/pflag v1.0.5
github.com/vishvananda/netlink v1.2.1-beta.2.0.20221214185949-378a404a26f0
@@ -75,7 +75,6 @@ require (
github.com/mitchellh/copystructure v1.2.0 // indirect
github.com/mitchellh/reflectwalk v1.0.2 // indirect
github.com/pion/dtls/v2 v2.2.7 // indirect
github.com/pion/logging v0.2.2 // indirect
github.com/pion/mdns v0.0.7 // indirect
github.com/pion/transport/v2 v2.2.1 // indirect
github.com/pion/turn/v2 v2.1.0 // indirect

14
go.sum
View File

@@ -20,7 +20,6 @@ github.com/armon/circbuf v0.0.0-20150827004946-bbbad097214e/go.mod h1:3U/XgcO3hC
github.com/armon/go-metrics v0.0.0-20180917152333-f0300d1749da/go.mod h1:Q73ZrmVTwzkszR9V5SSuryQ31EELlFMUz1kKyl939pY=
github.com/armon/go-radix v0.0.0-20180808171621-7fddfc383310/go.mod h1:ufUuZ+zHj4x4TnLV4JWEpy2hxWSpsRywHrMgIH9cCH8=
github.com/benbjohnson/clock v1.1.0 h1:Q92kusRqC1XV2MjkWETPvjJVqKetz1OzxZB7mHJLju8=
github.com/benbjohnson/clock v1.1.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA=
github.com/beorn7/perks v0.0.0-20180321164747-3a771d992973/go.mod h1:Dwedo/Wpr24TaqPxmxbtue+5NUziq4I4S80YR8gNf3Q=
github.com/beorn7/perks v1.0.0/go.mod h1:KWe93zE9D1o94FZ5RNwFwVgaQK1VOXiVxmqh+CedLV8=
github.com/bgentry/speakeasy v0.1.0/go.mod h1:+zsyZBPWlz7T6j88CTgSN5bM796AkVf0kBD4zp0CCIs=
@@ -261,8 +260,6 @@ github.com/pion/transport/v2 v2.2.1 h1:7qYnCBlpgSJNYMbLCKuSY9KbQdBFoETvPNETv0y4N
github.com/pion/transport/v2 v2.2.1/go.mod h1:cXXWavvCnFF6McHTft3DWS9iic2Mftcz1Aq29pGcU5g=
github.com/pion/turn/v2 v2.1.0 h1:5wGHSgGhJhP/RpabkUb/T9PdsAjkGLS6toYz5HNzoSI=
github.com/pion/turn/v2 v2.1.0/go.mod h1:yrT5XbXSGX1VFSF31A3c1kCNB5bBZgk/uu5LET162qs=
github.com/pion/zapion v0.0.0-20230529023309-3bb052e9490b h1:JMu33z7f/aBCrOOX42dl/3xGE59GEOrbeJ+Q5gIANrI=
github.com/pion/zapion v0.0.0-20230529023309-3bb052e9490b/go.mod h1:o63uQG0FvxFu+DJgxOhw/j/RIz7o45w5L4LX4v+gxPg=
github.com/pkg/errors v0.8.0/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
github.com/pkg/errors v0.8.1 h1:iURUrRGxPUNPdy5/HRSm+Yj6okJ6UtLINN0Q9M4+h3I=
github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
@@ -334,21 +331,17 @@ github.com/vishvananda/netns v0.0.4/go.mod h1:SpkAiCQRtJ6TvvxPnOSyH3BMl6unz3xZla
github.com/x448/float16 v0.8.4 h1:qLwI1I70+NjRFUR3zs1JPUCgaCXSh3SW62uAKT1mSBM=
github.com/x448/float16 v0.8.4/go.mod h1:14CWIYCyZA/cWjXOioeEpHeN/83MdbZDRQHoFcYsOfg=
github.com/xiang90/probing v0.0.0-20190116061207-43a291ad63a2/go.mod h1:UETIi67q53MR2AWcXfiuqkDkRtnGDLqkBTpCHuJHxtU=
github.com/yuin/goldmark v1.3.5/go.mod h1:mwnBkeHKe2W/ZEtQ+71ViKU8L12m81fl3OWwC1Zlc8k=
github.com/yuin/goldmark v1.4.13/go.mod h1:6yULJ656Px+3vBD8DxQVa3kxgyrAnzto9xy5taEt/CY=
go.etcd.io/bbolt v1.3.2/go.mod h1:IbVyRI1SCnLcuJnV2u8VeU0CEYM7e686BmAb1XKL+uU=
go.opencensus.io v0.21.0/go.mod h1:mSImk1erAIZhrmZN+AvHh14ztQfjbGwt4TtuofqLduU=
go.opencensus.io v0.22.0/go.mod h1:+kGneAE2xo2IficOXnaByMWTGM9T73dGwxeWcUqIpI8=
go.starlark.net v0.0.0-20220816155156-cfacd8902214/go.mod h1:VZcBMdr3cT3PnBoWunTabuSEXwVAH+ZJ5zxfs3AdASk=
go.uber.org/atomic v1.4.0/go.mod h1:gD2HeocX3+yG+ygLZcrzQJaqmWj9AIm7n08wl/qW/PE=
go.uber.org/atomic v1.7.0/go.mod h1:fEN4uk6kAWBTFdckzkM89CLk9XfWZrxpCo0nPH17wJc=
go.uber.org/atomic v1.11.0 h1:ZvwS0R+56ePWxUNi+Atn9dWONBPp/AUETXlHW0DxSjE=
go.uber.org/atomic v1.11.0/go.mod h1:LUxbIzbOniOlMKjJjyPfpl4v+PKK2cNJn91OQbhoJI0=
go.uber.org/goleak v1.1.11/go.mod h1:cwTWslyiVhfpKIDGSZEM2HlOvcqm+tG4zioyIeLoqMQ=
go.uber.org/goleak v1.2.1 h1:NBol2c7O1ZokfZ0LEU9K6Whx/KnwvepVetCUhtKja4A=
go.uber.org/goleak v1.2.1/go.mod h1:qlT2yGI9QafXHhZZLxlSuNsMw3FFLxBr+tBRlmO1xH4=
go.uber.org/multierr v1.1.0/go.mod h1:wR5kodmAFQ0UK8QlbwjlSNy0Z68gJhDJUG5sjR94q/0=
go.uber.org/multierr v1.6.0/go.mod h1:cdWPpRnG4AhwMwsgIHip0KRBQjJy5kYEpYjJxpXp9iU=
go.uber.org/multierr v1.11.0 h1:blXXJkSxSSfBVBlC76pxqeO+LN3aDfLQo+309xJstO0=
go.uber.org/multierr v1.11.0/go.mod h1:20+QtiLqy0Nd6FdQB9TLXag12DsQkrbs3htMFfDN80Y=
go.uber.org/zap v1.10.0/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q=
@@ -363,7 +356,6 @@ golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACk
golang.org/x/crypto v0.0.0-20190510104115-cbcb75029529/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI=
golang.org/x/crypto v0.0.0-20190605123033-f99c8df09eb5/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI=
golang.org/x/crypto v0.0.0-20190923035154-9ee001bba392/go.mod h1:/lpIB1dKB+9EgE3H3cr1v9wB50oz8l4C4h62xy7jSTY=
golang.org/x/crypto v0.0.0-20191011191535-87dc89f01550/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI=
golang.org/x/crypto v0.0.0-20210921155107-089bfa567519/go.mod h1:GvvjBRRGRdwPK5ydBHafDWAxML/pGHZbMvKqRZ5+Abc=
golang.org/x/crypto v0.8.0/go.mod h1:mRqEX+O9/h5TFCrQhkgjo2yKi0yYA+9ecGkdQoHrywE=
golang.org/x/crypto v0.9.0/go.mod h1:yrmDGqONDYtNj3tH8X9dzUun2m2lzPa9ngI6/RUPGR0=
@@ -389,7 +381,6 @@ golang.org/x/mobile v0.0.0-20190312151609-d3739f865fa6/go.mod h1:z+o9i4GpDbdi3rU
golang.org/x/mobile v0.0.0-20190719004257-d2bd2a29d028/go.mod h1:E/iHnbuqvinMTCcRqshq8CkpyQDoeVncDDYHnLhea+o=
golang.org/x/mod v0.0.0-20190513183733-4bf6d317e70e/go.mod h1:mXi4GBBbnImb6dmsKGUJ2LatrhH/nqhxcFungHvyanc=
golang.org/x/mod v0.1.0/go.mod h1:0QHyrYULN0/3qlju5TqG8bIK38QM8yzMo5ekMj3DlcY=
golang.org/x/mod v0.4.2/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA=
golang.org/x/mod v0.6.0-dev.0.20220419223038-86c51ed26bb4/go.mod h1:jJ57K6gSWd91VN4djpZkiMVwK6gcyfeH4XE8wZrZaV4=
golang.org/x/mod v0.8.0/go.mod h1:iBbtSCu2XBx23ZKBPSOrRkjjQPZFPuis4dIYUhu/chs=
golang.org/x/mod v0.10.0 h1:lFO9qtOdlre5W1jxS3r/4szv2/6iXxScdzjoBMXNhYk=
@@ -411,7 +402,6 @@ golang.org/x/net v0.0.0-20190620200207-3b0461eec859/go.mod h1:z5CRVTTTmAJ677TzLL
golang.org/x/net v0.0.0-20190923162816-aa69164e4478/go.mod h1:z5CRVTTTmAJ677TzLLGU+0bjPO0LkuOLi4/5GtJWs/s=
golang.org/x/net v0.0.0-20210226172049-e18ecbb05110/go.mod h1:m0MpNAwzfU5UDzcl9v0D8zg8gWTRqZa9RBIspLL5mdg=
golang.org/x/net v0.0.0-20210316092652-d523dce5a7f4/go.mod h1:RBQZq4jEuRlivfhVLdyRGr576XBO4/greRjx4P4O3yc=
golang.org/x/net v0.0.0-20210405180319-a5a99cb37ef4/go.mod h1:p54w0d4576C0XHj96bSt6lcn1PtDYWL6XObtHCRCNQM=
golang.org/x/net v0.0.0-20220722155237-a158d28d115b/go.mod h1:XRhObCWvk6IyKnWLug+ECip1KBveYUHfp+8e9klMJ9c=
golang.org/x/net v0.1.0/go.mod h1:Cx3nUiGt4eDBEyega/BKRp+/AlGL8hYe7U9odMt2Cco=
golang.org/x/net v0.5.0/go.mod h1:DivGGAXEgPSlEBzxGzZI+ZLohi+xUj054jfeKui00ws=
@@ -451,8 +441,6 @@ golang.org/x/sys v0.0.0-20190924154521-2837fb4f24fe/go.mod h1:h1NjWce9XRLGQEsW7w
golang.org/x/sys v0.0.0-20200217220822-9197077df867/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20210315160823-c6e025ad8005/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20210330210617-4fbd30eecc44/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20210510120138-977fb7262007/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20210906170528-6f6e22806c34/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20211117180635-dee7805ff2e1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
@@ -512,13 +500,11 @@ golang.org/x/tools v0.0.0-20190911174233-4f2ddba30aff/go.mod h1:b+2E5dAYhXwXZwtn
golang.org/x/tools v0.0.0-20191012152004-8de300cfc20a/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
golang.org/x/tools v0.0.0-20191112195655-aa38f8e97acc/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
golang.org/x/tools v0.0.0-20191119224855-298f0cb1881e/go.mod h1:b+2E5dAYhXwXZwtnZ6UAqBI28+e2cm9otk0dWdXHAEo=
golang.org/x/tools v0.1.5/go.mod h1:o0xws9oXOQQZyjljx8fwUC0k7L1pTE6eaCbjGeHmOkk=
golang.org/x/tools v0.1.12/go.mod h1:hNGJHUnrk76NpqgfD5Aqm5Crs+Hm0VOH/i9J2+nxYbc=
golang.org/x/tools v0.6.0/go.mod h1:Xwgl3UAJ/d3gWutnCtw505GrjyAbvKui8lOU390QaIU=
golang.org/x/tools v0.9.3 h1:Gn1I8+64MsuTb/HpH+LmQtNas23LhUVr3rYZ0eKuaMM=
golang.org/x/tools v0.9.3/go.mod h1:owI94Op576fPu3cIGQeHs3joujW/2Oc6MtlxbF5dfNc=
golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
golang.org/x/xerrors v0.0.0-20191011141410-1b5146add898/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
golang.org/x/xerrors v0.0.0-20191204190536-9bdfabe68543/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
golang.org/x/xerrors v0.0.0-20200804184101-5ec99f83aff1/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
golang.zx2c4.com/wintun v0.0.0-20230126152724-0fa3db229ce2 h1:B82qJJgjvYKsXS9jeunTOisW56dUokqW/FOteYJJ/yg=

View File

@@ -10,7 +10,6 @@ import (
"path/filepath"
"github.com/pion/ice/v2"
"github.com/pion/zapion"
"go.uber.org/zap"
"github.com/stv0g/cunicu/pkg/config"
@@ -69,7 +68,7 @@ func (i *Interface) setupUDPMux() error {
return true
}
i.mux, err = icex.NewMultiUDPMuxWithListen(listen, ifFilter, nil, i.Settings.ICE.NetworkTypes, false)
i.mux, err = icex.NewMultiUDPMuxWithListen(listen, ifFilter, nil, i.Settings.ICE.NetworkTypes, false, i.logger)
if err != nil {
return fmt.Errorf("failed to create multi UDP mux: %w", err)
}
@@ -90,22 +89,13 @@ func (i *Interface) setupUniversalUDPMux() error {
i.muxConns = append(i.muxConns, filteredConn)
lf := zapion.ZapFactory{
BaseLogger: log.Global.Named("ice").Logger,
}
var stunLogger *log.Logger
if i.logger.Core().Enabled(zap.DebugLevel) {
stunLogger = i.logger.Named("stun_conn")
}
stunConn := filteredConn.AddPacketReadHandlerConn(&netx.STUNPacketHandler{
Logger: stunLogger,
Logger: i.logger.Named("stun_conn"),
})
i.muxSrflx = ice.NewUniversalUDPMuxDefault(ice.UniversalUDPMuxParams{
UDPConn: stunConn,
Logger: lf.NewLogger("udpmux"),
Logger: log.NewPionLogger(i.logger, "ice.udpmux"),
})
lAddr := udpConn.LocalAddr().(*net.UDPAddr) //nolint:forcetypeassert

View File

@@ -14,7 +14,6 @@ import (
"github.com/cenkalti/backoff/v4"
"github.com/pion/ice/v2"
"github.com/pion/zapion"
"go.uber.org/zap"
"google.golang.org/grpc/codes"
"google.golang.org/grpc/status"
@@ -343,9 +342,7 @@ func (p *Peer) createAgent() error {
acfg.UDPMux = p.Interface.mux
acfg.UDPMuxSrflx = p.Interface.muxSrflx
acfg.LoggerFactory = &zapion.ZapFactory{
BaseLogger: p.logger.Named("ice").Logger,
}
acfg.LoggerFactory = log.NewPionLoggerFactory(p.logger)
p.localCredentials = epdiscproto.NewCredentials()
p.remoteCredentials = nil

View File

@@ -7,14 +7,13 @@ import (
"net"
"github.com/pion/ice/v2"
"github.com/pion/zapion"
"github.com/stv0g/cunicu/pkg/log"
)
type PacketListener interface{}
func NewMultiUDPMuxWithListen(listen func(ip net.IP) (net.PacketConn, error), interfaceFilter func(string) bool, ipFilter func(net.IP) bool, networkTypes []NetworkType, includeLoopback bool) (*ice.MultiUDPMuxDefault, error) {
func NewMultiUDPMuxWithListen(listen func(ip net.IP) (net.PacketConn, error), interfaceFilter func(string) bool, ipFilter func(net.IP) bool, networkTypes []NetworkType, includeLoopback bool, logger *log.Logger) (*ice.MultiUDPMuxDefault, error) {
ips, err := localInterfaces(interfaceFilter, ipFilter, networkTypes, includeLoopback)
if err != nil {
return nil, err
@@ -38,14 +37,10 @@ func NewMultiUDPMuxWithListen(listen func(ip net.IP) (net.PacketConn, error), in
return nil, err
}
lf := zapion.ZapFactory{
BaseLogger: log.Global.Named("ice").Logger,
}
muxes := make([]ice.UDPMux, 0, len(conns))
for _, conn := range conns {
mux := ice.NewUDPMuxDefault(ice.UDPMuxParams{
Logger: lf.NewLogger("udpmux"),
Logger: log.NewPionLogger(logger, "ice.udpmux"),
UDPConn: conn,
})
muxes = append(muxes, mux)

View File

@@ -52,14 +52,14 @@ var (
ColorCaller = tty.Color256(15)
ColorLevelUnknown = tty.Color256(1)
ColorLevelDebugVerbose = tty.Color256(138)
ColorLevels = map[zapcore.Level]string{
zapcore.DebugLevel: tty.Color256(138),
zapcore.InfoLevel: tty.Color256(12), // Blue
zapcore.WarnLevel: tty.Color256(208), // Yellow
zapcore.ErrorLevel: tty.Color256(124), // Red
zapcore.DPanicLevel: tty.Color256(196), // Red
zapcore.PanicLevel: tty.Color256(196), // Red
zapcore.FatalLevel: tty.Color256(196), // Red
ColorLevels = map[Level]string{
DebugLevel: tty.Color256(138),
InfoLevel: tty.Color256(12), // Blue
WarnLevel: tty.Color256(208), // Yellow
ErrorLevel: tty.Color256(124), // Red
DPanicLevel: tty.Color256(196), // Red
PanicLevel: tty.Color256(196), // Red
FatalLevel: tty.Color256(196), // Red
}
)
@@ -68,10 +68,10 @@ func ResetWidths() {
widthName.Store(0)
}
func ColorLevel(l zapcore.Level) string {
func ColorLevel(l Level) string {
if color, ok := ColorLevels[l]; ok {
return color
} else if l < zapcore.DebugLevel {
} else if l < DebugLevel {
return ColorLevelDebugVerbose
}
@@ -84,7 +84,7 @@ type encoderConfig struct {
ColorStacktrace string
ColorName string
ColorCaller string
ColorLevel func(lvl zapcore.Level) string
ColorLevel func(lvl Level) string
Function bool
Message bool
@@ -661,7 +661,7 @@ func (e *encoder) EncodeEntry(ent zapcore.Entry, fields []zapcore.Field) (*buffe
f.addSeparator(e.fieldSeparator)
if e.ColorLevel != nil {
f.colored(e.ColorLevel(ent.Level), cb)
f.colored(e.ColorLevel(Level(ent.Level)), cb)
} else {
cb()
}
@@ -702,7 +702,7 @@ func (e *encoder) EncodeEntry(ent zapcore.Entry, fields []zapcore.Field) (*buffe
// Add the message itself.
if f.Message {
f.addSeparator(e.fieldSeparator)
f.AppendString(ent.Message)
f.buf.AppendString(ent.Message)
}
// Add context

View File

@@ -524,7 +524,7 @@ var _ = Context("encoder", func() {
nil,
),
Entry("EncodeLevel with color",
tty.Mods("debug", ColorLevels[zapcore.DebugLevel]),
tty.Mods("debug", ColorLevels[DebugLevel]),
encoderConfig{Level: true, EncodeLevel: zapcore.LowercaseLevelEncoder, ColorLevel: ColorLevel},
nil,
nil,

View File

@@ -10,7 +10,6 @@ package log
import (
"errors"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
@@ -25,24 +24,6 @@ func NewFilteredCore(next zapcore.Core, rule *AtomicFilterRule) zapcore.Core {
return &filteringCore{next, rule}
}
// CheckAnyLevel determines whether at least one log level isn't filtered-out by the logger.
func CheckAnyLevel(logger *zap.Logger) bool {
for lvl := LevelMin; lvl <= LevelMax; lvl++ {
if lvl >= zapcore.PanicLevel {
continue // Panic and fatal cannot be skipped
}
if logger.Check(lvl, "") != nil {
return true
}
}
return false
}
// CheckLevel determines whether a specific log level would produce log or not.
func CheckLevel(logger *zap.Logger, level zapcore.Level) bool {
return logger.Check(level, "") != nil
}
type filteringCore struct {
next zapcore.Core
rule *AtomicFilterRule
@@ -52,9 +33,7 @@ type filteringCore struct {
// If the entry should be logged, the filteringCore adds itself to the zapcore.CheckedEntry
// and returns the results.
func (core *filteringCore) Check(entry zapcore.Entry, ce *zapcore.CheckedEntry) *zapcore.CheckedEntry {
// FIXME: consider calling downstream core.Check too, but need to document how to
// properly set logging level.
if r := core.rule.Load(); r != nil && r.Filter(entry, nil) {
if r := core.rule.Load(); r == nil || r.Filter(entry) {
ce = ce.AddCore(entry, core)
}
return ce
@@ -63,11 +42,7 @@ func (core *filteringCore) Check(entry zapcore.Entry, ce *zapcore.CheckedEntry)
// Write determines whether the supplied zapcore.Entry with provided []zapcore.Field should
// be logged, then calls the wrapped zapcore.Write.
func (core *filteringCore) Write(entry zapcore.Entry, fields []zapcore.Field) error {
if r := core.rule.Load(); r != nil && r.Filter(entry, fields) {
return core.next.Write(entry, fields)
}
return nil
return core.next.Write(entry, fields)
}
// With adds structured context to the wrapped zapcore.Core.
@@ -80,11 +55,8 @@ func (core *filteringCore) With(fields []zapcore.Field) zapcore.Core {
// Enabled asks the wrapped zapcore.Core to decide whether a given logging level is enabled
// when logging a message.
func (core *filteringCore) Enabled(level zapcore.Level) bool {
// FIXME: Maybe it's better to always return true and only rely on the Check() func?
// Another way to consider it is to keep the smaller log level configured on
// zapfilter.
return core.next.Enabled(level)
func (core *filteringCore) Enabled(_ zapcore.Level) bool {
return true
}
func (core *filteringCore) Level() zapcore.Level {

View File

@@ -16,7 +16,7 @@ import (
)
// FilterFunc is used to check whether to filter the given entry and filters out.
type FilterFunc func(zapcore.Entry, []zapcore.Field) bool
type FilterFunc func(zapcore.Entry) bool
type FilterRule struct {
Filter FilterFunc
@@ -49,11 +49,11 @@ func ParseFilterRule(expr string) (*FilterRule, error) {
}
func (f FilterFunc) Level() zapcore.Level {
for lvl := LevelMin; lvl <= LevelMax; lvl++ {
for l := MinLevel; l <= MaxLevel; l++ {
if f(zapcore.Entry{
Level: lvl,
}, nil) {
return lvl
Level: zapcore.Level(l),
}) {
return zapcore.Level(l)
}
}
@@ -90,7 +90,7 @@ func ByNamespaces(input string) FilterFunc { //nolint:gocognit
var mutex sync.Mutex
matchMap := map[string]bool{}
return func(entry zapcore.Entry, fields []zapcore.Field) bool {
return func(entry zapcore.Entry) bool {
mutex.Lock()
defer mutex.Unlock()
@@ -117,27 +117,27 @@ func ByNamespaces(input string) FilterFunc { //nolint:gocognit
}
// ExactLevel filters out entries with an invalid level.
func ExactLevel(level zapcore.Level) FilterFunc {
return func(entry zapcore.Entry, fields []zapcore.Field) bool {
return entry.Level == level
func ExactLevel(level Level) FilterFunc {
return func(entry zapcore.Entry) bool {
return Level(entry.Level) == level
}
}
// MinimumLevel filters out entries with a too low level.
func MinimumLevel(level zapcore.Level) FilterFunc {
return func(entry zapcore.Entry, fields []zapcore.Field) bool {
return entry.Level >= level
func MinimumLevel(level Level) FilterFunc {
return func(entry zapcore.Entry) bool {
return Level(entry.Level) >= level
}
}
// Any checks if any filter returns true.
func Any(filters ...FilterFunc) FilterFunc {
return func(entry zapcore.Entry, fields []zapcore.Field) bool {
return func(entry zapcore.Entry) bool {
for _, filter := range filters {
if filter == nil {
continue
}
if filter(entry, fields) {
if filter(entry) {
return true
}
}
@@ -147,20 +147,20 @@ func Any(filters ...FilterFunc) FilterFunc {
// Reverse checks is the passed filter returns false.
func Reverse(filter FilterFunc) FilterFunc {
return func(entry zapcore.Entry, fields []zapcore.Field) bool {
return !filter(entry, fields)
return func(entry zapcore.Entry) bool {
return !filter(entry)
}
}
// All checks if all filters return true.
func All(filters ...FilterFunc) FilterFunc {
return func(entry zapcore.Entry, fields []zapcore.Field) bool {
return func(entry zapcore.Entry) bool {
var atLeastOneSuccessful bool
for _, filter := range filters {
if filter == nil {
continue
}
if !filter(entry, fields) {
if !filter(entry) {
return false
}
atLeastOneSuccessful = true
@@ -296,7 +296,7 @@ func ByLevels(pattern string) (FilterFunc, error) {
}
}
return func(e zapcore.Entry, f []zapcore.Field) bool {
return func(e zapcore.Entry) bool {
return levelToBit(Level(e.Level))&enabled != 0
}, nil
}
@@ -314,10 +314,10 @@ func MustParseRules(expr string) FilterFunc {
return filter
}
func AlwaysFalseFilter(_ zapcore.Entry, _ []zapcore.Field) bool {
func AlwaysFalseFilter(_ zapcore.Entry) bool {
return false
}
func AlwaysTrueFilter(_ zapcore.Entry, _ []zapcore.Field) bool {
func AlwaysTrueFilter(_ zapcore.Entry) bool {
return true
}

View File

@@ -7,7 +7,6 @@ package log_test
import (
"errors"
"fmt"
"math/rand"
"strings"
"github.com/onsi/gomega/gcustom"
@@ -28,7 +27,7 @@ var (
errMismatchingField = errors.New("mismatch in context field")
)
func MatchEntry(expectedEntry zapcore.Entry, expectedFields ...zapcore.Field) OmegaMatcher {
func matchEntry(expectedEntry zapcore.Entry, expectedFields ...zapcore.Field) OmegaMatcher {
return gcustom.MakeMatcher(func(actualEntry observer.LoggedEntry) (bool, error) {
if expectedEntry.Message != "" && expectedEntry.Message != actualEntry.Message {
return false, fmt.Errorf("%w: %s != %s", errMismatchingLogMessage, expectedEntry.Message, actualEntry.Message)
@@ -72,6 +71,21 @@ func makeLogger(filterFunc log.FilterFunc) (*zap.Logger, *observer.ObservedLogs)
return zap.New(filtered), logs
}
// CheckAnyLevel determines whether at least one log level isn't filtered-out by the logger.
func checkAnyLevel(logger *zap.Logger) bool {
for l := log.MinLevel; l <= log.DPanicLevel; l++ {
if checkLevel(logger, l) {
return true
}
}
return false
}
// CheckLevel determines whether a specific log level would produce log or not.
func checkLevel(logger *zap.Logger, level log.Level) bool {
return logger.Check(zapcore.Level(level), "") != nil
}
var _ = Describe("filter", func() {
Describe("NewFilteredCore", func() {
It("wrap", func() {
@@ -91,7 +105,7 @@ var _ = Describe("filter", func() {
logger.Named("other").Debug("hello universe!")
Expect(logs.All()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "hello earth!"}),
matchEntry(zapcore.Entry{Message: "hello earth!"}),
))
})
@@ -104,7 +118,7 @@ var _ = Describe("filter", func() {
logger.Named("other").Debug("hello universe!")
Expect(logs.All()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "hello earth!"}),
matchEntry(zapcore.Entry{Message: "hello earth!"}),
))
})
})
@@ -120,16 +134,14 @@ var _ = Describe("filter", func() {
logger.Named("demo3.frontend").Debug("hello solar system!")
Expect(logs.All()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "hello region!", LoggerName: "demo1.frontend", Level: zapcore.DebugLevel}),
MatchEntry(zapcore.Entry{Message: "hello solar system!", LoggerName: "demo3.frontend", Level: zapcore.DebugLevel}),
matchEntry(zapcore.Entry{Message: "hello region!", LoggerName: "demo1.frontend", Level: zapcore.DebugLevel}),
matchEntry(zapcore.Entry{Message: "hello solar system!", LoggerName: "demo3.frontend", Level: zapcore.DebugLevel}),
))
})
It("custom", func() {
rand.Seed(42) //nolint:staticcheck
logger, logs := makeLogger(func(entry zapcore.Entry, fields []zapcore.Field) bool {
return rand.Intn(2) == 1 //nolint:gosec
logger, logs := makeLogger(func(entry zapcore.Entry) bool {
return strings.Contains(entry.Message, "planet")
})
defer logger.Sync() //nolint:errcheck
@@ -141,8 +153,7 @@ var _ = Describe("filter", func() {
logger.Debug("hello multiverse!")
Expect(logs.All()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "hello planet!"}),
MatchEntry(zapcore.Entry{Message: "hello multiverse!"}),
matchEntry(zapcore.Entry{Message: "hello planet!"}),
))
})
@@ -167,83 +178,83 @@ var _ = Describe("filter", func() {
Expect(gotLogs).To(Equal(expectedLogs))
},
Entry("allow-all",
func(entry zapcore.Entry, fields []zapcore.Field) bool {
func(entry zapcore.Entry) bool {
return true
},
[]string{"a", "b", "c", "d"},
),
Entry("disallow-all",
func(entry zapcore.Entry, fields []zapcore.Field) bool {
func(entry zapcore.Entry) bool {
return false
},
[]string{},
),
Entry("minimum-debug",
log.MinimumLevel(zapcore.DebugLevel),
log.MinimumLevel(log.DebugLevel),
[]string{"a", "b", "c", "d"},
),
Entry("minimum-info",
log.MinimumLevel(zapcore.InfoLevel),
log.MinimumLevel(log.InfoLevel),
[]string{"b", "c", "d"},
),
Entry("minimum-warn",
log.MinimumLevel(zapcore.WarnLevel),
log.MinimumLevel(log.WarnLevel),
[]string{"c", "d"},
),
Entry("minimum-error",
log.MinimumLevel(zapcore.ErrorLevel),
log.MinimumLevel(log.ErrorLevel),
[]string{"d"},
),
Entry("exact-debug",
log.ExactLevel(zapcore.DebugLevel),
log.ExactLevel(log.DebugLevel),
[]string{"a"},
),
Entry("exact-info",
log.ExactLevel(zapcore.InfoLevel),
log.ExactLevel(log.InfoLevel),
[]string{"b"},
),
Entry("exact-warn",
log.ExactLevel(zapcore.WarnLevel),
log.ExactLevel(log.WarnLevel),
[]string{"c"},
),
Entry("exact-error",
log.ExactLevel(zapcore.ErrorLevel),
log.ExactLevel(log.ErrorLevel),
[]string{"d"},
),
Entry("all-except-debug",
log.Reverse(log.ExactLevel(zapcore.DebugLevel)),
log.Reverse(log.ExactLevel(log.DebugLevel)),
[]string{"b", "c", "d"},
),
Entry("all-except-info",
log.Reverse(log.ExactLevel(zapcore.InfoLevel)),
log.Reverse(log.ExactLevel(log.InfoLevel)),
[]string{"a", "c", "d"},
),
Entry("all-except-warn",
log.Reverse(log.ExactLevel(zapcore.WarnLevel)),
log.Reverse(log.ExactLevel(log.WarnLevel)),
[]string{"a", "b", "d"},
),
Entry("all-except-error",
log.Reverse(log.ExactLevel(zapcore.ErrorLevel)),
log.Reverse(log.ExactLevel(log.ErrorLevel)),
[]string{"a", "b", "c"},
),
Entry("any",
log.Any(
log.ExactLevel(zapcore.DebugLevel),
log.ExactLevel(zapcore.WarnLevel),
log.ExactLevel(log.DebugLevel),
log.ExactLevel(log.WarnLevel),
),
[]string{"a", "c"},
),
Entry("all-1",
log.All(
log.ExactLevel(zapcore.DebugLevel),
log.ExactLevel(zapcore.WarnLevel),
log.ExactLevel(log.DebugLevel),
log.ExactLevel(log.WarnLevel),
),
[]string{},
),
Entry("all-2",
log.All(
log.ExactLevel(zapcore.DebugLevel),
log.ExactLevel(zapcore.DebugLevel),
log.ExactLevel(log.DebugLevel),
log.ExactLevel(log.DebugLevel),
),
[]string{"a"},
),
@@ -270,7 +281,7 @@ var _ = Describe("filter", func() {
logger.Named("myns").Debug("myns debug") // Matches *:myns
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "myns debug", LoggerName: "myns", Level: zapcore.DebugLevel}),
matchEntry(zapcore.Entry{Message: "myns debug", LoggerName: "myns", Level: zapcore.DebugLevel}),
))
logger.Named("bar").Debug("bar debug") // No match
@@ -284,7 +295,7 @@ var _ = Describe("filter", func() {
logger.Named("myns").Info("myns info") // Matches *:myns
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "myns info", LoggerName: "myns", Level: zapcore.InfoLevel}),
matchEntry(zapcore.Entry{Message: "myns info", LoggerName: "myns", Level: zapcore.InfoLevel}),
))
logger.Named("bar").Info("bar info") // No match
@@ -292,7 +303,7 @@ var _ = Describe("filter", func() {
logger.Named("myns").Named("foo").Info("myns.foo info") // Matches info,warn:myns.*
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "myns.foo info", LoggerName: "myns.foo", Level: zapcore.InfoLevel}),
matchEntry(zapcore.Entry{Message: "myns.foo info", LoggerName: "myns.foo", Level: zapcore.InfoLevel}),
))
logger.Warn("top warn") // No match
@@ -300,7 +311,7 @@ var _ = Describe("filter", func() {
logger.Named("myns").Warn("myns warn") // Matches *:myns
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "myns warn", LoggerName: "myns", Level: zapcore.WarnLevel}),
matchEntry(zapcore.Entry{Message: "myns warn", LoggerName: "myns", Level: zapcore.WarnLevel}),
))
logger.Named("bar").Warn("bar warn") // No match
@@ -308,27 +319,27 @@ var _ = Describe("filter", func() {
logger.Named("myns").Named("foo").Warn("myns.foo warn") // Matches info,warn:myns.*
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "myns.foo warn", LoggerName: "myns.foo", Level: zapcore.WarnLevel}),
matchEntry(zapcore.Entry{Message: "myns.foo warn", LoggerName: "myns.foo", Level: zapcore.WarnLevel}),
))
logger.Error("top error") // Matches error:*
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "top error", Level: zapcore.ErrorLevel}),
matchEntry(zapcore.Entry{Message: "top error", Level: zapcore.ErrorLevel}),
))
logger.Named("myns").Error("myns error") // Matches *:myns and error:*
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "myns error", LoggerName: "myns", Level: zapcore.ErrorLevel}),
matchEntry(zapcore.Entry{Message: "myns error", LoggerName: "myns", Level: zapcore.ErrorLevel}),
))
logger.Named("bar").Error("bar error") // Matches error:*
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "bar error", LoggerName: "bar", Level: zapcore.ErrorLevel}),
matchEntry(zapcore.Entry{Message: "bar error", LoggerName: "bar", Level: zapcore.ErrorLevel}),
))
logger.Named("myns").Named("foo").Error("myns.foo error") // Matches error:*
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "myns.foo error", LoggerName: "myns.foo", Level: zapcore.ErrorLevel}),
matchEntry(zapcore.Entry{Message: "myns.foo error", LoggerName: "myns.foo", Level: zapcore.ErrorLevel}),
))
})
@@ -465,7 +476,7 @@ var _ = Describe("filter", func() {
logger = logger.Named(name)
}
Expect(log.CheckAnyLevel(logger)).To(Equal(expected))
Expect(checkAnyLevel(logger)).To(Equal(expected))
},
Entry("1", "", false),
Entry("2", "demo", true),
@@ -476,27 +487,27 @@ var _ = Describe("filter", func() {
)
DescribeTable("level",
func(name string, lvl zapcore.Level, expected bool) {
func(name string, lvl log.Level, expected bool) {
logger, _ := makeLogger(log.MustParseRules("=debug:*.* =info:demo*"))
if name != "" {
logger = logger.Named(name)
}
Expect(log.CheckLevel(logger, lvl)).To(Equal(expected))
Expect(checkLevel(logger, lvl)).To(Equal(expected))
},
Entry("1", "", zap.DebugLevel, false),
Entry("2", "demo", zap.DebugLevel, false),
Entry("3", "blahdemo", zap.DebugLevel, false),
Entry("4", "demoblah", zap.DebugLevel, false),
Entry("5", "blah", zap.DebugLevel, false),
Entry("6", "blah.blah", zap.DebugLevel, true),
Entry("7", "", zap.InfoLevel, false),
Entry("8", "demo", zap.InfoLevel, true),
Entry("9", "blahdemo", zap.InfoLevel, false),
Entry("10", "demoblah", zap.InfoLevel, true),
Entry("11", "blah", zap.InfoLevel, false),
Entry("12", "blah.blah", zap.InfoLevel, false),
Entry("1", "", log.DebugLevel, false),
Entry("2", "demo", log.DebugLevel, false),
Entry("3", "blahdemo", log.DebugLevel, false),
Entry("4", "demoblah", log.DebugLevel, false),
Entry("5", "blah", log.DebugLevel, false),
Entry("6", "blah.blah", log.DebugLevel, true),
Entry("7", "", log.InfoLevel, false),
Entry("8", "demo", log.InfoLevel, true),
Entry("9", "blahdemo", log.InfoLevel, false),
Entry("10", "demoblah", log.InfoLevel, true),
Entry("11", "blah", log.InfoLevel, false),
Entry("12", "blah.blah", log.InfoLevel, false),
)
})
@@ -509,7 +520,7 @@ var _ = Describe("filter", func() {
logger.With(zap.String("lorem", "ipsum")).Named("demo1.frontend").Debug("hello region!")
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "hello region!", LoggerName: "demo1.frontend", Level: zapcore.DebugLevel}, zap.String("lorem", "ipsum")),
matchEntry(zapcore.Entry{Message: "hello region!", LoggerName: "demo1.frontend", Level: zapcore.DebugLevel}, zap.String("lorem", "ipsum")),
))
logger.With(zap.String("lorem", "ipsum")).Named("demo2.frontend").Debug("hello planet!")
@@ -517,7 +528,7 @@ var _ = Describe("filter", func() {
logger.With(zap.String("lorem", "ipsum")).Named("demo3.frontend").Debug("hello solar system!")
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "hello solar system!", LoggerName: "demo3.frontend", Level: zapcore.DebugLevel}, zap.String("lorem", "ipsum")),
matchEntry(zapcore.Entry{Message: "hello solar system!", LoggerName: "demo3.frontend", Level: zapcore.DebugLevel}, zap.String("lorem", "ipsum")),
))
})
@@ -529,7 +540,7 @@ var _ = Describe("filter", func() {
Expect(ce).NotTo(BeNil())
ce.Write()
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "a"}),
matchEntry(zapcore.Entry{Message: "a"}),
))
ce = logger.Check(zap.InfoLevel, "b")
@@ -540,7 +551,7 @@ var _ = Describe("filter", func() {
Expect(ce).NotTo(BeNil())
ce.Write()
Expect(logs.TakeAll()).To(HaveExactElements(
MatchEntry(zapcore.Entry{Message: "c"}),
matchEntry(zapcore.Entry{Message: "c"}),
))
ce = logger.Check(zap.WarnLevel, "d")

View File

@@ -5,90 +5,93 @@ package log
import (
"fmt"
"os"
"regexp"
"strconv"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
"google.golang.org/grpc/grpclog"
)
var grpcLogExpr = regexp.MustCompile(`(?m)^\[(\w+)\]$`)
var grpcLogScope = regexp.MustCompile(`(?m)^\[(\w+)\]$`)
var _ grpclog.LoggerV2 = (*grpcLogger)(nil)
type grpcLogger struct {
*zap.SugaredLogger
verbosity int
}
func NewGRPCLogger(logger *Logger, verbosity int) grpclog.LoggerV2 {
var level zapcore.Level
verbosityLevel := os.Getenv("GRPC_GO_LOG_VERBOSITY_LEVEL")
if vl, err := strconv.Atoi(verbosityLevel); err == nil {
verbosity = vl
}
severityLevel := os.Getenv("GRPC_GO_LOG_SEVERITY_LEVEL")
if severityLevel != "" {
if err := level.UnmarshalText([]byte(severityLevel)); err != nil {
logger.Fatal("Unknown gRPC logger severity level", zap.Error(err), zap.String("level", severityLevel))
}
} else {
level = zap.WarnLevel
}
logger = logger.WithOptions(zap.IncreaseLevel(level))
return &grpcLogger{
SugaredLogger: logger.Logger.Sugar(),
verbosity: verbosity,
}
func (l *grpcLogger) Warning(args ...any) {
l.SugaredLogger.Warn(args...)
}
func (l *grpcLogger) unwrap(args []any) (string, []zap.Field) {
fields := []zap.Field{}
func (l *grpcLogger) Warningln(args ...any) {
l.SugaredLogger.Warnln(args...)
}
func (l *grpcLogger) Warningf(format string, args ...any) {
l.SugaredLogger.Warnf(format, args...)
}
func (l *grpcLogger) Info(args ...any) {
l.log(TraceLevel, "", args)
}
func (l *grpcLogger) Infof(format string, args ...any) {
l.log(TraceLevel, format, args)
}
func (l *grpcLogger) InfoDepth(_ int, args ...any) {
l.log(DebugLevel-5, "", args)
}
func (l *grpcLogger) WarningDepth(_ int, args ...any) {
l.log(WarnLevel, "", args)
}
func (l *grpcLogger) ErrorDepth(_ int, args ...any) {
l.log(ErrorLevel, "", args)
}
func (l *grpcLogger) FatalDepth(_ int, args ...any) {
l.log(FatalLevel, "", args)
}
func (l *grpcLogger) unwrap(args []any) (string, []any) {
scope := ""
if len(args) > 0 {
if str, ok := args[0].(string); ok {
if m := grpcLogExpr.FindStringSubmatch(str); m != nil {
fields = append(fields, zap.String("scope", m[1]))
if m := grpcLogScope.FindStringSubmatch(str); m != nil {
scope = m[1]
args = args[1:]
}
}
}
return fmt.Sprint(args...), fields
return scope, args
}
func (l *grpcLogger) Warning(args ...any) {
l.Warn(args...)
}
func (l *grpcLogger) log(lvl Level, format string, args []any) {
scope, args := l.unwrap(args)
func (l *grpcLogger) Warningf(format string, args ...any) {
l.Warnf(format, args...)
}
d := l.Desugar().Named(scope)
func (l *grpcLogger) Infoln(args ...any) {
msg, fields := l.unwrap(args)
l.Desugar().Info(msg, fields...)
}
func (l *grpcLogger) Warningln(args ...any) {
msg, fields := l.unwrap(args)
l.Desugar().Warn(msg, fields...)
}
func (l *grpcLogger) Errorln(args ...any) {
msg, fields := l.unwrap(args)
l.Desugar().Error(msg, fields...)
}
func (l *grpcLogger) Fatalln(args ...any) {
msg, fields := l.unwrap(args)
l.Desugar().Fatal(msg, fields...)
// We check to avoid an unnecessary call to fmt.Sprint()
if d.Check(zapcore.Level(lvl), "") != nil {
if format != "" {
d.Log(zapcore.Level(lvl), fmt.Sprintf(format, args...))
} else {
d.Log(zapcore.Level(lvl), fmt.Sprint(args...))
}
}
}
func (l *grpcLogger) V(lvl int) bool {
return lvl < l.verbosity
return lvl >= Level(l.Level()).Verbosity()
}
func NewGRPCLogger(logger *Logger) grpclog.LoggerV2 {
return &grpcLogger{
SugaredLogger: logger.Sugar(),
}
}

View File

@@ -18,16 +18,24 @@ func levelEncoder(l zapcore.Level, enc zapcore.PrimitiveArrayEncoder) {
type Level zapcore.Level
const (
LevelMin = zapcore.DebugLevel - 10
LevelMax = zapcore.FatalLevel
DebugLevel Level = iota - 1
InfoLevel
WarnLevel
ErrorLevel
DPanicLevel
PanicLevel
FatalLevel
)
func (l Level) Verbosity() int {
if l > Level(zapcore.DebugLevel) {
return 0
}
//nolint:gochecknoglobals
var (
MaxLevel = FatalLevel
MinLevel = VerboseLevel(10)
TraceLevel = VerboseLevel(5)
)
return -int(l) - 1
func VerboseLevel(v int) Level {
return DebugLevel - Level(v)
}
func (l *Level) UnmarshalText(text []byte) error {
@@ -38,7 +46,7 @@ func (l *Level) UnmarshalText(text []byte) error {
v, _ = strconv.Atoi(vs)
}
*l = Level(zapcore.DebugLevel - zapcore.Level(v))
*l = DebugLevel - Level(v)
return nil
}
@@ -52,14 +60,14 @@ func (l *Level) UnmarshalText(text []byte) error {
return nil
}
func (l Level) MarshalText() ([]byte, error) {
return []byte(l.String()), nil
}
func (l Level) String() string {
if l < Level(zapcore.DebugLevel) {
if l < DebugLevel {
return zapcore.DebugLevel.String() + strconv.Itoa(l.Verbosity())
}
return zapcore.Level(l).String()
}
func (l Level) Verbosity() int {
return -int(l) - 1
}

View File

@@ -21,10 +21,6 @@ var (
Global *Logger
)
func DebugLevel(verbosity int) Level {
return Level(zapcore.DebugLevel) - Level(verbosity)
}
func openSink(path string) zapcore.WriteSyncer {
switch path {
case "stdout":
@@ -61,10 +57,6 @@ func SetupLogging(rule string, paths []string, color bool) (logger *Logger, err
EncodeLevel: levelEncoder,
}
if rule == "" {
rule = "*"
}
if color {
cfg.ColorTime = ColorTime
cfg.ColorContext = ColorContext
@@ -88,12 +80,14 @@ func SetupLogging(rule string, paths []string, color bool) (logger *Logger, err
enc := newEncoder(cfg)
core := zapcore.NewCore(enc, ws, &alwaysEnabled{})
filterRule, err := ParseFilterRule(rule)
if err != nil {
return nil, err
}
if rule != "" {
filterRule, err := ParseFilterRule(rule)
if err != nil {
return nil, err
}
Rule.Store(filterRule)
Rule.Store(filterRule)
}
zlogger := zap.New(core,
zap.ErrorOutput(ws),
@@ -111,16 +105,8 @@ func SetupLogging(rule string, paths []string, color bool) (logger *Logger, err
Global = logger
// Redirect gRPC log to Zap
glogger := logger.Named("grpc")
grpclog.SetLoggerV2(NewGRPCLogger(glogger, Level(zlogger.Level()).Verbosity()))
glogger := NewGRPCLogger(logger.Named("grpc"))
grpclog.SetLoggerV2(glogger)
return logger, nil
}
type forceReflect struct {
any
}
func ForceReflect(key string, val any) zapcore.Field {
return zapcore.Field{Key: key, Type: zapcore.ReflectType, Interface: forceReflect{val}}
}

View File

@@ -10,8 +10,6 @@ import (
"path/filepath"
"testing"
"github.com/pion/zapion"
"go.uber.org/zap/zapcore"
"google.golang.org/grpc/grpclog"
"github.com/stv0g/cunicu/pkg/log"
@@ -29,7 +27,7 @@ func TestSuite(t *testing.T) {
// https://github.com/uber-go/zap/issues/621
var _ = Context("log", Label("broken-on-windows"), func() {
var logger *log.Logger
var lvl zapcore.Level
var lvl log.Level
var logPath, msg, name string
BeforeEach(func() {
@@ -37,10 +35,7 @@ var _ = Context("log", Label("broken-on-windows"), func() {
logPath = filepath.Join(tmpDir, "std.log")
msg = "Test message"
os.Setenv("GRPC_GO_LOG_VERBOSITY_LEVEL", "2")
os.Setenv("GRPC_GO_LOG_SEVERITY_LEVEL", lvl.String())
os.Setenv("PION_LOG", lvl.String())
lvl = log.InfoLevel
log.ResetWidths()
})
@@ -68,10 +63,7 @@ var _ = Context("log", Label("broken-on-windows"), func() {
})
It("can log via pion logger", func() {
lf := zapion.ZapFactory{
BaseLogger: logger.Named("ice").Logger,
}
logger := lf.NewLogger("myscope")
logger := log.NewPionLogger(logger, "ice.myscope")
name = "ice.myscope"
logger.Info(msg)
@@ -79,6 +71,7 @@ var _ = Context("log", Label("broken-on-windows"), func() {
It("can log via gRPC logger", func() {
name = "grpc"
lvl = log.DebugLevel - 5
grpclog.Info(msg)
})
})

93
pkg/log/pion.go Normal file
View File

@@ -0,0 +1,93 @@
// SPDX-FileCopyrightText: 2023 Atsushi Watanabe <atsushi.w@ieee.org>
// SPDX-FileCopyrightText: 2023 Steffen Vogel <post@steffenvogel.de>
// SPDX-License-Identifier: MIT
package log
import (
"fmt"
"sync"
"github.com/pion/logging"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
var (
_ logging.LeveledLogger = (*pionLogger)(nil)
_ logging.LoggerFactory = (*PionLoggerFactory)(nil)
)
type pionLogger struct {
*zap.SugaredLogger
}
func (l *pionLogger) Trace(msg string) {
l.Desugar().Log(zapcore.Level(TraceLevel), msg)
}
func (l *pionLogger) Tracef(format string, args ...interface{}) {
// Check for level before calling fmt.Sprintf()
if d := l.Desugar(); d.Check(zapcore.Level(TraceLevel), "") != nil {
d.Log(zapcore.Level(TraceLevel), fmt.Sprintf(format, args...))
}
}
func (l *pionLogger) Debug(msg string) {
l.SugaredLogger.Debug(msg)
}
func (l *pionLogger) Info(msg string) {
l.SugaredLogger.Info(msg)
}
func (l *pionLogger) Warn(msg string) {
l.SugaredLogger.Warn(msg)
}
func (l *pionLogger) Error(msg string) {
l.SugaredLogger.Error(msg)
}
// PionLoggerFactory is a logger factory backended by zap logger.
type PionLoggerFactory struct {
base *zap.Logger
mu sync.Mutex
loggers []*pionLogger
}
// NewLogger creates new scoped logger.
func (f *PionLoggerFactory) NewLogger(scope string) logging.LeveledLogger {
f.mu.Lock()
defer f.mu.Unlock()
l := &pionLogger{
SugaredLogger: f.base.Named(scope).WithOptions(zap.AddCallerSkip(1)).Sugar(),
}
f.loggers = append(f.loggers, l)
return l
}
// SyncAll calls Sync() method of all child loggers.
// It is recommended to call this before exiting the program to
// ensure never loosing buffered log.
func (f *PionLoggerFactory) SyncAll() {
f.mu.Lock()
defer f.mu.Unlock()
for _, l := range f.loggers {
_ = l.SugaredLogger.Sync()
}
}
func NewPionLoggerFactory(base *Logger) logging.LoggerFactory {
return &PionLoggerFactory{
base: base.Logger,
}
}
func NewPionLogger(base *Logger, scope string) logging.LeveledLogger {
return NewPionLoggerFactory(base).NewLogger(scope)
}

View File

@@ -45,7 +45,7 @@ func (i *Interface) Dump(wr io.Writer, level log.Level) error {
return err
}
if level > log.DebugLevel(5) {
if level.Verbosity() > 5 {
if _, err := tty.FprintKV(wri, "private key", base64.StdEncoding.EncodeToString(i.PrivateKey)); err != nil {
return err
}
@@ -82,7 +82,7 @@ func (i *Interface) Dump(wr io.Writer, level log.Level) error {
return err
}
if err := i.Ice.Dump(wri, level.Verbosity()); err != nil {
if err := i.Ice.Dump(wri, level); err != nil {
return err
}
}
@@ -92,7 +92,7 @@ func (i *Interface) Dump(wr io.Writer, level log.Level) error {
return err
}
if err := p.Dump(wri, level.Verbosity()); err != nil {
if err := p.Dump(wri, level); err != nil {
return err
}
}

View File

@@ -13,6 +13,7 @@ import (
"golang.zx2c4.com/wireguard/wgctrl/wgtypes"
"github.com/stv0g/cunicu/pkg/log"
"github.com/stv0g/cunicu/pkg/tty"
)
@@ -53,7 +54,7 @@ func (p *Peer) Peer() wgtypes.Peer {
return q
}
func (p *Peer) Dump(wr io.Writer, verbosity int) error { //nolint:gocognit
func (p *Peer) Dump(wr io.Writer, level log.Level) error { //nolint:gocognit
wri := tty.NewIndenter(wr, " ")
if _, err := fmt.Fprintf(wr, tty.Mods("peer", tty.Bold, tty.FgYellow)+": "+tty.Mods("%s", tty.FgYellow)+"\n", p.Name); err != nil {
@@ -122,7 +123,7 @@ func (p *Peer) Dump(wr io.Writer, verbosity int) error { //nolint:gocognit
}
}
if len(p.PresharedKey) > 0 && verbosity > 5 {
if len(p.PresharedKey) > 0 && level.Verbosity() > 5 {
if _, err := tty.FprintKV(wri, "preshared key", base64.StdEncoding.EncodeToString(p.PresharedKey)); err != nil {
return err
}
@@ -137,7 +138,7 @@ func (p *Peer) Dump(wr io.Writer, verbosity int) error { //nolint:gocognit
return err
}
if err := p.Ice.Dump(wri, verbosity); err != nil {
if err := p.Ice.Dump(wri, level); err != nil {
return err
}
}

View File

@@ -12,6 +12,7 @@ import (
"github.com/pion/randutil"
"golang.org/x/exp/slices"
"github.com/stv0g/cunicu/pkg/log"
"github.com/stv0g/cunicu/pkg/tty"
)
@@ -58,8 +59,8 @@ func NewCredentials() *Credentials {
}
}
func (i *Interface) Dump(wr io.Writer, verbosity int) error {
if verbosity > 4 {
func (i *Interface) Dump(wr io.Writer, level log.Level) error {
if level.Verbosity() > 4 {
if _, err := tty.FprintKV(wr, "nat type", i.NatType); err != nil {
return err
}
@@ -74,7 +75,7 @@ func (i *Interface) Dump(wr io.Writer, verbosity int) error {
return nil
}
func (p *Peer) Dump(wr io.Writer, verbosity int) error { //nolint:gocognit
func (p *Peer) Dump(wr io.Writer, level log.Level) error { //nolint:gocognit
var v string
if p.SelectedCandidatePair != nil {
@@ -83,7 +84,7 @@ func (p *Peer) Dump(wr io.Writer, verbosity int) error { //nolint:gocognit
}
}
if verbosity > 4 {
if level.Verbosity() > 4 {
if _, err := tty.FprintKV(wr, "proxy type", p.ProxyType); err != nil {
return err
}
@@ -100,7 +101,7 @@ func (p *Peer) Dump(wr io.Writer, verbosity int) error { //nolint:gocognit
}
}
if verbosity > 5 && len(p.CandidatePairStats) > 0 {
if level.Verbosity() > 5 && len(p.CandidatePairStats) > 0 {
cmap := map[string]int{}
var cpsNom *CandidatePairStats
@@ -157,7 +158,7 @@ func (p *Peer) Dump(wr io.Writer, verbosity int) error { //nolint:gocognit
}
}
if len(p.CandidatePairStats) > 0 && verbosity > 6 {
if len(p.CandidatePairStats) > 0 && level.Verbosity() > 6 {
if _, err := tty.FprintKV(wr, "\npairs"); err != nil {
return err
}

View File

@@ -136,7 +136,7 @@ func (s *Subscription) NewMessage(env *Envelope) error {
return err
}
log.Global.Named("backend").Debug("Received signaling message", zap.Any("msg", msg), zap.Any("pkp", pkp))
log.Global.Named("backend").Debug("Received signaling message", zap.Reflect("msg", msg), zap.Any("pkp", pkp))
s.mu.RLock()
defer s.mu.RUnlock()

View File

@@ -130,7 +130,7 @@ func buildBinary(packagePath string) (string, []string, error) {
zap.Bool("test", test))
if output, err := exec.Command("go", cmdArgs...).CombinedOutput(); err != nil {
return "", nil, fmt.Errorf("ailed to build %s:\n\nError:\n%s\n\nOutput:\n%s", packagePath, path, string(output))
return "", nil, fmt.Errorf("failed to build %s:\n\nError:\n%s\n\nOutput:\n%s", packagePath, path, string(output))
}
logger.Debug("Finished building",