Remove remaining global loggers.

This removes all of the global loggers from the project and replaces them with loggers which are instantiated in vspd.go and passed down as params.

To support this, the background package was removed. It only contained one file so it was a bit pointless anyway. It only existed so background tasks could have their own named logger.
This commit is contained in:
jholdstock 2022-06-23 11:56:33 +01:00 committed by Jamie Holdstock
parent ebcfe0e5e9
commit 65fab01225
19 changed files with 134 additions and 283 deletions

View File

@ -2,12 +2,13 @@
// Use of this source code is governed by an ISC // Use of this source code is governed by an ISC
// license that can be found in the LICENSE file. // license that can be found in the LICENSE file.
package background package main
import ( import (
"errors" "errors"
"strings" "strings"
"github.com/decred/slog"
"github.com/decred/vspd/database" "github.com/decred/vspd/database"
"github.com/decred/vspd/rpc" "github.com/decred/vspd/rpc"
"github.com/jrick/wsrpc/v2" "github.com/jrick/wsrpc/v2"
@ -22,7 +23,7 @@ const (
// BlockConnected is called once when vspd starts up, and once each time a // BlockConnected is called once when vspd starts up, and once each time a
// blockconnected notification is received from dcrd. // blockconnected notification is received from dcrd.
func BlockConnected(dcrdRPC rpc.DcrdConnect, walletRPC rpc.WalletConnect, db *database.VspDatabase) { func BlockConnected(dcrdRPC rpc.DcrdConnect, walletRPC rpc.WalletConnect, db *database.VspDatabase, log slog.Logger) {
const funcName = "BlockConnected" const funcName = "BlockConnected"
@ -283,7 +284,7 @@ func BlockConnected(dcrdRPC rpc.DcrdConnect, walletRPC rpc.WalletConnect, db *da
// CheckWalletConsistency will retrieve all votable tickets from the database // CheckWalletConsistency will retrieve all votable tickets from the database
// and ensure they are all added to voting wallets with the correct vote // and ensure they are all added to voting wallets with the correct vote
// choices. // choices.
func CheckWalletConsistency(dcrdRPC rpc.DcrdConnect, walletRPC rpc.WalletConnect, db *database.VspDatabase) { func CheckWalletConsistency(dcrdRPC rpc.DcrdConnect, walletRPC rpc.WalletConnect, db *database.VspDatabase, log slog.Logger) {
const funcName = "CheckWalletConsistency" const funcName = "CheckWalletConsistency"

View File

@ -1,30 +0,0 @@
// Copyright (c) 2020 The Decred developers
// Use of this source code is governed by an ISC
// license that can be found in the LICENSE file.
package background
import (
"github.com/decred/slog"
)
// log is a logger that is initialized with no output filters. This
// means the package will not perform any logging by default until the caller
// requests it.
var log slog.Logger
// The default amount of logging is none.
func init() {
DisableLog()
}
// DisableLog disables all library log output. Logging output is disabled
// by default until UseLogger is called.
func DisableLog() {
log = slog.Disabled
}
// UseLogger uses a specified Logger to output package logging info.
func UseLogger(logger slog.Logger) {
log = logger
}

View File

@ -35,7 +35,6 @@ var (
defaultNetwork = "testnet" defaultNetwork = "testnet"
defaultHomeDir = dcrutil.AppDataDir(appName, false) defaultHomeDir = dcrutil.AppDataDir(appName, false)
defaultConfigFilename = fmt.Sprintf("%s.conf", appName) defaultConfigFilename = fmt.Sprintf("%s.conf", appName)
defaultLogFilename = fmt.Sprintf("%s.log", appName)
defaultDBFilename = fmt.Sprintf("%s.db", appName) defaultDBFilename = fmt.Sprintf("%s.db", appName)
defaultConfigFile = filepath.Join(defaultHomeDir, defaultConfigFilename) defaultConfigFile = filepath.Join(defaultHomeDir, defaultConfigFilename)
defaultDcrdHost = "127.0.0.1" defaultDcrdHost = "127.0.0.1"
@ -76,6 +75,9 @@ type config struct {
HomeDir string `long:"homedir" no-ini:"true" description:"Path to application home directory. Used for storing VSP database and logs."` HomeDir string `long:"homedir" no-ini:"true" description:"Path to application home directory. Used for storing VSP database and logs."`
ConfigFile string `long:"configfile" no-ini:"true" description:"Path to configuration file."` ConfigFile string `long:"configfile" no-ini:"true" description:"Path to configuration file."`
logBackend *slog.Backend
logLevel slog.Level
dbPath string dbPath string
netParams *netParams netParams *netParams
dcrdCert []byte dcrdCert []byte
@ -406,8 +408,16 @@ func loadConfig() (*config, error) {
// Initialize loggers and log rotation. // Initialize loggers and log rotation.
logDir := filepath.Join(cfg.HomeDir, "logs", cfg.netParams.Name) logDir := filepath.Join(cfg.HomeDir, "logs", cfg.netParams.Name)
initLogRotator(filepath.Join(logDir, defaultLogFilename), cfg.MaxLogSize, cfg.LogsToKeep) cfg.logBackend, err = NewLogBackend(logDir, appName, cfg.MaxLogSize, cfg.LogsToKeep)
setLogLevels(cfg.LogLevel) if err != nil {
return nil, fmt.Errorf("failed to initialize logger: %w", err)
}
var ok bool
cfg.logLevel, ok = slog.LevelFromString(cfg.LogLevel)
if !ok {
return nil, fmt.Errorf("unknown log level: %s", cfg.LogLevel)
}
// Set the database path // Set the database path
cfg.dbPath = filepath.Join(dataDir, defaultDBFilename) cfg.dbPath = filepath.Join(dataDir, defaultDBFilename)
@ -427,7 +437,7 @@ func loadConfig() (*config, error) {
} }
// Create new database. // Create new database.
err = database.CreateNew(cfg.dbPath, cfg.FeeXPub) err = database.CreateNew(cfg.dbPath, cfg.FeeXPub, cfg.Logger(" DB"))
if err != nil { if err != nil {
return nil, fmt.Errorf("error creating db file %s: %w", cfg.dbPath, err) return nil, fmt.Errorf("error creating db file %s: %w", cfg.dbPath, err)
} }
@ -445,3 +455,9 @@ func loadConfig() (*config, error) {
return &cfg, nil return &cfg, nil
} }
func (cfg *config) Logger(subsystem string) slog.Logger {
log := cfg.logBackend.Logger(subsystem)
log.SetLevel(cfg.logLevel)
return log
}

View File

@ -16,6 +16,7 @@ import (
"sync" "sync"
"time" "time"
"github.com/decred/slog"
"github.com/decred/vspd/rpc" "github.com/decred/vspd/rpc"
bolt "go.etcd.io/bbolt" bolt "go.etcd.io/bbolt"
) )
@ -25,6 +26,7 @@ import (
type VspDatabase struct { type VspDatabase struct {
db *bolt.DB db *bolt.DB
maxVoteChangeRecords int maxVoteChangeRecords int
log slog.Logger
ticketsMtx sync.RWMutex ticketsMtx sync.RWMutex
} }
@ -83,7 +85,8 @@ func (vdb *VspDatabase) writeHotBackupFile() error {
return fmt.Errorf("os.Rename: %w", err) return fmt.Errorf("os.Rename: %w", err)
} }
log.Tracef("Database backup written to %s", backupPath) vdb.log.Tracef("Database backup written to %s", backupPath)
return err return err
} }
@ -92,7 +95,7 @@ func (vdb *VspDatabase) writeHotBackupFile() error {
// - the provided extended pubkey (to be used for deriving fee addresses). // - the provided extended pubkey (to be used for deriving fee addresses).
// - an ed25519 keypair to sign API responses. // - an ed25519 keypair to sign API responses.
// - a secret key to use for initializing a HTTP cookie store. // - a secret key to use for initializing a HTTP cookie store.
func CreateNew(dbFile, feeXPub string) error { func CreateNew(dbFile, feeXPub string, log slog.Logger) error {
log.Infof("Initializing new database at %s", dbFile) log.Infof("Initializing new database at %s", dbFile)
db, err := bolt.Open(dbFile, 0600, &bolt.Options{Timeout: 1 * time.Second}) db, err := bolt.Open(dbFile, 0600, &bolt.Options{Timeout: 1 * time.Second})
@ -172,7 +175,7 @@ func CreateNew(dbFile, feeXPub string) error {
// Open initializes and returns an open database. An error is returned if no // Open initializes and returns an open database. An error is returned if no
// database file is found at the provided path. // database file is found at the provided path.
func Open(shutdownCtx context.Context, shutdownWg *sync.WaitGroup, dbFile string, func Open(shutdownCtx context.Context, shutdownWg *sync.WaitGroup, log slog.Logger, dbFile string,
backupInterval time.Duration, maxVoteChangeRecords int) (*VspDatabase, error) { backupInterval time.Duration, maxVoteChangeRecords int) (*VspDatabase, error) {
// Error if db file does not exist. This is needed because bolt.Open will // Error if db file does not exist. This is needed because bolt.Open will
@ -188,7 +191,10 @@ func Open(shutdownCtx context.Context, shutdownWg *sync.WaitGroup, dbFile string
return nil, fmt.Errorf("unable to open db file: %w", err) return nil, fmt.Errorf("unable to open db file: %w", err)
} }
vdb := &VspDatabase{db: db, maxVoteChangeRecords: maxVoteChangeRecords} vdb := &VspDatabase{
db: db,
log: log,
maxVoteChangeRecords: maxVoteChangeRecords}
dbVersion, err := vdb.Version() dbVersion, err := vdb.Version()
if err != nil { if err != nil {
@ -242,14 +248,14 @@ func (vdb *VspDatabase) Close() {
// closing the db and writing the file to disk. // closing the db and writing the file to disk.
err := vdb.db.Close() err := vdb.db.Close()
if err != nil { if err != nil {
log.Errorf("Error closing database: %v", err) vdb.log.Errorf("Error closing database: %v", err)
// Return here because if there is an issue with the database, we // Return here because if there is an issue with the database, we
// probably don't want to overwrite the backup file and potentially // probably don't want to overwrite the backup file and potentially
// break that too. // break that too.
return return
} }
log.Debug("Database closed") vdb.log.Debug("Database closed")
// Ensure the database backup file is up-to-date. // Ensure the database backup file is up-to-date.
backupPath := dbPath + "-backup" backupPath := dbPath + "-backup"
@ -260,32 +266,32 @@ func (vdb *VspDatabase) Close() {
from, err := os.Open(dbPath) from, err := os.Open(dbPath)
if err != nil { if err != nil {
log.Errorf("Failed to write a database backup (os.Open): %v", err) vdb.log.Errorf("Failed to write a database backup (os.Open): %v", err)
return return
} }
defer from.Close() defer from.Close()
to, err := os.OpenFile(tempPath, os.O_RDWR|os.O_CREATE, backupFileMode) to, err := os.OpenFile(tempPath, os.O_RDWR|os.O_CREATE, backupFileMode)
if err != nil { if err != nil {
log.Errorf("Failed to write a database backup (os.OpenFile): %v", err) vdb.log.Errorf("Failed to write a database backup (os.OpenFile): %v", err)
return return
} }
defer to.Close() defer to.Close()
_, err = io.Copy(to, from) _, err = io.Copy(to, from)
if err != nil { if err != nil {
log.Errorf("Failed to write a database backup (io.Copy): %v", err) vdb.log.Errorf("Failed to write a database backup (io.Copy): %v", err)
return return
} }
// Rename temporary file to actual backup file. // Rename temporary file to actual backup file.
err = os.Rename(tempPath, backupPath) err = os.Rename(tempPath, backupPath)
if err != nil { if err != nil {
log.Errorf("Failed to write a database backup (os.Rename): %v", err) vdb.log.Errorf("Failed to write a database backup (os.Rename): %v", err)
return return
} }
log.Tracef("Database backup written to %s", backupPath) vdb.log.Tracef("Database backup written to %s", backupPath)
} }
// KeyPair retrieves the keypair used to sign API responses from the database. // KeyPair retrieves the keypair used to sign API responses from the database.
@ -426,7 +432,7 @@ func (vdb *VspDatabase) CheckIntegrity(dcrd rpc.DcrdConnect) error {
} }
} }
log.Infof("Added missing purchase height to %d tickets", len(missing)) vdb.log.Infof("Added missing purchase height to %d tickets", len(missing))
return nil return nil
} }

View File

@ -1,4 +1,4 @@
// Copyright (c) 2020-2021 The Decred developers // Copyright (c) 2020-2022 The Decred developers
// Use of this source code is governed by an ISC // Use of this source code is governed by an ISC
// license that can be found in the LICENSE file. // license that can be found in the LICENSE file.
@ -16,6 +16,8 @@ import (
"sync" "sync"
"testing" "testing"
"time" "time"
"github.com/decred/slog"
) )
const ( const (
@ -82,15 +84,20 @@ func TestDatabase(t *testing.T) {
} }
for testName, test := range tests { for testName, test := range tests {
// Set test logger to stdout.
backend := slog.NewBackend(os.Stdout)
log := backend.Logger("test")
log.SetLevel(slog.LevelTrace)
// Create a new blank database for each sub-test. // Create a new blank database for each sub-test.
var err error var err error
var wg sync.WaitGroup var wg sync.WaitGroup
ctx, cancel := context.WithCancel(context.TODO()) ctx, cancel := context.WithCancel(context.TODO())
err = CreateNew(testDb, feeXPub) err = CreateNew(testDb, feeXPub, log)
if err != nil { if err != nil {
t.Fatalf("error creating test database: %v", err) t.Fatalf("error creating test database: %v", err)
} }
db, err = Open(ctx, &wg, testDb, time.Hour, maxVoteChangeRecords) db, err = Open(ctx, &wg, log, testDb, time.Hour, maxVoteChangeRecords)
if err != nil { if err != nil {
t.Fatalf("error opening test database: %v", err) t.Fatalf("error opening test database: %v", err)
} }

View File

@ -1,30 +0,0 @@
// Copyright (c) 2020 The Decred developers
// Use of this source code is governed by an ISC
// license that can be found in the LICENSE file.
package database
import (
"github.com/decred/slog"
)
// log is a logger that is initialized with no output filters. This
// means the package will not perform any logging by default until the caller
// requests it.
var log slog.Logger
// The default amount of logging is none.
func init() {
DisableLog()
}
// DisableLog disables all library log output. Logging output is disabled
// by default until UseLogger is called.
func DisableLog() {
log = slog.Disabled
}
// UseLogger uses a specified Logger to output package logging info.
func UseLogger(logger slog.Logger) {
log = logger
}

View File

@ -78,7 +78,7 @@ func (vdb *VspDatabase) Upgrade(currentVersion uint32) error {
// Execute all necessary upgrades in order. // Execute all necessary upgrades in order.
for _, upgrade := range upgrades[currentVersion:] { for _, upgrade := range upgrades[currentVersion:] {
err := upgrade(vdb.db, log) err := upgrade(vdb.db, vdb.log)
if err != nil { if err != nil {
return err return err
} }

101
log.go
View File

@ -11,105 +11,32 @@ import (
"github.com/decred/slog" "github.com/decred/slog"
"github.com/jrick/logrotate/rotator" "github.com/jrick/logrotate/rotator"
"github.com/decred/vspd/background"
"github.com/decred/vspd/database"
"github.com/decred/vspd/rpc"
"github.com/decred/vspd/webapi"
) )
// logWriter implements an io.Writer that outputs to both standard output and // logWriter implements an io.Writer that outputs to both standard output and
// the write-end pipe of an initialized log rotator. // the write-end pipe of an initialized log rotator.
type logWriter struct{} type logWriter struct {
rotator *rotator.Rotator
}
func (logWriter) Write(p []byte) (n int, err error) { func (lw logWriter) Write(p []byte) (n int, err error) {
os.Stdout.Write(p) os.Stdout.Write(p)
return logRotator.Write(p) return lw.rotator.Write(p)
} }
// Loggers per subsystem. A single backend logger is created and all subsytem func NewLogBackend(logDir string, appName string, maxLogSize int64, logsToKeep int) (*slog.Backend, error) {
// 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("VSP")
dbLog = backendLog.Logger(" DB")
bgLog = backendLog.Logger(" BG")
apiLog = backendLog.Logger("API")
rpcLog = backendLog.Logger("RPC")
)
// Initialize package-global logger variables.
func init() {
database.UseLogger(dbLog)
background.UseLogger(bgLog)
webapi.UseLogger(apiLog)
rpc.UseLogger(rpcLog)
}
// subsystemLoggers maps each subsystem identifier to its associated logger.
var subsystemLoggers = map[string]slog.Logger{
"VSP": log,
" DB": dbLog,
" BG": bgLog,
"API": apiLog,
"RPC": rpcLog,
}
// initLogRotator initializes the logging rotater to write logs to logFile and
// create roll files in the same directory. It must be called before the
// package-global log rotater variables are used.
func initLogRotator(logFile string, maxLogSize int64, logsToKeep int) {
logDir, _ := filepath.Split(logFile)
err := os.MkdirAll(logDir, 0700) err := os.MkdirAll(logDir, 0700)
if err != nil { if err != nil {
fmt.Fprintf(os.Stderr, "failed to create log directory: %v\n", err) return nil, fmt.Errorf("failed to create log directory: %w", err)
os.Exit(1)
} }
r, err := rotator.New(logFile, maxLogSize*1024, false, logsToKeep)
logFileName := fmt.Sprintf("%s.log", appName)
logFilePath := filepath.Join(logDir, logFileName)
r, err := rotator.New(logFilePath, maxLogSize*1024, false, logsToKeep)
if err != nil { if err != nil {
fmt.Fprintf(os.Stderr, "failed to create file rotator: %v\n", err) return nil, fmt.Errorf("failed to create log rotator: %w", err)
os.Exit(1)
} }
logRotator = r return slog.NewBackend(logWriter{r}), nil
}
// setLogLevel sets the logging level for provided subsystem. Invalid
// subsystems are ignored. Uninitialized subsystems are dynamically created as
// needed.
func setLogLevel(subsystemID string, logLevel string) {
// Ignore invalid subsystems.
logger, ok := subsystemLoggers[subsystemID]
if !ok {
return
}
// Defaults to info if the log level is invalid.
level, _ := slog.LevelFromString(logLevel)
logger.SetLevel(level)
}
// setLogLevels sets the log level for all subsystem loggers to the passed
// level. It also dynamically creates the subsystem loggers as needed, so it
// can be used to initialize the logging system.
func setLogLevels(logLevel string) {
// Configure all sub-systems with the new logging level. Dynamically
// create loggers as needed.
for subsystemID := range subsystemLoggers {
setLogLevel(subsystemID, logLevel)
}
} }

View File

@ -1,4 +1,4 @@
// Copyright (c) 2020 The Decred developers // Copyright (c) 2020-2022 The Decred developers
// Use of this source code is governed by an ISC // Use of this source code is governed by an ISC
// license that can be found in the LICENSE file. // license that can be found in the LICENSE file.
@ -10,6 +10,7 @@ import (
"crypto/x509" "crypto/x509"
"sync" "sync"
"github.com/decred/slog"
"github.com/jrick/wsrpc/v2" "github.com/jrick/wsrpc/v2"
) )
@ -35,9 +36,10 @@ type client struct {
tlsOpt wsrpc.Option tlsOpt wsrpc.Option
authOpt wsrpc.Option authOpt wsrpc.Option
notifier wsrpc.Notifier notifier wsrpc.Notifier
log slog.Logger
} }
func setup(user, pass, addr string, cert []byte) *client { func setup(user, pass, addr string, cert []byte, log slog.Logger) *client {
// Create TLS options. // Create TLS options.
pool := x509.NewCertPool() pool := x509.NewCertPool()
@ -63,20 +65,20 @@ func setup(user, pass, addr string, cert []byte) *client {
var mu sync.Mutex var mu sync.Mutex
var c *wsrpc.Client var c *wsrpc.Client
fullAddr := "wss://" + addr + "/ws" fullAddr := "wss://" + addr + "/ws"
return &client{&mu, c, fullAddr, tlsOpt, authOpt, nil} return &client{&mu, c, fullAddr, tlsOpt, authOpt, nil, log}
} }
func (c *client) Close() { func (c *client) Close() {
if c.client != nil { if c.client != nil {
select { select {
case <-c.client.Done(): case <-c.client.Done():
log.Tracef("RPC already closed (%s)", c.addr) c.log.Tracef("RPC already closed (%s)", c.addr)
default: default:
if err := c.client.Close(); err != nil { if err := c.client.Close(); err != nil {
log.Errorf("Failed to close RPC (%s): %v", c.addr, err) c.log.Errorf("Failed to close RPC (%s): %v", c.addr, err)
} else { } else {
log.Tracef("RPC closed (%s)", c.addr) c.log.Tracef("RPC closed (%s)", c.addr)
} }
} }
} }
@ -92,7 +94,7 @@ func (c *client) dial(ctx context.Context) (Caller, bool, error) {
if c.client != nil { if c.client != nil {
select { select {
case <-c.client.Done(): case <-c.client.Done():
log.Debugf("RPC client %s errored (%v); reconnecting...", c.addr, c.client.Err()) c.log.Debugf("RPC client %s errored (%v); reconnecting...", c.addr, c.client.Err())
c.client = nil c.client = nil
default: default:
return c.client, false, nil return c.client, false, nil

View File

@ -14,6 +14,7 @@ import (
"github.com/decred/dcrd/chaincfg/v3" "github.com/decred/dcrd/chaincfg/v3"
dcrdtypes "github.com/decred/dcrd/rpc/jsonrpc/types/v3" dcrdtypes "github.com/decred/dcrd/rpc/jsonrpc/types/v3"
"github.com/decred/dcrd/wire" "github.com/decred/dcrd/wire"
"github.com/decred/slog"
"github.com/jrick/bitset" "github.com/jrick/bitset"
"github.com/jrick/wsrpc/v2" "github.com/jrick/wsrpc/v2"
) )
@ -41,12 +42,14 @@ type DcrdRPC struct {
type DcrdConnect struct { type DcrdConnect struct {
client *client client *client
params *chaincfg.Params params *chaincfg.Params
log slog.Logger
} }
func SetupDcrd(user, pass, addr string, cert []byte, params *chaincfg.Params) DcrdConnect { func SetupDcrd(user, pass, addr string, cert []byte, params *chaincfg.Params, log slog.Logger) DcrdConnect {
return DcrdConnect{ return DcrdConnect{
client: setup(user, pass, addr, cert), client: setup(user, pass, addr, cert, log),
params: params, params: params,
log: log,
} }
} }
@ -56,12 +59,13 @@ func SetupDcrd(user, pass, addr string, cert []byte, params *chaincfg.Params) Dc
func (d *DcrdConnect) BlockConnectedHandler(blockConnected chan *wire.BlockHeader) { func (d *DcrdConnect) BlockConnectedHandler(blockConnected chan *wire.BlockHeader) {
d.client.notifier = &blockConnectedHandler{ d.client.notifier = &blockConnectedHandler{
blockConnected: blockConnected, blockConnected: blockConnected,
log: d.log,
} }
} }
func (d *DcrdConnect) Close() { func (d *DcrdConnect) Close() {
d.client.Close() d.client.Close()
log.Debug("dcrd client closed") d.log.Debug("dcrd client closed")
} }
// Client creates a new DcrdRPC client instance. Returns an error if dialing // Client creates a new DcrdRPC client instance. Returns an error if dialing
@ -132,7 +136,7 @@ func (d *DcrdConnect) Client() (*DcrdRPC, string, error) {
} }
} }
log.Debugf("Connected to dcrd") d.log.Debugf("Connected to dcrd")
return &DcrdRPC{c, ctx}, d.client.addr, nil return &DcrdRPC{c, ctx}, d.client.addr, nil
} }

View File

@ -12,6 +12,7 @@ import (
"github.com/decred/dcrd/chaincfg/v3" "github.com/decred/dcrd/chaincfg/v3"
dcrdtypes "github.com/decred/dcrd/rpc/jsonrpc/types/v3" dcrdtypes "github.com/decred/dcrd/rpc/jsonrpc/types/v3"
"github.com/decred/dcrd/wire" "github.com/decred/dcrd/wire"
"github.com/decred/slog"
) )
var ( var (
@ -28,18 +29,20 @@ type WalletRPC struct {
type WalletConnect struct { type WalletConnect struct {
clients []*client clients []*client
params *chaincfg.Params params *chaincfg.Params
log slog.Logger
} }
func SetupWallet(user, pass, addrs []string, cert [][]byte, params *chaincfg.Params) WalletConnect { func SetupWallet(user, pass, addrs []string, cert [][]byte, params *chaincfg.Params, log slog.Logger) WalletConnect {
clients := make([]*client, len(addrs)) clients := make([]*client, len(addrs))
for i := 0; i < len(addrs); i++ { for i := 0; i < len(addrs); i++ {
clients[i] = setup(user[i], pass[i], addrs[i], cert[i]) clients[i] = setup(user[i], pass[i], addrs[i], cert[i], log)
} }
return WalletConnect{ return WalletConnect{
clients: clients, clients: clients,
params: params, params: params,
log: log,
} }
} }
@ -47,7 +50,7 @@ func (w *WalletConnect) Close() {
for _, client := range w.clients { for _, client := range w.clients {
client.Close() client.Close()
} }
log.Debug("dcrwallet clients closed") w.log.Debug("dcrwallet clients closed")
} }
// Clients loops over each wallet and tries to establish a connection. It // Clients loops over each wallet and tries to establish a connection. It
@ -62,7 +65,7 @@ func (w *WalletConnect) Clients() ([]*WalletRPC, []string) {
c, newConnection, err := connect.dial(ctx) c, newConnection, err := connect.dial(ctx)
if err != nil { if err != nil {
log.Errorf("dcrwallet dial error: %v", err) w.log.Errorf("dcrwallet dial error: %v", err)
failedConnections = append(failedConnections, connect.addr) failedConnections = append(failedConnections, connect.addr)
continue continue
} }
@ -78,7 +81,7 @@ func (w *WalletConnect) Clients() ([]*WalletRPC, []string) {
var verMap map[string]dcrdtypes.VersionResult var verMap map[string]dcrdtypes.VersionResult
err = c.Call(ctx, "version", &verMap) err = c.Call(ctx, "version", &verMap)
if err != nil { if err != nil {
log.Errorf("dcrwallet.Version error (wallet=%s): %v", c.String(), err) w.log.Errorf("dcrwallet.Version error (wallet=%s): %v", c.String(), err)
failedConnections = append(failedConnections, connect.addr) failedConnections = append(failedConnections, connect.addr)
connect.Close() connect.Close()
continue continue
@ -86,7 +89,7 @@ func (w *WalletConnect) Clients() ([]*WalletRPC, []string) {
ver, exists := verMap["dcrwalletjsonrpcapi"] ver, exists := verMap["dcrwalletjsonrpcapi"]
if !exists { if !exists {
log.Errorf("dcrwallet.Version response missing 'dcrwalletjsonrpcapi' (wallet=%s)", w.log.Errorf("dcrwallet.Version response missing 'dcrwalletjsonrpcapi' (wallet=%s)",
c.String()) c.String())
failedConnections = append(failedConnections, connect.addr) failedConnections = append(failedConnections, connect.addr)
connect.Close() connect.Close()
@ -95,7 +98,7 @@ func (w *WalletConnect) Clients() ([]*WalletRPC, []string) {
sVer := semver{ver.Major, ver.Minor, ver.Patch} sVer := semver{ver.Major, ver.Minor, ver.Patch}
if !semverCompatible(requiredWalletVersion, sVer) { if !semverCompatible(requiredWalletVersion, sVer) {
log.Errorf("dcrwallet has incompatible JSON-RPC version (wallet=%s): got %s, expected %s", w.log.Errorf("dcrwallet has incompatible JSON-RPC version (wallet=%s): got %s, expected %s",
c.String(), sVer, requiredWalletVersion) c.String(), sVer, requiredWalletVersion)
failedConnections = append(failedConnections, connect.addr) failedConnections = append(failedConnections, connect.addr)
connect.Close() connect.Close()
@ -106,13 +109,13 @@ func (w *WalletConnect) Clients() ([]*WalletRPC, []string) {
var netID wire.CurrencyNet var netID wire.CurrencyNet
err = c.Call(ctx, "getcurrentnet", &netID) err = c.Call(ctx, "getcurrentnet", &netID)
if err != nil { if err != nil {
log.Errorf("dcrwallet.GetCurrentNet error (wallet=%s): %v", c.String(), err) w.log.Errorf("dcrwallet.GetCurrentNet error (wallet=%s): %v", c.String(), err)
failedConnections = append(failedConnections, connect.addr) failedConnections = append(failedConnections, connect.addr)
connect.Close() connect.Close()
continue continue
} }
if netID != w.params.Net { if netID != w.params.Net {
log.Errorf("dcrwallet on wrong network (wallet=%s): running on %s, expected %s", w.log.Errorf("dcrwallet on wrong network (wallet=%s): running on %s, expected %s",
c.String(), netID, w.params.Net) c.String(), netID, w.params.Net)
failedConnections = append(failedConnections, connect.addr) failedConnections = append(failedConnections, connect.addr)
connect.Close() connect.Close()
@ -123,7 +126,7 @@ func (w *WalletConnect) Clients() ([]*WalletRPC, []string) {
walletRPC := &WalletRPC{c, ctx} walletRPC := &WalletRPC{c, ctx}
walletInfo, err := walletRPC.WalletInfo() walletInfo, err := walletRPC.WalletInfo()
if err != nil { if err != nil {
log.Errorf("dcrwallet.WalletInfo error (wallet=%s): %v", c.String(), err) w.log.Errorf("dcrwallet.WalletInfo error (wallet=%s): %v", c.String(), err)
failedConnections = append(failedConnections, connect.addr) failedConnections = append(failedConnections, connect.addr)
connect.Close() connect.Close()
continue continue
@ -133,17 +136,17 @@ func (w *WalletConnect) Clients() ([]*WalletRPC, []string) {
// All wallet should not be adding tickets found via the network. This // All wallet should not be adding tickets found via the network. This
// misconfiguration should not have a negative impact on users, so just // misconfiguration should not have a negative impact on users, so just
// log an error here. Don't count this as a failed connection. // log an error here. Don't count this as a failed connection.
log.Errorf("wallet does not have manual tickets enabled (wallet=%s)", c.String()) w.log.Errorf("wallet does not have manual tickets enabled (wallet=%s)", c.String())
} }
if !walletInfo.Voting { if !walletInfo.Voting {
// All wallet RPCs can still be used if voting is disabled, so just // All wallet RPCs can still be used if voting is disabled, so just
// log an error here. Don't count this as a failed connection. // log an error here. Don't count this as a failed connection.
log.Errorf("wallet is not voting (wallet=%s)", c.String()) w.log.Errorf("wallet is not voting (wallet=%s)", c.String())
} }
if !walletInfo.Unlocked { if !walletInfo.Unlocked {
// SetVoteChoice can still be used even if the wallet is locked, so // SetVoteChoice can still be used even if the wallet is locked, so
// just log an error here. Don't count this as a failed connection. // just log an error here. Don't count this as a failed connection.
log.Errorf("wallet is not unlocked (wallet=%s)", c.String()) w.log.Errorf("wallet is not unlocked (wallet=%s)", c.String())
} }
walletClients = append(walletClients, walletRPC) walletClients = append(walletClients, walletRPC)
@ -209,9 +212,6 @@ func (c *WalletRPC) TicketInfo(startHeight int64) (map[string]*wallettypes.Ticke
return nil, err return nil, err
} }
log.Debugf("TicketInfo RPC returned %d tickets (wallet=%s, startHeight=%d)",
len(result), c.String(), startHeight)
// For easier access later on, store the tickets in a map using their hash // For easier access later on, store the tickets in a map using their hash
// as the key. // as the key.
tickets := make(map[string]*wallettypes.TicketInfoResult, len(result)) tickets := make(map[string]*wallettypes.TicketInfoResult, len(result))

View File

@ -1,30 +0,0 @@
// Copyright (c) 2020 The Decred developers
// Use of this source code is governed by an ISC
// license that can be found in the LICENSE file.
package rpc
import (
"github.com/decred/slog"
)
// log is a logger that is initialized with no output filters. This
// means the package will not perform any logging by default until the caller
// requests it.
var log slog.Logger
// The default amount of logging is none.
func init() {
DisableLog()
}
// DisableLog disables all library log output. Logging output is disabled
// by default until UseLogger is called.
func DisableLog() {
log = slog.Disabled
}
// UseLogger uses a specified Logger to output package logging info.
func UseLogger(logger slog.Logger) {
log = logger
}

View File

@ -8,10 +8,12 @@ import (
"fmt" "fmt"
"github.com/decred/dcrd/wire" "github.com/decred/dcrd/wire"
"github.com/decred/slog"
) )
type blockConnectedHandler struct { type blockConnectedHandler struct {
blockConnected chan *wire.BlockHeader blockConnected chan *wire.BlockHeader
log slog.Logger
} }
// Notify is called every time a notification is received from dcrd client. // Notify is called every time a notification is received from dcrd client.
@ -25,7 +27,7 @@ func (n *blockConnectedHandler) Notify(method string, msg json.RawMessage) error
header, err := parseBlockConnected(msg) header, err := parseBlockConnected(msg)
if err != nil { if err != nil {
log.Errorf("Failed to parse dcrd block notification: %v", err) n.log.Errorf("Failed to parse dcrd block notification: %v", err)
return nil return nil
} }

View File

@ -9,6 +9,8 @@ import (
"context" "context"
"os" "os"
"os/signal" "os/signal"
"github.com/decred/slog"
) )
// shutdownRequestChannel is used to initiate shutdown from one of the // shutdownRequestChannel is used to initiate shutdown from one of the
@ -45,7 +47,7 @@ func requestShutdown() {
// shutdownListener listens for shutdown requests and cancels all contexts // shutdownListener listens for shutdown requests and cancels all contexts
// created from withShutdownCancel. This function never returns and is intended // created from withShutdownCancel. This function never returns and is intended
// to be spawned in a new goroutine. // to be spawned in a new goroutine.
func shutdownListener() { func shutdownListener(log slog.Logger) {
interruptChannel := make(chan os.Signal, 1) interruptChannel := make(chan os.Signal, 1)
signal.Notify(interruptChannel, interruptSignals...) signal.Notify(interruptChannel, interruptSignals...)

39
vspd.go
View File

@ -13,7 +13,6 @@ import (
"time" "time"
"github.com/decred/dcrd/wire" "github.com/decred/dcrd/wire"
"github.com/decred/vspd/background"
"github.com/decred/vspd/database" "github.com/decred/vspd/database"
"github.com/decred/vspd/rpc" "github.com/decred/vspd/rpc"
"github.com/decred/vspd/version" "github.com/decred/vspd/version"
@ -30,29 +29,33 @@ const maxVoteChangeRecords = 10
const consistencyInterval = 30 * time.Minute const consistencyInterval = 30 * time.Minute
func main() { func main() {
// Create a context that is cancelled when a shutdown request is received
// through an interrupt signal.
shutdownCtx := withShutdownCancel(context.Background())
go shutdownListener()
// Run until an exit code is returned. // Run until an exit code is returned.
os.Exit(run(shutdownCtx)) os.Exit(run())
} }
// run is the main startup and teardown logic performed by the main package. It // run is the main startup and teardown logic performed by the main package. It
// is responsible for parsing the config, creating dcrd and dcrwallet RPC clients, // is responsible for parsing the config, creating dcrd and dcrwallet RPC clients,
// opening the database, starting the webserver, and stopping all started // opening the database, starting the webserver, and stopping all started
// services when the provided context is cancelled. // services when a shutdown is requested.
func run(shutdownCtx context.Context) int { func run() int {
// Load config file and parse CLI args. // Load config file and parse CLI args.
cfg, err := loadConfig() cfg, err := loadConfig()
if err != nil { if err != nil {
// Don't use logger here because it may not be initialized.
fmt.Fprintf(os.Stderr, "Config error: %v\n", err) fmt.Fprintf(os.Stderr, "Config error: %v\n", err)
return 1 return 1
} }
log := cfg.Logger("VSP")
dbLog := cfg.Logger(" DB")
apiLog := cfg.Logger("API")
rpcLog := cfg.Logger("RPC")
// Create a context that is cancelled when a shutdown request is received
// through an interrupt signal.
shutdownCtx := withShutdownCancel(context.Background())
go shutdownListener(log)
// Show version at startup. // Show version at startup.
log.Criticalf("Version %s (Go version %s %s/%s)", version.String(), runtime.Version(), log.Criticalf("Version %s (Go version %s %s/%s)", version.String(), runtime.Version(),
runtime.GOOS, runtime.GOARCH) runtime.GOOS, runtime.GOARCH)
@ -75,7 +78,7 @@ func run(shutdownCtx context.Context) int {
defer log.Criticalf("Shutdown complete") defer log.Criticalf("Shutdown complete")
// Open database. // Open database.
db, err := database.Open(shutdownCtx, &shutdownWg, cfg.dbPath, cfg.BackupInterval, maxVoteChangeRecords) db, err := database.Open(shutdownCtx, &shutdownWg, dbLog, cfg.dbPath, cfg.BackupInterval, maxVoteChangeRecords)
if err != nil { if err != nil {
log.Errorf("Database error: %v", err) log.Errorf("Database error: %v", err)
requestShutdown() requestShutdown()
@ -86,11 +89,11 @@ func run(shutdownCtx context.Context) int {
// Create RPC client for local dcrd instance (used for broadcasting and // Create RPC client for local dcrd instance (used for broadcasting and
// checking the status of fee transactions). // checking the status of fee transactions).
dcrd := rpc.SetupDcrd(cfg.DcrdUser, cfg.DcrdPass, cfg.DcrdHost, cfg.dcrdCert, cfg.netParams.Params) dcrd := rpc.SetupDcrd(cfg.DcrdUser, cfg.DcrdPass, cfg.DcrdHost, cfg.dcrdCert, cfg.netParams.Params, rpcLog)
defer dcrd.Close() defer dcrd.Close()
// Create RPC client for remote dcrwallet instance (used for voting). // Create RPC client for remote dcrwallet instance (used for voting).
wallets := rpc.SetupWallet(cfg.walletUsers, cfg.walletPasswords, cfg.walletHosts, cfg.walletCerts, cfg.netParams.Params) wallets := rpc.SetupWallet(cfg.walletUsers, cfg.walletPasswords, cfg.walletHosts, cfg.walletCerts, cfg.netParams.Params, rpcLog)
defer wallets.Close() defer wallets.Close()
// Create a channel to receive blockConnected notifications from dcrd. // Create a channel to receive blockConnected notifications from dcrd.
@ -104,7 +107,7 @@ func run(shutdownCtx context.Context) int {
return return
case header := <-notifChan: case header := <-notifChan:
log.Debugf("Block notification %d (%s)", header.Height, header.BlockHash().String()) log.Debugf("Block notification %d (%s)", header.Height, header.BlockHash().String())
background.BlockConnected(dcrd, wallets, db) BlockConnected(dcrd, wallets, db, log)
} }
} }
}() }()
@ -140,11 +143,11 @@ func run(shutdownCtx context.Context) int {
// Run the block connected handler now to catch up with any blocks mined // Run the block connected handler now to catch up with any blocks mined
// while vspd was shut down. // while vspd was shut down.
background.BlockConnected(dcrd, wallets, db) BlockConnected(dcrd, wallets, db, log)
// Run voting wallet consistency check now to ensure all wallets are up to // Run voting wallet consistency check now to ensure all wallets are up to
// date. // date.
background.CheckWalletConsistency(dcrd, wallets, db) CheckWalletConsistency(dcrd, wallets, db, log)
// Run voting wallet consistency check periodically. // Run voting wallet consistency check periodically.
shutdownWg.Add(1) shutdownWg.Add(1)
@ -155,7 +158,7 @@ func run(shutdownCtx context.Context) int {
shutdownWg.Done() shutdownWg.Done()
return return
case <-time.After(consistencyInterval): case <-time.After(consistencyInterval):
background.CheckWalletConsistency(dcrd, wallets, db) CheckWalletConsistency(dcrd, wallets, db, log)
} }
} }
}() }()
@ -174,7 +177,7 @@ func run(shutdownCtx context.Context) int {
MaxVoteChangeRecords: maxVoteChangeRecords, MaxVoteChangeRecords: maxVoteChangeRecords,
VspdVersion: version.String(), VspdVersion: version.String(),
} }
err = webapi.Start(shutdownCtx, requestShutdown, &shutdownWg, cfg.Listen, db, err = webapi.Start(shutdownCtx, requestShutdown, &shutdownWg, cfg.Listen, db, apiLog,
dcrd, wallets, apiCfg) dcrd, wallets, apiCfg)
if err != nil { if err != nil {
log.Errorf("Failed to initialize webapi: %v", err) log.Errorf("Failed to initialize webapi: %v", err)

View File

@ -1,30 +0,0 @@
// Copyright (c) 2020 The Decred developers
// Use of this source code is governed by an ISC
// license that can be found in the LICENSE file.
package webapi
import (
"github.com/decred/slog"
)
// log is a logger that is initialized with no output filters. This
// means the package will not perform any logging by default until the caller
// requests it.
var log slog.Logger
// The default amount of logging is none.
func init() {
DisableLog()
}
// DisableLog disables all library log output. Logging output is disabled
// by default until UseLogger is called.
func DisableLog() {
log = slog.Disabled
}
// UseLogger uses a specified Logger to output package logging info.
func UseLogger(logger slog.Logger) {
log = logger
}

View File

@ -312,7 +312,7 @@ func (s *Server) vspAuth(c *gin.Context) {
} else { } else {
commitmentAddress, err = getCommitmentAddress(hash, dcrdClient, s.cfg.NetParams) commitmentAddress, err = getCommitmentAddress(hash, dcrdClient, s.cfg.NetParams)
if err != nil { if err != nil {
log.Errorf("%s: Failed to get commitment address (clientIP=%s, ticketHash=%s): %v", s.log.Errorf("%s: Failed to get commitment address (clientIP=%s, ticketHash=%s): %v",
funcName, c.ClientIP(), hash, err) funcName, c.ClientIP(), hash, err)
var apiErr *apiError var apiErr *apiError

View File

@ -55,7 +55,7 @@ func randBytes(n int) []byte {
func TestMain(m *testing.M) { func TestMain(m *testing.M) {
// Set test logger to stdout. // Set test logger to stdout.
backend := slog.NewBackend(os.Stdout) backend := slog.NewBackend(os.Stdout)
log = backend.Logger("test") log := backend.Logger("test")
log.SetLevel(slog.LevelTrace) log.SetLevel(slog.LevelTrace)
// Set up some global params. // Set up some global params.
@ -73,11 +73,11 @@ func TestMain(m *testing.M) {
var err error var err error
var wg sync.WaitGroup var wg sync.WaitGroup
ctx, cancel := context.WithCancel(context.Background()) ctx, cancel := context.WithCancel(context.Background())
err = database.CreateNew(testDb, feeXPub) err = database.CreateNew(testDb, feeXPub, log)
if err != nil { if err != nil {
panic(fmt.Errorf("error creating test database: %w", err)) panic(fmt.Errorf("error creating test database: %w", err))
} }
db, err := database.Open(ctx, &wg, testDb, time.Hour, maxVoteChangeRecords) db, err := database.Open(ctx, &wg, log, testDb, time.Hour, maxVoteChangeRecords)
if err != nil { if err != nil {
panic(fmt.Errorf("error opening test database: %w", err)) panic(fmt.Errorf("error opening test database: %w", err))
} }

View File

@ -75,7 +75,8 @@ type Server struct {
} }
func Start(shutdownCtx context.Context, requestShutdown func(), shutdownWg *sync.WaitGroup, func Start(shutdownCtx context.Context, requestShutdown func(), shutdownWg *sync.WaitGroup,
listen string, vdb *database.VspDatabase, dcrd rpc.DcrdConnect, wallets rpc.WalletConnect, config Config) error { listen string, vdb *database.VspDatabase, log slog.Logger, dcrd rpc.DcrdConnect,
wallets rpc.WalletConnect, config Config) error {
s := &Server{ s := &Server{
cfg: config, cfg: config,
@ -216,7 +217,7 @@ func (s *Server) router(cookieSecret []byte, dcrd rpc.DcrdConnect, wallets rpc.W
// Recovery middleware handles any go panics generated while processing web // Recovery middleware handles any go panics generated while processing web
// requests. Ensures a 500 response is sent to the client rather than // requests. Ensures a 500 response is sent to the client rather than
// sending no response at all. // sending no response at all.
router.Use(Recovery(log)) router.Use(Recovery(s.log))
if s.cfg.Debug { if s.cfg.Debug {
// Logger middleware outputs very detailed logging of webserver requests // Logger middleware outputs very detailed logging of webserver requests