feat: chain hook rpc command #4384

m-schmoock · 2021-02-11T15:44:43Z

This chains the last remaining single hook rpc_command

Adds: feature, doc and modified testcase.

This is in draft as there is an open issue that will crash the test that I don't fully understand yet.
It seems like rpc_command_hook_payload *p or at least p->custom_result is freed with tal_free() somewhere,
so that we cant read the JSON p->custom_result (via command_raw_complete) anymore and give it to the daemon.

If we modify the code so that rpc_command_hook_final is explicitly called in the rpc_command_hook_callback, we have a similar situation where it then wants to tal_free() the rpc_command_hook_payload which is already freed.
Ideally I want to call rpc_command_hook_final just implicitly (just like the current code does) in order to detect if two or multiple plugins try to handle the same rpc_command.

@cdecker @rustyrussell some advice could be helpful.

--------------------------------------------------------- Captured stderr call ---------------------------------------------------------
lightningd: common/json_stream.c:99: json_stream_double_cr: Assertion `len >= 2' failed.
lightningd: FATAL SIGNAL 6 (version v0.9.3-107-g0bcc8ac-modded)
0x56017ae4e147 send_backtrace
	common/daemon.c:39
0x56017ae4e1ec crashdump
	common/daemon.c:52
0x7fe73bd6b69f ???
	???:0
0x7fe73bd6b615 ???
	???:0
0x7fe73bd54861 ???
	???:0
0x7fe73bd54746 ???
	???:0
0x7fe73bd63bf5 ???
	???:0
0x56017ae5842b json_stream_double_cr
	common/json_stream.c:99
0x56017ae584d1 json_stream_close
	common/json_stream.c:117
0x56017adf6d64 command_raw_complete
	lightningd/jsonrpc.c:459
0x56017adf7a2e rpc_command_hook_final
	lightningd/jsonrpc.c:751
0x56017ae24726 plugin_hook_callback
	lightningd/plugin_hook.c:216
0x56017ae1f1b0 plugin_response_handle
	lightningd/plugin.c:432

cdecker · 2021-02-14T14:17:56Z

Looking into the CI run with valgrind it seems like the field is not freed, otherwise valgrind would have complained about us asserting on a value that has been previously freed, so we'll need to look into this a bit further.

rustyrussell · 2021-02-22T09:47:18Z

Diff of partial fix. Basically, json_start() is linked only to the specific command, you need to be more primitive.

diff --git a/common/json_stream.c b/common/json_stream.c
index 45ac30ebd..20af11a29 100644
--- a/common/json_stream.c
+++ b/common/json_stream.c
@@ -194,8 +194,9 @@ void json_add_jsonstr(struct json_stream *js,
 	size_t len = strlen(jsonstr);
 
 	p = json_member_direct(js, fieldname, len);
-
-	memcpy(p, jsonstr, len);
+	/* Could be OOM! */
+	if (p)
+		memcpy(p, jsonstr, len);
 }
 
 /* This is where we read the json_stream and write it to conn */
diff --git a/lightningd/jsonrpc.c b/lightningd/jsonrpc.c
index 2bd96294f..75d2c4463 100644
--- a/lightningd/jsonrpc.c
+++ b/lightningd/jsonrpc.c
@@ -666,9 +666,9 @@ struct rpc_command_hook_payload {
 	const char *buffer;
 	const jsmntok_t *request;
 
-	/* custom repsonse/replace/error options plugins can have */
-	struct json_stream *custom_result;
-	struct json_stream *custom_error;
+	/* custom response/replace/error options plugins can have */
+	const char *custom_result;
+	const char *custom_error;
 	const jsmntok_t *custom_replace;
 	const char *custom_buffer;
 };
@@ -747,10 +747,18 @@ static void rpc_command_hook_final(struct rpc_command_hook_payload *p STEALS)
 	/* Free payload with cmd */
 	tal_steal(p->cmd, p);
 
-	if (p->custom_result != NULL)
-		return was_pending(command_raw_complete(p->cmd, p->custom_result));
-	if (p->custom_error != NULL)
-		return was_pending(command_failed(p->cmd, p->custom_error));
+	if (p->custom_result != NULL) {
+		struct json_stream *s = json_start(p->cmd);
+		json_add_jsonstr(s, "result", p->custom_result);
+		json_object_compat_end(s);
+		return was_pending(command_raw_complete(p->cmd, s));
+	}
+	if (p->custom_error != NULL) {
+		struct json_stream *s = json_start(p->cmd);
+		json_add_jsonstr(s, "error", p->custom_error);
+		json_object_compat_end(s);
+		return was_pending(command_raw_complete(p->cmd, s));
+	}
 	if (p->custom_replace != NULL)
 		return replace_command(p, p->custom_buffer, p->custom_replace);
 
@@ -769,7 +777,6 @@ rpc_command_hook_callback(struct rpc_command_hook_payload *p,
 {
 	const struct lightningd *ld = p->cmd->ld;
 	const jsmntok_t *tok, *custom_return;
-	struct json_stream *response;
 	static char *error = "";
 	char *method;
 
@@ -812,10 +819,7 @@ rpc_command_hook_callback(struct rpc_command_hook_payload *p,
 	if (tok) {
 		custom_return = json_get_member(buffer, tok, "result");
 		if (custom_return) {
-			response = json_start(p->cmd);
-			json_add_tok(response, "result", custom_return, buffer);
-			json_object_compat_end(response);
-			p->custom_result = response;
+			p->custom_result = json_strdup(p, buffer, custom_return);
 			return true;
 		}
 
@@ -835,8 +839,7 @@ rpc_command_hook_callback(struct rpc_command_hook_payload *p,
 				error = "'error' object does not contain a message.";
 				goto log_error_and_skip;
 			}
-			response = json_stream_fail_nodata(p->cmd, code, errmsg);
-			p->custom_error = response;
+			p->custom_error = json_strdup(p, buffer, custom_return);
 			return true;
 		}
 	}

rustyrussell · 2021-02-23T01:33:40Z

OK, this fixes it For Real:

diff --git a/lightningd/jsonrpc.c b/lightningd/jsonrpc.c
index 2bd96294f..c445e7b80 100644
--- a/lightningd/jsonrpc.c
+++ b/lightningd/jsonrpc.c
@@ -666,9 +666,9 @@ struct rpc_command_hook_payload {
 	const char *buffer;
 	const jsmntok_t *request;
 
-	/* custom repsonse/replace/error options plugins can have */
-	struct json_stream *custom_result;
-	struct json_stream *custom_error;
+	/* custom response/replace/error options plugins can have */
+	const char *custom_result;
+	const char *custom_error;
 	const jsmntok_t *custom_replace;
 	const char *custom_buffer;
 };
@@ -747,10 +747,18 @@ static void rpc_command_hook_final(struct rpc_command_hook_payload *p STEALS)
 	/* Free payload with cmd */
 	tal_steal(p->cmd, p);
 
-	if (p->custom_result != NULL)
-		return was_pending(command_raw_complete(p->cmd, p->custom_result));
-	if (p->custom_error != NULL)
-		return was_pending(command_failed(p->cmd, p->custom_error));
+	if (p->custom_result != NULL) {
+		struct json_stream *s = json_start(p->cmd);
+		json_add_jsonstr(s, "result", p->custom_result);
+		json_object_compat_end(s);
+		return was_pending(command_raw_complete(p->cmd, s));
+	}
+	if (p->custom_error != NULL) {
+		struct json_stream *s = json_start(p->cmd);
+		json_add_jsonstr(s, "error", p->custom_error);
+		json_object_compat_end(s);
+		return was_pending(command_raw_complete(p->cmd, s));
+	}
 	if (p->custom_replace != NULL)
 		return replace_command(p, p->custom_buffer, p->custom_replace);
 
@@ -769,7 +777,6 @@ rpc_command_hook_callback(struct rpc_command_hook_payload *p,
 {
 	const struct lightningd *ld = p->cmd->ld;
 	const jsmntok_t *tok, *custom_return;
-	struct json_stream *response;
 	static char *error = "";
 	char *method;
 
@@ -802,8 +809,10 @@ rpc_command_hook_callback(struct rpc_command_hook_payload *p,
 	 * it wants either to replace the request... */
 	tok = json_get_member(buffer, resulttok, "replace");
 	if (tok) {
-		p->custom_replace = tok;
-		p->custom_buffer = buffer;
+		/* We need to make copies here, as buffer and tokens
+		 * can be reused. */
+		p->custom_replace = json_tok_copy(p, tok);
+		p->custom_buffer = tal_strdup(p, buffer);
 		return true;
 	}
 
@@ -812,10 +821,7 @@ rpc_command_hook_callback(struct rpc_command_hook_payload *p,
 	if (tok) {
 		custom_return = json_get_member(buffer, tok, "result");
 		if (custom_return) {
-			response = json_start(p->cmd);
-			json_add_tok(response, "result", custom_return, buffer);
-			json_object_compat_end(response);
-			p->custom_result = response;
+			p->custom_result = json_strdup(p, buffer, custom_return);
 			return true;
 		}
 
@@ -835,8 +841,7 @@ rpc_command_hook_callback(struct rpc_command_hook_payload *p,
 				error = "'error' object does not contain a message.";
 				goto log_error_and_skip;
 			}
-			response = json_stream_fail_nodata(p->cmd, code, errmsg);
-			p->custom_error = response;
+			p->custom_error = json_strdup(p, buffer, custom_return);
 			return true;
 		}
 	}

m-schmoock · 2021-02-26T09:33:37Z

Thanks @rustyrussell for the investigation! I applied it and everything seems to work. Lets hope CI tests will be green...

I merged in your patch as mine but added your OOM as your extra commit ;)

m-schmoock · 2021-02-26T11:54:55Z

We have got a valgrind finding that complains about the buffer?? to be uninitialized when doing tal_strdup(p, buffer) (-> strlen(buffer) ) . I dont really understand why it thinks that at this point, as the buffer is used in that function already earlier for other stuff.

>  VALGRIND=1 ln_test tests/test_plugin.py::test_rpc_command_hook

...

Valgrind error file: valgrind-errors.27340
==27340== Conditional jump or move depends on uninitialised value(s)
==27340==    at 0x483DC88: strlen (vg_replace_strmem.c:459)
==27340==    by 0x1EF3E6: tal_strdup_ (str.c:18)
==27340==    by 0x134DC0: rpc_command_hook_callback (jsonrpc.c:815)
==27340==    by 0x16174E: plugin_hook_callback (plugin_hook.c:192)
==27340==    by 0x15C292: plugin_response_handle (plugin.c:432)
==27340==    by 0x15C49E: plugin_read_json_one (plugin.c:538)
==27340==    by 0x15C664: plugin_read_json (plugin.c:583)
==27340==    by 0x1E03A4: next_plan (io.c:59)
==27340==    by 0x1E0F2B: do_plan (io.c:407)
==27340==    by 0x1E0F69: io_ready (io.c:417)
==27340==    by 0x1E3128: io_loop (poll.c:445)
==27340==    by 0x13273B: io_loop_with_timers (io_loop_with_timers.c:24)

rustyrussell · 2021-03-02T04:24:28Z

We have got a valgrind finding that complains about the buffer?? to be uninitialized when doing tal_strdup(p, buffer) (-> strlen(buffer) ) . I dont really understand why it thinks that at this point, as the buffer is used in that function already earlier for other stuff.

>  VALGRIND=1 ln_test tests/test_plugin.py::test_rpc_command_hook

...

Valgrind error file: valgrind-errors.27340
==27340== Conditional jump or move depends on uninitialised value(s)
==27340==    at 0x483DC88: strlen (vg_replace_strmem.c:459)
==27340==    by 0x1EF3E6: tal_strdup_ (str.c:18)
==27340==    by 0x134DC0: rpc_command_hook_callback (jsonrpc.c:815)
==27340==    by 0x16174E: plugin_hook_callback (plugin_hook.c:192)
==27340==    by 0x15C292: plugin_response_handle (plugin.c:432)
==27340==    by 0x15C49E: plugin_read_json_one (plugin.c:538)
==27340==    by 0x15C664: plugin_read_json (plugin.c:583)
==27340==    by 0x1E03A4: next_plan (io.c:59)
==27340==    by 0x1E0F2B: do_plan (io.c:407)
==27340==    by 0x1E0F69: io_ready (io.c:417)
==27340==    by 0x1E3128: io_loop (poll.c:445)
==27340==    by 0x13273B: io_loop_with_timers (io_loop_with_timers.c:24)

Ah, buffer is not a nul-terminated string, ofc!

Fix is to use tal_dup_talarr() instead...

Changelog-Changed: The `rpc_command` hook is now chainable.

m-schmoock · 2021-03-02T22:02:51Z

Ah, buffer is not a nul-terminated string, ofc!

Fix is to use tal_dup_talarr() instead...

Thanks, I squashed that in...

rustyrussell · 2021-03-02T22:48:47Z

Ack fec9aa1

m-schmoock force-pushed the feat/chain_hook_rpc_command branch from 0bcc8ac to 913b122 Compare February 12, 2021 12:07

m-schmoock force-pushed the feat/chain_hook_rpc_command branch from 913b122 to 66de2aa Compare February 26, 2021 09:31

m-schmoock and others added 4 commits March 2, 2021 21:06

plugins: make rpc_command hook chainable

4e412ee

Changelog-Changed: The `rpc_command` hook is now chainable.

doc: make rpc_command hook chainable

5aab3f7

pytest: test rpc_command hook chain

95dca33

json: fix oom when adding a long string

fec9aa1

m-schmoock force-pushed the feat/chain_hook_rpc_command branch from bfc5917 to fec9aa1 Compare March 2, 2021 20:07

m-schmoock marked this pull request as ready for review March 2, 2021 22:01

m-schmoock requested a review from cdecker as a code owner March 2, 2021 22:01

rustyrussell merged commit 8af5764 into ElementsProject:master Mar 2, 2021

m-schmoock deleted the feat/chain_hook_rpc_command branch March 3, 2021 21:14

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat: chain hook rpc command #4384

feat: chain hook rpc command #4384

m-schmoock commented Feb 11, 2021 •

edited

Loading

cdecker commented Feb 14, 2021

rustyrussell commented Feb 22, 2021

rustyrussell commented Feb 23, 2021

m-schmoock commented Feb 26, 2021

m-schmoock commented Feb 26, 2021

rustyrussell commented Mar 2, 2021

m-schmoock commented Mar 2, 2021

rustyrussell commented Mar 2, 2021

feat: chain hook rpc command #4384

feat: chain hook rpc command #4384

Conversation

m-schmoock commented Feb 11, 2021 • edited Loading

cdecker commented Feb 14, 2021

rustyrussell commented Feb 22, 2021

rustyrussell commented Feb 23, 2021

m-schmoock commented Feb 26, 2021

m-schmoock commented Feb 26, 2021

rustyrussell commented Mar 2, 2021

m-schmoock commented Mar 2, 2021

rustyrussell commented Mar 2, 2021

m-schmoock commented Feb 11, 2021 •

edited

Loading