lightningd / plugins

Community curated plugins for core-lightning
BSD 3-Clause "New" or "Revised" License
269 stars 129 forks source link

JIT rebalance plugin crash #88

Closed darosior closed 4 years ago

darosior commented 4 years ago
2020-02-02T00:29:43.059Z **BROKEN** lightningd: Plugin for htlc_accepted returned non-result response {"jsonrpc": "2.0", "id": 34, "error": "Error while processing htlc_accepted: ValueError('Millisatoshi must be >= 0')"}
2020-02-02T00:29:43.461Z **BROKEN** lightningd: FATAL SIGNAL 6 (version v0.8.0-136-gf3600d2)
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: common/daemon.c:46 (send_backtrace) 0x56132d104049
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: common/daemon.c:54 (crashdump) 0x56132d104099
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0x7f515e4030ff
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0x7f515e403081
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0x7f515e3ee534
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: lightningd/log.c:819 (fatal) 0x56132d0d6b83
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: lightningd/plugin_hook.c:83 (plugin_hook_callback) 0x56132d0f8b4f
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: lightningd/plugin.c:241 (plugin_response_handle) 0x56132d0f4d33
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: lightningd/plugin.c:339 (plugin_read_json_one) 0x56132d0f4edb
2020-02-02T00:29:43.462Z **BROKEN** lightningd: backtrace: lightningd/plugin.c:371 (plugin_read_json) 0x56132d0f502e
2020-02-02T00:29:43.462Z **BROKEN** lightningd: backtrace: ccan/ccan/io/io.c:59 (next_plan) 0x56132d157eee
2020-02-02T00:29:43.462Z **BROKEN** lightningd: backtrace: ccan/ccan/io/io.c:407 (do_plan) 0x56132d158a6f
2020-02-02T00:29:43.462Z **BROKEN** lightningd: backtrace: ccan/ccan/io/io.c:417 (io_ready) 0x56132d158aad
2020-02-02T00:29:43.462Z **BROKEN** lightningd: backtrace: ccan/ccan/io/poll.c:445 (io_loop) 0x56132d15ac79
2020-02-02T00:29:43.462Z **BROKEN** lightningd: backtrace: lightningd/io_loop_with_timers.c:24 (io_loop_with_timers) 0x56132d0cd38c
2020-02-02T00:29:43.462Z **BROKEN** lightningd: backtrace: lightningd/lightningd.c:871 (main) 0x56132d0d4176
2020-02-02T00:29:43.462Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0x7f515e3efbba
2020-02-02T00:29:43.462Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0x56132d0b84a9
2020-02-02T00:29:43.462Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0xffffffffffffffff
darosior commented 4 years ago

I tried to quickly fix this but the log is confusing...

