2020-04-02 18:19:31.707 [WRN] LTND: open /tmp/lndtest-node639849499/data: no such file or directory 2020-04-02 18:19:31.707 [INF] LTND: Version: 0.9.0-beta commit=v0.9.0-beta-494-ga9b5e90df01a5d9ff622eb5b4bdf5f40306ec499, build=development, logging=default 2020-04-02 18:19:31.707 [INF] LTND: Active chain: Bitcoin (network=regtest) 2020-04-02 18:19:31.707 [INF] LTND: Opening the main database, this might take a few minutes... 2020-04-02 18:19:31.712 [INF] CHDB: Checking for schema update: latest_version=13, db_version=13 2020-04-02 18:19:31.712 [INF] LTND: Database now open (time_to_open=4.964584ms)! 2020-04-02 18:19:31.712 [INF] RPCS: Generating TLS certificates... 2020-04-02 18:19:31.720 [INF] RPCS: Done generating TLS certificates 2020-04-02 18:19:31.721 [INF] RPCS: password gRPC proxy started at 127.0.0.1:20082 2020-04-02 18:19:31.721 [INF] RPCS: password RPC server listening on 127.0.0.1:20081 2020-04-02 18:19:31.721 [INF] LTND: Waiting for wallet encryption password. Use `lncli create` to create a wallet, `lncli unlock` to unlock an existing wallet, or `lncli changepassword` to change the password of an existing wallet and unlock it. 2020-04-02 18:19:31.791 [INF] LNWL: Opened wallet 2020-04-02 18:19:31.792 [INF] LTND: Wallet recovery mode enabled with address lookahead of 1000 addresses 2020-04-02 18:19:31.799 [INF] LTND: Primary chain is set to: bitcoin 2020-04-02 18:19:31.812 [INF] LNWL: Started listening for bitcoind block notifications via ZMQ on //tmp/bitcoind295918325/blocks.socket 2020-04-02 18:19:31.814 [INF] LNWL: Started listening for bitcoind transaction notifications via ZMQ on //tmp/bitcoind295918325/txs.socket 2020-04-02 18:19:31.814 [INF] LNWL: The wallet has been unlocked without a time limit 2020-04-02 18:19:31.820 [INF] LTND: LightningWallet opened 2020-04-02 18:19:31.820 [DBG] LNWL: Locating suitable block for birthday 2020-03-31 18:15:05 +0000 UTC between blocks 0-2945 2020-04-02 18:19:31.821 [DBG] LNWL: Checking candidate block: height=1472, hash=2d1f0018cbd63a02596fbb8fa79f77b097c5a79a3b66e6e940352dbe91decc73, timestamp=2020-04-02 18:03:56 +0000 UTC 2020-04-02 18:19:31.823 [DBG] LNWL: Checking candidate block: height=736, hash=79bd28dcbb0a69c80e386fbbebd802c756dca172fbcc51dd1107c8f3a77198fa, timestamp=2020-04-02 17:56:13 +0000 UTC 2020-04-02 18:19:31.824 [DBG] LNWL: Checking candidate block: height=368, hash=32e4ea246244a49e11c8f33063e5e2b46cf20711dc9162d817ff5c7d18fd9596, timestamp=2020-04-02 17:53:59 +0000 UTC 2020-04-02 18:19:31.825 [INF] HSWC: Restoring in-memory circuit state from disk 2020-04-02 18:19:31.825 [DBG] LNWL: Checking candidate block: height=184, hash=27243e27ef328f95dd5e85680d163e8bbe2e76f26c382c16a7d13d0d046fd93f, timestamp=2020-04-02 17:53:28 +0000 UTC 2020-04-02 18:19:31.825 [INF] HSWC: Payment circuits loaded: num_pending=0, num_open=0 2020-04-02 18:19:31.826 [DBG] LNWL: Checking candidate block: height=92, hash=2176d8cc792ae377d260f3df38ea347da9297f2004ea9e51c5ff0aac6d33e9ce, timestamp=2020-04-02 17:53:13 +0000 UTC 2020-04-02 18:19:31.827 [DBG] LNWL: Checking candidate block: height=46, hash=09b97f736ca0617f2837a809a32436b69ffbefb64e721fd8c9f67dce1f820ee8, timestamp=2020-04-02 17:53:05 +0000 UTC 2020-04-02 18:19:31.828 [DBG] CRTR: Instantiating mission control with config: PenaltyHalfLife=1h0m0s, AprioriHopProbability=0.6, AprioriWeight=0.5 2020-04-02 18:19:31.828 [DBG] LNWL: Checking candidate block: height=23, hash=71e25e668b89f4c1549b2cdfcf5dc40c148d7572f1077bff95caab1bd2790b2a, timestamp=2020-04-02 17:53:01 +0000 UTC 2020-04-02 18:19:31.829 [DBG] CRTR: Mission control state reconstruction started 2020-04-02 18:19:31.829 [DBG] CRTR: Mission control state reconstruction finished: n=0, time=7.346µs 2020-04-02 18:19:31.829 [DBG] SRVR: Instantiating payment session source with config: PaymentAttemptPenalty=100, MinRouteProbability=0.01 2020-04-02 18:19:31.829 [DBG] LNWL: Checking candidate block: height=11, hash=708e40950247a83a217303ddb702927a047d79b95ac8adcaad1f17512f6bb5a2, timestamp=2020-04-02 17:52:59 +0000 UTC 2020-04-02 18:19:31.830 [DBG] LNWL: Checking candidate block: height=5, hash=152854b395c8607c54f194de1c6588af26481c4f40cf248eb88b37e6907a4506, timestamp=2020-04-02 17:52:58 +0000 UTC 2020-04-02 18:19:31.831 [DBG] LNWL: Checking candidate block: height=2, hash=13651cd84185fe1437b442329c1264999cc6f89a0b63f448091bd0c87baa29ce, timestamp=2020-04-02 17:52:57 +0000 UTC 2020-04-02 18:19:31.832 [DBG] LNWL: Checking candidate block: height=1, hash=6587958bc00ac4fa33b2d2d5bb9adf83c5d77157c0c7805dd19c60c95fcd681e, timestamp=2020-04-02 17:52:56 +0000 UTC 2020-04-02 18:19:31.833 [DBG] LNWL: Checking candidate block: height=0, hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, timestamp=2011-02-02 23:16:42 +0000 UTC 2020-04-02 18:19:31.833 [DBG] LNWL: Found birthday block: height=0, hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, timestamp=2011-02-02 23:16:42 +0000 UTC 2020-04-02 18:19:31.835 [INF] LNWL: RECOVERY MODE ENABLED -- rescanning for used addresses with recovery_window=1000 2020-04-02 18:19:31.838 [INF] LNWL: Seed birthday surpassed, starting recovery of wallet from height=1 hash=6587958bc00ac4fa33b2d2d5bb9adf83c5d77157c0c7805dd19c60c95fcd681e with recovery-window=1000 2020-04-02 18:19:31.840 [INF] SWPR: Migrating UTXO nursery finalized TXIDs 2020-04-02 18:19:31.841 [INF] LTND: Channel backup proxy channel notifier starting 2020-04-02 18:19:31.841 [INF] ATPL: Instantiating autopilot with active=false, max_channels=5, allocation=0.600000, min_chan_size=20000, max_chan_size=16777215, private=false, min_confs=1, conf_target=3 2020-04-02 18:19:31.841 [DBG] LTND: Populating dependencies for sub RPC server: SignRPC 2020-04-02 18:19:31.841 [DBG] LTND: Populating dependencies for sub RPC server: WalletKitRPC 2020-04-02 18:19:31.841 [DBG] LTND: Populating dependencies for sub RPC server: AutopilotRPC 2020-04-02 18:19:31.841 [DBG] LTND: Populating dependencies for sub RPC server: ChainRPC 2020-04-02 18:19:31.841 [DBG] LTND: Populating dependencies for sub RPC server: InvoicesRPC 2020-04-02 18:19:31.841 [DBG] LTND: Populating dependencies for sub RPC server: RouterRPC 2020-04-02 18:19:31.841 [DBG] LTND: Populating dependencies for sub RPC server: WatchtowerRPC 2020-04-02 18:19:31.841 [DBG] LTND: Populating dependencies for sub RPC server: WatchtowerClientRPC 2020-04-02 18:19:31.841 [INF] WLKT: Baking macaroons for WalletKit RPC Server at: /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/walletkit.macaroon 2020-04-02 18:19:31.842 [INF] RRPC: Making macaroons for Router RPC Server at: /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/router.macaroon 2020-04-02 18:19:31.842 [INF] SGNR: Making macaroons for Signer RPC Server at: /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/signer.macaroon 2020-04-02 18:19:31.843 [INF] NTFR: Baking macaroons for ChainNotifier RPC Server at: /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/chainnotifier.macaroon 2020-04-02 18:19:31.844 [INF] IRPC: Baking macaroons for invoices RPC Server at: /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/invoices.macaroon 2020-04-02 18:19:31.845 [DBG] WLKT: WalletKit RPC server successfully registered with root gRPC server 2020-04-02 18:19:31.845 [DBG] WTCL: WatchtowerClient RPC server successfully registered with root gRPC server 2020-04-02 18:19:31.845 [DBG] RRPC: Router RPC server successfully register with root gRPC server 2020-04-02 18:19:31.845 [DBG] SGNR: Signer RPC server successfully register with root gRPC server 2020-04-02 18:19:31.845 [DBG] ARPC: Autopilot RPC server successfully register with root gRPC server 2020-04-02 18:19:31.845 [DBG] NTFR: ChainNotifier RPC server successfully register with root gRPC server 2020-04-02 18:19:31.845 [DBG] IRPC: Invoices RPC server successfully registered with root gRPC server 2020-04-02 18:19:31.845 [DBG] RPCS: Starting sub RPC server: WalletKitRPC 2020-04-02 18:19:31.845 [DBG] RPCS: Starting sub RPC server: WatchtowerClientRPC 2020-04-02 18:19:31.845 [DBG] RPCS: Starting sub RPC server: WatchtowerRPC 2020-04-02 18:19:31.845 [DBG] RPCS: Starting sub RPC server: RouterRPC 2020-04-02 18:19:31.845 [DBG] RPCS: Starting sub RPC server: SignRPC 2020-04-02 18:19:31.845 [DBG] RPCS: Starting sub RPC server: AutopilotRPC 2020-04-02 18:19:31.845 [DBG] RPCS: Starting sub RPC server: ChainRPC 2020-04-02 18:19:31.845 [DBG] RPCS: Starting sub RPC server: InvoicesRPC 2020-04-02 18:19:31.845 [INF] RPCS: RPC server listening on 127.0.0.1:20081 2020-04-02 18:19:31.845 [INF] RPCS: gRPC proxy started at 127.0.0.1:20082 2020-04-02 18:19:31.851 [INF] PRNF: PeerNotifier starting 2020-04-02 18:19:31.855 [INF] HSWC: Starting HTLC Switch 2020-04-02 18:19:31.855 [INF] NTFN: New block epoch subscription 2020-04-02 18:19:31.855 [INF] NTFN: New block epoch subscription 2020-04-02 18:19:31.855 [INF] NTFN: New block epoch subscription 2020-04-02 18:19:31.856 [INF] NTFN: New block epoch subscription 2020-04-02 18:19:31.856 [INF] DISC: Authenticated Gossiper is starting 2020-04-02 18:19:31.856 [INF] BRAR: Starting contract observer, watching for breaches. 2020-04-02 18:19:31.858 [INF] NTFN: New block epoch subscription 2020-04-02 18:19:31.861 [INF] CRTR: FilteredChainView starting 2020-04-02 18:19:31.866 [INF] CRTR: Filtering chain using 0 channels active 2020-04-02 18:19:31.867 [INF] CRTR: Prune tip for Channel Graph: height=2945, hash=2908b34b8b12846e87bc03fce74eba41eb123a1af495c36059d3c175dc7b1950 2020-04-02 18:19:31.868 [DBG] INVC: Adding 0 pending invoices to the expiry watcher 2020-04-02 18:19:31.868 [INF] CHFT: Adding 0 channels to event store 2020-04-02 18:19:31.868 [INF] CHBU: Starting chanbackup.SubSwapper 2020-04-02 18:19:31.868 [DBG] CHBU: SubSwapper's backupUpdater is active! 2020-04-02 18:19:31.869 [INF] BTCN: Server listening on 127.0.0.1:20080 2020-04-02 18:19:31.869 [INF] SRVR: Auto peer bootstrapping is disabled 2020-04-02 18:19:31.871 [INF] CHBU: Updating backup file at /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/channel.backup 2020-04-02 18:19:31.873 [INF] CHBU: Swapping old multi backup file from /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/temp-dont-use.backup to /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/channel.backup 2020-04-02 18:19:32.827 [DBG] CRTR: New graph topology client subscription, client 1 2020-04-02 18:19:33.657 [INF] LNWL: Scanning 2000 blocks for recoverable addresses 2020-04-02 18:19:33.827 [DBG] CRTR: New graph topology client subscription, client 2 2020-04-02 18:19:35.348 [INF] LNWL: Recovered addresses from blocks 1-2000 2020-04-02 18:19:35.349 [INF] CHBU: Restoring ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) to disk: 2020-04-02 18:19:35.361 [INF] LTND: SCB Recovery: created channel shell for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0), chan_type=2 2020-04-02 18:19:35.361 [INF] LTND: Inserting 1 SCB channel shells into DB 2020-04-02 18:19:35.363 [INF] LTND: Informing chain watchers of new restored channels 2020-04-02 18:19:35.363 [INF] CNCT: Creating new ChannelArbitrator for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:35.363 [DBG] CNCT: New ChainEventSubscription(id=0) for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:35.363 [DBG] CNCT: Starting ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0), htlc_set=(map[contractcourt.HtlcSetKey]contractcourt.htlcSet) (len=2) { (contractcourt.HtlcSetKey) LocalHtlcSet: (contractcourt.htlcSet) { incomingHTLCs: (map[uint64]channeldb.HTLC) { }, outgoingHTLCs: (map[uint64]channeldb.HTLC) { } }, (contractcourt.HtlcSetKey) RemoteHtlcSet: (contractcourt.htlcSet) { incomingHTLCs: (map[uint64]channeldb.HTLC) { }, outgoingHTLCs: (map[uint64]channeldb.HTLC) { } } } 2020-04-02 18:19:35.363 [INF] NTFN: New block epoch subscription 2020-04-02 18:19:35.364 [INF] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): starting state=StateDefault, trigger=chainTrigger, triggerHeight=2945 2020-04-02 18:19:35.364 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): new block (height=2945) examining active HTLC's 2020-04-02 18:19:35.364 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): checking commit chain actions at height=2945, in_htlc_count=0, out_htlc_count=0 2020-04-02 18:19:35.365 [DBG] CNCT: Starting chain watcher for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:35.365 [INF] NTFN: New spend subscription: spend_id=1, outpoint=0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0, script=0 fce912056ec1945c8d54f6b659b3dbc790f37c8c88c55ab2c7b0fb61a10d2f3c, height_hint=2940 2020-04-02 18:19:35.365 [INF] NTFN: Dispatching historical spend rescan for outpoint=0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0, script=0 fce912056ec1945c8d54f6b659b3dbc790f37c8c88c55ab2c7b0fb61a10d2f3c, start=2940, end=2945 2020-04-02 18:19:35.365 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): new block (height=2945) examining active HTLC's 2020-04-02 18:19:35.365 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): checking commit chain actions at height=2945, in_htlc_count=0, out_htlc_count=0 2020-04-02 18:19:35.377 [DBG] NTFN: Updated spend hint to height=2945 for unconfirmed spend request outpoint=0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0, script=0 fce912056ec1945c8d54f6b659b3dbc790f37c8c88c55ab2c7b0fb61a10d2f3c 2020-04-02 18:19:35.377 [INF] CHBU: Attempting to connect to node=039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 (addrs=([]net.Addr) (len=1 cap=1) { (*net.TCPAddr)(0xc001b8c690)(127.0.0.1:20076) } ) to restore ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:35.377 [INF] LTND: Peer([3 149 147 81 141 110 32 202 240 2 243 122 101 129 144 84 195 101 215 158 72 118 51 14 49 203 1 253 167 54 68 132 185]) is already connected, proceeding with chan restore 2020-04-02 18:19:35.377 [INF] LTND: Attempting to connect to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 for SCB restore DLP 2020-04-02 18:19:35.377 [DBG] SRVR: Connecting to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.377 [INF] CNCT: Close observer for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) active 2020-04-02 18:19:35.377 [DBG] BTCN: Attempting to connect to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 (reqid 1) 2020-04-02 18:19:35.378 [INF] CHBU: Restoring ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) to disk: 2020-04-02 18:19:35.379 [DBG] BTCN: Connected to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 (reqid 1) 2020-04-02 18:19:35.379 [INF] SRVR: Established connection to: 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.379 [INF] SRVR: Finalizing connection to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076, inbound=false 2020-04-02 18:19:35.379 [DBG] PRNF: PeerNotifier notifying peer: 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 online 2020-04-02 18:19:35.379 [DBG] PEER: Sending Init to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.379 [DBG] PEER: Received Init from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.380 [DBG] PEER: Loaded 1 active channels from database with NodeKey(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9) 2020-04-02 18:19:35.382 [DBG] LNWL: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): starting local commitment: (*lnwallet.commitment)(0xc00033ad80)({ height: (uint64) 0, isOurs: (bool) true, ourMessageIndex: (uint64) 0, theirMessageIndex: (uint64) 0, ourHtlcIndex: (uint64) 0, theirHtlcIndex: (uint64) 0, txn: (*wire.MsgTx)(), sig: ([]uint8) , ourBalance: (lnwire.MilliSatoshi) 0 mSAT, theirBalance: (lnwire.MilliSatoshi) 0 mSAT, fee: (btcutil.Amount) 0 BTC, feePerKw: (chainfee.SatPerKWeight) 0 sat/kw, dustLimit: (btcutil.Amount) 0 BTC, outgoingHTLCs: ([]lnwallet.PaymentDescriptor) , incomingHTLCs: ([]lnwallet.PaymentDescriptor) , outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) { }, incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) { } }) 2020-04-02 18:19:35.383 [DBG] LNWL: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): starting remote commitment: (*lnwallet.commitment)(0xc00033ae40)({ height: (uint64) 0, isOurs: (bool) false, ourMessageIndex: (uint64) 0, theirMessageIndex: (uint64) 0, ourHtlcIndex: (uint64) 0, theirHtlcIndex: (uint64) 0, txn: (*wire.MsgTx)(), sig: ([]uint8) , ourBalance: (lnwire.MilliSatoshi) 0 mSAT, theirBalance: (lnwire.MilliSatoshi) 0 mSAT, fee: (btcutil.Amount) 0 BTC, feePerKw: (chainfee.SatPerKWeight) 0 sat/kw, dustLimit: (btcutil.Amount) 0 BTC, outgoingHTLCs: ([]lnwallet.PaymentDescriptor) , incomingHTLCs: ([]lnwallet.PaymentDescriptor) , outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) { }, incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) { } }) 2020-04-02 18:19:35.383 [DBG] LNWL: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): Restoring 0 dangling remote updates 2020-04-02 18:19:35.383 [INF] PEER: NodeKey(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9) loading ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:35.384 [DBG] CNCT: New ChainEventSubscription(id=1) for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:35.384 [INF] HSWC: Removing channel link with ChannelID(8d1200a08b3bfd8a7717e448791d54ec9e6a1baf766a3ed9a4db30ad4ccc6e0d) 2020-04-02 18:19:35.384 [INF] HSWC: ChannelLink(2940:1:0): starting 2020-04-02 18:19:35.386 [INF] HSWC: Trimming open circuits for chan_id=2940:1:0, start_htlc_id=0 2020-04-02 18:19:35.386 [INF] HSWC: Adding live link chan_id=8d1200a08b3bfd8a7717e448791d54ec9e6a1baf766a3ed9a4db30ad4ccc6e0d, short_chan_id=2940:1:0 2020-04-02 18:19:35.386 [DBG] SRVR: Notifying that peer 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 is online 2020-04-02 18:19:35.386 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:35.386 [INF] HSWC: ChannelLink(2940:1:0): HTLC manager started, bandwidth=0 mSAT 2020-04-02 18:19:35.386 [INF] HSWC: ChannelLink(2940:1:0): attempting to re-resynchronize 2020-04-02 18:19:35.386 [DBG] PEER: Sending ChannelReestablish(next_local_height=0, remote_tail_height=0) to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.386 [INF] SRVR: Negotiated chan series queries with 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 2020-04-02 18:19:35.386 [INF] DISC: Creating new GossipSyncer for peer=039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 2020-04-02 18:19:35.386 [DBG] DISC: Starting GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9) 2020-04-02 18:19:35.386 [DBG] DISC: Attempting initial historical sync with GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9) 2020-04-02 18:19:35.386 [DBG] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): state=chansSynced, type=PassiveSync 2020-04-02 18:19:35.386 [DBG] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): state=syncingChans, type=PassiveSync 2020-04-02 18:19:35.386 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): requesting new chans from height=0 and 4294967295 blocks after 2020-04-02 18:19:35.386 [DBG] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): state=waitingQueryRangeReply, type=PassiveSync 2020-04-02 18:19:35.386 [DBG] PEER: Received ChannelUpdate(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, short_chan_id=3232564185726976, mflags=00000001, cflags=00000001, update_time=2020-04-02 18:19:31 +0000 UTC) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.387 [DBG] PEER: Received ChannelReestablish(next_local_height=1, remote_tail_height=0) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.387 [DBG] PEER: Received AnnounceSignatures(chan_id=8d1200a08b3bfd8a7717e448791d54ec9e6a1baf766a3ed9a4db30ad4ccc6e0d, short_chan_id=3232564185726976) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.387 [DBG] PEER: Received QueryChannelRange(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, start_height=0, end_height=4294967294) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.387 [DBG] PEER: Sending QueryChannelRange(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, start_height=0, end_height=4294967294) to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.387 [INF] DISC: Received new remote channel announcement for 2940:1:0 2020-04-02 18:19:35.388 [INF] DISC: 1/2 of channel ann proof received for short_chan_id=3232564185726976, waiting for other half 2020-04-02 18:19:35.388 [INF] HSWC: ChannelLink(2940:1:0): received re-establishment message from remote side 2020-04-02 18:19:35.388 [ERR] LNWL: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): sync failed with local data loss: remote believes our tail height is 0, while we have 0! 2020-04-02 18:19:35.388 [WRN] LNWL: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): detected restored triggering DLP 2020-04-02 18:19:35.388 [WRN] HSWC: ChannelLink(2940:1:0): error when syncing channel states: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) with CommitPoint(030d148ba541ecfecd269de5c6f623a18376f74c76b6f9363ff36878d75841d242) had possible local commitment state data loss 2020-04-02 18:19:35.390 [INF] LTND: SCB Recovery: created channel shell for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0), chan_type=2 2020-04-02 18:19:35.390 [INF] LTND: Inserting 1 SCB channel shells into DB 2020-04-02 18:19:35.390 [ERR] HSWC: ChannelLink(2940:1:0): failing link: unable to synchronize channel states: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) with CommitPoint(030d148ba541ecfecd269de5c6f623a18376f74c76b6f9363ff36878d75841d242) had possible local commitment state data loss with error: unable to resume channel, recovery required 2020-04-02 18:19:35.390 [INF] HSWC: ChannelLink(2940:1:0): exited 2020-04-02 18:19:35.391 [DBG] PEER: Received ReplyChannelRange(start_height=0, end_height=4294967294, num_chans=1, encoding=0) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.391 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): buffering chan range reply of size=1 2020-04-02 18:19:35.391 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): filtering through 1 chans 2020-04-02 18:19:35.391 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): remote peer has no new chans 2020-04-02 18:19:35.391 [DBG] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): state=chansSynced, type=PassiveSync 2020-04-02 18:19:35.391 [DBG] DISC: Initial historical sync completed 2020-04-02 18:19:35.391 [DBG] DISC: Attempting to transition 3 passive GossipSyncers to active 2020-04-02 18:19:35.391 [DBG] DISC: Transitioning passive GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9) to active 2020-04-02 18:19:35.391 [DBG] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): transitioning from PassiveSync to ActiveSync 2020-04-02 18:19:35.391 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): applying gossipFilter(start=2020-04-02 18:19:35.391822075 +0000 UTC m=+3.710200297, end=2156-05-10 00:47:50.391822075 +0000 UTC m=+4294967298.710200297) 2020-04-02 18:19:35.391 [DBG] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): state=chansSynced, type=ActiveSync 2020-04-02 18:19:35.391 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): filtering chan range: start_height=0, num_blocks=4294967295 2020-04-02 18:19:35.391 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): sending final chan range chunk, size=1 2020-04-02 18:19:35.391 [DBG] PEER: Sending GossipTimestampRange(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, first_stamp=2020-04-02 18:19:35 +0000 UTC, stamp_range=4294967295) to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.391 [DBG] PEER: Sending ReplyChannelRange(start_height=0, end_height=4294967294, num_chans=1, encoding=0) to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.392 [INF] HSWC: Removing channel link with ChannelID(8d1200a08b3bfd8a7717e448791d54ec9e6a1baf766a3ed9a4db30ad4ccc6e0d) 2020-04-02 18:19:35.392 [INF] HSWC: ChannelLink(2940:1:0): stopping 2020-04-02 18:19:35.392 [ERR] RPCS: [/lnrpc.Lightning/SubscribeChannelGraph]: rpc error: code = Internal desc = transport: transport: the stream is done or WriteHeader was already called 2020-04-02 18:19:35.393 [DBG] PEER: Received GossipTimestampRange(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, first_stamp=2020-04-02 18:19:35 +0000 UTC, stamp_range=4294967295) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.393 [DBG] CHDB: ChanUpdatesInHorizon hit percentage: 0.000000 (0/1) 2020-04-02 18:19:35.393 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): applying new update horizon: start=2020-04-02 18:19:35 +0000 UTC, end=2156-05-10 00:47:50 +0000 UTC, backlog_size=0 2020-04-02 18:19:35.411 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.432 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.453 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.473 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.492 [DBG] PEER: Sending Error(chan_id=8d1200a08b3bfd8a7717e448791d54ec9e6a1baf766a3ed9a4db30ad4ccc6e0d, err=unable to resume channel, recovery required) to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.494 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.506 [DBG] PEER: Received ChannelUpdate(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, short_chan_id=3232564185726976, mflags=00000001, cflags=00000011, update_time=2020-04-02 18:19:35 +0000 UTC) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.514 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.526 [DBG] PEER: Received Error(chan_id=8d1200a08b3bfd8a7717e448791d54ec9e6a1baf766a3ed9a4db30ad4ccc6e0d, err=sync error) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:35.535 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.555 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.575 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.596 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.616 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.637 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.657 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.678 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.699 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.719 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.740 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.760 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.780 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.801 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.821 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.842 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.862 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.883 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.903 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.924 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.944 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.965 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:35.985 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.006 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.026 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.046 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.067 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.087 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.108 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.129 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.149 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.170 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.190 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.206 [INF] LNWL: Scanning 945 blocks for recoverable addresses 2020-04-02 18:19:36.211 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.231 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.252 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.272 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.293 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.313 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.334 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.354 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.374 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.395 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.415 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.436 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.456 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.477 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.498 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.518 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.539 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.559 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.580 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.602 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.623 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.643 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.664 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.685 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.705 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.719 [INF] LNWL: Recovered 1 external addrs at height=2934 hash=5bd2c32f3808bbf44e79c6f1cf07aa62b518de16523a693e6a51a794f5efa283 2020-04-02 18:19:36.719 [INF] LNWL: Found 1 spends from watched outpoints at height=2934 hash=5bd2c32f3808bbf44e79c6f1cf07aa62b518de16523a693e6a51a794f5efa283 2020-04-02 18:19:36.719 [DBG] LNWL: Marking transaction d4f735469da8f366286d0bbf3367fd4dd2ac1d42676f60308288635d96082581 output 0 (1 BTC) spendable 2020-04-02 18:19:36.720 [DBG] LNWL: Marked address bcrt1qp0q7073fyjx0tq7n0xufv5gjjkd6au3w6dqmdk used 2020-04-02 18:19:36.727 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.751 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.755 [INF] LNWL: Recovered 1 internal addrs at height=2940 hash=032d5187c74f89fbfc89985463feb1b455471bdc35f82a0514b90af190e8a086 2020-04-02 18:19:36.755 [INF] LNWL: Found 1 spends from watched outpoints at height=2940 hash=032d5187c74f89fbfc89985463feb1b455471bdc35f82a0514b90af190e8a086 2020-04-02 18:19:36.755 [DBG] LNWL: Marking transaction 0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d output 1 (0.89992363 BTC) spendable 2020-04-02 18:19:36.755 [DBG] LNWL: Marked address bcrt1qu8n77jyj09vuznts6hwhxuenjth9h4g9mj4l3u used 2020-04-02 18:19:36.772 [DBG] RPCS: [walletbalance] Total balance=0 BTC (confirmed=0 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.788 [INF] LNWL: Recovered addresses from blocks 2001-2945 2020-04-02 18:19:36.791 [INF] LNWL: Started rescan from block 2908b34b8b12846e87bc03fce74eba41eb123a1af495c36059d3c175dc7b1950 (height 2945) for 2 addresses 2020-04-02 18:19:36.792 [DBG] RPCS: [walletbalance] Total balance=0.89992363 BTC (confirmed=0.89992363 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:36.794 [INF] LNWL: Catching up block hashes to height 2945, this might take a while 2020-04-02 18:19:36.795 [INF] LNWL: Done catching up block hashes 2020-04-02 18:19:36.795 [INF] LNWL: Finished rescan for 2 addresses (synced to block 2908b34b8b12846e87bc03fce74eba41eb123a1af495c36059d3c175dc7b1950, height 2945) 2020-04-02 18:19:36.816 [DBG] RPCS: [connectpeer] requested connection to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:36.816 [ERR] RPCS: [connectpeer]: error connecting to peer: already connected to peer: 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:36.816 [ERR] RPCS: [/lnrpc.Lightning/ConnectPeer]: already connected to peer: 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:39.186 [DBG] RPCS: [pendingchannels] 2020-04-02 18:19:39.188 [INF] LTND: Received shutdown request. 2020-04-02 18:19:39.188 [INF] LTND: Shutting down... 2020-04-02 18:19:39.188 [INF] LTND: Gracefully shutting down. 2020-04-02 18:19:39.188 [INF] CRTR: FilteredChainView stopping 2020-04-02 18:19:39.188 [INF] HSWC: HTLC Switch shutting down 2020-04-02 18:19:39.188 [INF] HSWC: Block epoch canceled, decaying hash log shutting down 2020-04-02 18:19:39.189 [INF] UTXN: UTXO nursery shutting down 2020-04-02 18:19:39.189 [INF] BRAR: Breach arbiter shutting down 2020-04-02 18:19:39.189 [INF] DISC: Authenticated Gossiper is stopping 2020-04-02 18:19:39.189 [INF] CNCT: Stopping ChainArbitrator 2020-04-02 18:19:39.189 [DBG] CNCT: Stopping ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:39.189 [DBG] SWPR: Sweeper shutting down 2020-04-02 18:19:39.189 [DBG] SWPR: Sweeper shut down 2020-04-02 18:19:39.189 [INF] PRNF: Stopping PeerNotifier 2020-04-02 18:19:39.189 [INF] FNDG: Funding manager shutting down 2020-04-02 18:19:39.189 [INF] CHBU: Stopping chanbackup.SubSwapper 2020-04-02 18:19:39.189 [INF] CHFT: Stopping event store 2020-04-02 18:19:39.189 [INF] SRVR: Disconnecting from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:39.189 [DBG] SRVR: removing peer 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:39.189 [INF] PEER: disconnecting 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076, reason: server: disconnecting peer 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:39.189 [INF] PEER: unable to read message from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076: read tcp 127.0.0.1:40486->127.0.0.1:20076: use of closed network connection 2020-04-02 18:19:39.389 [DBG] SRVR: Peer 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 has been disconnected 2020-04-02 18:19:39.389 [INF] RPCS: Stopping RPC Server 2020-04-02 18:19:39.389 [INF] RPCS: Stopping WalletKitRPC Sub-RPC Server 2020-04-02 18:19:39.389 [INF] RPCS: Stopping WatchtowerClientRPC Sub-RPC Server 2020-04-02 18:19:39.389 [INF] RPCS: Stopping WatchtowerRPC Sub-RPC Server 2020-04-02 18:19:39.389 [INF] RPCS: Stopping RouterRPC Sub-RPC Server 2020-04-02 18:19:39.389 [INF] RPCS: Stopping SignRPC Sub-RPC Server 2020-04-02 18:19:39.389 [INF] RPCS: Stopping AutopilotRPC Sub-RPC Server 2020-04-02 18:19:39.389 [INF] RPCS: Stopping ChainRPC Sub-RPC Server 2020-04-02 18:19:39.389 [INF] RPCS: Stopping InvoicesRPC Sub-RPC Server 2020-04-02 18:19:39.390 [INF] LTND: Shutdown complete 2020-04-02 18:19:39.420 [WRN] LTND: read /tmp/lndtest-node639849499/data: is a directory 2020-04-02 18:19:39.420 [INF] LTND: Version: 0.9.0-beta commit=v0.9.0-beta-494-ga9b5e90df01a5d9ff622eb5b4bdf5f40306ec499, build=development, logging=default 2020-04-02 18:19:39.420 [INF] LTND: Active chain: Bitcoin (network=regtest) 2020-04-02 18:19:39.420 [INF] LTND: Opening the main database, this might take a few minutes... 2020-04-02 18:19:39.421 [INF] CHDB: Checking for schema update: latest_version=13, db_version=13 2020-04-02 18:19:39.421 [INF] LTND: Database now open (time_to_open=508.136µs)! 2020-04-02 18:19:39.429 [INF] RPCS: password gRPC proxy started at 127.0.0.1:20082 2020-04-02 18:19:39.429 [INF] RPCS: password RPC server listening on 127.0.0.1:20081 2020-04-02 18:19:39.429 [INF] LTND: Waiting for wallet encryption password. Use `lncli create` to create a wallet, `lncli unlock` to unlock an existing wallet, or `lncli changepassword` to change the password of an existing wallet and unlock it. 2020-04-02 18:19:40.401 [INF] LNWL: Opened wallet 2020-04-02 18:19:40.404 [INF] LTND: Primary chain is set to: bitcoin 2020-04-02 18:19:40.416 [INF] LNWL: Started listening for bitcoind transaction notifications via ZMQ on //tmp/bitcoind295918325/txs.socket 2020-04-02 18:19:40.416 [INF] LNWL: Started listening for bitcoind block notifications via ZMQ on //tmp/bitcoind295918325/blocks.socket 2020-04-02 18:19:40.419 [INF] LNWL: The wallet has been unlocked without a time limit 2020-04-02 18:19:40.422 [INF] LTND: LightningWallet opened 2020-04-02 18:19:40.423 [DBG] LNWL: Birthday block has already been verified: height=0, hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206 2020-04-02 18:19:40.426 [INF] HSWC: Restoring in-memory circuit state from disk 2020-04-02 18:19:40.426 [INF] HSWC: Payment circuits loaded: num_pending=0, num_open=0 2020-04-02 18:19:40.429 [INF] LNWL: Started rescan from block 2908b34b8b12846e87bc03fce74eba41eb123a1af495c36059d3c175dc7b1950 (height 2945) for 2 addresses 2020-04-02 18:19:40.429 [DBG] CRTR: Instantiating mission control with config: PenaltyHalfLife=1h0m0s, AprioriHopProbability=0.6, AprioriWeight=0.5 2020-04-02 18:19:40.430 [DBG] CRTR: Mission control state reconstruction started 2020-04-02 18:19:40.430 [DBG] CRTR: Mission control state reconstruction finished: n=0, time=6.433µs 2020-04-02 18:19:40.430 [DBG] SRVR: Instantiating payment session source with config: PaymentAttemptPenalty=100, MinRouteProbability=0.01 2020-04-02 18:19:40.431 [INF] LNWL: Catching up block hashes to height 2945, this might take a while 2020-04-02 18:19:40.432 [INF] LNWL: Done catching up block hashes 2020-04-02 18:19:40.432 [INF] LNWL: Finished rescan for 2 addresses (synced to block 2908b34b8b12846e87bc03fce74eba41eb123a1af495c36059d3c175dc7b1950, height 2945) 2020-04-02 18:19:40.441 [DBG] CHBU: Crafting backup for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:40.442 [INF] LTND: Channel backup proxy channel notifier starting 2020-04-02 18:19:40.442 [INF] ATPL: Instantiating autopilot with active=false, max_channels=5, allocation=0.600000, min_chan_size=20000, max_chan_size=16777215, private=false, min_confs=1, conf_target=3 2020-04-02 18:19:40.442 [DBG] LTND: Populating dependencies for sub RPC server: SignRPC 2020-04-02 18:19:40.442 [DBG] LTND: Populating dependencies for sub RPC server: WalletKitRPC 2020-04-02 18:19:40.442 [DBG] LTND: Populating dependencies for sub RPC server: AutopilotRPC 2020-04-02 18:19:40.442 [DBG] LTND: Populating dependencies for sub RPC server: ChainRPC 2020-04-02 18:19:40.442 [DBG] LTND: Populating dependencies for sub RPC server: InvoicesRPC 2020-04-02 18:19:40.442 [DBG] LTND: Populating dependencies for sub RPC server: RouterRPC 2020-04-02 18:19:40.442 [DBG] LTND: Populating dependencies for sub RPC server: WatchtowerRPC 2020-04-02 18:19:40.442 [DBG] LTND: Populating dependencies for sub RPC server: WatchtowerClientRPC 2020-04-02 18:19:40.442 [DBG] RRPC: Router RPC server successfully register with root gRPC server 2020-04-02 18:19:40.442 [DBG] SGNR: Signer RPC server successfully register with root gRPC server 2020-04-02 18:19:40.442 [DBG] ARPC: Autopilot RPC server successfully register with root gRPC server 2020-04-02 18:19:40.442 [DBG] NTFR: ChainNotifier RPC server successfully register with root gRPC server 2020-04-02 18:19:40.442 [DBG] IRPC: Invoices RPC server successfully registered with root gRPC server 2020-04-02 18:19:40.442 [DBG] WLKT: WalletKit RPC server successfully registered with root gRPC server 2020-04-02 18:19:40.442 [DBG] WTCL: WatchtowerClient RPC server successfully registered with root gRPC server 2020-04-02 18:19:40.442 [DBG] RPCS: Starting sub RPC server: RouterRPC 2020-04-02 18:19:40.442 [DBG] RPCS: Starting sub RPC server: SignRPC 2020-04-02 18:19:40.442 [DBG] RPCS: Starting sub RPC server: AutopilotRPC 2020-04-02 18:19:40.442 [DBG] RPCS: Starting sub RPC server: ChainRPC 2020-04-02 18:19:40.442 [DBG] RPCS: Starting sub RPC server: InvoicesRPC 2020-04-02 18:19:40.442 [DBG] RPCS: Starting sub RPC server: WalletKitRPC 2020-04-02 18:19:40.442 [DBG] RPCS: Starting sub RPC server: WatchtowerClientRPC 2020-04-02 18:19:40.442 [DBG] RPCS: Starting sub RPC server: WatchtowerRPC 2020-04-02 18:19:40.442 [INF] RPCS: RPC server listening on 127.0.0.1:20081 2020-04-02 18:19:40.442 [INF] RPCS: gRPC proxy started at 127.0.0.1:20082 2020-04-02 18:19:40.446 [INF] PRNF: PeerNotifier starting 2020-04-02 18:19:40.446 [INF] HSWC: Starting HTLC Switch 2020-04-02 18:19:40.446 [INF] NTFN: New block epoch subscription 2020-04-02 18:19:40.446 [INF] NTFN: New block epoch subscription 2020-04-02 18:19:40.447 [INF] NTFN: New block epoch subscription 2020-04-02 18:19:40.448 [INF] CNCT: Creating ChannelArbitrators for 1 active channels 2020-04-02 18:19:40.448 [DBG] CNCT: New ChainEventSubscription(id=0) for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:40.448 [INF] NTFN: New block epoch subscription 2020-04-02 18:19:40.449 [INF] NTFN: New block epoch subscription 2020-04-02 18:19:40.449 [DBG] CNCT: Starting chain watcher for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:40.449 [DBG] NTFN: Using height hint 2945 retrieved from cache for outpoint=0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0, script=0 fce912056ec1945c8d54f6b659b3dbc790f37c8c88c55ab2c7b0fb61a10d2f3c instead of 2940 2020-04-02 18:19:40.449 [INF] NTFN: New spend subscription: spend_id=1, outpoint=0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0, script=0 fce912056ec1945c8d54f6b659b3dbc790f37c8c88c55ab2c7b0fb61a10d2f3c, height_hint=2945 2020-04-02 18:19:40.449 [INF] NTFN: Dispatching historical spend rescan for outpoint=0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0, script=0 fce912056ec1945c8d54f6b659b3dbc790f37c8c88c55ab2c7b0fb61a10d2f3c, start=2945, end=2945 2020-04-02 18:19:40.451 [INF] CNCT: Close observer for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) active 2020-04-02 18:19:40.451 [DBG] CNCT: Starting ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0), htlc_set=(map[contractcourt.HtlcSetKey]contractcourt.htlcSet) (len=2) { (contractcourt.HtlcSetKey) LocalHtlcSet: (contractcourt.htlcSet) { incomingHTLCs: (map[uint64]channeldb.HTLC) { }, outgoingHTLCs: (map[uint64]channeldb.HTLC) { } }, (contractcourt.HtlcSetKey) RemoteHtlcSet: (contractcourt.htlcSet) { incomingHTLCs: (map[uint64]channeldb.HTLC) { }, outgoingHTLCs: (map[uint64]channeldb.HTLC) { } } } 2020-04-02 18:19:40.452 [INF] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): starting state=StateDefault, trigger=chainTrigger, triggerHeight=2945 2020-04-02 18:19:40.452 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): new block (height=2945) examining active HTLC's 2020-04-02 18:19:40.452 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): checking commit chain actions at height=2945, in_htlc_count=0, out_htlc_count=0 2020-04-02 18:19:40.452 [INF] DISC: Authenticated Gossiper is starting 2020-04-02 18:19:40.452 [INF] NTFN: New block epoch subscription 2020-04-02 18:19:40.452 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): new block (height=2945) examining active HTLC's 2020-04-02 18:19:40.452 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): checking commit chain actions at height=2945, in_htlc_count=0, out_htlc_count=0 2020-04-02 18:19:40.452 [INF] BRAR: Starting contract observer, watching for breaches. 2020-04-02 18:19:40.452 [INF] NTFN: Historical spend dispatch finished for request outpoint=0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0, script=0 fce912056ec1945c8d54f6b659b3dbc790f37c8c88c55ab2c7b0fb61a10d2f3c (start=2945 end=2945) with details: 2020-04-02 18:19:40.453 [DBG] DISC: Skipping retransmission of channel without AuthProof: 3232564185726976 2020-04-02 18:19:40.453 [INF] CRTR: FilteredChainView starting 2020-04-02 18:19:40.456 [INF] CRTR: Filtering chain using 1 channels active 2020-04-02 18:19:40.457 [INF] CRTR: Prune tip for Channel Graph: height=2945, hash=2908b34b8b12846e87bc03fce74eba41eb123a1af495c36059d3c175dc7b1950 2020-04-02 18:19:40.458 [DBG] INVC: Adding 0 pending invoices to the expiry watcher 2020-04-02 18:19:40.459 [INF] CHFT: Adding 0 channels to event store 2020-04-02 18:19:40.459 [INF] CHBU: Starting chanbackup.SubSwapper 2020-04-02 18:19:40.460 [DBG] CHBU: SubSwapper's backupUpdater is active! 2020-04-02 18:19:40.460 [DBG] SRVR: Attempting persistent connection to channel peer 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.460 [INF] SRVR: Auto peer bootstrapping is disabled 2020-04-02 18:19:40.460 [DBG] LNWL: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): starting local commitment: (*lnwallet.commitment)(0xc00001cc00)({ height: (uint64) 0, isOurs: (bool) true, ourMessageIndex: (uint64) 0, theirMessageIndex: (uint64) 0, ourHtlcIndex: (uint64) 0, theirHtlcIndex: (uint64) 0, txn: (*wire.MsgTx)(), sig: ([]uint8) , ourBalance: (lnwire.MilliSatoshi) 0 mSAT, theirBalance: (lnwire.MilliSatoshi) 0 mSAT, fee: (btcutil.Amount) 0 BTC, feePerKw: (chainfee.SatPerKWeight) 0 sat/kw, dustLimit: (btcutil.Amount) 0 BTC, outgoingHTLCs: ([]lnwallet.PaymentDescriptor) , incomingHTLCs: ([]lnwallet.PaymentDescriptor) , outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) { }, incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) { } }) 2020-04-02 18:19:40.461 [INF] BTCN: Server listening on 127.0.0.1:20080 2020-04-02 18:19:40.461 [DBG] BTCN: Attempting to connect to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 (reqid 1) 2020-04-02 18:19:40.462 [INF] CHBU: Updating backup file at /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/channel.backup 2020-04-02 18:19:40.463 [DBG] LNWL: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): starting remote commitment: (*lnwallet.commitment)(0xc0002e2fc0)({ height: (uint64) 0, isOurs: (bool) false, ourMessageIndex: (uint64) 0, theirMessageIndex: (uint64) 0, ourHtlcIndex: (uint64) 0, theirHtlcIndex: (uint64) 0, txn: (*wire.MsgTx)(), sig: ([]uint8) , ourBalance: (lnwire.MilliSatoshi) 0 mSAT, theirBalance: (lnwire.MilliSatoshi) 0 mSAT, fee: (btcutil.Amount) 0 BTC, feePerKw: (chainfee.SatPerKWeight) 0 sat/kw, dustLimit: (btcutil.Amount) 0 BTC, outgoingHTLCs: ([]lnwallet.PaymentDescriptor) , incomingHTLCs: ([]lnwallet.PaymentDescriptor) , outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) { }, incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) { } }) 2020-04-02 18:19:40.463 [DBG] BTCN: Connected to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 (reqid 1) 2020-04-02 18:19:40.463 [INF] SRVR: Established connection to: 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.463 [INF] SRVR: Finalizing connection to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076, inbound=false 2020-04-02 18:19:40.464 [DBG] LNWL: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): Restoring 0 dangling remote updates 2020-04-02 18:19:40.464 [DBG] PRNF: PeerNotifier notifying peer: 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 online 2020-04-02 18:19:40.464 [DBG] FNDG: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) with chan_id=8d1200a08b3bfd8a7717e448791d54ec9e6a1baf766a3ed9a4db30ad4ccc6e0d not found in opening database, assuming already announced to the network 2020-04-02 18:19:40.464 [INF] CHBU: Swapping old multi backup file from /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/temp-dont-use.backup to /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/channel.backup 2020-04-02 18:19:40.464 [DBG] PEER: Sending Init to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.464 [DBG] PEER: Received Init from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.464 [DBG] PEER: Loaded 1 active channels from database with NodeKey(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9) 2020-04-02 18:19:40.466 [DBG] LNWL: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): starting local commitment: (*lnwallet.commitment)(0xc00001ccc0)({ height: (uint64) 0, isOurs: (bool) true, ourMessageIndex: (uint64) 0, theirMessageIndex: (uint64) 0, ourHtlcIndex: (uint64) 0, theirHtlcIndex: (uint64) 0, txn: (*wire.MsgTx)(), sig: ([]uint8) , ourBalance: (lnwire.MilliSatoshi) 0 mSAT, theirBalance: (lnwire.MilliSatoshi) 0 mSAT, fee: (btcutil.Amount) 0 BTC, feePerKw: (chainfee.SatPerKWeight) 0 sat/kw, dustLimit: (btcutil.Amount) 0 BTC, outgoingHTLCs: ([]lnwallet.PaymentDescriptor) , incomingHTLCs: ([]lnwallet.PaymentDescriptor) , outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) { }, incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) { } }) 2020-04-02 18:19:40.468 [DBG] LNWL: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): starting remote commitment: (*lnwallet.commitment)(0xc00001cd80)({ height: (uint64) 0, isOurs: (bool) false, ourMessageIndex: (uint64) 0, theirMessageIndex: (uint64) 0, ourHtlcIndex: (uint64) 0, theirHtlcIndex: (uint64) 0, txn: (*wire.MsgTx)(), sig: ([]uint8) , ourBalance: (lnwire.MilliSatoshi) 0 mSAT, theirBalance: (lnwire.MilliSatoshi) 0 mSAT, fee: (btcutil.Amount) 0 BTC, feePerKw: (chainfee.SatPerKWeight) 0 sat/kw, dustLimit: (btcutil.Amount) 0 BTC, outgoingHTLCs: ([]lnwallet.PaymentDescriptor) , incomingHTLCs: ([]lnwallet.PaymentDescriptor) , outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) { }, incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) { } }) 2020-04-02 18:19:40.468 [DBG] LNWL: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): Restoring 0 dangling remote updates 2020-04-02 18:19:40.469 [INF] PEER: NodeKey(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9) loading ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:40.469 [WRN] PEER: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) has status ChanStatusDefault|ChanStatusLocalDataLoss|ChanStatusRestored, won't start. 2020-04-02 18:19:40.469 [INF] PEER: Sending 1 channel sync messages to peer after loading active channels 2020-04-02 18:19:40.469 [DBG] PEER: Sending ChannelReestablish(next_local_height=0, remote_tail_height=0) to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.469 [INF] SRVR: Negotiated chan series queries with 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 2020-04-02 18:19:40.469 [INF] DISC: Creating new GossipSyncer for peer=039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 2020-04-02 18:19:40.469 [DBG] DISC: Starting GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9) 2020-04-02 18:19:40.469 [DBG] DISC: Attempting initial historical sync with GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9) 2020-04-02 18:19:40.469 [DBG] SRVR: Notifying that peer 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 is online 2020-04-02 18:19:40.469 [DBG] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): state=chansSynced, type=PassiveSync 2020-04-02 18:19:40.469 [DBG] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): state=syncingChans, type=PassiveSync 2020-04-02 18:19:40.469 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): requesting new chans from height=0 and 4294967295 blocks after 2020-04-02 18:19:40.469 [DBG] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): state=waitingQueryRangeReply, type=PassiveSync 2020-04-02 18:19:40.469 [DBG] PEER: Sending QueryChannelRange(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, start_height=0, end_height=4294967294) to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.469 [DBG] PEER: Received ChannelReestablish(next_local_height=1, remote_tail_height=0) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.469 [ERR] PEER: resend failed: unable to fetch channel sync messages for peer 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076: unable to find closed channel summary 2020-04-02 18:19:40.469 [DBG] PEER: Received QueryChannelRange(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, start_height=0, end_height=4294967294) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.469 [DBG] PEER: Received ChannelUpdate(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, short_chan_id=3232564185726976, mflags=00000001, cflags=00000001, update_time=2020-04-02 18:19:31 +0000 UTC) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.469 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): filtering chan range: start_height=0, num_blocks=4294967295 2020-04-02 18:19:40.469 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): sending final chan range chunk, size=1 2020-04-02 18:19:40.469 [DBG] PEER: Sending ReplyChannelRange(start_height=0, end_height=4294967294, num_chans=1, encoding=0) to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.469 [DBG] NTFN: Updated spend hint to height=2945 for unconfirmed spend request outpoint=0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0, script=0 fce912056ec1945c8d54f6b659b3dbc790f37c8c88c55ab2c7b0fb61a10d2f3c 2020-04-02 18:19:40.470 [DBG] PEER: Received ReplyChannelRange(start_height=0, end_height=4294967294, num_chans=1, encoding=0) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.470 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): buffering chan range reply of size=1 2020-04-02 18:19:40.470 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): filtering through 1 chans 2020-04-02 18:19:40.470 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): remote peer has no new chans 2020-04-02 18:19:40.470 [DBG] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): state=chansSynced, type=PassiveSync 2020-04-02 18:19:40.470 [DBG] DISC: Initial historical sync completed 2020-04-02 18:19:40.470 [DBG] DISC: Attempting to transition 3 passive GossipSyncers to active 2020-04-02 18:19:40.470 [DBG] DISC: Transitioning passive GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9) to active 2020-04-02 18:19:40.470 [DBG] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): transitioning from PassiveSync to ActiveSync 2020-04-02 18:19:40.470 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): applying gossipFilter(start=2020-04-02 18:19:40.470251176 +0000 UTC m=+1.075874573, end=2156-05-10 00:47:55.470251176 +0000 UTC m=+4294967296.075874573) 2020-04-02 18:19:40.470 [DBG] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): state=chansSynced, type=ActiveSync 2020-04-02 18:19:40.470 [DBG] PEER: Sending GossipTimestampRange(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, first_stamp=2020-04-02 18:19:40 +0000 UTC, stamp_range=4294967295) to 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.470 [DBG] PEER: Received GossipTimestampRange(chain_hash=0f9188f13cb7b2c71f2a335e3a4fc328bf5beb436012afca590b1a11466e2206, first_stamp=2020-04-02 18:19:40 +0000 UTC, stamp_range=4294967295) from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:40.470 [DBG] CHDB: ChanUpdatesInHorizon hit percentage: NaN (0/0) 2020-04-02 18:19:40.470 [INF] DISC: GossipSyncer(039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9): applying new update horizon: start=2020-04-02 18:19:40 +0000 UTC, end=2156-05-10 00:47:55 +0000 UTC, backlog_size=0 2020-04-02 18:19:41.447 [DBG] CRTR: New graph topology client subscription, client 1 2020-04-02 18:19:42.448 [DBG] CRTR: New graph topology client subscription, client 2 2020-04-02 18:19:42.511 [DBG] LNWL: Filtering block 2946 (75d6b790ed0ca78d17d59ebe95c2553e73d6c394063861ccef30fcda0986c71f) with 2 transactions 2020-04-02 18:19:42.511 [DBG] LNWL: Filtering block 2946 (75d6b790ed0ca78d17d59ebe95c2553e73d6c394063861ccef30fcda0986c71f) with 2 transactions 2020-04-02 18:19:42.511 [INF] CRTR: Pruning channel graph using block 75d6b790ed0ca78d17d59ebe95c2553e73d6c394063861ccef30fcda0986c71f (height=2946) 2020-04-02 18:19:42.511 [INF] CHDB: Pruned unconnected node 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 from channel graph 2020-04-02 18:19:42.511 [INF] CHDB: Pruned 1 unconnected nodes from the channel graph 2020-04-02 18:19:42.511 [DBG] LNWL: Filtering block 2946 (75d6b790ed0ca78d17d59ebe95c2553e73d6c394063861ccef30fcda0986c71f) with 2 transactions 2020-04-02 18:19:42.512 [DBG] NTFN: Found spend of outpoint=0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0, script=0 fce912056ec1945c8d54f6b659b3dbc790f37c8c88c55ab2c7b0fb61a10d2f3c: spend_tx=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4, block_height=2946 2020-04-02 18:19:42.514 [INF] CRTR: Block 75d6b790ed0ca78d17d59ebe95c2553e73d6c394063861ccef30fcda0986c71f (height=2946) closed 1 channels 2020-04-02 18:19:42.514 [ERR] RPCS: [/lnrpc.Lightning/SubscribeChannelGraph]: rpc error: code = Internal desc = transport: transport: the stream is done or WriteHeader was already called 2020-04-02 18:19:42.515 [DBG] NTFN: Filtering 2 txns for 1 spend requests at height 2946 2020-04-02 18:19:42.515 [DBG] NTFN: Found spend of outpoint=0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0, script=0 fce912056ec1945c8d54f6b659b3dbc790f37c8c88c55ab2c7b0fb61a10d2f3c: spend_tx=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4, block_height=2946 2020-04-02 18:19:42.515 [DBG] NTFN: Spend request outpoint=0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0, script=0 fce912056ec1945c8d54f6b659b3dbc790f37c8c88c55ab2c7b0fb61a10d2f3c spent at tip=2946 2020-04-02 18:19:42.526 [INF] NTFN: New block: height=2946, sha=75d6b790ed0ca78d17d59ebe95c2553e73d6c394063861ccef30fcda0986c71f 2020-04-02 18:19:42.526 [INF] NTFN: Dispatching confirmed spend notification for outpoint=0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0, script=0 fce912056ec1945c8d54f6b659b3dbc790f37c8c88c55ab2c7b0fb61a10d2f3c at current height=2946: 972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4[0] spending 0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0 at height=2946 2020-04-02 18:19:42.527 [WRN] CNCT: Unprompted commitment broadcast for ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:42.527 [WRN] CNCT: Remote node broadcast state #0, which is more than 1 beyond best known state #0!!! Attempting recovery... 2020-04-02 18:19:42.527 [INF] CNCT: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) is tweakless, moving to sweep directly on chain 2020-04-02 18:19:42.527 [INF] CNCT: Unilateral close of ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) detected 2020-04-02 18:19:42.528 [INF] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): remote party has closed channel out on-chain 2020-04-02 18:19:42.528 [DBG] SWPR: New block: height=2946, sha=75d6b790ed0ca78d17d59ebe95c2553e73d6c394063861ccef30fcda0986c71f 2020-04-02 18:19:42.528 [INF] UTXN: Attempting to graduate height=2946: num_kids=0, num_babies=0 2020-04-02 18:19:42.552 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): new block (height=2946) examining active HTLC's 2020-04-02 18:19:42.552 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): checking commit chain actions at height=2946, in_htlc_count=0, out_htlc_count=0 yeee: *bdb.db 2020-04-02 18:19:42.552 [ERR] CHFT: Close channel 0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0 unknown to store 2020-04-02 18:19:42.552 [DBG] CHBU: Removing channel 0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0 from backup state 2020-04-02 18:19:42.552 [INF] CHBU: Updating on-disk multi SCB backup: num_old_chans=1, num_new_chans=0 2020-04-02 18:19:42.553 [INF] CHBU: Updating backup file at /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/channel.backup 2020-04-02 18:19:42.555 [INF] CHBU: Swapping old multi backup file from /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/temp-dont-use.backup to /tmp/lndtest-node639849499/data/chain/bitcoin/regtest/channel.backup 2020-04-02 18:19:42.563 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): checking commit chain actions at height=2946, in_htlc_count=0, out_htlc_count=0 2020-04-02 18:19:42.564 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): sending resolution message=([]contractcourt.ResolutionMsg) 2020-04-02 18:19:42.564 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): inserting 1 contract resolvers yeee: *bdb.db 2020-04-02 18:19:42.575 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): attempting to resolve *contractcourt.commitSweepResolver 2020-04-02 18:19:42.575 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): contract *contractcourt.commitSweepResolver not yet resolved 2020-04-02 18:19:42.575 [INF] NTFN: New confirmation subscription: conf_id=1, txid=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4, num_confs=1 height_hint=2946 2020-04-02 18:19:42.575 [DBG] NTFN: Dispatching historical confirmation rescan for txid=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4 2020-04-02 18:19:42.577 [DBG] NTFN: Updating confirmation details for txid=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4 2020-04-02 18:19:42.586 [INF] NTFN: Dispatching 1 confirmation notification for txid=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4 2020-04-02 18:19:42.586 [INF] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): still awaiting contract resolution 2020-04-02 18:19:42.586 [INF] NTFN: Canceling confirmation notification: conf_id=1, txid=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4 2020-04-02 18:19:42.586 [DBG] CNCT: *contractcourt.commitSweepResolver(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): commit conf_height=2946, unlock_height=2946 2020-04-02 18:19:42.586 [DBG] CNCT: *contractcourt.commitSweepResolver(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): isDelayedOutput=false, isLocalCommitTx=false 2020-04-02 18:19:42.586 [INF] CNCT: *contractcourt.commitSweepResolver(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): Sweeping with witness type: CommitmentNoDelayTweakless 2020-04-02 18:19:42.586 [INF] CNCT: *contractcourt.commitSweepResolver(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): sweeping commit output 2020-04-02 18:19:42.586 [INF] SWPR: Sweep request received: out_point=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0, witness_type=CommitmentNoDelayTweakless, time_lock=0, amount=0.0499095 BTC, params=(fee=6 blocks, force=false, exclusive_group=) 2020-04-02 18:19:42.586 [DBG] SWPR: Wait for spend of 972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0 2020-04-02 18:19:42.586 [INF] NTFN: New spend subscription: spend_id=2, outpoint=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0, script=0 023bbcd08957e04e8d2bb9ee98788d99993bda0e, height_hint=2946 2020-04-02 18:19:42.586 [INF] NTFN: Dispatching historical spend rescan for outpoint=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0, script=0 023bbcd08957e04e8d2bb9ee98788d99993bda0e, start=2946, end=2946 2020-04-02 18:19:42.598 [DBG] NTFN: Updated spend hint to height=2946 for unconfirmed spend request outpoint=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0, script=0 023bbcd08957e04e8d2bb9ee98788d99993bda0e 2020-04-02 18:19:42.598 [INF] SWPR: Candidate sweep set of size=1 (+0 wallet inputs), has yield=0.04985463 BTC, weight=439 2020-04-02 18:19:42.598 [DBG] SWPR: Sweep candidates at height=2946: total_num_pending=0, total_num_new=1 2020-04-02 18:19:42.598 [INF] SWPR: Sweep candidates at height=2946 with fee_rate=12500 sat/kw, yield 1 distinct txns 2020-04-02 18:19:42.598 [DBG] SWPR: Sweep timer started 2020-04-02 18:19:44.598 [DBG] SWPR: Sweep timer expired 2020-04-02 18:19:44.598 [INF] SWPR: Candidate sweep set of size=1 (+0 wallet inputs), has yield=0.04985463 BTC, weight=439 2020-04-02 18:19:44.598 [DBG] SWPR: Sweep candidates at height=2946: total_num_pending=0, total_num_new=1 2020-04-02 18:19:44.602 [INF] SWPR: Creating sweep transaction ee5eb61c540718ba4b20acf32ed0d55d1e743c08539a451c749524bee01daf81 for 1 inputs (972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0 (CommitmentNoDelayTweakless)) using 12500 sat/kw, tx_fee=0.00005487 BTC 2020-04-02 18:19:44.603 [DBG] SWPR: Publishing sweep tx ee5eb61c540718ba4b20acf32ed0d55d1e743c08539a451c749524bee01daf81, num_inputs=1, height=2946 2020-04-02 18:19:44.603 [INF] LNWL: Inserting unconfirmed transaction ee5eb61c540718ba4b20acf32ed0d55d1e743c08539a451c749524bee01daf81 2020-04-02 18:19:44.603 [DBG] LNWL: Marked address bcrt1q25znvlz7jts23uu6f4w0s9s2t73z0evplaq2ys used 2020-04-02 18:19:44.605 [DBG] LNWL: Marked address bcrt1q25znvlz7jts23uu6f4w0s9s2t73z0evplaq2ys used 2020-04-02 18:19:44.606 [DBG] SWPR: Rescheduling input 972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0 after 1 attempts at height 2947 (delta 1) 2020-04-02 18:19:45.874 [DBG] RPCS: [pendingchannels] 2020-04-02 18:19:45.876 [DBG] UTXN: NurseryReport: building nursery report for channel 0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0 2020-04-02 18:19:45.959 [DBG] LNWL: Filtering block 2947 (38b1c12afb2b17bbdc5cc9d7928271fdaab1a7ac010f6531d296b0c6061559f6) with 2 transactions 2020-04-02 18:19:45.959 [DBG] LNWL: Filtering block 2947 (38b1c12afb2b17bbdc5cc9d7928271fdaab1a7ac010f6531d296b0c6061559f6) with 2 transactions 2020-04-02 18:19:45.959 [DBG] LNWL: Filtering block 2947 (38b1c12afb2b17bbdc5cc9d7928271fdaab1a7ac010f6531d296b0c6061559f6) with 2 transactions 2020-04-02 18:19:45.959 [DBG] NTFN: Found spend of outpoint=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0, script=0 023bbcd08957e04e8d2bb9ee98788d99993bda0e: spend_tx=ee5eb61c540718ba4b20acf32ed0d55d1e743c08539a451c749524bee01daf81, block_height=2947 2020-04-02 18:19:45.959 [INF] CRTR: Pruning channel graph using block 38b1c12afb2b17bbdc5cc9d7928271fdaab1a7ac010f6531d296b0c6061559f6 (height=2947) 2020-04-02 18:19:45.961 [INF] CRTR: Block 38b1c12afb2b17bbdc5cc9d7928271fdaab1a7ac010f6531d296b0c6061559f6 (height=2947) closed 0 channels 2020-04-02 18:19:45.961 [INF] LNWL: Marking unconfirmed transaction ee5eb61c540718ba4b20acf32ed0d55d1e743c08539a451c749524bee01daf81 mined in block 2947 2020-04-02 18:19:45.961 [DBG] LNWL: Marked address bcrt1q25znvlz7jts23uu6f4w0s9s2t73z0evplaq2ys used 2020-04-02 18:19:45.963 [DBG] LNWL: Marked address bcrt1q25znvlz7jts23uu6f4w0s9s2t73z0evplaq2ys used 2020-04-02 18:19:45.965 [DBG] NTFN: Filtering 2 txns for 2 spend requests at height 2947 2020-04-02 18:19:45.965 [DBG] NTFN: Found spend of outpoint=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0, script=0 023bbcd08957e04e8d2bb9ee98788d99993bda0e: spend_tx=ee5eb61c540718ba4b20acf32ed0d55d1e743c08539a451c749524bee01daf81, block_height=2947 2020-04-02 18:19:45.965 [DBG] NTFN: Spend request outpoint=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0, script=0 023bbcd08957e04e8d2bb9ee98788d99993bda0e spent at tip=2947 2020-04-02 18:19:45.971 [DBG] RPCS: [pendingchannels] 2020-04-02 18:19:45.973 [DBG] UTXN: NurseryReport: building nursery report for channel 0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0 2020-04-02 18:19:45.976 [INF] NTFN: New block: height=2947, sha=38b1c12afb2b17bbdc5cc9d7928271fdaab1a7ac010f6531d296b0c6061559f6 2020-04-02 18:19:45.976 [INF] NTFN: Dispatching confirmed spend notification for outpoint=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0, script=0 023bbcd08957e04e8d2bb9ee98788d99993bda0e at current height=2947: ee5eb61c540718ba4b20acf32ed0d55d1e743c08539a451c749524bee01daf81[0] spending 972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0 at height=2947 2020-04-02 18:19:45.976 [DBG] SWPR: New block: height=2947, sha=38b1c12afb2b17bbdc5cc9d7928271fdaab1a7ac010f6531d296b0c6061559f6 2020-04-02 18:19:45.976 [DBG] SWPR: Delivering spend ntfn for 972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0 2020-04-02 18:19:45.976 [INF] UTXN: Attempting to graduate height=2947: num_kids=0, num_babies=0 2020-04-02 18:19:45.976 [INF] SWPR: Candidate sweep set of size=1 (+0 wallet inputs), has yield=0.04985463 BTC, weight=439 2020-04-02 18:19:45.976 [DBG] SWPR: Sweep candidates at height=2947: total_num_pending=1, total_num_new=0 2020-04-02 18:19:45.976 [INF] SWPR: Sweep candidates at height=2947 with fee_rate=12500 sat/kw, yield 1 distinct txns 2020-04-02 18:19:45.976 [DBG] SWPR: Sweep timer started 2020-04-02 18:19:45.976 [DBG] SWPR: Detected spend related to in flight inputs (is_ours=(*wire.MsgTx)(0xc0011b0ec0)({ Version: (int32) 2, TxIn: ([]*wire.TxIn) (len=1 cap=1) { (*wire.TxIn)(0xc00119f8c0)({ PreviousOutPoint: (wire.OutPoint) 972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0, SignatureScript: ([]uint8) { }, Witness: (wire.TxWitness) (len=2 cap=2) { ([]uint8) (len=72 cap=72) { 00000000 30 45 02 21 00 df 07 bb a3 cd 8e cb ac a8 a5 d2 |0E.!............| 00000010 bc 27 7f 85 97 0d 36 a7 4d 16 1e e6 6d 11 10 4c |.'....6.M...m..L| 00000020 42 68 ff ff a8 02 20 3a ef f8 04 8f a4 03 22 59 |Bh.... :......"Y| 00000030 47 c0 2d 56 0c 5a 15 df af d4 b2 6f 07 e3 07 7b |G.-V.Z.....o...{| 00000040 f4 e1 c1 1a 74 e6 ce 01 |....t...| }, ([]uint8) (len=33 cap=33) { 00000000 02 c8 71 a1 ae 53 fd ff 51 9a f5 e6 65 84 64 a1 |..q..S..Q...e.d.| 00000010 f8 b6 5b a2 b6 5d 85 e6 43 6b ce 5d 8b d0 17 68 |..[..]..Ck.]...h| 00000020 75 |u| } }, Sequence: (uint32) 0 }) }, TxOut: ([]*wire.TxOut) (len=1 cap=1) { (*wire.TxOut)(0xc0011cf4c0)({ Value: (int64) 4985463, PkScript: ([]uint8) (len=22 cap=22) { 00000000 00 14 55 05 36 7c 5e 92 e0 a8 f3 9a 4d 5c f8 16 |..U.6|^.....M\..| 00000010 0a 5f a2 27 e5 81 |._.'..| } }) }, LockTime: (uint32) 2946 }) ): true 2020-04-02 18:19:45.976 [DBG] SWPR: Dispatching sweep success for 972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0 to 1 listeners 2020-04-02 18:19:45.976 [DBG] SWPR: Canceling spend ntfn for 972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0 2020-04-02 18:19:45.976 [INF] NTFN: Canceling spend notification: spend_id=2, outpoint=972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0, script=0 023bbcd08957e04e8d2bb9ee98788d99993bda0e 2020-04-02 18:19:45.976 [DBG] SWPR: Timer still ticking 2020-04-02 18:19:45.976 [DBG] SWPR: Delivered spend ntfn for 972a76616a898e902faa27d4bd7162624f03703718ca17c3a99911a85455b8c4:0 2020-04-02 18:19:45.976 [INF] CNCT: *contractcourt.commitSweepResolver(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): commit tx fully resolved by sweep tx: ee5eb61c540718ba4b20acf32ed0d55d1e743c08539a451c749524bee01daf81 2020-04-02 18:19:45.988 [DBG] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): marking contract *contractcourt.commitSweepResolver fully resolved 2020-04-02 18:19:45.995 [DBG] RPCS: [pendingchannels] 2020-04-02 18:19:45.999 [INF] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): a contract has been fully resolved! 2020-04-02 18:19:45.999 [INF] CNCT: ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0): still awaiting contract resolution yeee: *bdb.db 2020-04-02 18:19:45.999 [DBG] UTXN: NurseryReport: building nursery report for channel 0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0 2020-04-02 18:19:46.010 [INF] CNCT: ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) has been fully resolved on-chain at height=2947 2020-04-02 18:19:46.010 [INF] CNCT: Marking ChannelPoint(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) fully resolved 2020-04-02 18:19:46.010 [INF] CHDB: Pruning link node 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 with zero open channels from database 2020-04-02 18:19:46.011 [DBG] CNCT: Stopping ChannelArbitrator(0d6ecc4cad30dba4d93e6a76af1b6a9eec541d7948e417778afd3b8ba000128d:0) 2020-04-02 18:19:46.020 [DBG] RPCS: [pendingchannels] 2020-04-02 18:19:46.021 [DBG] RPCS: [walletbalance] Total balance=0.94977826 BTC (confirmed=0.94977826 BTC, unconfirmed=0 BTC) 2020-04-02 18:19:46.036 [DBG] LNWL: Filtering block 2948 (515936a016edcdd26f5358d72f741e1012f38f9851130548bb2d3e90807be89b) with 1 transactions 2020-04-02 18:19:46.036 [DBG] LNWL: Filtering block 2948 (515936a016edcdd26f5358d72f741e1012f38f9851130548bb2d3e90807be89b) with 1 transactions 2020-04-02 18:19:46.037 [DBG] LNWL: Filtering block 2948 (515936a016edcdd26f5358d72f741e1012f38f9851130548bb2d3e90807be89b) with 1 transactions 2020-04-02 18:19:46.037 [INF] CRTR: Pruning channel graph using block 515936a016edcdd26f5358d72f741e1012f38f9851130548bb2d3e90807be89b (height=2948) 2020-04-02 18:19:46.038 [INF] CRTR: Block 515936a016edcdd26f5358d72f741e1012f38f9851130548bb2d3e90807be89b (height=2948) closed 0 channels 2020-04-02 18:19:46.045 [DBG] LNWL: Filtering block 2949 (20b15eceb661ceaa5155f2e06859368c7891e692368623a904627720d5b85bdf) with 1 transactions 2020-04-02 18:19:46.045 [DBG] LNWL: Filtering block 2949 (20b15eceb661ceaa5155f2e06859368c7891e692368623a904627720d5b85bdf) with 1 transactions 2020-04-02 18:19:46.045 [DBG] LNWL: Filtering block 2949 (20b15eceb661ceaa5155f2e06859368c7891e692368623a904627720d5b85bdf) with 1 transactions 2020-04-02 18:19:46.045 [INF] CRTR: Pruning channel graph using block 20b15eceb661ceaa5155f2e06859368c7891e692368623a904627720d5b85bdf (height=2949) 2020-04-02 18:19:46.046 [INF] CRTR: Block 20b15eceb661ceaa5155f2e06859368c7891e692368623a904627720d5b85bdf (height=2949) closed 0 channels 2020-04-02 18:19:46.050 [DBG] NTFN: Filtering 1 txns for 2 spend requests at height 2948 2020-04-02 18:19:46.050 [INF] NTFN: New block: height=2948, sha=515936a016edcdd26f5358d72f741e1012f38f9851130548bb2d3e90807be89b 2020-04-02 18:19:46.050 [INF] UTXN: Attempting to graduate height=2948: num_kids=0, num_babies=0 2020-04-02 18:19:46.050 [DBG] SWPR: New block: height=2948, sha=515936a016edcdd26f5358d72f741e1012f38f9851130548bb2d3e90807be89b 2020-04-02 18:19:46.050 [DBG] SWPR: Timer still ticking 2020-04-02 18:19:46.050 [DBG] LNWL: Filtering block 2950 (65b075d14accd760216b9d29fa28a06f2419852dc3dd7fc07a1dad6911cfce9c) with 1 transactions 2020-04-02 18:19:46.050 [DBG] LNWL: Filtering block 2950 (65b075d14accd760216b9d29fa28a06f2419852dc3dd7fc07a1dad6911cfce9c) with 1 transactions 2020-04-02 18:19:46.050 [DBG] LNWL: Filtering block 2950 (65b075d14accd760216b9d29fa28a06f2419852dc3dd7fc07a1dad6911cfce9c) with 1 transactions 2020-04-02 18:19:46.050 [INF] CRTR: Pruning channel graph using block 65b075d14accd760216b9d29fa28a06f2419852dc3dd7fc07a1dad6911cfce9c (height=2950) 2020-04-02 18:19:46.053 [INF] CRTR: Block 65b075d14accd760216b9d29fa28a06f2419852dc3dd7fc07a1dad6911cfce9c (height=2950) closed 0 channels 2020-04-02 18:19:46.060 [DBG] NTFN: Filtering 1 txns for 2 spend requests at height 2949 2020-04-02 18:19:46.060 [INF] NTFN: New block: height=2949, sha=20b15eceb661ceaa5155f2e06859368c7891e692368623a904627720d5b85bdf 2020-04-02 18:19:46.060 [DBG] SWPR: New block: height=2949, sha=20b15eceb661ceaa5155f2e06859368c7891e692368623a904627720d5b85bdf 2020-04-02 18:19:46.060 [DBG] SWPR: Timer still ticking 2020-04-02 18:19:46.060 [INF] UTXN: Attempting to graduate height=2949: num_kids=0, num_babies=0 2020-04-02 18:19:46.061 [DBG] NTFN: Filtering 1 txns for 2 spend requests at height 2950 2020-04-02 18:19:46.062 [INF] NTFN: New block: height=2950, sha=65b075d14accd760216b9d29fa28a06f2419852dc3dd7fc07a1dad6911cfce9c 2020-04-02 18:19:46.062 [INF] UTXN: Attempting to graduate height=2950: num_kids=0, num_babies=0 2020-04-02 18:19:46.062 [DBG] SWPR: New block: height=2950, sha=65b075d14accd760216b9d29fa28a06f2419852dc3dd7fc07a1dad6911cfce9c 2020-04-02 18:19:46.062 [DBG] SWPR: Timer still ticking 2020-04-02 18:19:47.976 [DBG] SWPR: Sweep timer expired 2020-04-02 18:19:52.045 [DBG] LNWL: Filtering block 2951 (456e4cb1a9f923c5c15cc43b444e4f06ff3ffd47af4414705722600ad29582e6) with 2 transactions 2020-04-02 18:19:52.045 [DBG] LNWL: Filtering block 2951 (456e4cb1a9f923c5c15cc43b444e4f06ff3ffd47af4414705722600ad29582e6) with 2 transactions 2020-04-02 18:19:52.045 [DBG] LNWL: Filtering block 2951 (456e4cb1a9f923c5c15cc43b444e4f06ff3ffd47af4414705722600ad29582e6) with 2 transactions 2020-04-02 18:19:52.045 [INF] CRTR: Pruning channel graph using block 456e4cb1a9f923c5c15cc43b444e4f06ff3ffd47af4414705722600ad29582e6 (height=2951) 2020-04-02 18:19:52.048 [INF] CRTR: Block 456e4cb1a9f923c5c15cc43b444e4f06ff3ffd47af4414705722600ad29582e6 (height=2951) closed 0 channels 2020-04-02 18:19:52.049 [DBG] NTFN: Filtering 2 txns for 2 spend requests at height 2951 2020-04-02 18:19:52.049 [INF] NTFN: New block: height=2951, sha=456e4cb1a9f923c5c15cc43b444e4f06ff3ffd47af4414705722600ad29582e6 2020-04-02 18:19:52.049 [DBG] SWPR: New block: height=2951, sha=456e4cb1a9f923c5c15cc43b444e4f06ff3ffd47af4414705722600ad29582e6 2020-04-02 18:19:52.049 [INF] UTXN: Attempting to graduate height=2951: num_kids=0, num_babies=0 2020-04-02 18:19:52.123 [DBG] RPCS: [listchannels] fetched 0 channels from DB 2020-04-02 18:19:52.145 [INF] PEER: unable to read message from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076: EOF 2020-04-02 18:19:52.145 [INF] PEER: disconnecting 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076, reason: read handler closed 2020-04-02 18:19:52.245 [DBG] SRVR: Peer 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 has been disconnected 2020-04-02 18:19:52.245 [DBG] FNDG: Cancelling all reservations for peer 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 2020-04-02 18:19:52.245 [DBG] FNDG: No active reservations for node: 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 2020-04-02 18:19:52.245 [INF] DISC: Removing GossipSyncer for peer=039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 2020-04-02 18:19:52.245 [DBG] SRVR: Notifying that peer 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 is offline 2020-04-02 18:19:52.245 [DBG] SRVR: removing peer 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 2020-04-02 18:19:52.245 [DBG] PRNF: PeerNotifier notifying peer: 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9 offline 2020-04-02 18:19:52.245 [DBG] SRVR: Scheduling connection re-establishment to persistent peer 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 in 2.1s 2020-04-02 18:19:52.245 [DBG] BTCN: Disconnected from 039593518d6e20caf002f37a65819054c365d79e4876330e31cb01fda7364484b9@127.0.0.1:20076 (reqid 1) 2020-04-02 18:19:52.248 [INF] LTND: Received shutdown request. 2020-04-02 18:19:52.248 [INF] LTND: Shutting down... 2020-04-02 18:19:52.248 [INF] LTND: Gracefully shutting down. 2020-04-02 18:19:52.248 [INF] CRTR: FilteredChainView stopping 2020-04-02 18:19:52.248 [INF] HSWC: HTLC Switch shutting down 2020-04-02 18:19:52.248 [INF] HSWC: Block epoch canceled, decaying hash log shutting down 2020-04-02 18:19:52.248 [INF] UTXN: UTXO nursery shutting down 2020-04-02 18:19:52.248 [INF] BRAR: Breach arbiter shutting down 2020-04-02 18:19:52.248 [INF] DISC: Authenticated Gossiper is stopping 2020-04-02 18:19:52.248 [INF] CNCT: Stopping ChainArbitrator 2020-04-02 18:19:52.248 [DBG] SWPR: Sweeper shutting down 2020-04-02 18:19:52.248 [DBG] SWPR: Sweeper shut down 2020-04-02 18:19:52.248 [INF] PRNF: Stopping PeerNotifier 2020-04-02 18:19:52.248 [INF] FNDG: Funding manager shutting down 2020-04-02 18:19:52.248 [INF] CHBU: Stopping chanbackup.SubSwapper 2020-04-02 18:19:52.249 [INF] CHFT: Stopping event store 2020-04-02 18:19:52.249 [INF] RPCS: Stopping RPC Server 2020-04-02 18:19:52.249 [INF] RPCS: Stopping RouterRPC Sub-RPC Server 2020-04-02 18:19:52.249 [INF] RPCS: Stopping SignRPC Sub-RPC Server 2020-04-02 18:19:52.249 [INF] RPCS: Stopping AutopilotRPC Sub-RPC Server 2020-04-02 18:19:52.249 [INF] RPCS: Stopping ChainRPC Sub-RPC Server 2020-04-02 18:19:52.249 [INF] RPCS: Stopping InvoicesRPC Sub-RPC Server 2020-04-02 18:19:52.249 [INF] RPCS: Stopping WalletKitRPC Sub-RPC Server 2020-04-02 18:19:52.249 [INF] RPCS: Stopping WatchtowerClientRPC Sub-RPC Server 2020-04-02 18:19:52.249 [INF] RPCS: Stopping WatchtowerRPC Sub-RPC Server 2020-04-02 18:19:52.249 [INF] LTND: Shutdown complete