loopd: fix data races of logger

This commit is contained in:
Boris Nagaev 2025-03-10 19:20:20 -03:00 committed by Slyghtning
parent 2249c41d2f
commit e0e66a9b38
No known key found for this signature in database
GPG key ID: F82D456EA023C9BF
8 changed files with 116 additions and 81 deletions

View file

@ -423,7 +423,7 @@ func getTLSConfig(cfg *Config) (*tls.Config, *credentials.TransportCredentials,
// If the certificate expired or it was outdated, delete it and the TLS // If the certificate expired or it was outdated, delete it and the TLS
// key and generate a new pair. // key and generate a new pair.
if time.Now().After(parsedCert.NotAfter) { if time.Now().After(parsedCert.NotAfter) {
log.Info("TLS certificate is expired or outdated, " + infof("TLS certificate is expired or outdated, " +
"removing old file then generating a new one") "removing old file then generating a new one")
err := os.Remove(cfg.TLSCertPath) err := os.Remove(cfg.TLSCertPath)
@ -464,7 +464,7 @@ func loadCertWithCreate(cfg *Config) (tls.Certificate, *x509.Certificate,
if !lnrpc.FileExists(cfg.TLSCertPath) && if !lnrpc.FileExists(cfg.TLSCertPath) &&
!lnrpc.FileExists(cfg.TLSKeyPath) { !lnrpc.FileExists(cfg.TLSKeyPath) {
log.Infof("Generating TLS certificates...") infof("Generating TLS certificates...")
certBytes, keyBytes, err := cert.GenCertPair( certBytes, keyBytes, err := cert.GenCertPair(
defaultSelfSignedOrganization, cfg.TLSExtraIPs, defaultSelfSignedOrganization, cfg.TLSExtraIPs,
cfg.TLSExtraDomains, cfg.TLSDisableAutofill, cfg.TLSExtraDomains, cfg.TLSDisableAutofill,
@ -481,7 +481,7 @@ func loadCertWithCreate(cfg *Config) (tls.Certificate, *x509.Certificate,
return tls.Certificate{}, nil, err return tls.Certificate{}, nil, err
} }
log.Infof("Done generating TLS certificates") infof("Done generating TLS certificates")
} }
return cert.LoadCert(cfg.TLSCertPath, cfg.TLSKeyPath) return cert.LoadCert(cfg.TLSCertPath, cfg.TLSKeyPath)

View file

@ -169,11 +169,11 @@ func (d *Daemon) Start() error {
// anything goes wrong now, we need to cleanly shut down again. // anything goes wrong now, we need to cleanly shut down again.
startErr := d.startWebServers() startErr := d.startWebServers()
if startErr != nil { if startErr != nil {
log.Errorf("Error while starting daemon: %v", err) errorf("Error while starting daemon: %v", err)
d.Stop() d.Stop()
stopErr := <-d.ErrChan stopErr := <-d.ErrChan
if stopErr != nil { if stopErr != nil {
log.Errorf("Error while stopping daemon: %v", stopErr) errorf("Error while stopping daemon: %v", stopErr)
} }
return startErr return startErr
} }
@ -253,7 +253,7 @@ func (d *Daemon) startWebServers() error {
d.registerDebugServer() d.registerDebugServer()
// Next, start the gRPC server listening for HTTP/2 connections. // Next, start the gRPC server listening for HTTP/2 connections.
log.Infof("Starting gRPC listener") infof("Starting gRPC listener")
serverTLSCfg, restClientCreds, err := getTLSConfig(d.cfg) serverTLSCfg, restClientCreds, err := getTLSConfig(d.cfg)
if err != nil { if err != nil {
return fmt.Errorf("could not create gRPC server options: %v", return fmt.Errorf("could not create gRPC server options: %v",
@ -322,7 +322,7 @@ func (d *Daemon) startWebServers() error {
// A nil listener indicates REST is disabled. // A nil listener indicates REST is disabled.
if d.restListener != nil { if d.restListener != nil {
log.Infof("Starting REST proxy listener") infof("Starting REST proxy listener")
d.restServer = &http.Server{ d.restServer = &http.Server{
Handler: restHandler, Handler: restHandler,
@ -333,7 +333,7 @@ func (d *Daemon) startWebServers() error {
go func() { go func() {
defer d.wg.Done() defer d.wg.Done()
log.Infof("REST proxy listening on %s", infof("REST proxy listening on %s",
d.restListener.Addr()) d.restListener.Addr())
err := d.restServer.Serve(d.restListener) err := d.restServer.Serve(d.restListener)
// ErrServerClosed is always returned when the proxy is // ErrServerClosed is always returned when the proxy is
@ -347,7 +347,7 @@ func (d *Daemon) startWebServers() error {
} }
}() }()
} else { } else {
log.Infof("REST proxy disabled") infof("REST proxy disabled")
} }
// Start the grpc server. // Start the grpc server.
@ -355,7 +355,7 @@ func (d *Daemon) startWebServers() error {
go func() { go func() {
defer d.wg.Done() defer d.wg.Done()
log.Infof("RPC server listening on %s", d.grpcListener.Addr()) infof("RPC server listening on %s", d.grpcListener.Addr())
err = d.grpcServer.Serve(d.grpcListener) err = d.grpcServer.Serve(d.grpcListener)
if err != nil && !errors.Is(err, grpc.ErrServerStopped) { if err != nil && !errors.Is(err, grpc.ErrServerStopped) {
// Notify the main error handler goroutine that // Notify the main error handler goroutine that
@ -378,7 +378,7 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
loopdb.EnableExperimentalProtocol() loopdb.EnableExperimentalProtocol()
} }
log.Infof("Protocol version: %v", loopdb.CurrentProtocolVersion()) infof("Protocol version: %v", loopdb.CurrentProtocolVersion())
// If no swap server is specified, use the default addresses for mainnet // If no swap server is specified, use the default addresses for mainnet
// and testnet. // and testnet.
@ -404,18 +404,18 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
// on main context cancel. So we create it early and pass it down. // on main context cancel. So we create it early and pass it down.
d.mainCtx, d.mainCtxCancel = context.WithCancel(context.Background()) d.mainCtx, d.mainCtxCancel = context.WithCancel(context.Background())
log.Infof("Swap server address: %v", d.cfg.Server.Host) infof("Swap server address: %v", d.cfg.Server.Host)
// Check if we need to migrate the database. // Check if we need to migrate the database.
if needSqlMigration(d.cfg) { if needSqlMigration(d.cfg) {
log.Infof("Boltdb found, running migration") infof("Boltdb found, running migration")
err := migrateBoltdb(d.mainCtx, d.cfg) err := migrateBoltdb(d.mainCtx, d.cfg)
if err != nil { if err != nil {
return fmt.Errorf("unable to migrate boltdb: %v", err) return fmt.Errorf("unable to migrate boltdb: %v", err)
} }
log.Infof("Successfully migrated boltdb") infof("Successfully migrated boltdb")
} }
// Now that we know where the database will live, we'll go ahead and // Now that we know where the database will live, we'll go ahead and
@ -436,7 +436,7 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
swapDb, swapDb,
) )
if err != nil { if err != nil {
log.Errorf("Cost migration failed: %v", err) errorf("Cost migration failed: %v", err)
return err return err
} }
@ -460,7 +460,7 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
d.lnd.NodePubkey) d.lnd.NodePubkey)
} }
log.Infof("Using asset client with version %v", getInfo.Version) infof("Using asset client with version %v", getInfo.Version)
} }
// Create an instance of the loop client library. // Create an instance of the loop client library.
@ -507,7 +507,7 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
cleanupMacaroonStore := func() { cleanupMacaroonStore := func() {
err := db.Close() err := db.Close()
if err != nil { if err != nil {
log.Errorf("Error closing macaroon store: %v", err) errorf("Error closing macaroon store: %v", err)
} }
} }
@ -555,11 +555,11 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
go func() { go func() {
defer d.wg.Done() defer d.wg.Done()
log.Info("Starting notification manager") infof("Starting notification manager")
err := notificationManager.Run(d.mainCtx) err := notificationManager.Run(d.mainCtx)
if err != nil { if err != nil {
d.internalErrChan <- err d.internalErrChan <- err
log.Errorf("Notification manager stopped: %v", err) errorf("Notification manager stopped: %v", err)
} }
}() }()
@ -711,7 +711,7 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
// started yet, so if we clean that up now, nothing else needs // started yet, so if we clean that up now, nothing else needs
// to be shut down at this point. // to be shut down at this point.
if err := d.macaroonService.Stop(); err != nil { if err := d.macaroonService.Stop(); err != nil {
log.Errorf("Error shutting down macaroon service: %v", errorf("Error shutting down macaroon service: %v",
err) err)
} }
cleanupMacaroonStore() cleanupMacaroonStore()
@ -728,7 +728,7 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
go func() { go func() {
defer d.wg.Done() defer d.wg.Done()
log.Infof("Starting swap client") infof("Starting swap client")
err := d.impl.Run(d.mainCtx, d.statusChan) err := d.impl.Run(d.mainCtx, d.statusChan)
if err != nil { if err != nil {
// Notify the main error handler goroutine that // Notify the main error handler goroutine that
@ -737,7 +737,7 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
// channel is sufficiently buffered. // channel is sufficiently buffered.
d.internalErrChan <- err d.internalErrChan <- err
} }
log.Infof("Swap client stopped") infof("Swap client stopped")
}() }()
// Start a goroutine that broadcasts swap updates to clients. // Start a goroutine that broadcasts swap updates to clients.
@ -745,7 +745,7 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
go func() { go func() {
defer d.wg.Done() defer d.wg.Done()
log.Infof("Waiting for updates") infof("Waiting for updates")
d.processStatusUpdates(d.mainCtx) d.processStatusUpdates(d.mainCtx)
}() }()
@ -753,13 +753,13 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
go func() { go func() {
defer d.wg.Done() defer d.wg.Done()
log.Info("Starting liquidity manager") infof("Starting liquidity manager")
err := d.liquidityMgr.Run(d.mainCtx) err := d.liquidityMgr.Run(d.mainCtx)
if err != nil && !errors.Is(err, context.Canceled) { if err != nil && !errors.Is(err, context.Canceled) {
d.internalErrChan <- err d.internalErrChan <- err
} }
log.Info("Liquidity manager stopped") infof("Liquidity manager stopped")
}() }()
// Start the reservation manager. // Start the reservation manager.
@ -777,8 +777,8 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
return return
} }
log.Info("Starting reservation manager") infof("Starting reservation manager")
defer log.Info("Reservation manager stopped") defer infof("Reservation manager stopped")
err = d.reservationManager.Run( err = d.reservationManager.Run(
d.mainCtx, int32(getInfo.BlockHeight), initChan, d.mainCtx, int32(getInfo.BlockHeight), initChan,
@ -815,8 +815,8 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
return return
} }
log.Info("Starting instantout manager") infof("Starting instantout manager")
defer log.Info("Instantout manager stopped") defer infof("Instantout manager stopped")
err = d.instantOutManager.Run( err = d.instantOutManager.Run(
d.mainCtx, initChan, int32(getInfo.BlockHeight), d.mainCtx, initChan, int32(getInfo.BlockHeight),
@ -846,12 +846,12 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
go func() { go func() {
defer d.wg.Done() defer d.wg.Done()
log.Info("Starting static address manager...") infof("Starting static address manager...")
err = staticAddressManager.Run(d.mainCtx) err = staticAddressManager.Run(d.mainCtx)
if err != nil && !errors.Is(context.Canceled, err) { if err != nil && !errors.Is(context.Canceled, err) {
d.internalErrChan <- err d.internalErrChan <- err
} }
log.Info("Static address manager stopped") infof("Static address manager stopped")
}() }()
} }
@ -869,12 +869,12 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
return return
} }
log.Info("Starting static address deposit manager...") infof("Starting static address deposit manager...")
err = depositManager.Run(d.mainCtx, info.BlockHeight) err = depositManager.Run(d.mainCtx, info.BlockHeight)
if err != nil && !errors.Is(context.Canceled, err) { if err != nil && !errors.Is(context.Canceled, err) {
d.internalErrChan <- err d.internalErrChan <- err
} }
log.Info("Static address deposit manager stopped") infof("Static address deposit manager stopped")
}() }()
depositManager.WaitInitComplete() depositManager.WaitInitComplete()
} }
@ -893,13 +893,13 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
return return
} }
log.Info("Starting static address deposit withdrawal " + infof("Starting static address deposit withdrawal " +
"manager...") "manager...")
err = withdrawalManager.Run(d.mainCtx, info.BlockHeight) err = withdrawalManager.Run(d.mainCtx, info.BlockHeight)
if err != nil && !errors.Is(context.Canceled, err) { if err != nil && !errors.Is(context.Canceled, err) {
d.internalErrChan <- err d.internalErrChan <- err
} }
log.Info("Static address deposit withdrawal manager " + infof("Static address deposit withdrawal manager " +
"stopped") "stopped")
}() }()
withdrawalManager.WaitInitComplete() withdrawalManager.WaitInitComplete()
@ -920,14 +920,14 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
return return
} }
log.Info("Starting static address loop-in manager...") infof("Starting static address loop-in manager...")
err = staticLoopInManager.Run( err = staticLoopInManager.Run(
d.mainCtx, info.BlockHeight, d.mainCtx, info.BlockHeight,
) )
if err != nil && !errors.Is(context.Canceled, err) { if err != nil && !errors.Is(context.Canceled, err) {
d.internalErrChan <- err d.internalErrChan <- err
} }
log.Info("Starting static address loop-in manager " + infof("Starting static address loop-in manager " +
"stopped") "stopped")
}() }()
staticLoopInManager.WaitInitComplete() staticLoopInManager.WaitInitComplete()
@ -948,7 +948,7 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
// signal the caller that we're done. // signal the caller that we're done.
select { select {
case runtimeErr = <-d.internalErrChan: case runtimeErr = <-d.internalErrChan:
log.Errorf("Runtime error in daemon, shutting down: "+ errorf("Runtime error in daemon, shutting down: "+
"%v", runtimeErr) "%v", runtimeErr)
case <-d.quit: case <-d.quit:
@ -958,7 +958,7 @@ func (d *Daemon) initialize(withMacaroonService bool) error {
// otherwise a caller might exit the process too early. // otherwise a caller might exit the process too early.
d.stop() d.stop()
cleanupMacaroonStore() cleanupMacaroonStore()
log.Info("Daemon exited") infof("Daemon exited")
// The caller expects exactly one message. So we send the error // The caller expects exactly one message. So we send the error
// even if it's nil because we cleanly shut down. // even if it's nil because we cleanly shut down.
@ -987,17 +987,17 @@ func (d *Daemon) stop() {
// As there is no swap activity anymore, we can forcefully shut down the // As there is no swap activity anymore, we can forcefully shut down the
// gRPC and HTTP servers now. // gRPC and HTTP servers now.
log.Infof("Stopping gRPC server") infof("Stopping gRPC server")
if d.grpcServer != nil { if d.grpcServer != nil {
d.grpcServer.Stop() d.grpcServer.Stop()
} }
log.Infof("Stopping REST server") infof("Stopping REST server")
if d.restServer != nil { if d.restServer != nil {
// Don't return the error here, we first want to give everything // Don't return the error here, we first want to give everything
// else a chance to shut down cleanly. // else a chance to shut down cleanly.
err := d.restServer.Close() err := d.restServer.Close()
if err != nil { if err != nil {
log.Errorf("Error stopping REST server: %v", err) errorf("Error stopping REST server: %v", err)
} }
} }
if d.restCtxCancel != nil { if d.restCtxCancel != nil {
@ -1007,7 +1007,7 @@ func (d *Daemon) stop() {
if d.macaroonService != nil { if d.macaroonService != nil {
err := d.macaroonService.Stop() err := d.macaroonService.Stop()
if err != nil { if err != nil {
log.Errorf("Error stopping macaroon service: %v", err) errorf("Error stopping macaroon service: %v", err)
} }
} }

View file

@ -1,6 +1,8 @@
package loopd package loopd
import ( import (
"sync/atomic"
"github.com/btcsuite/btclog/v2" "github.com/btcsuite/btclog/v2"
"github.com/lightninglabs/aperture/l402" "github.com/lightninglabs/aperture/l402"
"github.com/lightninglabs/lndclient" "github.com/lightninglabs/lndclient"
@ -22,18 +24,50 @@ import (
const Subsystem = "LOOPD" const Subsystem = "LOOPD"
var ( var (
log btclog.Logger log_ atomic.Pointer[btclog.Logger]
interceptor signal.Interceptor interceptor signal.Interceptor
) )
// log returns active logger.
func log() btclog.Logger {
return *log_.Load()
}
// setLogger uses a specified Logger to output package logging info.
func setLogger(logger btclog.Logger) {
log_.Store(&logger)
}
// tracef logs a message with level TRACE.
func tracef(format string, params ...interface{}) {
log().Tracef(format, params...)
}
// infof logs a message with level INFO.
func infof(format string, params ...interface{}) {
log().Infof(format, params...)
}
// warnf logs a message with level WARN.
func warnf(format string, params ...interface{}) {
log().Warnf(format, params...)
}
// errorf logs a message with level ERROR.
func errorf(format string, params ...interface{}) {
log().Errorf(format, params...)
}
// SetupLoggers initializes all package-global logger variables. // SetupLoggers initializes all package-global logger variables.
func SetupLoggers(root *build.SubLoggerManager, intercept signal.Interceptor) { func SetupLoggers(root *build.SubLoggerManager, intercept signal.Interceptor) {
genLogger := genSubLogger(root, intercept) genLogger := genSubLogger(root, intercept)
log = build.NewSubLogger(Subsystem, genLogger) logger := build.NewSubLogger(Subsystem, genLogger)
setLogger(logger)
interceptor = intercept interceptor = intercept
lnd.SetSubLogger(root, Subsystem, log) lnd.SetSubLogger(root, Subsystem, logger)
lnd.AddSubLogger(root, "LOOP", intercept, loop.UseLogger) lnd.AddSubLogger(root, "LOOP", intercept, loop.UseLogger)
lnd.AddSubLogger(root, "SWEEP", intercept, sweepbatcher.UseLogger) lnd.AddSubLogger(root, "SWEEP", intercept, sweepbatcher.UseLogger)
lnd.AddSubLogger(root, "LNDC", intercept, lndclient.UseLogger) lnd.AddSubLogger(root, "LNDC", intercept, lndclient.UseLogger)

View file

@ -66,7 +66,7 @@ func needSqlMigration(cfg *Config) bool {
// any deleted files occasionally (reboot, etc). // any deleted files occasionally (reboot, etc).
sqliteDBPath := filepath.Join(cfg.DataDir, "loop_sqlite.db") sqliteDBPath := filepath.Join(cfg.DataDir, "loop_sqlite.db")
if lnrpc.FileExists(sqliteDBPath) { if lnrpc.FileExists(sqliteDBPath) {
log.Infof("Found sqlite db at %v, skipping migration", infof("Found sqlite db at %v, skipping migration",
sqliteDBPath) sqliteDBPath)
return false return false

View file

@ -222,7 +222,7 @@ func Run(rpcCfg RPCConfig) error {
} }
// Print the version before executing either primary directive. // Print the version before executing either primary directive.
log.Infof("Version: %v", loop.Version()) infof("Version: %v", loop.Version())
lisCfg := NewListenerConfig(&config, rpcCfg) lisCfg := NewListenerConfig(&config, rpcCfg)
@ -235,7 +235,7 @@ func Run(rpcCfg RPCConfig) error {
select { select {
case <-interceptor.ShutdownChannel(): case <-interceptor.ShutdownChannel():
log.Infof("Received SIGINT (Ctrl+C).") infof("Received SIGINT (Ctrl+C).")
daemon.Stop() daemon.Stop()
// The above stop will return immediately. But we'll be // The above stop will return immediately. But we'll be

View file

@ -112,7 +112,7 @@ func (s *swapClientServer) LoopOut(ctx context.Context,
in *looprpc.LoopOutRequest) ( in *looprpc.LoopOutRequest) (
*looprpc.SwapResponse, error) { *looprpc.SwapResponse, error) {
log.Infof("Loop out request received") infof("Loop out request received")
// Note that LoopOutRequest.PaymentTimeout is unsigned and therefore // Note that LoopOutRequest.PaymentTimeout is unsigned and therefore
// cannot be negative. // cannot be negative.
@ -257,7 +257,7 @@ func (s *swapClientServer) LoopOut(ctx context.Context,
info, err := s.impl.LoopOut(ctx, req) info, err := s.impl.LoopOut(ctx, req)
if err != nil { if err != nil {
log.Errorf("LoopOut: %v", err) errorf("LoopOut: %v", err)
return nil, err return nil, err
} }
@ -461,7 +461,7 @@ func (s *swapClientServer) marshallSwap(ctx context.Context,
func (s *swapClientServer) Monitor(in *looprpc.MonitorRequest, func (s *swapClientServer) Monitor(in *looprpc.MonitorRequest,
server looprpc.SwapClient_MonitorServer) error { server looprpc.SwapClient_MonitorServer) error {
log.Infof("Monitor request received") infof("Monitor request received")
send := func(info loop.SwapInfo) error { send := func(info loop.SwapInfo) error {
rpcSwap, err := s.marshallSwap(server.Context(), &info) rpcSwap, err := s.marshallSwap(server.Context(), &info)
@ -732,11 +732,11 @@ func (s *swapClientServer) AbandonSwap(ctx context.Context,
func (s *swapClientServer) LoopOutTerms(ctx context.Context, func (s *swapClientServer) LoopOutTerms(ctx context.Context,
_ *looprpc.TermsRequest) (*looprpc.OutTermsResponse, error) { _ *looprpc.TermsRequest) (*looprpc.OutTermsResponse, error) {
log.Infof("Loop out terms request received") infof("Loop out terms request received")
terms, err := s.impl.LoopOutTerms(ctx, defaultLoopdInitiator) terms, err := s.impl.LoopOutTerms(ctx, defaultLoopdInitiator)
if err != nil { if err != nil {
log.Errorf("Terms request: %v", err) errorf("Terms request: %v", err)
return nil, err return nil, err
} }
@ -822,11 +822,11 @@ func (s *swapClientServer) LoopOutQuote(ctx context.Context,
func (s *swapClientServer) GetLoopInTerms(ctx context.Context, func (s *swapClientServer) GetLoopInTerms(ctx context.Context,
_ *looprpc.TermsRequest) (*looprpc.InTermsResponse, error) { _ *looprpc.TermsRequest) (*looprpc.InTermsResponse, error) {
log.Infof("Loop in terms request received") infof("Loop in terms request received")
terms, err := s.impl.LoopInTerms(ctx, defaultLoopdInitiator) terms, err := s.impl.LoopInTerms(ctx, defaultLoopdInitiator)
if err != nil { if err != nil {
log.Errorf("Terms request: %v", err) errorf("Terms request: %v", err)
return nil, err return nil, err
} }
@ -840,7 +840,7 @@ func (s *swapClientServer) GetLoopInTerms(ctx context.Context,
func (s *swapClientServer) GetLoopInQuote(ctx context.Context, func (s *swapClientServer) GetLoopInQuote(ctx context.Context,
req *looprpc.QuoteRequest) (*looprpc.InQuoteResponse, error) { req *looprpc.QuoteRequest) (*looprpc.InQuoteResponse, error) {
log.Infof("Loop in quote request received") infof("Loop in quote request received")
var ( var (
numDeposits = uint32(len(req.DepositOutpoints)) numDeposits = uint32(len(req.DepositOutpoints))
@ -981,7 +981,7 @@ func unmarshallHopHint(rpcHint *swapserverrpc.HopHint) (zpay32.HopHint, error) {
func (s *swapClientServer) Probe(ctx context.Context, func (s *swapClientServer) Probe(ctx context.Context,
req *looprpc.ProbeRequest) (*looprpc.ProbeResponse, error) { req *looprpc.ProbeRequest) (*looprpc.ProbeResponse, error) {
log.Infof("Probe request received") infof("Probe request received")
var lastHop *route.Vertex var lastHop *route.Vertex
if req.LastHop != nil { if req.LastHop != nil {
@ -1013,7 +1013,7 @@ func (s *swapClientServer) Probe(ctx context.Context,
func (s *swapClientServer) LoopIn(ctx context.Context, func (s *swapClientServer) LoopIn(ctx context.Context,
in *looprpc.LoopInRequest) (*looprpc.SwapResponse, error) { in *looprpc.LoopInRequest) (*looprpc.SwapResponse, error) {
log.Infof("Loop in request received") infof("Loop in request received")
htlcConfTarget, err := validateLoopInRequest( htlcConfTarget, err := validateLoopInRequest(
in.HtlcConfTarget, in.ExternalHtlc, 0, in.Amt, in.HtlcConfTarget, in.ExternalHtlc, 0, in.Amt,
@ -1052,7 +1052,7 @@ func (s *swapClientServer) LoopIn(ctx context.Context,
} }
swapInfo, err := s.impl.LoopIn(ctx, req) swapInfo, err := s.impl.LoopIn(ctx, req)
if err != nil { if err != nil {
log.Errorf("Loop in: %v", err) errorf("Loop in: %v", err)
return nil, err return nil, err
} }
@ -1079,7 +1079,7 @@ func (s *swapClientServer) LoopIn(ctx context.Context,
func (s *swapClientServer) GetL402Tokens(ctx context.Context, func (s *swapClientServer) GetL402Tokens(ctx context.Context,
_ *looprpc.TokensRequest) (*looprpc.TokensResponse, error) { _ *looprpc.TokensRequest) (*looprpc.TokensResponse, error) {
log.Infof("Get L402 tokens request received") infof("Get L402 tokens request received")
tokens, err := s.impl.L402Store.AllTokens() tokens, err := s.impl.L402Store.AllTokens()
if err != nil { if err != nil {
@ -1128,7 +1128,7 @@ func (s *swapClientServer) GetL402Tokens(ctx context.Context,
func (s *swapClientServer) GetLsatTokens(ctx context.Context, func (s *swapClientServer) GetLsatTokens(ctx context.Context,
req *looprpc.TokensRequest) (*looprpc.TokensResponse, error) { req *looprpc.TokensRequest) (*looprpc.TokensResponse, error) {
log.Warnf("Received deprecated call GetLsatTokens. Please update the " + warnf("Received deprecated call GetLsatTokens. Please update the " +
"client software. Calling GetL402Tokens now.") "client software. Calling GetL402Tokens now.")
return s.GetL402Tokens(ctx, req) return s.GetL402Tokens(ctx, req)
@ -1754,7 +1754,7 @@ func (s *swapClientServer) StaticAddressLoopIn(ctx context.Context,
in *looprpc.StaticAddressLoopInRequest) ( in *looprpc.StaticAddressLoopInRequest) (
*looprpc.StaticAddressLoopInResponse, error) { *looprpc.StaticAddressLoopInResponse, error) {
log.Infof("Static loop-in request received") infof("Static loop-in request received")
routeHints, err := unmarshallRouteHints(in.RouteHints) routeHints, err := unmarshallRouteHints(in.RouteHints)
if err != nil { if err != nil {
@ -2187,52 +2187,52 @@ func validateLoopOutRequest(ctx context.Context, lnd lndclient.LightningClient,
func hasBandwidth(channels []lndclient.ChannelInfo, amt btcutil.Amount, func hasBandwidth(channels []lndclient.ChannelInfo, amt btcutil.Amount,
maxParts int) (bool, int) { maxParts int) (bool, int) {
log.Tracef("Checking if %v sats can be routed with %v parts over "+ tracef("Checking if %v sats can be routed with %v parts over "+
"channel set of length %v", amt, maxParts, len(channels)) "channel set of length %v", amt, maxParts, len(channels))
localBalances := make([]btcutil.Amount, len(channels)) localBalances := make([]btcutil.Amount, len(channels))
var totalBandwidth btcutil.Amount var totalBandwidth btcutil.Amount
for i, channel := range channels { for i, channel := range channels {
log.Tracef("Channel %v: local=%v remote=%v", channel.ChannelID, tracef("Channel %v: local=%v remote=%v", channel.ChannelID,
channel.LocalBalance, channel.RemoteBalance) channel.LocalBalance, channel.RemoteBalance)
localBalances[i] = channel.LocalBalance localBalances[i] = channel.LocalBalance
totalBandwidth += channel.LocalBalance totalBandwidth += channel.LocalBalance
} }
log.Tracef("Total bandwidth: %v", totalBandwidth) tracef("Total bandwidth: %v", totalBandwidth)
if totalBandwidth < amt { if totalBandwidth < amt {
return false, 0 return false, 0
} }
logLocalBalances := func(shard int) { logLocalBalances := func(shard int) {
log.Tracef("Local balances for %v shards:", shard) tracef("Local balances for %v shards:", shard)
for i, balance := range localBalances { for i, balance := range localBalances {
log.Tracef("Channel %v: localBalances[%v]=%v", tracef("Channel %v: localBalances[%v]=%v",
channels[i].ChannelID, i, balance) channels[i].ChannelID, i, balance)
} }
} }
split := amt split := amt
for shard := 0; shard <= maxParts; { for shard := 0; shard <= maxParts; {
log.Tracef("Trying to split %v sats into %v parts", amt, shard) tracef("Trying to split %v sats into %v parts", amt, shard)
paid := false paid := false
for i := 0; i < len(localBalances); i++ { for i := 0; i < len(localBalances); i++ {
// TODO(hieblmi): Consider channel reserves because the // TODO(hieblmi): Consider channel reserves because the
// channel can't send its full local balance. // channel can't send its full local balance.
if localBalances[i] >= split { if localBalances[i] >= split {
log.Tracef("len(shards)=%v: Local channel "+ tracef("len(shards)=%v: Local channel "+
"balance %v can pay %v sats", "balance %v can pay %v sats",
shard, localBalances[i], split) shard, localBalances[i], split)
localBalances[i] -= split localBalances[i] -= split
log.Tracef("len(shards)=%v: Subtracted "+ tracef("len(shards)=%v: Subtracted "+
"%v sats from localBalance[%v]=%v", "%v sats from localBalance[%v]=%v",
shard, split, i, localBalances[i]) shard, split, i, localBalances[i])
amt -= split amt -= split
log.Tracef("len(shards)=%v: Remaining total "+ tracef("len(shards)=%v: Remaining total "+
"amount amt=%v", shard, amt) "amount amt=%v", shard, amt)
paid = true paid = true
@ -2245,26 +2245,26 @@ func hasBandwidth(channels []lndclient.ChannelInfo, amt btcutil.Amount,
logLocalBalances(shard) logLocalBalances(shard)
if amt == 0 { if amt == 0 {
log.Tracef("Payment is routable with %v part(s)", shard) tracef("Payment is routable with %v part(s)", shard)
return true, shard return true, shard
} }
if !paid { if !paid {
log.Tracef("len(shards)=%v: No channel could pay %v "+ tracef("len(shards)=%v: No channel could pay %v "+
"sats, halving payment to %v and trying again", "sats, halving payment to %v and trying again",
split/2) split/2)
split /= 2 split /= 2
} else { } else {
log.Tracef("len(shards)=%v: Payment was made, trying "+ tracef("len(shards)=%v: Payment was made, trying "+
"to pay remaining sats %v", shard, amt) "to pay remaining sats %v", shard, amt)
split = amt split = amt
} }
} }
log.Tracef("Payment is not routable, remaining amount that can't be "+ tracef("Payment is not routable, remaining amount that can't be "+
"sent: %v sats", amt) "sent: %v sats", amt)
logLocalBalances(maxParts) logLocalBalances(maxParts)

View file

@ -491,7 +491,8 @@ func TestValidateLoopOutRequest(t *testing.T) {
logger := btclog.NewSLogger( logger := btclog.NewSLogger(
btclog.NewDefaultHandler(os.Stdout), btclog.NewDefaultHandler(os.Stdout),
) )
log = logger.SubSystem(Subsystem) setLogger(logger.SubSystem(Subsystem))
conf, err := validateLoopOutRequest( conf, err := validateLoopOutRequest(
ctx, lnd.Client, &test.chain, req, ctx, lnd.Client, &test.chain, req,
test.destAddr, test.maxParts, test.destAddr, test.maxParts,

View file

@ -57,12 +57,12 @@ func getClient(cfg *Config, swapDb loopdb.SwapStore,
} }
if cfg.MaxL402Cost == defaultCost && cfg.MaxLSATCost != 0 { if cfg.MaxL402Cost == defaultCost && cfg.MaxLSATCost != 0 {
log.Warnf("Option maxlsatcost is deprecated and will be " + warnf("Option maxlsatcost is deprecated and will be " +
"removed. Switch to maxl402cost.") "removed. Switch to maxl402cost.")
clientConfig.MaxL402Cost = btcutil.Amount(cfg.MaxLSATCost) clientConfig.MaxL402Cost = btcutil.Amount(cfg.MaxLSATCost)
} }
if cfg.MaxL402Fee == defaultFee && cfg.MaxLSATFee != 0 { if cfg.MaxL402Fee == defaultFee && cfg.MaxLSATFee != 0 {
log.Warnf("Option maxlsatfee is deprecated and will be " + warnf("Option maxlsatfee is deprecated and will be " +
"removed. Switch to maxl402fee.") "removed. Switch to maxl402fee.")
clientConfig.MaxL402Fee = btcutil.Amount(cfg.MaxLSATFee) clientConfig.MaxL402Fee = btcutil.Amount(cfg.MaxLSATFee)
} }
@ -87,7 +87,7 @@ func openDatabase(cfg *Config, chainParams *chaincfg.Params) (loopdb.SwapStore,
) )
switch cfg.DatabaseBackend { switch cfg.DatabaseBackend {
case DatabaseBackendSqlite: case DatabaseBackendSqlite:
log.Infof("Opening sqlite3 database at: %v", infof("Opening sqlite3 database at: %v",
cfg.Sqlite.DatabaseFileName) cfg.Sqlite.DatabaseFileName)
db, err = loopdb.NewSqliteStore(cfg.Sqlite, chainParams) db, err = loopdb.NewSqliteStore(cfg.Sqlite, chainParams)
@ -97,7 +97,7 @@ func openDatabase(cfg *Config, chainParams *chaincfg.Params) (loopdb.SwapStore,
baseDb = *db.(*loopdb.SqliteSwapStore).BaseDB baseDb = *db.(*loopdb.SqliteSwapStore).BaseDB
case DatabaseBackendPostgres: case DatabaseBackendPostgres:
log.Infof("Opening postgres database at: %v", infof("Opening postgres database at: %v",
cfg.Postgres.DSN(true)) cfg.Postgres.DSN(true))
db, err = loopdb.NewPostgresStore(cfg.Postgres, chainParams) db, err = loopdb.NewPostgresStore(cfg.Postgres, chainParams)