cmd/loopd: add persistent logging, debug level toggle

In this commit, we add persistent logic to the loopd daemon. Users can
now designate a default logging directory, as well as log rotation
options. Additionally, we've added a new `--debuglevel` command which
allows users to crank up the logging for particular sub-systems on start
up.

Fixes #5.
pull/30/head
Olaoluwa Osuntokun 5 years ago
parent 9a824d88b1
commit 6ddf0fa523
No known key found for this signature in database
GPG Key ID: CE58F7F8E20FD9A2

@ -1,5 +1,25 @@
package main
import (
"path/filepath"
"github.com/btcsuite/btcutil"
)
var (
loopDirBase = btcutil.AppDataDir("loop", false)
defaultConfigFilename = "loopd.conf"
defaultLogLevel = "info"
defaultLogDirname = "logs"
defaultLogFilename = "loopd.log"
defaultLogDir = filepath.Join(loopDirBase, defaultLogDirname)
defaultMaxLogFiles = 3
defaultMaxLogFileSize = 10
)
type lndConfig struct {
Host string `long:"host" description:"lnd instance rpc address"`
MacaroonPath string `long:"macaroonpath" description:"Path to lnd macaroon"`
@ -19,6 +39,12 @@ type config struct {
Lnd *lndConfig `group:"lnd" namespace:"lnd"`
View viewParameters `command:"view" alias:"v" description:"View all swaps in the database. This command can only be executed when loopd is not running."`
LogDir string `long:"logdir" description:"Directory to log output."`
MaxLogFiles int `long:"maxlogfiles" description:"Maximum logfiles to keep (0 for no rotation)"`
MaxLogFileSize int `long:"maxlogfilesize" description:"Maximum logfile size in MB"`
DebugLevel string `short:"d" long:"debuglevel" description:"Logging level for all subsystems {trace, debug, info, warn, error, critical} -- You may also specify <subsystem>=<level>,<subsystem2>=<level>,... to set the log level for individual subsystems -- Use show to list available subsystems"`
}
var defaultConfig = config{
@ -30,4 +56,8 @@ var defaultConfig = config{
Lnd: &lndConfig{
Host: "localhost:10009",
},
MaxLogFiles: defaultMaxLogFiles,
MaxLogFileSize: defaultMaxLogFileSize,
DebugLevel: defaultLogLevel,
LogDir: defaultLogDir,
}

@ -62,7 +62,7 @@ func daemon(config *config) error {
looprpc.RegisterSwapClientServer(grpcServer, &server)
// Next, start the gRPC server listening for HTTP/2 connections.
logger.Infof("Starting gRPC listener")
loopdLog.Infof("Starting gRPC listener")
grpcListener, err := net.Listen("tcp", config.RPCListen)
if err != nil {
return fmt.Errorf("RPC server unable to listen on %s",
@ -84,7 +84,7 @@ func daemon(config *config) error {
return err
}
logger.Infof("Starting REST proxy listener")
loopdLog.Infof("Starting REST proxy listener")
restListener, err := net.Listen("tcp", config.RESTListen)
if err != nil {
return fmt.Errorf("REST proxy unable to listen on %s",
@ -104,14 +104,14 @@ func daemon(config *config) error {
go func() {
defer wg.Done()
logger.Infof("Starting swap client")
loopdLog.Infof("Starting swap client")
err := swapClient.Run(mainCtx, statusChan)
if err != nil {
logger.Error(err)
loopdLog.Error(err)
}
logger.Infof("Swap client stopped")
loopdLog.Infof("Swap client stopped")
logger.Infof("Stopping gRPC server")
loopdLog.Infof("Stopping gRPC server")
grpcServer.Stop()
cancel()
@ -122,7 +122,7 @@ func daemon(config *config) error {
go func() {
defer wg.Done()
logger.Infof("Waiting for updates")
loopdLog.Infof("Waiting for updates")
for {
select {
case swap := <-statusChan:
@ -149,12 +149,12 @@ func daemon(config *config) error {
go func() {
defer wg.Done()
logger.Infof("RPC server listening on %s", grpcListener.Addr())
logger.Infof("REST proxy listening on %s", restListener.Addr())
loopdLog.Infof("RPC server listening on %s", grpcListener.Addr())
loopdLog.Infof("REST proxy listening on %s", restListener.Addr())
err = grpcServer.Serve(grpcListener)
if err != nil {
logger.Error(err)
loopdLog.Error(err)
}
}()
@ -164,7 +164,7 @@ func daemon(config *config) error {
// Run until the users terminates loopd or an error occurred.
select {
case <-interruptChannel:
logger.Infof("Received SIGINT (Ctrl+C).")
loopdLog.Infof("Received SIGINT (Ctrl+C).")
// TODO: Remove debug code.
// Debug code to dump goroutines on hanging exit.

@ -1,24 +1,207 @@
package main
import (
"fmt"
"io"
"os"
"path/filepath"
"sort"
"strings"
"github.com/btcsuite/btclog"
"github.com/jrick/logrotate/rotator"
"github.com/lightninglabs/loop"
"github.com/lightninglabs/loop/lndclient"
"github.com/lightningnetwork/lnd/build"
)
// 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.
// Loggers per subsystem. A single backend logger is created and all subsystem
// 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 = btclog.NewBackend(logWriter{})
logger = backendLog.Logger("LOOPD")
logWriter = &build.LogWriter{}
// 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
loopdLog = build.NewSubLogger("LOOPD", backendLog.Logger)
loopLog = build.NewSubLogger("LOOP", backendLog.Logger)
lndClientLog = build.NewSubLogger("LNDC", backendLog.Logger)
)
// 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 init() {
loop.UseLogger(loopLog)
lndclient.UseLogger(lndClientLog)
}
// initLogRotator initializes the logging rotator to write logs to logFile and
// create roll files in the same directory. It must be called before the
// package-global log rotator variables are used.
func initLogRotator(logFile string, maxLogFileSize int, maxLogFiles int) {
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, int64(maxLogFileSize*1024), false, maxLogFiles,
)
if err != nil {
fmt.Fprintf(os.Stderr, "failed to create file rotator: %v\n", err)
os.Exit(1)
}
pr, pw := io.Pipe()
go r.Run(pr)
logWriter.RotatorPipe = pw
logRotator = r
}
// subsystemLoggers maps each subsystem identifier to its associated logger.
var subsystemLoggers = map[string]btclog.Logger{
"LOOPD": loopdLog,
"LOOP": loopLog,
"LNDC": lndClientLog,
}
// 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, _ := btclog.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)
}
}
// 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
// String invokes the underlying function and returns the result.
func (c logClosure) String() string {
return c()
}
// newLogClosure returns a new closure over a function that returns a string
// which itself provides a Stringer interface so that it can be used with the
// logging system.
func newLogClosure(c func() string) logClosure {
return logClosure(c)
}
// parseAndSetDebugLevels attempts to parse the specified debug level and set
// the levels accordingly. An appropriate error is returned if anything is
// invalid.
func parseAndSetDebugLevels(debugLevel string) error {
// When the specified string doesn't have any delimiters, treat it as
// the log level for all subsystems.
if !strings.Contains(debugLevel, ",") && !strings.Contains(debugLevel, "=") {
// Validate debug log level.
if !validLogLevel(debugLevel) {
str := "The specified debug level [%v] is invalid"
return fmt.Errorf(str, debugLevel)
}
// Change the logging level for all subsystems.
setLogLevels(debugLevel)
return nil
}
// Split the specified string into subsystem/level pairs while detecting
// issues and update the log levels accordingly.
for _, logLevelPair := range strings.Split(debugLevel, ",") {
if !strings.Contains(logLevelPair, "=") {
str := "The specified debug level contains an invalid " +
"subsystem/level pair [%v]"
return fmt.Errorf(str, logLevelPair)
}
// Extract the specified subsystem and log level.
fields := strings.Split(logLevelPair, "=")
subsysID, logLevel := fields[0], fields[1]
// Validate subsystem.
if _, exists := subsystemLoggers[subsysID]; !exists {
str := "The specified subsystem [%v] is invalid -- " +
"supported subsystems %v"
return fmt.Errorf(str, subsysID, supportedSubsystems())
}
// Validate log level.
if !validLogLevel(logLevel) {
str := "The specified debug level [%v] is invalid"
return fmt.Errorf(str, logLevel)
}
setLogLevel(subsysID, logLevel)
}
return nil
}
// validLogLevel returns whether or not logLevel is a valid debug log level.
func validLogLevel(logLevel string) bool {
switch logLevel {
case "trace":
fallthrough
case "debug":
fallthrough
case "info":
fallthrough
case "warn":
fallthrough
case "error":
fallthrough
case "critical":
fallthrough
case "off":
return true
}
return false
}
// supportedSubsystems returns a sorted slice of the supported subsystems for
// logging purposes.
func supportedSubsystems() []string {
// Convert the subsystemLoggers map keys to a slice.
subsystems := make([]string, 0, len(subsystemLoggers))
for subsysID := range subsystemLoggers {
subsystems = append(subsystems, subsysID)
}
func (logWriter) Write(p []byte) (n int, err error) {
os.Stdout.Write(p)
return len(p), nil
// Sort the subsystems for stable display.
sort.Strings(subsystems)
return subsystems
}

@ -9,7 +9,6 @@ import (
flags "github.com/jessevdk/go-flags"
"github.com/btcsuite/btcutil"
"github.com/lightninglabs/loop"
"github.com/lightningnetwork/lnd/lntypes"
)
@ -19,9 +18,6 @@ const (
)
var (
loopDirBase = btcutil.AppDataDir("loop", false)
defaultConfigFilename = "loopd.conf"
swaps = make(map[lntypes.Hash]loop.SwapInfo)
subscribers = make(map[int]chan<- interface{})
nextSubscriberID int
@ -81,8 +77,32 @@ func start() error {
os.Exit(0)
}
// Special show command to list supported subsystems and exit.
if config.DebugLevel == "show" {
fmt.Println("Supported subsystems", supportedSubsystems())
os.Exit(0)
}
// Append the network type to the log directory so it is "namespaced"
// per network in the same fashion as the data directory.
config.LogDir = filepath.Join(config.LogDir, config.Network)
// Parse, validate, and set debug log level(s).
usageMessage := fmt.Sprintf("Use %s -h to show usage", appName)
if err := parseAndSetDebugLevels(config.DebugLevel); err != nil {
fmt.Fprintln(os.Stderr, err)
fmt.Fprintln(os.Stderr, usageMessage)
return err
}
// Initialize logging at the default logging level.
initLogRotator(
filepath.Join(config.LogDir, defaultLogFilename),
config.MaxLogFileSize, config.MaxLogFiles,
)
// Print the version before executing either primary directive.
logger.Infof("Version: %v", loop.Version())
loopdLog.Infof("Version: %v", loop.Version())
// Execute command.
if parser.Active == nil {

@ -32,7 +32,7 @@ func (s *swapClientServer) LoopOut(ctx context.Context,
in *looprpc.LoopOutRequest) (
*looprpc.SwapResponse, error) {
logger.Infof("LoopOut request received")
loopdLog.Infof("LoopOut request received")
var sweepAddr btcutil.Address
if in.Dest == "" {
@ -65,7 +65,7 @@ func (s *swapClientServer) LoopOut(ctx context.Context,
}
hash, err := s.impl.LoopOut(ctx, req)
if err != nil {
logger.Errorf("LoopOut: %v", err)
loopdLog.Errorf("LoopOut: %v", err)
return nil, err
}
@ -118,7 +118,7 @@ func (s *swapClientServer) marshallSwap(loopSwap *loop.SwapInfo) (
func (s *swapClientServer) Monitor(in *looprpc.MonitorRequest,
server looprpc.SwapClient_MonitorServer) error {
logger.Infof("Monitor request received")
loopdLog.Infof("Monitor request received")
send := func(info loop.SwapInfo) error {
rpcSwap, err := s.marshallSwap(&info)
@ -212,11 +212,11 @@ func (s *swapClientServer) Monitor(in *looprpc.MonitorRequest,
func (s *swapClientServer) LoopOutTerms(ctx context.Context,
req *looprpc.TermsRequest) (*looprpc.TermsResponse, error) {
logger.Infof("Terms request received")
loopdLog.Infof("Terms request received")
terms, err := s.impl.LoopOutTerms(ctx)
if err != nil {
logger.Errorf("Terms request: %v", err)
loopdLog.Errorf("Terms request: %v", err)
return nil, err
}

Loading…
Cancel
Save