Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Pending channel with negative blocks_til_maturity #1610

Closed
vpecinka opened this issue Jul 23, 2018 · 44 comments
Closed

Pending channel with negative blocks_til_maturity #1610

vpecinka opened this issue Jul 23, 2018 · 44 comments
Assignees
Labels
P2 should be fixed if one has time utxo sweeping

Comments

@vpecinka
Copy link

Background

I cannot get rid of forced closed channel (from the other party). There is negative number in block_til_maturity and satoshis are in limbo. The channel was created originaly from my side with 100.000 sat, no transaction was made on it.

Your environment

Actual behaviour

$ lncli pendingchannels
{
    "total_limbo_balance": "33273",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "02a456b816697c6b8407ee2176475d74b790a96143bc30e896e8bf7a8852a8b637",
                "channel_point": "73c6e4f0b9cc1703ae7db6510fc7f665d11a537c65e590b848a671a7fcd8dba7:0",
                "capacity": "100000",
                "local_balance": "64778",
                "remote_balance": "0"
            },
            "closing_txid": "60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b",
            "limbo_balance": "33273",
            "maturity_height": 533272,
            "blocks_til_maturity": -29,
            "recovered_balance": "64778",
            "pending_htlcs": [
                {
                    "incoming": false,
                    "amount": "33273",
                    "outpoint": "6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd:0",
                    "maturity_height": 533282,
                    "blocks_til_maturity": -19,
                    "stage": 2
                }
            ]
        }
    ],
    "waiting_close_channels": [
    ]
}
@slush0
Copy link

slush0 commented Jul 23, 2018

Seems related to #1571.

@cfromknecht
Copy link
Contributor

cfromknecht commented Jul 23, 2018

@vpecinka do you know if the sweep transaction is being broadcast? Has the problem persisted across restarts?

Can you try restarting LND and looking for these logs with UTXN prefix? The latter is probably returning an error
https://github.com/lightningnetwork/lnd/blob/master/utxonursery.go#L666
https://github.com/lightningnetwork/lnd/blob/master/utxonursery.go#L678

If you didn't initiate that payment, then someone probably routed a payment through you.

@Roasbeef
Copy link
Member

Looking on chain, all outputs have been swept at this point. Is your lnd node still getting notifications from the chain backend? Are you using a bitcoind backend? If so, is it remote?

@cfromknecht
Copy link
Contributor

I only see the first stage being confirmed, but the second layer sweep hasn't shown up, which seems consistent with the output in pendingchannels

@vpecinka
Copy link
Author

@cfromknecht I would guess my lnd and bitcoind are working fine. Both run locally under same user. How or where else can I verify it receives notifications?

$ lncli getinfo
{
    "identity_pubkey": "0213cac619573fc6021aca72ff023e2d8df65a6df5286c3d52947024cb1332dec7",
    "alias": "VP-CZE 🇨🇿",
    "num_pending_channels": 0,
    "num_active_channels": 17,
    "num_peers": 18,
    "block_height": 533398,
    "block_hash": "0000000000000000001ade1dff3b0e3c716849ef8f52402ed1dc8df1f24ae62d",
    "synced_to_chain": true,
    "testnet": false,
    "chains": [
        "bitcoin"
    ],
    "uris": [
        "0213cac619573fc6021aca72ff023e2d8df65a6df5286c3d52947024cb1332dec7@81.90.251.125:9735"
    ],
    "best_header_timestamp": "1532414810",
    "version": "0.4.2-beta commit=bca926d6af69b117eb6afa0e50ec2dc32d2899d4"
}
$ bitcoin-cli -getinfo
{
  "version": 160100,
  "protocolversion": 70015,
  "walletversion": 139900,
  "balance": 0.00000000,
  "blocks": 533398,
  "timeoffset": 0,
  "connections": 11,
  "proxy": "",
  "difficulty": 5178671069072.251,
  "testnet": false,
  "keypoololdest": 1517906472,
  "keypoolsize": 1000,
  "unlocked_until": 0,
  "paytxfee": 0.00000000,
  "relayfee": 0.00000000,
  "warnings": ""
}

I also tried to restart LND, still having this pending channel.

$ lncli pendingchannels
{
    "total_limbo_balance": "33273",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "02a456b816697c6b8407ee2176475d74b790a96143bc30e896e8bf7a8852a8b637",
                "channel_point": "73c6e4f0b9cc1703ae7db6510fc7f665d11a537c65e590b848a671a7fcd8dba7:0",
                "capacity": "100000",
                "local_balance": "64778",
                "remote_balance": "0"
            },
            "closing_txid": "60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b",
            "limbo_balance": "33273",
            "maturity_height": 533272,
            "blocks_til_maturity": -126,
            "recovered_balance": "64778",
            "pending_htlcs": [
                {
                    "incoming": false,
                    "amount": "33273",
                    "outpoint": "6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd:0",
                    "maturity_height": 533282,
                    "blocks_til_maturity": -116,
                    "stage": 2
                }
            ]
        }
    ],
    "waiting_close_channels": [
    ]
}

Output of all logs I have now:

$ zgrep "Re-registering confirmations" .lnd/logs/bitcoin/mainnet/lnd.log*
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-23 18:18:09.529 [INF] UTXN: Re-registering confirmations for 1 already graduated heights below height=533301
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-23 18:20:26.434 [INF] UTXN: Re-registering confirmations for 1 already graduated heights below height=533301
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-23 18:24:44.582 [INF] UTXN: Re-registering confirmations for 1 already graduated heights below height=533301
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-23 18:27:20.691 [INF] UTXN: Re-registering confirmations for 1 already graduated heights below height=533301

and for the second one:

$ zgrep "Failed to regraduate outputs at" .lnd/logs/bitcoin/mainnet/lnd.log*
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-23 18:18:09.539 [ERR] UTXN: Failed to regraduate outputs at height=533282: -26: 66: min relay fee not met
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-23 18:20:26.441 [ERR] UTXN: Failed to regraduate outputs at height=533282: -26: 66: min relay fee not met
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-23 18:24:44.592 [ERR] UTXN: Failed to regraduate outputs at height=533282: -26: 66: min relay fee not met

For context, I have minrelaytxfee=0 in my bitcoind.conf.

@vpecinka
Copy link
Author

This unconfirmed balance is related? I didn't notice it before lnd restart, however, I'm not sure. Maybe it was there...

$ lncli walletbalance
{
    "total_balance": "1187719",
    "confirmed_balance": "1154566",
    "unconfirmed_balance": "33153"
}

@vpecinka
Copy link
Author

Here is all related to closing_txid 60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b in my logs, if it helps:

$ zgrep  60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b .lnd/logs/bitcoin/mainnet/lnd.log*
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-22 18:36:43.789 [INF] LNWL: Inserting unconfirmed transaction 60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-22 18:36:43.851 [INF] UTXN: Commitment outpoint 60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b:1 registered for confirmation notification.
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-22 18:36:43.851 [INF] NTFN: New confirmation subscription: txid=60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b, numconfs=1
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-22 18:36:43.863 [INF] NTFN: New confirmation subscription: txid=60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b, numconfs=1
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-22 18:42:54.947 [INF] NTFN: Dispatching 1 conf notification for 60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-22 18:42:54.947 [INF] NTFN: Dispatching 1 conf notification for 60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-22 18:42:54.947 [INF] NTFN: New spend subscription: utxo=60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b:1
.lnd/logs/bitcoin/mainnet/lnd.log:   PreviousOutPoint: (wire.OutPoint) 60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b:0,
.lnd/logs/bitcoin/mainnet/lnd.log:   PreviousOutPoint: (wire.OutPoint) 60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b:1,
.lnd/logs/bitcoin/mainnet/lnd.log:2018-07-23 14:12:14.781 [INF] NTFN: Dispatching spend notification for outpoint=60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b:1
.lnd/logs/bitcoin/mainnet/lnd.log:   PreviousOutPoint: (wire.OutPoint) 60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b:0,

and also this multiline dumps:

2018-07-22 20:29:47.946 [INF] UTXN: Publishing CLTV-delayed HTLC output using timeout tx (txid=6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd): (*wire.MsgTx)(0xc42
0d7b840)({
 Version: (int32) 2,
 TxIn: ([]*wire.TxIn) (len=1 cap=1) {
  (*wire.TxIn)(0xc4215495c0)({
   PreviousOutPoint: (wire.OutPoint) 60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b:0,
   SignatureScript: ([]uint8) {
   },
   Witness: (wire.TxWitness) (len=5 cap=5) {
    ([]uint8) {
    },
    ([]uint8) (len=71 cap=71) {
     00000000  30 44 02 20 68 7e ea 64  7f 5d 20 55 36 e2 3a 57  |0D. h~.d.] U6.:W|
     00000010  00 62 0f 89 72 6e 90 0a  cf fe 40 89 19 d7 1b de  |.b..rn....@.....|
     00000020  d8 0e 22 c4 02 20 56 03  51 86 d9 ad 9f 75 1f 1b  |..".. V.Q....u..|
     00000030  0d 00 80 2d ad bc 65 30  25 ae 16 c1 3c 80 7b 97  |...-..e0%...<.{.|
     00000040  1b 05 89 ae 3c d0 01                              |....<..|
    },
    ([]uint8) (len=72 cap=72) {
     00000000  30 45 02 21 00 cd 3d 2e  97 63 75 37 64 b3 a3 a4  |0E.!..=..cu7d...|
     00000010  98 0b 7c 17 4e 0a 80 e6  ca 42 97 b5 91 40 8a dd  |..|.N....B...@..|
     00000020  9b f9 1b df b1 02 20 0e  83 c9 28 51 02 89 e4 cd  |...... ...(Q....|
     00000030  29 3f d2 8e fb f4 d7 72  d4 be ab 1b 9b d8 76 d2  |)?.....r......v.|
     00000040  fd fb 92 18 17 3e 88 01                           |.....>..|
    },
    ([]uint8) {
    },
    ([]uint8) (len=133 cap=133) {
     00000000  76 a9 14 1b a1 ce 46 d0  28 2a d6 a2 e1 3a 06 7f  |v.....F.(*...:..|
     00000010  65 e8 de 90 6b 2d ab 87  63 ac 67 21 03 47 36 ff  |e...k-..c.g!.G6.|
     00000020  36 1a 68 39 bc 8a 60 85  3d 6e 8f 20 ea 88 a1 cc  |6.h9..`.=n. ....|
     00000030  bd f3 45 15 9b d4 9e 07  2e ab a6 ba e8 7c 82 01  |..E..........|..|
     00000040  20 87 64 75 52 7c 21 03  39 f8 e9 01 88 ec 14 66  | .duR|!.9......f|
     00000050  ac f2 46 dc c5 40 5b a3  c1 cd 72 3b ba 8a bb a2  |..F..@[...r;....|
     00000060  63 8a e3 aa c9 35 25 05  52 ae 67 a9 14 d7 60 ec  |c....5%.R.g...`.|
     00000070  18 df 43 ed 5d 00 76 49  65 df fc a7 06 cf aa a5  |..C.].vIe.......|
     00000080  e4 88 ac 68 68                                    |...hh|
    }
   },
   Sequence: (uint32) 0
  })
 },
 TxOut: ([]*wire.TxOut) (len=1 cap=1) {
  (*wire.TxOut)(0xc422f810a0)({
   Value: (int64) 33273,
   PkScript: ([]uint8) (len=34 cap=34) {
    00000000  00 20 2d 71 26 60 47 05  08 bd f4 85 2c a6 1c 38  |. -q&`G.....,..8|
    00000010  1f c8 c7 fa ca 87 e5 b7  46 b7 58 20 44 96 4a 99  |........F.X D.J.|
    00000020  46 2e                                             |F.|
   }
  })
 },
 LockTime: (uint32) 533137
})

and later one:

2018-07-23 18:18:09.512 [INF] LNWL: Removed conflicting tx: (*wire.MsgTx)(0xc420358900)({
 Version: (int32) 2,
 TxIn: ([]*wire.TxIn) (len=1 cap=1) {
  (*wire.TxIn)(0xc4200891a0)({
   PreviousOutPoint: (wire.OutPoint) 60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b:0,
   SignatureScript: ([]uint8) {
   },
   Witness: (wire.TxWitness) (len=5 cap=5) {
    ([]uint8) {
    },
    ([]uint8) (len=71 cap=71) {
     00000000  30 44 02 20 68 7e ea 64  7f 5d 20 55 36 e2 3a 57  |0D. h~.d.] U6.:W|
     00000010  00 62 0f 89 72 6e 90 0a  cf fe 40 89 19 d7 1b de  |.b..rn....@.....|
     00000020  d8 0e 22 c4 02 20 56 03  51 86 d9 ad 9f 75 1f 1b  |..".. V.Q....u..|
     00000030  0d 00 80 2d ad bc 65 30  25 ae 16 c1 3c 80 7b 97  |...-..e0%...<.{.|
     00000040  1b 05 89 ae 3c d0 01                              |....<..|
    },
    ([]uint8) (len=72 cap=72) {
     00000000  30 45 02 21 00 cd 3d 2e  97 63 75 37 64 b3 a3 a4  |0E.!..=..cu7d...|
     00000010  98 0b 7c 17 4e 0a 80 e6  ca 42 97 b5 91 40 8a dd  |..|.N....B...@..|
     00000020  9b f9 1b df b1 02 20 0e  83 c9 28 51 02 89 e4 cd  |...... ...(Q....|
     00000030  29 3f d2 8e fb f4 d7 72  d4 be ab 1b 9b d8 76 d2  |)?.....r......v.|
     00000040  fd fb 92 18 17 3e 88 01                           |.....>..|
    },
    ([]uint8) {
    },
    ([]uint8) (len=133 cap=133) {
     00000000  76 a9 14 1b a1 ce 46 d0  28 2a d6 a2 e1 3a 06 7f  |v.....F.(*...:..|
     00000010  65 e8 de 90 6b 2d ab 87  63 ac 67 21 03 47 36 ff  |e...k-..c.g!.G6.|
     00000020  36 1a 68 39 bc 8a 60 85  3d 6e 8f 20 ea 88 a1 cc  |6.h9..`.=n. ....|
     00000030  bd f3 45 15 9b d4 9e 07  2e ab a6 ba e8 7c 82 01  |..E..........|..|
     00000040  20 87 64 75 52 7c 21 03  39 f8 e9 01 88 ec 14 66  | .duR|!.9......f|
     00000050  ac f2 46 dc c5 40 5b a3  c1 cd 72 3b ba 8a bb a2  |..F..@[...r;....|
     00000060  63 8a e3 aa c9 35 25 05  52 ae 67 a9 14 d7 60 ec  |c....5%.R.g...`.|
     00000070  18 df 43 ed 5d 00 76 49  65 df fc a7 06 cf aa a5  |..C.].vIe.......|
     00000080  e4 88 ac 68 68                                    |...hh|
    }
   },
   Sequence: (uint32) 0
  })
 },
 TxOut: ([]*wire.TxOut) (len=1 cap=1) {
  (*wire.TxOut)(0xc420782f00)({
   Value: (int64) 33273,
   PkScript: ([]uint8) (len=34 cap=34) {
    00000000  00 20 2d 71 26 60 47 05  08 bd f4 85 2c a6 1c 38  |. -q&`G.....,..8|
    00000010  1f c8 c7 fa ca 87 e5 b7  46 b7 58 20 44 96 4a 99  |........F.X D.J.|
    00000020  46 2e                                             |F.|
   }
  })
 },
 LockTime: (uint32) 533137
})

@cfromknecht
Copy link
Contributor

@vpecinka thank you for your detailed logs, helped a bunch in figuring out what was going on

have you had any luck since getting this sweep to confirm?

@vpecinka
Copy link
Author

@cfromknecht you're welcome. Unfortunately, it is still pending - I updated lnd to the 0.4.2-beta commit=098cd940e312c111dda3efe5fa2c7d375743f770 version.

{
    "total_limbo_balance": "33273",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "02a456b816697c6b8407ee2176475d74b790a96143bc30e896e8bf7a8852a8b637",
                "channel_point": "73c6e4f0b9cc1703ae7db6510fc7f665d11a537c65e590b848a671a7fcd8dba7:0",
                "capacity": "100000",
                "local_balance": "64778",
                "remote_balance": "0"
            },
            "closing_txid": "60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b",
            "limbo_balance": "33273",
            "maturity_height": 533272,
            "blocks_til_maturity": -609,
            "recovered_balance": "64778",
            "pending_htlcs": [
                {
                    "incoming": false,
                    "amount": "33273",
                    "outpoint": "6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd:0",
                    "maturity_height": 533282,
                    "blocks_til_maturity": -599,
                    "stage": 2
                }
            ]
        }
    ],
    "waiting_close_channels": [
    ]
}

I don't know if this helps and is related: this is from log in context of pending_htlcs with output 6e6c6a...

