Pay plugin stop to work after call "pay an_bolt11"

[vincenzopalazzo]

Hi all,

I'm testing the 0.9.0-rc2, in particular my configuration include one node with 0.9.0-rc2 on desktop and two node 0.8.2 on android. I'm testing the to open channels and pay bolt11 from different node but today I run the last rc version from the code and I receive the following error

{
   "code": -4,
   "message": "Plugin terminated before replying to RPC call."
}

With the following stakstrace

2020-07-19T13:00:24.463Z DEBUG 036c78a7959a62640a5f1e871d00ae0a47bb97907fc64da220dc0841d1fadd5d0c-gossipd: Received channel_update for channel 1781122x121x0/1 now ACTIVE
pay: plugins/libplugin-pay.c:1431: local_channel_hints_listpeers: Assertion `spendsats != NULL && scid != NULL && dir != NULL' failed.
pay: FATAL SIGNAL 6 (version v0.9.0rc2-15-g660a743)
0x5644f5402999 send_backtrace
	common/daemon.c:38
0x5644f5402a3f crashdump
	common/daemon.c:51
0x7f7f0cb85fcf ???
	???:0
0x7f7f0cb85f47 ???
	???:0
0x7f7f0cb878b0 ???
	???:0
0x7f7f0cb77429 ???
	???:0
0x7f7f0cb774a1 ???
	???:0
0x5644f53f1299 local_channel_hints_listpeers
	plugins/libplugin-pay.c:1431
0x5644f53e94a6 handle_rpc_reply
	plugins/libplugin.c:547
0x5644f53e9b16 rpc_read_response_one
	plugins/libplugin.c:662
0x5644f53e9c07 rpc_conn_read_response
	plugins/libplugin.c:681
0x5644f5419e25 next_plan
	ccan/ccan/io/io.c:59
0x5644f541a9a2 do_plan
	ccan/ccan/io/io.c:407
0x5644f541a9e0 io_ready
	ccan/ccan/io/io.c:417
0x5644f541cba6 io_loop
	ccan/ccan/io/poll.c:445
0x5644f53ebd9b plugin_main
	plugins/libplugin.c:1284
0x5644f53e8057 main
	plugins/pay.c:2010
0x7f7f0cb68b96 ???
	???:0
0x5644f53e1549 ???
	???:0
0xffffffffffffffff ???
	???:0
pay: FATAL SIGNAL 11 (version v0.9.0rc2-15-g660a743)
0x5644f5402999 send_backtrace
	common/daemon.c:38
0x5644f5402a3f crashdump
	common/daemon.c:51
0x7f7f0cb85fcf ???
	???:0
0x0 ???
	???:0
2020-07-19T13:00:33.215Z INFO plugin-pay: Killing plugin: Plugin exited before completing handshake.

Issue and Steps to Reproduce

I can describe my configuration with the testnet network.

Node A: rc2 version on linux
Node B: 0.8.2 on android
Node C: 0.8.2 on android

I open the channel with the following order

A->B->C

With C I generate the bol11 and I want to pay the bolt11 with the node A but after run command pay I received the error described in the previous section

When I try to pay the bolt11 from B to node C I receive the could not find a route error

The staus of the channel are

Node A with id: 0360dca2f35336d303643a7fb172ba6185b9086aa1fbd6063a1447050f2dda0f87

listchannels

{
   "channels": [
      {
         "source": "0360dca2f35336d303643a7fb172ba6185b9086aa1fbd6063a1447050f2dda0f87",
         "destination": "036c78a7959a62640a5f1e871d00ae0a47bb97907fc64da220dc0841d1fadd5d0c",
         "short_channel_id": "1781122x121x0",
         "public": false,
         "satoshis": 10000,
         "amount_msat": "10000000msat",
         "message_flags": 1,
         "channel_flags": 0,
         "active": true,
         "last_update": 1595163626,
         "base_fee_millisatoshi": 1,
         "fee_per_millionth": 10,
         "delay": 6,
         "htlc_minimum_msat": "0msat",
         "htlc_maximum_msat": "9454000msat",
         "features": ""
      },
      {
         "source": "036c78a7959a62640a5f1e871d00ae0a47bb97907fc64da220dc0841d1fadd5d0c",
         "destination": "0360dca2f35336d303643a7fb172ba6185b9086aa1fbd6063a1447050f2dda0f87",
         "short_channel_id": "1781122x121x0",
         "public": false,
         "satoshis": 10000,
         "amount_msat": "10000000msat",
         "message_flags": 1,
         "channel_flags": 1,
         "active": true,
         "last_update": 1595163624,
         "base_fee_millisatoshi": 1,
         "fee_per_millionth": 10,
         "delay": 6,
         "htlc_minimum_msat": "0msat",
         "htlc_maximum_msat": "9454000msat",
         "features": ""
      }
   ]
}

Node B with id 036c78a7959a62640a5f1e871d00ae0a47bb97907fc64da220dc0841d1fadd5d0c

listchannels

,$ lightning-cli listchannels
{
   "channels": [
      {
         "source": "0360dca2f35336d303643a7fb172ba6185b9086aa1fbd6063a1447050f2dda0f87",
         "destination": "036c78a7959a62640a5f1e871d00ae0a47bb97907fc64da220dc0841d1fadd5d0c",
         "short_channel_id": "1781122x121x0",
         "public": false,
         "satoshis": 10000,
         "amount_msat": "10000000msat",
         "message_flags": 1,
         "channel_flags": 0,
         "active": true,
         "last_update": 1595163626,
         "base_fee_millisatoshi": 1,
         "fee_per_millionth": 10,
         "delay": 6,
         "htlc_minimum_msat": "0msat",
         "htlc_maximum_msat": "9454000msat"
      },
      {
         "source": "036c78a7959a62640a5f1e871d00ae0a47bb97907fc64da220dc0841d1fadd5d0c",
         "destination": "0360dca2f35336d303643a7fb172ba6185b9086aa1fbd6063a1447050f2dda0f87",
         "short_channel_id": "1781122x121x0",
         "public": false,
         "satoshis": 10000,
         "amount_msat": "10000000msat",
         "message_flags": 1,
         "channel_flags": 1,
         "active": true,
         "last_update": 1595163624,
         "base_fee_millisatoshi": 1,
         "fee_per_millionth": 10,
         "delay": 6,
         "htlc_minimum_msat": "0msat",
         "htlc_maximum_msat": "9454000msat"
      },
      {
         "source": "02824defe8bf628f676f44a01e02a22c1c613571e1e55df738d6ad072310fb7bf8",
         "destination": "036c78a7959a62640a5f1e871d00ae0a47bb97907fc64da220dc0841d1fadd5d0c",
         "short_channel_id": "1781123x197x0",
         "public": false,
         "satoshis": 10000,
         "amount_msat": "10000000msat",
         "message_flags": 1,
         "channel_flags": 0,
         "active": false,
         "last_update": 1595163857,
         "base_fee_millisatoshi": 1,
         "fee_per_millionth": 10,
         "delay": 6,
         "htlc_minimum_msat": "0msat",
         "htlc_maximum_msat": "9454000msat"
      },
      {
         "source": "036c78a7959a62640a5f1e871d00ae0a47bb97907fc64da220dc0841d1fadd5d0c",
         "destination": "02824defe8bf628f676f44a01e02a22c1c613571e1e55df738d6ad072310fb7bf8",
         "short_channel_id": "1781123x197x0",
         "public": false,
         "satoshis": 10000,
         "amount_msat": "10000000msat",
         "message_flags": 1,
         "channel_flags": 1,
         "active": false,
         "last_update": 1595163855,
         "base_fee_millisatoshi": 1,
         "fee_per_millionth": 10,
         "delay": 6,
         "htlc_minimum_msat": "0msat",
         "htlc_maximum_msat": "9454000msat"
      }
   ]
}

Node C with id 02824defe8bf628f676f44a01e02a22c1c613571e1e55df738d6ad072310fb7bf8

listchannels

$ lightning-cli listchannels
{ 
   "channels": [ 
      { 
         "source": "02824defe8bf628f676f44a01e02a22c1c613571e1e55df738d6ad072310fb7bf8", 
         "destination": "036c78a7959a62640a5f1e871d00ae0a47bb97907fc64da220dc0841d1fadd5d0c", 
         "short_channel_id": "1781123x197x0", 
         "public": false, 
         "satoshis": 10000, 
         "amount_msat": "10000000msat", 
         "message_flags": 1, 
         "channel_flags": 0, 
         "active": true, 
         "last_update": 1595165728, 
         "base_fee_millisatoshi": 1, 
         "fee_per_millionth": 10, 
         "delay": 6, 
         "htlc_minimum_msat": "0msat", 
         "htlc_maximum_msat": "9454000msat" 
      }, 
      { 
         "source": "036c78a7959a62640a5f1e871d00ae0a47bb97907fc64da220dc0841d1fadd5d0c", 
         "destination": "02824defe8bf628f676f44a01e02a22c1c613571e1e55df738d6ad072310fb7bf8", 
         "short_channel_id": "1781123x197x0", 
         "public": false, 
         "satoshis": 10000, 
         "amount_msat": "10000000msat", 
         "message_flags": 1, 
         "channel_flags": 1, 
         "active": true, 
         "last_update": 1595165726, 
         "base_fee_millisatoshi": 1, 
         "fee_per_millionth": 10, 
         "delay": 6, 
         "htlc_minimum_msat": "0msat", 
         "htlc_maximum_msat": "9454000msat" 
      } 
   ] 
}

getinfo output

{   "id": "0360dca2f35336d303643a7fb172ba6185b9086aa1fbd6063a1447050f2dda0f87",
   "alias": "BRUCEWAYN-TES-DEV",
   "color": "03ad98",
   "num_peers": 2,
   "num_pending_channels": 0,
   "num_active_channels": 1,
   "num_inactive_channels": 3,
   "address": [
      {
         "type": "torv3",
         "address": "fp463inc4w3lamhhduytrwdwq6q6uzugtaeapylqfc43agrdnnqsheyd.onion",
         "port": 9735
      },
      {
         "type": "torv3",
         "address": "3xjyamprb43ubatvfr3ruvpj2bdolkko6jrcbevwjb2o37o7reacjvad.onion",
         "port": 9735
      }
   ],
   "binding": [
      {
         "type": "ipv4",
         "address": "127.0.0.1",
         "port": 9735
      }
   ],
   "version": "v0.9.0rc2-15-g660a743",
   "blockheight": 1781124,
   "network": "testnet",
   "msatoshi_fees_collected": 0,
   "fees_collected_msat": "0msat",
   "lightning-dir": "/media/vincent/Maxtor/sanboxTestWrapperRPC/lightning_dir_dev/testnet"
}

The behavior that I aspect from the rc2 should be the same from the 0.8.2 version? in other words, the paid plugin should return the error could not find a route. I'm losing somethings and this behavior is correct and my mind contains a bug?

[ZmnSCPxj]

plugins/libplugin-pay.c:1431 is: https://github.com/ElementsProject/lightning/blob/master/plugins/libplugin-pay.c#L1431

The assertion is checking the results of these calls: https://github.com/ElementsProject/lightning/blob/master/plugins/libplugin-pay.c#L1428-L1431

Those calls are doing lookups for spendable_msat, short_channel_id, and direction. The assertion triggers because those fields are missing in some channels.

But "missing for some channels" is perfectly normal! A channel that is not yet had its funding confirmed is not going to have a stable short_channel_id, so that field would be missing.

I think the fix here should just be a simple replacement of that assert with:

if (spendsats == NULL || scid == NULL || dir == NULL)
        continue;

[vincenzopalazzo]

Hi @ZmnSCPxj, yep, I agree, in most cases, I make the wrong sequence to pay the bolt11 and I don't want if I have made some logic error inside the command the plugin pay stop to work. (Is only my opinion)

[ZmnSCPxj]

Looks like a successful replication here: https://travis-ci.org/github/ZmnSCPxj/lightning/jobs/709724045#L4164-L4214

Also: https://travis-ci.org/github/ZmnSCPxj/lightning/jobs/709724045#L1828