JSON optimizations, cleanups and listsendpays optimizations #3957

rustyrussell · 2020-08-20T03:57:35Z

@fiatjaf reported in #3941 that listspays was slow, and indeed, it was.

I created 50,000 payments, and ran some tests.

With no optimization:
- listsendpays takes 0.983 seconds
- listpays takes 52.415 seconds
With -O3 -flto:
- listsendpays takes 0.628 seconds
- listpays takes 43.104 seconds

After these optimizations (mostly FIXMEs!) the results are:

With no optimization:
- listsendpays takes 0.676 seconds
- listpays takes 1.545 seconds.
With -O3 -flto:
- listsendpays takes 0.416 seconds
- listpays takes 0.971 seconds.

Tested on a test node which had made 50,000 payment, with no optimization. For comparison, time for 'listsendpays' was 0.983s. time lightning-cli -R --network=regtest --lightning-dir /tmp/ltests-k8jhvtty/test_pay_stress_1/lightning-1/ listpays > /dev/null Before: real 0m52.415s user 0m0.127s sys 0m0.044s After: real 0m42.741s user 0m0.149s sys 0m0.016s Signed-off-by: Rusty Russell <rusty@rustcorp.com.au> Changelog-Fixed: libplugin: significant speedups for reading large JSON replies (e.g. calling listsendpays on large nodes, or listchannels / listnodes).

We're going to change the API on the more complete JSON parser, so make and use a simple API for the easy cases. Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

They should all show the complete JSON, so unify them. Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

ZmnSCPxj

ACK 94058b4

Minor quibble though.

plugins/libplugin.c

rustyrussell · 2020-08-20T07:09:09Z

Fixed core dump in test-json, which I hadn't fixed up to the new API (at once stage I used NULL args to json_parse_input instead of implementing a separate json_parse_simple).

darosior

ACK 7471a83

Impressive!

rustyrussell · 2020-08-20T11:43:05Z

... and the other test where I made the same damn mistake...

darosior · 2020-08-20T11:28:33Z

lightningd/test/run-jsonrpc.c

-	toks = json_parse_input(str, str, strlen(str), &valid);
+	toks = toks_alloc(str);
+	jsmn_init(&parser);
+	valid = json_parse_input(&parser, &toks, str, strlen(str), NULL);


NULL will be dereferenced, maybe json_parse_input_simple ?

(did not submit the review)...