2018-07-26 08:39:41.009 [INF] CNCT: *contractcourt.htlcTimeoutResolver(6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd:0): waiting second-level tx (txid=6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd) to be fully confirmed
2018-07-26 08:39:41.009 [INF] NTFN: New confirmation subscription: txid=6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd, numconfs=1
2018-07-26 08:39:41.010 [INF] CNCT: ChannelArbitrator(4218ade3839c3fb31a8597013527e3e6e2ac5b3964e0027facc79871a54286e8:0): starting state=StateDefault
2018-07-26 08:39:41.011 [INF] CNCT: ChannelArbitrator(e21bb5218b98a4ba2a47291120bd976ec9d3efba8c1ca0b88d32a3e8ffaf0439:0): starting state=StateDefault
2018-07-26 08:39:41.085 [INF] CNCT: ChannelArbitrator(5b42258d98d803e7a9b6fefaa8dd72d3dca09e9df9f446e772d9de53815f5b79:0): starting state=StateDefault
2018-07-26 08:39:41.086 [INF] CNCT: ChannelArbitrator(edbbe4c58b65e2836e0f8032c3e8f93f43032eb04a9fa8114514cba3ee33fc82:0): starting state=StateDefault
2018-07-26 08:39:41.102 [INF] DISC: Authenticated Gossiper is starting
2018-07-26 08:39:41.102 [INF] BRAR: Starting contract observer, watching for breaches.
2018-07-26 08:39:41.102 [INF] NTFN: Dispatching 1 conf notification for 6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd
2018-07-26 08:39:41.102 [INF] NTFN: New block epoch subscription
2018-07-26 08:39:41.102 [INF] CNCT: *contractcourt.htlcTimeoutResolver(6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd:0): resolving htlc with incoming fail msg, fully confirmed
2018-07-26 08:39:41.102 [INF] HSWC: Received outside contract resolution, mapping to: (*htlcswitch.htlcPacket)(0xc4206d1340)({
 destNode: ([33]uint8) (len=33 cap=33) {
  00000000  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
  00000010  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  |................|
  00000020  00                                                |.|
 },
 incomingChanID: (lnwire.ShortChannelID) 0:0:0,
 outgoingChanID: (lnwire.ShortChannelID) 532842:2815:0,
 incomingHTLCID: (uint64) 0,
 incomingHtlcAmt: (lnwire.MilliSatoshi) 0 mSAT,
 outgoingHTLCID: (uint64) 0,
 sourceRef: (*channeldb.AddRef)(<nil>),
 destRef: (*channeldb.SettleFailRef)(<nil>),
 incomingAmount: (lnwire.MilliSatoshi) 0 mSAT,
 amount: (lnwire.MilliSatoshi) 0 mSAT,
 htlc: (*lnwire.UpdateFailHTLC)(0xc420512740)({
  ChanID: (lnwire.ChannelID) (len=32 cap=32) 0000000000000000000000000000000000000000000000000000000000000000,
  ID: (uint64) 0,
  Reason: (lnwire.OpaqueReason) <nil>
 }),
 obfuscator: (htlcswitch.ErrorEncrypter) <nil>,
 localFailure: (bool) false,
 hasSource: (bool) false,
 isResolution: (bool) true,
 circuit: (*htlcswitch.PaymentCircuit)(<nil>),
 incomingTimeout: (uint32) 0,
 outgoingTimeout: (uint32) 0
})

2018-07-26 08:39:41.103 [ERR] HSWC: Unable to find target channel for HTLC settle/fail: channel ID = 532842:2815:0, HTLC ID = 0
2018-07-26 08:39:41.103 [ERR] HSWC: Unable to forward resolution msg: Unable to find target channel for HTLC settle/fail: channel ID = 532842:2815:0, HTLC ID = 0
2018-07-26 08:39:41.103 [INF] CNCT: *contractcourt.htlcTimeoutResolver(6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd:0): waiting for nursery to spend CSV delayed output
2018-07-26 08:39:41.103 [INF] NTFN: New spend subscription: utxo=6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd:0

@Roasbeef
Copy link
Member

Have you tried lowering your minrelayfee and minfee settings for your bitcoind node? This should allow the transaction to enter the mempool. From there, you'll eventually be able to possibly push the sweeping transaction via an API site or the like.

@brndnmtthws
Copy link
Contributor

brndnmtthws commented Aug 5, 2018

Same issue here. I have minrelaytxfee=0 set with bitcoind 0.16.0. Here's the stuck TX:

root@instance-5:/lnd# lncli pendingchannels
{
    "total_limbo_balance": "4346",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "03e28223dc9b962d824c4a41dd6a2d178a72004594b87aa28cbfdf63e551fbef33",
                "channel_point": "6bb225f1a7c4a1575bfe42342b4d8436b9a48cd64e32751d486e09fa3f819a90:1",
                "capacity": "340000",
                "local_balance": "3467",
                "remote_balance": "0"
            },
            "closing_txid": "2db99f4220628fe1ea048176b5c4393ef1aac8b42f3f0275bd880e2769c98088",
            "limbo_balance": "4346",
            "maturity_height": 531032,
            "blocks_til_maturity": -4317,
            "recovered_balance": "3467",
            "pending_htlcs": [
                {
                    "incoming": false,
                    "amount": "2173",
                    "outpoint": "9762c96c8eab23c660d287eb3c65e8dc7ab53bfb49817d5a5ed4cfb011313745:0",
                    "maturity_height": 531041,
                    "blocks_til_maturity": -4308,
                    "stage": 2
                },
                {
                    "incoming": false,
                    "amount": "2173",
                    "outpoint": "dc36145b1bf6db7f68a2b23ef225bbcf257b3605d3298c54ac3018c29b069e60:0",
                    "maturity_height": 531041,
                    "blocks_til_maturity": -4308,
                    "stage": 2
                }
            ]
        }
    ],
    "waiting_close_channels": [
    ]
}
root@instance-5:/lnd# lncli walletbalance
{
    "total_balance": "25502772",
    "confirmed_balance": "25498624",
    "unconfirmed_balance": "4148"
}
root@instance-5:/lnd#

@vpecinka
Copy link
Author

vpecinka commented Aug 6, 2018

I have minrelaytxfee=0 in my bitcoin.conf

@cfromknecht
Copy link
Contributor

cfromknecht commented Aug 6, 2018

Working on a fix so that we can get these 2nd stage sweeps resigned and broadcast

@brndnmtthws are you also seeing "min relay fee not met"?

Is anyone else getting this with other backends?

@Roasbeef
Copy link
Member

Roasbeef commented Aug 7, 2018

@brndnmtthws on restart, do you see lnd trying to re-broadcast those transactions? Also can you try lowering your minrelayfee as well as mintxfee settings?

@brndnmtthws
Copy link
Contributor

@Roasbeef mintxrelayfee and mintxfee are set to 0:

brenden@instance-5:~$ ps waux | grep -i bitcoind
brenden   2206 62.0  0.5 1810744 364180 ?      Ssl  22:26   3:06 /usr/bin/bitcoind -daemon -printtoconsole -pid=/home/brenden/.bitcoin/bitcoind.pid -conf=/home/brenden/.bitcoin/bitcoin.conf -datadir=/home/brenden/.bitcoin -txindex=1 -mintxfee=0 -minrelaytxfee=0 -disablewallet

here's the log after restarting lnd: https://gist.github.com/brndnmtthws/ec67de5c57dbe09998cf903c60c426fc

@Roasbeef
Copy link
Member

Roasbeef commented Aug 7, 2018

Logs show a rebroadcast by the nursery. Are you running bitcoind in blocks only mode? During a restart, can you check the mempool bitcoind logs to see if the transaction is actually being accepted over RPC, and then set out to peers? My node doesn't have that txid in its mempool, so looks like bitcoind isn't sending it out for some reason.

@brndnmtthws
Copy link
Contributor

@Roasbeef not running in blocks only mode. The tx appears to be in the mempool:

brenden@instance-5:~/.bitcoin$ bitcoin-cli gettxout d26ea65251302a02d52754d7bf7fa720b32c367ef8220b743417a05328b3c241 0
{
  "bestblock": "00000000000000000006a5c887ef705069a818d7680dbd3e978f3164f2826b5b",
  "confirmations": 0,
  "value": 0.00004148,
  "scriptPubKey": {
    "asm": "0 ff8de97ca4e15dbf875074ee2ad4c6f8677295c3",
    "hex": "0014ff8de97ca4e15dbf875074ee2ad4c6f8677295c3",
    "reqSigs": 1,
    "type": "witness_v0_keyhash",
    "addresses": [
      "bc1ql7x7jl9yu9wmlp6swnhz44xxlpnh99wrgjggxy"
    ]
  },
  "coinbase": false
}
brenden@instance-5:~/.bitcoin$

@vpecinka
Copy link
Author

vpecinka commented Aug 8, 2018

@cfromknecht yes, I can see this:

$ zgrep -i "min relay fee not met" .lnd/logs/bitcoin/mainnet/lnd.log*
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 15:31:35.801 [ERR] UTXN: unable to broadcast sweep tx: -26: 66: min relay fee not met, (*wire.MsgTx)(0xc4217a7080)({
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 15:31:35.801 [ERR] UTXN: Failed to sweep 1 kindergarten outputs at height=533282: -26: 66: min relay fee not met
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 15:31:35.801 [ERR] UTXN: error while graduating class at height=533282: -26: 66: min relay fee not met
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 18:18:09.536 [ERR] UTXN: unable to broadcast sweep tx: -26: 66: min relay fee not met, (*wire.MsgTx)(0xc42031a000)({
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 18:18:09.537 [ERR] UTXN: Failed to re-register for kindergarten sweep transaction at height=533282: -26: 66: min relay fee not met
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 18:18:09.539 [ERR] UTXN: Failed to regraduate outputs at height=533282: -26: 66: min relay fee not met
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 18:18:09.539 [ERR] SRVR: unable to start server: -26: 66: min relay fee not met
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 18:20:26.440 [ERR] UTXN: unable to broadcast sweep tx: -26: 66: min relay fee not met, (*wire.MsgTx)(0xc4205ce1c0)({
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 18:20:26.441 [ERR] UTXN: Failed to re-register for kindergarten sweep transaction at height=533282: -26: 66: min relay fee not met
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 18:20:26.441 [ERR] UTXN: Failed to regraduate outputs at height=533282: -26: 66: min relay fee not met
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 18:20:26.441 [ERR] SRVR: unable to start server: -26: 66: min relay fee not met
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 18:24:44.590 [ERR] UTXN: unable to broadcast sweep tx: -26: 66: min relay fee not met, (*wire.MsgTx)(0xc4201da7c0)({
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 18:24:44.592 [ERR] UTXN: Failed to re-register for kindergarten sweep transaction at height=533282: -26: 66: min relay fee not met
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 18:24:44.592 [ERR] UTXN: Failed to regraduate outputs at height=533282: -26: 66: min relay fee not met
.lnd/logs/bitcoin/mainnet/lnd.log.4.gz:2018-07-23 18:24:44.592 [ERR] SRVR: unable to start server: -26: 66: min relay fee not met

@brndnmtthws
Copy link
Contributor

This is still a problem for me. It would appear that the issue is that the fee for the TX is too low, and won't be accepted by any other Bitcoin nodes.

Here's the raw tx:

0200000000010245373111b0cfd45e5a7d8149fb3bb57adce8653ceb87d260c623ab8e6cc96297000000000090000000609e069bc21830ac548c29d305367b25cfbb25f23eb2a2687fdbf61b5b1436dc000000000090000000013410000000000000160014ff8de97ca4e15dbf875074ee2ad4c6f8677295c303483045022100e1e54ccf46105e7dc710d9a9055dd61ad9ad71ef81269cf934acefa4073c7980022067d502bebb2c3de4a58dfcf787c2be8021323b7398a3b7617d0ff43e7aad1a8001004d63210246f91d0def8c35996f5e64adbaa989dd46bd046eb5e9ed19666f92257725ea6567029000b2752103eaab4acc93d6f6382ae6e06fc4f8bf279cda79b13e474c22d989ea1360b0477568ac0348304502210094f0a68fa0aa9f6e62220e7bdee9105ab7beb5ce34ef524ebc629e8d391e56f7022044f9a10b516a854a1f27db0fe882399f5d556ca467015dc819a3012f4b86c22d01004d63210246f91d0def8c35996f5e64adbaa989dd46bd046eb5e9ed19666f92257725ea6567029000b2752103eaab4acc93d6f6382ae6e06fc4f8bf279cda79b13e474c22d989ea1360b0477568ac00000000

Is there a way to force lnd to create a new tx with an appropriate fee?

@Roasbeef
Copy link
Member

@brndnmtthws this is a problem at the latest version of lnd? You can take that raw tx and try to use the existing API services that will push the tx for free (like blockchain.info).

@brndnmtthws
Copy link
Contributor

brndnmtthws commented Aug 30, 2018 via email

@vpecinka
Copy link
Author

vpecinka commented Sep 2, 2018

@Roasbeef how can I get the raw tx?

pending channels:

$ lncli pendingchannels
{
    "total_limbo_balance": "33273",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "02a456b816697c6b8407ee2176475d74b790a96143bc30e896e8bf7a8852a8b637",
                "channel_point": "73c6e4f0b9cc1703ae7db6510fc7f665d11a537c65e590b848a671a7fcd8dba7:0",
                "capacity": "100000",
                "local_balance": "64778",
                "remote_balance": "0"
            },
            "closing_txid": "60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b",
            "limbo_balance": "33273",
            "maturity_height": 533272,
            "blocks_til_maturity": -6345,
            "recovered_balance": "64778",
            "pending_htlcs": [
                {
                    "incoming": false,
                    "amount": "33273",
                    "outpoint": "6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd:0",
                    "maturity_height": 533282,
                    "blocks_til_maturity": -6335,
                    "stage": 2
                }
            ]
        }
    ],
    "waiting_close_channels": [
    ]
}

but when asking bitcoind for the closing transaction or txid from pending_htlss, I get nothing.

$ bitcoin-cli gettransaction 60ccda7151a4131abdc28c693342f48f0ecea667bbc56c8388f739cf2b26105b
error code: -5
error message:
Invalid or non-wallet transaction id


$ bitcoin-cli gettransaction 6e6c6a744d6bbee760152751cfd2f1d89712f577434fd3720ce9b4941ed278cd
error code: -5
error message:
Invalid or non-wallet transaction id

@brndnmtthws
Copy link
Contributor

So is there a way to get lnd to regenerate the TX? I'm currently stuck because no other bitcoin nodes will relay the TX, thus the TX will never confirm (because the fee is below the default min relay fee).

It's been stuck in this state for months, meaning I have a completely useless node where I can't transact, and there's about ~2 BTC locked up on it.

@Roasbeef
Copy link
Member

@brndnmtthws 2 BTC? Every single one of you channels was closed before the fee floor was activated? Or is it that you have dependent spends from each of them? This PR implements logic for on-demand fee bumping when signing #1704

@vpecinka in order to get the transaction, you need to lower the min fee rate on your bitcoind node. Only at that point will it be accepted into the mempool.

@brndnmtthws
Copy link
Contributor

@Roasbeef Sweet, that PR looks like what I need. I haven't actually explicitly closed any channels myself, I've just let lnd run and do its thing.

@Roasbeef
Copy link
Member

Oh gotcha. I mean that the channel you linked above was older, and was broadcast at the point where we didn't properly apply the fee floor. So if you close them now the fee floor will be properly enforced. I was getting at this comment:

It's been stuck in this state for months, meaning I have a completely useless node where I can't transact, and there's about ~2 BTC locked up on it.

You can't move the funds or send funds out of the wallet as is?

@brndnmtthws
Copy link
Contributor

@Roasbeef that's right, if I try to use lncli sendcoins it fails because of missing inputs.

Trying to force the channel to close again results in an error:

root@instance-5:/lnd# lncli closechannel --force 6bb225f1a7c4a1575bfe42342b4d8436b9a48cd64e32751d486e09fa3f819a90 1
[lncli] rpc error: code = Unknown desc = unable to find channel
root@instance-5:/lnd#

@Roasbeef
Copy link
Member

Roasbeef commented Sep 26, 2018 via email

@brndnmtthws
Copy link
Contributor

I tried all the channel points and the result was the same:

root@instance-5:/lnd# lncli pendingchannels
{
    "total_limbo_balance": "4346",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "03e28223dc9b962d824c4a41dd6a2d178a72004594b87aa28cbfdf63e551fbef33",
                "channel_point": "6bb225f1a7c4a1575bfe42342b4d8436b9a48cd64e32751d486e09fa3f819a90:1",
                "capacity": "340000",
                "local_balance": "3467",
                "remote_balance": "0"
            },
            "closing_txid": "2db99f4220628fe1ea048176b5c4393ef1aac8b42f3f0275bd880e2769c98088",
            "limbo_balance": "4346",
            "maturity_height": 531032,
            "blocks_til_maturity": -12182,
            "recovered_balance": "3467",
            "pending_htlcs": [
                {
                    "incoming": false,
                    "amount": "2173",
                    "outpoint": "9762c96c8eab23c660d287eb3c65e8dc7ab53bfb49817d5a5ed4cfb011313745:0",
                    "maturity_height": 531041,
                    "blocks_til_maturity": -12173,
                    "stage": 2
                },
                {
                    "incoming": false,
                    "amount": "2173",
                    "outpoint": "dc36145b1bf6db7f68a2b23ef225bbcf257b3605d3298c54ac3018c29b069e60:0",
                    "maturity_height": 531041,
                    "blocks_til_maturity": -12173,
                    "stage": 2
                }
            ]
        }
    ],
    "waiting_close_channels": [
    ]
}
root@instance-5:/lnd# lncli closechannel --force 6bb225f1a7c4a1575bfe42342b4d8436b9a48cd64e32751d486e09fa3f819a90 1
[lncli] rpc error: code = Unknown desc = unable to find channel
root@instance-5:/lnd# lncli closechannel --force 9762c96c8eab23c660d287eb3c65e8dc7ab53bfb49817d5a5ed4cfb011313745 0
[lncli] rpc error: code = Unknown desc = unable to find channel
root@instance-5:/lnd# lncli closechannel --force dc36145b1bf6db7f68a2b23ef225bbcf257b3605d3298c54ac3018c29b069e60 0
[lncli] rpc error: code = Unknown desc = unable to find channel
root@instance-5:/lnd#

Is there a different way to determine the channel point?

@Roasbeef
Copy link
Member

Roasbeef commented Sep 26, 2018 via email

@brndnmtthws
Copy link
Contributor

@Roasbeef I see. I understood your comment to mean "try closing them again to generate a new TX" or something of that nature.

@vpecinka
Copy link
Author

vpecinka commented Oct 5, 2018

Just letting you know that I don't have pending channels any more... I don't know when and how it happend, however. I noticed it now after power outage and server reboot.

Anyway, thanks a lot!

@sangaman
Copy link
Contributor

I'm seeing this issue now too, apparently on a very old transaction that was confirmed a long time ago. Any ideas? Should I open a new issue?

lncli pendingchannels
{
    "total_limbo_balance": "2607",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "02ad6fb8d693dc1e4569bcedefadf5f72a931ae027dc0f0c544b34c1c6f3b9a02b",
                "channel_point": "566c2e38017c6172cdcb8ef59341773dbdf1385a9e10fdc114477906f6d04bcc:0",
                "capacity": "2000000",
                "local_balance": "1796219",
                "remote_balance": "0"
            },
            "closing_txid": "af245bf71ba488217c2ca8d3ce19821990cce59154add44a7f39c9254acba446",
            "limbo_balance": "2607",
            "maturity_height": 528542,
            "blocks_til_maturity": -18546,
            "recovered_balance": "1805975",
            "pending_htlcs": [
                {
                    "incoming": false,
                    "amount": "9756",
                    "outpoint": "1af56a47c9ea2084cbf55ffaed95996a4612f2d32a6765f0be5221df5ed1d292:0",
                    "maturity_height": 528788,
                    "blocks_til_maturity": -18300,
                    "stage": 0
                },
                {
                    "incoming": false,
                    "amount": "2607",
                    "outpoint": "b555cd22c2ed3df563dc835f3b33014dbcfb881f9a6562c5b113f87c04542cea:0",
                    "maturity_height": 528552,
                    "blocks_til_maturity": -18536,
                    "stage": 2
                }
            ]
        }
    ],
    "waiting_close_channels": [
    ]
}

