sendcoins generated a transaction which did not show up in the network

[alevchuk]

What broke

lncli sendcoins generated a transaction, yet it did to show up in the blockchain explorer or the external wallet

Theory

A possible explanation is that lncli sendcoins seems to be able to generate transactions that will be rejected by the network

Environment

Testnet, Autopilot, 30 channels, running LND 83b779d (Feb 23)

Context (what happened?)

To do LND upgrade:

1. I turned off Autopilot
2. Closed all the channels (a few had to --force)
3. After about 1 hour all channels were still closed, and it looked like all funds were in the wallet (yet, I failed to grab the output of lncli walletbalance at that time)

It's usually difficult to see how much funds I have total among the wallet and the channels. Yet it looked like I had 2.3 tBTC available to transfer out. I tried moving out 2.3 tBTC as follows, and the command "succeed":

$ lncli sendcoins --addr tb1q<...> 230000000  --sat_per_byte 40
{
    "txid": "b0a732349958b2a771562fd25f05492fa3e6bcaa4af082daadb1aaf89e0641ee"
}

A day later, transaction is still not visible in testnet, and in the balances looks like I only have 1.6 tBTC:

$ lncli channelbalance
{
    "balance": "0"
}

$ lncli walletbalance
{
    "total_balance": "1637104",
    "confirmed_balance": "1080833",
    "unconfirmed_balance": "556271"
}

Did this ever work?

When funds are available

Yes. I used lncli sendcoins many times to do LND upgrades. The transaction would show up in the external wallet almost instantly (5 seconds) and then would get confirmed easily with --sat_per_byte 40. Yet, this time the transaction did not even show up.

When funds are not available

Yes. Many times when I specify the amount that was too large, lncli sendcoins would always tell me that not enough funds are available, and not generate a transaction.