# grep -A5 -B10 "Error while processing" ~bitcoin/.lightning/debug.log
2020-02-02T00:29:43.045Z DEBUG 03abf6f44c355dec0d5aa155bdbdd6e0c8fefe318eff402de65c6eb2e1be55dc3e-gossipd: Ignoring redundant update for 608302x1773x0/1 (last 1580428758, now 1580603311)
2020-02-02T00:29:43.045Z DEBUG 02a04446caa81636d60d63b066f2814cbd3a6b5c258e3172cbdded7a16e2cfff4c-channeld-chan#3847: Trying commit
2020-02-02T00:29:43.046Z DEBUG 03abf6f44c355dec0d5aa155bdbdd6e0c8fefe318eff402de65c6eb2e1be55dc3e-gossipd: Received channel_update for channel 540093x1056x0/1 now ACTIVE
2020-02-02T00:29:43.046Z DEBUG 02a04446caa81636d60d63b066f2814cbd3a6b5c258e3172cbdded7a16e2cfff4c-channeld-chan#3847: Can't send commit: nothing to send
2020-02-02T00:29:43.046Z DEBUG 03abf6f44c355dec0d5aa155bdbdd6e0c8fefe318eff402de65c6eb2e1be55dc3e-gossipd: Received channel_update for channel 552181x1013x0/1 now ACTIVE
2020-02-02T00:29:43.046Z DEBUG 03abf6f44c355dec0d5aa155bdbdd6e0c8fefe318eff402de65c6eb2e1be55dc3e-gossipd: Ignoring redundant update for 552181x1013x0/1 (last 1580516495, now 1580602895)
2020-02-02T00:29:43.046Z DEBUG 03abf6f44c355dec0d5aa155bdbdd6e0c8fefe318eff402de65c6eb2e1be55dc3e-gossipd: Received channel_update for channel 596317x1251x1/0 now ACTIVE
2020-02-02T00:29:43.046Z DEBUG 03abf6f44c355dec0d5aa155bdbdd6e0c8fefe318eff402de65c6eb2e1be55dc3e-gossipd: Received channel_update for channel 593010x1214x1/0 now ACTIVE
2020-02-02T00:29:43.046Z INFO plugin-jitrebalance.py: Got an incoming HTLC htlc={'amount': '124308249msat', 'cltv_expiry': 615771, 'cltv_expiry_relative': 191, 'payment_hash': 'ba694fedb64a6e2add4b7c3fb48f1d2c3d5afcc29a80edb256e1fef72eb30d6e'}, onion={'payload': '1502040768ca9c040309655406080962b300070c0000', 'type': 'tlv', 'short_channel_id': '615091x1804x0', 'forward_amount': '124308124msat', 'outgoing_cltv_value': 615764, 'next_onion': '000243800cfc90d5762a583abfececaacaec029754fa626b5a8469fc69df839e99d1da3591f64c7931706ea70dbe474505db2b8983e8e249f7195270279c3eb2d497715bed246f5e08d96b5f104df41109d416dd4cc30f38e2f6d6811c745dd41fdfba17ff20c604173ec15cfa467d40db9c26888ed4bdaa96007512cb2b8139008421504f714e5981a25096a34c8ce58edbfcaccb708ccf5374445dd0ddfa7257f7cfccf96df992035e48d3a653adafbb8a8ea9ef4030d91085f25c61a67e7151e8d3db76ada6391490d81f652a15f8b18aed20671f74952c6e53bbd267dc14bd472cbe59038cfb3d5a9877a09aac56df45bc9b0fbf221dd21e7d67c497c501fb499ae3d5c294cb804b0feef20ec3ad71df0523e913267c889f7794980ff06bff606c14b3926b72e11b4dedbe77df8c0d68caeb99e6f0ea68c3147068ba110860bdb9176244f2565ac9f6089c5a60e1d1e3e23e7c99649facbcf46607482101ff44ff9984f9786c30de81a34f0e6ec1b821dcd99a15409c4b2e28eae2ee26563790033999438ff0afacfd3ee7e4d3892c1475fb749fd964a90d79f7d27fcbef5032286035b50f427e8dd6432083fb18796e1e9ada75aabfc64fd6f1f66c8f257a0feb14fd9d3229a20feb7030393abecc7f67bf83f45ce487a48c5e16cab9fdb76b331f355183e1412cf2094ec151397476e85f7c68b2320d37e659ab1da49c9ee3945d40cd252d2ae0b8c86fdb83f99463b9789d7f907f045f2191f6a8d40fa5f3ea6f80c174b547b0d3270014d33f742dc7d59ba3d1f803d280e480d8650a9fd2db3fce94586a580b1ac28fa5e83206c095a532ed060f5dbe017f6f118a626e602c1f801d6d9daeb745d0d7abe5dfc9dc97e161d110db163baa115eeb800b2b062342e7c9cd6e5a63f9503438266614a46e54178679c98ec0e9c97c982b278df2e02584d12d02b8eead0ba8442cb359ed96a6d8f886652422c20f6098c5b3ba213d38a9d3a4041027dd25ba5a280ba88a63b65419672ea635e1b3ab1b63e7d85cc890cf936d28ca00d35410d7e4552c433dbabc4a832b7811f7e87ace38346ca9d9efa60dd7feec8bfaa26044b2282d7401bb43119c4da0e1a515b9de9a7f1cf81d0b08a36477b378d16e5cee3c68c4a92ba3015ab2ed9b177187352c2e55876a8a77dd6bcde291f015ee7ca75816d30a30da81c1825a7108afc5bcb1db7a7fd107078b13e57b13006c68f32adbfc5a9eece7d333438d5f60b4815e323b7f6d0f0a3a69c3136902105952a0cc4cb699765c9cfaa329b2902837f31c4deab3a64cf74e29e80a95256016a43a04e9832f65b3853fcc8087e39c69461c8c97af441fbe78fa013fce8ea76ee755a4f72523cc13b571c4bde95e15c78f47fa8d33a833105144eba86625b1f45b1cb0b4a039c6ec5f7753797e8c229613fb5d6723cdb9fedd347e3d3a80a4ce05ad951168bcdf0e674a945b63a68ca536a35a1225fac9c36e4a5f99de7136f56319c292bfb718f38f271bfa38908eaccb8d7b22b8af68c144cdd5467ebfa45a10859ae247532f2f34562d81368a68fe4ad6c9e151868ddfdec57aa536b8cdfec2a17d090f032d61095be504478980d82e714290af55b0387734912f322e8549fc16790f936d4af5c3cf7e656d3fde801910ada630dee3c3ee9ef202c2c5df42514b4112e3344d4e562cbfb81c7e6a7bb62d30a340ee7f2f5ea8229157d7757169763ebad64a76eae2efe47808d3b811b0d2032ff335230994d15cfce4c2717bb72738d90a1082edf8775b0a159fd5b48ebe984c65a94fd87661a061bf53aabc85af5ca00b95016993b69f117678a4e0fbc20f193b5cc9a7d54f3a4753638d9372d1257e5b4c733c0690487cd28aea662a9867c725b4534c8e4816d3e4e47bc5e2717b2829ca0c3776c8ef', 'shared_secret': '684af28c7acbc1d8229e8a536d9038ea76ca2401a707cf039b9f35fae3f7bdbb'}
2020-02-02T00:29:43.046Z DEBUG 03abf6f44c355dec0d5aa155bdbdd6e0c8fefe318eff402de65c6eb2e1be55dc3e-gossipd: Received channel_update for channel 586169x1111x0/1 now ACTIVE
2020-02-02T00:29:43.059Z **BROKEN** lightningd: Plugin for htlc_accepted returned non-result response {"jsonrpc": "2.0", "id": 34, "error": "Error while processing htlc_accepted: ValueError('Millisatoshi must be >= 0')"}
2020-02-02T00:29:43.461Z **BROKEN** lightningd: FATAL SIGNAL 6 (version v0.8.0-136-gf3600d2)
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: common/daemon.c:46 (send_backtrace) 0x56132d104049
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: common/daemon.c:54 (crashdump) 0x56132d104099
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0x7f515e4030ff
2020-02-02T00:29:43.461Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0x7f515e403081
--
2020-02-08T21:00:10.029Z DEBUG 0395033b252c6f40e3756984162d68174e2bd8060a129c0d3462a9370471c6d28f-channeld-chan#3699: Sending master 1022
2020-02-08T21:00:10.029Z DEBUG 0395033b252c6f40e3756984162d68174e2bd8060a129c0d3462a9370471c6d28f-chan#3699: got revoke 15904: 1 changed
2020-02-08T21:00:10.029Z DEBUG 0395033b252c6f40e3756984162d68174e2bd8060a129c0d3462a9370471c6d28f-chan#3699: HTLC in 512 SENT_ADD_ACK_COMMIT->RCVD_ADD_ACK_REVOCATION
2020-02-08T21:00:10.031Z DEBUG 0395033b252c6f40e3756984162d68174e2bd8060a129c0d3462a9370471c6d28f-chan#3699: their htlc 512 locked
2020-02-08T21:00:10.138Z DEBUG 0395033b252c6f40e3756984162d68174e2bd8060a129c0d3462a9370471c6d28f-channeld-chan#3699: ... , awaiting 1122
2020-02-08T21:00:10.138Z DEBUG 0395033b252c6f40e3756984162d68174e2bd8060a129c0d3462a9370471c6d28f-channeld-chan#3699: Got it!
2020-02-08T21:00:10.139Z DEBUG 0395033b252c6f40e3756984162d68174e2bd8060a129c0d3462a9370471c6d28f-channeld-chan#3699: revoke_and_ack LOCAL: remote_per_commit = 03c33569878aab64bf7603ef0ce8eec14db3196c87211913344ea6063af0fd3c03, old_remote_per_commit = 03b9f5bda3fbb23a4908b5ae7c3b96b4616e3c683699d81973f4dc2c6527f4fa46
2020-02-08T21:00:10.139Z DEBUG 0395033b252c6f40e3756984162d68174e2bd8060a129c0d3462a9370471c6d28f-channeld-chan#3699: Trying commit
2020-02-08T21:00:10.139Z DEBUG 0395033b252c6f40e3756984162d68174e2bd8060a129c0d3462a9370471c6d28f-channeld-chan#3699: Can't send commit: nothing to send
2020-02-08T21:00:10.140Z INFO plugin-jitrebalance.py: Got an incoming HTLC htlc={'amount': '200003600msat', 'cltv_expiry': 616622, 'cltv_expiry_relative': 61, 'payment_hash': 'b5bf8456f332089894f1bd3b44471c248f855250408a9ef2ca1687374b0d75b8'}, onion={'payload': '1502040bebce8004030968a70608095f230005fd0001', 'type': 'tlv', 'short_channel_id': '614179x1533x1', 'forward_amount': '200003200msat', 'outgoing_cltv_value': 616615, 'next_onion': '0002cae12c6b9220ef0ff12dba1117c066ec8beb1a8a989dc3d833e3f6d592c91c6be46815a8d006a3a3af49426cd0a006d875ded271f5a98334e6e08445c7d9d589a1728fdc39ddada2ddfa7ac2232bc5cbc83777af6305cd433ba06c8152914e09a5f6868e3cca2cf7a3afbc0c16067cd571bff3e6724ef01ed5a7abf8e0cc1241cbbcb699d0012c709e363185e68c4e45596d38a3e4db407ba6e1fd35b1727729b2e2caf8707d8e648117e3bea431d3deadf5379249aae7f7152cc4925dcaeae273bb960360b02dadb79c29a14fd84652febf005b730a739e3834a327e7fea9a1bf7a3b260c7280fbcb593e4534b498278c2b3c0ce1a37946cfadf94b9228dd242fc4b2810e73904470cbd6acb24f7559e263678003b9d99d3003e830e02140a77c1e0c4b744895d64cd6d0dc94cb2e85e9e10242ddae26c63733ab15fcd9fd67ac8f4600789db6355b6ec92fc4cf2b5f12dbcf2bc176a97a866813dc4e8b3601bb46dbf9ccf61ca2ee5506b219e38cfc957ec526c2f5b336f01ff13e4fdc141e83f3c2e76adcdcad4e9a9a67a73371941710c80a2a5b0a796baa7cc8ce60f923f344d08ea886c69725f444e443b37c51a29e90639d951d9d0934a49023a26ca004e72dc0dddbf1bec32651bdcae6842a297782da56172baf081de05fabde2c072d71fb93c01cd716b2f7409c9b25ae0da053b0949eb2ac2b83c926f07ae1e5a3998cdd71b239d94b8c018e50ba517b7d94102cfe98060b9907edc7efe2a901a126f9111e31c2b431f5485e46c078ef8f6266540df306d94a1157951148a512feae9d23321d5291aedfe1f93ff5ed221808c1a139ea94322a60a24edc3f5b29d9982f395fc18d389b2a58f8202c852a06048e32f866fb59f6526811878166f644139eca002709acaf3eeb3c8ad3c5521cc39f0c177f8bc6349c14bd3b83d1ce3a78bd10e65fd54f8c980c6d897f65de2e2dcece28a9c4d29727249b3f235b2b76197c6c839688ee33061ce0d038fe9a028aa575130ea32d1559fe5ebe1ce1ae834b958eadd9485335a7eca287f19202739c11d68017abe4126b266c46f106f344db2083d1772f4eb567dc90de357b85c79ff35b61a6690d174972705de9ba657e7e90b6d9dccb6af718a308f3cb0ac18dd1ff1f5594d60f2e5b8cf078993cd3f913a2fbac0840198e11d601d317772d9234cbb0b3643a821770bd4572993bc567fc95bad897244bf05bf94398b63ec74795f38c0b156296cdce2189466911927cad31505e849f3c5c253613af55201e920f48c6f7c85c1d26c73a80be154aa51af585f82e8e09fa50caf00c3594c74e0ed1044a0966ab6d3a615cc18948717ee0cd9bc55025ad7535fc1487542c69da68b63dc4b98c7ecd4a3550c385d484ca40763bb747895acb6f08376699584339f1fada75b81fe248654606bce6298bdb5349ed58e8031ce735a96e6711675ae547949069d95c9952fdb26d035c841eae8e78c879379420e8aa23e883047db059ed76171e27d692c39ff34c456294047ee293d3cc715dacbec9a482490d38083b756c467506f2221a789fea9059bce1beb6a94a768fde63082941c5d658eced2fcd2fbfd9289997c14da2599f54220d6b84ebb451728160b0060a5c9e8ca6bbcfb822049dc25957944507ce38d2e9061b78c82816c6abddeb832b12df8ab8e775fd21fe81720cebf882334f201e1b6c3139f1fe603239bb8a5fc771199fe04286f0dc3853aebf8bf3896d1c0177107ca4703e5791b324f5eb72de01cb94bd192a81e5f1c69a2b00c398b2582089a31d68a7b4ec99e2e8af1fe8893669a7bc42ff57db56463929d80bd37c1ec0ea658b67f3d56186c14addd9cee589b896d043c8740c2cc41a1b7e276cea56ffe8be557d4ebdb15055b35b9b7c888640273485c8717a522ee2', 'shared_secret': '1ef369ae0b3eee1dd68f1883683a1d1b2bda438af747127d556612fc6931295c'}
2020-02-08T21:00:10.237Z **BROKEN** lightningd: Plugin for htlc_accepted returned non-result response {"jsonrpc": "2.0", "id": 23161, "error": "Error while processing htlc_accepted: ValueError('Millisatoshi must be >= 0')"}
2020-02-08T21:00:10.935Z **BROKEN** lightningd: FATAL SIGNAL 6 (version v0.8.0-202-g53ac284-modded)
2020-02-08T21:00:10.935Z **BROKEN** lightningd: backtrace: common/daemon.c:44 (send_backtrace) 0x562667e556a1
2020-02-08T21:00:10.935Z **BROKEN** lightningd: backtrace: common/daemon.c:52 (crashdump) 0x562667e556f1
2020-02-08T21:00:10.935Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0x7f7e2d51f0ff
2020-02-08T21:00:10.935Z **BROKEN** lightningd: backtrace: (null):0 ((null)) 0x7f7e2d51f081