@halseth
Copy link
Contributor

halseth commented Oct 29, 2018

@sangaman Do you see unable to advance state: no contract resolutions exist at startup? In that case you might be running into #1993

@brndnmtthws
Copy link
Contributor

After having tried everything in this thread, the TX is still stuck:

root@instance-5:/lnd# lncli pendingchannels
{
    "total_limbo_balance": "4346",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "03e28223dc9b962d824c4a41dd6a2d178a72004594b87aa28cbfdf63e551fbef33",
                "channel_point": "6bb225f1a7c4a1575bfe42342b4d8436b9a48cd64e32751d486e09fa3f819a90:1",
                "capacity": "340000",
                "local_balance": "3467",
                "remote_balance": "0"
            },
            "closing_txid": "2db99f4220628fe1ea048176b5c4393ef1aac8b42f3f0275bd880e2769c98088",
            "limbo_balance": "4346",
            "maturity_height": 531032,
            "blocks_til_maturity": -20898,
            "recovered_balance": "3467",
            "pending_htlcs": [
                {
                    "incoming": false,
                    "amount": "2173",
                    "outpoint": "9762c96c8eab23c660d287eb3c65e8dc7ab53bfb49817d5a5ed4cfb011313745:0",
                    "maturity_height": 531041,
                    "blocks_til_maturity": -20889,
                    "stage": 2
                },
                {
                    "incoming": false,
                    "amount": "2173",
                    "outpoint": "dc36145b1bf6db7f68a2b23ef225bbcf257b3605d3298c54ac3018c29b069e60:0",
                    "maturity_height": 531041,
                    "blocks_til_maturity": -20889,
                    "stage": 2
                }
            ]
        },
        {
            "channel": {
                "remote_node_pub": "03aeca3b52e028b68c67d01a62eede65df55bda5cd04e4341ac42688d25fc151cd",
                "channel_point": "1d683f035e4599bb15dca2176eff07868c11d79a35c5e201532ecea5371fe792:0",
                "capacity": "108261",
                "local_balance": "1677",
                "remote_balance": "0"
            },
            "closing_txid": "b6178264f839e9d5dff5b85e1bd9b272d1af4ed02094ea6263fe133d2d6ee807",
            "limbo_balance": "0",
            "maturity_height": 0,
            "blocks_til_maturity": 0,
            "recovered_balance": "0",
            "pending_htlcs": [
            ]
        }
    ],
    "waiting_close_channels": [
    ]
}
root@instance-5:/lnd#

Strangely there's another TX (b6178264f839e9d5dff5b85e1bd9b272d1af4ed02094ea6263fe133d2d6ee807) which confirmed a while ago, but is also apparently stuck. I'm not sure what that's about.

What are my options here? How do I get this thing unstuck? Should I open another issue?

FWIW, I'm able to send other transactions again (no longer getting the "missing inputs" error).

@sangaman
Copy link
Contributor

@halseth Sorry I didn't see your message when you first posted. Do I need to be on debug level logging to see it on startup? I don't see anything like that with info.

As an update, I do still have this pending force close channel running the latest from master v0.5.1-beta-40-gfc4fe070100a66ea220a14e74f52f9c9d1550636. Otherwise lnd seems to be working normally.

@davidknezic
Copy link
Contributor

davidknezic commented Nov 29, 2018

I think I'm having a similar issue here, with 441713 sat stuck in limbo. Pending HTLC blocks_til_maturity = -3913 and closing tx blocks_til_maturity = -3777. I've just updated to v0.5.1 and was hoping the issue would resolve itself.

The closing tx is broadcast and seems valid, just not sure if LOCK TIME = 539683104 is normal.

