ElementsProject / lightning

Core Lightning — Lightning Network implementation focusing on spec compliance and performance
Other
2.86k stars 902 forks source link

Channel closing because local/remote feerates are too different #2354

Closed billygarrison closed 5 years ago

billygarrison commented 5 years ago

Issue and Steps to Reproduce

I had a channel close out automatically.

listpeers gives this status:

"status": [
            "CHANNELD_NORMAL:Received error from peer: channel 5466dea37ff282212d3df23022de2e6432aec1a0ddf54b6f697bfe2fa0ac0883: local/remote feerates are too different: remoteFeeratePerKw=7476 localFeeratePerKw=821",
            "ONCHAIN:Tracking our own unilateral close",
            "ONCHAIN:2 outputs unresolved: in 75 blocks will spend DELAYED_OUTPUT_TO_US (5ead07d77ab9054798f191c7a5d6f0ba5114f68431e0734ca899b47f6cd2c131:0) using OUR_DELAYED_RETURN_TO_WALLET"
          ],

I tend to open channels with lightning-cli fundchannel <peer_id> slow because I'm not in a hurry to get them opened and want to pay the smallest on-chain fee. So maybe this has something to do with it? (I'm not certain if I used default or slow when opening this channel, FWIW).

I have a copy of the lightningd database from yesterday (before the channel closed), and it shows that the local and remote feerate_per_kw are both 7475. What could cause the local to change and cause this channel-closing error?

The peer is using ACINQ according to 1ml.com.

I'm wondering what caused the channel to close and how I can avoid this problem in the future.

getinfo output

{
  "id": "02843833374b6c42daa4b780df2066a9985cb8cf97bc4566dd63cf693d32cbf7b5",
  "alias": "BillyGarrison",
  "color": "009900",
  "num_peers": 10,
  "num_pending_channels": 1,
  "num_active_channels": 8,
  "num_inactive_channels": 1,
  "address": [
    {
      "type": "ipv4",
      "address": "47.55.123.202",
      "port": 9735
    }
  ],
  "binding": [
  ],
  "version": "v0.6.3",
  "blockheight": 563043,
  "network": "bitcoin",
  "msatoshi_fees_collected": 3375
}
SimonVrouwe commented 5 years ago

Hello, the feerate slow given in lightning-cli fundchannel <peer_id> slow is the feerate for the funding transaction only. When the channel becomes operational after funding_locked, the fee-paying node (usually the node that initiated the channel) updates the feerate for the commitment tx in update_fee messages when it deems necessary.

Apparently the feerate your node proposed (from bitcoin-cli estimatesmartfee 2 CONSERVATIVE) was outside the remote node's acceptable range. This is a known problem, I had the same myself last week. This is especially hard for the node that is funding the channel and paying the fees, because it somehow has to guess what feerate-estimate the other node sees. Maybe you can check if there was a spike in bitcoind's feerate estimate at that particular moment in your case here.

billygarrison commented 5 years ago

@SimonVrouwe, thank you for the information.

The feerate estimate did spike, as the mempool was full for 2 days (just the other day). It looks like eclair nodes also use bitcoind for feerate estimate, could it be that we had different views of the mempool at that moment and their feerate increased sooner than mine did? Or perhaps they get a different feerate from bitcoind for another reason?

SimonVrouwe commented 5 years ago

Yeah, its interesting in your case your node sees the spike before the remote node and in my case it was the other way around (probably). But the first case (c-lightning sees the upward spike first) we smooth the spike using ~a 90 second~ exponential smoothing ~window~. Was it the spike around 19:00 on Jan 13? BTW, p2sh.info feerates are in sat/B, so you need multiply that with 1000/4

If you have set log-level=debug, there should be a line in your log saying something like:

... polled feerate estimate for urgent (?) smoothed to 7476 (alpha=0.44)

where ? is something around 17081 sat/kw, and another line

Feerate estimate for urgent set to 7476

EDIT: my math is probably incorrect, the exact smoothing formula can be found here

billygarrison commented 5 years ago

It looks closer to Feb 13 at 03:00.

I do have log-level=debug, but I don't know where the log file is located. All I know is how to use lightning-cli getlog. Also, what format is the time in, e.g. 17280.503747429?

SimonVrouwe commented 5 years ago

It looks closer to Feb 13 at 03:00.

Sorry, I looked at wrong chart in p2sh.info. But at that time (03:00), I actually don't see any spike. The logfile is in the $HOME/.lightning directory.

Also, what format is the time in, e.g. 17280.503747429?

Is seconds since node start.

billygarrison commented 5 years ago

Thanks for the help, closing this now. I've restarted my node since posting this so I guess I wont be able to look at past logs?

SimonVrouwe commented 5 years ago

By default log messages go to stdout, but with the option --log-file=<file> it is stored in file. Also handy IMHO is pipe to both using tee: lightningd | tee -a <file>

Thanks for reporting. Actually recent versions of eclair nodes do have feerate smoothing.

billygarrison commented 5 years ago

Thanks for that info! I think I looked everywhere for --log-file except lightningd --help.