Proposal (what I'd expect to happen)

Since funds may not be truly available until all the Timelock contracts are fulfilled, I expect that lncli sendcoins would report that funds are not yet available and not generate a transaction.

[alevchuk]

Interestingly b0a732349958b2a771562fd25f05492fa3e6bcaa4af082daadb1aaf89e0641ee does not show up inlncli listchaintxns

[alevchuk]

I found the transaction in the logs:

Somehow --sat_per_byte 40 became sat/byte=1

2018-03-09 23:19:22.879 [INF] DISC: Broadcasting batch of 6 new announcements
2018-03-09 23:19:52.879 [INF] DISC: Broadcasting batch of 1 new announcements
2018-03-09 23:20:22.879 [INF] DISC: Broadcasting batch of 1 new announcements
2018-03-09 23:21:10.267 [INF] RPCS: [sendcoins] addr=tb1q<...>, amt=2.3 BTC, sat/byte=1
2018-03-09 23:21:10.277 [INF] LNWL: Inserting unconfirmed transaction b0a732349958b2a771562fd25f05492fa3e6bcaa4af082daadb1aaf89e0641ee
2018-03-09 23:21:10.304 [INF] RPCS: [sendcoins] spend generated txid: b0a732349958b2a771562fd25f05492fa3e6bcaa4af082daadb1aaf89e0641ee
2018-03-09 23:21:22.879 [INF] DISC: Broadcasting batch of 5 new announcements
2018-03-09 23:22:22.879 [INF] DISC: Broadcasting batch of 1 new announcements
2018-03-09 23:22:52.879 [INF] DISC: Broadcasting batch of 1 new announcements

[Roasbeef]

Did your node have the transaction in its mempool? Were both your lnd and lncli binary built off of the same commit?

I just tried to reproduce, and the sat/byte gets translated properly:

⛰ lncli sendcoins --addr=sb1qyu0cqm7uavtr07zumr8sl0jf02uytcws9l4e7j --amt=100000 --sat_per_byte=40
{
    "txid": "6eaee07d1743b05379e7dd8213c9abe6a703dc4b785bfdcabae7e311417fc03b"
}

2018-03-10 12:41:34.194 [INF] RPCS: [sendcoins] addr=sb1qyu0cqm7uavtr07zumr8sl0jf02uytcws9l4e7j, amt=0.001 BTC, sat/vbyte=40

[alevchuk]

I'm 99% sure that lnd and lncli were both build from 83b779d commit. I looking at ls -l of the binaries and that matches when I did the build. I wish --versionand logs printed the git hash.

Not sure what's the better way to check if transaction got into the mempool. External wallet and https://www.blocktrail.com/tBTC/ did not see it, usually both of those see the transaction in under 5 seconds from issuing sendcoins. Yet, that's expected not to see it with sat/byte=1

[alevchuk]

I wish --version and logs printed the git hash.

[Roasbeef]

What node were you connected to? Check the logs of that node.

Not sure what's at foot here, are you able to reproduce a similar send's fee rate getting downgraded?

[alevchuk]

I only run one node and lncil connects to it locally. Let me try to repro the fee downgrade...

[alevchuk]

Funds showed up. Some channels also showed up, even though I did not re-enable Autopilot.
Can't send coins:

date && ls -l /home/ligtning/src/go/bin/l* &&  \
  lncli channelbalance && lncli walletbalance && \
  lncli sendcoins --addr tb1q<...> --amt 231000000  --sat_per_byte 40 && echo OK

Sat Mar 10 12:55:33 PST 2018
-rwxrwxr-x 1 ligtning ligtning 13994237 Mar  9 22:29 /home/ligtning/src/go/bin/lncli
-rwxrwxr-x 1 ligtning ligtning 29579443 Mar  9 22:29 /home/ligtning/src/go/bin/lnd
{
    "balance": "251637244"
}
{
    "total_balance": "231638017",
    "confirmed_balance": "231638017",
    "unconfirmed_balance": "0"
}
[lncli] rpc error: code = Unknown desc = -22: TX rejected: output da9aa63c434fc8c4acc57563a46ef24e2ec06f415300c3b4a73306099c7235c5:1 already spent by transaction b0a732349958b2a771562fd25f05492fa3e6bcaa4af082daadb1aaf89e0641ee in the memory pool

fee downgrade did not re-pro:

2018-03-10 12:55:33.355 [INF] RPCS: [sendcoins] addr=tb1q<...>, amt=2.31 BTC, sat/byte=40
2018-03-10 12:55:33.368 [INF] LNWL: Inserting unconfirmed transaction de38f552f11028dff0d5e4853f4ffc908beebebf8cde161e5b1090a0020c9107

[Roasbeef]

If you're getting a rejection there, then it's due to the fact that the wallet wrote the transaction to the database, but it actually didn't land in the mempool. If you restart, we'll prune away that zombie utxo, though we should also do it if we get a rejection upon sending.

[alevchuk]

After restart the funding transaction showed up in the an inactive channel:

2018-03-10 13:11:34.124 [INF] PEER: NodeKey(0231eee2441073c86d38f6085aedaf2bb7ad3d43af4c0e2669c1edd1a7d566ce31) loading ChannelPoint(da9aa63c434fc8c4acc57563a46ef24e2ec06f415300c3b4a73306099c7235c5:0)

Let me close all the channels again and re-try. Not sure why the channels are re-opening.

[Roasbeef]

If you have the autopilot setting active, it will automatically open channels for you. Other nodes may also be automatically opening channels to you.

[alevchuk]

I have Autoplot off. Oh, good point, let me not supply --externalip on start, so others don't open channels to me.

If I'm to make a pull request to include git hash in --version and logs, would you help outline how it should be implemented. Maybe something like:

1. During build read hash from where .git/HEAD is pointing (e.g. .git/refs/heads/master)
2. Write hash to file X
3. At run time read from X

[Roasbeef]

This PR to add a makefile can be extended to do so: #689

You'd do something like set a variable string in lnd.go, then pass the commit hash through with -ldflags.

[cfromknecht]

FWIW I added a variable for commit version in the build package PR #703 with the intent that #689 set it when compiling

[halseth]

For the record, some changes to fee rate calculation landed a few days after 83b779d, so would be interesting to see if this could be reproduced on latest master.

EDIT: looking at these changes in rpcserver's SendCoins, I still can't see how 40 sat/byte could become 1 sat/byte, it's just a few lines of code:

lnd/rpcserver.go

Line 409 in 83b779d

rpcsLog.Infof("[sendcoins] addr=%v, amt=%v, sat/byte=%v",