Pay plugin returns invalid JSON when malformed arguments are passed in

[thestick613]

I've ran lightning-rpc pay SOME_INVOICE_XXX help (notice the extra help). I pressed Ctrl+C after a second, but lightningd crashed with this log. There seems to be an issue with quoting strings inside JSON.

2019-06-04T19:53:50.288Z plugin-pay Killing plugin: Failed to parse JSON response '??{ "jsonrpc": "2.0", "id": 9,  "error" :  { "code" : -32602, "message" : ""msatoshi" should be a millisatoshi amount, not "help"" } }??'
lightningd: FATAL SIGNAL 11 (version v0.6.1-1310-ge902d9a)
0x42807e send_backtrace
        common/daemon.c:40
0x428108 crashdump
        common/daemon.c:53
0x7f069675a4af ???
        ???:0
0x7f0696773cc0 ???
        ???:0
0x7f069683b895 ???
        ???:0
0x45b82e vsnprintf
        /usr/include/x86_64-linux-gnu/bits/stdio2.h:77
0x45b82e do_vfmt
        ccan/ccan/tal/str/str.c:66
0x45b98d tal_vfmt_
        ccan/ccan/tal/str/str.c:92
0x412b88 logv
        lightningd/log.c:267
0x412ac6 log_
        lightningd/log.c:336
0x40fc3d destroy_jcon
        lightningd/jsonrpc.c:153
0x45c6c9 notify
        ccan/ccan/tal/tal.c:235
0x45c766 del_tree
        ccan/ccan/tal/tal.c:397
0x45c79d del_tree
        ccan/ccan/tal/tal.c:407
0x45cc9f tal_free
        ccan/ccan/tal/tal.c:481
0x453bd6 io_close
        ccan/ccan/io/io.c:450
0x453c53 do_plan
        ccan/ccan/io/io.c:401
0x453c9d io_ready
        ccan/ccan/io/io.c:417
0x455346 io_loop
        ccan/ccan/io/poll.c:445
0x40e29d io_loop_with_timers
        lightningd/io_loop_with_timers.c:24
0x411de3 main
        lightningd/lightningd.c:818
0x7f069674582f ???
        ???:0
0x4038f8 ???
        ???:0
0xffffffffffffffff ???
        ???:0
