akovalenko/lnd.xprv
1
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

Merge pull request #3564 from joostjager/htlcswitch-logging

Browse Source 
build+htlcswitch+lnwallet: add prefix logger
This commit is contained in:
Conner Fromknecht 2019-10-16 13:00:36 +02:00 committed by GitHub
commit dbc0e88584
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
4 changed files with 285 additions and 206 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

112
build/prefix_log.go Normal file
View File

@ -0,0 +1,112 @@
package build
import "github.com/btcsuite/btclog"
// PrefixLog is a pass-through logger that adds a prefix to every logged line.
type PrefixLog struct {
log btclog.Logger
prefix string
}
// NewPrefixLog instantiates a new prefixed logger.
func NewPrefixLog(prefix string, log btclog.Logger) *PrefixLog {
return &PrefixLog{
prefix: prefix,
log: log,
}
}
// addFormatPrefix prepends the prefix to a format string.
func (p *PrefixLog) addFormatPrefix(s string) string {
return p.prefix + " " + s
}
// addArgsPrefix prepends the prefix to a list of arguments.
func (p *PrefixLog) addArgsPrefix(args []interface{}) []interface{} {
return append([]interface{}{p.prefix}, args...)
}
// Tracef formats message according to format specifier and writes to to log
// with LevelTrace.
func (p *PrefixLog) Tracef(format string, params ...interface{}) {
p.log.Tracef(p.addFormatPrefix(format), params...)
}
// Debugf formats message according to format specifier and writes to log with
// LevelDebug.
func (p *PrefixLog) Debugf(format string, params ...interface{}) {
p.log.Debugf(p.addFormatPrefix(format), params...)
}
// Infof formats message according to format specifier and writes to log with
// LevelInfo.
func (p *PrefixLog) Infof(format string, params ...interface{}) {
p.log.Infof(p.addFormatPrefix(format), params...)
}
// Warnf formats message according to format specifier and writes to to log with
// LevelWarn.
func (p *PrefixLog) Warnf(format string, params ...interface{}) {
p.log.Warnf(p.addFormatPrefix(format), params...)
}
// Errorf formats message according to format specifier and writes to to log
// with LevelError.
func (p *PrefixLog) Errorf(format string, params ...interface{}) {
p.log.Errorf(p.addFormatPrefix(format), params...)
}
// Criticalf formats message according to format specifier and writes to log
// with LevelCritical.
func (p *PrefixLog) Criticalf(format string, params ...interface{}) {
p.log.Criticalf(p.addFormatPrefix(format), params...)
}
// Trace formats message using the default formats for its operands and writes
// to log with LevelTrace.
func (p *PrefixLog) Trace(v ...interface{}) {
p.log.Trace(p.addArgsPrefix(v)...)
}
// Debug formats message using the default formats for its operands and writes
// to log with LevelDebug.
func (p *PrefixLog) Debug(v ...interface{}) {
p.log.Debug(p.addArgsPrefix(v)...)
}
// Info formats message using the default formats for its operands and writes to
// log with LevelInfo.
func (p *PrefixLog) Info(v ...interface{}) {
p.log.Info(p.addArgsPrefix(v)...)
}
// Warn formats message using the default formats for its operands and writes to
// log with LevelWarn.
func (p *PrefixLog) Warn(v ...interface{}) {
p.log.Warn(p.addArgsPrefix(v)...)
}
// Error formats message using the default formats for its operands and writes
// to log with LevelError.
func (p *PrefixLog) Error(v ...interface{}) {
p.log.Error(p.addArgsPrefix(v)...)
}
// Critical formats message using the default formats for its operands and
// writes to log with LevelCritical.
func (p *PrefixLog) Critical(v ...interface{}) {
p.log.Critical(p.addArgsPrefix(v)...)
}
// Level returns the current logging level.
func (p *PrefixLog) Level() btclog.Level {
return p.log.Level()
}
// SetLevel changes the logging level to the passed level.
func (p *PrefixLog) SetLevel(level btclog.Level) {
p.log.SetLevel(level)
}
// Assert that PrefixLog fulfills the btclog.Logger interface.
var _ btclog.Logger = &PrefixLog{}

268
htlcswitch/link.go
View File

