Skip to content

Commit

Permalink
Move logger subsystem variables to internal package
Browse files Browse the repository at this point in the history
This will allow the loader package to pass in appropriate logger
variables for the subsystems that it initializes.
  • Loading branch information
jrick committed Apr 24, 2023
1 parent dc82294 commit c6933a3
Show file tree
Hide file tree
Showing 5 changed files with 121 additions and 98 deletions.
3 changes: 2 additions & 1 deletion config.go
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@ import (

"decred.org/dcrwallet/v3/errors"
"decred.org/dcrwallet/v3/internal/cfgutil"
"decred.org/dcrwallet/v3/internal/loggers"
"decred.org/dcrwallet/v3/internal/netparams"
"decred.org/dcrwallet/v3/version"
"decred.org/dcrwallet/v3/wallet"
Expand Down Expand Up @@ -518,7 +519,7 @@ func loadConfig(ctx context.Context) (*config, []string, error) {

// Initialize log rotation. After log rotation has been initialized, the
// logger variables may be used.
initLogRotator(filepath.Join(cfg.LogDir.Value, defaultLogFilename), logsize)
loggers.InitLogRotator(filepath.Join(cfg.LogDir.Value, defaultLogFilename), logsize)
}

// Special show command to list supported subsystems and exit.
Expand Down
9 changes: 3 additions & 6 deletions dcrwallet.go
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@ import (
"decred.org/dcrwallet/v3/chain"
"decred.org/dcrwallet/v3/errors"
ldr "decred.org/dcrwallet/v3/internal/loader"
"decred.org/dcrwallet/v3/internal/loggers"
"decred.org/dcrwallet/v3/internal/prompt"
"decred.org/dcrwallet/v3/internal/rpc/rpcserver"
"decred.org/dcrwallet/v3/internal/vsp"
Expand Down Expand Up @@ -83,11 +84,7 @@ func run(ctx context.Context) error {
return err
}
cfg = tcfg
defer func() {
if logRotator != nil {
logRotator.Close()
}
}()
defer loggers.CloseLogRotator()

// Show version at startup.
log.Infof("Version %s (Go version %s %s/%s)", version.String(), runtime.Version(),
Expand Down Expand Up @@ -575,7 +572,7 @@ func rpcSyncLoop(ctx context.Context, w *wallet.Wallet) {
})
err := syncer.Run(ctx)
if err != nil {
syncLog.Errorf("Wallet synchronization stopped: %v", err)
loggers.SyncLog.Errorf("Wallet synchronization stopped: %v", err)
select {
case <-ctx.Done():
return
Expand Down
87 changes: 87 additions & 0 deletions internal/loggers/loggers.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,87 @@
// Copyright (c) 2023 The Decred developers
// Use of this source code is governed by an ISC
// license that can be found in the LICENSE file.

package loggers

import (
"fmt"
"os"
"path/filepath"

"github.com/decred/slog"
"github.com/jrick/logrotate/rotator"
)

// logWriter implements an io.Writer that outputs to both standard output and
// the write-end pipe of an initialized log rotator.
type logWriter struct{}

func (logWriter) Write(p []byte) (n int, err error) {
os.Stdout.Write(p)
if logRotator != nil {
logRotator.Write(p)
}
return len(p), nil
}

// Loggers per subsystem. A single backend logger is created and all subsytem
// loggers created from it will write to the backend. When adding new
// subsystems, add the subsystem logger variable here and to the
// subsystemLoggers map.
//
// Loggers can not be used before the log rotator has been initialized with a
// log file. This must be performed early during application startup by calling
// initLogRotator.
var (
// backendLog is the logging backend used to create all subsystem loggers.
// The backend must not be used before the log rotator has been initialized,
// or data races and/or nil pointer dereferences will occur.
backendLog = slog.NewBackend(logWriter{})

// logRotator is one of the logging outputs. It should be closed on
// application shutdown.
logRotator *rotator.Rotator

MainLog = backendLog.Logger("DCRW")
LoaderLog = backendLog.Logger("LODR")
WalletLog = backendLog.Logger("WLLT")
TkbyLog = backendLog.Logger("TKBY")
SyncLog = backendLog.Logger("SYNC")
GrpcLog = backendLog.Logger("GRPC")
JsonrpcLog = backendLog.Logger("RPCS")
CmgrLog = backendLog.Logger("CMGR")
VspcLog = backendLog.Logger("VSPC")
)

// InitLogRotator initializes the logging rotater to write logs to logFile and
// create roll files in the same directory. logSize is the size in KiB after
// which a log file will be rotated and compressed.
//
// This function must be called before the package-global log rotater variables
// are used.
func InitLogRotator(logFile string, logSize int64) {
logDir, _ := filepath.Split(logFile)
err := os.MkdirAll(logDir, 0700)
if err != nil {
fmt.Fprintf(os.Stderr, "failed to create log directory: %v\n", err)
os.Exit(1)
}
r, err := rotator.New(logFile, logSize, false, 0)
if err != nil {
fmt.Fprintf(os.Stderr, "failed to create file rotator: %v\n", err)
os.Exit(1)
}

logRotator = r
}

// CloseLogRotator closes the log rotator, syncing all file writes, if the
// rotator was initialized.
func CloseLogRotator() error {
if logRotator == nil {
return nil
}

return logRotator.Close()
}
109 changes: 23 additions & 86 deletions log.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,12 +6,11 @@
package main

import (
"fmt"
"os"
"path/filepath"

"decred.org/dcrwallet/v3/chain"
"decred.org/dcrwallet/v3/internal/loader"
"decred.org/dcrwallet/v3/internal/loggers"
"decred.org/dcrwallet/v3/internal/rpc/jsonrpc"
"decred.org/dcrwallet/v3/internal/rpc/rpcserver"
"decred.org/dcrwallet/v3/internal/vsp"
Expand All @@ -22,98 +21,36 @@ import (
"decred.org/dcrwallet/v3/wallet/udb"
"github.com/decred/dcrd/connmgr/v3"
"github.com/decred/slog"
"github.com/jrick/logrotate/rotator"
)

// logWriter implements an io.Writer that outputs to both standard output and
// the write-end pipe of an initialized log rotator.
type logWriter struct{}

func (logWriter) Write(p []byte) (n int, err error) {
os.Stdout.Write(p)
if logRotator != nil {
logRotator.Write(p)
}
return len(p), nil
}

// Loggers per subsystem. A single backend logger is created and all subsytem
// loggers created from it will write to the backend. When adding new
// subsystems, add the subsystem logger variable here and to the
// subsystemLoggers map.
//
// Loggers can not be used before the log rotator has been initialized with a
// log file. This must be performed early during application startup by calling
// initLogRotator.
var (
// backendLog is the logging backend used to create all subsystem loggers.
// The backend must not be used before the log rotator has been initialized,
// or data races and/or nil pointer dereferences will occur.
backendLog = slog.NewBackend(logWriter{})

// logRotator is one of the logging outputs. It should be closed on
// application shutdown.
logRotator *rotator.Rotator

log = backendLog.Logger("DCRW")
loaderLog = backendLog.Logger("LODR")
walletLog = backendLog.Logger("WLLT")
tkbyLog = backendLog.Logger("TKBY")
syncLog = backendLog.Logger("SYNC")
grpcLog = backendLog.Logger("GRPC")
jsonrpcLog = backendLog.Logger("RPCS")
cmgrLog = backendLog.Logger("CMGR")
vspcLog = backendLog.Logger("VSPC")
)
var log = loggers.MainLog

// Initialize package-global logger variables.
func init() {
loader.UseLogger(loaderLog)
wallet.UseLogger(walletLog)
udb.UseLogger(walletLog)
ticketbuyer.UseLogger(tkbyLog)
chain.UseLogger(syncLog)
spv.UseLogger(syncLog)
p2p.UseLogger(syncLog)
rpcserver.UseLogger(grpcLog)
jsonrpc.UseLogger(jsonrpcLog)
connmgr.UseLogger(cmgrLog)
vsp.UseLogger(vspcLog)
loader.UseLogger(loggers.LoaderLog)
wallet.UseLogger(loggers.WalletLog)
udb.UseLogger(loggers.WalletLog)
ticketbuyer.UseLogger(loggers.TkbyLog)
chain.UseLogger(loggers.SyncLog)
spv.UseLogger(loggers.SyncLog)
p2p.UseLogger(loggers.SyncLog)
rpcserver.UseLogger(loggers.GrpcLog)
jsonrpc.UseLogger(loggers.JsonrpcLog)
connmgr.UseLogger(loggers.CmgrLog)
vsp.UseLogger(loggers.VspcLog)
}

// subsystemLoggers maps each subsystem identifier to its associated logger.
var subsystemLoggers = map[string]slog.Logger{
"DCRW": log,
"LODR": loaderLog,
"WLLT": walletLog,
"TKBY": tkbyLog,
"SYNC": syncLog,
"GRPC": grpcLog,
"RPCS": jsonrpcLog,
"CMGR": cmgrLog,
"VSPC": vspcLog,
}

// initLogRotator initializes the logging rotater to write logs to logFile and
// create roll files in the same directory. logSize is the size in KiB after
// which a log file will be rotated and compressed.
//
// This function must be called before the package-global log rotater variables
// are used.
func initLogRotator(logFile string, logSize int64) {
logDir, _ := filepath.Split(logFile)
err := os.MkdirAll(logDir, 0700)
if err != nil {
fmt.Fprintf(os.Stderr, "failed to create log directory: %v\n", err)
os.Exit(1)
}
r, err := rotator.New(logFile, logSize, false, 0)
if err != nil {
fmt.Fprintf(os.Stderr, "failed to create file rotator: %v\n", err)
os.Exit(1)
}

logRotator = r
"DCRW": loggers.MainLog,
"LODR": loggers.LoaderLog,
"WLLT": loggers.WalletLog,
"TKBY": loggers.TkbyLog,
"SYNC": loggers.SyncLog,
"GRPC": loggers.GrpcLog,
"RPCS": loggers.JsonrpcLog,
"CMGR": loggers.CmgrLog,
"VSPC": loggers.VspcLog,
}

// setLogLevel sets the logging level for provided subsystem. Invalid
Expand Down Expand Up @@ -147,6 +84,6 @@ func setLogLevels(logLevel string) {
func fatalf(format string, args ...interface{}) {
log.Errorf(format, args...)
os.Stdout.Sync()
logRotator.Close()
loggers.CloseLogRotator()
os.Exit(1)
}
11 changes: 6 additions & 5 deletions rpcserver.go
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ import (
"decred.org/dcrwallet/v3/errors"
"decred.org/dcrwallet/v3/internal/cfgutil"
"decred.org/dcrwallet/v3/internal/loader"
"decred.org/dcrwallet/v3/internal/loggers"
"decred.org/dcrwallet/v3/internal/rpc/jsonrpc"
"decred.org/dcrwallet/v3/internal/rpc/rpcserver"

Expand Down Expand Up @@ -401,7 +402,7 @@ func serviceName(method string) string {
func interceptStreaming(srv interface{}, ss grpc.ServerStream, info *grpc.StreamServerInfo, handler grpc.StreamHandler) error {
p, ok := peer.FromContext(ss.Context())
if ok {
grpcLog.Debugf("Streaming method %s invoked by %s", info.FullMethod,
loggers.GrpcLog.Debugf("Streaming method %s invoked by %s", info.FullMethod,
p.Addr.String())
}
err := rpcserver.ServiceReady(serviceName(info.FullMethod))
Expand All @@ -410,12 +411,12 @@ func interceptStreaming(srv interface{}, ss grpc.ServerStream, info *grpc.Stream
}
err = handler(srv, ss)
if err != nil && ok {
logf := grpcLog.Errorf
logf := loggers.GrpcLog.Errorf
if status.Code(err) == codes.Canceled && done(ss.Context()) {
// Canceled contexts in streaming calls are expected
// when client-initiated, so only log them with debug
// level to reduce clutter.
logf = grpcLog.Debugf
logf = loggers.GrpcLog.Debugf
}

logf("Streaming method %s invoked by %s errored: %v",
Expand All @@ -427,7 +428,7 @@ func interceptStreaming(srv interface{}, ss grpc.ServerStream, info *grpc.Stream
func interceptUnary(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (resp interface{}, err error) {
p, ok := peer.FromContext(ctx)
if ok {
grpcLog.Debugf("Unary method %s invoked by %s", info.FullMethod,
loggers.GrpcLog.Debugf("Unary method %s invoked by %s", info.FullMethod,
p.Addr.String())
}
err = rpcserver.ServiceReady(serviceName(info.FullMethod))
Expand All @@ -436,7 +437,7 @@ func interceptUnary(ctx context.Context, req interface{}, info *grpc.UnaryServer
}
resp, err = handler(ctx, req)
if err != nil && ok {
grpcLog.Errorf("Unary method %s invoked by %s errored: %v",
loggers.GrpcLog.Errorf("Unary method %s invoked by %s errored: %v",
info.FullMethod, p.Addr.String(), err)
}
return resp, err
Expand Down

0 comments on commit c6933a3

Please sign in to comment.