The forward_amount is actually >= 0

cdecker commented 4 years ago

There should be a python stacktrace somewhere in the logs before the crash. Can you share that? Or even better maybe there is a good way to reproduce this issue in a test? That'd be perfect to get it fixed :-)

darosior commented 4 years ago

I'll grep for it (didn't think about it the first time..) EDIT: actually that the first thing I did but no backtrace, the plugin crashes lightningd but not itself.

I'll try to reproduce ASAP if I'm able to...

‐‐‐‐‐‐‐ Original Message ‐‐‐‐‐‐‐ Le mardi, février 11, 2020 12:49 PM, Christian Decker notifications@github.com a écrit :

There should be a python stacktrace somewhere in the logs before the crash. Can you share that? Or even better maybe there is a good way to reproduce this issue in a test? That'd be perfect to get it fixed :-)

You are receiving this because you authored the thread.

Reply to this email directly, view it on GitHub, or unsubscribe.[https://github.com/notifications/beacon/AFLK3FYHDYIXS73VN7OAWGLRCKGGBA5CNFSM4KPI5WL2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOELMEKZI.gif]

darosior commented 4 years ago

Ok @trobjo on IRC came up with the reproduction case and a pastebin :-) Apparently it was triggered at startup with a non-resolved HTLC. Here is the pastebin.