@ -11,8 +11,10 @@ import (
"time" "time"
"github.com/btcsuite/btcd/wire" "github.com/btcsuite/btcd/wire"
"github.com/btcsuite/btclog"
"github.com/davecgh/go-spew/spew" "github.com/davecgh/go-spew/spew"
"github.com/go-errors/errors" "github.com/go-errors/errors"
"github.com/lightningnetwork/lnd/build"
"github.com/lightningnetwork/lnd/channeldb" "github.com/lightningnetwork/lnd/channeldb"
"github.com/lightningnetwork/lnd/contractcourt" "github.com/lightningnetwork/lnd/contractcourt"
"github.com/lightningnetwork/lnd/htlcswitch/hodl" "github.com/lightningnetwork/lnd/htlcswitch/hodl"
@ -378,6 +380,9 @@ type channelLink struct {
// resolving those htlcs when we receive a message on hodlQueue. // resolving those htlcs when we receive a message on hodlQueue.
hodlMap map[channeldb.CircuitKey]hodlHtlc hodlMap map[channeldb.CircuitKey]hodlHtlc
// log is a link-specific logging instance.
log btclog.Logger
wg sync.WaitGroup wg sync.WaitGroup
quit chan struct{} quit chan struct{}
} }
@ -393,6 +398,8 @@ type hodlHtlc struct {
func NewChannelLink(cfg ChannelLinkConfig, func NewChannelLink(cfg ChannelLinkConfig,
channel *lnwallet.LightningChannel) ChannelLink { channel *lnwallet.LightningChannel) ChannelLink {
logPrefix := fmt.Sprintf("ChannelLink(%v):", channel.ShortChanID())
return &channelLink{ return &channelLink{
cfg: cfg, cfg: cfg,
channel: channel, channel: channel,
@ -403,6 +410,7 @@ func NewChannelLink(cfg ChannelLinkConfig,
htlcUpdates: make(chan *contractcourt.ContractUpdate), htlcUpdates: make(chan *contractcourt.ContractUpdate),
hodlMap: make(map[channeldb.CircuitKey]hodlHtlc), hodlMap: make(map[channeldb.CircuitKey]hodlHtlc),
hodlQueue: queue.NewConcurrentQueue(10), hodlQueue: queue.NewConcurrentQueue(10),
log: build.NewPrefixLog(logPrefix, log),
quit: make(chan struct{}), quit: make(chan struct{}),
} }
} }
@ -418,11 +426,11 @@ var _ ChannelLink = (*channelLink)(nil)
func (l *channelLink) Start() error { func (l *channelLink) Start() error {
if !atomic.CompareAndSwapInt32(&l.started, 0, 1) { if !atomic.CompareAndSwapInt32(&l.started, 0, 1) {
err := errors.Errorf("channel link(%v): already started", l) err := errors.Errorf("channel link(%v): already started", l)
log.Warn(err) l.log.Warn("already started")
return err return err
} }
log.Infof("ChannelLink(%v) is starting", l) l.log.Info("starting")
// If the config supplied watchtower client, ensure the channel is // If the config supplied watchtower client, ensure the channel is
// registered before trying to use it during operation. // registered before trying to use it during operation.
@ -475,8 +483,7 @@ func (l *channelLink) Start() error {
err := l.cfg.UpdateContractSignals(signals) err := l.cfg.UpdateContractSignals(signals)
if err != nil { if err != nil {
log.Errorf("Unable to update signals for "+ l.log.Errorf("unable to update signals")
"ChannelLink(%v)", l)
} }
}() }()
} }
@ -495,11 +502,11 @@ func (l *channelLink) Start() error {
// NOTE: Part of the ChannelLink interface. // NOTE: Part of the ChannelLink interface.
func (l *channelLink) Stop() { func (l *channelLink) Stop() {
if !atomic.CompareAndSwapInt32(&l.shutdown, 0, 1) { if !atomic.CompareAndSwapInt32(&l.shutdown, 0, 1) {
log.Warnf("channel link(%v): already stopped", l) l.log.Warn("already stopped")
return return
} }
log.Infof("ChannelLink(%v) is stopping", l) l.log.Info("stopping")
// As the link is stopping, we are no longer interested in hodl events // As the link is stopping, we are no longer interested in hodl events
// coming from the invoice registry. // coming from the invoice registry.
@ -524,7 +531,7 @@ func (l *channelLink) Stop() {
// we had learned them at some point. // we had learned them at some point.
err := l.cfg.PreimageCache.AddPreimages(l.uncommittedPreimages...) err := l.cfg.PreimageCache.AddPreimages(l.uncommittedPreimages...)
if err != nil { if err != nil {
log.Errorf("Unable to add preimages=%v to cache: %v", l.log.Errorf("unable to add preimages=%v to cache: %v",
l.uncommittedPreimages, err) l.uncommittedPreimages, err)
} }
} }
@ -571,8 +578,8 @@ func (l *channelLink) sampleNetworkFee() (lnwallet.SatPerKWeight, error) {
return 0, err return 0, err
} }
log.Debugf("ChannelLink(%v): sampled fee rate for 3 block conf: %v "+ l.log.Debugf("sampled fee rate for 3 block conf: %v sat/kw",
"sat/kw", l, int64(feePerKw)) int64(feePerKw))
return feePerKw, nil return feePerKw, nil
} }
@ -603,8 +610,7 @@ func shouldAdjustCommitFee(netFee, chanFee lnwallet.SatPerKWeight) bool {
// flow. We'll compare out commitment chains with the remote party, and re-send // flow. We'll compare out commitment chains with the remote party, and re-send
// either a danging commit signature, a revocation, or both. // either a danging commit signature, a revocation, or both.
func (l *channelLink) syncChanStates() error { func (l *channelLink) syncChanStates() error {
log.Infof("Attempting to re-resynchronize ChannelPoint(%v)", l.log.Info("attempting to re-resynchronize")
l.channel.ChannelPoint())
// First, we'll generate our ChanSync message to send to the other // First, we'll generate our ChanSync message to send to the other
// side. Based on this message, the remote party will decide if they // side. Based on this message, the remote party will decide if they
@ -643,9 +649,7 @@ func (l *channelLink) syncChanStates() error {
localChanSyncMsg.NextLocalCommitHeight == 1 && localChanSyncMsg.NextLocalCommitHeight == 1 &&
!l.channel.IsPending() { !l.channel.IsPending() {
log.Infof("ChannelPoint(%v): resending "+ l.log.Infof("resending FundingLocked message to peer")
"FundingLocked message to peer",
l.channel.ChannelPoint())
nextRevocation, err := l.channel.NextRevocationKey() nextRevocation, err := l.channel.NextRevocationKey()
if err != nil { if err != nil {
@ -664,8 +668,7 @@ func (l *channelLink) syncChanStates() error {
} }
// In any case, we'll then process their ChanSync message. // In any case, we'll then process their ChanSync message.
log.Infof("Received re-establishment message from remote side "+ l.log.Info("received re-establishment message from remote side")
"for channel(%v)", l.channel.ChannelPoint())
var ( var (
openedCircuits []CircuitKey openedCircuits []CircuitKey
@ -694,9 +697,8 @@ func (l *channelLink) syncChanStates() error {
} }
if len(msgsToReSend) > 0 { if len(msgsToReSend) > 0 {
log.Infof("Sending %v updates to synchronize the "+ l.log.Infof("sending %v updates to synchronize the "+
"state for ChannelPoint(%v)", len(msgsToReSend), "state", len(msgsToReSend))
l.channel.ChannelPoint())
} }
// If we have any messages to retransmit, we'll do so // If we have any messages to retransmit, we'll do so
@ -724,7 +726,7 @@ func (l *channelLink) resolveFwdPkgs() error {
return err return err
} }
l.debugf("loaded %d fwd pks", len(fwdPkgs)) l.log.Debugf("loaded %d fwd pks", len(fwdPkgs))
var needUpdate bool var needUpdate bool
for _, fwdPkg := range fwdPkgs { for _, fwdPkg := range fwdPkgs {
@ -751,13 +753,13 @@ func (l *channelLink) resolveFwdPkgs() error {
func (l *channelLink) resolveFwdPkg(fwdPkg *channeldb.FwdPkg) (bool, error) { func (l *channelLink) resolveFwdPkg(fwdPkg *channeldb.FwdPkg) (bool, error) {
// Remove any completed packages to clear up space. // Remove any completed packages to clear up space.
if fwdPkg.State == channeldb.FwdStateCompleted { if fwdPkg.State == channeldb.FwdStateCompleted {
l.debugf("removing completed fwd pkg for height=%d", l.log.Debugf("removing completed fwd pkg for height=%d",
fwdPkg.Height) fwdPkg.Height)
err := l.channel.RemoveFwdPkg(fwdPkg.Height) err := l.channel.RemoveFwdPkg(fwdPkg.Height)
if err != nil { if err != nil {
l.errorf("unable to remove fwd pkg for height=%d: %v", l.log.Errorf("unable to remove fwd pkg for height=%d: "+
fwdPkg.Height, err) "%v", fwdPkg.Height, err)
return false, err return false, err
} }
} }
@ -775,7 +777,7 @@ func (l *channelLink) resolveFwdPkg(fwdPkg *channeldb.FwdPkg) (bool, error) {
fwdPkg.Source, fwdPkg.Height, fwdPkg.SettleFails, fwdPkg.Source, fwdPkg.Height, fwdPkg.SettleFails,
) )
if err != nil { if err != nil {
l.errorf("Unable to process remote log updates: %v", l.log.Errorf("unable to process remote log updates: %v",
err) err)
return false, err return false, err
} }
@ -792,7 +794,7 @@ func (l *channelLink) resolveFwdPkg(fwdPkg *channeldb.FwdPkg) (bool, error) {
fwdPkg.Source, fwdPkg.Height, fwdPkg.Adds, fwdPkg.Source, fwdPkg.Height, fwdPkg.Adds,
) )
if err != nil { if err != nil {
l.errorf("Unable to process remote log updates: %v", l.log.Errorf("unable to process remote log updates: %v",
err) err)
return false, err return false, err
} }
@ -827,7 +829,8 @@ func (l *channelLink) fwdPkgGarbager() {
case <-l.cfg.FwdPkgGCTicker.Ticks(): case <-l.cfg.FwdPkgGCTicker.Ticks():
fwdPkgs, err := l.channel.LoadFwdPkgs() fwdPkgs, err := l.channel.LoadFwdPkgs()
if err != nil { if err != nil {
l.warnf("unable to load fwdpkgs for gc: %v", err) l.log.Warnf("unable to load fwdpkgs for gc: %v",
err)
continue continue
} }
@ -839,7 +842,7 @@ func (l *channelLink) fwdPkgGarbager() {
err = l.channel.RemoveFwdPkg(fwdPkg.Height) err = l.channel.RemoveFwdPkg(fwdPkg.Height)
if err != nil { if err != nil {
l.warnf("unable to remove fwd pkg "+ l.log.Warnf("unable to remove fwd pkg "+
"for height=%d: %v", "for height=%d: %v",
fwdPkg.Height, err) fwdPkg.Height, err)
} }
@ -864,11 +867,10 @@ func (l *channelLink) htlcManager() {
defer func() { defer func() {
l.cfg.BatchTicker.Stop() l.cfg.BatchTicker.Stop()
l.wg.Done() l.wg.Done()
log.Infof("ChannelLink(%v) has exited", l) l.log.Infof("exited")
}() }()
log.Infof("HTLC manager for ChannelPoint(%v) started, "+ l.log.Infof("HTLC manager started, bandwidth=%v", l.Bandwidth())
"bandwidth=%v", l.channel.ChannelPoint(), l.Bandwidth())
// TODO(roasbeef): need to call wipe chan whenever D/C? // TODO(roasbeef): need to call wipe chan whenever D/C?
@ -879,14 +881,14 @@ func (l *channelLink) htlcManager() {
if l.cfg.SyncStates { if l.cfg.SyncStates {
err := l.syncChanStates() err := l.syncChanStates()
if err != nil { if err != nil {
log.Warnf("Error when syncing channel states: %v", err) l.log.Warnf("error when syncing channel states: %v", err)
errDataLoss, localDataLoss := errDataLoss, localDataLoss :=
err.(*lnwallet.ErrCommitSyncLocalDataLoss) err.(*lnwallet.ErrCommitSyncLocalDataLoss)
switch { switch {
case err == ErrLinkShuttingDown: case err == ErrLinkShuttingDown:
log.Debugf("unable to sync channel states, " + l.log.Debugf("unable to sync channel states, " +
"link is shutting down") "link is shutting down")
return return
@ -934,7 +936,7 @@ func (l *channelLink) htlcManager() {
errDataLoss.CommitPoint, errDataLoss.CommitPoint,
) )
if err != nil { if err != nil {
log.Errorf("Unable to mark channel "+ l.log.Errorf("unable to mark channel "+
"data loss: %v", err) "data loss: %v", err)
} }
@ -945,7 +947,7 @@ func (l *channelLink) htlcManager() {
// cases where this error is returned? // cases where this error is returned?
case err == lnwallet.ErrCannotSyncCommitChains: case err == lnwallet.ErrCannotSyncCommitChains:
if err := l.channel.MarkBorked(); err != nil { if err := l.channel.MarkBorked(); err != nil {
log.Errorf("Unable to mark channel "+ l.log.Errorf("unable to mark channel "+
"borked: %v", err) "borked: %v", err)
} }
@ -1008,7 +1010,7 @@ out:
// We must always check if we failed at some point processing // We must always check if we failed at some point processing
// the last update before processing the next. // the last update before processing the next.
if l.failed { if l.failed {
l.errorf("link failed, exiting htlcManager") l.log.Errorf("link failed, exiting htlcManager")
break out break out
} }
@ -1036,7 +1038,8 @@ out:
// blocks. // blocks.
netFee, err := l.sampleNetworkFee() netFee, err := l.sampleNetworkFee()
if err != nil { if err != nil {
log.Errorf("unable to sample network fee: %v", err) l.log.Errorf("unable to sample network fee: %v",
err)
continue continue
} }
@ -1055,7 +1058,8 @@ out:
// If we do, then we'll send a new UpdateFee message to // If we do, then we'll send a new UpdateFee message to
// the remote party, to be locked in with a new update. // the remote party, to be locked in with a new update.
if err := l.updateChannelFee(newCommitFee); err != nil { if err := l.updateChannelFee(newCommitFee); err != nil {
log.Errorf("unable to update fee rate: %v", err) l.log.Errorf("unable to update fee rate: %v",
err)
continue continue
} }
@ -1066,15 +1070,15 @@ out:
// //
// TODO(roasbeef): add force closure? also breach? // TODO(roasbeef): add force closure? also breach?
case <-l.cfg.ChainEvents.RemoteUnilateralClosure: case <-l.cfg.ChainEvents.RemoteUnilateralClosure:
log.Warnf("Remote peer has closed ChannelPoint(%v) on-chain", l.log.Warnf("remote peer has closed on-chain")
l.channel.ChannelPoint())
// TODO(roasbeef): remove all together // TODO(roasbeef): remove all together
go func() { go func() {
chanPoint := l.channel.ChannelPoint() chanPoint := l.channel.ChannelPoint()
err := l.cfg.Peer.WipeChannel(chanPoint) err := l.cfg.Peer.WipeChannel(chanPoint)
if err != nil { if err != nil {
log.Errorf("unable to wipe channel %v", err) l.log.Errorf("unable to wipe channel "+
"%v", err)
} }
}() }()
@ -1121,7 +1125,7 @@ out:
// to continue propagating within the network. // to continue propagating within the network.
case packet := <-l.overflowQueue.outgoingPkts: case packet := <-l.overflowQueue.outgoingPkts:
msg := packet.htlc.(*lnwire.UpdateAddHTLC) msg := packet.htlc.(*lnwire.UpdateAddHTLC)
log.Tracef("Reprocessing downstream add update "+ l.log.Tracef("reprocessing downstream add update "+
"with payment hash(%x)", msg.PaymentHash[:]) "with payment hash(%x)", msg.PaymentHash[:])
l.handleDownStreamPkt(packet, true) l.handleDownStreamPkt(packet, true)
@ -1136,7 +1140,7 @@ out:
// failed, then we'll free up a new slot. // failed, then we'll free up a new slot.
htlc, ok := pkt.htlc.(*lnwire.UpdateAddHTLC) htlc, ok := pkt.htlc.(*lnwire.UpdateAddHTLC)
if ok && l.overflowQueue.Length() != 0 { if ok && l.overflowQueue.Length() != 0 {
log.Infof("Downstream htlc add update with "+ l.log.Infof("downstream htlc add update with "+
"payment hash(%x) have been added to "+ "payment hash(%x) have been added to "+
"reprocessing queue, batch_size=%v", "reprocessing queue, batch_size=%v",
htlc.PaymentHash[:], htlc.PaymentHash[:],
@ -1224,7 +1228,7 @@ func (l *channelLink) processHodlEvent(hodlEvent invoices.HodlEvent,
// Determine required action for the resolution. // Determine required action for the resolution.
if hodlEvent.Preimage != nil { if hodlEvent.Preimage != nil {
l.debugf("Received hodl settle event for %v", circuitKey) l.log.Debugf("received hodl settle event for %v", circuitKey)
return l.settleHTLC( return l.settleHTLC(
*hodlEvent.Preimage, htlc.pd.HtlcIndex, *hodlEvent.Preimage, htlc.pd.HtlcIndex,
@ -1232,7 +1236,7 @@ func (l *channelLink) processHodlEvent(hodlEvent invoices.HodlEvent,
) )
} }
l.debugf("Received hodl cancel event for %v", circuitKey) l.log.Debugf("received hodl cancel event for %v", circuitKey)
// In case of a cancel, always return // In case of a cancel, always return
// incorrect_or_unknown_payment_details in order to avoid leaking info. // incorrect_or_unknown_payment_details in order to avoid leaking info.
@ -1270,7 +1274,7 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
// arbitrary delays between the switch adding an ADD to the // arbitrary delays between the switch adding an ADD to the
// mailbox, and the HTLC being added to the commitment state. // mailbox, and the HTLC being added to the commitment state.
if l.cfg.HodlMask.Active(hodl.AddOutgoing) { if l.cfg.HodlMask.Active(hodl.AddOutgoing) {
l.warnf(hodl.AddOutgoing.Warning()) l.log.Warnf(hodl.AddOutgoing.Warning())
l.mailBox.AckPacket(pkt.inKey()) l.mailBox.AckPacket(pkt.inKey())
return return
} }
@ -1287,7 +1291,7 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
// The channels spare bandwidth is fully allocated, so // The channels spare bandwidth is fully allocated, so
// we'll put this HTLC into the overflow queue. // we'll put this HTLC into the overflow queue.
case lnwallet.ErrMaxHTLCNumber: case lnwallet.ErrMaxHTLCNumber:
l.infof("Downstream htlc add update with "+ l.log.Infof("downstream htlc add update with "+
"payment hash(%x) have been added to "+ "payment hash(%x) have been added to "+
"reprocessing queue, batch: %v", "reprocessing queue, batch: %v",
htlc.PaymentHash[:], htlc.PaymentHash[:],
@ -1300,7 +1304,8 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
// machine, as a result, we'll signal the switch to // machine, as a result, we'll signal the switch to
// cancel the pending payment. // cancel the pending payment.
default: default:
l.warnf("Unable to handle downstream add HTLC: %v", err) l.log.Warnf("unable to handle downstream add "+
"HTLC: %v", err)
var ( var (
localFailure = false localFailure = false
@ -1325,7 +1330,7 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
var b bytes.Buffer var b bytes.Buffer
err := lnwire.EncodeFailure(&b, failure, 0) err := lnwire.EncodeFailure(&b, failure, 0)
if err != nil { if err != nil {
l.errorf("unable to encode failure: %v", err) l.log.Errorf("unable to encode failure: %v", err)
l.mailBox.AckPacket(pkt.inKey()) l.mailBox.AckPacket(pkt.inKey())
return return
} }
@ -1335,7 +1340,7 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
var err error var err error
reason, err = pkt.obfuscator.EncryptFirstHop(failure) reason, err = pkt.obfuscator.EncryptFirstHop(failure)
if err != nil { if err != nil {
l.errorf("unable to obfuscate error: %v", err) l.log.Errorf("unable to obfuscate error: %v", err)
l.mailBox.AckPacket(pkt.inKey()) l.mailBox.AckPacket(pkt.inKey())
return return
} }
@ -1370,7 +1375,7 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
} }
} }
l.tracef("Received downstream htlc: payment_hash=%x, "+ l.log.Tracef("received downstream htlc: payment_hash=%x, "+
"local_log_index=%v, batch_size=%v", "local_log_index=%v, batch_size=%v",
htlc.PaymentHash[:], index, l.batchCounter+1) htlc.PaymentHash[:], index, l.batchCounter+1)
@ -1378,7 +1383,7 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
pkt.outgoingHTLCID = index pkt.outgoingHTLCID = index
htlc.ID = index htlc.ID = index
l.debugf("Queueing keystone of ADD open circuit: %s->%s", l.log.Debugf("queueing keystone of ADD open circuit: %s->%s",
pkt.inKey(), pkt.outKey()) pkt.inKey(), pkt.outKey())
l.openedCircuits = append(l.openedCircuits, pkt.inKey()) l.openedCircuits = append(l.openedCircuits, pkt.inKey())
@ -1392,7 +1397,7 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
// SETTLE to the mailbox, and the HTLC being added to the // SETTLE to the mailbox, and the HTLC being added to the
// commitment state. // commitment state.
if l.cfg.HodlMask.Active(hodl.SettleOutgoing) { if l.cfg.HodlMask.Active(hodl.SettleOutgoing) {
l.warnf(hodl.SettleOutgoing.Warning()) l.log.Warnf(hodl.SettleOutgoing.Warning())
l.mailBox.AckPacket(pkt.inKey()) l.mailBox.AckPacket(pkt.inKey())
return return
} }
@ -1409,7 +1414,7 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
&inKey, &inKey,
) )
if err != nil { if err != nil {
l.errorf("unable to settle incoming HTLC for "+ l.log.Errorf("unable to settle incoming HTLC for "+
"circuit-key=%v: %v", inKey, err) "circuit-key=%v: %v", inKey, err)
// If the HTLC index for Settle response was not known // If the HTLC index for Settle response was not known
@ -1428,8 +1433,8 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
return return
} }
l.debugf("Queueing removal of SETTLE closed circuit: %s->%s", l.log.Debugf("queueing removal of SETTLE closed circuit: "+
pkt.inKey(), pkt.outKey()) "%s->%s", pkt.inKey(), pkt.outKey())
l.closedCircuits = append(l.closedCircuits, pkt.inKey()) l.closedCircuits = append(l.closedCircuits, pkt.inKey())
@ -1450,7 +1455,7 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
// the mailbox, and the HTLC being added to the commitment // the mailbox, and the HTLC being added to the commitment
// state. // state.
if l.cfg.HodlMask.Active(hodl.FailOutgoing) { if l.cfg.HodlMask.Active(hodl.FailOutgoing) {
l.warnf(hodl.FailOutgoing.Warning()) l.log.Warnf(hodl.FailOutgoing.Warning())
l.mailBox.AckPacket(pkt.inKey()) l.mailBox.AckPacket(pkt.inKey())
return return
} }
@ -1466,7 +1471,7 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
&inKey, &inKey,
) )
if err != nil { if err != nil {
l.errorf("unable to cancel incoming HTLC for "+ l.log.Errorf("unable to cancel incoming HTLC for "+
"circuit-key=%v: %v", inKey, err) "circuit-key=%v: %v", inKey, err)
// If the HTLC index for Fail response was not known to // If the HTLC index for Fail response was not known to
@ -1485,7 +1490,7 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
return return
} }
l.debugf("Queueing removal of FAIL closed circuit: %s->%s", l.log.Debugf("queueing removal of FAIL closed circuit: %s->%s",
pkt.inKey(), pkt.outKey()) pkt.inKey(), pkt.outKey())
l.closedCircuits = append(l.closedCircuits, pkt.inKey()) l.closedCircuits = append(l.closedCircuits, pkt.inKey())
@ -1523,13 +1528,13 @@ func (l *channelLink) handleDownStreamPkt(pkt *htlcPacket, isReProcess bool) {
func (l *channelLink) cleanupSpuriousResponse(pkt *htlcPacket) { func (l *channelLink) cleanupSpuriousResponse(pkt *htlcPacket) {
inKey := pkt.inKey() inKey := pkt.inKey()
l.debugf("Cleaning up spurious response for incoming circuit-key=%v", l.log.Debugf("cleaning up spurious response for incoming "+
inKey) "circuit-key=%v", inKey)
// If the htlc packet doesn't have a source reference, it is unsafe to // If the htlc packet doesn't have a source reference, it is unsafe to
// proceed, as skipping this ack may cause the htlc to be reforwarded. // proceed, as skipping this ack may cause the htlc to be reforwarded.
if pkt.sourceRef == nil { if pkt.sourceRef == nil {
l.errorf("uanble to cleanup response for incoming "+ l.log.Errorf("uanble to cleanup response for incoming "+
"circuit-key=%v, does not contain source reference", "circuit-key=%v, does not contain source reference",
inKey) inKey)
return return
@ -1540,7 +1545,7 @@ func (l *channelLink) cleanupSpuriousResponse(pkt *htlcPacket) {
// of the incoming HTLC belonging to this link. // of the incoming HTLC belonging to this link.
err := l.channel.AckAddHtlcs(*pkt.sourceRef) err := l.channel.AckAddHtlcs(*pkt.sourceRef)
if err != nil { if err != nil {
l.errorf("unable to ack AddRef for incoming "+ l.log.Errorf("unable to ack AddRef for incoming "+
"circuit-key=%v: %v", inKey, err) "circuit-key=%v: %v", inKey, err)
// If this operation failed, it is unsafe to attempt removal of // If this operation failed, it is unsafe to attempt removal of
@ -1563,19 +1568,19 @@ func (l *channelLink) cleanupSpuriousResponse(pkt *htlcPacket) {
if pkt.destRef != nil { if pkt.destRef != nil {
err := l.channel.AckSettleFails(*pkt.destRef) err := l.channel.AckSettleFails(*pkt.destRef)
if err != nil { if err != nil {
l.errorf("unable to ack SettleFailRef "+ l.log.Errorf("unable to ack SettleFailRef "+
"for incoming circuit-key=%v: %v", "for incoming circuit-key=%v: %v",
inKey, err) inKey, err)
} }
} }
l.debugf("Deleting circuit for incoming circuit-key=%x", inKey) l.log.Debugf("deleting circuit for incoming circuit-key=%x", inKey)
// With all known references acked, we can now safely delete the circuit // With all known references acked, we can now safely delete the circuit
// from the switch's circuit map, as the state is no longer needed. // from the switch's circuit map, as the state is no longer needed.
err = l.cfg.Circuits.DeleteCircuits(inKey) err = l.cfg.Circuits.DeleteCircuits(inKey)
if err != nil { if err != nil {
l.errorf("unable to delete circuit for "+ l.log.Errorf("unable to delete circuit for "+
"circuit-key=%v: %v", inKey, err) "circuit-key=%v: %v", inKey, err)
} }
} }
@ -1597,7 +1602,7 @@ func (l *channelLink) handleUpstreamMsg(msg lnwire.Message) {
return return
} }
l.tracef("Receive upstream htlc with payment hash(%x), "+ l.log.Tracef("receive upstream htlc with payment hash(%x), "+
"assigning index: %v", msg.PaymentHash[:], index) "assigning index: %v", msg.PaymentHash[:], index)
case *lnwire.UpdateFulfillHTLC: case *lnwire.UpdateFulfillHTLC:
@ -1650,7 +1655,7 @@ func (l *channelLink) handleUpstreamMsg(msg lnwire.Message) {
OnionSHA256: msg.ShaOnionBlob, OnionSHA256: msg.ShaOnionBlob,
} }
default: default:
log.Warnf("Unexpected failure code received in "+ l.log.Warnf("unexpected failure code received in "+
"UpdateFailMailformedHTLC: %v", msg.FailureCode) "UpdateFailMailformedHTLC: %v", msg.FailureCode)
// We don't just pass back the error we received from // We don't just pass back the error we received from
@ -1671,7 +1676,7 @@ func (l *channelLink) handleUpstreamMsg(msg lnwire.Message) {
// form. // form.
var b bytes.Buffer var b bytes.Buffer
if err := lnwire.EncodeFailure(&b, failure, 0); err != nil { if err := lnwire.EncodeFailure(&b, failure, 0); err != nil {
l.errorf("unable to encode malformed error: %v", err) l.log.Errorf("unable to encode malformed error: %v", err)
return return
} }
@ -1758,7 +1763,7 @@ func (l *channelLink) handleUpstreamMsg(msg lnwire.Message) {
// state. // state.
nextRevocation, currentHtlcs, err := l.channel.RevokeCurrentCommitment() nextRevocation, currentHtlcs, err := l.channel.RevokeCurrentCommitment()
if err != nil { if err != nil {
log.Errorf("unable to revoke commitment: %v", err) l.log.Errorf("unable to revoke commitment: %v", err)
return return
} }
l.cfg.Peer.SendMessage(false, nextRevocation) l.cfg.Peer.SendMessage(false, nextRevocation)
@ -1894,8 +1899,7 @@ func (l *channelLink) handleUpstreamMsg(msg lnwire.Message) {
"ChannelPoint(%v): received error from peer: %v", "ChannelPoint(%v): received error from peer: %v",
l.channel.ChannelPoint(), msg.Error()) l.channel.ChannelPoint(), msg.Error())
default: default:
log.Warnf("ChannelPoint(%v): received unknown message of type %T", l.log.Warnf("received unknown message of type %T", msg)
l.channel.ChannelPoint(), msg)
} }
} }
@ -1919,7 +1923,7 @@ func (l *channelLink) ackDownStreamPackets() error {
continue continue
} }
l.debugf("removing Add packet %s from mailbox", inKey) l.log.Debugf("removing Add packet %s from mailbox", inKey)
l.mailBox.AckPacket(inKey) l.mailBox.AckPacket(inKey)
} }
@ -1933,7 +1937,7 @@ func (l *channelLink) ackDownStreamPackets() error {
// Successful deletion. // Successful deletion.
default: default:
l.errorf("unable to delete %d circuits: %v", l.log.Errorf("unable to delete %d circuits: %v",
len(l.closedCircuits), err) len(l.closedCircuits), err)
return err return err
} }
@ -1944,7 +1948,8 @@ func (l *channelLink) ackDownStreamPackets() error {
// the circuits must have been removed at some point, so it is now safe // the circuits must have been removed at some point, so it is now safe
// to un-queue the corresponding Settle/Fails. // to un-queue the corresponding Settle/Fails.
for _, inKey := range l.closedCircuits { for _, inKey := range l.closedCircuits {
l.debugf("removing Fail/Settle packet %s from mailbox", inKey) l.log.Debugf("removing Fail/Settle packet %s from mailbox",
inKey)
l.mailBox.AckPacket(inKey) l.mailBox.AckPacket(inKey)
} }
@ -1976,14 +1981,14 @@ func (l *channelLink) updateCommitTx() error {
// permits testing of either the switch or link's ability to trim // permits testing of either the switch or link's ability to trim
// circuits that have been opened, but unsuccessfully committed. // circuits that have been opened, but unsuccessfully committed.
if l.cfg.HodlMask.Active(hodl.Commit) { if l.cfg.HodlMask.Active(hodl.Commit) {
l.warnf(hodl.Commit.Warning()) l.log.Warnf(hodl.Commit.Warning())
return nil return nil
} }
theirCommitSig, htlcSigs, pendingHTLCs, err := l.channel.SignNextCommitment() theirCommitSig, htlcSigs, pendingHTLCs, err := l.channel.SignNextCommitment()
if err == lnwallet.ErrNoWindow { if err == lnwallet.ErrNoWindow {
l.tracef("revocation window exhausted, unable to send: %v, "+ l.log.Tracef("revocation window exhausted, unable to send: "+
"dangling_opens=%v, dangling_closes%v", "%v, dangling_opens=%v, dangling_closes%v",
l.batchCounter, newLogClosure(func() string { l.batchCounter, newLogClosure(func() string {
return spew.Sdump(l.openedCircuits) return spew.Sdump(l.openedCircuits)
}), }),
@ -2077,14 +2082,14 @@ func (l *channelLink) UpdateShortChanID() (lnwire.ShortChannelID, error) {
// short channel ID. // short channel ID.
err := l.channel.State().RefreshShortChanID() err := l.channel.State().RefreshShortChanID()
if err != nil { if err != nil {
l.errorf("unable to refresh short_chan_id for chan_id=%v: %v", l.log.Errorf("unable to refresh short_chan_id for chan_id=%v: "+
chanID, err) "%v", chanID, err)
return hop.Source, err return hop.Source, err
} }
sid := l.channel.ShortChanID() sid := l.channel.ShortChanID()
l.infof("Updating to short_chan_id=%v for chan_id=%v", sid, chanID) l.log.Infof("updating to short_chan_id=%v for chan_id=%v", sid, chanID)
l.Lock() l.Lock()
l.shortChanID = sid l.shortChanID = sid
@ -2096,8 +2101,7 @@ func (l *channelLink) UpdateShortChanID() (lnwire.ShortChannelID, error) {
ShortChanID: sid, ShortChanID: sid,
}) })
if err != nil { if err != nil {
log.Errorf("Unable to update signals for "+ l.log.Errorf("unable to update signals")
"ChannelLink(%v)", l)
} }
}() }()
@ -2206,8 +2210,9 @@ func (l *channelLink) HtlcSatifiesPolicy(payHash [32]byte,
// any case, we'll cancel this HTLC. // any case, we'll cancel this HTLC.
actualFee := incomingHtlcAmt - amtToForward actualFee := incomingHtlcAmt - amtToForward
if incomingHtlcAmt < amtToForward || actualFee < expectedFee { if incomingHtlcAmt < amtToForward || actualFee < expectedFee {
l.errorf("outgoing htlc(%x) has insufficient fee: expected %v, "+ l.log.Errorf("outgoing htlc(%x) has insufficient fee: "+
"got %v", payHash[:], int64(expectedFee), int64(actualFee)) "expected %v, got %v",
payHash[:], int64(expectedFee), int64(actualFee))
// As part of the returned error, we'll send our latest routing // As part of the returned error, we'll send our latest routing
// policy so the sending node obtains the most up to date data. // policy so the sending node obtains the most up to date data.
@ -2230,7 +2235,7 @@ func (l *channelLink) HtlcSatifiesPolicy(payHash [32]byte,
// sender messed up, or an intermediate node tampered with the HTLC. // sender messed up, or an intermediate node tampered with the HTLC.
timeDelta := policy.TimeLockDelta timeDelta := policy.TimeLockDelta
if incomingTimeout < outgoingTimeout+timeDelta { if incomingTimeout < outgoingTimeout+timeDelta {
l.errorf("Incoming htlc(%x) has incorrect time-lock value: "+ l.log.Errorf("incoming htlc(%x) has incorrect time-lock value: "+
"expected at least %v block delta, got %v block delta", "expected at least %v block delta, got %v block delta",
payHash[:], timeDelta, incomingTimeout-outgoingTimeout) payHash[:], timeDelta, incomingTimeout-outgoingTimeout)
@ -2282,7 +2287,7 @@ func (l *channelLink) htlcSatifiesPolicyOutgoing(policy ForwardingPolicy,
// too small for the next hop. If so, then we'll cancel the HTLC // too small for the next hop. If so, then we'll cancel the HTLC
// directly. // directly.
if amt < policy.MinHTLC { if amt < policy.MinHTLC {
l.errorf("outgoing htlc(%x) is too small: min_htlc=%v, "+ l.log.Errorf("outgoing htlc(%x) is too small: min_htlc=%v, "+
"htlc_value=%v", payHash[:], policy.MinHTLC, "htlc_value=%v", payHash[:], policy.MinHTLC,
amt) amt)
@ -2304,7 +2309,7 @@ func (l *channelLink) htlcSatifiesPolicyOutgoing(policy ForwardingPolicy,
// Next, ensure that the passed HTLC isn't too large. If so, we'll cancel // Next, ensure that the passed HTLC isn't too large. If so, we'll cancel
// the HTLC directly. // the HTLC directly.
if policy.MaxHTLC != 0 && amt > policy.MaxHTLC { if policy.MaxHTLC != 0 && amt > policy.MaxHTLC {
l.errorf("outgoing htlc(%x) is too large: max_htlc=%v, "+ l.log.Errorf("outgoing htlc(%x) is too large: max_htlc=%v, "+
"htlc_value=%v", payHash[:], policy.MaxHTLC, amt) "htlc_value=%v", payHash[:], policy.MaxHTLC, amt)
// As part of the returned error, we'll send our latest routing policy // As part of the returned error, we'll send our latest routing policy
@ -2324,7 +2329,7 @@ func (l *channelLink) htlcSatifiesPolicyOutgoing(policy ForwardingPolicy,
// future, so we'll reject an HTLC if the outgoing expiration time is // future, so we'll reject an HTLC if the outgoing expiration time is
// too close to the current height. // too close to the current height.
if timeout <= heightNow+l.cfg.OutgoingCltvRejectDelta { if timeout <= heightNow+l.cfg.OutgoingCltvRejectDelta {
l.errorf("htlc(%x) has an expiry that's too soon: "+ l.log.Errorf("htlc(%x) has an expiry that's too soon: "+
"outgoing_expiry=%v, best_height=%v", payHash[:], "outgoing_expiry=%v, best_height=%v", payHash[:],
timeout, heightNow) timeout, heightNow)
@ -2343,8 +2348,8 @@ func (l *channelLink) htlcSatifiesPolicyOutgoing(policy ForwardingPolicy,
// Check absolute max delta. // Check absolute max delta.
if timeout > l.cfg.MaxOutgoingCltvExpiry+heightNow { if timeout > l.cfg.MaxOutgoingCltvExpiry+heightNow {
l.errorf("outgoing htlc(%x) has a time lock too far in the "+ l.log.Errorf("outgoing htlc(%x) has a time lock too far in "+
"future: got %v, but maximum is %v", payHash[:], "the future: got %v, but maximum is %v", payHash[:],
timeout-heightNow, l.cfg.MaxOutgoingCltvExpiry) timeout-heightNow, l.cfg.MaxOutgoingCltvExpiry)
return &lnwire.FailExpiryTooFar{} return &lnwire.FailExpiryTooFar{}
@ -2377,7 +2382,7 @@ func (l *channelLink) String() string {
// //
// NOTE: Part of the ChannelLink interface. // NOTE: Part of the ChannelLink interface.
func (l *channelLink) HandleSwitchPacket(pkt *htlcPacket) error { func (l *channelLink) HandleSwitchPacket(pkt *htlcPacket) error {
l.tracef("received switch packet inkey=%v, outkey=%v", l.log.Tracef("received switch packet inkey=%v, outkey=%v",
pkt.inKey(), pkt.outKey()) pkt.inKey(), pkt.outKey())
l.mailBox.AddPacket(pkt) l.mailBox.AddPacket(pkt)
@ -2396,14 +2401,12 @@ func (l *channelLink) HandleChannelUpdate(message lnwire.Message) {
// committing to an update_fee message. // committing to an update_fee message.
func (l *channelLink) updateChannelFee(feePerKw lnwallet.SatPerKWeight) error { func (l *channelLink) updateChannelFee(feePerKw lnwallet.SatPerKWeight) error {
log.Infof("ChannelPoint(%v): updating commit fee to %v sat/kw", l, l.log.Infof("updating commit fee to %v sat/kw", feePerKw)
feePerKw)
// We skip sending the UpdateFee message if the channel is not // We skip sending the UpdateFee message if the channel is not
// currently eligible to forward messages. // currently eligible to forward messages.
if !l.EligibleToForward() { if !l.EligibleToForward() {
log.Debugf("ChannelPoint(%v): skipping fee update for "+ l.log.Debugf("skipping fee update for inactive channel")
"inactive channel", l.ChanID())
return nil return nil
} }
@ -2433,8 +2436,7 @@ func (l *channelLink) processRemoteSettleFails(fwdPkg *channeldb.FwdPkg,
return return
} }
log.Debugf("ChannelLink(%v): settle-fail-filter %v", l.log.Debugf("settle-fail-filter %v", fwdPkg.SettleFailFilter)
l.ShortChanID(), fwdPkg.SettleFailFilter)
var switchPackets []*htlcPacket var switchPackets []*htlcPacket
for i, pd := range settleFails { for i, pd := range settleFails {
@ -2458,7 +2460,7 @@ func (l *channelLink) processRemoteSettleFails(fwdPkg *channeldb.FwdPkg,
// forward the SETTLE to the switch and will not signal // forward the SETTLE to the switch and will not signal
// a free slot on the commitment transaction. // a free slot on the commitment transaction.
if l.cfg.HodlMask.Active(hodl.SettleIncoming) { if l.cfg.HodlMask.Active(hodl.SettleIncoming) {
l.warnf(hodl.SettleIncoming.Warning()) l.log.Warnf(hodl.SettleIncoming.Warning())
continue continue
} }
@ -2486,7 +2488,7 @@ func (l *channelLink) processRemoteSettleFails(fwdPkg *channeldb.FwdPkg,
// forward the FAIL to the switch and will not signal a // forward the FAIL to the switch and will not signal a
// free slot on the commitment transaction. // free slot on the commitment transaction.
if l.cfg.HodlMask.Active(hodl.FailIncoming) { if l.cfg.HodlMask.Active(hodl.FailIncoming) {
l.warnf(hodl.FailIncoming.Warning()) l.log.Warnf(hodl.FailIncoming.Warning())
continue continue
} }
@ -2538,7 +2540,7 @@ func (l *channelLink) processRemoteSettleFails(fwdPkg *channeldb.FwdPkg,
func (l *channelLink) processRemoteAdds(fwdPkg *channeldb.FwdPkg, func (l *channelLink) processRemoteAdds(fwdPkg *channeldb.FwdPkg,
lockedInHtlcs []*lnwallet.PaymentDescriptor) bool { lockedInHtlcs []*lnwallet.PaymentDescriptor) bool {
l.tracef("processing %d remote adds for height %d", l.log.Tracef("processing %d remote adds for height %d",
len(lockedInHtlcs), fwdPkg.Height) len(lockedInHtlcs), fwdPkg.Height)
decodeReqs := make( decodeReqs := make(
@ -2620,7 +2622,7 @@ func (l *channelLink) processRemoteAdds(fwdPkg *channeldb.FwdPkg,
onionBlob[:], pd.SourceRef) onionBlob[:], pd.SourceRef)
needUpdate = true needUpdate = true
log.Errorf("unable to decode onion hop "+ l.log.Errorf("unable to decode onion hop "+
"iterator: %v", failureCode) "iterator: %v", failureCode)
continue continue
} }
@ -2639,7 +2641,7 @@ func (l *channelLink) processRemoteAdds(fwdPkg *channeldb.FwdPkg,
) )
needUpdate = true needUpdate = true
log.Errorf("unable to decode onion "+ l.log.Errorf("unable to decode onion "+
"obfuscator: %v", failureCode) "obfuscator: %v", failureCode)
continue continue
} }
@ -2659,7 +2661,7 @@ func (l *channelLink) processRemoteAdds(fwdPkg *channeldb.FwdPkg,
) )
needUpdate = true needUpdate = true
log.Errorf("Unable to decode forwarding "+ l.log.Errorf("unable to decode forwarding "+
"instructions: %v", err) "instructions: %v", err)
continue continue
} }
@ -2688,7 +2690,7 @@ func (l *channelLink) processRemoteAdds(fwdPkg *channeldb.FwdPkg,
// validate the forwarded ADD, nor will we send the // validate the forwarded ADD, nor will we send the
// packet to the htlc switch. // packet to the htlc switch.
if l.cfg.HodlMask.Active(hodl.AddIncoming) { if l.cfg.HodlMask.Active(hodl.AddIncoming) {
l.warnf(hodl.AddIncoming.Warning()) l.log.Warnf(hodl.AddIncoming.Warning())
continue continue
} }
@ -2759,7 +2761,7 @@ func (l *channelLink) processRemoteAdds(fwdPkg *channeldb.FwdPkg,
buf := bytes.NewBuffer(addMsg.OnionBlob[0:0]) buf := bytes.NewBuffer(addMsg.OnionBlob[0:0])
err := chanIterator.EncodeNextHop(buf) err := chanIterator.EncodeNextHop(buf)
if err != nil { if err != nil {
log.Errorf("unable to encode the "+ l.log.Errorf("unable to encode the "+
"remaining route %v", err) "remaining route %v", err)
var failure lnwire.FailureMessage var failure lnwire.FailureMessage
@ -2825,7 +2827,7 @@ func (l *channelLink) processRemoteAdds(fwdPkg *channeldb.FwdPkg,
return needUpdate return needUpdate
} }
l.debugf("forwarding %d packets to switch", len(switchPackets)) l.log.Debugf("forwarding %d packets to switch", len(switchPackets))
// NOTE: This call is made synchronous so that we ensure all circuits // NOTE: This call is made synchronous so that we ensure all circuits
// are committed in the exact order that they are processed in the link. // are committed in the exact order that they are processed in the link.
@ -2847,7 +2849,7 @@ func (l *channelLink) processExitHop(pd *lnwallet.PaymentDescriptor,
// ADD, nor will we settle the corresponding invoice or respond with the // ADD, nor will we settle the corresponding invoice or respond with the
// preimage. // preimage.
if l.cfg.HodlMask.Active(hodl.ExitSettle) { if l.cfg.HodlMask.Active(hodl.ExitSettle) {
l.warnf(hodl.ExitSettle.Warning()) l.log.Warnf(hodl.ExitSettle.Warning())
return false, nil return false, nil
} }
@ -2857,7 +2859,7 @@ func (l *channelLink) processExitHop(pd *lnwallet.PaymentDescriptor,
// matches the HTLC we were extended. // matches the HTLC we were extended.
if pd.Amount != fwdInfo.AmountToForward { if pd.Amount != fwdInfo.AmountToForward {
log.Errorf("Onion payload of incoming htlc(%x) has incorrect "+ l.log.Errorf("onion payload of incoming htlc(%x) has incorrect "+
"value: expected %v, got %v", pd.RHash, "value: expected %v, got %v", pd.RHash,
pd.Amount, fwdInfo.AmountToForward) pd.Amount, fwdInfo.AmountToForward)
@ -2870,7 +2872,7 @@ func (l *channelLink) processExitHop(pd *lnwallet.PaymentDescriptor,
// We'll also ensure that our time-lock value has been computed // We'll also ensure that our time-lock value has been computed
// correctly. // correctly.
if pd.Timeout != fwdInfo.OutgoingCTLV { if pd.Timeout != fwdInfo.OutgoingCTLV {
log.Errorf("Onion payload of incoming htlc(%x) has incorrect "+ l.log.Errorf("onion payload of incoming htlc(%x) has incorrect "+
"time-lock: expected %v, got %v", "time-lock: expected %v, got %v",
pd.RHash[:], pd.Timeout, fwdInfo.OutgoingCTLV) pd.RHash[:], pd.Timeout, fwdInfo.OutgoingCTLV)
@ -2939,7 +2941,7 @@ func (l *channelLink) settleHTLC(preimage lntypes.Preimage, htlcIndex uint64,
hash := preimage.Hash() hash := preimage.Hash()
l.infof("settling htlc %v as exit hop", hash) l.log.Infof("settling htlc %v as exit hop", hash)
err := l.channel.SettleHTLC( err := l.channel.SettleHTLC(
preimage, htlcIndex, sourceRef, nil, nil, preimage, htlcIndex, sourceRef, nil, nil,
@ -2951,7 +2953,7 @@ func (l *channelLink) settleHTLC(preimage lntypes.Preimage, htlcIndex uint64,
// If the link is in hodl.BogusSettle mode, replace the preimage with a // If the link is in hodl.BogusSettle mode, replace the preimage with a
// fake one before sending it to the peer. // fake one before sending it to the peer.
if l.cfg.HodlMask.Active(hodl.BogusSettle) { if l.cfg.HodlMask.Active(hodl.BogusSettle) {
l.warnf(hodl.BogusSettle.Warning()) l.log.Warnf(hodl.BogusSettle.Warning())
preimage = [32]byte{} preimage = [32]byte{}
copy(preimage[:], bytes.Repeat([]byte{2}, 32)) copy(preimage[:], bytes.Repeat([]byte{2}, 32))
} }
@ -3002,7 +3004,7 @@ func (l *channelLink) handleBatchFwdErrs(errChan chan error) {
continue continue
} }
l.errorf("unhandled error while forwarding htlc packet over "+ l.log.Errorf("unhandled error while forwarding htlc packet over "+
"htlcswitch: %v", err) "htlcswitch: %v", err)
} }
} }
@ -3014,13 +3016,13 @@ func (l *channelLink) sendHTLCError(htlcIndex uint64, failure lnwire.FailureMess
reason, err := e.EncryptFirstHop(failure) reason, err := e.EncryptFirstHop(failure)
if err != nil { if err != nil {
log.Errorf("unable to obfuscate error: %v", err) l.log.Errorf("unable to obfuscate error: %v", err)
return return
} }
err = l.channel.FailHTLC(htlcIndex, reason, sourceRef, nil, nil) err = l.channel.FailHTLC(htlcIndex, reason, sourceRef, nil, nil)
if err != nil { if err != nil {
log.Errorf("unable cancel htlc: %v", err) l.log.Errorf("unable cancel htlc: %v", err)
return return
} }
@ -3039,7 +3041,7 @@ func (l *channelLink) sendMalformedHTLCError(htlcIndex uint64,
shaOnionBlob := sha256.Sum256(onionBlob) shaOnionBlob := sha256.Sum256(onionBlob)
err := l.channel.MalformedFailHTLC(htlcIndex, code, shaOnionBlob, sourceRef) err := l.channel.MalformedFailHTLC(htlcIndex, code, shaOnionBlob, sourceRef)
if err != nil { if err != nil {
log.Errorf("unable cancel htlc: %v", err) l.log.Errorf("unable cancel htlc: %v", err)
return return
} }
@ -3062,45 +3064,15 @@ func (l *channelLink) fail(linkErr LinkFailureError,
// Return if we have already notified about a failure. // Return if we have already notified about a failure.
if l.failed { if l.failed {
l.warnf("Ignoring link failure (%v), as link already failed", l.log.Warnf("ignoring link failure (%v), as link already "+
reason) "failed", reason)
return return
} }
l.errorf("Failing link: %s", reason) l.log.Errorf("failing link: %s", reason)
// Set failed, such that we won't process any more updates, and notify // Set failed, such that we won't process any more updates, and notify
// the peer about the failure. // the peer about the failure.
l.failed = true l.failed = true
l.cfg.OnChannelFailure(l.ChanID(), l.ShortChanID(), linkErr) l.cfg.OnChannelFailure(l.ChanID(), l.ShortChanID(), linkErr)
} }
// infof prefixes the channel's identifier before printing to info log.
func (l *channelLink) infof(format string, a ...interface{}) {
msg := fmt.Sprintf(format, a...)
log.Infof("ChannelLink(%s) %s", l.ShortChanID(), msg)
}
// debugf prefixes the channel's identifier before printing to debug log.
func (l *channelLink) debugf(format string, a ...interface{}) {
msg := fmt.Sprintf(format, a...)
log.Debugf("ChannelLink(%s) %s", l.ShortChanID(), msg)
}
// warnf prefixes the channel's identifier before printing to warn log.
func (l *channelLink) warnf(format string, a ...interface{}) {
msg := fmt.Sprintf(format, a...)
log.Warnf("ChannelLink(%s) %s", l.ShortChanID(), msg)
}
// errorf prefixes the channel's identifier before printing to error log.
func (l *channelLink) errorf(format string, a ...interface{}) {
msg := fmt.Sprintf(format, a...)
log.Errorf("ChannelLink(%s) %s", l.ShortChanID(), msg)
}
// tracef prefixes the channel's identifier before printing to trace log.
func (l *channelLink) tracef(format string, a ...interface{}) {
msg := fmt.Sprintf(format, a...)
log.Tracef("ChannelLink(%s) %s", l.ShortChanID(), msg)
}

1
htlcswitch/link_test.go
View File

@ -5417,6 +5417,7 @@ func TestHtlcSatisfyPolicy(t *testing.T) {
FetchLastChannelUpdate: fetchLastChannelUpdate, FetchLastChannelUpdate: fetchLastChannelUpdate,
MaxOutgoingCltvExpiry: DefaultMaxOutgoingCltvExpiry, MaxOutgoingCltvExpiry: DefaultMaxOutgoingCltvExpiry,
}, },
log: log,
} }
var hash [32]byte var hash [32]byte

110
lnwallet/channel.go
View File

@ -14,10 +14,11 @@ import (
"github.com/btcsuite/btcd/chaincfg/chainhash" "github.com/btcsuite/btcd/chaincfg/chainhash"
"github.com/btcsuite/btcd/txscript" "github.com/btcsuite/btcd/txscript"
"github.com/btcsuite/btcd/wire" "github.com/btcsuite/btcd/wire"
"github.com/btcsuite/btclog"
"github.com/btcsuite/btcutil" "github.com/btcsuite/btcutil"
"github.com/btcsuite/btcutil/txsort" "github.com/btcsuite/btcutil/txsort"
"github.com/davecgh/go-spew/spew" "github.com/davecgh/go-spew/spew"
"github.com/lightningnetwork/lnd/build"
"github.com/lightningnetwork/lnd/chainntnfs" "github.com/lightningnetwork/lnd/chainntnfs"
"github.com/lightningnetwork/lnd/channeldb" "github.com/lightningnetwork/lnd/channeldb"
"github.com/lightningnetwork/lnd/input" "github.com/lightningnetwork/lnd/input"
@ -1378,6 +1379,9 @@ type LightningChannel struct {
// channel. // channel.
RemoteFundingKey *btcec.PublicKey RemoteFundingKey *btcec.PublicKey
// log is a channel-specific logging instance.
log btclog.Logger
sync.RWMutex sync.RWMutex
} }
@ -1402,6 +1406,8 @@ func NewLightningChannel(signer input.Signer,
localCommit.RemoteLogIndex, localCommit.RemoteHtlcIndex, localCommit.RemoteLogIndex, localCommit.RemoteHtlcIndex,
) )
logPrefix := fmt.Sprintf("ChannelPoint(%v):", state.FundingOutpoint)
lc := &LightningChannel{ lc := &LightningChannel{
Signer: signer, Signer: signer,
sigPool: sigPool, sigPool: sigPool,
@ -1417,6 +1423,7 @@ func NewLightningChannel(signer input.Signer,
Capacity: state.Capacity, Capacity: state.Capacity,
LocalFundingKey: state.LocalChanCfg.MultiSigKey.PubKey, LocalFundingKey: state.LocalChanCfg.MultiSigKey.PubKey,
RemoteFundingKey: state.RemoteChanCfg.MultiSigKey.PubKey, RemoteFundingKey: state.RemoteChanCfg.MultiSigKey.PubKey,
log: build.NewPrefixLog(logPrefix, walletLog),
} }
// With the main channel struct reconstructed, we'll now restore the // With the main channel struct reconstructed, we'll now restore the
@ -1652,8 +1659,8 @@ func (lc *LightningChannel) restoreCommitState(
} }
lc.localCommitChain.addCommitment(localCommit) lc.localCommitChain.addCommitment(localCommit)
walletLog.Debugf("ChannelPoint(%v), starting local commitment: %v", lc.log.Debugf("starting local commitment: %v",
lc.channelState.FundingOutpoint, newLogClosure(func() string { newLogClosure(func() string {
return spew.Sdump(lc.localCommitChain.tail()) return spew.Sdump(lc.localCommitChain.tail())
}), }),
) )
@ -1668,8 +1675,8 @@ func (lc *LightningChannel) restoreCommitState(
} }
lc.remoteCommitChain.addCommitment(remoteCommit) lc.remoteCommitChain.addCommitment(remoteCommit)
walletLog.Debugf("ChannelPoint(%v), starting remote commitment: %v", lc.log.Debugf("starting remote commitment: %v",
lc.channelState.FundingOutpoint, newLogClosure(func() string { newLogClosure(func() string {
return spew.Sdump(lc.remoteCommitChain.tail()) return spew.Sdump(lc.remoteCommitChain.tail())
}), }),
) )
@ -1703,8 +1710,7 @@ func (lc *LightningChannel) restoreCommitState(
} }
lc.remoteCommitChain.addCommitment(pendingRemoteCommit) lc.remoteCommitChain.addCommitment(pendingRemoteCommit)
walletLog.Debugf("ChannelPoint(%v), pending remote "+ lc.log.Debugf("pending remote commitment: %v",
"commitment: %v", lc.channelState.FundingOutpoint,
newLogClosure(func() string { newLogClosure(func() string {
return spew.Sdump(lc.remoteCommitChain.tip()) return spew.Sdump(lc.remoteCommitChain.tip())
}), }),
@ -1834,7 +1840,7 @@ func (lc *LightningChannel) restoreStateLogs(
lc.localUpdateLog.logIndex > 0 { lc.localUpdateLog.logIndex > 0 {
payDesc.LogIndex = lc.localUpdateLog.logIndex payDesc.LogIndex = lc.localUpdateLog.logIndex
walletLog.Debugf("Found FeeUpdate on "+ lc.log.Debugf("Found FeeUpdate on "+
"pendingRemoteCommitDiff without logIndex, "+ "pendingRemoteCommitDiff without logIndex, "+
"using %v", payDesc.LogIndex) "using %v", payDesc.LogIndex)
} }
@ -3278,14 +3284,14 @@ func (lc *LightningChannel) SignNextCommitment() (lnwire.Sig, []lnwire.Sig, []ch
return sig, htlcSigs, nil, err return sig, htlcSigs, nil, err
} }
walletLog.Tracef("ChannelPoint(%v): extending remote chain to height %v, "+ lc.log.Tracef("extending remote chain to height %v, "+
"local_log=%v, remote_log=%v", "local_log=%v, remote_log=%v",
lc.channelState.FundingOutpoint, newCommitView.height, newCommitView.height,
lc.localUpdateLog.logIndex, remoteACKedIndex) lc.localUpdateLog.logIndex, remoteACKedIndex)
walletLog.Tracef("ChannelPoint(%v): remote chain: our_balance=%v, "+ lc.log.Tracef("remote chain: our_balance=%v, "+
"their_balance=%v, commit_tx: %v", "their_balance=%v, commit_tx: %v",
lc.channelState.FundingOutpoint, newCommitView.ourBalance, newCommitView.ourBalance,
newCommitView.theirBalance, newCommitView.theirBalance,
newLogClosure(func() string { newLogClosure(func() string {
return spew.Sdump(newCommitView.txn) return spew.Sdump(newCommitView.txn)
@ -3423,9 +3429,8 @@ func (lc *LightningChannel) ProcessChanSyncMsg(
// In this case, we'll return an error to indicate the // In this case, we'll return an error to indicate the
// remote node sent us the wrong values. This will let // remote node sent us the wrong values. This will let
// the caller act accordingly. // the caller act accordingly.
walletLog.Errorf("ChannelPoint(%v), sync failed: "+ lc.log.Errorf("sync failed: remote provided invalid " +
"remote provided invalid commit secret!", "commit secret!")
lc.channelState.FundingOutpoint)
return nil, nil, nil, ErrInvalidLastCommitSecret return nil, nil, nil, ErrInvalidLastCommitSecret
} }
} }
@ -3455,15 +3460,12 @@ func (lc *LightningChannel) ProcessChanSyncMsg(
// If their reported height for our local chain tail is ahead of our // If their reported height for our local chain tail is ahead of our
// view, then we're behind! // view, then we're behind!
case msg.RemoteCommitTailHeight > localTailHeight || isRestoredChan: case msg.RemoteCommitTailHeight > localTailHeight || isRestoredChan:
walletLog.Errorf("ChannelPoint(%v), sync failed with local "+ lc.log.Errorf("sync failed with local data loss: remote "+
"data loss: remote believes our tail height is %v, "+ "believes our tail height is %v, while we have %v!",
"while we have %v!", lc.channelState.FundingOutpoint,
msg.RemoteCommitTailHeight, localTailHeight) msg.RemoteCommitTailHeight, localTailHeight)
if isRestoredChan { if isRestoredChan {
walletLog.Warnf("ChannelPoint(%v): detected restored "+ lc.log.Warnf("detected restored triggering DLP")
"triggering DLP",
lc.channelState.FundingOutpoint)
} }
// We must check that we had recovery options to ensure the // We must check that we had recovery options to ensure the
@ -3475,9 +3477,9 @@ func (lc *LightningChannel) ProcessChanSyncMsg(
// doesn't support data loss protection. In either case // doesn't support data loss protection. In either case
// it is not safe for us to keep using the channel, so // it is not safe for us to keep using the channel, so
// we mark it borked and fail the channel. // we mark it borked and fail the channel.
walletLog.Errorf("ChannelPoint(%v), sync failed: "+ lc.log.Errorf("sync failed: local data loss, but no " +
"local data loss, but no recovery option.", "recovery option.")
lc.channelState.FundingOutpoint)
return nil, nil, nil, ErrCannotSyncCommitChains return nil, nil, nil, ErrCannotSyncCommitChains
} }
@ -3492,9 +3494,8 @@ func (lc *LightningChannel) ProcessChanSyncMsg(
// is behind our view of the chain, then they probably lost some state, // is behind our view of the chain, then they probably lost some state,
// and we'll force close the channel. // and we'll force close the channel.
case msg.RemoteCommitTailHeight+1 < localTailHeight: case msg.RemoteCommitTailHeight+1 < localTailHeight:
walletLog.Errorf("ChannelPoint(%v), sync failed: remote "+ lc.log.Errorf("sync failed: remote believes our tail height is "+
"believes our tail height is %v, while we have %v!", "%v, while we have %v!",
lc.channelState.FundingOutpoint,
msg.RemoteCommitTailHeight, localTailHeight) msg.RemoteCommitTailHeight, localTailHeight)
return nil, nil, nil, ErrCommitSyncRemoteDataLoss return nil, nil, nil, ErrCommitSyncRemoteDataLoss
@ -3507,9 +3508,8 @@ func (lc *LightningChannel) ProcessChanSyncMsg(
// this case we'll re-send the last revocation message that we sent. // this case we'll re-send the last revocation message that we sent.
// This will be the revocation message for our prior chain tail. // This will be the revocation message for our prior chain tail.
case msg.RemoteCommitTailHeight+1 == localTailHeight: case msg.RemoteCommitTailHeight+1 == localTailHeight:
walletLog.Debugf("ChannelPoint(%v), sync: remote believes "+ lc.log.Debugf("sync: remote believes our tail height is %v, "+
"our tail height is %v, while we have %v, we owe "+ "while we have %v, we owe them a revocation",
"them a revocation", lc.channelState.FundingOutpoint,
msg.RemoteCommitTailHeight, localTailHeight) msg.RemoteCommitTailHeight, localTailHeight)
revocationMsg, err := lc.generateRevocation( revocationMsg, err := lc.generateRevocation(
@ -3555,9 +3555,8 @@ func (lc *LightningChannel) ProcessChanSyncMsg(
// There should be no other possible states. // There should be no other possible states.
default: default:
walletLog.Errorf("ChannelPoint(%v), sync failed: remote "+ lc.log.Errorf("sync failed: remote believes our tail height is "+
"believes our tail height is %v, while we have %v!", "%v, while we have %v!",
lc.channelState.FundingOutpoint,
msg.RemoteCommitTailHeight, localTailHeight) msg.RemoteCommitTailHeight, localTailHeight)
return nil, nil, nil, ErrCannotSyncCommitChains return nil, nil, nil, ErrCannotSyncCommitChains
} }
@ -3572,18 +3571,16 @@ func (lc *LightningChannel) ProcessChanSyncMsg(
// or not, we will fail the channel, but should not force close it // or not, we will fail the channel, but should not force close it
// automatically. // automatically.
case msg.NextLocalCommitHeight > remoteTipHeight+1: case msg.NextLocalCommitHeight > remoteTipHeight+1:
walletLog.Errorf("ChannelPoint(%v), sync failed: remote's "+ lc.log.Errorf("sync failed: remote's next commit height is %v, "+
"next commit height is %v, while we believe it is %v!", "while we believe it is %v!",
lc.channelState.FundingOutpoint,
msg.NextLocalCommitHeight, remoteTipHeight) msg.NextLocalCommitHeight, remoteTipHeight)
return nil, nil, nil, ErrCannotSyncCommitChains return nil, nil, nil, ErrCannotSyncCommitChains
// They are waiting for a state they have already ACKed. // They are waiting for a state they have already ACKed.
case msg.NextLocalCommitHeight <= remoteTailHeight: case msg.NextLocalCommitHeight <= remoteTailHeight:
walletLog.Errorf("ChannelPoint(%v), sync failed: remote's "+ lc.log.Errorf("sync failed: remote's next commit height is %v, "+
"next commit height is %v, while we believe it is %v!", "while we believe it is %v!",
lc.channelState.FundingOutpoint,
msg.NextLocalCommitHeight, remoteTipHeight) msg.NextLocalCommitHeight, remoteTipHeight)
// They previously ACKed our current tail, and now they are // They previously ACKed our current tail, and now they are
@ -3598,9 +3595,8 @@ func (lc *LightningChannel) ProcessChanSyncMsg(
// re-send all the updates necessary to recreate this state, along // re-send all the updates necessary to recreate this state, along
// with the commit sig. // with the commit sig.
case msg.NextLocalCommitHeight == remoteTipHeight: case msg.NextLocalCommitHeight == remoteTipHeight:
walletLog.Debugf("ChannelPoint(%v), sync: remote's next "+ lc.log.Debugf("sync: remote's next commit height is %v, while "+
"commit height is %v, while we believe it is %v, we "+ "we believe it is %v, we owe them a commitment",
"owe them a commitment", lc.channelState.FundingOutpoint,
msg.NextLocalCommitHeight, remoteTipHeight) msg.NextLocalCommitHeight, remoteTipHeight)
// Grab the current remote chain tip from the database. This // Grab the current remote chain tip from the database. This
@ -3629,9 +3625,8 @@ func (lc *LightningChannel) ProcessChanSyncMsg(
// can have at most two elements. If that's the case, something is // can have at most two elements. If that's the case, something is
// wrong. // wrong.
default: default:
walletLog.Errorf("ChannelPoint(%v), sync failed: remote's "+ lc.log.Errorf("sync failed: remote's next commit height is %v, "+
"next commit height is %v, while we believe it is %v!", "while we believe it is %v!",
lc.channelState.FundingOutpoint,
msg.NextLocalCommitHeight, remoteTipHeight) msg.NextLocalCommitHeight, remoteTipHeight)
return nil, nil, nil, ErrCannotSyncCommitChains return nil, nil, nil, ErrCannotSyncCommitChains
} }
@ -3669,9 +3664,8 @@ func (lc *LightningChannel) ProcessChanSyncMsg(
if !tweakless && commitPoint != nil && if !tweakless && commitPoint != nil &&
!commitPoint.IsEqual(msg.LocalUnrevokedCommitPoint) { !commitPoint.IsEqual(msg.LocalUnrevokedCommitPoint) {
walletLog.Errorf("ChannelPoint(%v), sync failed: remote "+ lc.log.Errorf("sync failed: remote sent invalid commit point "+
"sent invalid commit point for height %v!", "for height %v!",
lc.channelState.FundingOutpoint,
msg.NextLocalCommitHeight) msg.NextLocalCommitHeight)
return nil, nil, nil, ErrInvalidLocalUnrevokedCommitPoint return nil, nil, nil, ErrInvalidLocalUnrevokedCommitPoint
} }
@ -4033,13 +4027,13 @@ func (lc *LightningChannel) ReceiveNewCommitment(commitSig lnwire.Sig,
return err return err
} }
walletLog.Tracef("ChannelPoint(%v): extending local chain to height %v, "+ lc.log.Tracef("extending local chain to height %v, "+
"local_log=%v, remote_log=%v", "local_log=%v, remote_log=%v",
lc.channelState.FundingOutpoint, localCommitmentView.height, localCommitmentView.height,
localACKedIndex, lc.remoteUpdateLog.logIndex) localACKedIndex, lc.remoteUpdateLog.logIndex)
walletLog.Tracef("ChannelPoint(%v): local chain: our_balance=%v, "+ lc.log.Tracef("local chain: our_balance=%v, "+
"their_balance=%v, commit_tx: %v", lc.channelState.FundingOutpoint, "their_balance=%v, commit_tx: %v",
localCommitmentView.ourBalance, localCommitmentView.theirBalance, localCommitmentView.ourBalance, localCommitmentView.theirBalance,
newLogClosure(func() string { newLogClosure(func() string {
return spew.Sdump(localCommitmentView.txn) return spew.Sdump(localCommitmentView.txn)
@ -4181,8 +4175,8 @@ func (lc *LightningChannel) RevokeCurrentCommitment() (*lnwire.RevokeAndAck, []c
return nil, nil, err return nil, nil, err
} }
walletLog.Tracef("ChannelPoint(%v): revoking height=%v, now at height=%v", lc.log.Tracef("revoking height=%v, now at height=%v",
lc.channelState.FundingOutpoint, lc.localCommitChain.tail().height, lc.localCommitChain.tail().height,
lc.currentHeight+1) lc.currentHeight+1)
// Advance our tail, as we've revoked our previous state. // Advance our tail, as we've revoked our previous state.
@ -4198,9 +4192,9 @@ func (lc *LightningChannel) RevokeCurrentCommitment() (*lnwire.RevokeAndAck, []c
return nil, nil, err return nil, nil, err
} }
walletLog.Tracef("ChannelPoint(%v): state transition accepted: "+ lc.log.Tracef("state transition accepted: "+
"our_balance=%v, their_balance=%v", "our_balance=%v, their_balance=%v",
lc.channelState.FundingOutpoint, chainTail.ourBalance, chainTail.ourBalance,
chainTail.theirBalance) chainTail.theirBalance)
revocationMsg.ChanID = lnwire.NewChanIDFromOutPoint( revocationMsg.ChanID = lnwire.NewChanIDFromOutPoint(
@ -4260,8 +4254,8 @@ func (lc *LightningChannel) ReceiveRevocation(revMsg *lnwire.RevokeAndAck) (
lc.channelState.RemoteCurrentRevocation = lc.channelState.RemoteNextRevocation lc.channelState.RemoteCurrentRevocation = lc.channelState.RemoteNextRevocation
lc.channelState.RemoteNextRevocation = revMsg.NextRevocationKey lc.channelState.RemoteNextRevocation = revMsg.NextRevocationKey
walletLog.Tracef("ChannelPoint(%v): remote party accepted state transition, "+ lc.log.Tracef("remote party accepted state transition, revoked height "+
"revoked height %v, now at %v", lc.channelState.FundingOutpoint, "%v, now at %v",
lc.remoteCommitChain.tail().height, lc.remoteCommitChain.tail().height,
lc.remoteCommitChain.tail().height+1) lc.remoteCommitChain.tail().height+1)