TrueCloudLab/frostfs-node
20
1
Fork 28
Code Issues 109 Pull requests 4 Projects Releases 2 Packages 4 Activity Actions

WIP: logger: Filter entries by tags provided in config #1619

Closed
acid-ant wants to merge 6 commits from acid-ant/frostfs-node:feature/log-tags into master
pull from: acid-ant/frostfs-node:feature/log-tags
merge into: TrueCloudLab:master
Conversation 15 Commits 6 Files changed 37 +550 -110
37 changed files with 550 additions and 110 deletions
Download patch file Download diff file Expand all files Collapse all files

27
cmd/frostfs-ir/config.go
View file

@ -4,11 +4,14 @@ import (
"context"
"os"
"os/signal"
"strconv"
"syscall"
configViper "git.frostfs.info/TrueCloudLab/frostfs-node/cmd/internal/common/config"
"git.frostfs.info/TrueCloudLab/frostfs-node/internal/logs"
control "git.frostfs.info/TrueCloudLab/frostfs-node/pkg/services/control/ir"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger"
"github.com/spf13/cast"
"github.com/spf13/viper"
"go.uber.org/zap"
)
@ -38,13 +41,33 @@ func reloadConfig() error {
}
cmode.Store(cfg.GetBool("node.kludge_compatibility_mode"))
audit.Store(cfg.GetBool("audit.enabled"))
var logPrm logger.Prm
err = logPrm.SetLevelString(cfg.GetString("logger.level"))
if err != nil {
return err
}
logPrm.PrependTimestamp = cfg.GetBool("logger.timestamp")
err = logPrm.SetTags(loggerTags())
if err != nil {
return err
}
log.Reload(logPrm)
return logPrm.Reload()
return nil
}
func loggerTags() [][]string {
var res [][]string
for i := 0; ; i++ {
var item []string
index := strconv.FormatInt(int64(i), 10)
names := cast.ToString(cfg.Get("logger.tags." + index + ".names"))
if names == "" {
break
}
item = append(item, names, cast.ToString(cfg.Get("logger.tags."+index+".level")))
res = append(res, item)
}
return res
}
func watchForSignal(ctx context.Context, cancel func()) {

4
cmd/frostfs-ir/main.go
View file

@ -31,7 +31,6 @@ const (
var (
wg = new(sync.WaitGroup)
intErr = make(chan error) // internal inner ring errors
logPrm = new(logger.Prm)
innerRing *innerring.Server
pprofCmp *pprofComponent
metricsCmp *httpComponent
@ -70,6 +69,7 @@ func main() {
metrics := irMetrics.NewInnerRingMetrics()
var logPrm logger.Prm
err = logPrm.SetLevelString(
cfg.GetString("logger.level"),
)
@ -80,6 +80,8 @@ func main() {
exitErr(err)
logPrm.SamplingHook = metrics.LogMetrics().GetSamplingHook()
logPrm.PrependTimestamp = cfg.GetBool("logger.timestamp")
err = logPrm.SetTags(loggerTags())
exitErr(err)
log, err = logger.NewLogger(logPrm)
exitErr(err)

48
cmd/frostfs-node/config.go
View file

@ -108,6 +108,7 @@ type applicationConfiguration struct {
level string
destination string
timestamp bool
tags [][]string
}
ObjectCfg struct {
@ -232,6 +233,7 @@ func (a *applicationConfiguration) readConfig(c *config.Config) error {
a.LoggerCfg.level = loggerconfig.Level(c)
a.LoggerCfg.destination = loggerconfig.Destination(c)
a.LoggerCfg.timestamp = loggerconfig.Timestamp(c)
a.LoggerCfg.tags = loggerconfig.Tags(c)
// Object
@ -473,7 +475,6 @@ type shared struct {
// dynamicConfiguration stores parameters of the
// components that supports runtime reconfigurations.
type dynamicConfiguration struct {
logger *logger.Prm
pprof *httpComponent
metrics *httpComponent
}
@ -714,7 +715,8 @@ func initCfg(appCfg *config.Config) *cfg {
netState.metrics = c.metricsCollector
logPrm := c.loggerPrm()
logPrm, err := c.loggerPrm()
fatalOnErr(err)
logPrm.SamplingHook = c.metricsCollector.LogMetrics().GetSamplingHook()
log, err := logger.NewLogger(logPrm)
fatalOnErr(err)
@ -1076,26 +1078,27 @@ func (c *cfg) getShardOpts(ctx context.Context, shCfg shardCfg) shardOptsWithID
return sh
}
func (c *cfg) loggerPrm() *logger.Prm {
// check if it has been inited before
if c.dynamicConfiguration.logger == nil {
c.dynamicConfiguration.logger = new(logger.Prm)
}
func (c *cfg) loggerPrm() (logger.Prm, error) {
var prm logger.Prm
// (re)init read configuration
err := c.dynamicConfiguration.logger.SetLevelString(c.LoggerCfg.level)
err := prm.SetLevelString(c.LoggerCfg.level)
if err != nil {
// not expected since validation should be performed before
panic("incorrect log level format: " + c.LoggerCfg.level)
return logger.Prm{}, errors.New("incorrect log level format: " + c.LoggerCfg.level)
}
err = c.dynamicConfiguration.logger.SetDestination(c.LoggerCfg.destination)
err = prm.SetDestination(c.LoggerCfg.destination)
if err != nil {
// not expected since validation should be performed before
panic("incorrect log destination format: " + c.LoggerCfg.destination)
return logger.Prm{}, errors.New("incorrect log destination format: " + c.LoggerCfg.destination)
}
prm.PrependTimestamp = c.LoggerCfg.timestamp
err = prm.SetTags(c.LoggerCfg.tags)
if err != nil {
// not expected since validation should be performed before
return logger.Prm{}, errors.New("incorrect allowed tags format: " + c.LoggerCfg.destination)
}
c.dynamicConfiguration.logger.PrependTimestamp = c.LoggerCfg.timestamp
return c.dynamicConfiguration.logger
return prm, nil
}
func (c *cfg) LocalAddress() network.AddressGroup {
@ -1335,11 +1338,7 @@ func (c *cfg) reloadConfig(ctx context.Context) {
// all the components are expected to support
// Logger's dynamic reconfiguration approach
// Logger
logPrm := c.loggerPrm()
components := c.getComponents(ctx, logPrm)
components := c.getComponents(ctx)
// Object
c.cfgObject.tombstoneLifetime.Store(c.ObjectCfg.tombstoneLifetime)
@ -1377,10 +1376,17 @@ func (c *cfg) reloadConfig(ctx context.Context) {
c.log.Info(ctx, logs.FrostFSNodeConfigurationHasBeenReloadedSuccessfully)
}
func (c *cfg) getComponents(ctx context.Context, logPrm *logger.Prm) []dCmp {
func (c *cfg) getComponents(ctx context.Context) []dCmp {
var components []dCmp
components = append(components, dCmp{"logger", logPrm.Reload})
components = append(components, dCmp{"logger", func() error {
prm, err := c.loggerPrm()
if err != nil {
return err
}
c.log.Reload(prm)
return nil
}})
components = append(components, dCmp{"runtime", func() error {
setRuntimeParameters(ctx, c)
return nil

18
cmd/frostfs-node/config/logger/config.go
View file

@ -2,6 +2,7 @@ package loggerconfig
import (
"os"
"strconv"
"time"
"git.frostfs.info/TrueCloudLab/frostfs-node/cmd/frostfs-node/config"
@ -60,6 +61,23 @@ func Timestamp(c *config.Config) bool {
return config.BoolSafe(c.Sub(subsection), "timestamp")
}
// Tags returns the value of "tags" config parameter from "logger" section.
func Tags(c *config.Config) [][]string {
var res [][]string
sub := c.Sub(subsection).Sub("tags")
for i := 0; ; i++ {
var item []string
s := sub.Sub(strconv.FormatInt(int64(i), 10))
names := config.StringSafe(s, "names")
if names == "" {
break
}
item = append(item, names, config.StringSafe(s, "level"))
res = append(res, item)
}
return res
}
// ToLokiConfig extracts loki config.
func ToLokiConfig(c *config.Config) loki.Config {
hostname, _ := os.Hostname()

3
cmd/frostfs-node/config/logger/config_test.go
View file

@ -22,6 +22,9 @@ func TestLoggerSection_Level(t *testing.T) {
require.Equal(t, "debug", loggerconfig.Level(c))
require.Equal(t, "journald", loggerconfig.Destination(c))
require.Equal(t, true, loggerconfig.Timestamp(c))
tags := loggerconfig.Tags(c)
require.Equal(t, "main, morph", tags[0][0])
require.Equal(t, "debug", tags[0][1])
}
configtest.ForEachFileType(path, fileConfigTest)

14
cmd/frostfs-node/morph.go
View file

@ -14,6 +14,7 @@ import (
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/morph/event"
netmapEvent "git.frostfs.info/TrueCloudLab/frostfs-node/pkg/morph/event/netmap"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/morph/subscriber"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/rand"
"github.com/nspcc-dev/neo-go/pkg/core/block"
"github.com/nspcc-dev/neo-go/pkg/core/state"
@ -83,7 +84,7 @@ func initMorphClient(ctx context.Context, c *cfg) {
cli, err := client.New(ctx,
c.key,
client.WithDialTimeout(morphconfig.DialTimeout(c.appCfg)),
client.WithLogger(c.log),
client.WithLogger(c.log.WithTag(logger.TagMorph)),
client.WithMetrics(c.metricsCollector.MorphClientMetrics()),
client.WithEndpoints(addresses...),
client.WithConnLostCallback(func() {
@ -164,6 +165,7 @@ func listenMorphNotifications(ctx context.Context, c *cfg) {
err error
subs subscriber.Subscriber
)
log := c.log.WithTag(logger.TagMorph)
fromSideChainBlock, err := c.persistate.UInt32(persistateSideChainLastBlockKey)
if err != nil {
@ -172,14 +174,14 @@ func listenMorphNotifications(ctx context.Context, c *cfg) {
}
subs, err = subscriber.New(ctx, &subscriber.Params{
Log: c.log,
Log: log,
StartFromBlock: fromSideChainBlock,
Client: c.cfgMorph.client,
})
fatalOnErr(err)
lis, err := event.NewListener(event.ListenerParams{
Logger: c.log,
Logger: log,
Subscriber: subs,
})
fatalOnErr(err)
@ -197,7 +199,7 @@ func listenMorphNotifications(ctx context.Context, c *cfg) {
setNetmapNotificationParser(c, newEpochNotification, func(src *state.ContainedNotificationEvent) (event.Event, error) {
res, err := netmapEvent.ParseNewEpoch(src)
if err == nil {
c.log.Info(ctx, logs.FrostFSNodeNewEpochEventFromSidechain,
log.Info(ctx, logs.FrostFSNodeNewEpochEventFromSidechain,
zap.Uint64("number", res.(netmapEvent.NewEpoch).EpochNumber()),
)
}
@ -208,11 +210,11 @@ func listenMorphNotifications(ctx context.Context, c *cfg) {
registerNotificationHandlers(c.cfgContainer.scriptHash, lis, c.cfgContainer.parsers, c.cfgContainer.subscribers)
registerBlockHandler(lis, func(ctx context.Context, block *block.Block) {
c.log.Debug(ctx, logs.FrostFSNodeNewBlock, zap.Uint32("index", block.Index))
log.Debug(ctx, logs.FrostFSNodeNewBlock, zap.Uint32("index", block.Index))
err = c.persistate.SetUInt32(persistateSideChainLastBlockKey, block.Index)
if err != nil {
c.log.Warn(ctx, logs.FrostFSNodeCantUpdatePersistentState,
log.Warn(ctx, logs.FrostFSNodeCantUpdatePersistentState,
zap.String("chain", "side"),
zap.Uint32("block_index", block.Index))
}

3
cmd/frostfs-node/session.go
View file

@ -14,6 +14,7 @@ import (
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/services/session/storage"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/services/session/storage/persistent"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/services/session/storage/temporary"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger"
"git.frostfs.info/TrueCloudLab/frostfs-sdk-go/api/session"
sessionGRPC "git.frostfs.info/TrueCloudLab/frostfs-sdk-go/api/session/grpc"
"git.frostfs.info/TrueCloudLab/frostfs-sdk-go/user"
@ -55,7 +56,7 @@ func initSessionService(c *cfg) {
server := sessionTransportGRPC.New(
sessionSvc.NewSignService(
&c.key.PrivateKey,
sessionSvc.NewExecutionService(c.privateTokenStore, c.respSvc, c.log),
sessionSvc.NewExecutionService(c.privateTokenStore, c.respSvc, c.log.WithTag(logger.TagSessionSvc)),
),
)

3
cmd/frostfs-node/tree.go
View file

@ -14,6 +14,7 @@ import (
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/morph/event"
containerEvent "git.frostfs.info/TrueCloudLab/frostfs-node/pkg/morph/event/container"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/services/tree"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger"
cid "git.frostfs.info/TrueCloudLab/frostfs-sdk-go/container/id"
"go.uber.org/zap"
"google.golang.org/grpc"
@ -56,7 +57,7 @@ func initTreeService(c *cfg) {
tree.WithFrostfsidSubjectProvider(c.shared.frostfsidClient),
tree.WithNetmapSource(c.netMapSource),
tree.WithPrivateKey(&c.key.PrivateKey),
tree.WithLogger(c.log),
tree.WithLogger(c.log.WithTag(logger.TagTreeSvc)),
tree.WithStorage(c.cfgObject.cfgLocalStorage.localStorage),
tree.WithContainerCacheSize(treeConfig.CacheSize()),
tree.WithReplicationTimeout(treeConfig.ReplicationTimeout()),

5
cmd/frostfs-node/validate.go
View file

@ -30,6 +30,11 @@ func validateConfig(c *config.Config) error {
return fmt.Errorf("invalid logger destination: %w", err)
}
err = loggerPrm.SetTags(loggerconfig.Tags(c))
if err != nil {
return fmt.Errorf("invalid list of allowed tags: %w", err)
}
// shard configuration validation
shardNum := 0

2
config/example/ir.env
View file

@ -1,5 +1,7 @@
FROSTFS_IR_LOGGER_LEVEL=info
FROSTFS_IR_LOGGER_TIMESTAMP=true
FROSTFS_IR_LOGGER_TAGS_0_NAMES="main, morph"
FROSTFS_IR_LOGGER_TAGS_0_LEVEL="debug"
FROSTFS_IR_WALLET_PATH=/path/to/wallet.json
FROSTFS_IR_WALLET_ADDRESS=NUHtW3eM6a4mmFCgyyr4rj4wygsTKB88XX

3
config/example/ir.yaml
View file

@ -3,6 +3,9 @@
logger:
level: info # Logger level: one of "debug", "info" (default), "warn", "error", "dpanic", "panic", "fatal"
timestamp: true
tags:
- names: "main, morph" # Possible values: `main`, `morph`, `grpc_svc`, `ir`, `processor`.
level: debug
wallet:
path: /path/to/wallet.json # Path to NEP-6 NEO wallet file

2
config/example/node.env
View file

@ -1,6 +1,8 @@
FROSTFS_LOGGER_LEVEL=debug
FROSTFS_LOGGER_DESTINATION=journald
FROSTFS_LOGGER_TIMESTAMP=true
FROSTFS_LOGGER_TAGS_0_NAMES="main, morph"
FROSTFS_LOGGER_TAGS_0_LEVEL="debug"
FROSTFS_PPROF_ENABLED=true
FROSTFS_PPROF_ADDRESS=localhost:6060

8
config/example/node.json
View file

@ -2,7 +2,13 @@
"logger": {
"level": "debug",
"destination": "journald",
"timestamp": true
"timestamp": true,
"tags": [
{
"names": "main, morph",
"level": "debug"
}
]
},
"pprof": {
"enabled": true,

3
config/example/node.yaml
View file

@ -2,6 +2,9 @@ logger:
level: debug # logger level: one of "debug", "info" (default), "warn", "error", "dpanic", "panic", "fatal"
destination: journald # logger destination: one of "stdout" (default), "journald"
timestamp: true
tags:
- names: "main, morph"
level: debug
systemdnotify:
enabled: true

12
docs/storage-node-configuration.md
View file

@ -111,11 +111,21 @@ Contains logger parameters.
```yaml
logger:
level: info
tags:
- names: "main, morph"
level: debug
```
| Parameter | Type | Default value | Description |
|-----------|----------|---------------|---------------------------------------------------------------------------------------------------|
|-----------|-----------------------------------------------|---------------|---------------------------------------------------------------------------------------------------|
| `level` | `string` | `info` | Logging level.<br/>Possible values: `debug`, `info`, `warn`, `error`, `dpanic`, `panic`, `fatal` |
| `tags` | list of [tags descriptions](#tags-subsection) | | Array of tags description. |
## `tags` subsection
| Parameter | Type | Default value | Description |
|-----------|----------|---------------|---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------|
| `names` | `string` | | List of components divided by `,`.<br/>Possible values: `main`, `morph`, `grpc_svc`, `ir`, `processor`, `engine`, `blobovnicza`, `blobstor`, `fstree`, `gc`, `shard`, `writecache`, `deletesvc`, `getsvc`, `searchsvc`, `sessionsvc`, `treesvc`, `policer`, `replicator`. |
| `level` | `string` | | Logging level for the components from `names`, overrides default logging level. |
# `contracts` section
Contains override values for FrostFS side-chain contract hashes. Most of the time contract

16
pkg/innerring/initialization.go
View file

@ -50,7 +50,7 @@ func (s *Server) initNetmapProcessor(ctx context.Context, cfg *viper.Viper,
var err error
s.netmapProcessor, err = netmap.New(&netmap.Params{
Log: s.log,
Log: s.log.WithTag(logger.TagProcessor),
Metrics: s.irMetrics,
PoolSize: poolSize,
NetmapClient: netmap.NewNetmapClient(s.netmapClient),
@ -159,7 +159,7 @@ func (s *Server) createAlphaSync(cfg *viper.Viper, frostfsCli *frostfsClient.Cli
} else {
// create governance processor
governanceProcessor, err := governance.New(&governance.Params{
Log: s.log,
Log: s.log.WithTag(logger.TagProcessor),
Metrics: s.irMetrics,
FrostFSClient: frostfsCli,
AlphabetState: s,
@ -225,7 +225,7 @@ func (s *Server) initAlphabetProcessor(ctx context.Context, cfg *viper.Viper) er
// create alphabet processor
s.alphabetProcessor, err = alphabet.New(&alphabet.Params{
ParsedWallets: parsedWallets,
Log: s.log,
Log: s.log.WithTag(logger.TagProcessor),
Metrics: s.irMetrics,
PoolSize: poolSize,
AlphabetContracts: s.contracts.alphabet,
@ -247,7 +247,7 @@ func (s *Server) initContainerProcessor(ctx context.Context, cfg *viper.Viper, c
s.log.Debug(ctx, logs.ContainerContainerWorkerPool, zap.Int("size", poolSize))
// container processor
containerProcessor, err := cont.New(&cont.Params{
Log: s.log,
Log: s.log.WithTag(logger.TagProcessor),
Metrics: s.irMetrics,
PoolSize: poolSize,
AlphabetState: s,
@ -268,7 +268,7 @@ func (s *Server) initBalanceProcessor(ctx context.Context, cfg *viper.Viper, fro
s.log.Debug(ctx, logs.BalanceBalanceWorkerPool, zap.Int("size", poolSize))
// create balance processor
balanceProcessor, err := balance.New(&balance.Params{
Log: s.log,
Log: s.log.WithTag(logger.TagProcessor),
Metrics: s.irMetrics,
PoolSize: poolSize,
FrostFSClient: frostfsCli,
@ -291,7 +291,7 @@ func (s *Server) initFrostFSMainnetProcessor(ctx context.Context, cfg *viper.Vip
s.log.Debug(ctx, logs.FrostFSFrostfsWorkerPool, zap.Int("size", poolSize))
frostfsProcessor, err := frostfs.New(&frostfs.Params{
Log: s.log,
Log: s.log.WithTag(logger.TagProcessor),
Metrics: s.irMetrics,
PoolSize: poolSize,
FrostFSContract: s.contracts.frostfs,
@ -342,7 +342,7 @@ func (s *Server) initGRPCServer(ctx context.Context, cfg *viper.Viper, log *logg
controlSvc := controlsrv.NewAuditService(controlsrv.New(p, s.netmapClient, s.containerClient,
controlsrv.WithAllowedKeys(authKeys),
), log, audit)
), log.WithTag(logger.TagGrpcSvc), audit)
grpcControlSrv := grpc.NewServer()
control.RegisterControlServiceServer(grpcControlSrv, controlSvc)
@ -458,7 +458,7 @@ func (s *Server) initMorph(ctx context.Context, cfg *viper.Viper, errChan chan<-
}
morphChain := &chainParams{
log: s.log,
log: s.log.WithTag(logger.TagMorph),
cfg: cfg,
key: s.key,
name: morphPrefix,

2
pkg/innerring/innerring.go
View file

@ -339,7 +339,7 @@ func New(ctx context.Context, log *logger.Logger, cfg *viper.Viper, errChan chan
) (*Server, error) {
var err error
server := &Server{
log: log,
log: log.WithTag(logger.TagIr),
irMetrics: metrics,
cmode: cmode,
}

2
pkg/local_object_storage/blobovnicza/blobovnicza.go
View file

@ -110,7 +110,7 @@ func WithFullSizeLimit(lim uint64) Option {
// WithLogger returns an option to specify Blobovnicza's logger.
func WithLogger(l *logger.Logger) Option {
return func(c *cfg) {
c.log = l.With(zap.String("component", "Blobovnicza"))
c.log = l.WithTag(logger.TagBlobovnicza)
}
}

2
pkg/local_object_storage/blobstor/blobstor.go
View file

@ -91,7 +91,7 @@ func WithStorages(st []SubStorage) Option {
// WithLogger returns option to specify BlobStor's logger.
func WithLogger(l *logger.Logger) Option {
return func(c *cfg) {
c.log = l.With(zap.String("component", "BlobStor"))
c.log = l.WithTag(logger.TagBlobstor)
}
}

3
pkg/local_object_storage/blobstor/fstree/option.go
View file

@ -4,7 +4,6 @@ import (
"io/fs"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger"
"go.uber.org/zap"
)
type Option func(*FSTree)
@ -53,6 +52,6 @@ func WithFileCounter(c FileCounter) Option {
func WithLogger(l *logger.Logger) Option {
return func(f *FSTree) {
f.log = l.With(zap.String("component", "FSTree"))
f.log = l.WithTag(logger.TagFSTree)
}
}

2
pkg/local_object_storage/engine/engine.go
View file

@ -224,7 +224,7 @@ func New(opts ...Option) *StorageEngine {
// WithLogger returns option to set StorageEngine's logger.
func WithLogger(l *logger.Logger) Option {
return func(c *cfg) {
c.log = l
c.log = l.WithTag(logger.TagEngine)
}
}

2
pkg/local_object_storage/shard/gc.go
View file

@ -495,7 +495,7 @@ func (s *Shard) collectExpiredTombstones(ctx context.Context, e Event) {
}()
epoch := e.(newEpoch).epoch
log := s.log.With(zap.Uint64("epoch", epoch))
log := s.log.With(zap.Uint64("epoch", epoch)).WithTag(logger.TagGC)
log.Debug(ctx, logs.ShardStartedExpiredTombstonesHandling)
defer log.Debug(ctx, logs.ShardFinishedExpiredTombstonesHandling)

4
pkg/local_object_storage/shard/shard.go
View file

@ -204,8 +204,8 @@ func WithPiloramaOptions(opts ...pilorama.Option) Option {
// WithLogger returns option to set Shard's logger.
func WithLogger(l *logger.Logger) Option {
return func(c *cfg) {
c.log = l
c.gcCfg.log = l
c.log = l.WithTag(logger.TagShard)
c.gcCfg.log = l.WithTag(logger.TagGC)
}
}

3
pkg/local_object_storage/writecache/options.go
View file

@ -5,7 +5,6 @@ import (
"git.frostfs.info/TrueCloudLab/frostfs-node/internal/qos"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger"
"go.uber.org/zap"
)
// Option represents write-cache configuration option.
@ -46,7 +45,7 @@ type options struct {
// WithLogger sets logger.
func WithLogger(log *logger.Logger) Option {
return func(o *options) {
o.log = log.With(zap.String("component", "WriteCache"))
o.log = log.WithTag(logger.TagWriteCache)
}
}

2
pkg/services/object/common/writer/ec_test.go
View file

@ -130,7 +130,7 @@ func TestECWriter(t *testing.T) {
nodeKey, err := keys.NewPrivateKey()
require.NoError(t, err)
log, err := logger.NewLogger(nil)
log, err := logger.NewLogger(logger.Prm{})
require.NoError(t, err)
var n nmKeys

2
pkg/services/object/delete/service.go
View file

@ -92,6 +92,6 @@ func New(gs *getsvc.Service,
// WithLogger returns option to specify Delete service's logger.
func WithLogger(l *logger.Logger) Option {
return func(c *cfg) {
c.log = l.With(zap.String("component", "objectSDK.Delete service"))
c.log = l.WithTag(logger.TagDeleteSvc)
}
}

2
pkg/services/object/get/service.go
View file

@ -53,6 +53,6 @@ func New(
// WithLogger returns option to specify Get service's logger.
func WithLogger(l *logger.Logger) Option {
return func(s *Service) {
s.log = l.With(zap.String("component", "Object.Get service"))
s.log = l.WithTag(logger.TagGetSvc)
}
}

2
pkg/services/object/get/v2/service.go
View file

@ -145,6 +145,6 @@ func (s *Service) Head(ctx context.Context, req *objectV2.HeadRequest) (*objectV
func WithLogger(l *logger.Logger) Option {
return func(c *cfg) {
c.log = l.With(zap.String("component", "Object.Get V2 service"))
c.log = l.WithTag(logger.TagGetSvc)
}
}

2
pkg/services/object/search/service.go
View file

@ -94,6 +94,6 @@ func New(e *engine.StorageEngine,
// WithLogger returns option to specify Get service's logger.
func WithLogger(l *logger.Logger) Option {
return func(c *cfg) {
c.log = l.With(zap.String("component", "Object.Search service"))
c.log = l.WithTag(logger.TagSearchSvc)
}
}

4
pkg/services/policer/policer.go
View file

@ -4,9 +4,9 @@ import (
"sync"
"time"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger"
oid "git.frostfs.info/TrueCloudLab/frostfs-sdk-go/object/id"
lru "github.com/hashicorp/golang-lru/v2"
"go.uber.org/zap"
)
type objectsInWork struct {
@ -54,7 +54,7 @@ func New(opts ...Option) *Policer {
opts[i](c)
}
c.log = c.log.With(zap.String("component", "Object Policer"))
c.log = c.log.WithTag(logger.TagPolicer)
cache, err := lru.New[oid.Address, time.Time](int(c.cacheSize))
if err != nil {

3
pkg/services/replicator/replicator.go
View file

@ -7,7 +7,6 @@ import (
objectwriter "git.frostfs.info/TrueCloudLab/frostfs-node/pkg/services/object/common/writer"
getsvc "git.frostfs.info/TrueCloudLab/frostfs-node/pkg/services/object/get"
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger"
"go.uber.org/zap"
)
// Replicator represents the utility that replicates
@ -45,7 +44,7 @@ func New(opts ...Option) *Replicator {
opts[i](c)
}
c.log = c.log.With(zap.String("component", "Object Replicator"))
c.log = c.log.WithTag(logger.TagReplicator)
return &Replicator{
cfg: c,

5
pkg/services/session/executor.go
View file

@ -33,10 +33,7 @@ func NewExecutionService(exec ServiceExecutor, respSvc *response.Service, l *log
}
func (s *executorSvc) Create(ctx context.Context, req *session.CreateRequest) (*session.CreateResponse, error) {
s.log.Debug(ctx, logs.ServingRequest,
zap.String("component", "SessionService"),
zap.String("request", "Create"),
)
s.log.Debug(ctx, logs.ServingRequest, zap.String("request", "Create"))
respBody, err := s.exec.Create(ctx, req.GetBody())
if err != nil {

21
pkg/util/logger/log.go
View file

@ -6,21 +6,34 @@ import (
"git.frostfs.info/TrueCloudLab/frostfs-node/pkg/tracing"
qos "git.frostfs.info/TrueCloudLab/frostfs-qos/tagging"
"go.uber.org/zap"
"go.uber.org/zap/zapcore"
)
func (l *Logger) Debug(ctx context.Context, msg string, fields ...zap.Field) {
if l.denyLogEntry(zapcore.DebugLevel) {
return
}
l.z.Debug(msg, appendContext(ctx, fields...)...)
}
func (l *Logger) Info(ctx context.Context, msg string, fields ...zap.Field) {
if l.denyLogEntry(zapcore.InfoLevel) {
return
}
l.z.Info(msg, appendContext(ctx, fields...)...)
}
func (l *Logger) Warn(ctx context.Context, msg string, fields ...zap.Field) {
if l.denyLogEntry(zapcore.WarnLevel) {
return
}
l.z.Warn(msg, appendContext(ctx, fields...)...)
}
func (l *Logger) Error(ctx context.Context, msg string, fields ...zap.Field) {
if l.denyLogEntry(zapcore.ErrorLevel) {
return
}
l.z.Error(msg, appendContext(ctx, fields...)...)
}
@ -33,3 +46,11 @@ func appendContext(ctx context.Context, fields ...zap.Field) []zap.Field {
}
return fields
}
func (l *Logger) denyLogEntry(level zapcore.Level) bool {
tl := l.tl.Load().(map[Tag]zapcore.Level)
if lvl, ok := tl[l.t]; ok {
return level < lvl
}
return level < l.lvl.Level()
}

94
pkg/util/logger/logger.go
View file

@ -2,6 +2,7 @@ package logger
import (
"fmt"
"sync/atomic"
"time"
"git.frostfs.info/TrueCloudLab/zapjournald"
@ -15,6 +16,12 @@ import (
type Logger struct {
z *zap.Logger
lvl zap.AtomicLevel
// Tag used by Logger
t Tag
// Contains map of Tag to log level, overrides lvl
tl *atomic.Value
// Parent zap.Logger, required to override field zapTagFieldName in the output
pz *zap.Logger
}
// Prm groups Logger's parameters.
@ -23,16 +30,8 @@ type Logger struct {
// Parameters that have been connected to the Logger support its
// configuration changing.
//
// Passing Prm after a successful connection via the NewLogger, connects
// the Prm to a new instance of the Logger.
//
// See also Reload, SetLevelString.
// See also Logger.Reload, SetLevelString.
type Prm struct {
// link to the created Logger
// instance; used for a runtime
// reconfiguration
_log *Logger
// support runtime rereading
level zapcore.Level
@ -44,12 +43,17 @@ type Prm struct {
// PrependTimestamp specifies whether to prepend a timestamp in the log
PrependTimestamp bool
// map of tag's bit masks to log level, overrides lvl
tl map[Tag]zapcore.Level
}
const (
DestinationUndefined = ""
DestinationStdout = "stdout"
DestinationJournald = "journald"
zapTagFieldName = "tag"
)
// SetLevelString sets the minimum logging level. Default is
@ -73,20 +77,10 @@ func (p *Prm) SetDestination(d string) error {
return nil
}
// Reload reloads configuration of a connected instance of the Logger.
// Returns ErrLoggerNotConnected if no connection has been performed.
// Returns any reconfiguration error from the Logger directly.
func (p Prm) Reload() error {
if p._log == nil {
// incorrect logger usage
panic("parameters are not connected to any Logger")
}
return p._log.reload(p)
}
func defaultPrm() *Prm {
return new(Prm)
// SetTags parses list of tags with log level.
func (p *Prm) SetTags(tags [][]string) (err error) {
p.tl, err = parseTags(tags)
return err
}
// NewLogger constructs a new zap logger instance. Constructing with nil
@ -100,10 +94,7 @@ func defaultPrm() *Prm {
// - ISO8601 time encoding.
//
// Logger records a stack trace for all messages at or above fatal level.
func NewLogger(prm *Prm) (*Logger, error) {
if prm == nil {
prm = defaultPrm()
}
func NewLogger(prm Prm) (*Logger, error) {
switch prm.dest {
case DestinationUndefined, DestinationStdout:
return newConsoleLogger(prm)
@ -114,11 +105,9 @@ func NewLogger(prm *Prm) (*Logger, error) {
}
}
func newConsoleLogger(prm *Prm) (*Logger, error) {
lvl := zap.NewAtomicLevelAt(prm.level)
func newConsoleLogger(prm Prm) (*Logger, error) {
c := zap.NewProductionConfig()
c.Level = lvl
c.Level = zap.NewAtomicLevelAt(zapcore.DebugLevel)
c.Encoding = "console"
if prm.SamplingHook != nil {
c.Sampling.Hook = prm.SamplingHook
@ -137,16 +126,19 @@ func newConsoleLogger(prm *Prm) (*Logger, error) {
if err != nil {
return nil, err
}
parentZap := *lZap
lZap = lZap.With(zap.String(zapTagFieldName, tagToString(TagMain)))
l := &Logger{z: lZap, lvl: lvl}
prm._log = l
v := atomic.Value{}
v.Store(prm.tl)
l := &Logger{z: lZap, pz: &parentZap, lvl: zap.NewAtomicLevelAt(prm.level), t: TagMain, tl: &v}
return l, nil
}
func newJournaldLogger(prm *Prm) (*Logger, error) {
lvl := zap.NewAtomicLevelAt(prm.level)
func newJournaldLogger(prm Prm) (*Logger, error) {
lvl := zap.NewAtomicLevelAt(zapcore.DebugLevel)
c := zap.NewProductionConfig()
if prm.SamplingHook != nil {
c.Sampling.Hook = prm.SamplingHook
@ -179,28 +171,48 @@ func newJournaldLogger(prm *Prm) (*Logger, error) {
samplerOpts...,
)
lZap := zap.New(samplingCore, zap.AddStacktrace(zap.NewAtomicLevelAt(zap.FatalLevel)), zap.AddCallerSkip(1))
parentZap := *lZap
lZap = lZap.With(zap.String(zapTagFieldName, tagToString(TagMain)))
l := &Logger{z: lZap, lvl: lvl}
prm._log = l
v := atomic.Value{}
v.Store(prm.tl)
l := &Logger{z: lZap, pz: &parentZap, lvl: zap.NewAtomicLevelAt(prm.level), t: TagMain, tl: &v}
return l, nil
}
func (l *Logger) reload(prm Prm) error {
func (l *Logger) Reload(prm Prm) {
l.lvl.SetLevel(prm.level)
return nil
l.tl.Store(prm.tl)
}
func (l *Logger) WithOptions(options ...zap.Option) {
l.z = l.z.WithOptions(options...)
l.pz = l.pz.WithOptions(options...)
}
func (l *Logger) With(fields ...zap.Field) *Logger {
return &Logger{z: l.z.With(fields...)}
c := *l
c.z = l.z.With(fields...)
return &c
}
func (l *Logger) WithTag(tag Tag) *Logger {
c := *l
c.t = tag
c.z = c.pz.With(zap.String(zapTagFieldName, tagToString(tag)))
return &c
}
func NewLoggerWrapper(z *zap.Logger) *Logger {
tl := &atomic.Value{}
tl.Store(make(map[Tag]zapcore.Level))
return &Logger{
z: z.WithOptions(zap.AddCallerSkip(1)),
pz: z.WithOptions(zap.AddCallerSkip(1)),
tl: tl,
lvl: zap.NewAtomicLevelAt(zapcore.DebugLevel),
}
}

78
pkg/util/logger/logger_test.go Normal file
View file

@ -0,0 +1,78 @@
package logger
import (
"context"
"testing"
"github.com/stretchr/testify/require"
)
func BenchmarkLoggerDebug(b *testing.B) {
ctx := context.Background()
prm := Prm{}
require.NoError(b, prm.SetLevelString("debug"))
logger, err := NewLogger(prm)
require.NoError(b, err)
b.ResetTimer()
b.ReportAllocs()
for range b.N {
logger.Debug(ctx, "test debug")
logger.Info(ctx, "test info")
logger.Warn(ctx, "test warn")
logger.Error(ctx, "test error")
}
}
func BenchmarkLoggerError(b *testing.B) {
ctx := context.Background()
prm := Prm{}
require.NoError(b, prm.SetLevelString("error"))
logger, err := NewLogger(prm)
require.NoError(b, err)
b.ResetTimer()
b.ReportAllocs()
for range b.N {
logger.Debug(ctx, "test debug")
logger.Info(ctx, "test info")
logger.Warn(ctx, "test warn")
logger.Error(ctx, "test error")
}
}
func BenchmarkLoggerLevelLess(b *testing.B) {
ctx := context.Background()
prm := Prm{}
require.NoError(b, prm.SetLevelString("info"))
require.NoError(b, prm.SetTags([][]string{{"main", "debug"}, {"morph", "debug"}}))
logger, err := NewLogger(prm)
require.NoError(b, err)
b.ResetTimer()
b.ReportAllocs()
for range b.N {
logger.Debug(ctx, "test debug")
logger.Info(ctx, "test info")
logger.Warn(ctx, "test warn")
logger.Error(ctx, "test error")
}
}
func BenchmarkLoggerLevelGreater(b *testing.B) {
ctx := context.Background()
prm := Prm{}
require.NoError(b, prm.SetLevelString("debug"))
require.NoError(b, prm.SetTags([][]string{{"main", "error"}, {"morph", "debug"}}))
logger, err := NewLogger(prm)
require.NoError(b, err)
b.ResetTimer()
b.ReportAllocs()
for range b.N {
logger.Debug(ctx, "test debug")
logger.Info(ctx, "test info")
logger.Warn(ctx, "test warn")
logger.Error(ctx, "test error")
}
}

71
pkg/util/logger/logger_test.result Normal file
View file

@ -0,0 +1,71 @@
BenchmarkLoggerDebug
goos: linux
goarch: amd64
pkg: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger
cpu: 11th Gen Intel(R) Core(TM) i5-1135G7 @ 2.40GHz
10000 534.6 ns/op 23 B/op 0 allocs/op
10000 530.9 ns/op 23 B/op 0 allocs/op
10000 667.4 ns/op 23 B/op 0 allocs/op
10000 582.2 ns/op 23 B/op 0 allocs/op
10000 530.7 ns/op 23 B/op 0 allocs/op
10000 666.8 ns/op 23 B/op 0 allocs/op
10000 533.1 ns/op 23 B/op 0 allocs/op
10000 531.8 ns/op 23 B/op 0 allocs/op
10000 529.5 ns/op 22 B/op 0 allocs/op
10000 645.0 ns/op 23 B/op 0 allocs/op
PASS
ok git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger 0.069s
BenchmarkLoggerError
goos: linux
goarch: amd64
pkg: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger
cpu: 11th Gen Intel(R) Core(TM) i5-1135G7 @ 2.40GHz
10000 137.3 ns/op 6 B/op 0 allocs/op
10000 144.2 ns/op 6 B/op 0 allocs/op
10000 137.5 ns/op 6 B/op 0 allocs/op
10000 142.6 ns/op 6 B/op 0 allocs/op
10000 136.3 ns/op 6 B/op 0 allocs/op
10000 137.0 ns/op 6 B/op 0 allocs/op
10000 144.0 ns/op 6 B/op 0 allocs/op
10000 152.6 ns/op 6 B/op 0 allocs/op
10000 136.4 ns/op 6 B/op 0 allocs/op
10000 137.9 ns/op 6 B/op 0 allocs/op
PASS
ok git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger 0.024s
BenchmarkLoggerLevelLess
goos: linux
goarch: amd64
pkg: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger
cpu: 11th Gen Intel(R) Core(TM) i5-1135G7 @ 2.40GHz
10000 554.3 ns/op 23 B/op 0 allocs/op
10000 630.1 ns/op 23 B/op 0 allocs/op
10000 642.0 ns/op 23 B/op 0 allocs/op
10000 548.0 ns/op 23 B/op 0 allocs/op
10000 562.7 ns/op 23 B/op 0 allocs/op
10000 572.7 ns/op 23 B/op 0 allocs/op
10000 552.1 ns/op 23 B/op 0 allocs/op
10000 555.4 ns/op 23 B/op 0 allocs/op
10000 546.0 ns/op 23 B/op 0 allocs/op
10000 561.0 ns/op 22 B/op 0 allocs/op
PASS
ok git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger 0.069s
BenchmarkLoggerLevelGreater
goos: linux
goarch: amd64
pkg: git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger
cpu: 11th Gen Intel(R) Core(TM) i5-1135G7 @ 2.40GHz
10000 159.6 ns/op 6 B/op 0 allocs/op
10000 161.9 ns/op 6 B/op 0 allocs/op
10000 161.4 ns/op 6 B/op 0 allocs/op
10000 160.9 ns/op 6 B/op 0 allocs/op
10000 166.9 ns/op 6 B/op 0 allocs/op
10000 163.9 ns/op 6 B/op 0 allocs/op
10000 163.4 ns/op 6 B/op 0 allocs/op
10000 158.7 ns/op 6 B/op 0 allocs/op
10000 173.2 ns/op 6 B/op 0 allocs/op
10000 160.7 ns/op 6 B/op 0 allocs/op
PASS
ok git.frostfs.info/TrueCloudLab/frostfs-node/pkg/util/logger 0.028s

177
pkg/util/logger/tags.go Normal file
View file

@ -0,0 +1,177 @@
package logger
import (
"fmt"
"math"
"strings"
"go.uber.org/zap/zapcore"
)
type Tag uint8
const (
TagMain Tag = iota
TagMorph
TagGrpcSvc
TagIr
TagProcessor
TagEngine
TagBlobovnicza
TagBlobstor
TagFSTree
TagGC
TagShard
TagWriteCache
TagDeleteSvc
TagGetSvc
TagSearchSvc
TagSessionSvc
TagTreeSvc
TagPolicer
TagReplicator
tagMain = "main"
tagMorph = "morph"
tagGrpcSvc = "grpc_svc"
tagIr = "ir"
tagProcessor = "processor"
tagEngine = "engine"
tagBlobovnicza = "blobovnicza"
tagBlobstor = "blobstor"
tagFSTree = "fstree"
tagGC = "gc"
tagShard = "shard"
tagWriteCache = "writecache"
tagDeleteSvc = "deletesvc"
tagGetSvc = "getsvc"
tagSearchSvc = "searchsvc"
tagSessionSvc = "sessionsvc"
tagTreeSvc = "treesvc"
tagPolicer = "policer"
tagReplicator = "replicator"
)
// tagToMask return bit mask for the tag, encoded in uint32.
func tagFromString(str string) (Tag, error) {
switch str {
case tagMain:
return TagMain, nil
case tagMorph:
return TagMorph, nil
case tagGrpcSvc:
return TagGrpcSvc, nil
case tagIr:
return TagIr, nil
case tagProcessor:
return TagProcessor, nil
case tagEngine:
return TagEngine, nil
case tagBlobovnicza:
return TagBlobovnicza, nil
case tagBlobstor:
return TagBlobstor, nil
case tagFSTree:
return TagFSTree, nil
case tagGC:
return TagGC, nil
case tagShard:
return TagShard, nil
case tagWriteCache:
return TagWriteCache, nil
case tagDeleteSvc:
return TagDeleteSvc, nil
case tagGetSvc:
return TagGetSvc, nil
case tagSearchSvc:
return TagSearchSvc, nil
case tagSessionSvc:
return TagSessionSvc, nil
case tagTreeSvc:
return TagTreeSvc, nil
case tagPolicer:
return TagPolicer, nil
case tagReplicator:
return TagReplicator, nil
default:
return math.MaxUint8, fmt.Errorf("unsupported tag %s", str)
}
}
// tagToString return string representation for the tag.
func tagToString(tag Tag) string {
switch tag {
case TagMain:
return tagMain
case TagMorph:
return tagMorph
case TagGrpcSvc:
return tagGrpcSvc
case TagIr:
return tagIr
case TagProcessor:
return tagProcessor
case TagEngine:
return tagEngine
case TagBlobovnicza:
return tagBlobovnicza
case TagBlobstor:
return tagBlobstor
case TagFSTree:
return tagFSTree
case TagGC:
return tagGC
case TagShard:
return tagShard
case TagWriteCache:
return tagWriteCache
case TagDeleteSvc:
return tagDeleteSvc
case TagGetSvc:
return tagGetSvc
case TagSearchSvc:
return tagSearchSvc
case TagSessionSvc:
return tagSessionSvc
case TagTreeSvc:
return tagTreeSvc
case TagPolicer:
return tagPolicer
case TagReplicator:
return tagReplicator
default:
return ""
}
}
// parseTags returns:
// - map(always instantiated) of tag to custom log level for that tag;
// - error if it occurred(map is empty).
func parseTags(raw [][]string) (map[Tag]zapcore.Level, error) {
m := make(map[Tag]zapcore.Level)
if len(raw) == 0 {
return m, nil
}
for _, item := range raw {
str, level := item[0], item[1]
if len(level) == 0 {
// It is not necessary to parse tags without level,
// because default log level will be used.
continue
}
var l zapcore.Level
err := l.UnmarshalText([]byte(level))
if err != nil {
return nil, err
}
tmp := strings.Split(str, ",")
for _, tagStr := range tmp {
tag, err := tagFromString(strings.TrimSpace(tagStr))
if err != nil {
return nil, err
}
m[tag] = l
}
}
return m, nil
}