YEah, originally instead of the json_parse_simple() API I allowed NULL args for parser and complete. But I reverted that, and of course, missed this :(

Fixed in the obvious way now...

The jsmn parser is a beautiful piece of code. In particular, you can parse part of a string, then continue where you left off. We don't take advantage of this, however, meaning for large JSON objects we parse them multiple times before finally having enough to complete. Expose the parser state and tokens through the API, so the caller can pass them in repeatedly. For the moment, every caller is allocates each time (except the unit tests). Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

time lightning-cli -R --network=regtest --lightning-dir /tmp/ltests-k8jhvtty/test_pay_stress_1/lightning-1/ listpays > /dev/null Before: real 0m42.741s user 0m0.149s sys 0m0.016s After: real 0m13.674s user 0m0.131s sys 0m0.024s Signed-off-by: Rusty Russell <rusty@rustcorp.com.au> Changelog-Fixed: JSON-RPC: significant speedups for plugins which create large JSON replies (e.g. listpays on large nodes).

This doesn't make any difference, since lightningd generally sends us short commands (command responses are via the rpc loop, which is already done), but it's harmless. Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

memmem is also O(n^2), though it's faster. Now we have infrastructure, let's do incremental parsing. time lightning-cli -R --network=regtest --lightning-dir /tmp/ltests-k8jhvtty/test_pay_stress_1/lightning-1/ listpays > /dev/null Before: real 0m13.674s user 0m0.131s sys 0m0.024s After: real 0m12.447s user 0m0.143s sys 0m0.008s Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

time lightning-cli -R --network=regtest --lightning-dir /tmp/ltests-k8jhvtty/test_pay_stress_1/lightning-1/ listpays > /dev/null Before: real 0m12.447s user 0m0.143s sys 0m0.008s After: real 0m2.054s user 0m0.114s sys 0m0.024s Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

We have sanity checks in there that it's a valid point. Simply store the JSON token like we do with others. time lightning-cli -R --network=regtest --lightning-dir /tmp/ltests-k8jhvtty/test_pay_stress_1/lightning-1/ listpays > /dev/null Before: real 0m2.054s user 0m0.114s sys 0m0.024s After: real 0m1.781s user 0m0.127s sys 0m0.013s Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

We've never hit this, we do check them on insert, and it's slowing down some operations unnecessarily. $ time lightning-cli -R --network=regtest --lightning-dir /tmp/ltests-k8jhvtty/test_pay_stress_1/lightning-1/ listpays > /dev/null Before: real 0m1.781s user 0m0.127s sys 0m0.013s After: real 0m1.545s user 0m0.124s sys 0m0.024s Also, the raw listsendpays drops from 0.983s to 0.676s. (With -O3 -flto, listsendpays is 0.416s, listpays 0.971s). Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

PR ElementsProject#3957 improved performance considerably, however we still look over the entire message for the message separator. If instead we just look in the incrementally read data, we remove the quadratic behavior for large messages. This is safe since we then loop over the messages which would drain any message separator from the buffer before we attempt the next read.

PR ElementsProject#3957 improved performance considerably, however we still look over the entire message for the message separator. If instead we just look in the incrementally read data, we remove the quadratic behavior for large messages. This is safe since we then loop over the messages which would drain any message separator from the buffer before we attempt the next read. Changelog-Fixed: bcli: Significant speedups for block synchronization

PR #3957 improved performance considerably, however we still look over the entire message for the message separator. If instead we just look in the incrementally read data, we remove the quadratic behavior for large messages. This is safe since we then loop over the messages which would drain any message separator from the buffer before we attempt the next read. Changelog-Fixed: bcli: Significant speedups for block synchronization

rustyrussell added 3 commits August 20, 2020 09:45

common: add simple json parse wrapper for the complete cases.

5756685

We're going to change the API on the more complete JSON parser, so make and use a simple API for the easy cases. Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

plugins/bcli: use simplified parser, unify bad JSON paths.

837d731

They should all show the complete JSON, so unify them. Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

rustyrussell added cleanup json-rpc performance plugin pay-plugin labels Aug 20, 2020

rustyrussell requested review from darosior and ZmnSCPxj August 20, 2020 03:57

rustyrussell requested a review from cdecker as a code owner August 20, 2020 03:57

rustyrussell force-pushed the guilt/json-order branch from 40ccec4 to 94058b4 Compare August 20, 2020 05:12

ZmnSCPxj approved these changes Aug 20, 2020

View reviewed changes

plugins/libplugin.c Outdated Show resolved Hide resolved

rustyrussell force-pushed the guilt/json-order branch from 94058b4 to 7471a83 Compare August 20, 2020 07:08

darosior approved these changes Aug 20, 2020

View reviewed changes

rustyrussell force-pushed the guilt/json-order branch from 7471a83 to 1b67d52 Compare August 20, 2020 11:42

darosior reviewed Aug 20, 2020

View reviewed changes

rustyrussell added 7 commits August 20, 2020 23:10

libplugin: do incremental parsing on lightningd commands.

3b8eb19

This doesn't make any difference, since lightningd generally sends us short commands (command responses are via the rpc loop, which is already done), but it's harmless. Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

rustyrussell force-pushed the guilt/json-order branch from 1b67d52 to e264e9f Compare August 20, 2020 13:40

rustyrussell merged commit f762f7e into ElementsProject:master Aug 21, 2020

cdecker mentioned this pull request Aug 26, 2020

blocksync: Some performance improvements on top of #3957 #3985

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

JSON optimizations, cleanups and listsendpays optimizations #3957

JSON optimizations, cleanups and listsendpays optimizations #3957

rustyrussell commented Aug 20, 2020

ZmnSCPxj left a comment

rustyrussell commented Aug 20, 2020

darosior left a comment

rustyrussell commented Aug 20, 2020

darosior Aug 20, 2020

darosior Aug 20, 2020

darosior Aug 20, 2020

rustyrussell Aug 20, 2020

JSON optimizations, cleanups and listsendpays optimizations #3957

JSON optimizations, cleanups and listsendpays optimizations #3957

Conversation

rustyrussell commented Aug 20, 2020

ZmnSCPxj left a comment

Choose a reason for hiding this comment

rustyrussell commented Aug 20, 2020

darosior left a comment

Choose a reason for hiding this comment

rustyrussell commented Aug 20, 2020

darosior Aug 20, 2020

Choose a reason for hiding this comment

darosior Aug 20, 2020

Choose a reason for hiding this comment

darosior Aug 20, 2020

Choose a reason for hiding this comment

rustyrussell Aug 20, 2020

Choose a reason for hiding this comment