diff --git a/Makefile b/Makefile index a36999c3d..dedcc1730 100644 --- a/Makefile +++ b/Makefile @@ -143,6 +143,7 @@ check: unit itest itest-only: @$(call print, "Running integration tests with ${backend} backend.") $(ITEST) + lntest/itest/log_check_errors.sh itest: btcd build-itest itest-only diff --git a/fundingmanager.go b/fundingmanager.go index ae4c1f934..6ae890c4a 100644 --- a/fundingmanager.go +++ b/fundingmanager.go @@ -2725,8 +2725,9 @@ func (f *fundingManager) handleFundingLocked(fmsg *fundingLockedMsg) { if err := fmsg.peer.AddNewChannel(channel, f.quit); err != nil { fndgLog.Errorf("Unable to add new channel %v with peer %x: %v", + channel.FundingOutpoint, fmsg.peer.IdentityKey().SerializeCompressed(), - channel.FundingOutpoint, err) + err) } } diff --git a/lntest/itest/log_check_errors.sh b/lntest/itest/log_check_errors.sh new file mode 100755 index 000000000..80d6a07d3 --- /dev/null +++ b/lntest/itest/log_check_errors.sh @@ -0,0 +1,12 @@ +#!/bin/bash + +BASEDIR=$(dirname "$0") + +# Filter all log files for errors, substitute variable data and match against whitelist. +cat $BASEDIR/*.log | grep "\[ERR\]" | \ +sed -r -f $BASEDIR/log_substitutions.txt | \ +sort | uniq | \ +grep -Fv -f $BASEDIR/log_error_whitelist.txt + +# If something shows up (not on whitelist) exit with error code 1. +test $? -eq 1 diff --git a/lntest/itest/log_error_whitelist.txt b/lntest/itest/log_error_whitelist.txt new file mode 100644 index 000000000..171560008 --- /dev/null +++ b/lntest/itest/log_error_whitelist.txt @@ -0,0 +1,158 @@ +<time> [ERR] BRAR: Unable to broadcast justice tx: Transaction rejected: output already spent +<time> [ERR] BRAR: Unable to register for conf for txid(<hex>): TxNotifier is exiting +<time> [ERR] BTCN: Broadcast attempt failed: rejected by <ip>: replacement transaction <hex> has an insufficient absolute fee: needs <amt>, has <amt> +<time> [ERR] BTCN: Broadcast attempt failed: rejected by <ip>: replacement transaction <hex> has an insufficient fee rate: needs more than <amt>, has <amt> +<time> [ERR] BTCN: Unable to process block connected (height=<height>, hash=<hex>): out of order block <hex>: expected PrevBlock <hex>, got <hex> +<time> [ERR] BTCN: Unknown connid=<id> +<time> [ERR] CHFT: Close channel <chan_point> unknown to store +<time> [ERR] CNCT: *contractcourt.commitSweepResolver(<chan_point>): unable to sweep input: remote party swept utxo +<time> [ERR] CNCT: ChannelArbitrator(<chan_point>): unable to advance state: channel not found +<time> [ERR] CNCT: ChannelArbitrator(<chan_point>): unable to broadcast close tx: Transaction rejected: output already spent +<time> [ERR] CNCT: ChannelArbitrator(<chan_point>): unable to force close: channel not found +<time> [ERR] CNCT: ChannelArbitrator(<chan_point>): unable to progress *contractcourt.commitSweepResolver: remote party swept utxo +<time> [ERR] CNCT: ChannelArbitrator(<chan_point>): unable to progress *contractcourt.htlcOutgoingContestResolver: chain notifier shutting down +<time> [ERR] CNCT: ChannelArbitrator(<chan_point>): unable to progress *contractcourt.htlcOutgoingContestResolver: the client has been shutdown +<time> [ERR] CNCT: ChannelArbitrator(<chan_point>): unable to progress *contractcourt.htlcOutgoingContestResolver: unable to create pre-image from witness: invalid preimage length of 33, want 32 +<time> [ERR] CNCT: ChannelArbitrator(<chan_point>): unable to progress *contractcourt.htlcSuccessResolver: Transaction rejected: output already spent +<time> [ERR] CNCT: Unable to advance state: channel not found +<time> [ERR] CNCT: unable to hand breached contract off to breachArbiter: server is shutting down +<time> [ERR] CNCT: unable to handle channel breach for chan_point=<chan_point>: server is shutting down +<time> [ERR] CRTR: Channel update of ourselves received +<time> [ERR] CRTR: Error collecting result for shard <number> for payment <hex>: shard handler exiting +<time> [ERR] CRTR: Error encountered during rescan: rescan exited +<time> [ERR] CRTR: Failed sending attempt <number> for payment <hex> to switch: insufficient bandwidth to route htlc +<time> [ERR] CRTR: Failed sending attempt <number> for payment <hex> to switch: UnknownNextPeer +<time> [ERR] CRTR: out of order block: expecting height=<height>, got height=<height> +<time> [ERR] CRTR: Payment with hash <hex> failed: router shutting down +<time> [ERR] CRTR: Resuming payment with hash <hex> failed: error. +<time> [ERR] CRTR: Resuming payment with hash <hex> failed: incorrect_payment_details. +<time> [ERR] CRTR: Resuming payment with hash <hex> failed: no_route. +<time> [ERR] CRTR: Resuming payment with hash <hex> failed: router shutting down. +<time> [ERR] CRTR: Unable to retrieve channel by id: edge not found +<time> [ERR] DISC: channel announcement proof for short_chan_id=<hex> isn't valid: can't verify first bitcoin signature +<time> [ERR] DISC: router shutting down +<time> [ERR] DISC: unable add proof to the channel chanID=<hex>: edge marked as zombie +<time> [ERR] DISC: unable add proof to the channel chanID=<hex>: edge not found +<time> [ERR] DISC: Unable to reply to peer query: set tcp <ip>: use of closed network connection +<time> [ERR] DISC: Unable to reply to peer query: write tcp <ip>-><ip>: use of closed network connection +<time> [ERR] DISC: Unable to reply to peer query: write tcp <ip>-><ip>: write: broken pipe +<time> [ERR] FNDG: received funding error from <hex>: chan_id=<hex>, err=Number of pending channels exceed maximum +<time> [ERR] FNDG: Unable to add new channel <chan_point> with peer <hex>: peer exiting +<time> [ERR] FNDG: Unable to advance pending state of ChannelPoint(<chan_point>): error waiting for funding confirmation for ChannelPoint(<chan_point>): epoch client shutting down +<time> [ERR] FNDG: Unable to advance pending state of ChannelPoint(<chan_point>): error waiting for funding confirmation for ChannelPoint(<chan_point>): funding manager shutting down +<time> [ERR] FNDG: Unable to advance pending state of ChannelPoint(<chan_point>): error waiting for funding confirmation for ChannelPoint(<chan_point>): waiting for fundingconfirmation failed +<time> [ERR] FNDG: Unable to advance state(<chan_point>): error sending channel announcement: channel announcement failed: channel announcement proof for short_chan_id=<hex> isn't valid: can't verify first bitcoin signature +<time> [ERR] FNDG: Unable to advance state(<chan_point>): error sending channel announcement: channel announcement failed: funding manager shutting down +<time> [ERR] FNDG: Unable to advance state(<chan_point>): error sending channel announcement: channel announcement failed: gossiper is shutting down +<time> [ERR] FNDG: Unable to advance state(<chan_point>): error sending channel announcement: channel announcement failed: router shutting down +<time> [ERR] FNDG: Unable to advance state(<chan_point>): error sending channel announcement: channel announcement failed: unable add proof to the channel chanID=<hex>: edge marked as zombie +<time> [ERR] FNDG: Unable to advance state(<chan_point>): error sending channel announcement: channel announcement failed: unable add proof to the channel chanID=<hex>: edge not found +<time> [ERR] FNDG: Unable to advance state(<chan_point>): failed sending fundingLocked: funding manager shutting down +<time> [ERR] FNDG: unable to cancel reservation: no active reservations for peer(<hex>) +<time> [ERR] FNDG: unable to report short chan id: link <hex> not found +<time> [ERR] FNDG: Unable to send channel proof: channel announcement proof for short_chan_id=<hex> isn't valid: can't verify first bitcoin signature +<time> [ERR] FNDG: Unable to send channel proof: gossiper is shutting down +<time> [ERR] FNDG: Unable to send channel proof: unable add proof to the channel chanID=<hex>: edge marked as zombie +<time> [ERR] FNDG: Unable to send channel proof: unable add proof to the channel chanID=<hex>: edge not found +<time> [ERR] FNDG: Unable to send node announcement: gossiper is shutting down +<time> [ERR] FNDG: Unable to send node announcement: router shutting down +<time> [ERR] HSWC: AmountBelowMinimum(amt=<amt>, update=(lnwire.ChannelUpdate) { +<time> [ERR] HSWC: ChannelLink(<chan>): failing link: ChannelPoint(<chan_point>): received error from peer: chan_id=<hex>, err=invalid update with error: remote error +<time> [ERR] HSWC: ChannelLink(<chan>): failing link: unable to handle upstream settle HTLC: Invalid payment preimage <hex> for hash <hex> with error: invalid update +<time> [ERR] HSWC: ChannelLink(<chan>): failing link: unable to synchronize channel states: ChannelPoint(<chan_point>) with CommitPoint(<hex>) had possible local commitment state data loss with error: unable to resume channel, recovery required +<time> [ERR] HSWC: ChannelLink(<chan>): failing link: unable to synchronize channel states: possible remote commitment state data loss with error: sync error +<time> [ERR] HSWC: ChannelLink(<chan>): failing link: unable to synchronize channel states: Unable to send chan sync message for ChannelPoint(<chan_point>): peer exiting with error: unable to resume channel, recovery required +<time> [ERR] HSWC: ChannelLink(<chan>): failing link: unable to synchronize channel states: Unable to send chan sync message for ChannelPoint(<chan_point>): write tcp <ip>-><ip>: use of closed network connection with error: unable to resume channel, recovery required +<time> [ERR] HSWC: ChannelLink(<chan>): failing link: unable to synchronize channel states: Unable to send chan sync message for ChannelPoint(<chan_point>): write tcp <ip>-><ip>: write: broken pipe with error: unable to resume channel, recovery required +<time> [ERR] HSWC: ChannelLink(<chan>): link failed, exiting htlcManager +<time> [ERR] HSWC: ChannelLink(<chan>): outgoing htlc(<hex>) has insufficient fee: expected 575000, got 1075 +<time> [ERR] HSWC: ChannelLink(<chan>): outgoing htlc(<hex>) is too small: min_htlc=<amt>, htlc_value=<amt> +<time> [ERR] HSWC: ChannelLink(<chan>): unable to decode onion hop iterator: TemporaryChannelFailure +<time> [ERR] HSWC: ChannelLink(<chan>): unhandled error while forwarding htlc packet over htlcswitch: AmountBelowMinimum(amt=4000 mSAT, update=(lnwire.ChannelUpdate) { +<time> [ERR] HSWC: ChannelLink(<chan>): unhandled error while forwarding htlc packet over htlcswitch: circuit has already been closed +<time> [ERR] HSWC: ChannelLink(<chan>): unhandled error while forwarding htlc packet over htlcswitch: insufficient bandwidth to route htlc +<time> [ERR] HSWC: ChannelLink(<chan>): unhandled error while forwarding htlc packet over htlcswitch: node configured to disallow forwards +<time> [ERR] HSWC: ChannelLink(<chan>): unhandled error while forwarding htlc packet over htlcswitch: UnknownNextPeer +<time> [ERR] HSWC: ChannelLink(<chan>): Unhandled error while reforwarding htlc settle/fail over htlcswitch: AmountBelowMinimum(amt=<amt>, update=(lnwire.ChannelUpdate) { +<time> [ERR] HSWC: ChannelLink(<chan>): Unhandled error while reforwarding htlc settle/fail over htlcswitch: circuit has already been closed +<time> [ERR] HSWC: ChannelLink(<chan>): Unhandled error while reforwarding htlc settle/fail over htlcswitch: FeeInsufficient(htlc_amt==<amt>, update=(lnwire.ChannelUpdate) { +<time> [ERR] HSWC: ChannelLink(<chan>): Unhandled error while reforwarding htlc settle/fail over htlcswitch: insufficient bandwidth to route htlc +<time> [ERR] HSWC: ChannelLink(<chan>): Unhandled error while reforwarding htlc settle/fail over htlcswitch: node configured to disallow forwards +<time> [ERR] HSWC: ChannelLink(<chan>): Unhandled error while reforwarding htlc settle/fail over htlcswitch: UnknownNextPeer +<time> [ERR] HSWC: FeeInsufficient(htlc_amt==<amt>, update=(lnwire.ChannelUpdate) { +<time> [ERR] HSWC: insufficient bandwidth to route htlc +<time> [ERR] HSWC: Link <chan> not found +<time> [ERR] HSWC: Link <chan> policy for local forward not satisfied +<time> [ERR] HSWC: node configured to disallow forwards +<time> [ERR] HSWC: unable to de-obfuscate onion failure (hash=<hex>, pid=<pid>): invalid error length: expected 292 got 0 +<time> [ERR] HSWC: unable to find target channel for HTLC fail: channel ID = <chan>, HTLC ID = <id> +<time> [ERR] HSWC: Unable to forward resolution msg: unable to find target channel for HTLC fail: channel ID = <chan>, HTLC ID = <id> +<time> [ERR] HSWC: unable to process onion packet: sphinx packet replay attempted +<time> [ERR] HSWC: UnknownNextPeer +<time> [ERR] LNWL: ChannelPoint(<chan_point>): sync failed with local data loss: remote believes our tail height is <height>, while we have <height>! +<time> [ERR] LNWL: ChannelPoint(<chan_point>): sync failed: remote believes our tail height is <height>, while we have <height>! +<time> [ERR] LNWL: ChannelPoint(<chan_point>): sync failed: remote's next commit height is <height>, while we believe it is <height>! +<time> [ERR] LNWL: Neutrino rescan ended with error: rescan exited +<time> [ERR] LNWL: Notifying unmined tx notification (<hex>) while creating notification for blocks +<time> [ERR] LTND: Unable to lookup witness: no witnesses +<time> [ERR] NANN: Unable to retrieve chan status for Channel(<chan_point>): edge not found +<time> [ERR] NANN: Unable to retrieve chan status for Channel(<chan_point>): unable to extract ChannelUpdate for channel <chan_point> +<time> [ERR] NANN: Unable to sign update disabling channel(<chan_point>): edge not found +<time> [ERR] NTFN: Error during rescan: rescan exited +<time> [ERR] NTFN: Rescan to determine the spend details of <chan_point> failed: the client has been shutdown +<time> [ERR] NTFN: Unable to fetch block header: the client has been shutdown +<time> [ERR] NTFN: unable to find blockhash for height=<height>: -1: Block number out of range +<time> [ERR] NTFN: unable to get block: the client has been shutdown +<time> [ERR] NTFN: unable to get missed blocks: starting height <height> is greater than ending height <height> +<time> [ERR] NTFN: Unable to rewind chain from height <height> to height <height>: unable to find blockhash for disconnected height=<height>: -1: Block number out of range +<time> [ERR] PEER: resend failed: unable to fetch channel sync messages for peer <hex>@<ip>: unable to find closed channel summary +<time> [ERR] PEER: unable to force close link(<chan>): ChainArbitrator exiting +<time> [ERR] PEER: unable to force close link(<chan>): channel not found +<time> [ERR] PEER: unable to force close link(<chan>): unable to find arbitrator +<time> [ERR] PEER: unable to get best block: the client has been shutdown +<time> [ERR] PEER: unable to send msg to remote peer: peer exiting +<time> [ERR] PEER: unable to send msg to remote peer: write tcp <ip>-><ip>: write: broken pipe +<time> [ERR] RPCS: [/invoicesrpc.Invoices/SubscribeSingleInvoice]: rpc error: code = Canceled desc = context canceled +<time> [ERR] RPCS: [/lnrpc.Lightning/CloseChannel]: cannot co-op close frozen channel as initiator until height=<height>, (current_height=<height>) +<time> [ERR] RPCS: [/lnrpc.Lightning/CloseChannel]: cannot co-op close frozen channel as initiator until height=3059, (current_height=3055) +<time> [ERR] RPCS: [/lnrpc.Lightning/CloseChannel]: chain notifier shutting down +<time> [ERR] RPCS: [/lnrpc.Lightning/ConnectPeer]: already connected to peer: <hex>@<ip> +<time> [ERR] RPCS: [/lnrpc.Lightning/FundingStateStep]: pendingChanID(<hex>) already has intent registered +<time> [ERR] RPCS: [/lnrpc.Lightning/GetChanInfo]: edge marked as zombie +<time> [ERR] RPCS: [/lnrpc.Lightning/OpenChannel]: channels cannot be created before the wallet is fully synced +<time> [ERR] RPCS: [/lnrpc.Lightning/OpenChannel]: received funding error from <hex>: chan_id=<hex>, err=Number of pending channels exceed maximum +<time> [ERR] RPCS: [/lnrpc.Lightning/PendingChannels]: unable to find arbitrator +<time> [ERR] RPCS: [/lnrpc.Lightning/SendCoins]: address: tb1qfc8fusa98jx8uvnhzavxccqlzvg749tvjw82tg is not valid for this network: regtest +<time> [ERR] RPCS: [/lnrpc.Lightning/SendCoins]: amount set while SendAll is active +<time> [ERR] RPCS: [/lnrpc.Lightning/SendCoins]: cannot send coins to pubkeys +<time> [ERR] RPCS: [/lnrpc.Lightning/SendCoins]: unknown address type +<time> [ERR] RPCS: [/lnrpc.Lightning/SendPayment]: rpc error: code = Canceled desc = context canceled +<time> [ERR] RPCS: [/lnrpc.Lightning/SendPayment]: rpc error: code = DeadlineExceeded desc = context deadline exceeded +<time> [ERR] RPCS: [/lnrpc.Lightning/SendPayment]: rpc server shutting down +<time> [ERR] RPCS: [/lnrpc.Lightning/SendToRoute]: rpc error: code = Canceled desc = context canceled +<time> [ERR] RPCS: [/lnrpc.Lightning/SendToRoute]: rpc error: code = DeadlineExceeded desc = context deadline exceeded +<time> [ERR] RPCS: [/lnrpc.Lightning/SendToRoute]: rpc server shutting down +<time> [ERR] RPCS: [/lnrpc.Lightning/SubscribeChannelEvents]: rpc error: code = Canceled desc = context canceled +<time> [ERR] RPCS: [/lnrpc.Lightning/SubscribeChannelGraph]: ChannelRouter shutting down +<time> [ERR] RPCS: [/lnrpc.Lightning/SubscribeChannelGraph]: router not started +<time> [ERR] RPCS: [/lnrpc.Lightning/SubscribeChannelGraph]: rpc error: code = Canceled desc = context canceled +<time> [ERR] RPCS: [/lnrpc.Lightning/SubscribeChannelGraph]: rpc error: code = DeadlineExceeded desc = context deadline exceeded +<time> [ERR] RPCS: [/lnrpc.Lightning/SubscribeChannelGraph]: rpc error: code = Internal desc = transport: transport: the stream is done or WriteHeader was already called +<time> [ERR] RPCS: [/lnrpc.Lightning/SubscribeInvoices]: rpc error: code = Canceled desc = context canceled +<time> [ERR] RPCS: [/routerrpc.Router/SendPayment]: routerrpc server shutting down +<time> [ERR] RPCS: [closechannel] unable to close ChannelPoint(<chan_point>): chain notifier shutting down +<time> [ERR] RPCS: [connectpeer]: error connecting to peer: already connected to peer: <hex>@<ip> +<time> [ERR] RPCS: Failed receiving from stream: rpc error: code = Canceled desc = context canceled +<time> [ERR] RPCS: Failed receiving from stream: rpc error: code = DeadlineExceeded desc = context deadline exceeded +<time> [ERR] RPCS: Failed sending error response: rpc error: code = Canceled desc = context canceled +<time> [ERR] RPCS: Failed sending error response: rpc error: code = Internal desc = transport: transport: the stream is done or WriteHeader was already called +<time> [ERR] RPCS: Failed sending response: rpc error: code = Canceled desc = context canceled +<time> [ERR] RPCS: Failed sending response: rpc error: code = Internal desc = transport: transport: the stream is done or WriteHeader was already called +<time> [ERR] RPCS: unable to open channel to NodeKey(<hex>): received funding error from <hex>: chan_id=<hex>, err=Number of pending channels exceed maximum +<time> [ERR] RPCS: Websocket receive error from <ip>: read tcp4 <ip>-><ip>: use of closed network connection +<time> [ERR] RPCS: Websocket receive error from <ip>: websocket: close 1006 unexpected EOF +<time> [ERR] SRVR: Unable to retrieve advertised address for node <hex>: no advertised addresses found +<time> [ERR] SRVR: Unable to retrieve advertised address for node <hex>: unable to find node +<time> [ERR] UTXN: error while graduating class at height=<height>: TxNotifier is exiting +<time> [ERR] UTXN: Failed to sweep first-stage HTLC (CLTV-delayed) output <chan_point> +<time> [ERR] UTXN: Notification chan closed, can't advance output <chan_point> \ No newline at end of file diff --git a/lntest/itest/log_substitutions.txt b/lntest/itest/log_substitutions.txt new file mode 100644 index 000000000..75b39983a --- /dev/null +++ b/lntest/itest/log_substitutions.txt @@ -0,0 +1,19 @@ +s/[0-9a-f]{64}\:[[:digit:]]+/<chan_point>/g +s/[0-9a-f]{16,}/<hex>/g +s/[[:digit:]]+\.[[:digit:]]+\.[[:digit:]]+\.[[:digit:]]+\:[[:digit:]]+/<ip>/g +s/[[:digit:]]{4}-[[:digit:]]{2}-[[:digit:]]{2} [[:digit:]]{2}:[[:digit:]]{2}:[[:digit:]]{2}\.[[:digit:]]{3}/<time>/g +s/[[:digit:]]+\:[[:digit:]]+\:[[:digit:]]+/<chan>/g +s/[[:digit:]]+ mSAT/<amt>/g +s/HTLC ID = [[:digit:]]+/HTLC ID = <id>/g +s/height=[[:digit:]]+/height=<height>/g +s/collecting result for shard [[:digit:]]+/collecting result for shard <number>/g +s/sending attempt [[:digit:]]+/sending attempt <number>/g +s/Unable to rewind chain from height [[:digit:]]+ to height [[:digit:]]+/Unable to rewind chain from height <height> to height <height>/g +s/NTFN: unable to get missed blocks: starting height [[:digit:]]+ is greater than ending height [[:digit:]]+/NTFN: unable to get missed blocks: starting height <height> is greater than ending height <height>/g +s/BTCN: Broadcast attempt failed: rejected by <ip>: replacement transaction <hex> has an insufficient fee rate: needs more than [[:digit:]]+, has [[:digit:]]+/BTCN: Broadcast attempt failed: rejected by <ip>: replacement transaction <hex> has an insufficient fee rate: needs more than <amt>, has <amt>/g +s/pid=[[:digit:]]+/pid=<pid>/g +s/connid=[[:digit:]]+/connid=<id>/g +s/sync failed with local data loss: remote believes our tail height is [[:digit:]]+, while we have [[:digit:]]+/sync failed with local data loss: remote believes our tail height is <height>, while we have <height>/g +s/sync failed: remote believes our tail height is [[:digit:]]+, while we have [[:digit:]]+/sync failed: remote believes our tail height is <height>, while we have <height>/g +s/sync failed: remote's next commit height is [[:digit:]]+, while we believe it is [[:digit:]]+/sync failed: remote's next commit height is <height>, while we believe it is <height>/g +s/replacement transaction <hex> has an insufficient absolute fee: needs [[:digit:]]+, has [[:digit:]]+/replacement transaction <hex> has an insufficient absolute fee: needs <amt>, has <amt>/g \ No newline at end of file