From 8fa2b95c124b6f2ea7b492d9b999bce788b2dd69 Mon Sep 17 00:00:00 2001 From: Andrey Samokhvalov Date: Wed, 21 Jun 2017 18:07:44 +0300 Subject: [PATCH] lnd: remove seelog logger The btclog package has been changed to defining its own logging interface (rather than seelog's) and provides a default implementation for callers to use. There are two primary advantages to the new logger implementation. First, all log messages are created before the call returns. Compared to seelog, this prevents data races when mutable variables are logged. Second, the new logger does not implement any kind of artifical rate limiting (what seelog refers to as "adaptive logging"). Log messages are outputted as soon as possible and the application will appear to perform much better when watching standard output. Because log rotation is not a feature of the btclog logging implementation, it is handled by the main package by importing a file rotation package that provides an io.Reader interface for creating output to a rotating file output. The rotator has been configured with the same defaults that btcd previously used in the seelog config (10MB file limits with maximum of 3 rolls) but now compresses newly created roll files. Due to the high compressibility of log text, the compressed files typically reduce to around 15-30% of the original 10MB file. --- chainntnfs/log.go | 32 +------ channeldb/log.go | 32 +------ config.go | 2 +- discovery/log.go | 34 +------ glide.lock | 18 ++-- glide.yaml | 9 +- htlcswitch/log.go | 32 +------ lnd.go | 6 +- lnwallet/log.go | 28 +----- log.go | 201 ++++++++++++++++----------------------- routing/chainview/log.go | 30 +----- routing/log.go | 28 +----- 12 files changed, 115 insertions(+), 337 deletions(-) diff --git a/chainntnfs/log.go b/chainntnfs/log.go index 65ea0030..b6a3f148 100644 --- a/chainntnfs/log.go +++ b/chainntnfs/log.go @@ -1,11 +1,6 @@ package chainntnfs -import ( - "errors" - "io" - - "github.com/btcsuite/btclog" -) +import "github.com/btcsuite/btclog" // 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 @@ -18,7 +13,7 @@ func init() { } // DisableLog disables all library log output. Logging output is disabled -// by default until either UseLogger or SetLogWriter are called. +// by default until UseLogger is called. func DisableLog() { Log = btclog.Disabled } @@ -29,26 +24,3 @@ func DisableLog() { func UseLogger(logger btclog.Logger) { Log = logger } - -// SetLogWriter uses a specified io.Writer to output package logging info. -// This allows a caller to direct package logging output without needing a -// dependency on seelog. If the caller is also using btclog, UseLogger should -// be used instead. -func SetLogWriter(w io.Writer, level string) error { - if w == nil { - return errors.New("nil writer") - } - - lvl, ok := btclog.LogLevelFromString(level) - if !ok { - return errors.New("invalid log level") - } - - l, err := btclog.NewLoggerFromWriter(w, lvl) - if err != nil { - return err - } - - UseLogger(l) - return nil -} diff --git a/channeldb/log.go b/channeldb/log.go index e13a0e5c..d44192e7 100644 --- a/channeldb/log.go +++ b/channeldb/log.go @@ -1,11 +1,6 @@ package channeldb -import ( - "errors" - "io" - - "github.com/btcsuite/btclog" -) +import "github.com/btcsuite/btclog" // 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 @@ -18,7 +13,7 @@ func init() { } // DisableLog disables all library log output. Logging output is disabled -// by default until either UseLogger or SetLogWriter are called. +// by default until UseLogger is called. func DisableLog() { log = btclog.Disabled } @@ -29,26 +24,3 @@ func DisableLog() { func UseLogger(logger btclog.Logger) { log = logger } - -// SetLogWriter uses a specified io.Writer to output package logging info. -// This allows a caller to direct package logging output without needing a -// dependency on seelog. If the caller is also using btclog, UseLogger should -// be used instead. -func SetLogWriter(w io.Writer, level string) error { - if w == nil { - return errors.New("nil writer") - } - - lvl, ok := btclog.LogLevelFromString(level) - if !ok { - return errors.New("invalid log level") - } - - l, err := btclog.NewLoggerFromWriter(w, lvl) - if err != nil { - return err - } - - UseLogger(l) - return nil -} diff --git a/config.go b/config.go index 782b6748..5b8452fa 100644 --- a/config.go +++ b/config.go @@ -289,7 +289,7 @@ func loadConfig() (*config, error) { registeredChains.primaryChain.String()) // Initialize logging at the default logging level. - initSeelogLogger(filepath.Join(cfg.LogDir, defaultLogFilename)) + initLogRotator(filepath.Join(cfg.LogDir, defaultLogFilename)) setLogLevels(defaultLogLevel) // Parse, validate, and set debug log level(s). diff --git a/discovery/log.go b/discovery/log.go index 08fa7e07..7d38664c 100644 --- a/discovery/log.go +++ b/discovery/log.go @@ -1,12 +1,6 @@ package discovery -import ( - "errors" - "io" - - "github.com/btcsuite/btclog" - btcwallet "github.com/roasbeef/btcwallet/wallet" -) +import "github.com/btcsuite/btclog" // 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 @@ -19,7 +13,7 @@ func init() { } // DisableLog disables all library log output. Logging output is disabled -// by default until either UseLogger or SetLogWriter are called. +// by default until UseLogger is called. func DisableLog() { log = btclog.Disabled } @@ -29,30 +23,6 @@ func DisableLog() { // using btclog. func UseLogger(logger btclog.Logger) { log = logger - btcwallet.UseLogger(logger) -} - -// SetLogWriter uses a specified io.Writer to output package logging info. -// This allows a caller to direct package logging output without needing a -// dependency on seelog. If the caller is also using btclog, UseLogger should -// be used instead. -func SetLogWriter(w io.Writer, level string) error { - if w == nil { - return errors.New("nil writer") - } - - lvl, ok := btclog.LogLevelFromString(level) - if !ok { - return errors.New("invalid log level") - } - - l, err := btclog.NewLoggerFromWriter(w, lvl) - if err != nil { - return err - } - - UseLogger(l) - return nil } // logClosure is used to provide a closure over expensive logging operations diff --git a/glide.lock b/glide.lock index 3e37192d..0cecbb9d 100644 --- a/glide.lock +++ b/glide.lock @@ -1,5 +1,5 @@ -hash: 4c71a2926e3bff9e7075bbbfd51de535f545d8b9b457287c77dea50b3ca494dd -updated: 2017-06-19T14:30:43.865744449+02:00 +hash: 6c18f5869f221e2cd4a979035580efeffd1b12e975d89190d416e98dc7b74498 +updated: 2017-06-25T12:56:35.351126486+03:00 imports: - name: github.com/aead/chacha20 version: d31a916ded42d1640b9d89a26f8abd53cc96790c @@ -18,7 +18,7 @@ imports: - name: github.com/boltdb/bolt version: 583e8937c61f1af6513608ccc75c97b6abdf4ff9 - name: github.com/btcsuite/btclog - version: 73889fb79bd687870312b6e40effcecffbd57d30 + version: 96c2a91a67da03552a5e6554fe3ccbfbc7f860be - name: github.com/btcsuite/fastsha256 version: 637e656429416087660c84436a2a035d69d54e2e - name: github.com/btcsuite/go-flags @@ -37,8 +37,6 @@ imports: - salsa20/salsa - scrypt - ssh/terminal -- name: github.com/btcsuite/seelog - version: ae8891d029dd3c269dcfd6f261ad23e761acd99f - name: github.com/btcsuite/websocket version: 31079b6807923eb23992c421b114992b95131b55 - name: github.com/davecgh/go-spew @@ -62,10 +60,14 @@ imports: - utilities - name: github.com/howeyc/gopass version: bf9dde6d0d2c004a008c27aaee91170c786f6db8 +- name: github.com/jrick/logrotate + version: 4ed05ed86ef17d10ff99cce77481e0fcf6f2c7b0 + subpackages: + - rotator - name: github.com/kkdai/bstream version: f391b8402d23024e7c0f624b31267a89998fca95 - name: github.com/lightninglabs/neutrino - version: 38ea335359ce38a83d51caea7a39a3a8658d30a4 + version: ccfa94a1c213e5df752c08c7edc30cb0a56d4dcf subpackages: - filterdb - headerfs @@ -78,7 +80,7 @@ imports: - chaincfg/chainhash - wire - name: github.com/roasbeef/btcd - version: 4d38357cee3ed3843cd81a347e1573f037e0301e + version: 34fdda7d41cc47d9456550fd1147a77db89f601a subpackages: - addrmgr - blockchain @@ -93,7 +95,7 @@ imports: - txscript - wire - name: github.com/roasbeef/btcrpcclient - version: 9a7826550df8071460e2f5dd6ed9139dcbf260b8 + version: d0f4db8b4dad0ca3d569b804f21247c3dd96acbb - name: github.com/roasbeef/btcutil version: a259eaf2ec1b54653cdd67848a41867f280797ee subpackages: diff --git a/glide.yaml b/glide.yaml index a7e165ef..808f45bb 100644 --- a/glide.yaml +++ b/glide.yaml @@ -4,8 +4,7 @@ import: version: ^1.2.1 - package: github.com/btcsuite/btclog - package: github.com/btcsuite/go-flags -- package: github.com/btcsuite/seelog - version: ^2.1.0 +- package: github.com/jrick/logrotate - package: github.com/davecgh/go-spew subpackages: - spew @@ -14,7 +13,7 @@ import: - proto - package: github.com/howeyc/gopass - package: github.com/roasbeef/btcd - version: 4d38357cee3ed3843cd81a347e1573f037e0301e + version: 34fdda7d41cc47d9456550fd1147a77db89f601a subpackages: - blockchain - btcec @@ -24,7 +23,7 @@ import: - wire - connmgr - package: github.com/roasbeef/btcrpcclient - version: 9a7826550df8071460e2f5dd6ed9139dcbf260b8 + version: d0f4db8b4dad0ca3d569b804f21247c3dd96acbb - package: github.com/roasbeef/btcutil version: a259eaf2ec1b54653cdd67848a41867f280797ee subpackages: @@ -69,4 +68,4 @@ import: subpackages: - chaincfg - package: github.com/lightninglabs/neutrino - version: 38ea335359ce38a83d51caea7a39a3a8658d30a4 + version: ccfa94a1c213e5df752c08c7edc30cb0a56d4dcf diff --git a/htlcswitch/log.go b/htlcswitch/log.go index 19c83038..69e71e4b 100644 --- a/htlcswitch/log.go +++ b/htlcswitch/log.go @@ -1,11 +1,6 @@ package htlcswitch -import ( - "errors" - "io" - - "github.com/btcsuite/btclog" -) +import "github.com/btcsuite/btclog" // 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 @@ -18,7 +13,7 @@ func init() { } // DisableLog disables all library log output. Logging output is disabled -// by default until either UseLogger or SetLogWriter are called. +// by default until UseLogger is called. func DisableLog() { log = btclog.Disabled } @@ -29,26 +24,3 @@ func DisableLog() { func UseLogger(logger btclog.Logger) { log = logger } - -// SetLogWriter uses a specified io.Writer to output package logging info. -// This allows a caller to direct package logging output without needing a -// dependency on seelog. If the caller is also using btclog, UseLogger should -// be used instead. -func SetLogWriter(w io.Writer, level string) error { - if w == nil { - return errors.New("nil writer") - } - - lvl, ok := btclog.LogLevelFromString(level) - if !ok { - return errors.New("invalid log level") - } - - l, err := btclog.NewLoggerFromWriter(w, lvl) - if err != nil { - return err - } - - UseLogger(l) - return nil -} diff --git a/lnd.go b/lnd.go index 905a5baa..fc97f4e2 100644 --- a/lnd.go +++ b/lnd.go @@ -41,7 +41,11 @@ func lndMain() error { return err } cfg = loadedConfig - defer backendLog.Flush() + defer func() { + if logRotator != nil { + logRotator.Close() + } + }() // Show version at startup. ltndLog.Infof("Version %s", version()) diff --git a/lnwallet/log.go b/lnwallet/log.go index 199fd432..95b26405 100644 --- a/lnwallet/log.go +++ b/lnwallet/log.go @@ -1,9 +1,6 @@ package lnwallet import ( - "errors" - "io" - "github.com/btcsuite/btclog" "github.com/roasbeef/btcrpcclient" "github.com/roasbeef/btcwallet/chain" @@ -22,7 +19,7 @@ func init() { } // DisableLog disables all library log output. Logging output is disabled -// by default until either UseLogger or SetLogWriter are called. +// by default until UseLogger is called. func DisableLog() { walletLog = btclog.Disabled } @@ -39,29 +36,6 @@ func UseLogger(logger btclog.Logger) { chain.UseLogger(logger) } -// SetLogWriter uses a specified io.Writer to output package logging info. -// This allows a caller to direct package logging output without needing a -// dependency on seelog. If the caller is also using btclog, UseLogger should -// be used instead. -func SetLogWriter(w io.Writer, level string) error { - if w == nil { - return errors.New("nil writer") - } - - lvl, ok := btclog.LogLevelFromString(level) - if !ok { - return errors.New("invalid log level") - } - - l, err := btclog.NewLoggerFromWriter(w, lvl) - if err != nil { - return err - } - - UseLogger(l) - return nil -} - // logClosure is used to provide a closure over expensive logging operations // so don't have to be performed when the logging level doesn't warrant it. type logClosure func() string diff --git a/log.go b/log.go index 74333359..8bbabf94 100644 --- a/log.go +++ b/log.go @@ -1,11 +1,15 @@ package main import ( - "fmt" "os" + "io" + + "fmt" + "path/filepath" + "github.com/btcsuite/btclog" - "github.com/btcsuite/seelog" + "github.com/jrick/logrotate/rotator" "github.com/lightninglabs/neutrino" "github.com/lightningnetwork/lnd/chainntnfs" "github.com/lightningnetwork/lnd/channeldb" @@ -16,29 +20,67 @@ import ( "github.com/roasbeef/btcd/connmgr" ) -// Loggers per subsystem. Note that backendLog is a seelog logger that all of -// the subsystem loggers route their messages to. When adding new subsystems, -// add a reference here, to the subsystemLoggers map, and the useLogger -// function. +// 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) + logRotatorPipe.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 = seelog.Disabled - ltndLog = btclog.Disabled - lnwlLog = btclog.Disabled - peerLog = btclog.Disabled - discLog = btclog.Disabled - fndgLog = btclog.Disabled - rpcsLog = btclog.Disabled - srvrLog = btclog.Disabled - ntfnLog = btclog.Disabled - chdbLog = btclog.Disabled - hswcLog = btclog.Disabled - utxnLog = btclog.Disabled - brarLog = btclog.Disabled - cmgrLog = btclog.Disabled - crtrLog = btclog.Disabled - btcnLog = btclog.Disabled + // 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 = btclog.NewBackend(logWriter{}) + + // logRotator is one of the logging outputs. It should be closed on + // application shutdown. + logRotator *rotator.Rotator + + // logRotatorPipe is the write-end pipe for writing to the log rotator. It + // is written to by the Write method of the logWriter type. + logRotatorPipe *io.PipeWriter + + ltndLog = backendLog.Logger("LTND") + lnwlLog = backendLog.Logger("LNWL") + peerLog = backendLog.Logger("PEER") + discLog = backendLog.Logger("DISC") + rpcsLog = backendLog.Logger("RPCS") + srvrLog = backendLog.Logger("SRVR") + ntfnLog = backendLog.Logger("NTFN") + chdbLog = backendLog.Logger("CHDB") + fndgLog = backendLog.Logger("FNDG") + hswcLog = backendLog.Logger("HSWC") + utxnLog = backendLog.Logger("UTXN") + brarLog = backendLog.Logger("BRAR") + cmgrLog = backendLog.Logger("CMGR") + crtrLog = backendLog.Logger("CRTR") + btcnLog = backendLog.Logger("BTCN") ) +// Initialize package-global logger variables. +func init() { + lnwallet.UseLogger(lnwlLog) + discovery.UseLogger(discLog) + chainntnfs.UseLogger(ntfnLog) + channeldb.UseLogger(chdbLog) + htlcswitch.UseLogger(hswcLog) + connmgr.UseLogger(cmgrLog) + routing.UseLogger(crtrLog) + neutrino.UseLogger(btcnLog) +} + // subsystemLoggers maps each subsystem identifier to its associated logger. var subsystemLoggers = map[string]btclog.Logger{ "LTND": ltndLog, @@ -58,93 +100,27 @@ var subsystemLoggers = map[string]btclog.Logger{ "BTCN": btcnLog, } -// useLogger updates the logger references for subsystemID to logger. Invalid -// subsystems are ignored. -func useLogger(subsystemID string, logger btclog.Logger) { - if _, ok := subsystemLoggers[subsystemID]; !ok { - return - } - subsystemLoggers[subsystemID] = logger - - switch subsystemID { - case "LTND": - ltndLog = logger - - case "LNWL": - lnwlLog = logger - lnwallet.UseLogger(logger) - - case "PEER": - peerLog = logger - - case "DISC": - discLog = logger - discovery.UseLogger(logger) - - case "RPCS": - rpcsLog = logger - - case "SRVR": - srvrLog = logger - - case "NTFN": - ntfnLog = logger - chainntnfs.UseLogger(logger) - - case "CHDB": - chdbLog = logger - channeldb.UseLogger(logger) - - case "FNDG": - fndgLog = logger - - case "HSWC": - hswcLog = logger - htlcswitch.UseLogger(logger) - - case "UTXN": - utxnLog = logger - - case "BRAR": - brarLog = logger - - case "CMGR": - cmgrLog = logger - connmgr.UseLogger(logger) - - case "CRTR": - crtrLog = logger - routing.UseLogger(crtrLog) - - case "BTCN": - btcnLog = logger - neutrino.UseLogger(logger) - } -} - -// initSeelogLogger initializes a new seelog logger that is used as the backend -// for all logging subsystems. -func initSeelogLogger(logFile string) { - config := ` - - - - - - - - - ` - config = fmt.Sprintf(config, logFile) - - logger, err := seelog.LoggerFromConfigAsString(config) +// 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) { + logDir, _ := filepath.Split(logFile) + err := os.MkdirAll(logDir, 0700) if err != nil { - fmt.Fprintf(os.Stderr, "failed to create logger: %v", err) + fmt.Fprintf(os.Stderr, "failed to create log directory: %v\n", err) + os.Exit(1) + } + pr, pw := io.Pipe() + r, err := rotator.New(pr, logFile, 10*1024, false, 3) + if err != nil { + fmt.Fprintf(os.Stderr, "failed to create file rotator: %v\n", err) os.Exit(1) } - backendLog = logger + go r.Run() + + logRotator = r + logRotatorPipe = pw } // setLogLevel sets the logging level for provided subsystem. Invalid @@ -157,17 +133,8 @@ func setLogLevel(subsystemID string, logLevel string) { return } - // Default to info if the log level is invalid. - level, ok := btclog.LogLevelFromString(logLevel) - if !ok { - level = btclog.InfoLvl - } - - // Create new logger for the subsystem if needed. - if logger == btclog.Disabled { - logger = btclog.NewSubsystemLogger(backendLog, subsystemID+": ") - useLogger(subsystemID, logger) - } + // Defaults to info if the log level is invalid. + level, _ := btclog.LevelFromString(logLevel) logger.SetLevel(level) } @@ -175,7 +142,7 @@ func setLogLevel(subsystemID string, logLevel string) { // 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 subsystems with the new logging level. Dynamically + // Configure all sub-systems with the new logging level. Dynamically // create loggers as needed. for subsystemID := range subsystemLoggers { setLogLevel(subsystemID, logLevel) diff --git a/routing/chainview/log.go b/routing/chainview/log.go index 511110fc..cb3b59a2 100644 --- a/routing/chainview/log.go +++ b/routing/chainview/log.go @@ -1,11 +1,6 @@ package chainview -import ( - "errors" - "io" - - "github.com/btcsuite/btclog" -) +import "github.com/btcsuite/btclog" // 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 @@ -29,26 +24,3 @@ func DisableLog() { func UseLogger(logger btclog.Logger) { log = logger } - -// SetLogWriter uses a specified io.Writer to output package logging info. -// This allows a caller to direct package logging output without needing a -// dependency on seelog. If the caller is also using btclog, UseLogger should -// be used instead. -func SetLogWriter(w io.Writer, level string) error { - if w == nil { - return errors.New("nil writer") - } - - lvl, ok := btclog.LogLevelFromString(level) - if !ok { - return errors.New("invalid log level") - } - - l, err := btclog.NewLoggerFromWriter(w, lvl) - if err != nil { - return err - } - - UseLogger(l) - return nil -} diff --git a/routing/log.go b/routing/log.go index 8e26fe03..b990aa74 100644 --- a/routing/log.go +++ b/routing/log.go @@ -1,9 +1,6 @@ package routing import ( - "errors" - "io" - "github.com/btcsuite/btclog" "github.com/lightningnetwork/lnd/routing/chainview" ) @@ -19,7 +16,7 @@ func init() { } // DisableLog disables all library log output. Logging output is disabled by -// default until either UseLogger or SetLogWriter are called. +// by default until UseLogger is called. func DisableLog() { log = btclog.Disabled } @@ -32,29 +29,6 @@ func UseLogger(logger btclog.Logger) { chainview.UseLogger(logger) } -// SetLogWriter uses a specified io.Writer to output package logging info. -// This allows a caller to direct package logging output without needing a -// dependency on seelog. If the caller is also using btclog, UseLogger should -// be used instead. -func SetLogWriter(w io.Writer, level string) error { - if w == nil { - return errors.New("nil writer") - } - - lvl, ok := btclog.LogLevelFromString(level) - if !ok { - return errors.New("invalid log level") - } - - l, err := btclog.NewLoggerFromWriter(w, lvl) - if err != nil { - return err - } - - UseLogger(l) - return nil -} - // logClosure is used to provide a closure over expensive logging operations so // don't have to be performed when the logging level doesn't warrant it. type logClosure func() string