May 24 14:41:25 bitcoin-node lightningd[13028]: plugin-webhook  initialized plugin v3.1
May 24 14:41:25 bitcoin-node lightningd[13028]: plugin-sparko  initialized plugin v2.0
May 24 14:41:25 bitcoin-node lightningd[13028]: plugin-sparko  Login credentials read: PilatusTest:PilatusTest (full-access key: ZxkdYa6Jresaqr5qlw0sSr883Tz3xI8djCyEjzC7yM)
May 24 14:41:25 bitcoin-node lightningd[13028]: plugin-sparko 1 keys read: PilatusTest (full-access)
May 24 14:41:25 bitcoin-node lightningd[13028]: plugin-sparko  HTTP server on http://REMOVED_IP:19736/
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020/05/24 14:41:25 plugin-waitpay initialized waitpay plugin.
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.919Z DEBUG hsmd: Client: Received message 10 from client
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.920Z INFO plugin-jitrebalance.py: jitrebalance.py initializing {'lightning-dir': '/home/bitcoin_testnet/.lightning/testnet', 'rpc-file': 'lightning-rpc', 'startup': True, 'network': 'testnet', 'feature_set': {'init': '02aaa2', 'node': '8000000002aaa2', 'channel': '', 'invoice': '028200'}}
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.920Z DEBUG hsmd: Client: Received message 10 from client
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.920Z DEBUG connectd: REPLY WIRE_CONNECTCTL_ACTIVATE_REPLY with 0 fds
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.922Z INFO lightningd: --------------------------------------------------
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.922Z INFO lightningd: Server started with public key 03ac388eaf01314c302d9469b1c291b95702276ad5d6c32ab40fc59677dff4329d, alias Pilatus-testnet (color #03ac38) and lightningd v0.8.2.1
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.922Z DEBUG 027455aef8453d92f4706b560b61527cc217ddf14da41770e8ed6607190a1851b8-chan#23: Will try reconnect in 1 seconds
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.922Z DEBUG 028ec70462207b57e3d4d9332d9e0aee676c92d89b7c9fb0850fc2a24814d4d83c-chan#24: Will try reconnect in 2 seconds
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.922Z DEBUG 0263983b2261d6ad9e2e134c1aa60d0c82d47c1c16b876a096a38d4f283fc236dc-chan#26: Will try reconnect in 3 seconds
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.923Z DEBUG hsmd: Client: Received message 10 from client
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.930Z INFO plugin-autoclean: autocleaning every 3600 seconds
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.931Z INFO plugin-jitrebalance.py: Got an incoming HTLC htlc={'amount': '159403595msat', 'cltv_expiry': 1746445, 'cltv_expiry_relative': 600, 'payment_hash': 'e5ad6b9dc9f14277385021f016ba5465c1745730baee32687ceba9a24f84eac1'}, onion={'payload': '1502040980481004031aa60706081896d10000980000', 'type': 'tlv', 'short_channel_id': '1611473x152x0', 'forward_amount': '159402000msat', 'outgoing_cltv_value': 1746439, 'next_onion': '00020e7b2dc36853aa68f929b9d9978396c9419869a433756d8423601179d97fc98247172b458cd0a8d770dbbe98f077df3a8db29a68718961bb843c68c81d87eefa6ade9d51f75b7742a20a0a2f8b54ffe0e1190912f9b8c17642902622b49b0728e5e454d5ceec84698629266424b8a6e8507460b5695fb01a4d89d9d686473b2eb799b657085e499ef226265180a180d2324f461b1076f58901b6556031de9bdf2c42331ff3955f10934e20399607102a189d3929b930308e801516c142226fa6b0092d4f17011226dc7e9879f35096852a887469e89da76a2eed386ebeda04f13ed3cf806f2cd0940ff83e7c2109936ebad727f3a2594f9b9297d33fd43be4413d8fa88f902d84a8fd38a5bc81594d4d6f8217b9efc75928446064d6a1fa1555f2d407e1670c0fb39444db32247f3409f1c9f2d6c7bc47d6b4122f7e8a559ce103236e1f96cd7e4d1270af6c5bac02174e141c41c89e90e233da37b4296a7d3b3701f34d1a166cedf28ca8e21f8b86f14eedbbbb229af5d9d410c6c18d3e2adc56fb60697d863ecfb3ad7ccdbe4c8d51c40eab82bcf7be43e97023d77b2f0c437a218350790f4d9c21e9a5eaa060039d0563053aa46bcceb5f299bcd3895a365c6cdb0c646419706e643bf1b831c4a29034dad36ba6239199310690d6cc8624311ad3f0a31c4fac7636f2b7072dcc9d1ec3e81b5f61c3a206cbe25d66bedff1a18431470f138734584271f4ec849a20b543f92bae4dea428f396b18cb7437aa157a8cc711fe2057ec01e877ead0e2a117cc2773ab4203fe99b13cb9f826c12b678c54883cd7836379bdea642b2a7dbaa21dc755f57ea086fcfecb04719231f79863913b79e9c11fed84b8566494cc46e73fcd97618539025dd15baee8064a5ce1025638f8515318f49d1f5dc174c54991aff91c9ed058d156555eea26b15147e5b2b0d04530a3a0cc812884a4249336b6318d68ddf8df4e465a38d213c4746128f05f88ff80f19d9ca7a18f5baa1097f33696abc1ce5f4c2913e20fd4b0288252e337c0daa3ac197e5717ca7b696897032dd2162c2f9e0cad661ce31ca0b8c0a561a58a6ee3d59096a0d53c18f3866bf98bd08c9c04ae0611d2061889f598b
May 24 14:41:25 bitcoin-node lightningd[13028]: 25d82cf4e1c28ab29d2c665ee09d34132cca21c31946af7a593c65ee15c29a7fe8306725f57a8807357ef15fd223459f0e1dc1a7867d7d8b2a98242c73d887c82f82ebc9f4f4527f9b98f269b1d64f74e02cb2db651c05089eee11aae9eff6b24ac4eae676f7b3e67bdc3ee30e13b98486ed67bfd6a3290ac78e704676f1a1fe1ac94b8bd360a893f787e63e8e17c2f5f71f31178c2070524083315a9ec4e97811f55684f73ab3e290cd118ca6d31645f1fb499853369db5cd4c4327449b24d342a652bfbf8489c427240419c8531282a5a7a3c1b6f7b97f04dd957c78724b3de4cd581d2c2a1cf74302484eb5201888ced61a95c3db303b4ba8070118ade425c74c0f2a866a6119d637f9505ee231e598f24f4344b9c85efb6a06f1a2f9b373e6f9160a81982a1b3d0810bb08c1bf9cb8deb9ee973d15d74bf68f731f761d919f163c415dc24d2820c13ff3315587a2616dac06ae31834d55eb3b27d1c6f58ea6caa2d0e387b2f69982f3fcef8161618705e7f882cb183ce459bab912900dd882cb577a624a1f8b9918c2218ab74b6d98c553cf92b858412718b1005f1bc59273b872ea2ea9f4ada7e693da3cc8ad337ab0ddc2a0024c9a3b9b45a3532560defa8c546fafd58d024f63f5ad3ea7295f474cf3a3856e9c7da2a96a9084b524ba35b93eaebd819be4f160891608fde3499437112bf34102cc97d23a090929ad54a483805fc8f12b1d1d44fa35156ab112634ff316496b39cd81ef5ca0201735b86eb00d7952f7e3321c0711df95bc3789d3e51d793f', 'shared_secret': 'a1ab1c20870607f9857b5714c40d1196ab9c510fb1688b54dddbdf0784b505c9'}
May 24 14:41:25 bitcoin-node lightningd[13028]: Plugin for htlc_accepted returned non-result response {"jsonrpc": "2.0", "id": 23, "error": {"code": -32600, "message": "Error while processing htlc_accepted: 'short_channel_id'"}}
May 24 14:41:25 bitcoin-node lightningd[13028]: 2020-05-24T14:41:25.940Z **BROKEN** lightningd: Plugin for htlc_accepted returned non-result response {"jsonrpc": "2.0", "id": 23, "error": {"code": -32600, "message": "Error while processing htlc_accepted: 'short_channel_id'"}}
May 24 14:41:25 bitcoin-node lightningd[13028]: lightningd: FATAL SIGNAL 6 (version v0.8.2.1)
May 24 14:41:25 bitcoin-node lightningd[13028]: 0x560dba451eed send_backtrace
May 24 14:41:25 bitcoin-node lightningd[13028]:         common/daemon.c:39
May 24 14:41:25 bitcoin-node lightningd[13028]: 0x560dba451f72 crashdump
May 24 14:41:25 bitcoin-node lightningd[13028]:         common/daemon.c:52
May 24 14:41:25 bitcoin-node lightningd[13028]: 0x7f298415d05f ???
May 24 14:41:25 bitcoin-node lightningd[13028]:         ???:0
May 24 14:41:25 bitcoin-node lightningd[13028]: 0x7f298415cfff ???
May 24 14:41:25 bitcoin-node lightningd[13028]:         ???:0
May 24 14:41:25 bitcoin-node lightningd[13028]: 0x7f298415e429 ???
May 24 14:41:25 bitcoin-node lightningd[13028]:         ???:0
May 24 14:41:25 bitcoin-node lightningd[13028]: 0x560dba434540 fatal
May 24 14:41:25 bitcoin-node lightningd[13028]:         lightningd/log.c:819
May 24 14:41:25 bitcoin-node lightningd[13028]: 0x560dba44a087 plugin_hook_callback
May 24 14:41:25 bitcoin-node lightningd[13028]:         lightningd/plugin_hook.c:178
May 24 14:41:25 bitcoin-node lightningd[13028]: 0x560dba449112 plugin_response_handle
May 24 14:41:25 bitcoin-node lightningd[13028]:         lightningd/plugin.c:274
May 24 14:41:25 bitcoin-node lightningd[13028]: 0x560dba44921e plugin_read_json_one
May 24 14:41:25 bitcoin-node lightningd[13028]:         lightningd/plugin.c:372
May 24 14:41:25 bitcoin-node lightningd[13028]: 0x560dba4492f4 plugin_read_json
May 24 14:41:26 bitcoin-node systemd[1]: lightningd@testnet.service: Main process exited, code=killed, status=6/ABRT
May 24 14:41:26 bitcoin-node systemd[1]: lightningd@testnet.service: Control process exited, code=exited status=2
May 24 14:41:26 bitcoin-node systemd[1]: lightningd@testnet.service: Unit entered failed state.
May 24 14:41:26 bitcoin-node systemd[1]: lightningd@testnet.service: Failed with result 'signal'.
May 24 14:41:26 bitcoin-node systemd[1]: lightningd@testnet.service: Service hold-off time over, scheduling restart.
May 24 14:41:26 bitcoin-node systemd[1]: Stopped Custom systemd service implementation of the Lightning daemon.
May 24 14:41:26 bitcoin-node systemd[1]: lightningd@testnet.service: Start request repeated too quickly.
May 24 14:41:26 bitcoin-node systemd[1]: Failed to start Custom systemd service implementation of the Lightning daemon.
cdecker commented 4 years ago

That sounds like a key error, in which we try to access a dict field that is not set. Really strange that there is no traceback