2019-06-04T19:53:55.767Z lightningd(738): FATAL SIGNAL 11 (version v0.6.1-1310-ge902d9a)
2019-06-04T19:53:55.767Z lightningd(738): backtrace: common/daemon.c:45 (send_backtrace) 0x4280c2
2019-06-04T19:53:55.767Z lightningd(738): backtrace: common/daemon.c:53 (crashdump) 0x428108
2019-06-04T19:53:55.767Z lightningd(738): backtrace: (null):0 ((null)) 0x7f069675a4af
2019-06-04T19:53:55.767Z lightningd(738): backtrace: (null):0 ((null)) 0x7f0696773cc0
2019-06-04T19:53:55.767Z lightningd(738): backtrace: (null):0 ((null)) 0x7f069683b895
2019-06-04T19:53:55.767Z lightningd(738): backtrace: /usr/include/x86_64-linux-gnu/bits/stdio2.h:77 (vsnprintf) 0x45b82e
2019-06-04T19:53:55.767Z lightningd(738): backtrace: ccan/ccan/tal/str/str.c:66 (do_vfmt) 0x45b82e
2019-06-04T19:53:55.767Z lightningd(738): backtrace: ccan/ccan/tal/str/str.c:92 (tal_vfmt_) 0x45b98d
2019-06-04T19:53:55.767Z lightningd(738): backtrace: lightningd/log.c:267 (logv) 0x412b88
2019-06-04T19:53:55.767Z lightningd(738): backtrace: lightningd/log.c:336 (log_) 0x412ac6
2019-06-04T19:53:55.767Z lightningd(738): backtrace: lightningd/jsonrpc.c:153 (destroy_jcon) 0x40fc3d
2019-06-04T19:53:55.767Z lightningd(738): backtrace: ccan/ccan/tal/tal.c:235 (notify) 0x45c6c9
2019-06-04T19:53:55.767Z lightningd(738): backtrace: ccan/ccan/tal/tal.c:397 (del_tree) 0x45c766
2019-06-04T19:53:55.767Z lightningd(738): backtrace: ccan/ccan/tal/tal.c:407 (del_tree) 0x45c79d
2019-06-04T19:53:55.767Z lightningd(738): backtrace: ccan/ccan/tal/tal.c:481 (tal_free) 0x45cc9f
2019-06-04T19:53:55.767Z lightningd(738): backtrace: ccan/ccan/io/io.c:450 (io_close) 0x453bd6
2019-06-04T19:53:55.767Z lightningd(738): backtrace: ccan/ccan/io/io.c:401 (do_plan) 0x453c53
2019-06-04T19:53:55.767Z lightningd(738): backtrace: ccan/ccan/io/io.c:417 (io_ready) 0x453c9d
2019-06-04T19:53:55.767Z lightningd(738): backtrace: ccan/ccan/io/poll.c:445 (io_loop) 0x455346
2019-06-04T19:53:55.767Z lightningd(738): backtrace: lightningd/io_loop_with_timers.c:24 (io_loop_with_timers) 0x40e29d
2019-06-04T19:53:55.767Z lightningd(738): backtrace: lightningd/lightningd.c:818 (main) 0x411de3
2019-06-04T19:53:55.767Z lightningd(738): backtrace: (null):0 ((null)) 0x7f069674582f
2019-06-04T19:53:55.767Z lightningd(738): backtrace: (null):0 ((null)) 0x4038f8
2019-06-04T19:53:55.767Z lightningd(738): backtrace: (null):0 ((null)) 0xffffffffffffffff
Log dumped in crash.log.20190604195355

[darosior]

lightningd: FATAL SIGNAL 11 (version v0.6.1-1310-ge902d9a)

Maybe you should update to the latest stable release ;) ? https://github.com/ElementsProject/lightning/releases

[thestick613]

I'm actually running latest from git master.

[m-schmoock]

Your logs tell otherwise. Is there any chance you start an old lightningd binary on your system?

[thestick613]

It's this problem.

[m-schmoock]

Okay, sorry. your right e902d9a is more or less current master, at least after 0.7

So I agree we may have an issue here. The correct syntax for pay is

pay bolt11 [msatoshi] [label] [riskfactor] [maxfeepercent] [retry_for] [maxdelay] [exemptfee]

This means you are passing "help" as msatoshi. It shouldn't crash but print an error...

[darosior]

Cannot reproduce the crash on master, but the invalid JSON seems to be generated from here : https://github.com/ElementsProject/lightning/blob/bbedd3819d0eb0047c0c3cb4e8f74b9ab6763e4a/plugins/libplugin.c#L203-L220

[SimonVrouwe]

~Can reproduce (on non-dev build), seems to go wrong when write to stdout, here: https://github.com/ElementsProject/lightning/blob/bbedd3819d0eb0047c0c3cb4e8f74b9ab6763e4a/plugins/libplugin.c#L170~

[SimonVrouwe]

When unknown extra argument is given to pay, the plugin is killed because:

plugin-pay Killing plugin: Failed to parse JSON response '??{ "jsonrpc": "2.0", "id": 4,  "error" :  { "code" : -32602, "message" : ""msatoshi" should be a millisatoshi amount, not "pipo""'

Looks like too many quotes " in json response? There is being worked on in #2705, which at least doesn't crash it anymore.

[thestick613]

I just hope there are no attack surfaces enabled by this.

[SimonVrouwe]

Hmmm ... since a few rebuilds, I am not able anymore to reproduce a crash (now just a descent Abandoning command pay). And the one time it did crash, it actually showed a different backtrace then the OP's, which got lost in my terminal history :disappointed: .

So not sure if this needs high prio.

[rustyrussell]

Fixed in #2705 thanks!