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

sendpay from plugin crashes lightningd (FATAL SIGNAL 6) #3431

Closed
s-tikhomirov opened this issue Jan 22, 2020 · 9 comments · Fixed by #3470
Closed

sendpay from plugin crashes lightningd (FATAL SIGNAL 6) #3431

s-tikhomirov opened this issue Jan 22, 2020 · 9 comments · Fixed by #3470
Labels
state::fixed These issues should have been addressed. Pending confirmation by OP, will close soon otherwise

Comments

@s-tikhomirov
Copy link

s-tikhomirov commented Jan 22, 2020

Issue and Steps to Reproduce

I'm experimenting with sendpay on regtest. Calling a plugin which uses sendpay consistently crashes the node.

The following is the minimal example. I'm sending a payment of 1000 sats from node 0306 to node 03da. There is a channel between them with enough capacity, as indicated by lightning-cli listchannels output (the relevant part):

      {
         "source": "03068d9ac7f6973cbdb7212f2598afee2db14becd3d31e937659b0c09cee9f78f2",
         "destination": "03daff103e6808993cdbead929769821becc54b78b751902f07a10f8d7f081bcc4",
         "short_channel_id": "1294x2x0",
         "public": true,
         "satoshis": 10000000,
         "amount_msat": "10000000000msat",
         "message_flags": 1,
         "channel_flags": 0,
         "active": true,
         "last_update": 1579616360,
         "base_fee_millisatoshi": 1,
         "fee_per_millionth": 10,
         "delay": 6,
         "htlc_minimum_msat": "0msat",
         "htlc_maximum_msat": "4294967295msat"
      },

The plugin code:

#!/usr/bin/env python3

from lightning import Plugin
import random, string

plugin = Plugin()

@plugin.method("sendpay_test")
def sendpay_test(plugin, receiver, amount=1000):
    route = plugin.rpc.getroute(receiver, amount, riskfactor=1)['route']
    payment_hash = ''.join(random.choice(string.hexdigits) for _ in range(64))
    plugin.rpc.sendpay(
        route=route,
        payment_hash=payment_hash,
        msatoshi=amount*1000
        )
    return

@plugin.init()
def init(options, configuration, plugin):
    plugin.log("Plugin sendpay_test.py initialized")

plugin.add_option('greeting', 'Hello', 'The greeting I should use.')
plugin.run()

Calling the plugin and the crash:

$ lightning-cli sendpay_test 03daff103e6808993cdbead929769821becc54b78b751902f07a10f8d7f081bcc4
lightning-cli: reading response: socket closed

The log file:

38752 bytes, Wed Jan 22 14:55:37 2020
+0.001826483 plugin-managerDEBUG: started(9322) /usr/local/bin/../libexec/c-lightning/plugins/fundchannel
+0.002792650 plugin-managerDEBUG: started(9323) /usr/local/bin/../libexec/c-lightning/plugins/pay
+0.003802837 plugin-managerDEBUG: started(9324) /usr/local/bin/../libexec/c-lightning/plugins/autoclean
+0.005034440 plugin-managerDEBUG: started(9325) /home/sergei/Documents/code/lightning/lightning-probing/sendpay-crash.py
+0.005074356 plugin-sendpay-crash.pyIO_OUT: 7b226a736f6e727063223a22322e30222c226964223a332c226d6574686f64223a226765746d616e6966657374222c22706172616d73223a7b7d7d0a0a
+0.005076479 plugin-autocleanIO_OUT: 7b226a736f6e727063223a22322e30222c226964223a322c226d6574686f64223a226765746d616e6966657374222c22706172616d73223a7b7d7d0a0a
+0.005079130 plugin-payIO_OUT: 7b226a736f6e727063223a22322e30222c226964223a312c226d6574686f64223a226765746d616e6966657374222c22706172616d73223a7b7d7d0a0a
+0.005082174 plugin-fundchannelIO_OUT: 7b226a736f6e727063223a22322e30222c226964223a302c226d6574686f64223a226765746d616e6966657374222c22706172616d73223a7b7d7d0a0a
+0.007552636 plugin-fundchannelIO_IN: 7b226a736f6e727063223a22322e30222c226964223a302c22726573756c74223a7b226f7074696f6e73223a5b5d2c227270636d6574686f6473223a5b7b226e
+0.007574353 plugin-fundchannelIO_IN: 616d65223a2266756e646368616e6e656c222c227573616765223a22696420616d6f756e74205b666565726174655d205b616e6e6f756e63655d205b6d696e63
+0.007584532 plugin-fundchannelIO_IN: 6f6e665d205b7574786f735d205b707573685f6d7361745d222c226465736372697074696f6e223a2246756e64206368616e6e656c2077697468207b69647d207573696e67207b7361746f7368697d20286f722027616c6c27292c206174206f7074696f6e616c207b666565726174657d2e204f6e6c7920757365206f757470
+0.007591803 plugin-fundchannelIO_IN: 75747320746861742068617665207b6d696e636f6e667d20636f6e6669726d6174696f6e732e222c226c6f6e675f6465736372697074696f6e223a22496e69746961746965732061206368616e6e656c206f70656e2077697468206e6f646520276964272e204d75737420626520636f6e6e656374656420746f20746865206e6f646520616e64206861766520656e6f7567682066756e647320617661696c61626c652061742074686520726571756573746564206d696e696d756d20636f6e6669726d6174696f6e20646570746820286d696e636f6e6629227d5d2c22737562736372697074696f6e73223a5b5d2c22686f6f6b73223a5b5d2c2264796e61
+0.007600612 plugin-fundchannelIO_IN: 6d6963223a2274727565227d7d0a0a
+0.008237805 plugin-payIO_IN: 7b226a736f6e727063223a22322e30222c226964223a312c22726573756c74223a7b226f7074696f6e73223a5b5d2c227270636d6574686f6473223a5b7b226e
+0.008251807 plugin-payIO_IN: 616d65223a22706179222c227573616765223a22626f6c743131205b6d7361746f7368695d205b6c6162656c5d205b7269736b666163746f725d205b6d617866
+0.008257242 plugin-payIO_IN: 656570657263656e745d205b72657472795f666f725d205b6d617864656c61795d205b6578656d70746665655d222c226465736372697074696f6e223a2253656e64207061796d656e7420737065636966696564206279207b626f6c7431317d2077697468207b616d6f756e747d222c226c6f6e675f6465736372697074696f
+0.008262496 plugin-payIO_IN: 6e223a2254727920746f2073656e642061207061796d656e742c207265747279696e67207b72657472795f666f727d207365636f6e6473206265666f726520676976696e67207570227d2c7b226e616d65223a22706179737461747573222c227573616765223a225b626f6c7431315d222c226465736372697074696f6e223a2244657461696c20737461747573206f6620617474656d70747320746f20706179207b626f6c7431317d2c206f7220616c6c222c226c6f6e675f6465736372697074696f6e223a22436f7665727320626f7468206f6c64207061796d656e747320616e642063757272656e74206f6e65732e227d2c7b226e616d65223a226c69
+0.008268950 plugin-payIO_IN: 737470617973222c227573616765223a225b626f6c7431315d222c226465736372697074696f6e223a224c69737420726573756c74206f66207061796d656e74207b626f6c7431317d2c206f7220616c6c222c226c6f6e675f6465736372697074696f6e223a22436f76657273206f6c64207061796d656e747320286661696c656420616e64207375636365656465642920616e642063757272656e74206f6e65732e227d5d2c22737562736372697074696f6e73223a5b5d2c22686f6f6b73223a5b5d2c2264796e616d6963223a2274727565227d7d0a0a
+0.009147747 plugin-autocleanIO_IN: 7b226a736f6e727063223a22322e30222c226964223a322c22726573756c74223a7b226f7074696f6e73223a5b7b226e616d65223a226175746f636c65616e69
+0.009159445 plugin-autocleanIO_IN: 6e766f6963652d6379636c65222c2274797065223a22737472696e67222c226465736372697074696f6e223a22506572666f726d20636c65616e7570206f6620
+0.009163889 plugin-autocleanIO_IN: 6578706972656420696e766f6963657320657665727920676976656e207365636f6e64732c206f7220646f206e6f74206175746f636c65616e2069662030227d2c7b226e616d65223a226175746f636c65616e696e766f6963652d657870697265642d6279222c2274797065223a22737472696e67222c226465736372697074
+0.009168908 plugin-autocleanIO_IN: 696f6e223a224966206578706972656420696e766f696365206175746f636c65616e20656e61626c65642c20696e766f6963657320746861742068617665206578706972656420666f72206174206c65617374207468697320676976656e207365636f6e64732061726520636c65616e6564227d5d2c227270636d6574686f6473223a5b7b226e616d65223a226175746f636c65616e696e766f696365222c227573616765223a225b6379636c655f7365636f6e64735d205b657870697265645f62795d222c226465736372697074696f6e223a22536574207570206175746f636c65616e206f66206578706972656420696e766f696365732e20222c226c6f
+0.009181804 plugin-autocleanIO_IN: 6e675f6465736372697074696f6e223a22506572666f726d20636c65616e7570206576657279207b6379636c655f7365636f6e64737d202864656661756c742033363030292c206f722064697361626c65206175746f636c65616e20696620302e20436c65616e207570206578706972656420696e766f6963657320746861742068617665206578706972656420666f72207b657870697265645f62797d207365636f6e6473202864656661756c74203836343030292e20227d5d2c22737562736372697074696f6e73223a5b5d2c22686f6f6b73223a5b5d2c2264796e616d6963223a2274727565227d7d0a0a
+0.061311716 plugin-sendpay-crash.pyIO_IN: 7b226a736f6e727063223a2022322e30222c20226d6574686f64223a20226c6f67222c2022706172616d73223a207b226c6576656c223a2022696e666f222c20
+0.061323616 plugin-sendpay-crash.pyIO_IN: 226d657373616765223a2022525043206d6574686f64202773656e647061795f746573742720646f6573206e6f742068617665206120646f63737472696e672e
+0.061329354 plugin-sendpay-crash.pyIO_IN: 227d7d0a0a
+0.061333997 plugin-sendpay-crash.pyINFO: RPC method 'sendpay_test' does not have a docstring.
+0.061510828 plugin-sendpay-crash.pyIO_IN: 7b226a736f6e727063223a2022322e30222c20226964223a20332c2022726573756c74223a207b226f7074696f6e73223a205b7b226e616d65223a20226772656574696e67222c202264656661756c74223a202248656c6c6f222c20226465736372697074696f6e223a2022546865206772656574696e6720492073686f756c64207573652e222c202274797065223a2022737472696e67222c202276616c7565223a206e756c6c7d5d2c20227270636d6574686f6473223a205b7b226e616d65223a202273656e647061795f74657374222c202263617465676f7279223a2022706c7567696e222c20227573616765223a20227265636569766572205b
+0.061536422 plugin-sendpay-crash.pyIO_IN: 616d6f756e745d222c20226465736372697074696f6e223a2022556e646f63756d656e74656420525043206d6574686f642066726f6d206120706c7567696e2e227d5d2c2022737562736372697074696f6e73223a205b5d2c2022686f6f6b73223a205b5d7d7d0a0a
+0.062582487 lightningdDEBUG: testing /usr/local/libexec/c-lightning/lightning_channeld
+0.064020299 lightningdDEBUG: testing /usr/local/libexec/c-lightning/lightning_closingd
+0.065421884 lightningdDEBUG: testing /usr/local/libexec/c-lightning/lightning_connectd
+0.066778888 lightningdDEBUG: testing /usr/local/libexec/c-lightning/lightning_gossipd
+0.068225466 lightningdDEBUG: testing /usr/local/libexec/c-lightning/lightning_hsmd
+0.069610310 lightningdDEBUG: testing /usr/local/libexec/c-lightning/lightning_onchaind
+0.071046426 lightningdDEBUG: testing /usr/local/libexec/c-lightning/lightning_openingd
+0.089762280 hsmdDEBUG: pid 9333, msgfd 23
+0.095994037 connectdDEBUG: pid 9334, msgfd 26
+0.096085451 hsmdDEBUG: Client: Received message 11 from client
+0.096099887 hsmdDEBUG: Client: Received message 9 from client
+0.096109290 hsmdDEBUG: new_client: 0
+0.102865446 connectdDEBUG: Created IPv4 listener on port 9737
+0.102879603 connectdDEBUG: REPLY WIRE_CONNECTCTL_INIT_REPLY with 0 fds
+0.103203103 gossipdDEBUG: pid 9335, msgfd 25
+0.117165047 hsmdDEBUG: Client: Received message 9 from client
+0.117196481 hsmdDEBUG: new_client: 0
+0.127552974 gossipdDEBUG: gossip_store_compact_offline: 0 deleted, 21 copied
+0.127593764 lightningdUNUSUAL: Unable to estimate CONSERVATIVE/2 fee
+0.129848728 gossipdDEBUG: total store load time: 0 msec
+0.129864148 gossipdDEBUG: gossip_store: Read 5/8/3/0 cannounce/cupdate/nannounce/cdelete from store (0 deleted) in 4002 bytes
+0.129875856 gossipdDEBUG: seeker: state = STARTING_UP New seeker
+0.131132750 lightningdUNUSUAL: Unable to estimate ECONOMICAL/4 fee
+0.132271369 lightningdDEBUG: Adding block 1293: 35d7a8b297e3537bc45cd5fc6472a7f3c9c057e671a9c755975923ff00710419
+0.141355116 lightningdUNUSUAL: Unable to estimate ECONOMICAL/100 fee
+0.141414569 lightningdDEBUG: Smoothed feerate estimate for urgent initialized to polled estimate 253
+0.141415696 lightningdDEBUG: Feerate estimate for urgent set to 253 (was 0)
+0.141416507 lightningdDEBUG: Smoothed feerate estimate for normal initialized to polled estimate 253
+0.141417110 lightningdDEBUG: Feerate estimate for normal set to 253 (was 0)
+0.141417694 lightningdDEBUG: Smoothed feerate estimate for slow initialized to polled estimate 253
+0.141418240 lightningdDEBUG: Feerate estimate for slow set to 253 (was 0)
+0.142276993 walletDEBUG: Loaded 0 HTLC signatures from DB
+0.143015235 walletDEBUG: Loaded 0 HTLC signatures from DB
+0.143795504 walletDEBUG: Loaded 0 HTLC signatures from DB
+0.144600071 walletDEBUG: Loaded 0 HTLC signatures from DB
+0.144726053 walletDEBUG: Loaded 4 channels from DB
+0.144737174 walletDEBUG: Loading in HTLCs for channel 6
+0.144802526 walletDEBUG: Restored 0 incoming HTLCS
+0.144803712 walletDEBUG: Loading in HTLCs for channel 8
+0.144842544 walletDEBUG: Restored 0 incoming HTLCS
+0.144843321 walletDEBUG: Loading in HTLCs for channel 9
+0.144877779 walletDEBUG: Restored 0 incoming HTLCS
+0.144878522 walletDEBUG: Loading in HTLCs for channel 10
+0.144910967 walletDEBUG: Restored 0 incoming HTLCS
+0.144992433 walletDEBUG: Restored 0 outgoing HTLCS
+0.145035979 walletDEBUG: Restored 0 outgoing HTLCS
+0.145083862 walletDEBUG: Restored 0 outgoing HTLCS
+0.145123939 walletDEBUG: Restored 0 outgoing HTLCS
+0.145224983 plugin-sendpay-crash.pyIO_OUT: 7b226a736f6e727063223a22322e30222c226964223a372c226d6574686f64223a22696e6974222c22706172616d73223a7b226f7074696f6e73223a7b226772656574696e67223a2248656c6c6f227d2c22636f6e66696775726174696f6e223a7b226c696768746e696e672d646972223a222f686f6d652f7365726765692f2e6c696768746e696e672f72656774657374222c227270632d66696c65223a226c696768746e696e672d727063222c2273746172747570223a747275652c226e6574776f726b223a2272656774657374227d7d7d0a0a
+0.145225920 plugin-autocleanIO_OUT: 7b226a736f6e727063223a22322e30222c226964223a362c226d6574686f64223a22696e6974222c22706172616d73223a7b226f7074696f6e73223a7b7d2c22636f6e66696775726174696f6e223a7b226c696768746e696e672d646972223a222f686f6d652f7365726765692f2e6c696768746e696e672f72656774657374222c227270632d66696c65223a226c696768746e696e672d727063222c2273746172747570223a747275652c226e6574776f726b223a2272656774657374227d7d7d0a0a
+0.145226623 plugin-payIO_OUT: 7b226a736f6e727063223a22322e30222c226964223a352c226d6574686f64223a22696e6974222c22706172616d73223a7b226f7074696f6e73223a7b7d2c22636f6e66696775726174696f6e223a7b226c696768746e696e672d646972223a222f686f6d652f7365726765692f2e6c696768746e696e672f72656774657374222c227270632d66696c65223a226c696768746e696e672d727063222c2273746172747570223a747275652c226e6574776f726b223a2272656774657374227d7d7d0a0a
+0.145227248 plugin-fundchannelIO_OUT: 7b226a736f6e727063223a22322e30222c226964223a342c226d6574686f64223a22696e6974222c22706172616d73223a7b226f7074696f6e73223a7b7d2c22636f6e66696775726174696f6e223a7b226c696768746e696e672d646972223a222f686f6d652f7365726765692f2e6c696768746e696e672f72656774657374222c227270632d66696c65223a226c696768746e696e672d727063222c2273746172747570223a747275652c226e6574776f726b223a2272656774657374227d7d7d0a0a
+0.145269928 hsmdDEBUG: Client: Received message 10 from client
+0.145291367 hsmdDEBUG: Client: Received message 10 from client
+0.145320373 hsmdDEBUG: Client: Received message 10 from client
+0.145336808 jsonrpc#27IO_IN: 7b226a736f6e727063223a22322e30222c226964223a302c226d6574686f64223a226c697374636f6e66696773222c22706172616d73223a7b22636f6e666967
+0.145355641 jsonrpc#27IO_IN: 223a22616c6c6f772d646570726563617465642d61706973227d7d0a0a
+0.145367927 jsonrpc#28IO_IN: 7b226a736f6e727063223a22322e30222c226964223a302c226d6574686f64223a226c697374636f6e66696773222c22706172616d73223a7b22636f6e666967
+0.145377264 hsmdDEBUG: Client: Received message 10 from client
+0.145382449 connectdDEBUG: REPLY WIRE_CONNECTCTL_ACTIVATE_REPLY with 0 fds
+0.145493599 lightningdINFO: --------------------------------------------------
+0.145509475 lightningdINFO: Server started with public key 03068d9ac7f6973cbdb7212f2598afee2db14becd3d31e937659b0c09cee9f78f2, alias clightningM (color #03068d) and lightningd v0.8.0-40-g899f5de
+0.146844639 jsonrpc#27IO_OUT: 7b226a736f6e727063223a22322e30222c226964223a302c22726573756c74223a7b22616c6c6f772d646570726563617465642d61706973223a747275657d207d0a0a
+0.146863230 plugin-sendpay-crash.pyIO_IN: 7b226a736f6e727063223a2022322e30222c20226d6574686f64223a20226c6f67222c2022706172616d73223a207b226c6576656c223a2022696e666f222c20226d657373616765223a2022506c7567696e2073656e647061795f746573742e707920696e697469616c697a6564227d7d0a0a7b226a736f6e727063223a2022322e30222c20226964223a20372c2022726573756c74223a206e756c6c7d0a0a
+0.146871917 plugin-sendpay-crash.pyINFO: Plugin sendpay_test.py initialized
+0.146902379 jsonrpc#28IO_IN: 223a22616c6c6f772d646570726563617465642d61706973227d7d0a0a
+0.146915345 jsonrpc#29IO_IN: 7b226a736f6e727063223a22322e30222c226964223a302c226d6574686f64223a226c697374636f6e66696773222c22706172616d73223a7b22636f6e666967
+0.146930700 jsonrpc#27IO_IN: 7b226a736f6e727063223a22322e30222c226964223a302c226d6574686f64223a22676574696e666f222c22706172616d73223a7b7d7d0a0a
+0.146945335 jsonrpc#29IO_IN: 223a22616c6c6f772d646570726563617465642d61706973227d7d0a0a
+0.147201333 chan#6DEBUG: Will try reconnect in 1 seconds
+0.147324976 connectdDEBUG: Failed connected out: 127.0.0.1:9735: Connection establishment: Connection refused. 
+0.147641533 chan#8DEBUG: Will try reconnect in 1 seconds
+0.147842303 connectdDEBUG: Failed connected out: 127.0.0.1:9736: Connection establishment: Connection refused. 
+0.147860966 connectdDEBUG: Connected out, starting crypto
+0.147880252 connectdDEBUG: Connected out, starting crypto
+0.147938120 jsonrpc#28IO_OUT: 7b226a736f6e727063223a22322e30222c226964223a302c22726573756c74223a7b22616c6c6f772d646570726563617465642d61706973223a747275657d207d0a0a
+0.148080736 jsonrpc#27IO_OUT: 7b226a736f6e727063223a22322e30222c226964223a302c22726573756c74223a7b226964223a22303330363864396163376636393733636264623732313266323539386166656532646231346265636433643331653933373635396230633039636565396637386632222c22616c696173223a22636c696768746e696e674d222c22636f6c6f72223a22303330363864222c226e756d5f7065657273223a342c226e756d5f70656e64696e675f6368616e6e656c73223a302c226e756d5f6163746976655f6368616e6e656c73223a342c226e756d5f696e6163746976655f6368616e6e656c73223a302c2261646472657373223a5b5d2c2262696e64696e67223a5b7b2274797065223a2269707634222c2261646472657373223a223132372e302e302e31222c22706f7274223a393733377d5d2c2276657273696f6e223a2276302e382e302d34302d6738393966356465222c22626c6f636b686569676874223a313239332c226e6574776f726b223a2272656774657374222c226d7361746f7368695f666565735f636f6c6c6563746564223a302c22666565735f636f6c6c65637465645f6d736174223a22306d736174222c226c696768746e696e672d646972223a222f686f6d652f7365726765692f2e6c696768746e696e672f72656774657374222c227761726e696e675f6c696768746e696e67645f73796e63223a225374696c6c206c6f6164696e67206c617465737420626c6f636b732066726f6d20626974636f696e642e227d207d0a0a
+0.148092061 jsonrpc#29IO_OUT: 7b226a736f6e727063223a22322e30222c226964223a302c22726573756c74223a7b22616c6c6f772d646570726563617465642d61706973223a747275657d207d0a0a
+0.148112485 jsonrpc#28IO_IN: 7b226a736f6e727063223a22322e30222c226964223a302c226d6574686f64223a226c697374636f6e66696773222c22706172616d73223a7b22636f6e666967223a226e6574776f726b227d7d0a0a
+0.148151522 plugin-autocleanIO_IN: 7b226a736f6e727063223a22322e30222c226d6574686f64223a226c6f67222c22706172616d73223a7b226c6576656c223a226465627567222c226d657373616765223a226175746f636c65616e696e67206e6f7420616374697665227d7d0a0a
+0.148156376 plugin-autocleanDEBUG: autocleaning not active
+0.148165373 plugin-autocleanIO_IN: 7b226a736f6e727063223a22322e30222c226964223a362c22726573756c74223a7b7d7d0a0a
+0.148174498 jsonrpc#27IO_IN: 7b226a736f6e727063223a22322e30222c226964223a302c226d6574686f64223a226c697374636f6e66696773222c22706172616d73223a7b22636f6e666967223a226d61782d6c6f636b74696d652d626c6f636b73227d7d0a0a
+0.149839364 jsonrpc#28IO_OUT: 7b226a736f6e727063223a22322e30222c226964223a302c22726573756c74223a7b226e6574776f726b223a2272656774657374227d207d0a0a
+0.149865375 jsonrpc#27IO_OUT: 7b226a736f6e727063223a22322e30222c226964223a302c22726573756c74223a7b226d61782d6c6f636b74696d652d626c6f636b73223a323031367d207d0a0a
+0.149908410 hsmdDEBUG: Client: Received message 1 from client
+0.149917777 connectdDEBUG: Connect OUT
+0.149934508 plugin-fundchannelIO_IN: 7b226a736f6e727063223a22322e30222c226964223a342c22726573756c74223a7b7d7d0a0a
+0.149959772 hsmdDEBUG: Client: Received message 1 from client
+0.149968991 connectdDEBUG: peer_out WIRE_INIT
+0.149989985 connectdDEBUG: Connect OUT
+0.150013572 connectdDEBUG: peer_out WIRE_INIT
+0.150032461 plugin-payIO_IN: 7b226a736f6e727063223a22322e30222c226964223a352c22726573756c74223a7b7d7d0a0a
+0.150043988 connectdDEBUG: peer_in WIRE_INIT
+0.150088763 chan#9DEBUG: Peer has reconnected, state CHANNELD_NORMAL
+0.150620107 channeld-chan#9DEBUG: pid 9348, msgfd 32
+0.150652321 chan#9DEBUG: Already have funding locked in
+0.150654448 chan#9DEBUG: Ignoring fee limits!
+0.150868072 hsmdDEBUG: Client: Received message 9 from client
+0.150890832 connectdDEBUG: peer_in WIRE_INIT
+0.150927853 hsmdDEBUG: new_client: 9
+0.150977055 chan#10DEBUG: Peer has reconnected, state CHANNELD_NORMAL
+0.151405933 channeld-chan#10DEBUG: pid 9349, msgfd 33
+0.151443351 chan#10DEBUG: Already have funding locked in
+0.151444524 chan#10DEBUG: Ignoring fee limits!
+0.151647664 hsmdDEBUG: Client: Received message 9 from client
+0.151686123 hsmdDEBUG: new_client: 10
+0.152120011 lightningdDEBUG: Adding block 1294: 3814a17376a7d36d15bd78e713f0655229aba822d7eee80e746d9aae4e29bf19
+0.157462557 walletDEBUG: Owning output 0 10000000000sat (SEGWIT) txid 9a2a134281dc578e782873350dbe5c4c27dd0f04d0ee0afa8c9647d1e4f7be01 CONFIRMED
+0.166755865 walletDEBUG: Owning output 1 9969998917sat (SEGWIT) txid dcf16ef36acd5145633fc473b8c5b35ceda2ddf323beca12b72d9b582c91ebce CONFIRMED
+0.190134412 hsmdDEBUG: Client: Received message 18 from client
+0.190163792 channeld-chan#10DEBUG: init LOCAL: remote_per_commit = 022f6c9996ecf473059d237185c2dec99d19fddf6de5ddcd4b7def127866daec69, old_remote_per_commit = 0216114e36500ab427fa21e84ee02466e13372bb58796eb48fcb3ed3dafc755f7d next_idx_local = 5 next_idx_remote = 5 revocations_received = 4 feerates { SENT_ADD_ACK_REVOCATION:253 } range 253-4294967295
+0.190190044 channeld-chan#9DEBUG: init LOCAL: remote_per_commit = 02c92782660434ffc827745c7cb2c2ef56c9a08624d76216bd3ae16858c49dd61b, old_remote_per_commit = 02823de3405510ee65039ec455b3b9f81721f31970febeb677cc7b8c1c105bd0b0 next_idx_local = 9 next_idx_remote = 9 revocations_received = 8 feerates { SENT_ADD_ACK_REVOCATION:253 } range 253-4294967295
+0.193679704 hsmdDEBUG: Client: Received message 18 from client
+0.193715042 channeld-chan#10DEBUG: option_static_remotekey = 1
+0.193742586 channeld-chan#9DEBUG: option_static_remotekey = 1
+0.193827051 hsmdDEBUG: Client: Received message 18 from client
+0.193860056 channeld-chan#10DEBUG: peer_out WIRE_CHANNEL_REESTABLISH
+0.193886329 channeld-chan#9DEBUG: peer_out WIRE_CHANNEL_REESTABLISH
+0.193969718 hsmdDEBUG: Client: Received message 18 from client
+0.194152940 hsmdDEBUG: Client: Received message 18 from client
+0.194179493 channeld-chan#10DEBUG: peer_in WIRE_CHANNEL_REESTABLISH
+0.194211144 channeld-chan#9DEBUG: peer_in WIRE_CHANNEL_REESTABLISH
+0.194291106 hsmdDEBUG: Client: Received message 18 from client
+0.194319307 channeld-chan#10DEBUG: Got reestablish commit=5 revoke=4
+0.194345042 channeld-chan#9DEBUG: Got reestablish commit=9 revoke=8
+0.194431930 channeld-chan#10DEBUG: next_revocation_number = 4
+0.194457708 channeld-chan#9DEBUG: next_revocation_number = 8
+0.194533963 channeld-chan#10DEBUG: option_static_remotekey: fields are correct
+0.194557252 channeld-chan#9DEBUG: option_static_remotekey: fields are correct
+0.197272452 channeld-chan#9BROKEN: select failed: Bad file descriptor (version v0.8.0-40-g899f5de)
+0.197457068 channeld-chan#10BROKEN: select failed: Bad file descriptor (version v0.8.0-40-g899f5de)
+0.197504556 channeld-chan#9BROKEN: backtrace: common/daemon.c:46 (send_backtrace) 0x560a690d4499
+0.197583086 channeld-chan#10BROKEN: backtrace: common/daemon.c:46 (send_backtrace) 0x55f88e84c499
+0.197619840 channeld-chan#9BROKEN: backtrace: common/status.c:206 (status_failed) 0x560a690dc81f
+0.197691778 channeld-chan#10BROKEN: backtrace: common/status.c:206 (status_failed) 0x55f88e85481f
+0.197727009 channeld-chan#9BROKEN: backtrace: channeld/channeld.c:3227 (main) 0x560a690c984a
+0.197798058 channeld-chan#10BROKEN: backtrace: channeld/channeld.c:3227 (main) 0x55f88e84184a
+0.197833502 channeld-chan#9BROKEN: backtrace: (null):0 ((null)) 0x7fe3a41f9b96
+0.197905375 channeld-chan#10BROKEN: backtrace: (null):0 ((null)) 0x7f0ddc085b96
+0.197945441 channeld-chan#9BROKEN: backtrace: (null):0 ((null)) 0x560a690c3619
+0.198050989 channeld-chan#10BROKEN: backtrace: (null):0 ((null)) 0x55f88e83b619
+0.198110466 channeld-chan#9BROKEN: backtrace: (null):0 ((null)) 0xffffffffffffffff
+0.198239276 channeld-chan#10BROKEN: backtrace: (null):0 ((null)) 0xffffffffffffffff
+0.198299901 channeld-chan#9BROKEN: STATUS_FAIL_INTERNAL_ERROR: select failed: Bad file descriptor
+0.198413599 chan#9INFO: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (61952)
+0.198460921 chan#9DEBUG: Will try reconnect in 1 seconds
+0.198592207 channeld-chan#10BROKEN: STATUS_FAIL_INTERNAL_ERROR: select failed: Bad file descriptor
+0.198685419 chan#10INFO: Peer transient failure in CHANNELD_NORMAL: channeld: Owning subdaemon channeld died (61952)
+0.198714188 chan#10DEBUG: Will try reconnect in 1 seconds
+0.199020576 lightningdDEBUG: Adding block 1295: 1749faac7f39999a030afcb09aeb2533452d8edfc3da58128784f60dc0877e9f
+0.219759458 lightningdDEBUG: Adding block 1296: 3e71c86426c4fe2021ec61ff5ad5c8fe97e74f11f5692926c443b5424aedc4e6
+0.238716461 lightningdDEBUG: Adding block 1297: 7bfc776bf53229f4696f1db58854bf365b3fe9f7824e989a02c25e7e12197984
+0.256295874 lightningdDEBUG: Adding block 1298: 5bcf0f284d64a4184b56e919ea93305d492a61ab0e14045af440c0c45ee7a8f4
+0.273231032 lightningdDEBUG: Adding block 1299: 43b3f6074df3c4d98fb740877012feca9210ee51a96c005d99a6e461f718f6ba
+0.290875792 lightningdDEBUG: Adding block 1300: 05e8dba5545fc14a69a41c7a357772f648dad58238078062cfc22f12d5efcfc6
+0.310000486 lightningdDEBUG: Adding block 1301: 7886fee4b81fcd3b4fafea1a01af6e71731d4275b92ac29bc5594117e2c921f5
+0.330452774 lightningdDEBUG: Adding block 1302: 5ac10b55ec580a9325dbae0b6dad176fffd42f6aea3c9432559bb4622aa154b1
+0.351192916 lightningdDEBUG: Adding block 1303: 2a208449d09c978b68f16a563408772931b604710e4eaf5897c514b1550214e0
+0.370507438 lightningdDEBUG: Adding block 1304: 1facd5b3cc2e7904bca3a6f6a2cb302de83a1c296d1c0f4a8f944177d5a02229
+0.382638452 walletDEBUG: Owning output 1 9959998763sat (SEGWIT) txid 5303098c4ff27bf9d2d36678a351ef4449bf2d6c6597754e9d0a7924867e586c CONFIRMED
+0.402959155 lightningdDEBUG: Adding block 1305: 61a59737d7055ed2a5d64ab3473c19a91fc8d6ab98dc1f076399d357e020c464
+0.423121753 lightningdDEBUG: Adding block 1306: 39b23476d9f56a93d3e8186829887cc7055fb7f86fc950c996f3d17bb02ed849
+0.444913913 lightningdDEBUG: Adding block 1307: 00fafdbf17d3e1b4c54c2ae5126dc1681cca04a0c2d509f84dc491f2dc0995ab
+0.464095928 lightningdDEBUG: Adding block 1308: 2333590bd365bdee6bbcd0676f9f26d031862e26a05087f5f733b9147709384e
+0.481308606 lightningdDEBUG: Adding block 1309: 0032e67edc13d0336d58f173cd0cc78920b778afe1a780db7e5092c2469d3c29
+0.498789294 lightningdDEBUG: Adding block 1310: 1783c454dfe77afac4e45823eab9e4bece2466085c01fec2018d6ee2d5b19057
+0.516222581 lightningdDEBUG: Adding block 1311: 4b71dfa16a4b59ae8030597e8cd6a7bf42d877fefff6909a2f2692ed4816a59b
+0.535684941 lightningdDEBUG: Adding block 1312: 21c14c21f5c40e352bd063fd09ada867d8586db25c87206ecc9553de29d0cf98
+0.554011107 lightningdDEBUG: Adding block 1313: 2f0b3e242842e971eb8c9723895c6a95f109e36acc3a0176d03da449c79d87eb
+0.571966737 lightningdDEBUG: Adding block 1314: 445577533f007e69f5c64c446753ee869584e94a803955930ed1ddda1149a811
+0.590092620 lightningdDEBUG: Adding block 1315: 0be25206cc3c5aaf97f5c59431d23d6c59f039d82d8d4154d1dc25967482309a
+0.609626418 lightningdDEBUG: Adding block 1316: 4d931251587075da3f496c9df2ac56c001369cf2b5fb2752a3ffe63ec9befb9b
+0.631851066 lightningdDEBUG: Adding block 1317: 0b8ea986db6be4824a4a87874564c9da10a3a8d6127d27050c0daf570e1e1f13
+0.653960639 lightningdDEBUG: Adding block 1318: 3bf1def7674c4e4852608a162e895f8a7302f6e098e870509fa51c1966cdc18b
+0.675638678 lightningdDEBUG: Adding block 1319: 2f386e863970712abc9ef84c0374bc6c4c9fcb33fa7e40c6d44d19ddd369c789
+0.693652529 lightningdDEBUG: Adding block 1320: 67d7521828c6a8e27af6766784a177e223fc01b653cdf3094fea544e9b46aac3
+0.711441837 lightningdDEBUG: Adding block 1321: 00b00a4b8a3482d3a81a9e0ef32e7c2a68dd8cdb354fbee458d2e9c471728fd3
+0.729587478 lightningdDEBUG: Adding block 1322: 1e760ffc6e52d17a2ed50d27f81835bae7e2cd2c6b32c1d771ed868df864767d
+0.747413906 lightningdDEBUG: Adding block 1323: 444f82554238c95d75cda153196cd44b6518527c47eb755ef4b0f87fc1a9c6d2
+0.759332818 chan#6DEBUG: Got depth change 0->631 for 8d9e7969fa1d2b0817f51d15210608d00a6ac20866de7b6d37f35e4365fdde75
+0.759364813 chan#6DEBUG: Funding tx 8d9e7969fa1d2b0817f51d15210608d00a6ac20866de7b6d37f35e4365fdde75 depth 631 of 3
+0.759509684 chan#6DEBUG: Funding tx 8d9e7969fa1d2b0817f51d15210608d00a6ac20866de7b6d37f35e4365fdde75 confirmed, but peer disconnected
+0.759542726 chan#9DEBUG: Got depth change 0->30 for dcf16ef36acd5145633fc473b8c5b35ceda2ddf323beca12b72d9b582c91ebce
+0.759563002 chan#9DEBUG: Funding tx dcf16ef36acd5145633fc473b8c5b35ceda2ddf323beca12b72d9b582c91ebce depth 30 of 1
+0.759646195 chan#9DEBUG: Funding tx dcf16ef36acd5145633fc473b8c5b35ceda2ddf323beca12b72d9b582c91ebce confirmed, but peer disconnected
+0.759673628 chan#10DEBUG: Got depth change 0->20 for 5303098c4ff27bf9d2d36678a351ef4449bf2d6c6597754e9d0a7924867e586c
+0.759689625 chan#10DEBUG: Funding tx 5303098c4ff27bf9d2d36678a351ef4449bf2d6c6597754e9d0a7924867e586c depth 20 of 1
+0.759755170 chan#10DEBUG: Funding tx 5303098c4ff27bf9d2d36678a351ef4449bf2d6c6597754e9d0a7924867e586c confirmed, but peer disconnected
+0.759809608 chan#8DEBUG: Got depth change 0->333 for 658298d048ad78a71733fead4e3200c9a5531026d331acf709b1e522b22562ae
+0.759825928 chan#8DEBUG: Funding tx 658298d048ad78a71733fead4e3200c9a5531026d331acf709b1e522b22562ae depth 333 of 3
+0.759895780 chan#8DEBUG: Funding tx 658298d048ad78a71733fead4e3200c9a5531026d331acf709b1e522b22562ae confirmed, but peer disconnected
+1.447817448 connectdDEBUG: Connected out, starting crypto
+1.450951624 hsmdDEBUG: Client: Received message 1 from client
+1.451316682 connectdDEBUG: Connect OUT
+1.451392900 connectdDEBUG: peer_out WIRE_INIT
+1.452122490 gossipdDEBUG: seeker: chosen as startup peer
+1.452207685 gossipdDEBUG: seeker: starting gossip
+1.452283105 connectdDEBUG: peer_in WIRE_INIT
+1.452546192 chan#10DEBUG: Peer has reconnected, state CHANNELD_NORMAL
+1.453604017 channeld-chan#10DEBUG: pid 9416, msgfd 33
+1.453675909 chan#10DEBUG: Already have funding locked in (and ready to announce)
+1.453682784 chan#10DEBUG: Ignoring fee limits!
+1.454452974 hsmdDEBUG: Client: Received message 9 from client
+1.454531430 hsmdDEBUG: new_client: 10
+1.463193331 channeld-chan#10DEBUG: init LOCAL: remote_per_commit = 022f6c9996ecf473059d237185c2dec99d19fddf6de5ddcd4b7def127866daec69, old_remote_per_commit = 0216114e36500ab427fa21e84ee02466e13372bb58796eb48fcb3ed3dafc755f7d next_idx_local = 5 next_idx_remote = 5 revocations_received = 4 feerates { SENT_ADD_ACK_REVOCATION:253 } range 253-4294967295
+1.463225463 channeld-chan#10DEBUG: option_static_remotekey = 1
+1.463410909 hsmdDEBUG: Client: Received message 18 from client
+1.463752914 hsmdDEBUG: Client: Received message 18 from client
+1.463761573 channeld-chan#10DEBUG: peer_out WIRE_CHANNEL_REESTABLISH
+1.464063909 channeld-chan#10DEBUG: peer_in WIRE_CHANNEL_REESTABLISH
+1.464091651 channeld-chan#10DEBUG: Got reestablish commit=5 revoke=4
+1.464115604 channeld-chan#10DEBUG: next_revocation_number = 4
+1.464299383 hsmdDEBUG: Client: Received message 18 from client
+1.464316399 channeld-chan#10DEBUG: option_static_remotekey: fields are correct
+1.464391133 channeld-chan#10DEBUG: Exchanging announcement signatures.
+1.464414668 gossipdDEBUG: Attempted to local_add_channel a known channel
+1.465168999 hsmdDEBUG: Client: Received message 2 from client
+1.465521750 channeld-chan#10DEBUG: peer_out WIRE_ANNOUNCEMENT_SIGNATURES
+1.488909907 channeld-chan#10DEBUG: peer_in WIRE_ANNOUNCEMENT_SIGNATURES
+1.508927580 channeld-chan#10DEBUG: peer_in WIRE_GOSSIP_TIMESTAMP_FILTER
+1.509009440 channeld-chan#10DEBUG: peer_out WIRE_GOSSIP_TIMESTAMP_FILTER
+1.509072361 channeld-chan#10DEBUG: Trying commit
+1.509131395 channeld-chan#10DEBUG: Can't send commit: nothing to send
+1.510014430 connectdDEBUG: Connected out, starting crypto
+1.512761856 hsmdDEBUG: Client: Received message 1 from client
+1.512956324 connectdDEBUG: Connect OUT
+1.513069913 connectdDEBUG: peer_out WIRE_INIT
+1.514106506 connectdDEBUG: peer_in WIRE_INIT
+1.514256620 chan#9DEBUG: Peer has reconnected, state CHANNELD_NORMAL
+1.515447779 channeld-chan#9DEBUG: pid 9417, msgfd 34
+1.515570982 chan#9DEBUG: Already have funding locked in (and ready to announce)
+1.515592488 chan#9DEBUG: Ignoring fee limits!
+1.516864424 hsmdDEBUG: Client: Received message 9 from client
+1.517003684 hsmdDEBUG: new_client: 9
+1.535603798 channeld-chan#9DEBUG: init LOCAL: remote_per_commit = 02c92782660434ffc827745c7cb2c2ef56c9a08624d76216bd3ae16858c49dd61b, old_remote_per_commit = 02823de3405510ee65039ec455b3b9f81721f31970febeb677cc7b8c1c105bd0b0 next_idx_local = 9 next_idx_remote = 9 revocations_received = 8 feerates { SENT_ADD_ACK_REVOCATION:253 } range 253-4294967295
+1.535692832 channeld-chan#9DEBUG: option_static_remotekey = 1
+1.536290085 hsmdDEBUG: Client: Received message 18 from client
+1.537128613 hsmdDEBUG: Client: Received message 18 from client
+1.537190208 channeld-chan#9DEBUG: peer_out WIRE_CHANNEL_REESTABLISH
+1.537402280 channeld-chan#9DEBUG: peer_in WIRE_CHANNEL_REESTABLISH
+1.537470330 channeld-chan#9DEBUG: Got reestablish commit=9 revoke=8
+1.537532258 channeld-chan#9DEBUG: next_revocation_number = 8
+1.538191940 hsmdDEBUG: Client: Received message 18 from client
+1.538281491 channeld-chan#9DEBUG: option_static_remotekey: fields are correct
+1.538442588 channeld-chan#9DEBUG: Exchanging announcement signatures.
+1.538475400 gossipdDEBUG: Attempted to local_add_channel a known channel
+1.539446380 hsmdDEBUG: Client: Received message 2 from client
+1.540272490 channeld-chan#9DEBUG: peer_out WIRE_ANNOUNCEMENT_SIGNATURES
+1.550171911 channeld-chan#9DEBUG: peer_in WIRE_ANNOUNCEMENT_SIGNATURES
+1.566336667 channeld-chan#9DEBUG: peer_in WIRE_GOSSIP_TIMESTAMP_FILTER
+1.566401635 channeld-chan#9DEBUG: Trying commit
+1.566449785 channeld-chan#9DEBUG: Can't send commit: nothing to send
+1.994875021 chan#6DEBUG: Will try reconnect in 2 seconds
+1.994941694 connectdDEBUG: Failed connected out: 127.0.0.1:9735: Connection establishment: Connection refused. 
+2.069607294 chan#8DEBUG: Will try reconnect in 2 seconds
+2.069683142 connectdDEBUG: Failed connected out: 127.0.0.1:9736: Connection establishment: Connection refused. 
+3.291871373 jsonrpc#4IO_IN: 7b20226a736f6e72706322203a2022322e30222c20226d6574686f6422203a202273656e647061795f74657374222c2022696422203a20226c696768746e696e
+3.291898865 jsonrpc#4IO_IN: 672d636c692d39343139222c2022706172616d7322203a5b20223033646166663130336536383038393933636462656164393239373639383231626563633534
+3.291931785 jsonrpc#4IO_IN: 62373862373531393032663037613130663864376630383162636334225d207d
+3.293042096 plugin-sendpay-crash.pyIO_OUT: 7b20226a736f6e72706322203a2022322e30222c20226d6574686f6422203a202273656e647061795f74657374222c2022696422203a20382c2022706172616d7322203a5b2022303364616666313033653638303839393363646265616439323937363938323162656363353462373862373531393032663037613130663864376630383162636334225d207d0a0a
+3.293920766 jsonrpc#30IO_IN: 7b226d6574686f64223a2022676574726f757465222c2022706172616d73223a207b226964223a20223033646166663130336536383038393933636462656164
+3.293947655 jsonrpc#30IO_IN: 39323937363938323162656363353462373862373531393032663037613130663864376630383162636334222c20226d7361746f736869223a20313030302c20
+3.293979102 jsonrpc#30IO_IN: 227269736b666163746f72223a20312c2022636c7476223a20392c20226578636c756465223a205b5d2c20226d6178686f7073223a2032307d2c20226964223a20307d
+3.295460713 gossipdDEBUG: Trying to find a route from (me) to 03daff103e6808993cdbead929769821becc54b78b751902f07a10f8d7f081bcc4 for 1000msat
+3.295516495 gossipdDEBUG: REPLY WIRE_GOSSIP_GETROUTE_REPLY with 0 fds
+3.295573851 jsonrpc#30IO_OUT: 7b226a736f6e727063223a22322e30222c226964223a302c22726573756c74223a7b22726f757465223a5b7b226964223a22303364616666313033653638303839393363646265616439323937363938323162656363353462373862373531393032663037613130663864376630383162636334222c226368616e6e656c223a223132393478327830222c22646972656374696f6e223a302c226d7361746f736869223a313030302c22616d6f756e745f6d736174223a22313030306d736174222c2264656c6179223a392c227374796c65223a22746c76227d5d7d207d0a0a
+3.296346501 jsonrpc#30IO_IN: 7b226d6574686f64223a202273656e64706179222c2022706172616d73223a207b22726f757465223a205b7b226964223a202230336461666631303365363830
+3.296420361 jsonrpc#30IO_IN: 3839393363646265616439323937363938323162656363353462373862373531393032663037613130663864376630383162636334222c20226368616e6e656c
+3.296445495 jsonrpc#30IO_IN: 223a20223132393478327830222c2022646972656374696f6e223a20302c20226d7361746f736869223a20313030302c2022616d6f756e745f6d736174223a2022313030306d736174222c202264656c6179223a20392c20227374796c65223a2022746c76227d5d2c20227061796d656e745f68617368223a20226561333566
+3.296491153 jsonrpc#30IO_IN: 6645354545443543334165394437393746386145313046423762666139366631426636396642383645664439374635424138394444654144413039222c20226d7361746f736869223a20313030303030307d2c20226964223a20317d
+3.314190575 lightningdBROKEN: FATAL SIGNAL 6 (version v0.8.0-40-g899f5de)
+3.314209080 lightningdBROKEN: backtrace: common/daemon.c:46 (send_backtrace) 0x55cef88dc663
+3.314214053 lightningdBROKEN: backtrace: common/daemon.c:54 (crashdump) 0x55cef88dc6ae
+3.314218021 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7fe14abddf1f
+3.314221950 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7fe14abdde97
+3.314225183 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7fe14abdf800
+3.314228360 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7fe14abcf399
+3.314231298 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7fe14abcf411
+3.314234741 lightningdBROKEN: backtrace: common/onion.c:98 (onion_final_hop) 0x55cef88e1534
+3.314238313 lightningdBROKEN: backtrace: lightningd/pay.c:998 (send_payment) 0x55cef88c8858
+3.314242994 lightningdBROKEN: backtrace: lightningd/pay.c:1321 (json_sendpay) 0x55cef88c923a
+3.314246262 lightningdBROKEN: backtrace: lightningd/jsonrpc.c:588 (command_exec) 0x55cef88bb126
+3.314249771 lightningdBROKEN: backtrace: lightningd/jsonrpc.c:679 (rpc_command_hook_callback) 0x55cef88bc7e4
+3.314253020 lightningdBROKEN: backtrace: lightningd/plugin_hook.c:123 (plugin_hook_call_) 0x55cef88d4ec1
+3.314256398 lightningdBROKEN: backtrace: lightningd/jsonrpc.c:729 (plugin_hook_call_rpc_command) 0x55cef88bb714
+3.314259116 lightningdBROKEN: backtrace: lightningd/jsonrpc.c:736 (call_rpc_command_hook) 0x55cef88bb714
+3.314262359 lightningdBROKEN: backtrace: common/timeout.c:39 (timer_expired) 0x55cef88e4770
+3.314265407 lightningdBROKEN: backtrace: lightningd/io_loop_with_timers.c:32 (io_loop_with_timers) 0x55cef88b98db
+3.314268958 lightningdBROKEN: backtrace: lightningd/lightningd.c:860 (main) 0x55cef88bde30
+3.314272111 lightningdBROKEN: backtrace: (null):0 ((null)) 0x7fe14abc0b96
+3.314275280 lightningdBROKEN: backtrace: (null):0 ((null)) 0x55cef88abd59
+3.314280222 lightningdBROKEN: backtrace: (null):0 ((null)) 0xffffffffffffffff

One could conclude from the logs that the receiver (03da..bcc4@localhost:9735) is offline. However, it shows up with "connected": true, in lightning-cli listpeers, and re-connecting manually doesn't resolve the issue.

getinfo output

{
   "id": "03068d9ac7f6973cbdb7212f2598afee2db14becd3d31e937659b0c09cee9f78f2",
   "alias": "clightningM",
   "color": "03068d",
   "num_peers": 4,
   "num_pending_channels": 0,
   "num_active_channels": 4,
   "num_inactive_channels": 0,
   "address": [],
   "binding": [
      {
         "type": "ipv4",
         "address": "127.0.0.1",
         "port": 9737
      }
   ],
   "version": "v0.8.0-40-g899f5de",
   "blockheight": 1323,
   "network": "regtest",
   "msatoshi_fees_collected": 0,
   "fees_collected_msat": "0msat",
   "lightning-dir": "/home/sergei/.lightning/regtest"
}
@s-tikhomirov s-tikhomirov changed the title sendpay from plugin crashed lightningd (FATAL SIGNAL 6) sendpay from plugin crashes lightningd (FATAL SIGNAL 6) Jan 22, 2020
@renepickhardt
Copy link
Collaborator

renepickhardt commented Jan 22, 2020

try to replace this line:

 plugin.rpc.sendpay(
        route=route,
        payment_hash=payment_hash,
        msatoshi=amount*1000
        )

with

 plugin.rpc.sendpay(
        route=route,
        payment_hash=payment_hash,
        )

works for me then

@s-tikhomirov
Copy link
Author

@renepickhardt this helped!

So if I use sendpay I shouldn't specify the amount, as the amount is taken from the route object, right?

@ZmnSCPxj
Copy link
Collaborator

You seem to assume that the amount in getroute is in satoshi, while the amount to pass into sendpay is in millisatoshi. However, all amounts offchain are always in millisatoshi, and getroute is an offchain concern (blockchains have no concept of routing). So the amount to pass into getroute should be in millisatoshi as well. You should probably be more explicit in your plugin about satoshi vs millisatoshi.

The reason it is crashing is, I think, is because the amount recorded (msatoshi argument of sendpay) should be less than or equal to the amount that reaches the destination.

Regardless, this should lead to an RPC error, not a crash of the lightningd....

@s-tikhomirov
Copy link
Author

s-tikhomirov commented Jan 23, 2020

@ZmnSCPxj I changed the amounts to millisatoshis and now observe two different outcomes.

If I use exactly the same amounts in getroute and sendpay (1 million msat), I get the following error: WIRE_TEMPORARY_CHANNEL_FAILURE (First peer not ready). This is not what I expected (I expected WIRE_INCORRECT_OR_UNKNOWN_PAYMENT_DETAILS). The peer in question has "connected": true, and the channel has "state": "CHANNELD_NORMAL".

I thought that the problem may have been in fees (the real payment demands a higher fee than getroute thought?..), so I tried calculating the route for 1M msat but sending a payment of only 500k msat. The result: lightningd crashes (with FATAL SIGNAL 6).

(Sorry for the long paste that follows; if there is a way to wrap a code fragment into a smaller scrollable block -- please let me know and I'll edit this.)

Log attached as file: crash.log.20200123114958.txt.

@ZmnSCPxj
Copy link
Collaborator

ZmnSCPxj commented Jan 23, 2020

You could put the text in an ordinary text file and drag it into the UI of GitHub (assuming you are using the web GitHub interface), the bit which says "Attach files by dragging & dropping", which would also be easier on us so as not to scroll so much in the GitHub issue and to read the logs in our preferred editor / text slice-and-dice tool (the one and only VIM).

@cdecker
Copy link
Member

cdecker commented Jan 26, 2020

The culprit is this assert in the onion construction:

lightning/common/onion.c

Lines 97 to 98 in 6489e63

if (!payment_secret)
assert(amount_msat_eq(total_msat, forward));

It seems you are mixing two different concepts here: by specifying a total_msat that is different from what the current route will deliver you opted into MPP, however MPP requires that you specify a payment_secret (usually a secret that is in the invoice and that the recipient can check against what it's expecting). So in this case you are sending a partial payment of 1000msat, but promise the recipient that you'll ultimately deliver 1'000'000msat, without adhering to the MPP protocol.

The crash is undesirable and can be fixed by just checking that having a value for either msatoshi or payment_secret implies also having the other one.

cdecker added a commit to cdecker/lightning that referenced this issue Jan 26, 2020
We were implicitly assuming a multi-part payment if the `msatoshi` argument
was specified, but then didn't check that we have all the pieces in place for
mpp. This adds a couple of additional checks to the arguments and makes it
more explicit what it means to do an mpp.

Fixes ElementsProject#3431

Reported-by: Sergei Tikhomirov <@s-tikhomirov>
@s-tikhomirov
Copy link
Author

@cdecker So am I correct to assume that the following use case is discouraged / not possible?

  • calculate a route once for some amount A;
  • perform multiple (non-atomic) payments along this route which in total are less than A.

@cdecker
Copy link
Member

cdecker commented Jan 26, 2020

@cdecker So am I correct to assume that the following use case is discouraged / not possible?

  • calculate a route once for some amount A;
  • perform multiple (non-atomic) payments along this route which in total are less than A.

It is possible, however the route needs adjustments for different values, since each element in the route array contains the absolute value the processing node should forward. So you can't. In addition if you want to split a payment, each split needs a unique partid, otherwise it is detected as an attempt to re-issue an already in flight payment (not a part of an mpp) and our sanity check would refuse it. Ideally though each partial payment would get routed through a different path, increasing privacy by not allowing forwarders to collate multiple parts.

For an example on how to manually drive a multi-part payment please see the following tests:

def test_partial_payment(node_factory, bitcoind, executor):

def test_partial_payment_timeout(node_factory, bitcoind):

def test_partial_payment_restart(node_factory, bitcoind):

def test_partial_payment_htlc_loss(node_factory, bitcoind):

@cdecker cdecker added the state::fixed These issues should have been addressed. Pending confirmation by OP, will close soon otherwise label Jan 28, 2020
cdecker added a commit to cdecker/lightning that referenced this issue Jan 30, 2020
We were implicitly assuming a multi-part payment if the `msatoshi` argument
was specified, but then didn't check that we have all the pieces in place for
mpp. This adds a couple of additional checks to the arguments and makes it
more explicit what it means to do an mpp.

Fixes ElementsProject#3431

Reported-by: Sergei Tikhomirov <@s-tikhomirov>
@ZmnSCPxj
Copy link
Collaborator

ZmnSCPxj commented Feb 3, 2020

increasing privacy by not allowing forwarders to collate multiple parts

Assuming surveillors only run a single node on the network. If a surveillor runs multiple nodes (likely, since that is more likely to catch more payments for them to monitor) then the extra routes make it easier to triangulate the destination. Fortunately Payment Decorrelation Fixes This (TM). When Schnorrrrrrr?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
state::fixed These issues should have been addressed. Pending confirmation by OP, will close soon otherwise
Projects
None yet
4 participants