lncli pendingchannels
{
    "total_limbo_balance": "441713",
    "pending_open_channels": [
    ],
    "pending_closing_channels": [
    ],
    "pending_force_closing_channels": [
        {
            "channel": {
                "remote_node_pub": "03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c",
                "channel_point": "c0e3a018c8fd9a8ab968aa1e2c216b42028920c6132e1d6ddd42f000ac41e165:1",
                "capacity": "484000",
                "local_balance": "22800",
                "remote_balance": "0"
            },
            "closing_txid": "e85d5c6b906fb66c10765ab4ff1018cd22d6c934e937fd6199a61edebec50e20",
            "limbo_balance": "441713",
            "maturity_height": 548157,
            "blocks_til_maturity": -3777,
            "recovered_balance": "22800",
            "pending_htlcs": [
                {
                    "incoming": false,
                    "amount": "441713",
                    "outpoint": "f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249:0",
                    "maturity_height": 548021,
                    "blocks_til_maturity": -3913,
                    "stage": 1
                }
            ]
        }
    ],
    "waiting_close_channels": [
    ]
}
lncli getinfo
{
    "identity_pubkey": "0235e252a7ba8fd602a22eec1168f7647b611dd7b4ee5c329aa333be0a8a0d792e",
    "alias": "coincenter.lnd.lightning.land",
    "num_pending_channels": 0,
    "num_active_channels": 3,
    "num_peers": 5,
    "block_height": 551935,
    "block_hash": "0000000000000000001c60b22763eff726cb5285670c637f8f6a58d72fa22055",
    "synced_to_chain": true,
    "testnet": false,
    "chains": [
        "bitcoin"
    ],
    "uris": [
        "0235e252a7ba8fd602a22eec1168f7647b611dd7b4ee5c329aa333be0a8a0d792e@109.202.192.11:9735"
    ],
    "best_header_timestamp": "1543505954",
    "version": "0.5.1-beta commit=",
    "num_inactive_channels": 0
}
lnd.log
2018-11-29 15:48:18.556 [INF] LTND: Active chain: Bitcoin (network=mainnet)
2018-11-29 15:48:18.557 [INF] CHDB: Checking for schema update: latest_version=7, db_version=7
2018-11-29 15:48:18.560 [INF] RPCS: password gRPC proxy started at [::]:20002
2018-11-29 15:48:18.560 [INF] RPCS: password RPC server listening on [::]:20001
2018-11-29 15:48:18.560 [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.
2018-11-29 15:48:51.082 [INF] LNWL: Opened wallet
2018-11-29 15:48:51.298 [INF] LTND: Primary chain is set to: bitcoin
2018-11-29 15:48:51.334 [INF] LNWL: Started listening for bitcoind block notifications via ZMQ on tcp://127.0.0.1:28332
2018-11-29 15:48:51.334 [INF] LNWL: Started listening for bitcoind transaction notifications via ZMQ on tcp://127.0.0.1:28333
2018-11-29 15:48:51.334 [INF] LTND: Initializing bitcoind backed fee estimator
2018-11-29 15:48:54.229 [INF] LNWL: The wallet has been unlocked without a time limit
2018-11-29 15:48:54.274 [INF] LTND: LightningWallet opened
2018-11-29 15:48:54.320 [INF] HSWC: Restoring in-memory circuit state from disk
2018-11-29 15:48:54.327 [INF] HSWC: Payment circuits loaded: num_pending=1, num_open=1
2018-11-29 15:48:54.368 [INF] LNWL: Started rescan from block 0000000000000000001c60b22763eff726cb5285670c637f8f6a58d72fa22055 (height 551935) for 51 addresses
2018-11-29 15:48:54.370 [INF] HSWC: Trimming open circuits for chan_id=550344:1283:0, start_htlc_id=0
2018-11-29 15:48:54.370 [INF] HSWC: Trimming open circuits for chan_id=550329:757:0, start_htlc_id=0
2018-11-29 15:48:54.370 [INF] HSWC: Trimming open circuits for chan_id=548889:84:1, start_htlc_id=4
2018-11-29 15:48:54.371 [INF] LNWL: Starting rescan from block 0000000000000000001c60b22763eff726cb5285670c637f8f6a58d72fa22055
2018-11-29 15:48:54.378 [INF] LNWL: Rescan finished at 551935 (0000000000000000001c60b22763eff726cb5285670c637f8f6a58d72fa22055)
2018-11-29 15:48:54.378 [INF] LNWL: Catching up block hashes to height 551935, this might take a while
2018-11-29 15:48:54.391 [INF] LNWL: Done catching up block hashes
2018-11-29 15:48:54.391 [INF] LNWL: Finished rescan for 51 addresses (synced to block 0000000000000000001c60b22763eff726cb5285670c637f8f6a58d72fa22055, height 551935)
2018-11-29 15:48:54.395 [INF] RPCS: RPC server listening on [::]:20001
2018-11-29 15:48:54.395 [INF] RPCS: gRPC proxy started at [::]:20002
2018-11-29 15:48:54.405 [INF] LTND: Waiting for chain backend to finish sync, start_height=551935
2018-11-29 15:48:54.413 [INF] LTND: Chain backend is fully synced (end_height=551935)!
2018-11-29 15:48:54.428 [INF] HSWC: Starting HTLC Switch
2018-11-29 15:48:54.428 [INF] NTFN: New block epoch subscription
2018-11-29 15:48:54.429 [INF] NTFN: New block epoch subscription
2018-11-29 15:48:54.466 [INF] NTFN: New block epoch subscription
2018-11-29 15:48:54.475 [INF] UTXN: Re-registering confirmations for 1 already graduated heights below height=551935
2018-11-29 15:48:54.475 [INF] UTXN: Re-registering confirmation for first-stage HTLC outputs at height=548021 
2018-11-29 15:48:54.476 [INF] UTXN: Publishing CLTV-delayed HTLC output using timeout tx (txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249): (*wire.MsgTx)(0x18456e0)({
 Version: (int32) 2,
 TxIn: ([]*wire.TxIn) (len=1 cap=1) {
  (*wire.TxIn)(0x1998b80)({
   PreviousOutPoint: (wire.OutPoint) e85d5c6b906fb66c10765ab4ff1018cd22d6c934e937fd6199a61edebec50e20:1,
   SignatureScript: ([]uint8) {
   },
   Witness: (wire.TxWitness) (len=5 cap=5) {
    ([]uint8) {
    },
    ([]uint8) (len=72 cap=72) {
     00000000  30 45 02 21 00 d8 8a d3  ad fb b2 92 1a 5f cb c3  |0E.!........._..|
     00000010  fb 15 58 3b 7b 95 8f 5e  ba 47 0f 66 a7 f9 89 03  |..X;{..^.G.f....|
     00000020  8e 25 b6 4f f9 02 20 68  97 f7 3b 81 17 0e 1a d0  |.%.O.. h..;.....|
     00000030  a2 d9 3c 2a 54 b5 fc e0  e2 1f 49 4e 15 7d 03 eb  |..<*T.....IN.}..|
     00000040  3d d1 ca e7 5e a1 4b 01                           |=...^.K.|
    },
    ([]uint8) (len=72 cap=72) {
     00000000  30 45 02 21 00 ab f0 19  69 ea 6d c9 1b 05 8e de  |0E.!....i.m.....|
     00000010  85 83 d0 3a 40 04 f8 93  a8 72 8e 0a 69 20 e7 fd  |...:@....r..i ..|
     00000020  17 58 38 fa 8d 02 20 1d  c0 91 67 4a ef b4 af c6  |.X8... ...gJ....|
     00000030  0a 24 f3 4f 0d b7 5b ec  e9 5a 91 6b 9b ef 1a e5  |.$.O..[..Z.k....|
     00000040  2b 63 b3 9c b0 0d 91 01                           |+c......|
    },
    ([]uint8) {
    },
    ([]uint8) (len=133 cap=133) {
     00000000  76 a9 14 6e 11 c8 20 c2  a1 24 65 f7 c8 71 62 17  |v..n.. ..$e..qb.|
     00000010  f9 a7 e6 a0 b8 5b 60 87  63 ac 67 21 03 90 8c 47  |.....[`.c.g!...G|
     00000020  67 a5 d4 ea 8b b4 52 78  ed 84 a4 41 c9 9f f3 99  |g.....Rx...A....|
     00000030  59 dd e0 86 fb b9 a6 3c  62 e8 75 c7 71 7c 82 01  |Y......2018-11-29 15:48:54.476 [INF] LNWL: Inserting unconfirmed transaction f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249
2018-11-29 15:48:54.498 [INF] NTFN: New confirmation subscription: txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249, numconfs=1
2018-11-29 15:48:54.498 [INF] UTXN: Htlc output f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249:0 registered for promotion notification.
2018-11-29 15:48:54.547 [INF] CNCT: Creating ChannelArbitrators for 3 active channels
2018-11-29 15:48:54.548 [INF] NTFN: New block epoch subscription
2018-11-29 15:48:54.548 [INF] NTFN: New block epoch subscription
2018-11-29 15:48:54.553 [INF] NTFN: New block epoch subscription
2018-11-29 15:48:54.562 [INF] CNCT: Creating ChannelArbitrators for 1 closing channels
2018-11-29 15:48:54.563 [INF] NTFN: New block epoch subscription
2018-11-29 15:48:54.563 [INF] NTFN: New spend subscription: spend_id=1, outpoint=22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0, height_hint=550329
2018-11-29 15:48:54.563 [INF] NTFN: New spend subscription: spend_id=2, outpoint=970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1, height_hint=548889
2018-11-29 15:48:54.563 [INF] NTFN: New spend subscription: spend_id=3, outpoint=e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0, height_hint=550344
2018-11-29 15:48:54.584 [INF] CNCT: Close observer for ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0) active
2018-11-29 15:48:54.602 [INF] CNCT: Close observer for ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1) active
2018-11-29 15:48:54.621 [INF] CNCT: Close observer for ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0) active
2018-11-29 15:48:54.621 [INF] CNCT: ChannelArbitrator(c0e3a018c8fd9a8ab968aa1e2c216b42028920c6132e1d6ddd42f000ac41e165:1): starting state=StateWaitingFullResolution
2018-11-29 15:48:54.625 [INF] CNCT: ChannelArbitrator(c0e3a018c8fd9a8ab968aa1e2c216b42028920c6132e1d6ddd42f000ac41e165:1): still awaiting contract resolution
2018-11-29 15:48:54.625 [INF] CNCT: ChannelArbitrator(c0e3a018c8fd9a8ab968aa1e2c216b42028920c6132e1d6ddd42f000ac41e165:1): relaunching 1 contract resolvers
2018-11-29 15:48:54.626 [INF] CNCT: ChannelArbitrator(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0): starting state=StateDefault
2018-11-29 15:48:54.627 [INF] NTFN: New confirmation subscription: txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249, numconfs=1
2018-11-29 15:48:54.628 [INF] CNCT: *contractcourt.htlcTimeoutResolver(f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249:0): waiting second-level tx (txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249) to be fully confirmed
2018-11-29 15:48:54.635 [INF] CNCT: ChannelArbitrator(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0): starting state=StateDefault
2018-11-29 15:48:54.638 [INF] CNCT: ChannelArbitrator(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1): starting state=StateDefault
2018-11-29 15:48:54.650 [INF] DISC: Authenticated Gossiper is starting
2018-11-29 15:48:54.650 [INF] BRAR: Starting contract observer, watching for breaches.
2018-11-29 15:48:54.650 [INF] NTFN: New block epoch subscription
2018-11-29 15:48:54.677 [INF] CRTR: FilteredChainView starting
2018-11-29 15:48:55.160 [INF] CRTR: Filtering chain using 12955 channels active
2018-11-29 15:48:55.168 [INF] CRTR: Prune tip for Channel Graph: height=551935, hash=0000000000000000001c60b22763eff726cb5285670c637f8f6a58d72fa22055
2018-11-29 15:48:55.260 [INF] CMGR: Server listening on 192.168.2.101:20000
2018-11-29 15:48:55.287 [INF] SRVR: Initializing peer network bootstrappers!
2018-11-29 15:48:55.288 [INF] SRVR: Creating DNS peer bootstrapper with seeds: [[nodes.lightning.directory soa.nodes.lightning.directory]]
2018-11-29 15:48:55.288 [INF] DISC: Attempting to bootstrap with: Authenticated Channel Graph
2018-11-29 15:48:55.313 [INF] DISC: Obtained 3 addrs to bootstrap network with
2018-11-29 15:48:55.341 [INF] SRVR: Established connection to: 80.211.252.216:9735
2018-11-29 15:48:55.342 [INF] SRVR: Finalizing connection to 03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c, inbound=false
2018-11-29 15:48:55.388 [INF] PEER: NodeKey(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c) loading ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1)
2018-11-29 15:48:55.398 [INF] HSWC: Removing channel link with ChannelID(4d50651060dfd60b9356bc08554cbfabe39fd1b274cbacbcb4bdaddbd3dd0d96)
2018-11-29 15:48:55.399 [INF] HSWC: ChannelLink(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1) is starting
2018-11-29 15:48:55.400 [INF] HSWC: Trimming open circuits for chan_id=548889:84:1, start_htlc_id=4
2018-11-29 15:48:55.400 [INF] HSWC: Adding live link chan_id=4d50651060dfd60b9356bc08554cbfabe39fd1b274cbacbcb4bdaddbd3dd0d96, short_chan_id=548889:84:1
2018-11-29 15:48:55.400 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1)
2018-11-29 15:48:55.400 [INF] HSWC: HTLC manager for ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1) started, bandwidth=12150000 mSAT
2018-11-29 15:48:55.401 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1)
2018-11-29 15:48:55.402 [INF] SRVR: Negotiated chan series queries with 03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c
2018-11-29 15:48:55.402 [INF] DISC: Creating new gossipSyncer for peer=03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c
2018-11-29 15:48:55.403 [INF] DISC: gossipSyncer(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c): requesting new chans from height=551780 and 4294415515 blocks after
2018-11-29 15:48:55.427 [INF] HSWC: Received re-establishment message from remote side for channel(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1)
2018-11-29 15:48:55.495 [INF] SRVR: Established connection to: 46.229.165.138:9735
2018-11-29 15:48:55.495 [INF] SRVR: Finalizing connection to 03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618, inbound=false
2018-11-29 15:48:55.512 [INF] SRVR: Established connection to: 46.229.165.140:9735
2018-11-29 15:48:55.512 [INF] SRVR: Finalizing connection to 031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2, inbound=false
2018-11-29 15:48:55.602 [INF] SRVR: Established connection to: 98.204.71.100:9735
2018-11-29 15:48:55.603 [INF] SRVR: Finalizing connection to 02fe079f0737c4d5b7bd5add5e4ce1bdc2f0b79fcbe4b45aad8388f05b54ac1df8, inbound=false
2018-11-29 15:48:55.617 [INF] PEER: NodeKey(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618) loading ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0)
2018-11-29 15:48:55.626 [INF] HSWC: Removing channel link with ChannelID(0e0a9782840ecba987920c228edba7b942997bb892e156c173d78a4391d0ff22)
2018-11-29 15:48:55.627 [INF] HSWC: ChannelLink(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0) is starting
2018-11-29 15:48:55.627 [INF] HSWC: Trimming open circuits for chan_id=550329:757:0, start_htlc_id=0
2018-11-29 15:48:55.627 [INF] HSWC: Adding live link chan_id=0e0a9782840ecba987920c228edba7b942997bb892e156c173d78a4391d0ff22, short_chan_id=550329:757:0
2018-11-29 15:48:55.627 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0)
2018-11-29 15:48:55.628 [INF] SRVR: Negotiated chan series queries with 03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618
2018-11-29 15:48:55.628 [INF] DISC: Creating new gossipSyncer for peer=03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618
2018-11-29 15:48:55.628 [INF] HSWC: HTLC manager for ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0) started, bandwidth=0 mSAT
2018-11-29 15:48:55.629 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0)
2018-11-29 15:48:55.629 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): requesting new chans from height=551780 and 4294415515 blocks after
2018-11-29 15:48:55.630 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): filtering chan range: start_height=551780, num_blocks=4294415515
2018-11-29 15:48:55.631 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): sending final chan range chunk, size=131
2018-11-29 15:48:55.632 [INF] HSWC: Received re-establishment message from remote side for channel(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0)
2018-11-29 15:48:55.635 [INF] PEER: NodeKey(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2) loading ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0)
2018-11-29 15:48:55.639 [INF] HSWC: Removing channel link with ChannelID(e1f6a6b924c9290a9d785b4216fd4d3927a285f1dc5e94b09951229dafe4bde1)
2018-11-29 15:48:55.639 [INF] HSWC: ChannelLink(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0) is starting
2018-11-29 15:48:55.641 [INF] HSWC: Trimming open circuits for chan_id=550344:1283:0, start_htlc_id=0
2018-11-29 15:48:55.641 [INF] HSWC: Adding live link chan_id=e1f6a6b924c9290a9d785b4216fd4d3927a285f1dc5e94b09951229dafe4bde1, short_chan_id=550344:1283:0
2018-11-29 15:48:55.641 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0)
2018-11-29 15:48:55.641 [INF] HSWC: HTLC manager for ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0) started, bandwidth=0 mSAT
2018-11-29 15:48:55.642 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0)
2018-11-29 15:48:55.643 [INF] SRVR: Negotiated chan series queries with 031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2
2018-11-29 15:48:55.643 [INF] DISC: Creating new gossipSyncer for peer=031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2
2018-11-29 15:48:55.643 [INF] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): requesting new chans from height=551780 and 4294415515 blocks after
2018-11-29 15:48:55.645 [INF] HSWC: Received re-establishment message from remote side for channel(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0)
2018-11-29 15:48:55.645 [INF] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): filtering chan range: start_height=551780, num_blocks=4294415515
2018-11-29 15:48:55.646 [INF] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): sending final chan range chunk, size=131
2018-11-29 15:48:55.685 [INF] SRVR: Established connection to: 45.50.46.221:9735
2018-11-29 15:48:55.686 [INF] SRVR: Finalizing connection to 02445ff6a24e69242d6f6f38e1b7e8ae9c01eb9b660f3daf3304cb4b7cfeb79a99, inbound=false
2018-11-29 15:48:55.727 [INF] SRVR: Pruning peer 02fe079f0737c4d5b7bd5add5e4ce1bdc2f0b79fcbe4b45aad8388f05b54ac1df8 from persistent connections, number of open channels is now zero
2018-11-29 15:48:55.727 [INF] SRVR: Negotiated chan series queries with 02fe079f0737c4d5b7bd5add5e4ce1bdc2f0b79fcbe4b45aad8388f05b54ac1df8
2018-11-29 15:48:55.728 [INF] DISC: Creating new gossipSyncer for peer=02fe079f0737c4d5b7bd5add5e4ce1bdc2f0b79fcbe4b45aad8388f05b54ac1df8
2018-11-29 15:48:55.728 [INF] DISC: gossipSyncer(02fe079f0737c4d5b7bd5add5e4ce1bdc2f0b79fcbe4b45aad8388f05b54ac1df8): requesting new chans from height=551780 and 4294415515 blocks after
2018-11-29 15:48:55.731 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): buffering chan range reply of size=132
2018-11-29 15:48:55.731 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): filtering through 132 chans
2018-11-29 15:48:55.731 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): starting query for 1 new chans
2018-11-29 15:48:55.731 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): querying for 1 new channels
2018-11-29 15:48:55.745 [INF] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): buffering chan range reply of size=131
2018-11-29 15:48:55.745 [INF] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): filtering through 131 chans
2018-11-29 15:48:55.746 [INF] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): remote peer has no new chans
2018-11-29 15:48:55.747 [INF] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): applying gossipFilter(start=2018-11-29 14:48:55.747184111 +0000 UTC m=-3562.671001803)
2018-11-29 15:48:55.869 [INF] SRVR: Pruning peer 02445ff6a24e69242d6f6f38e1b7e8ae9c01eb9b660f3daf3304cb4b7cfeb79a99 from persistent connections, number of open channels is now zero
2018-11-29 15:48:55.869 [INF] SRVR: Negotiated chan series queries with 02445ff6a24e69242d6f6f38e1b7e8ae9c01eb9b660f3daf3304cb4b7cfeb79a99
2018-11-29 15:48:55.870 [INF] DISC: Creating new gossipSyncer for peer=02445ff6a24e69242d6f6f38e1b7e8ae9c01eb9b660f3daf3304cb4b7cfeb79a99
2018-11-29 15:48:55.870 [INF] DISC: gossipSyncer(02445ff6a24e69242d6f6f38e1b7e8ae9c01eb9b660f3daf3304cb4b7cfeb79a99): requesting new chans from height=551780 and 4294415515 blocks after
2018-11-29 15:48:55.871 [INF] DISC: gossipSyncer(02445ff6a24e69242d6f6f38e1b7e8ae9c01eb9b660f3daf3304cb4b7cfeb79a99): filtering chan range: start_height=551780, num_blocks=4294415515
2018-11-29 15:48:55.872 [INF] DISC: gossipSyncer(02445ff6a24e69242d6f6f38e1b7e8ae9c01eb9b660f3daf3304cb4b7cfeb79a99): sending final chan range chunk, size=131
2018-11-29 15:48:56.009 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): applying new update horizon: start=2018-11-29 14:48:55 +0000 UTC, end=2155-01-05 21:17:10 +0000 UTC, backlog_size=3301
2018-11-29 15:48:56.009 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): no more chans to query
2018-11-29 15:48:56.009 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): applying gossipFilter(start=2018-11-29 14:48:56.009707131 +0000 UTC m=-3562.408477908)
2018-11-29 15:48:56.055 [INF] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): applying new update horizon: start=2018-11-29 14:47:24 +0000 UTC, end=2155-01-05 21:15:39 +0000 UTC, backlog_size=3319
2018-11-29 15:48:56.075 [INF] DISC: gossipSyncer(02445ff6a24e69242d6f6f38e1b7e8ae9c01eb9b660f3daf3304cb4b7cfeb79a99): buffering chan range reply of size=131
2018-11-29 15:48:56.076 [INF] DISC: gossipSyncer(02445ff6a24e69242d6f6f38e1b7e8ae9c01eb9b660f3daf3304cb4b7cfeb79a99): filtering through 131 chans
2018-11-29 15:48:56.077 [INF] DISC: gossipSyncer(02445ff6a24e69242d6f6f38e1b7e8ae9c01eb9b660f3daf3304cb4b7cfeb79a99): remote peer has no new chans
2018-11-29 15:48:56.078 [INF] DISC: gossipSyncer(02445ff6a24e69242d6f6f38e1b7e8ae9c01eb9b660f3daf3304cb4b7cfeb79a99): applying gossipFilter(start=2018-11-29 14:48:56.078074797 +0000 UTC m=-3562.340110743)
2018-11-29 15:48:56.274 [INF] DISC: gossipSyncer(02445ff6a24e69242d6f6f38e1b7e8ae9c01eb9b660f3daf3304cb4b7cfeb79a99): applying new update horizon: start=2018-11-29 14:48:55 +0000 UTC, end=2155-01-05 21:17:10 +0000 UTC, backlog_size=3301
2018-11-29 15:48:58.465 [INF] CRTR: New channel discovered! Link connects 0219c2f8818bd2124dcc41827b726fd486c13cdfb6edf4e1458194663fb07891c7 and 02cdf83ef8e45908b1092125d25c68dcec7751ca8d39f557775cd842e5bc127469 with ChannelPoint(6011fdf59d97eb96b79296766b8d07123b6dca66e6f941959a618854eb918600:1): chan_id=599630761031630849, capacity=0.00500002 BTC
2018-11-29 15:48:58.701 [INF] DISC: gossipSyncer(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c): applying new update horizon: start=1970-01-01 00:00:00 +0000 UTC, end=2106-02-07 06:28:15 +0000 UTC, backlog_size=39361
2018-11-29 15:48:58.702 [INF] DISC: gossipSyncer(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c): buffering chan range reply of size=136
2018-11-29 15:48:58.702 [INF] DISC: gossipSyncer(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c): filtering through 136 chans
2018-11-29 15:48:58.704 [INF] DISC: gossipSyncer(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c): starting query for 5 new chans
2018-11-29 15:48:58.704 [INF] DISC: Received new remote channel announcement: (*lnwire.AnnounceSignatures)(0x1696000)({
ChannelID: (lnwire.ChannelID) (len=32 cap=32) 4d50651060dfd60b9356bc08554cbfabe39fd1b274cbacbcb4bdaddbd3dd0d96,
ShortChannelID: (lnwire.ShortChannelID) 548889:84:1,
NodeSignature: (lnwire.Sig) (len=64 cap=64) {
00000000 de 73 54 dd 7d 1c 43 5b 3a 23 9b e5 2d 32 81 84 |.sT.}.C[:#..-2..|
00000010 9e ce 25 f5 f9 88 0c 52 27 96 f6 a7 01 2c 16 ca |..%....R'....,..|
00000020 6b f4 ff 0d d7 52 28 09 9b ee 34 3d 7c 83 a3 cd |k....R(...4=|...|
00000030 18 5f 71 16 4f 3f e4 f7 a4 3b 11 6d a9 2b 15 23 |._q.O?...;.m.+.#|
},
BitcoinSignature: (lnwire.Sig) (len=64 cap=64) {
00000000 2e f6 a9 08 e2 d5 a7 39 98 d8 19 26 81 ee 41 58 |.......9...&..AX|
00000010 74 3a 81 13 e2 df 26 40 e1 b7 c0 bd d1 5c 1d 5e |t:....&@......^|
00000020 3b c3 aa 17 89 0e d7 5f 4a 6f be 22 ce 6b d5 8c |;......_Jo.".k..|
00000030 a5 d5 f2 a8 c7 09 6a 39 6f 6f 9a 0f 70 6b b2 5b |......j9oo..pk.[|
},
ExtraOpaqueData: ([]uint8)
})

2018-11-29 15:48:58.704 [INF] DISC: gossipSyncer(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c): querying for 5 new channels
2018-11-29 15:48:59.181 [INF] DISC: gossipSyncer(02fe079f0737c4d5b7bd5add5e4ce1bdc2f0b79fcbe4b45aad8388f05b54ac1df8): applying new update horizon: start=1970-01-01 00:00:00 +0000 UTC, end=2106-02-07 06:28:15 +0000 UTC, backlog_size=39361
2018-11-29 15:48:59.182 [INF] DISC: gossipSyncer(02fe079f0737c4d5b7bd5add5e4ce1bdc2f0b79fcbe4b45aad8388f05b54ac1df8): buffering chan range reply of size=131
2018-11-29 15:48:59.182 [INF] DISC: gossipSyncer(02fe079f0737c4d5b7bd5add5e4ce1bdc2f0b79fcbe4b45aad8388f05b54ac1df8): filtering through 131 chans
2018-11-29 15:48:59.184 [INF] DISC: gossipSyncer(02fe079f0737c4d5b7bd5add5e4ce1bdc2f0b79fcbe4b45aad8388f05b54ac1df8): remote peer has no new chans
2018-11-29 15:48:59.184 [INF] DISC: gossipSyncer(02fe079f0737c4d5b7bd5add5e4ce1bdc2f0b79fcbe4b45aad8388f05b54ac1df8): applying gossipFilter(start=2018-11-29 14:48:59.184278079 +0000 UTC m=-3559.233907544)
2018-11-29 15:49:23.010 [INF] CRTR: New channel discovered! Link connects 0360e59bf60cabdb0aababf410fd5c567ef61a59503eb4fbb4d1699596f4b6bdc5 and 03adae695ae0e060a75dd6a3a1db11f9d70de1e9a298d112cc593e4631beefd123 with ChannelPoint(e9243a4224f5a5b5723335790b9f051b84e703da34c19b2bec719931c71060d4:0): chan_id=556562890413768704, capacity=0.00002 BTC
2018-11-29 15:49:23.037 [INF] CRTR: New channel discovered! Link connects 02c119d2fd2e98a88f50d0d2ee4213255b7b8ec2be3a95f9aabd6afb09dd25b083 and 03381d03415d45d91c342752ec48d6ae77b7bd676c217d9233e4acb3f207b966d0 with ChannelPoint(97ee87fd60a86c61a4b1877e6e5aea322d469ba44975f645e31d799e33f57e9e:0): chan_id=556466133422899200, capacity=0.0001 BTC
2018-11-29 15:49:23.052 [INF] CRTR: New channel discovered! Link connects 0235447c7485ff2b945bac5fbc366d54a87389bab8cacf1b64b26ec01e96bd165a and 02d4079fbbed8f92d4eb57712dae93c9df909a8fe876e771b8349380c2c08da37f with ChannelPoint(c245118b23d776ee1ce3b34fb855fd577da638a3cf2bda2cc22d60a628c2061d:0): chan_id=556328694560522240, capacity=0.0005 BTC
2018-11-29 15:49:23.076 [INF] CRTR: New channel discovered! Link connects 0331a2398d2787f39af6d958994dd4edc3e809f567b717377863d4a23a62bfd8e3 and 034d11119748816bac2e5f2b4f3127e05d783e39b6e9b65b8db9920ec553506301 with ChannelPoint(cb638fd6a732ac974e523546861bcbad055262983d385b8c256e17917fc995f5:0): chan_id=567042335844925440, capacity=0.00002222 BTC
2018-11-29 15:49:23.214 [INF] CRTR: New channel discovered! Link connects 02dcdd7e18b80dc7fd51af34e871901c13f574e4b82325dc74c0beeada5771e8e9 and 037b7cd33aada9dd91ccb95857d8f71c34fd31c426057016f28f48b0633ae844cd with ChannelPoint(60fb6f448bc254be734b99ce596ace1d1bc5b7bc8e20fa2540bad1c8e10f495f:0): chan_id=560425474860449792, capacity=0.00002 BTC
2018-11-29 15:49:23.230 [INF] CRTR: New channel discovered! Link connects 020976875f2a90838859bcdb280b6dacdcc0a9854764b5ff02b138ac9ca91a5e8c and 023337924c8c847b6b78982d0baa8efd3c48a65facb987fdd277a04c7c7791a4eb with ChannelPoint(ec8e0b27854889505e56fab47d905406efbe76dd77036d0aadab393576dbe30c:0): chan_id=556484825142984704, capacity=0.000011 BTC
2018-11-29 15:49:23.242 [INF] CRTR: New channel discovered! Link connects 0222a8b36a27a067fd358c7f2858f7bf639c85762dcff091c99e6325bb4701677a and 02f6725f9c1c40333b67faea92fd211c183050f28df32cac3f9d69685fe9665432 with ChannelPoint(dc174ef9c52f9c9b6b4fbf1008316cca3e59fb012ae8c124edda39e9e4b9e478:1): chan_id=561211625577644033, capacity=0.002 BTC
2018-11-29 15:49:23.256 [INF] CRTR: New channel discovered! Link connects 023337924c8c847b6b78982d0baa8efd3c48a65facb987fdd277a04c7c7791a4eb and 02f6725f9c1c40333b67faea92fd211c183050f28df32cac3f9d69685fe9665432 with ChannelPoint(d0d6b717ddab8bf613a3584b4d24ceee7a678d0da9a71115e1928588c0d50be2:0): chan_id=556461735434977280, capacity=0.000011 BTC
2018-11-29 15:49:23.274 [INF] CRTR: New channel discovered! Link connects 027ccec61f4bf1fafb5156931da6527dc104ec3613dd4f4050161d89dd76ab494c and 03adae695ae0e060a75dd6a3a1db11f9d70de1e9a298d112cc593e4631beefd123 with ChannelPoint(5fa795a66f4c5d890436b075a0643d90ba4d15c66b4d831c546a5cdbf0ab7f6a:0): chan_id=565449143387226112, capacity=0.00010103 BTC
2018-11-29 15:49:24.678 [INF] DISC: Broadcasting batch of 40 new announcements

@halseth
Copy link
Contributor

halseth commented Dec 3, 2018

@sangaman Yes, try setting debuglevel=debug and post the logs after lnd restart!

@davidknezic Seems like the HTLC spend does not get confirmed. Can you also try setting debuglevel=debug and restart lnd?

@davidknezic
Copy link
Contributor

Hi @halseth, thanks for helping out!

lnd.log
2018-12-03 19:52:39.202 [WRN] LTND: open /mnt/data/lnd/coincenter/lnd.conf: no such file or directory
2018-12-03 19:52:39.203 [INF] LTND: Version: 0.5.1-beta commit=v0.5.1-beta-73-gf4b6e0b7755982fc571e2763e0a2ec93c8e89900-dirty, build=production, logging=default
2018-12-03 19:52:39.204 [INF] LTND: Active chain: Bitcoin (network=mainnet)
2018-12-03 19:52:39.207 [INF] CHDB: Checking for schema update: latest_version=7, db_version=7
2018-12-03 19:52:39.211 [INF] RPCS: password RPC server listening on [::]:20001
2018-12-03 19:52:39.212 [INF] RPCS: password gRPC proxy started at [::]:20002
2018-12-03 19:52:39.212 [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.
2018-12-03 19:52:55.122 [INF] LNWL: Opened wallet
2018-12-03 19:52:55.332 [INF] LTND: Primary chain is set to: bitcoin
2018-12-03 19:52:55.350 [INF] LTND: Initializing bitcoind backed fee estimator
2018-12-03 19:52:55.350 [INF] LNWL: Started listening for bitcoind block notifications via ZMQ on tcp://127.0.0.1:28332
2018-12-03 19:52:55.350 [INF] LNWL: Started listening for bitcoind transaction notifications via ZMQ on tcp://127.0.0.1:28333
2018-12-03 19:52:55.352 [DBG] LNWL: Using minimum fee rate of 253 sat/kw
2018-12-03 19:52:57.950 [INF] LNWL: The wallet has been unlocked without a time limit
2018-12-03 19:52:57.957 [INF] LTND: LightningWallet opened
2018-12-03 19:52:57.957 [DBG] LNWL: Birthday block has already been verified: height=544644, hash=000000000000000000047ef072fc5d0a49f0239b11aff67af74751e8048c9b83
2018-12-03 19:52:57.979 [INF] HSWC: Restoring in-memory circuit state from disk
2018-12-03 19:52:57.986 [INF] HSWC: Payment circuits loaded: num_pending=1, num_open=1
2018-12-03 19:52:58.004 [INF] HSWC: Trimming open circuits for chan_id=552208:1162:1, start_htlc_id=0
2018-12-03 19:52:58.004 [INF] HSWC: Trimming open circuits for chan_id=550344:1283:0, start_htlc_id=0
2018-12-03 19:52:58.004 [INF] HSWC: Trimming open circuits for chan_id=550329:757:0, start_htlc_id=0
2018-12-03 19:52:58.004 [INF] HSWC: Trimming open circuits for chan_id=548889:84:1, start_htlc_id=4
2018-12-03 19:52:58.025 [DBG] LTND: Populating dependencies for sub RPC server: SignRPC
2018-12-03 19:52:58.025 [INF] RPCS: RPC server listening on [::]:20001
2018-12-03 19:52:58.026 [INF] RPCS: gRPC proxy started at [::]:20002
2018-12-03 19:52:58.029 [INF] LTND: Waiting for chain backend to finish sync, start_height=552421
2018-12-03 19:52:58.036 [INF] LNWL: Started rescan from block 0000000000000000001c8566f33f3438e8b2d09a7f70e8f77c6fdeef06581508 (height 552421) for 57 addresses
2018-12-03 19:52:58.043 [INF] LNWL: Starting rescan from block 0000000000000000001c8566f33f3438e8b2d09a7f70e8f77c6fdeef06581508
2018-12-03 19:52:58.051 [INF] LNWL: Rescan finished at 552421 (0000000000000000001c8566f33f3438e8b2d09a7f70e8f77c6fdeef06581508)
2018-12-03 19:52:58.051 [INF] LNWL: Catching up block hashes to height 552421, this might take a while
2018-12-03 19:52:58.059 [INF] LNWL: Done catching up block hashes
2018-12-03 19:52:58.059 [INF] LNWL: Finished rescan for 57 addresses (synced to block 0000000000000000001c8566f33f3438e8b2d09a7f70e8f77c6fdeef06581508, height 552421)
2018-12-03 19:52:59.052 [INF] LTND: Chain backend is fully synced (end_height=552421)!
2018-12-03 19:52:59.069 [INF] HSWC: Starting HTLC Switch
2018-12-03 19:52:59.069 [INF] NTFN: New block epoch subscription
2018-12-03 19:52:59.069 [INF] NTFN: New block epoch subscription
2018-12-03 19:52:59.128 [INF] NTFN: New block epoch subscription
2018-12-03 19:52:59.145 [INF] UTXN: Re-registering confirmations for 1 already graduated heights below height=552421
2018-12-03 19:52:59.145 [DBG] UTXN: Attempting to regraduate outputs at height=548021
2018-12-03 19:52:59.146 [INF] UTXN: Re-registering confirmation for first-stage HTLC outputs at height=548021 
2018-12-03 19:52:59.146 [INF] UTXN: Publishing CLTV-delayed HTLC output using timeout tx (txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249): (*wire.MsgTx)(0x18dfd40)({
 Version: (int32) 2,
 TxIn: ([]*wire.TxIn) (len=1 cap=1) {
  (*wire.TxIn)(0x15f9240)({
   PreviousOutPoint: (wire.OutPoint) e85d5c6b906fb66c10765ab4ff1018cd22d6c934e937fd6199a61edebec50e20:1,
   SignatureScript: ([]uint8) {
   },
   Witness: (wire.TxWitness) (len=5 cap=5) {
    ([]uint8) {
    },
    ([]uint8) (len=72 cap=72) {
     00000000  30 45 02 21 00 d8 8a d3  ad fb b2 92 1a 5f cb c3  |0E.!........._..|
     00000010  fb 15 58 3b 7b 95 8f 5e  ba 47 0f 66 a7 f9 89 03  |..X;{..^.G.f....|
     00000020  8e 25 b6 4f f9 02 20 68  97 f7 3b 81 17 0e 1a d0  |.%.O.. h..;.....|
     00000030  a2 d9 3c 2a 54 b5 fc e0  e2 1f 49 4e 15 7d 03 eb  |..<*T.....IN.}..|
     00000040  3d d1 ca e7 5e a1 4b 01                           |=...^.K.|
    },
    ([]uint8) (len=72 cap=72) {
     00000000  30 45 02 21 00 ab f0 19  69 ea 6d c9 1b 05 8e de  |0E.!....i.m.....|
     00000010  85 83 d0 3a 40 04 f8 93  a8 72 8e 0a 69 20 e7 fd  |...:@....r..i ..|
     00000020  17 58 38 fa 8d 02 20 1d  c0 91 67 4a ef b4 af c6  |.X8... ...gJ....|
     00000030  0a 24 f3 4f 0d b7 5b ec  e9 5a 91 6b 9b ef 1a e5  |.$.O..[..Z.k....|
     00000040  2b 63 b3 9c b0 0d 91 01                           |+c......|
    },
    ([]uint8) {
    },
    ([]uint8) (len=133 cap=133) {
     00000000  76 a9 14 6e 11 c8 20 c2  a1 24 65 f7 c8 71 62 17  |v..n.. ..$e..qb.|
     00000010  f9 a7 e6 a0 b8 5b 60 87  63 ac 67 21 03 90 8c 47  |.....[`.c.g!...G|
     00000020  67 a5 d4 ea 8b b4 52 78  ed 84 a4 41 c9 9f f3 99  |g.....Rx...A....|
     00000030  59 dd e0 86 fb b9 a6 3c  62 e8 75 c7 71 7c 82 01  |Y......2018-12-03 19:52:59.147 [INF] LNWL: Inserting unconfirmed transaction f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249
2018-12-03 19:52:59.170 [INF] NTFN: New confirmation subscription: txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249, numconfs=1
2018-12-03 19:52:59.170 [DBG] NTFN: Using height hint 552421 retrieved from cache for f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249
2018-12-03 19:52:59.170 [DBG] NTFN: Dispatching historical rescan for txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249
2018-12-03 19:52:59.170 [INF] UTXN: Htlc output f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249:0 registered for promotion notification.
2018-12-03 19:52:59.178 [DBG] NTFN: Conf details for txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249 not found during historical dispatch, waiting to dispatch at tip
2018-12-03 19:52:59.238 [INF] CNCT: Creating ChannelArbitrators for 4 active channels
2018-12-03 19:52:59.239 [DBG] CNCT: New ChainEventSubscription(id=0) for ChannelPoint(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1)
2018-12-03 19:52:59.239 [DBG] CNCT: New ChainEventSubscription(id=0) for ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0)
2018-12-03 19:52:59.239 [INF] NTFN: New block epoch subscription
2018-12-03 19:52:59.239 [INF] NTFN: New block epoch subscription
2018-12-03 19:52:59.239 [DBG] CNCT: New ChainEventSubscription(id=0) for ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0)
2018-12-03 19:52:59.240 [DBG] CNCT: New ChainEventSubscription(id=0) for ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1)
2018-12-03 19:52:59.240 [INF] NTFN: New block epoch subscription
2018-12-03 19:52:59.240 [INF] NTFN: New block epoch subscription
2018-12-03 19:52:59.250 [INF] CNCT: Creating ChannelArbitrators for 1 closing channels
2018-12-03 19:52:59.251 [INF] NTFN: New block epoch subscription
2018-12-03 19:52:59.251 [DBG] CNCT: Starting chain watcher for ChannelPoint(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1)
2018-12-03 19:52:59.251 [DBG] CNCT: Starting chain watcher for ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1)
2018-12-03 19:52:59.251 [DBG] CNCT: Starting chain watcher for ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0)
2018-12-03 19:52:59.251 [DBG] NTFN: Using height hint 550344 retrieved from cache for e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0
2018-12-03 19:52:59.251 [DBG] CNCT: Starting chain watcher for ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0)
2018-12-03 19:52:59.251 [DBG] NTFN: Using height hint 548889 retrieved from cache for 970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1
2018-12-03 19:52:59.251 [DBG] NTFN: Using height hint 552208 retrieved from cache for 0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1
2018-12-03 19:52:59.251 [INF] NTFN: New spend subscription: spend_id=3, outpoint=e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0, height_hint=550344
2018-12-03 19:52:59.252 [DBG] NTFN: Using height hint 550329 retrieved from cache for 22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0
2018-12-03 19:52:59.252 [INF] NTFN: New spend subscription: spend_id=2, outpoint=970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1, height_hint=548889
2018-12-03 19:52:59.253 [INF] NTFN: New spend subscription: spend_id=1, outpoint=0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1, height_hint=552208
2018-12-03 19:52:59.253 [INF] NTFN: New spend subscription: spend_id=4, outpoint=22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0, height_hint=550329
2018-12-03 19:52:59.276 [INF] CNCT: Close observer for ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0) active
2018-12-03 19:52:59.296 [INF] CNCT: Close observer for ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1) active
2018-12-03 19:52:59.315 [INF] CNCT: Close observer for ChannelPoint(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1) active
2018-12-03 19:52:59.333 [INF] CNCT: Close observer for ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0) active
2018-12-03 19:52:59.333 [DBG] CNCT: Starting ChannelArbitrator(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1), htlc_set=(contractcourt.htlcSet) {
incomingHTLCs: (map[uint64]channeldb.HTLC) {
},
outgoingHTLCs: (map[uint64]channeldb.HTLC) {
}
}

2018-12-03 19:52:59.334 [INF] CNCT: ChannelArbitrator(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1): starting state=StateDefault
2018-12-03 19:52:59.339 [DBG] CNCT: ChannelArbitrator(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1): new block (height=552421) examining active HTLC's
2018-12-03 19:52:59.339 [DBG] CNCT: ChannelArbitrator(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1): checking chain actions at height=552421
2018-12-03 19:52:59.340 [DBG] CNCT: Starting ChannelArbitrator(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0), htlc_set=(contractcourt.htlcSet) {
incomingHTLCs: (map[uint64]channeldb.HTLC) {
},
outgoingHTLCs: (map[uint64]channeldb.HTLC) {
}
}

2018-12-03 19:52:59.340 [INF] CNCT: ChannelArbitrator(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0): starting state=StateDefault
2018-12-03 19:52:59.343 [DBG] CNCT: ChannelArbitrator(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0): new block (height=552421) examining active HTLC's
2018-12-03 19:52:59.344 [DBG] CNCT: ChannelArbitrator(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0): checking chain actions at height=552421
2018-12-03 19:52:59.344 [DBG] CNCT: Starting ChannelArbitrator(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0), htlc_set=(contractcourt.htlcSet) {
incomingHTLCs: (map[uint64]channeldb.HTLC) {
},
outgoingHTLCs: (map[uint64]channeldb.HTLC) {
}
}

2018-12-03 19:52:59.344 [INF] CNCT: ChannelArbitrator(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0): starting state=StateDefault
2018-12-03 19:52:59.347 [DBG] CNCT: ChannelArbitrator(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0): new block (height=552421) examining active HTLC's
2018-12-03 19:52:59.348 [DBG] CNCT: ChannelArbitrator(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0): checking chain actions at height=552421
2018-12-03 19:52:59.348 [DBG] CNCT: Starting ChannelArbitrator(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1), htlc_set=(contractcourt.htlcSet) {
incomingHTLCs: (map[uint64]channeldb.HTLC) {
},
outgoingHTLCs: (map[uint64]channeldb.HTLC) {
}
}

2018-12-03 19:52:59.348 [INF] CNCT: ChannelArbitrator(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1): starting state=StateDefault
2018-12-03 19:52:59.351 [DBG] CNCT: ChannelArbitrator(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1): new block (height=552421) examining active HTLC's
2018-12-03 19:52:59.351 [DBG] CNCT: ChannelArbitrator(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1): checking chain actions at height=552421
2018-12-03 19:52:59.351 [DBG] CNCT: Starting ChannelArbitrator(c0e3a018c8fd9a8ab968aa1e2c216b42028920c6132e1d6ddd42f000ac41e165:1), htlc_set=(contractcourt.htlcSet) {
incomingHTLCs: (map[uint64]channeldb.HTLC) {
},
outgoingHTLCs: (map[uint64]channeldb.HTLC) {
}
}

2018-12-03 19:52:59.351 [INF] CNCT: ChannelArbitrator(c0e3a018c8fd9a8ab968aa1e2c216b42028920c6132e1d6ddd42f000ac41e165:1): starting state=StateWaitingFullResolution
2018-12-03 19:52:59.354 [INF] CNCT: ChannelArbitrator(c0e3a018c8fd9a8ab968aa1e2c216b42028920c6132e1d6ddd42f000ac41e165:1): still awaiting contract resolution
2018-12-03 19:52:59.357 [INF] CNCT: ChannelArbitrator(c0e3a018c8fd9a8ab968aa1e2c216b42028920c6132e1d6ddd42f000ac41e165:1): relaunching 1 contract resolvers
2018-12-03 19:52:59.357 [DBG] CNCT: ChannelArbitrator(c0e3a018c8fd9a8ab968aa1e2c216b42028920c6132e1d6ddd42f000ac41e165:1): attempting to resolve *contractcourt.htlcTimeoutResolver
2018-12-03 19:52:59.357 [DBG] CNCT: ChannelArbitrator(c0e3a018c8fd9a8ab968aa1e2c216b42028920c6132e1d6ddd42f000ac41e165:1): contract *contractcourt.htlcTimeoutResolver not yet resolved
2018-12-03 19:52:59.357 [INF] NTFN: New confirmation subscription: txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249, numconfs=1
2018-12-03 19:52:59.357 [DBG] NTFN: Using height hint 552421 retrieved from cache for f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249
2018-12-03 19:52:59.358 [DBG] NTFN: Attempting to dispatch conf for txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249 on registration since rescan has finished
2018-12-03 19:52:59.358 [DBG] NTFN: Unable to dispatch f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249, no details provided
2018-12-03 19:52:59.358 [INF] CNCT: *contractcourt.htlcTimeoutResolver(f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249:0): waiting second-level tx (txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249) to be fully confirmed
2018-12-03 19:52:59.369 [INF] DISC: Authenticated Gossiper is starting
2018-12-03 19:52:59.369 [INF] BRAR: Starting contract observer, watching for breaches.
2018-12-03 19:52:59.369 [INF] NTFN: New block epoch subscription
2018-12-03 19:52:59.372 [INF] CRTR: FilteredChainView starting
2018-12-03 19:52:59.809 [INF] CRTR: Filtering chain using 12587 channels active
2018-12-03 19:52:59.815 [INF] CRTR: Prune tip for Channel Graph: height=552421, hash=0000000000000000001c8566f33f3438e8b2d09a7f70e8f77c6fdeef06581508
2018-12-03 19:52:59.918 [INF] CMGR: Server listening on 192.168.2.101:20000
2018-12-03 19:52:59.956 [DBG] SRVR: Attempting persistent connection to channel peer 0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4@51.15.123.173:9735
2018-12-03 19:52:59.957 [DBG] SRVR: Attempting persistent connection to channel peer 0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4@88.208.115.66:37050
2018-12-03 19:52:59.957 [DBG] CMGR: Attempting to connect to 0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4@51.15.123.173:9735 (reqid 1)
2018-12-03 19:52:59.958 [DBG] SRVR: Attempting persistent connection to channel peer 031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2@46.229.165.140:47800
2018-12-03 19:52:59.958 [DBG] CMGR: Attempting to connect to 0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4@88.208.115.66:37050 (reqid 2)
2018-12-03 19:52:59.959 [DBG] CMGR: Attempting to connect to 031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2@46.229.165.140:47800 (reqid 3)
2018-12-03 19:52:59.959 [DBG] SRVR: Attempting persistent connection to channel peer 031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2@46.229.165.140:9735
2018-12-03 19:52:59.960 [DBG] SRVR: Attempting persistent connection to channel peer 03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618@46.229.165.138:9735
2018-12-03 19:52:59.960 [DBG] CMGR: Attempting to connect to 031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2@46.229.165.140:9735 (reqid 4)
2018-12-03 19:52:59.961 [DBG] SRVR: Attempting persistent connection to channel peer 03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618@46.229.165.138:50319
2018-12-03 19:52:59.961 [DBG] SRVR: Attempting persistent connection to channel peer 03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c@80.211.252.216:9735
2018-12-03 19:52:59.961 [DBG] CMGR: Attempting to connect to 03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618@46.229.165.138:9735 (reqid 5)
2018-12-03 19:52:59.961 [DBG] CMGR: Attempting to connect to 03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618@46.229.165.138:50319 (reqid 6)
2018-12-03 19:52:59.961 [INF] SRVR: Initializing peer network bootstrappers!
2018-12-03 19:52:59.962 [INF] SRVR: Creating DNS peer bootstrapper with seeds: [[nodes.lightning.directory soa.nodes.lightning.directory]]
2018-12-03 19:52:59.962 [DBG] CMGR: Attempting to connect to 03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c@80.211.252.216:9735 (reqid 7)
2018-12-03 19:52:59.962 [INF] DISC: Attempting to bootstrap with: Authenticated Channel Graph
2018-12-03 19:52:59.987 [INF] DISC: Obtained 3 addrs to bootstrap network with
2018-12-03 19:53:00.008 [ERR] SRVR: Unable to connect to 02fb74056358782bf2b555c80807fa29c9ddfbe5051cfadf2eb83871c155544391@85.214.73.34:9735: dial tcp 85.214.73.34:9735: connect: connection refused
2018-12-03 19:53:00.008 [ERR] SRVR: Unable to connect to 02fb74056358782bf2b555c80807fa29c9ddfbe5051cfadf2eb83871c155544391@85.214.73.34:9735: dial tcp 85.214.73.34:9735: connect: connection refused
2018-12-03 19:53:00.039 [INF] SRVR: Established connection to: 35.195.6.96:9735
2018-12-03 19:53:00.039 [INF] SRVR: Finalizing connection to 0256c4eb4c563ab602a46431092635fdcaaeeab21727ed92241412ddd4a5c2814e, inbound=false
2018-12-03 19:53:00.040 [DBG] CMGR: Connected to 03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c@80.211.252.216:9735 (reqid 7)
2018-12-03 19:53:00.040 [INF] SRVR: Established connection to: 80.211.252.216:9735
2018-12-03 19:53:00.040 [INF] SRVR: Finalizing connection to 03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c, inbound=false
2018-12-03 19:53:00.040 [DBG] PEER: Sending Init to 35.195.6.96:9735
2018-12-03 19:53:00.041 [DBG] PEER: Sending Init to 80.211.252.216:9735
2018-12-03 19:53:00.056 [DBG] PEER: Received Init from 35.195.6.96:9735
2018-12-03 19:53:00.057 [INF] SRVR: Pruning peer 0256c4eb4c563ab602a46431092635fdcaaeeab21727ed92241412ddd4a5c2814e from persistent connections, number of open channels is now zero
2018-12-03 19:53:00.058 [DBG] PEER: Loaded 0 active channels from database with NodeKey(0256c4eb4c563ab602a46431092635fdcaaeeab21727ed92241412ddd4a5c2814e)
2018-12-03 19:53:00.059 [INF] SRVR: Requesting full table sync with 0256c4eb4c563ab602a46431092635fdcaaeeab21727ed92241412ddd4a5c2814e
2018-12-03 19:53:00.060 [DBG] CMGR: Failed to connect to 031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2@46.229.165.140:47800 (reqid 3): dial tcp 46.229.165.140:47800: connect: connection refused
2018-12-03 19:53:00.062 [DBG] CMGR: Retrying connection to 031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2@46.229.165.140:47800 (reqid 3) in 5s
2018-12-03 19:53:00.064 [DBG] CMGR: Failed to connect to 03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618@46.229.165.138:50319 (reqid 6): dial tcp 46.229.165.138:50319: connect: connection refused
2018-12-03 19:53:00.065 [DBG] CMGR: Retrying connection to 03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618@46.229.165.138:50319 (reqid 6) in 5s
2018-12-03 19:53:00.070 [DBG] CMGR: Connected to 0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4@51.15.123.173:9735 (reqid 1)
2018-12-03 19:53:00.073 [INF] SRVR: Established connection to: 51.15.123.173:9735
2018-12-03 19:53:00.073 [INF] SRVR: Finalizing connection to 0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4, inbound=false
2018-12-03 19:53:00.073 [DBG] CMGR: Canceling: 0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4@88.208.115.66:37050 (reqid 2)
2018-12-03 19:53:00.074 [DBG] PEER: Received Init from 80.211.252.216:9735
2018-12-03 19:53:00.075 [DBG] PEER: Sending Init to 51.15.123.173:9735
2018-12-03 19:53:00.082 [DBG] PEER: Loaded 1 active channels from database with NodeKey(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c)
2018-12-03 19:53:00.089 [DBG] LNWL: ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1), starting local commitment: (*lnwallet.commitment)(0x216a000)({
height: (uint64) 34,
isOurs: (bool) true,
ourMessageIndex: (uint64) 13,
theirMessageIndex: (uint64) 13,
ourHtlcIndex: (uint64) 4,
theirHtlcIndex: (uint64) 9,
txn: (*wire.MsgTx)(0x28420a0)({
Version: (int32) 2,
TxIn: ([]*wire.TxIn) (len=1 cap=1) {
(*wire.TxIn)(0x28b4140)({
PreviousOutPoint: (wire.OutPoint) 970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1,
SignatureScript: ([]uint8) {
},
Witness: (wire.TxWitness) ,
Sequence: (uint32) 2162582271
})
},
TxOut: ([]*wire.TxOut) (len=2 cap=2) {
(*wire.TxOut)(0x28b0060)({
Value: (int64) 20198,
PkScript: ([]uint8) (len=34 cap=34) {
00000000 00 20 a9 58 51 42 58 3d 50 37 ed 0a 94 5f 2d b5 |. .XQBX=P7..._-.|
00000010 f9 96 18 89 a3 8f 4f 6f 07 04 1d 31 9b fb 5d 71 |......Oo...1..]q|
00000020 13 49 |.I|
}
}),
(*wire.TxOut)(0x28b0074)({
Value: (int64) 374150,
PkScript: ([]uint8) (len=22 cap=22) {
00000000 00 14 aa 21 51 f3 ed d8 98 29 f8 27 d6 3c 50 33 |...!Q....).'.<P3|
00000010 eb 7b 29 d2 49 6f |.{).Io|
}
})
},
LockTime: (uint32) 548012592
}),
sig: ([]uint8) (len=70 cap=70) {
00000000 30 44 02 20 7b 5e 14 59 07 ba 57 60 29 84 d4 cd |0D. {^.Y..W`)...|
00000010 4d 2e d0 97 df 82 a9 18 96 df 13 2f 33 0c 55 95 |M........../3.U.|
00000020 e3 b5 27 08 02 20 50 9f 21 49 8b e9 58 ef d2 87 |..'.. P.!I..X...|
00000030 27 78 f6 f7 13 e0 84 61 6f 8c cf 73 ae 50 ae 16 |'x.....ao..s.P..|
00000040 69 98 4e ac 15 aa |i.N...|
},
ourBalance: (lnwire.MilliSatoshi) 20198000 mSAT,
theirBalance: (lnwire.MilliSatoshi) 374150000 mSAT,
fee: (btcutil.Amount) 0.00005652 BTC,
feePerKw: (lnwallet.SatPerKWeight) 7808,
dustLimit: (btcutil.Amount) 0.00000573 BTC,
outgoingHTLCs: ([]lnwallet.PaymentDescriptor) ,
incomingHTLCs: ([]lnwallet.PaymentDescriptor) ,
outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
},
incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
}
})

2018-12-03 19:53:00.112 [DBG] LNWL: ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1), starting remote commitment: (*lnwallet.commitment)(0x2826000)({
height: (uint64) 34,
isOurs: (bool) false,
ourMessageIndex: (uint64) 13,
theirMessageIndex: (uint64) 13,
ourHtlcIndex: (uint64) 4,
theirHtlcIndex: (uint64) 9,
txn: (*wire.MsgTx)(0x2842120)({
Version: (int32) 2,
TxIn: ([]*wire.TxIn) (len=1 cap=1) {
(*wire.TxIn)(0x28b4200)({
PreviousOutPoint: (wire.OutPoint) 970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1,
SignatureScript: ([]uint8) {
},
Witness: (wire.TxWitness) ,
Sequence: (uint32) 2162582271
})
},
TxOut: ([]*wire.TxOut) (len=2 cap=2) {
(*wire.TxOut)(0x28b0090)({
Value: (int64) 20198,
PkScript: ([]uint8) (len=22 cap=22) {
00000000 00 14 ed eb ce fd 1f 67 54 08 44 7d 87 56 06 b1 |.......gT.D}.V..|
00000010 20 c3 41 18 64 ec | .A.d.|
}
}),
(*wire.TxOut)(0x28b00a4)({
Value: (int64) 374150,
PkScript: ([]uint8) (len=34 cap=34) {
00000000 00 20 e3 18 17 f4 19 f3 c9 58 d9 a0 2a 38 f9 ba |. .......X..*8..|
00000010 8f 5d 2b 16 4d ce 4e 74 18 1d 63 42 2f 3a 54 62 |.]+.M.Nt..cB/:Tb|
00000020 da 05 |..|
}
})
},
LockTime: (uint32) 548012592
}),
sig: ([]uint8) {
},
ourBalance: (lnwire.MilliSatoshi) 20198000 mSAT,
theirBalance: (lnwire.MilliSatoshi) 374150000 mSAT,
fee: (btcutil.Amount) 0.00005652 BTC,
feePerKw: (lnwallet.SatPerKWeight) 7808,
dustLimit: (btcutil.Amount) 0.00000546 BTC,
outgoingHTLCs: ([]lnwallet.PaymentDescriptor) ,
incomingHTLCs: ([]lnwallet.PaymentDescriptor) ,
outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
},
incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
}
})

2018-12-03 19:53:00.113 [INF] PEER: NodeKey(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c) loading ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1)
2018-12-03 19:53:00.119 [DBG] CNCT: New ChainEventSubscription(id=1) for ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1)
2018-12-03 19:53:00.119 [INF] HSWC: Removing channel link with ChannelID(4d50651060dfd60b9356bc08554cbfabe39fd1b274cbacbcb4bdaddbd3dd0d96)
2018-12-03 19:53:00.119 [INF] HSWC: ChannelLink(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1) is starting
2018-12-03 19:53:00.119 [INF] HSWC: Trimming open circuits for chan_id=548889:84:1, start_htlc_id=4
2018-12-03 19:53:00.120 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1)
2018-12-03 19:53:00.120 [INF] HSWC: Adding live link chan_id=4d50651060dfd60b9356bc08554cbfabe39fd1b274cbacbcb4bdaddbd3dd0d96, short_chan_id=548889:84:1
2018-12-03 19:53:00.120 [INF] HSWC: HTLC manager for ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1) started, bandwidth=16198000 mSAT
2018-12-03 19:53:00.120 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1)
2018-12-03 19:53:00.120 [INF] SRVR: Negotiated chan series queries with 03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c
2018-12-03 19:53:00.121 [INF] DISC: Creating new gossipSyncer for peer=03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c
2018-12-03 19:53:00.121 [DBG] DISC: Starting gossipSyncer(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c)
2018-12-03 19:53:00.121 [DBG] DISC: gossipSyncer(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c): state=syncingChans
2018-12-03 19:53:00.121 [INF] DISC: gossipSyncer(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c): requesting new chans from height=552272 and 4294415023 blocks after
2018-12-03 19:53:00.121 [DBG] DISC: gossipSyncer(03f18da23535adee245903c81750745197e3079d3b88b3898981c90a5f2411008c): state=waitingQueryRangeReply
2018-12-03 19:53:00.121 [DBG] PEER: Sending QueryChannelRange(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, start_height=552272, num_blocks=4294415023) to 80.211.252.216:9735
2018-12-03 19:53:00.122 [DBG] PEER: Sending ChannelReestablish(next_local_height=35, remote_tail_height=34) to 80.211.252.216:9735
2018-12-03 19:53:00.123 [DBG] SRVR: Announcing channel(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1) disabled=false
2018-12-03 19:53:00.124 [DBG] PEER: Received Init from 51.15.123.173:9735
2018-12-03 19:53:00.129 [DBG] PEER: Loaded 1 active channels from database with NodeKey(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4)
2018-12-03 19:53:00.142 [DBG] LNWL: ChannelPoint(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1), starting local commitment: (*lnwallet.commitment)(0x1b6a480)({
height: (uint64) 0,
isOurs: (bool) true,
ourMessageIndex: (uint64) 0,
theirMessageIndex: (uint64) 0,
ourHtlcIndex: (uint64) 0,
theirHtlcIndex: (uint64) 0,
txn: (*wire.MsgTx)(0x18aa280)({
Version: (int32) 2,
TxIn: ([]*wire.TxIn) (len=1 cap=1) {
(*wire.TxIn)(0x216c0c0)({
PreviousOutPoint: (wire.OutPoint) 0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1,
SignatureScript: ([]uint8) {
},
Witness: (wire.TxWitness) ,
Sequence: (uint32) 2153147959
})
},
TxOut: ([]*wire.TxOut) (len=1 cap=1) {
(*wire.TxOut)(0x18aa2a0)({
Value: (int64) 4994349,
PkScript: ([]uint8) (len=22 cap=22) {
00000000 00 14 4f 67 ce e4 75 6b 25 5c da 6a 3c ae 17 f1 |..Og..uk%.j<...|
00000010 a3 10 ff 52 1d 7d |...R.}|
}
})
},
LockTime: (uint32) 541341084
}),
sig: ([]uint8) (len=71 cap=71) {
00000000 30 45 02 21 00 e5 98 56 94 42 ef 64 58 b9 e3 6e |0E.!...V.B.dX..n|
00000010 ab 3b 16 7e 39 02 b2 82 c7 a1 75 cd 0d 00 a4 17 |.;.~9.....u.....|
00000020 d2 8e f5 28 96 02 20 6d 93 4e 1d 33 1f a9 56 2d |...(.. m.N.3..V-|
00000030 6a 2e 4f 8f 29 1e 5c 44 d2 12 05 74 2d 3c de 37 |j.O.).\D...t-<.7|
00000040 96 40 23 86 9b 3d b5 |.@#..=.|
},
ourBalance: (lnwire.MilliSatoshi) 0 mSAT,
theirBalance: (lnwire.MilliSatoshi) 4994349000 mSAT,
fee: (btcutil.Amount) 0.00005652 BTC,
feePerKw: (lnwallet.SatPerKWeight) 7808,
dustLimit: (btcutil.Amount) 0.00000573 BTC,
outgoingHTLCs: ([]lnwallet.PaymentDescriptor) ,
incomingHTLCs: ([]lnwallet.PaymentDescriptor) ,
outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
},
incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
}
})

2018-12-03 19:53:00.148 [DBG] PEER: Received ChannelReestablish(next_local_height=35, remote_tail_height=34) from 80.211.252.216:9735
2018-12-03 19:53:00.148 [INF] HSWC: Received re-establishment message from remote side for channel(970dddd3dbadbdb4bcaccb74b2d19fe3abbf4c5508bc56930bd6df601065504d:1)
2018-12-03 19:53:00.149 [DBG] LNWL: ChannelPoint(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1), starting remote commitment: (*lnwallet.commitment)(0x1932000)({
height: (uint64) 0,
isOurs: (bool) false,
ourMessageIndex: (uint64) 0,
theirMessageIndex: (uint64) 0,
ourHtlcIndex: (uint64) 0,
theirHtlcIndex: (uint64) 0,
txn: (*wire.MsgTx)(0x18aa2e0)({
Version: (int32) 2,
TxIn: ([]*wire.TxIn) (len=1 cap=1) {
(*wire.TxIn)(0x216c180)({
PreviousOutPoint: (wire.OutPoint) 0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1,
SignatureScript: ([]uint8) {
},
Witness: (wire.TxWitness) ,
Sequence: (uint32) 2153147959
})
},
TxOut: ([]*wire.TxOut) (len=1 cap=1) {
(*wire.TxOut)(0x18aa300)({
Value: (int64) 4994349,
PkScript: ([]uint8) (len=34 cap=34) {
00000000 00 20 42 09 17 4a b9 52 66 1b 52 94 5c 0a 8a d9 |. B..J.Rf.R....|
00000010 24 43 7d eb 18 7f e9 9b 48 84 95 1c 42 54 c4 b5 |$C}.....H...BT..|
00000020 51 eb |Q.|
}
})
},
LockTime: (uint32) 541341084
}),
sig: ([]uint8) {
},
ourBalance: (lnwire.MilliSatoshi) 0 mSAT,
theirBalance: (lnwire.MilliSatoshi) 4994349000 mSAT,
fee: (btcutil.Amount) 0.00005652 BTC,
feePerKw: (lnwallet.SatPerKWeight) 7808,
dustLimit: (btcutil.Amount) 0.00000573 BTC,
outgoingHTLCs: ([]lnwallet.PaymentDescriptor) ,
incomingHTLCs: ([]lnwallet.PaymentDescriptor) ,
outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
},
incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
}
})

2018-12-03 19:53:00.150 [INF] PEER: NodeKey(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4) loading ChannelPoint(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1)
2018-12-03 19:53:00.158 [DBG] CNCT: New ChainEventSubscription(id=1) for ChannelPoint(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1)
2018-12-03 19:53:00.158 [INF] HSWC: Removing channel link with ChannelID(b83e3cd863a6379c06b7ac71ff688c5d508ef5c198a1dd28dadd2a900f475002)
2018-12-03 19:53:00.158 [INF] HSWC: ChannelLink(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1) is starting
2018-12-03 19:53:00.158 [INF] HSWC: Trimming open circuits for chan_id=552208:1162:1, start_htlc_id=0
2018-12-03 19:53:00.159 [INF] HSWC: Adding live link chan_id=b83e3cd863a6379c06b7ac71ff688c5d508ef5c198a1dd28dadd2a900f475002, short_chan_id=552208:1162:1
2018-12-03 19:53:00.159 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1)
2018-12-03 19:53:00.159 [INF] SRVR: Negotiated chan series queries with 0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4
2018-12-03 19:53:00.159 [INF] DISC: Creating new gossipSyncer for peer=0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4
2018-12-03 19:53:00.159 [DBG] DISC: Starting gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4)
2018-12-03 19:53:00.159 [INF] HSWC: HTLC manager for ChannelPoint(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1) started, bandwidth=0 mSAT
2018-12-03 19:53:00.160 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1)
2018-12-03 19:53:00.160 [DBG] DISC: gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4): state=syncingChans
2018-12-03 19:53:00.160 [INF] DISC: gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4): requesting new chans from height=552272 and 4294415023 blocks after
2018-12-03 19:53:00.160 [DBG] DISC: gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4): state=waitingQueryRangeReply
2018-12-03 19:53:00.160 [DBG] PEER: Sending QueryChannelRange(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, start_height=552272, num_blocks=4294415023) to 51.15.123.173:9735
2018-12-03 19:53:00.161 [DBG] PEER: Sending ChannelReestablish(next_local_height=1, remote_tail_height=0) to 51.15.123.173:9735
2018-12-03 19:53:00.161 [DBG] PEER: Received ChannelReestablish(next_local_height=1, remote_tail_height=0) from 51.15.123.173:9735
2018-12-03 19:53:00.162 [DBG] PEER: Received QueryChannelRange(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, start_height=552272, num_blocks=4294415023) from 51.15.123.173:9735
2018-12-03 19:53:00.162 [INF] HSWC: ChannelPoint(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1): resending FundingLocked message to peer
2018-12-03 19:53:00.162 [INF] DISC: gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4): filtering chan range: start_height=552272, num_blocks=4294415023
2018-12-03 19:53:00.162 [INF] DISC: gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4): sending final chan range chunk, size=192
2018-12-03 19:53:00.162 [DBG] DISC: gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4): state=waitingQueryRangeReply
2018-12-03 19:53:00.163 [INF] HSWC: Received re-establishment message from remote side for channel(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1)
2018-12-03 19:53:00.163 [DBG] PEER: Sending ReplyChannelRange(complete=1, encoding=0, num_chans=192) to 51.15.123.173:9735
2018-12-03 19:53:00.163 [DBG] PEER: Sending FundingLocked(chan_id=b83e3cd863a6379c06b7ac71ff688c5d508ef5c198a1dd28dadd2a900f475002, next_point=027f55bbd578f918d76eb19a229a98eaa7912fd8100faf1323ffd3fb6652dac646) to 51.15.123.173:9735
2018-12-03 19:53:00.164 [DBG] SRVR: Announcing channel(0350470f902addda28dda198c1f58e505d8c68ff71acb7069c37a663d83c3eb8:1) disabled=false
2018-12-03 19:53:00.167 [DBG] HSWC: ChannelLink(548889:84:1) loaded 0 fwd pks
2018-12-03 19:53:00.176 [DBG] CMGR: Connected to 031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2@46.229.165.140:9735 (reqid 4)
2018-12-03 19:53:00.176 [INF] SRVR: Established connection to: 46.229.165.140:9735
2018-12-03 19:53:00.176 [INF] SRVR: Finalizing connection to 031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2, inbound=false
2018-12-03 19:53:00.177 [DBG] CMGR: Canceling: 031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2@46.229.165.140:47800 (reqid 3)
2018-12-03 19:53:00.177 [DBG] PEER: Sending Init to 46.229.165.140:9735
2018-12-03 19:53:00.178 [DBG] CMGR: Connected to 03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618@46.229.165.138:9735 (reqid 5)
2018-12-03 19:53:00.178 [INF] SRVR: Established connection to: 46.229.165.138:9735
2018-12-03 19:53:00.179 [INF] SRVR: Finalizing connection to 03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618, inbound=false
2018-12-03 19:53:00.179 [DBG] CMGR: Canceling: 03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618@46.229.165.138:50319 (reqid 6)
2018-12-03 19:53:00.179 [DBG] PEER: Sending Init to 46.229.165.138:9735
2018-12-03 19:53:00.181 [DBG] PEER: Received GossipTimestampRange(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, first_stamp=1970-01-01 00:00:00 +0000 UTC, stamp_range=4294967295) from 80.211.252.216:9735
2018-12-03 19:53:00.182 [DBG] PEER: Received AnnounceSignatures(chan_id=4d50651060dfd60b9356bc08554cbfabe39fd1b274cbacbcb4bdaddbd3dd0d96, short_chan_id=603509837863845889) from 80.211.252.216:9735
2018-12-03 19:53:00.182 [DBG] PEER: Received ReplyChannelRange(complete=1, encoding=1, num_chans=196) from 80.211.252.216:9735
2018-12-03 19:53:00.190 [DBG] HSWC: ChannelLink(552208:1162:1) loaded 0 fwd pks
2018-12-03 19:53:00.212 [DBG] PEER: Received FundingLocked(chan_id=b83e3cd863a6379c06b7ac71ff688c5d508ef5c198a1dd28dadd2a900f475002, next_point=0355ac3fcf0a66644e5a20fa1aa0e019b5f3b5bf8a57afb7d9683b7f3f9cbe0800) from 51.15.123.173:9735
2018-12-03 19:53:00.212 [DBG] FNDG: Received FundingLocked for ChannelID(b83e3cd863a6379c06b7ac71ff688c5d508ef5c198a1dd28dadd2a900f475002) from peer 0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4
2018-12-03 19:53:00.212 [DBG] PEER: Received ReplyChannelRange(complete=1, encoding=0, num_chans=195) from 51.15.123.173:9735
2018-12-03 19:53:00.213 [INF] DISC: gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4): buffering chan range reply of size=195
2018-12-03 19:53:00.213 [INF] DISC: gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4): filtering through 195 chans
2018-12-03 19:53:00.215 [INF] DISC: gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4): starting query for 3 new chans
2018-12-03 19:53:00.215 [DBG] DISC: gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4): state=queryNewChannels
2018-12-03 19:53:00.216 [INF] DISC: gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4): querying for 3 new channels
2018-12-03 19:53:00.216 [DBG] DISC: gossipSyncer(0279c22ed7a068d10dc1a38ae66d2d6461e269226c60258c021b1ddcdfe4b00bc4): state=waitingQueryChanReply
2018-12-03 19:53:00.216 [DBG] PEER: Sending QueryShortChanIDs(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, encoding=0, num_chans=3) to 51.15.123.173:9735
2018-12-03 19:53:00.218 [DBG] PEER: Received GossipTimestampRange(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, first_stamp=2018-12-03 18:53:00 +0000 UTC, stamp_range=4294967295) from 51.15.123.173:9735
2018-12-03 19:53:00.272 [DBG] PEER: Received ReplyShortChanIDsEnd(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, complete=1) from 51.15.123.173:9735
2018-12-03 19:53:00.277 [DBG] PEER: Received Init from 46.229.165.140:9735
2018-12-03 19:53:00.281 [DBG] PEER: Received Init from 46.229.165.138:9735
2018-12-03 19:53:00.286 [DBG] PEER: Loaded 1 active channels from database with NodeKey(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2)
2018-12-03 19:53:00.290 [INF] FNDG: Received duplicate fundingLocked for ChannelID(b83e3cd863a6379c06b7ac71ff688c5d508ef5c198a1dd28dadd2a900f475002), ignoring.
2018-12-03 19:53:00.291 [DBG] PEER: Loaded 1 active channels from database with NodeKey(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618)
2018-12-03 19:53:00.309 [DBG] LNWL: ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0), starting local commitment: (*lnwallet.commitment)(0x2756000)({
height: (uint64) 76,
isOurs: (bool) true,
ourMessageIndex: (uint64) 0,
theirMessageIndex: (uint64) 0,
ourHtlcIndex: (uint64) 0,
theirHtlcIndex: (uint64) 0,
txn: (*wire.MsgTx)(0x2864060)({
Version: (int32) 2,
TxIn: ([]*wire.TxIn) (len=1 cap=1) {
(*wire.TxIn)(0x223e080)({
PreviousOutPoint: (wire.OutPoint) e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0,
SignatureScript: ([]uint8) {
},
Witness: (wire.TxWitness) ,
Sequence: (uint32) 2155502777
})
},
TxOut: ([]*wire.TxOut) (len=1 cap=1) {
(*wire.TxOut)(0x2864080)({
Value: (int64) 8994345,
PkScript: ([]uint8) (len=22 cap=22) {
00000000 00 14 cb fe 9b a3 93 a8 cf e7 03 4d d4 ec d2 67 |...........M...g|
00000010 62 44 06 27 49 96 |bD.'I.|
}
})
},
LockTime: (uint32) 553586050
}),
sig: ([]uint8) (len=71 cap=71) {
00000000 30 45 02 21 00 ad 50 7d eb f4 8f e6 4f f7 03 03 |0E.!..P}....O...|
00000010 5b 05 ff e5 a9 94 a3 2d 48 7a e1 4b 90 e8 6a 2b |[......-Hz.K..j+|
00000020 dc 81 16 c3 f3 02 20 49 e5 1d 57 85 09 83 3e e1 |...... I..W...>.|
00000030 9a 05 da 34 5b d7 63 f5 ba f5 f3 6c 36 26 bb d9 |...4[.c....l6&..|
00000040 9f 0a 22 09 78 a2 e9 |..".x..|
},
ourBalance: (lnwire.MilliSatoshi) 0 mSAT,
theirBalance: (lnwire.MilliSatoshi) 8994345000 mSAT,
fee: (btcutil.Amount) 0.00005655 BTC,
feePerKw: (lnwallet.SatPerKWeight) 7812,
dustLimit: (btcutil.Amount) 0.00000573 BTC,
outgoingHTLCs: ([]lnwallet.PaymentDescriptor) ,
incomingHTLCs: ([]lnwallet.PaymentDescriptor) ,
outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
},
incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
}
})

2018-12-03 19:53:00.314 [DBG] LNWL: ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0), starting local commitment: (*lnwallet.commitment)(0x288a000)({
height: (uint64) 52,
isOurs: (bool) true,
ourMessageIndex: (uint64) 0,
theirMessageIndex: (uint64) 0,
ourHtlcIndex: (uint64) 0,
theirHtlcIndex: (uint64) 0,
txn: (*wire.MsgTx)(0x2183380)({
Version: (int32) 2,
TxIn: ([]*wire.TxIn) (len=1 cap=1) {
(*wire.TxIn)(0x1d4b2c0)({
PreviousOutPoint: (wire.OutPoint) 22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0,
SignatureScript: ([]uint8) {
},
Witness: (wire.TxWitness) ,
Sequence: (uint32) 2157495666
})
},
TxOut: ([]*wire.TxOut) (len=1 cap=1) {
(*wire.TxOut)(0x21833a0)({
Value: (int64) 894348,
PkScript: ([]uint8) (len=22 cap=22) {
00000000 00 14 d5 f4 02 29 46 fe ff c2 ab 03 3b 12 a3 4e |.....)F.....;..N|
00000010 8e 0e d1 9c 3b b9 |....;.|
}
})
},
LockTime: (uint32) 544703609
}),
sig: ([]uint8) (len=71 cap=71) {
00000000 30 45 02 21 00 a0 17 05 ef 6f 62 d1 01 ec 37 8a |0E.!.....ob...7.|
00000010 62 b3 5b 3e 65 c4 f1 bf 96 f9 6a 04 de 0a e4 56 |b.[>e.....j....V|
00000020 69 a5 c9 63 24 02 20 34 d1 e7 3b 73 a1 d2 9a 35 |i..c$. 4..;s...5|
00000030 0d 79 b6 ea 74 c3 93 9c 64 7d c8 86 8e 57 77 1b |.y..t...d}...Ww.|
00000040 f1 b2 4f bd 3e 5e 2d |..O.>^-|
},
ourBalance: (lnwire.MilliSatoshi) 0 mSAT,
theirBalance: (lnwire.MilliSatoshi) 894348000 mSAT,
fee: (btcutil.Amount) 0.00005652 BTC,
feePerKw: (lnwallet.SatPerKWeight) 7808,
dustLimit: (btcutil.Amount) 0.00000573 BTC,
outgoingHTLCs: ([]lnwallet.PaymentDescriptor) ,
incomingHTLCs: ([]lnwallet.PaymentDescriptor) ,
outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
},
incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
}
})

2018-12-03 19:53:00.317 [DBG] LNWL: ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0), starting remote commitment: (*lnwallet.commitment)(0x1f7a000)({
height: (uint64) 76,
isOurs: (bool) false,
ourMessageIndex: (uint64) 0,
theirMessageIndex: (uint64) 0,
ourHtlcIndex: (uint64) 0,
theirHtlcIndex: (uint64) 0,
txn: (*wire.MsgTx)(0x2864100)({
Version: (int32) 2,
TxIn: ([]*wire.TxIn) (len=1 cap=1) {
(*wire.TxIn)(0x223e140)({
PreviousOutPoint: (wire.OutPoint) e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0,
SignatureScript: ([]uint8) {
},
Witness: (wire.TxWitness) ,
Sequence: (uint32) 2155502777
})
},
TxOut: ([]*wire.TxOut) (len=1 cap=1) {
(*wire.TxOut)(0x2864120)({
Value: (int64) 8994345,
PkScript: ([]uint8) (len=34 cap=34) {
00000000 00 20 ee 0d da 02 7f 0c 18 09 71 47 d3 39 a6 37 |. ........qG.9.7|
00000010 2f d7 d9 48 8e 4d 83 43 17 f0 1c fe 33 22 1c f9 |/..H.M.C....3"..|
00000020 9f 7f |..|
}
})
},
LockTime: (uint32) 553586050
}),
sig: ([]uint8) {
},
ourBalance: (lnwire.MilliSatoshi) 0 mSAT,
theirBalance: (lnwire.MilliSatoshi) 8994345000 mSAT,
fee: (btcutil.Amount) 0.00005655 BTC,
feePerKw: (lnwallet.SatPerKWeight) 7812,
dustLimit: (btcutil.Amount) 0.00000573 BTC,
outgoingHTLCs: ([]lnwallet.PaymentDescriptor) ,
incomingHTLCs: ([]lnwallet.PaymentDescriptor) ,
outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
},
incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
}
})

2018-12-03 19:53:00.318 [INF] PEER: NodeKey(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2) loading ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0)
2018-12-03 19:53:00.322 [DBG] LNWL: ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0), starting remote commitment: (*lnwallet.commitment)(0x2756090)({
height: (uint64) 52,
isOurs: (bool) false,
ourMessageIndex: (uint64) 0,
theirMessageIndex: (uint64) 0,
ourHtlcIndex: (uint64) 0,
theirHtlcIndex: (uint64) 0,
txn: (*wire.MsgTx)(0x21833e0)({
Version: (int32) 2,
TxIn: ([]*wire.TxIn) (len=1 cap=1) {
(*wire.TxIn)(0x169e480)({
PreviousOutPoint: (wire.OutPoint) 22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0,
SignatureScript: ([]uint8) {
},
Witness: (wire.TxWitness) ,
Sequence: (uint32) 2157495666
})
},
TxOut: ([]*wire.TxOut) (len=1 cap=1) {
(*wire.TxOut)(0x2183400)({
Value: (int64) 894348,
PkScript: ([]uint8) (len=34 cap=34) {
00000000 00 20 3e 0a 4d 94 81 c2 01 e8 84 28 c2 d6 21 0e |. >.M......(..!.|
00000010 a1 be f0 17 11 bd f9 da d7 4f d0 7b e2 d9 4c 05 |.........O.{..L.|
00000020 5f 1e |_.|
}
})
},
LockTime: (uint32) 544703609
}),
sig: ([]uint8) {
},
ourBalance: (lnwire.MilliSatoshi) 0 mSAT,
theirBalance: (lnwire.MilliSatoshi) 894348000 mSAT,
fee: (btcutil.Amount) 0.00005652 BTC,
feePerKw: (lnwallet.SatPerKWeight) 7808,
dustLimit: (btcutil.Amount) 0.00000573 BTC,
outgoingHTLCs: ([]lnwallet.PaymentDescriptor) ,
incomingHTLCs: ([]lnwallet.PaymentDescriptor) ,
outgoingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
},
incomingHTLCIndex: (map[int32]*lnwallet.PaymentDescriptor) {
}
})

2018-12-03 19:53:00.323 [INF] PEER: NodeKey(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618) loading ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0)
2018-12-03 19:53:00.324 [DBG] CNCT: New ChainEventSubscription(id=1) for ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0)
2018-12-03 19:53:00.325 [INF] HSWC: Removing channel link with ChannelID(e1f6a6b924c9290a9d785b4216fd4d3927a285f1dc5e94b09951229dafe4bde1)
2018-12-03 19:53:00.325 [INF] HSWC: ChannelLink(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0) is starting
2018-12-03 19:53:00.326 [INF] HSWC: Trimming open circuits for chan_id=550344:1283:0, start_htlc_id=0
2018-12-03 19:53:00.326 [INF] HSWC: Adding live link chan_id=e1f6a6b924c9290a9d785b4216fd4d3927a285f1dc5e94b09951229dafe4bde1, short_chan_id=550344:1283:0
2018-12-03 19:53:00.326 [INF] HSWC: HTLC manager for ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0) started, bandwidth=0 mSAT
2018-12-03 19:53:00.326 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0)
2018-12-03 19:53:00.326 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0)
2018-12-03 19:53:00.326 [INF] SRVR: Negotiated chan series queries with 031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2
2018-12-03 19:53:00.327 [INF] DISC: Creating new gossipSyncer for peer=031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2
2018-12-03 19:53:00.327 [DBG] DISC: Starting gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2)
2018-12-03 19:53:00.327 [DBG] PEER: Sending ChannelReestablish(next_local_height=77, remote_tail_height=76) to 46.229.165.140:9735
2018-12-03 19:53:00.327 [DBG] SRVR: Announcing channel(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0) disabled=false
2018-12-03 19:53:00.328 [DBG] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): state=syncingChans
2018-12-03 19:53:00.328 [DBG] PEER: Received ChannelReestablish(next_local_height=77, remote_tail_height=76) from 46.229.165.140:9735
2018-12-03 19:53:00.328 [INF] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): requesting new chans from height=552272 and 4294415023 blocks after
2018-12-03 19:53:00.328 [DBG] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): state=waitingQueryRangeReply
2018-12-03 19:53:00.329 [DBG] PEER: Sending QueryChannelRange(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, start_height=552272, num_blocks=4294415023) to 46.229.165.140:9735
2018-12-03 19:53:00.329 [DBG] PEER: Received QueryChannelRange(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, start_height=552272, num_blocks=4294415023) from 46.229.165.140:9735
2018-12-03 19:53:00.329 [INF] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): filtering chan range: start_height=552272, num_blocks=4294415023
2018-12-03 19:53:00.329 [INF] HSWC: Received re-establishment message from remote side for channel(e1bde4af9d225199b0945edcf185a227394dfd16425b789d0a29c924b9a6f6e1:0)
2018-12-03 19:53:00.330 [INF] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): sending final chan range chunk, size=192
2018-12-03 19:53:00.330 [DBG] DISC: gossipSyncer(031ce29116eab7edd66148f5169f1fb658fad62bdc5091221ab895fe5d36db00b2): state=waitingQueryRangeReply
2018-12-03 19:53:00.330 [DBG] PEER: Sending ReplyChannelRange(complete=1, encoding=0, num_chans=192) to 46.229.165.140:9735
2018-12-03 19:53:00.333 [DBG] CNCT: New ChainEventSubscription(id=1) for ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0)
2018-12-03 19:53:00.333 [INF] HSWC: Removing channel link with ChannelID(0e0a9782840ecba987920c228edba7b942997bb892e156c173d78a4391d0ff22)
2018-12-03 19:53:00.333 [INF] HSWC: ChannelLink(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0) is starting
2018-12-03 19:53:00.334 [INF] HSWC: Trimming open circuits for chan_id=550329:757:0, start_htlc_id=0
2018-12-03 19:53:00.334 [INF] HSWC: Adding live link chan_id=0e0a9782840ecba987920c228edba7b942997bb892e156c173d78a4391d0ff22, short_chan_id=550329:757:0
2018-12-03 19:53:00.334 [INF] HSWC: HTLC manager for ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0) started, bandwidth=0 mSAT
2018-12-03 19:53:00.334 [INF] HSWC: Attempting to re-resynchronize ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0)
2018-12-03 19:53:00.334 [INF] CNCT: Attempting to update ContractSignals for ChannelPoint(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0)
2018-12-03 19:53:00.334 [INF] SRVR: Negotiated chan series queries with 03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618
2018-12-03 19:53:00.335 [INF] DISC: Creating new gossipSyncer for peer=03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618
2018-12-03 19:53:00.335 [DBG] DISC: Starting gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618)
2018-12-03 19:53:00.335 [DBG] PEER: Sending ChannelReestablish(next_local_height=53, remote_tail_height=52) to 46.229.165.138:9735
2018-12-03 19:53:00.335 [DBG] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): state=syncingChans
2018-12-03 19:53:00.336 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): requesting new chans from height=552272 and 4294415023 blocks after
2018-12-03 19:53:00.336 [DBG] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): state=waitingQueryRangeReply
2018-12-03 19:53:00.336 [DBG] PEER: Sending QueryChannelRange(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, start_height=552272, num_blocks=4294415023) to 46.229.165.138:9735
2018-12-03 19:53:00.337 [DBG] PEER: Received ChannelReestablish(next_local_height=53, remote_tail_height=52) from 46.229.165.138:9735
2018-12-03 19:53:00.338 [INF] HSWC: Received re-establishment message from remote side for channel(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0)
2018-12-03 19:53:00.338 [DBG] PEER: Received QueryChannelRange(chain_hash=000000000019d6689c085ae165831e934ff763ae46a2a6c172b3f1b60a8ce26f, start_height=552272, num_blocks=4294415023) from 46.229.165.138:9735
2018-12-03 19:53:00.338 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): filtering chan range: start_height=552272, num_blocks=4294415023
2018-12-03 19:53:00.338 [INF] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): sending final chan range chunk, size=192
2018-12-03 19:53:00.339 [DBG] DISC: gossipSyncer(03d37fca0656558de4fd86bbe490a38d84a46228e7ec1361801f54f9437a18d618): state=waitingQueryRangeReply
2018-12-03 19:53:00.339 [DBG] PEER: Sending ReplyChannelRange(complete=1, encoding=0, num_chans=192) to 46.229.165.138:9735
2018-12-03 19:53:00.356 [DBG] SRVR: Announcing channel(22ffd091438ad773c156e192b87b9942b9a7db8e220c9287a9cb0e8482970a0e:0) disabled=false

I looked at entries mentioning the stuck channel c0e3a018c8fd9a8ab968aa1e2c216b42028920c6132e1d6ddd42f000ac41e165:1 or the pending HTLC f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249. Looks like you're right with your assumption that the HTLC never gets confirmed.

[INF] UTXN: Publishing CLTV-delayed HTLC output using timeout tx (txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249): ...

...

[INF] LNWL: Inserting unconfirmed transaction f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249
[INF] NTFN: New confirmation subscription: txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249, numconfs=1
[DBG] NTFN: Using height hint 552421 retrieved from cache for f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249
[DBG] NTFN: Dispatching historical rescan for txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249 
[INF] UTXN: Htlc output f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249:0 registered for promotion notification.
[DBG] NTFN: Conf details for txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249 not found during historical dispatch, waiting to dispatch at tip

...

[INF] NTFN: New confirmation subscription: txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249, numconfs=1
[DBG] NTFN: Using height hint 552421 retrieved from cache for f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249
[DBG] NTFN: Attempting to dispatch conf for txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249 on registration since rescan has finished
[DBG] NTFN: Unable to dispatch f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249, no details provided
[INF] CNCT: *contractcourt.htlcTimeoutResolver(f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249:0): waiting second-level tx (txid=f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249) to be fully confirmed

What could be the reason for that?

@halseth
Copy link
Contributor

halseth commented Dec 5, 2018

@davidknezic That's weird, looks like f835bee0b7e950be6bb7314867f4d9f1744d69e4200a6743c75f70c56713b249 is broadcasted, but doesn't make it onto the network.

Could be a fee issues, but then we should see an error. Do you have access to you bitcoin full node logs, to see how it handles the tx when it receives it?

@halseth
Copy link
Contributor

halseth commented Dec 5, 2018

Which backend are you using btw?

@Roasbeef
Copy link
Member

Bumping this thread to notify y'all that #1960 has been merged which should unstick the outputs!

@brndnmtthws
Copy link
Contributor

Can confirm, appears to be fixed. Thanks for the fine work.

This is gentlemen.

@sangaman
Copy link
Contributor

Great! My stuck pending channels are gone too. It took a little while - I did still see the pending channels with negative blocks shortly after updating - and I restarted lnd twice in the meantime to finally collect the logs @halseth requested earlier.

I do have the log output with debug from starting lnd to the point that it starts listening for p2p connections, if they would be of any value I can share them but otherwise everything seems fine now. Thanks!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
P2 should be fixed if one has time utxo sweeping
Projects
None yet
Development

No branches or pull requests

8 participants