diff --git a/chainntnfs/txnotifier.go b/chainntnfs/txnotifier.go index f6cd0c1b8..be471da3c 100644 --- a/chainntnfs/txnotifier.go +++ b/chainntnfs/txnotifier.go @@ -772,8 +772,8 @@ func (n *TxNotifier) CancelConf(confRequest ConfRequest, confID uint64) { return } - Log.Infof("Canceling confirmation notification: conf_id=%d, %v", confID, - confRequest) + Log.Debugf("Canceling confirmation notification: conf_id=%d, %v", + confID, confRequest) // We'll close all the notification channels to let the client know // their cancel request has been fulfilled. @@ -925,7 +925,7 @@ func (n *TxNotifier) dispatchConfDetails( // we'll dispatch a confirmation notification to the caller. confHeight := details.BlockHeight + ntfn.NumConfirmations - 1 if confHeight <= n.currentHeight { - Log.Infof("Dispatching %v confirmation notification for %v", + Log.Debugf("Dispatching %v confirmation notification for %v", ntfn.NumConfirmations, ntfn.ConfRequest) // We'll send a 0 value to the Updates channel, @@ -1058,7 +1058,7 @@ func (n *TxNotifier) RegisterSpend(outpoint *wire.OutPoint, pkScript []byte, n.Lock() defer n.Unlock() - Log.Infof("New spend subscription: spend_id=%d, %v, height_hint=%d", + Log.Debugf("New spend subscription: spend_id=%d, %v, height_hint=%d", ntfn.SpendID, ntfn.SpendRequest, startHeight) // Keep track of the notification request so that we can properly @@ -1136,7 +1136,7 @@ func (n *TxNotifier) RegisterSpend(outpoint *wire.OutPoint, pkScript []byte, // notifications don't also attempt a historical dispatch. spendSet.rescanStatus = rescanPending - Log.Infof("Dispatching historical spend rescan for %v, start=%d, "+ + Log.Debugf("Dispatching historical spend rescan for %v, start=%d, "+ "end=%d", ntfn.SpendRequest, startHeight, n.currentHeight) return &SpendRegistration{ @@ -1171,7 +1171,7 @@ func (n *TxNotifier) CancelSpend(spendRequest SpendRequest, spendID uint64) { return } - Log.Infof("Canceling spend notification: spend_id=%d, %v", spendID, + Log.Debugf("Canceling spend notification: spend_id=%d, %v", spendID, spendRequest) // We'll close all the notification channels to let the client know @@ -1364,7 +1364,7 @@ func (n *TxNotifier) dispatchSpendDetails(ntfn *SpendNtfn, details *SpendDetail) return nil } - Log.Infof("Dispatching confirmed spend notification for %v at "+ + Log.Debugf("Dispatching confirmed spend notification for %v at "+ "current height=%d: %v", ntfn.SpendRequest, n.currentHeight, details) @@ -1743,7 +1743,7 @@ func (n *TxNotifier) NotifyHeight(height uint32) error { for ntfn := range n.ntfnsByConfirmHeight[height] { confSet := n.confNotifications[ntfn.ConfRequest] - Log.Infof("Dispatching %v confirmation notification for %v", + Log.Debugf("Dispatching %v confirmation notification for %v", ntfn.NumConfirmations, ntfn.ConfRequest) // The default notification we assigned above includes the diff --git a/sweep/sweeper.go b/sweep/sweeper.go index e8e7d77a4..39a03228d 100644 --- a/sweep/sweeper.go +++ b/sweep/sweeper.go @@ -767,11 +767,11 @@ func (s *UtxoSweeper) signalResult(pi *SweeperInput, result Result) { listeners := pi.listeners if result.Err == nil { - log.Debugf("Dispatching sweep success for %v to %v listeners", + log.Tracef("Dispatching sweep success for %v to %v listeners", op, len(listeners), ) } else { - log.Debugf("Dispatching sweep error for %v to %v listeners: %v", + log.Tracef("Dispatching sweep error for %v to %v listeners: %v", op, len(listeners), result.Err, ) } @@ -830,6 +830,9 @@ func (s *UtxoSweeper) sweep(set InputSet) error { outpoints[i] = inp.OutPoint() } + log.Errorf("Initial broadcast failed: %v, inputs=\n%v", err, + inputTypeSummary(set.Inputs())) + // TODO(yy): find out which input is causing the failure. s.markInputsPublishFailed(outpoints) @@ -855,7 +858,7 @@ func (s *UtxoSweeper) markInputsPendingPublish(set InputSet) { // It could be that this input is an additional wallet // input that was attached. In that case there also // isn't a pending input to update. - log.Debugf("Skipped marking input as pending "+ + log.Tracef("Skipped marking input as pending "+ "published: %v not found in pending inputs", input.OutPoint()) @@ -904,7 +907,7 @@ func (s *UtxoSweeper) markInputsPublished(tr *TxRecord, // It could be that this input is an additional wallet // input that was attached. In that case there also // isn't a pending input to update. - log.Debugf("Skipped marking input as published: %v "+ + log.Tracef("Skipped marking input as published: %v "+ "not found in pending inputs", input.PreviousOutPoint) @@ -940,7 +943,7 @@ func (s *UtxoSweeper) markInputsPublishFailed(outpoints []wire.OutPoint) { // It could be that this input is an additional wallet // input that was attached. In that case there also // isn't a pending input to update. - log.Debugf("Skipped marking input as publish failed: "+ + log.Tracef("Skipped marking input as publish failed: "+ "%v not found in pending inputs", op) continue @@ -948,7 +951,7 @@ func (s *UtxoSweeper) markInputsPublishFailed(outpoints []wire.OutPoint) { // Valdiate that the input is in an expected state. if pi.state != PendingPublish && pi.state != Published { - log.Errorf("Expect input %v to have %v, instead it "+ + log.Debugf("Expect input %v to have %v, instead it "+ "has %v", op, PendingPublish, pi.state) continue @@ -1397,7 +1400,7 @@ func (s *UtxoSweeper) markInputsSwept(tx *wire.MsgTx, isOurTx bool) { if !ok { // It's very likely that a spending tx contains inputs // that we don't know. - log.Debugf("Skipped marking input as swept: %v not "+ + log.Tracef("Skipped marking input as swept: %v not "+ "found in pending inputs", outpoint) continue diff --git a/sweep/sweeper_test.go b/sweep/sweeper_test.go index 667906de9..c8d9fc510 100644 --- a/sweep/sweeper_test.go +++ b/sweep/sweeper_test.go @@ -695,12 +695,12 @@ func TestSweepPendingInputs(t *testing.T) { // Mock the methods used in `sweep`. This is not important for this // unit test. - setNeedWallet.On("Inputs").Return(nil).Times(4) + setNeedWallet.On("Inputs").Return(nil).Maybe() setNeedWallet.On("DeadlineHeight").Return(testHeight).Once() setNeedWallet.On("Budget").Return(btcutil.Amount(1)).Once() setNeedWallet.On("StartingFeeRate").Return( fn.None[chainfee.SatPerKWeight]()).Once() - normalSet.On("Inputs").Return(nil).Times(4) + normalSet.On("Inputs").Return(nil).Maybe() normalSet.On("DeadlineHeight").Return(testHeight).Once() normalSet.On("Budget").Return(btcutil.Amount(1)).Once() normalSet.On("StartingFeeRate").Return( diff --git a/sweep/tx_input_set.go b/sweep/tx_input_set.go index cfa4a0ba4..27cdafada 100644 --- a/sweep/tx_input_set.go +++ b/sweep/tx_input_set.go @@ -241,13 +241,13 @@ func (b *BudgetInputSet) NeedWalletInput() bool { // If the input's budget is not even covered by itself, we need // to borrow outputs from other inputs. if budgetBorrowable < 0 { - log.Debugf("Input %v specified a budget that exceeds "+ + log.Tracef("Input %v specified a budget that exceeds "+ "its output value: %v > %v", inp, budget, output) } } - log.Tracef("NeedWalletInput: budgetNeeded=%v, budgetBorrowable=%v", + log.Debugf("NeedWalletInput: budgetNeeded=%v, budgetBorrowable=%v", budgetNeeded, budgetBorrowable) // If we don't have enough extra budget to borrow, we need wallet @@ -314,6 +314,8 @@ func (b *BudgetInputSet) AddWalletInputs(wallet Wallet) error { } b.addInput(pi) + log.Debugf("Added wallet input %v to input set", pi) + // Return if we've reached the minimum output amount. if !b.NeedWalletInput() { return nil